[sync] Authentication problems

Tue Apr 26 09:52:51 PDT 2005

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>