Hello all,
after Ralf put me on the right track as regards an error in the vhost
configuration for my EGW install, I was able to get Thunderbird and
Lightning to sync against EGW. So, one problem down, one left to resolve.
The current problem is with synchronising contacts and calendar items
from EGW to Outlook via the Funambol plugins. I’ve tried both version
7.0.7 and the most recent version 8.0.4, with the same result each time.
My EGW config in a nutshell is to store accounts in LDAP, and to store
contacts in SQL. I have xmlrpc and soap enabled.
Doing a sync of contacts from an Outlook 2003 client running on XP Pro
SP3 with Funambol 8.0.4 installed gives me this in
/var/log/httpd/access_log on the EGW server:
192.168.118.88 - - [21/Aug/2009:14:45:51 +0200] “POST
/egroupware/rpc.php HTTP/1.1” 200 408 “-” “Funambol Outlook Sync Client
v. 8.0.4”
That request also generates a lot of output in /var/log/httpd/error_log:
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML[syncml-7b632e902ff1879253d49af3af08f56a]: starting new session
for michael [on line 169 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML[syncml-7b632e902ff1879253d49af3af08f56a]: create new session
state variable [on line 175 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML[syncml-7b632e902ff1879253d49af3af08f56a]: package 1
+++++++++++++++++++++ started [on line 219 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML: Authentication not yet possible currently. Password not
available [on line 258 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/State_egw.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML_EGW: Authentication of
michael@default/syncml-7b632e902ff1879253d49af3af08f56a succeded [on
line 272 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/State_egw.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML[syncml-7b632e902ff1879253d49af3af08f56a]: found action commands
1 [on line 500 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML: create new sync for card 204 [on line 333 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/Command/Alert.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] EGWSYNC: []
SyncML: new sync for alerttype 204 [on line 41 of
"/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/Sync.php"]
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] Database
error: Invalid SQL: SELECT sync_serverts,sync_clientts FROM
egw_syncmlsummary WHERE
dev_id=‘michael@defaultfol-V1NfREFWSUQ6ZGF2aWQ=’ AND
sync_path=‘card’:\nTable ‘egroupware.egw_syncmlsummary’ doesn’t exist
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #0
/usr/share/egroupware/phpgwapi/inc/class.egw_db.inc.php(684):
egw_db->halt(‘Invalid SQL: SE…’, 235, ‘/usr/share/egro…’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #1
/usr/share/egroupware/phpgwapi/inc/class.egw_db.inc.php(1913):
egw_db->query(‘SELECT sync_ser…’, 235, ‘/usr/share/egro…’, false,
-1, false, 2)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #2
/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/State_egw.php(235):
egw_db->select(‘egw_syncmlsumma…’, Array, Array, 235,
’/usr/share/egro…’, false, ‘’, ‘syncml’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #3
/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML/Command/Alert.php(90):
EGW_SyncML_State->getSyncSummary(‘card’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #4
/usr/share/egroupware/phpgwapi/inc/horde/Horde/SyncML.php(655):
Horde_SyncML_Command_Alert->output(2, Object(XML_WBXML_ContentHandler))
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #5
/usr/share/egroupware/phpgwapi/inc/horde/Horde/RPC/syncml.php(248):
Horde_SyncML_SyncMLBody->endElement(’’, ‘Alert’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #6
/usr/share/egroupware/phpgwapi/inc/horde/Horde/RPC/syncml.php(167):
Horde_RPC_syncml->endElement(’’, ‘Alert’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #7 [internal
function]: Horde_RPC_syncml->_endElement(Resource id #80, ‘Alert’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #8
/usr/share/egroupware/phpgwapi/inc/horde/Horde/RPC/syncml.php(142):
xml_parse(Resource id #80, ‘<?xml version="…’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #9
/usr/share/egroupware/phpgwapi/inc/horde/Horde/RPC/syncml.php(94):
Horde_RPC_syncml->_parse(’<?xml version="…’)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #10
/usr/share/egroupware/rpc.php(119): Horde_RPC_syncml->getResponse(’<?xml
version="…’, NULL)
[Fri Aug 21 14:45:51 2009] [error] [client 192.168.118.88] #11 {main}
And here is what the Funambol client logs to its own logfile:
2009-08-21 14:46:42 GMT +2:00 - # Funambol Outlook Sync Client v. 8.0.4
14:46:42 GMT +2:00 [DEBUG] - Starting the Sync process…
14:46:42 GMT +2:00 [DEBUG] - Set a lower priority to the process
14:46:42 GMT +2:00 [DEBUG] - Set listeners
14:46:42 GMT +2:00 [DEBUG] - Creating SyncSources…
14:46:42 GMT +2:00 [DEBUG] - Creating the sync-mutex
(“fol-SyncInProgress-1250858802”)
14:46:42 GMT +2:00 [DEBUG] - Start SyncClient::Sync() with 1 sources
14:46:42 GMT +2:00 [INFO] -
************************** BEGIN of Synchronization session
14:46:42 GMT +2:00 [DEBUG] - Synchronization URL:
http://192.168.118.15/egroupware/rpc.php
14:46:42 GMT +2:00 [INFO] - Preparing synchronization of contact…
14:46:42 GMT +2:00 [DEBUG] - Checking devinfo…
14:46:42 GMT +2:00 [DEBUG] - devinfo hash: TSaRayXSQspu6MLR+pxVaQ==
14:46:42 GMT +2:00 [DEBUG] - devinfo changed, retransmit
14:46:42 GMT +2:00 [DEBUG] - Server capabilities are invalid (Server URL
changed)
14:46:42 GMT +2:00 [DEBUG] - Initialization message:
14:46:42 GMT +2:00 [DEBUG] - User Agent = Funambol Outlook Sync Client
v. 8.0.4
14:46:42 GMT +2:00 [DEBUG] - Initialization sent.
14:46:42 GMT +2:00 [DEBUG] - <?xml version="1.0" encoding="UTF-8"?>
1.2
SyncML/1.2
1250858802
1
http://192.168.118.15/egroupware/rpc.php
fol-V1NfREFWSUQ6ZGF2aWQ=
b64
syncml:auth-basic
bWljaGFlbDptaWNoYWVs
250000
1
204
card
contact
0
1250858802
2
application/vnd.syncml-devinf+xml
./devinf12
3
application/vnd.syncml-devinf+xml
./devinf12
1.2
Funambol
Funambol Outlook Sync Client
8.0.4
fol-V1NfREFWSUQ6ZGF2aWQ=
workstation
appointment
text/x-vcalendar
1.0
text/x-s4j-sife
1.0
text/x-vcalendar
1.0
text/x-vcalendar
1.0
text/x-s4j-sife
1.0
text/x-vcalendar
1.0
2
1
5
3
6
4
contact
text/x-vcard
2.1
text/x-s4j-sifc
1.0
text/x-vcard
2.1
text/x-vcard
2.1
text/x-s4j-sifc
1.0
text/x-vcard
2.1
2
1
5
3
6
4
note
text/x-s4j-sifn
1.0
text/x-s4j-sifn
1.0
text/x-vnote
1.1
text/x-s4j-sifn
1.0
text/x-s4j-sifn
1.0
text/x-vnote
1.1
2
1
5
3
6
4
task
text/x-s4j-sift
1.0
text/x-s4j-sift
1.0
text/x-vcalendar
1.0
text/x-s4j-sift
1.0
text/x-s4j-sift
1.0
text/x-vcalendar
1.0
2
1
5
3
6
4
14:46:42 GMT +2:00 [DEBUG] - Connecting to 192.168.118.15:80
14:46:42 GMT +2:00 [DEBUG] - Requesting resource /egroupware/rpc.php
14:46:42 GMT +2:00 [DEBUG] - Sending data of size 3834…
14:46:43 GMT +2:00 [DEBUG] - Message sent
14:46:43 GMT +2:00 [DEBUG] - Finished sending data of size 3834.
14:46:43 GMT +2:00 [DEBUG] - Data sent successfully to server. Server
responds OK
14:46:43 GMT +2:00 [DEBUG] - Header:
14:46:43 GMT +2:00 [DEBUG] - Reading response…
14:46:43 GMT +2:00 [DEBUG] - Content-length: 408
14:46:43 GMT +2:00 [DEBUG] - Receiving data of size 408…
14:46:43 GMT +2:00 [DEBUG] - Finished receiving data of size 408.
14:46:43 GMT +2:00 [DEBUG] - Response read:
Database error
Database error
Invalid SQL: SELECT sync_serverts,sync_clientts FROM
egw_syncmlsummary WHERE
dev_id='michael@defaultfol-V1NfREFWSUQ6ZGF2aWQ=' AND sync_path='card':
Table 'egroupware.egw_syncmlsummary' doesn't exist
Click here to resume your eGroupWare
Session.
14:46:43 GMT +2:00 [ERROR] - Error processing SyncHdr Status
14:46:43 GMT +2:00 [DEBUG] - Error occurred in sync: code 3 = Error
reading status code of command ‘SyncHdr’
14:46:43 GMT +2:00 [ERROR] - Error in preparing sync: Error reading
status code of command ‘SyncHdr’
14:46:43 GMT +2:00 [INFO] -
============================================================
================ SYNCHRONIZATION REPORT ================
============================================================
SYNCHRONIZATION COMPLETED WITH ERRORS
Last error message = “Error reading status code of command ‘SyncHdr’”
Last error code = 700
Contacts:
Not synced.
14:46:43 GMT +2:00 [DEBUG] - Saving configuration to winRegistry
14:46:43 GMT +2:00 [DEBUG] - Writing configuration settings to the
management tree
14:46:43 GMT +2:00 [DEBUG] - Releasing sync-mutex…
14:46:43 GMT +2:00 [DEBUG] - Sync-mutex released - closing handle.
14:46:43 GMT +2:00 [DEBUG] - Delete SyncSources…
14:46:43 GMT +2:00 [INFO] - Syncronization process completed with errors
(code = 700).
I’ve used phpmyadmin to take a look at the EGW database tables, and the
table the logs are complaining about (egw_syncmlsummary) does not exist.
Is this a bug in the code, or am I doing something wrong? I’ve followed
the wiki procedure as regards Funambol. Any help would be much appreciated.
Regards,
Michael
–
Michael Liermann
Linux Engineer
4th Dimension Technology | South Africa
Office: +27 21 506 6260 | Cell: +27 72 214 6058 | Fax: +27 86 610 5792 | www.4dt.co.za
