04/06/2012 17:36:15 [ 921] [user] [DEBUG] -------- Start
04/06/2012 17:36:15 [ 921] [user] [ INFO] Version='2.0beta5-1261' method='POST' from='95.19.91.179' cmd='Sync' getUser='user' devId='Appl790312PRA4S' devType='iPhone'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Used timezone 'Europe/Berlin'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Including backend file: 'z-push/backend/combined/combined.php'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Including backend file: 'z-push/backend/imap.php'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Including backend file: 'z-push/backend/caldav.php'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Including backend file: 'z-push/backend/ldap.php'
04/06/2012 17:36:15 [ 921] [user] [ INFO] Combined 3 backends loaded.
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Request::ProcessHeaders() ASVersion: 2.5
04/06/2012 17:36:15 [ 921] [user] [DEBUG] ZPush::CommandNeedsProvisioning(0): true
04/06/2012 17:36:15 [ 921] [user] [DEBUG] FileStateMachine->GetState() on file: '/var/lib/z-push/s/4/Appl790312PRA4S-devicedata'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] ASDevice data loaded for user: 'user'
04/06/2012 17:36:15 [ 921] [user] [DEBUG] TopCollector(): Initialized mutexid Resource id #121 and memid Resource id #122.
04/06/2012 17:36:15 [ 921] [user] [DEBUG] LoopDetection(): Initialized mutexid Resource id #124 and memid Resource id #125.
04/06/2012 17:36:15 [ 921] [user] [DEBUG] ZPush::HierarchyCommand(0): false
04/06/2012 17:36:15 [ 921] [user] [DEBUG] DeviceManager->ProvisioningRequired('710056429') saved device key '710056429': false
04/06/2012 17:36:15 [ 921] [user] [DEBUG] ZPush::CommandNeedsAuthentication(0): true
04/06/2012 17:36:15 [ 921] [user] [DEBUG] Combined->Logon('user', '',***))
04/06/2012 17:36:18 [ 921] [user] [ INFO] BackendIMAP->Logon(): User 'user' is authenticated on IMAP
04/06/2012 17:36:20 [ 921] [user] [ INFO] BackendCalDAV->Logon(): User 'user' is authenticated on CalDAV
04/06/2012 17:36:20 [ 921] [user] [ INFO] BackendLDAP->Logon(): User 'user' is authenticated on LDAP
04/06/2012 17:36:20 [ 921] [user] [ INFO] Combined->Logon() success
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->Setup('user', 'true', '')
04/06/2012 17:36:20 [ 921] [user] [ INFO] Combined->Setup() success
04/06/2012 17:36:20 [ 921] [user] [DEBUG] ZPush::CommandNeedsPlainInput(0): false
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Sync folder: 'Contacts'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->GetState() on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-fd'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] SyncParameters->UseCPO('DEFAULT')
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->GetState() on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-69'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->GetState() on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-fs-69'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] ZPush::GetAdditionalSyncFolderStore('l/Private Contacts'): 'false'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->Setup('', 'false', '')
04/06/2012 17:36:20 [ 921] [user] [ INFO] Combined->Setup() success
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->GetImporter() Content: ImportChangesCombined:('l/Private Contacts')
04/06/2012 17:36:20 [ 921] [user] [DEBUG] ImportChangesCombined->Config(...)
04/06/2012 17:36:20 [ 921] [user] [DEBUG] ImportChangesCombined->Config() success
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Supported variables to be unset: anniversary,birthday,businesscountry,email2address,email3address,businessfaxnumber,homecity,homecountry,homefaxnumber,home2phonenumber,homepostalcode,homestate,homestreet,middlename,suffix,othercity,othercountry,carphonenumber,otherpostalcode,otherstate,otherstreet,assistantname,assistnamephonenumber,spouse,business2phonenumber,jobtitle,yomifirstname,yomilastname,radiophonenumber,imaddress,imaddress2,imaddress3,managername,companymainphone,nickname
04/06/2012 17:36:20 [ 921] [user] [ WARN] PHP-Push-2/lib/default/diffbackend/diffstate.php:257 Invalid argument supplied for foreach() (2)
04/06/2012 17:36:20 [ 921] [user] [ INFO] StatusException: ImportChangesDiff->ImportMessageChange('1586d8b8-1f3c-1031-9f73-e1f285e81745','SyncContact'): unknown error in backend - code: 9
04/06/2012 17:36:20 [ 921] [user] [ INFO] Processed '1' incoming changes
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->SetState() written 6803 bytes on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-fs-69'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] HandleSync(): Start Output
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->GetExporter('l/Private Contacts')
04/06/2012 17:36:20 [ 921] [user] [DEBUG] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '56' messages in state
04/06/2012 17:36:20 [ 921] [user] [DEBUG] BackendLDAP->GetMessageList('Private Contacts','0')
04/06/2012 17:36:20 [ 921] [user] [DEBUG] BackendLDAP->GetMessageList(): Got 56 contacts in base_dn 'cn=user,ou=private,ou=rcabook,dc=qustodium,dc=net'.
04/06/2012 17:36:20 [ 921] [user] [ INFO] ExportChangesDiff->InitializeExporter(): Found '1' changes
04/06/2012 17:36:20 [ 921] [user] [DEBUG] BackendLDAP->GetMessage('Private Contacts','1586d8b8-1f3c-1031-9f73-e1f285e81745')
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->SetState() written 6549 bytes on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-70'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] SyncCollections->SaveCollection(): Data of folder 'l/Private Contacts' changed
04/06/2012 17:36:20 [ 921] [user] [DEBUG] FileStateMachine->SetState() written 676 bytes on file: '/var/lib/z-push/s/4/Appl790312PRA4S-e5782d20-6c6d-421e-b486-86550456240b-fd'
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->Logoff()
04/06/2012 17:36:20 [ 921] [user] [DEBUG] BackendIMAP->Logoff(): IMAP connection closed
04/06/2012 17:36:20 [ 921] [user] [ INFO] BackendLDAP->Logoff(): Disconnection successfull.
04/06/2012 17:36:20 [ 921] [user] [DEBUG] Combined->Logoff() success
04/06/2012 17:36:20 [ 921] [user] [DEBUG] -------- End