[sync] Authentication problems

Roel Gloudemans roel at gloudemans.info
Tue Apr 26 11:30:27 PDT 2005 

I set session.auto_start = 1

And now I get another error
Horde/SyncML/sifConverter.php not found.
Forgotten commit?

Thanx,
Roel.

Quoting Karsten Fourmont <fourmont at gmx.de>:

> Hi,
>
> the authentication seems to be fine (authorized=1), it's more of a 
> session handling issue.
>
> Your logs indicate that the for the second message sent from the 
> client, horde SyncML creates a new session:
>
> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: New session created:
> syncmlscpimoutlook1 [on line 162 of "/usr/share/pear/Horde/SyncML.php"]
>
> This is wrong: it should say something like "SyncML: Existing session 
> continued: syncml scpimoutlook1..."
>
> Without the session information, the SyncML code does not know 
> user/password (client sends this only for 1st msg) and so the backend 
> produces the "not authorized error".
>
> Try fiddling around with your horde session handling config.
>
> My php.ini says something like:
>
> session.save_handler = files
> session.save_path = /mydirforsessioninfo
>
> which results in files sess_syncml... files being created in that dir 
> during syncing. (The files get deleted after succesful sync)
>
> Hope this helps,
>  Karsten
>
>
>
> Roel Gloudemans wrote:
>
>
>> My Horde installation uses LDAP for authentication. Syncing using 
>> sync4j fails each and every time with the message that no password 
>> has been provided for LDAP authentication.
>>
>> Where should I look to debug this?
>>
>> Cheers,
>> Roel.
>>
>> ---- horde log -------
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: New session created: 
>> syncmlscpimoutlook1 [on line 162 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> Prefs_sql::retrieve(): SELECT pref_scope, pref_name, pref_value FROM 
>> horde_prefs WHERE pref_uid = ? AND (pref_scope = ? OR pref_scope = 
>> 'horde') ORDER BY pref_scope [on line 132 of 
>> "/usr/share/pear/Horde/Prefs/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: authorized=1 version=1 
>> msgid=1 source=sc-pim-outlook target=http://lancer.gloudemans.info 
>> user=lancer charset=ISO-8859-1 [on line 216 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: looking for sync for 
>> contacts [on line 260 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: Create new sync for 
>> contacts [on line 266 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> DataTree_sql::_buildParentIds(): SELECT datatree_id, datatree_parents
>>> FROM horde_datatree WHERE datatree_name = 'contacts' AND group_uid =
>> 'syncml' ORDER BY datatree_id [on line 257 of 
>> "/usr/share/pear/Horde/DataTree/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> DataTree_sql::_load(): SELECT c.datatree_id, c.datatree_name, 
>> c.datatree_parents, c.datatree_order FROM horde_datatree c WHERE 
>> c.group_uid = 'syncml'  [on line 118 of 
>> "/usr/share/pear/Horde/DataTree/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: No info about 
>> previous syncs found for id lancer:sc-pim-outlookand database 
>> contacts [on line 99 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: Anchor 
>> mismatch, enforcing SlowSync [on line 121 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: return message 
>> completed [on line 486 of "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: New session created: 
>> syncmlscpimoutlook1 [on line 162 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [emergency] [horde] No password provided for 
>> LDAP authentication. [on line 94 of 
>> "/usr/share/pear/Horde/Auth/ldap.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: New session created: 
>> syncmlscpimoutlook1 [on line 162 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> Prefs_sql::retrieve(): SELECT pref_scope, pref_name, pref_value FROM 
>> horde_prefs WHERE pref_uid = ? AND (pref_scope = ? OR pref_scope = 
>> 'horde') ORDER BY pref_scope [on line 132 of 
>> "/usr/share/pear/Horde/Prefs/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: authorized=1 version=1 
>> msgid=1 source=sc-pim-outlook target=http://lancer.gloudemans.info 
>> user=lancer charset=ISO-8859-1 [on line 216 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: looking for sync for 
>> calendar [on line 260 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: Create new sync for 
>> calendar [on line 266 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> DataTree_sql::_buildParentIds(): SELECT datatree_id, datatree_parents
>>> FROM horde_datatree WHERE datatree_name = 'calendar' AND group_uid =
>> 'syncml' ORDER BY datatree_id [on line 257 of 
>> "/usr/share/pear/Horde/DataTree/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SQL Query by 
>> DataTree_sql::_load(): SELECT c.datatree_id, c.datatree_name, 
>> c.datatree_parents, c.datatree_order FROM horde_datatree c WHERE 
>> c.group_uid = 'syncml'  [on line 118 of 
>> "/usr/share/pear/Horde/DataTree/sql.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: No info about 
>> previous syncs found for id lancer:sc-pim-outlookand database 
>> calendar [on line 99 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: Anchor 
>> mismatch, enforcing SlowSync [on line 121 of 
>> "/usr/share/pear/Horde/SyncML/Command/Alert.php"]
>> Apr 26 18:03:17 HORDE [debug] [horde] SyncML: SyncML: return message 
>> completed [on line 486 of "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:18 HORDE [debug] [horde] SyncML: New session created: 
>> syncmlscpimoutlook1 [on line 162 of 
>> "/usr/share/pear/Horde/SyncML.php"]
>> Apr 26 18:03:18 HORDE [emergency] [horde] No password provided for 
>> LDAP authentication. [on line 94 of 
>> "/usr/share/pear/Horde/Auth/ldap.php"]
>>
>>
>> ---- sync4j log -------
>> 18:03:15:578 [INFO] - Initializing
>> 18:03:15:578 [INFO] - **********  CONTACTS SYNC  ************
>> 18:03:15:578 [DEBUG] - initialization-message:
>> 18:03:15:578 [DEBUG] - <?xml version="1.0" encoding="UTF-8"?><SyncML>
>> <SyncHdr>
>> <VerDTD>1.1</VerDTD>
>> <VerProto>SyncML/1.1</VerProto>
>> <SessionID>1</SessionID>
>> <MsgID>1</MsgID>
>> <Target><LocURI>http://lancer.gloudemans.info</LocURI></Target>
>> <Source><LocURI>sc-pim-outlook</LocURI></Source>
>> <Cred>
>> <Meta><Format xmlns='syncml:metinf'>b64</Format><Type 
>> xmlns='syncml:metinf'>syncml:auth-basic</Type></Meta>
>> <Data>[DATA REMOVED]</Data>
>> </Cred>
>> </SyncHdr>
>> <SyncBody>
>> <Alert>
>> <CmdID>1</CmdID>
>> <Data>201</Data>
>> <Item>
>> <Target><LocURI>contacts</LocURI></Target>
>> <Source><LocURI>contact</LocURI></Source>
>> <Meta><Anchor xmlns="syncml:metinf">
>> <Last>0</Last>
>> <Next>1114531395</Next>
>> </Anchor></Meta>
>> </Item>
>> </Alert>
>>
>> <Final/>
>> </SyncBody>
>> </SyncML>
>> 18:03:15:578 [DEBUG] - Connecting to lancer.gloudemans.info:80
>> 18:03:15:593 [DEBUG] - Requesting resource /horde/rpc.php
>> 18:03:15:890 [DEBUG] - Message sent
>> 18:03:15:906 [DEBUG] - Reading response...
>> 18:03:15:906 [DEBUG] - Content-length: 940
>> 18:03:15:906 [DEBUG] - Response read
>> 18:03:15:906 [INFO] - Initialization done
>> 18:03:15:906 [DEBUG] - response to inizialization-message:
>> 18:03:15:906 [DEBUG] - 
>> <SyncML><SyncHdr><VerDTD>1.1</VerDTD><VerProto>SyncML/1.1</VerProto><SessionID>1</SessionID><MsgID>1</MsgID><Target><LocURI>sc-pim-outlook</LocURI></Target><Source><LocURI>http://lancer.gloudemans.info</LocURI></Source></SyncHdr><SyncBody><Status><CmdID>1</CmdID><MsgRef>1</MsgRef><CmdRef>0</CmdRef><Cmd>SyncHdr</Cmd><SourceRef>sc-pim-outlook</SourceRef><TargetRef>http://lancer.gloudemans.info</TargetRef><Data>212</Data></Status><Status><CmdID>2</CmdID><MsgRef>1</MsgRef><CmdRef>1</CmdRef><Cmd>Alert</Cmd><SourceRef>contact</SourceRef><TargetRef>contacts</TargetRef><Data>508</Data><Item><Data><Anchor><Next>1114531395</Next><Last>0</Last></Anchor></Data></Item></Status><Alert><CmdID>3</CmdID><Data>201</Data><Item><Target><LocURI>contact</LocURI></Target><Source><LocURI>contacts</LocURI></Source><Meta><Anchor 
>> xmlns="syncml:metinf"><Last>0</Last><Next>1114531397</Next></Anchor></Meta></Item></Alert><Final></Final></SyncBody></SyncML>
>> 18:03:15:906 [INFO] - The server alert code for contacts is 201
>> 18:03:15:906 [DEBUG] - url from response to inizialization-message:
>> 18:03:15:937 [INFO] - Synchronizing contacts
>> 18:03:15:937 [INFO] - Preparing slow sync for contacts
>> 18:03:15:937 [INFO] - Detected 0 items
>> 18:03:15:937 [DEBUG] - Preparing slow sync for contact
>> 18:03:15:937 [DEBUG] - modification-message:
>> 18:03:15:937 [DEBUG] - <?xml version="1.0" 
>> encoding="UTF-8"?><SyncML><SyncHdr>
>> <VerDTD>1.1</VerDTD>
>> <VerProto>SyncML/1.1</VerProto>
>> <SessionID>1</SessionID>
>> <MsgID>2</MsgID>
>> <Target><LocURI>http://lancer.gloudemans.info</LocURI></Target>
>> <Source><LocURI>sc-pim-outlook</LocURI></Source>
>> </SyncHdr>
>> <SyncBody>
>> <Status>
>> <CmdID>1</CmdID>
>> <MsgRef>1</MsgRef>
>> <CmdRef>0</CmdRef>
>> <Cmd>SyncHdr</Cmd>
>> <TargetRef>http://lancer.gloudemans.info</TargetRef>
>> <SourceRef>sc-pim-outlook</SourceRef>
>> <Data>200</Data>
>> </Status>
>> <Status>
>> <CmdID>2</CmdID>
>> <MsgRef>1</MsgRef><CmdRef>1</CmdRef><Cmd>Alert</Cmd>
>> <TargetRef>contacts</TargetRef>
>> <SourceRef>contact</SourceRef>
>> <Data>200</Data>
>> <Item>
>> <Data>
>> <Anchor xmlns='syncml:metinf'><Next>1114531395</Next></Anchor>
>> </Data>
>> </Item>
>> </Status>
>> <Sync><CmdID>3</CmdID>
>> <Target><LocURI>contacts</LocURI></Target>
>> <Source><LocURI>contact</LocURI></Source>
>>
>> </Sync><Final/>
>> </SyncBody>
>> </SyncML>
>> 18:03:15:937 [INFO] - Sending modifications
>> 18:03:15:937 [DEBUG] - Connecting to lancer.gloudemans.info:80
>> 18:03:15:937 [DEBUG] - Requesting resource /horde/rpc.php
>> 18:03:16:062 [DEBUG] - Message sent
>> 18:03:16:062 [DEBUG] - Reading response...
>> 18:03:16:062 [DEBUG] - Content-length: 269
>> 18:03:16:062 [DEBUG] - Response read
>> 18:03:16:062 [DEBUG] - response to modification-message:
>> 18:03:16:062 [DEBUG] - <html>
>> <head><title>Horde :: Fatal Error</title></head>
>> <body style="background-color: white; color: black;"><h1>A fatal 
>> error has occurred</h1><h3>No password provided for LDAP 
>> authentication.</h3><h3>Details have been logged for the 
>> administrator.</h3></body>
>> </html>
>> 18:03:16:078 [INFO] - **********  CALENDAR SYNC  ************
>> 18:03:16:078 [DEBUG] - initialization-message:
>> 18:03:16:093 [DEBUG] - <?xml version="1.0" encoding="UTF-8"?><SyncML>
>> <SyncHdr>
>> <VerDTD>1.1</VerDTD>
>> <VerProto>SyncML/1.1</VerProto>
>> <SessionID>1</SessionID>
>> <MsgID>1</MsgID>
>> <Target><LocURI>http://lancer.gloudemans.info</LocURI></Target>
>> <Source><LocURI>sc-pim-outlook</LocURI></Source>
>> <Cred>
>> <Meta><Format xmlns='syncml:metinf'>b64</Format><Type 
>> xmlns='syncml:metinf'>syncml:auth-basic</Type></Meta>
>> <Data>[DATA REMOVED]</Data>
>> </Cred>
>> </SyncHdr>
>> <SyncBody>
>> <Alert>
>> <CmdID>1</CmdID>
>> <Data>201</Data>
>> <Item>
>> <Target><LocURI>calendar</LocURI></Target>
>> <Source><LocURI>calendar</LocURI></Source>
>> <Meta><Anchor xmlns="syncml:metinf">
>> <Last>0</Last>
>> <Next>1114531396</Next>
>> </Anchor></Meta>
>> </Item>
>> </Alert>
>>
>> <Final/>
>> </SyncBody>
>> </SyncML>
>> 18:03:16:093 [DEBUG] - Connecting to lancer.gloudemans.info:80
>> 18:03:16:093 [DEBUG] - Requesting resource /horde/rpc.php
>> 18:03:16:296 [DEBUG] - Message sent
>> 18:03:16:296 [DEBUG] - Reading response...
>> 18:03:16:296 [DEBUG] - Content-length: 942
>> 18:03:16:296 [DEBUG] - Response read
>> 18:03:16:296 [INFO] - Initialization done
>> 18:03:16:296 [DEBUG] - response to inizialization-message:
>> 18:03:16:296 [DEBUG] - 
>> <SyncML><SyncHdr><VerDTD>1.1</VerDTD><VerProto>SyncML/1.1</VerProto><SessionID>1</SessionID><MsgID>1</MsgID><Target><LocURI>sc-pim-outlook</LocURI></Target><Source><LocURI>http://lancer.gloudemans.info</LocURI></Source></SyncHdr><SyncBody><Status><CmdID>1</CmdID><MsgRef>1</MsgRef><CmdRef>0</CmdRef><Cmd>SyncHdr</Cmd><SourceRef>sc-pim-outlook</SourceRef><TargetRef>http://lancer.gloudemans.info</TargetRef><Data>212</Data></Status><Status><CmdID>2</CmdID><MsgRef>1</MsgRef><CmdRef>1</CmdRef><Cmd>Alert</Cmd><SourceRef>calendar</SourceRef><TargetRef>calendar</TargetRef><Data>508</Data><Item><Data><Anchor><Next>1114531396</Next><Last>0</Last></Anchor></Data></Item></Status><Alert><CmdID>3</CmdID><Data>201</Data><Item><Target><LocURI>calendar</LocURI></Target><Source><LocURI>calendar</LocURI></Source><Meta><Anchor 
>> xmlns="syncml:metinf"><Last>0</Last><Next>1114531397</Next></Anchor></Meta></Item></Alert><Final></Final></SyncBody></SyncML>
>> 18:03:16:296 [INFO] - The server alert code for calendar is 201
>> 18:03:16:296 [DEBUG] - url from response to inizialization-message:
>> 18:03:16:359 [INFO] - Synchronizing calendar
>> 18:03:16:359 [INFO] - Preparing slow sync for calendar
>> 18:03:16:359 [INFO] - Detected 0 items
>> 18:03:16:359 [DEBUG] - Preparing slow sync for calendar
>> 18:03:16:359 [DEBUG] - modification-message:
>> 18:03:16:359 [DEBUG] - <?xml version="1.0" 
>> encoding="UTF-8"?><SyncML><SyncHdr>
>> <VerDTD>1.1</VerDTD>
>> <VerProto>SyncML/1.1</VerProto>
>> <SessionID>1</SessionID>
>> <MsgID>2</MsgID>
>> <Target><LocURI>http://lancer.gloudemans.info</LocURI></Target>
>> <Source><LocURI>sc-pim-outlook</LocURI></Source>
>> </SyncHdr>
>> <SyncBody>
>> <Status>
>> <CmdID>1</CmdID>
>> <MsgRef>1</MsgRef>
>> <CmdRef>0</CmdRef>
>> <Cmd>SyncHdr</Cmd>
>> <TargetRef>http://lancer.gloudemans.info</TargetRef>
>> <SourceRef>sc-pim-outlook</SourceRef>
>> <Data>200</Data>
>> </Status>
>> <Status>
>> <CmdID>2</CmdID>
>> <MsgRef>1</MsgRef><CmdRef>1</CmdRef><Cmd>Alert</Cmd>
>> <TargetRef>calendar</TargetRef>
>> <SourceRef>calendar</SourceRef>
>> <Data>200</Data>
>> <Item>
>> <Data>
>> <Anchor xmlns='syncml:metinf'><Next>1114531396</Next></Anchor>
>> </Data>
>> </Item>
>> </Status>
>> <Sync><CmdID>3</CmdID>
>> <Target><LocURI>calendar</LocURI></Target>
>> <Source><LocURI>calendar</LocURI></Source>
>>
>> </Sync><Final/>
>> </SyncBody>
>> </SyncML>
>> 18:03:16:359 [INFO] - Sending modifications
>> 18:03:16:359 [DEBUG] - Connecting to lancer.gloudemans.info:80
>> 18:03:16:359 [DEBUG] - Requesting resource /horde/rpc.php
>> 18:03:16:843 [DEBUG] - Message sent
>> 18:03:16:875 [DEBUG] - Reading response...
>> 18:03:16:875 [DEBUG] - Content-length: 269
>> 18:03:16:875 [DEBUG] - Response read
>> 18:03:16:890 [DEBUG] - response to modification-message:
>> 18:03:16:890 [DEBUG] - <html>
>> <head><title>Horde :: Fatal Error</title></head>
>> <body style="background-color: white; color: black;"><h1>A fatal 
>> error has occurred</h1><h3>No password provided for LDAP 
>> authentication.</h3><h3>Details have been logged for the 
>> administrator.</h3></body>
>> </html>
>>
>>
>
>

More information about the sync mailing list