search

Z-Hub / Z-Push

Home of Z-Push
https://z-push.org
GNU Affero General Public License v3.0
88 stars 43 forks source link

Error once an iOS created appointment is pushed to Z-Push #99

Open ray-magini opened 1 month ago

ray-magini commented 1 month ago

Describe the bug Once I create an appointment in the iOS calender app and it is synced to z-push, the below error is happening.

To Reproduce Steps to reproduce the behavior:

  1. Create an appointment in the iOS calender app in the Z-Push calendar.
  2. Check the z-push logs once it is synced to z-push

Server (please complete the following information):

Smartphone (please complete the following information):

Additional context Z-Push error logs 

11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] -------- Start
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] cmd='Sync' devType='iPhone' devId='kc28f3e3o53nhduj5rmqk1sge4' getUser='dirk' from='192.168.2.52' version='2.7.3
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Used timezone 'Europe/Berlin'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Including backend file: '//mnt/data/web/activesync/z-push/src/backend/imap/imap.php'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Including backend file: '//mnt/data/web/activesync/z-push/src/backend/caldav/caldav.php'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Including backend file: '//mnt/data/web/activesync/z-push/src/backend/carddav/carddav.php'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Combined 3 backends loaded.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SqlStateMachine(): init
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SqlStateMachine->checkDbAndTables(): Database and tables exist.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SqlStateMachine->GetStateVersion(): supporting version '2'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Request::ProcessHeaders() ASVersion: 16.1
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] ZPush::CommandNeedsProvisioning(0): true
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SqlStateMachine->GetState(): devid:'kc28f3e3o53nhduj5rmqk1sge4' type:'devicedata' key:'null' counter:'false'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] ASDevice data loaded for user: 'dirk'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] InterProcessData:__construct type: 'kc28f3e3o53nhduj5rmqk1sge4'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] TopCollector(): Initialized.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] InterProcessData:__construct type: 'kc28f3e3o53nhduj5rmqk1sge4'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] LoopDetection(): Initialized.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] ZPush::HierarchyCommand(0): false
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] DeviceManager->ProvisioningRequired('893268036') saved device key '893268036': false
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] DeviceManager->getPolicyName(): determined policy name: 'default'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] ZPush::CommandNeedsAuthentication(0): true
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Combined->Logon('dirk', '',***))
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] BackendIMAP->Logon(): User 'dirk' is authenticated on '{imap.example.de:993/imap/norsh/ssl/novalidate-cert}'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] BackendCalDAV->caldav_backend(): base_url '/calendars/dirk/'
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] CalDAVClient->DoRequest: 'OPTIONS' request on https://caldav.example.de:443/calendars/dirk/ using:
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] CalDAVClient->DoRequest: Response from https://caldav.example.de:443/calendars/dirk/:
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] BackendCalDAV->Logon(): User 'dirk' is authenticated on CalDAV 'https://caldav.example.de:443/calendars/dirk/'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] BackendCardDAV->Logon(): User 'dirk' is authenticated on 'https://carddav.example.de:443/addressbooks/dirk/'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] BackendCardDAV::discoverAddressbooks() Included addressbook 'https://carddav.example.de:443/addressbooks/dirk/private/'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] Combined->Logon() success
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] ZPush::CommandNeedsPlainInput(0): false
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I  <Synchronize>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I   <Folders>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I    <Folder>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <SyncKey>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      {b54fe9d9-a32d-4566-af92-9447812f3b40}15
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     </SyncKey>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <FolderId>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      c/Cprivate
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     </FolderId>
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SqlStateMachine->GetState(): devid:'kc28f3e3o53nhduj5rmqk1sge4' type:'fd' key:'b54fe9d9-a32d-4566-af92-9447812f3b40' counter:'false'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SyncParameters->UseCPO('DEFAULT')
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'c/Cprivate', returning as is.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SyncCollections->AddCollection(): Folder id 'c/Cprivate' : ref. PolicyKey '893268036', ref. Lifetime '', last sync at '1723365195'
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SyncCollections->AddCollection(): Updated reference PolicyKey '893268036', reference Lifetime '', Last sync at '1723365195'
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <GetChanges/>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <WindowSize>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      25
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     </WindowSize>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <Options>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      <AirSyncBase:BodyPreference>
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] SyncParameters->UseCPO('DEFAULT')
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       <AirSyncBase:Type>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        1
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       </AirSyncBase:Type>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       <AirSyncBase:TruncationSize>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        32768
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       </AirSyncBase:TruncationSize>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      </AirSyncBase:BodyPreference>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     </Options>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     <Perform>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      <Add>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       <ClientEntryId>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        51523
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       </ClientEntryId>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       <Data>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Timezone>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         xP///wAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAoAAAAFAAMAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMAAAAFAAIAAAAAAAAAxP///w==
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:Timezone>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:AllDayEvent>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         0
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:AllDayEvent>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:BusyStatus>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         2
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:BusyStatus>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:EndTime>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         20240811T100000Z
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:EndTime>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <AirSyncBase:Location/>
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Reminder/>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Sensitivity>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         0
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:Sensitivity>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Subject>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         Dbbdbd
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:Subject>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:StartTime>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         20240811T080000Z
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:StartTime>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:ClientUid>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         DC4CA654023E452BAE98DE0D2407A8A80.32
11/08/2024 10:33:16 [2416485] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
11/08/2024 10:33:16 [2416485] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:ClientUid>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:MeetingStatus>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I         0
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        </POOMCAL:MeetingStatus>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Attendees/>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I        <POOMCAL:Recurrence/>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I       </Data>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I      </Add>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I     </Perform>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I    </Folder>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I   </Folders>
11/08/2024 10:33:16 [2416485] [WBXML] [dirk] I  </Synchronize>
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
11/08/2024 10:33:16 [2416485] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDe2I1NGZlOWQ5LWEzMmQtNDU2Ni1hZjkyLTk0NDc4MTJmM2I0MH0xNQABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1MTUyMwABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgxMVQxMDAwMDBaAAEAESAABCRlAzAAAWYDRGJiZGJkAAFnAzIwMjQwODExVDA4MDAwMFoAAXwDREM0Q0E2NTQwMjNFNDUyQkFFOThERTBEMjQwN0E4QTgwLjMyAAFYAzAAAQcbAQEBAQEB
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDe2I1NGZlOWQ5LWEzMmQtNDU2Ni1hZjkyLTk0NDc4MTJmM2I0MH0xNQABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1MTUyMwABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgxMVQxMDAwMDBaAAEAESAABCRlAzAAAWYDRGJiZGJkAAFnAzIwMjQwODExVDA4MDAwMFoAAXwDREM0Q0E2NTQwMjNFNDUyQkFFOThERTBEMjQwN0E4QTgwLjMyAAFYAzAAAQcbAQEBAQEB
11/08/2024 10:33:16 [2416485] [ INFO] [dirk] User-agent: 'Apple-iPhone16C1/2107.93'
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
11/08/2024 10:33:16 [2416485] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] LoopDetection->ProcessLoopDetectionTerminate()
11/08/2024 10:33:16 [2416485] [ INFO] [dirk] cmd='Sync' memory='2.17 MiB/4.00 MiB' time='0.19s' devType='iPhone' devId='kc28f3e3o53nhduj5rmqk1sge4' getUser='dirk' from='192.168.2.52' idle='0s' version='2.7.3
11/08/2024 10:33:16 [2416485] [DEBUG] [dirk] -------- End
matidau commented 4 weeks ago

Thanks for logging this issue. Also thank you for using/testing the latest git.

It looks like we also have a WBXML problem causing a fatal error. Can you run this without the WBXML level logging?

ray-magini commented 3 weeks ago

Thanks for logging this issue. Also thank you for using/testing the latest git.

It looks like we also have a WBXML problem causing a fatal error. Can you run this without the WBXML level logging?

@matidau Thanks for looking into it!

Below you will find the log: 

20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135603] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 12:53:18 [4135603] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135603] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDezUwYzM2YzM3LTdhZWYtNDZkMy04MDk0LTQyZDllZjIxMTQxY30xMwABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1ODI4MQABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgyMlQxMjAwMDBaAAEAESAABCRlAzAAAWYDVGVzdDIAAWcDMjAyNDA4MjJUMTAwMDAwWgABfAM0MTRFODlEREJFRUI0N0YyOUVCODhFOTU3MjExQkU2QjAuMzIAAVgDMAABBxsBAQEBAQE=
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDezUwYzM2YzM3LTdhZWYtNDZkMy04MDk0LTQyZDllZjIxMTQxY30xMwABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1ODI4MQABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgyMlQxMjAwMDBaAAEAESAABCRlAzAAAWYDVGVzdDIAAWcDMjAyNDA4MjJUMTAwMDAwWgABfAM0MTRFODlEREJFRUI0N0YyOUVCODhFOTU3MjExQkU2QjAuMzIAAVgDMAABBxsBAQEBAQE=
20/08/2024 12:53:18 [4135603] [ INFO] [dirk] User-agent: 'Apple-iPhone16C1/2107.93'
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 12:53:18 [4135603] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 12:53:18 [4135603] [ INFO] [dirk] cmd='Sync' memory='2.17 MiB/4.00 MiB' time='0.22s' devType='iPhone' devId='kc28f3e3o53nhduj5rmqk1sge4' getUser='dirk' from='192.168.2.52' idle='0s' version='2.7.3
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:97 Undefined array key "AirSyncBase:Location" (2)
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/core/streamer.php:105 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135616] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 12:53:18 [4135616] [ERROR] [dirk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/mnt/data/web/activesync/z-push/src/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135616] [WARN] [dirk] /mnt/data/web/activesync/z-push/src/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on null (2)
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /mnt/data/web/activesync/z-push/src/lib/request/requestprocessor.php:117
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDezUwYzM2YzM3LTdhZWYtNDZkMy04MDk0LTQyZDllZjIxMTQxY30xMwABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1ODI4MQABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgyMlQxMjAwMDBaAAEAESAABCRlAzAAAWYDVGVzdDIAAWcDMjAyNDA4MjJUMTAwMDAwWgABfAM0MTRFODlEREJFRUI0N0YyOUVCODhFOTU3MjExQkU2QjAuMzIAAVgDMAABBxsBAQEBAQE=
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] WBXML 10K debug data: AwFqAEVcT0sDezUwYzM2YzM3LTdhZWYtNDZkMy04MDk0LTQyZDllZjIxMTQxY30xMwABUgNjL0Nwcml2YXRlAAETVQMyNQABVwARRUYDMQABRwMzMjc2OAABAQEAAFZHTAM1ODI4MQABXQAERQN4UC8vL3dBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBb0FBQUFGQUFNQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQUFBQU1BQUFBRkFBSUFBQUFBQUFBQXhQLy8vdz09AAFGAzAAAU0DMgABUgMyMDI0MDgyMlQxMjAwMDBaAAEAESAABCRlAzAAAWYDVGVzdDIAAWcDMjAyNDA4MjJUMTAwMDAwWgABfAM0MTRFODlEREJFRUI0N0YyOUVCODhFOTU3MjExQkU2QjAuMzIAAVgDMAABBxsBAQEBAQE=
20/08/2024 12:53:18 [4135616] [ INFO] [dirk] User-agent: 'Apple-iPhone16C1/2107.93'
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 12:53:18 [4135616] [FATAL] [dirk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 12:53:18 [4135616] [ INFO] [dirk] cmd='Sync' memory='2.17 MiB/4.00 MiB' time='0.23s' devType='iPhone' devId='kc28f3e3o53nhduj5rmqk1sge4' getUser='dirk' from='192.168.2.52' idle='0s' version='2.7.3
rpc-scandinavia commented 3 weeks ago

I was asked to post here in issue #100. My takeaway is this:

Device: Android User-agent: Android-Mail/2024.07.28.660409857.Release Data type: Calendar [I guess it is from Facebook because of fb://event/26236185719330506, otherwise it is from Outlook] WBXML error: could not read end tag in tag AirSyncBase:DisplayName

20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         <AirSyncBase:DisplayName>
20/08/2024 10:55:25 [4067346] [ERROR] [x@x.dk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/usr/local/lib/z-push/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I          Havneplads 1, 8500 Grenaa, Denmark
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         </AirSyncBase:DisplayName>

And at the end Trying to access array offset on value of type null:

20/08/2024 10:55:25 [4067346] [WARN] [x@x.dk] /usr/local/lib/z-push/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on value of type null (2)
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /usr/local/lib/z-push/lib/request/requestprocessor.php:117

z-push-error.log:

20/08/2024 10:55:25 [4067346] [ERROR] [x@x.dk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/usr/local/lib/z-push/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 10:55:25 [4067346] [WARN] [x@x.dk] /usr/local/lib/z-push/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on value of type null (2)
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /usr/local/lib/z-push/lib/request/requestprocessor.php:117
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] WBXML 10K debug data: AwFqAE..... removed .....EBAQEB
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 10:55:25 [4067346] [WARN] [x@x.dk] Unknown:0 PHP Request Shutdown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)

z-push.log:

20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] -------- Start
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] cmd='Sync' devType='Android' devId='androidc1694273380' getUser='x@x.dk' from='10.10.1.23' version='2.7.3
' method='POST'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Used timezone 'Europe/Copenhagen'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Including backend file: '/usr/local/lib/z-push/backend/imap/imap.php'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Including backend file: '/usr/local/lib/z-push/backend/caldav/caldav.php'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Including backend file: '/usr/local/lib/z-push/backend/carddav/carddav.php'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Combined 3 backends loaded.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SqlStateMachine(): init
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SqlStateMachine->checkDbAndTables(): Database and tables exist.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SqlStateMachine->GetStateVersion(): supporting version '2'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Request::ProcessHeaders() ASVersion: 16.0
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] ZPush::CommandNeedsProvisioning(0): true
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SqlStateMachine->GetState(): devid:'androidc1694273380' type:'devicedata' key:'null' counter:'false'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] ASDevice data loaded for user: 'x@x.dk'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] InterProcessData:__construct type: 'androidc1694273380'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] TopCollector(): Initialized.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] InterProcessData:__construct type: 'androidc1694273380'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] LoopDetection(): Initialized.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] ZPush::HierarchyCommand(0): false
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] DeviceManager->ProvisioningRequired('148799020') saved device key '148799020': false
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] DeviceManager->getPolicyName(): determined policy name: 'default'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] ZPush::CommandNeedsAuthentication(0): true
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Combined->Logon('x@x.dk', '',***))
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendIMAP->Logon(): User 'x@x.dk' is authenticated on '{[fd00:1::23]:143/imap/notls/norsh}'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCalDAV->caldav_backend(): base_url '/x@x.dk/'
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] CalDAVClient->DoRequest: 'OPTIONS' request on http://cal.post.itdd.dk:80/x@x.dk/ using:

20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] CalDAVClient->DoRequest: Response from http://cal.post.itdd.dk:80/x@x.dk/:
HTTP/1.1 200 OK
Date: Tue, 20 Aug 2024 08:55:25 GMT
Server: WSGIServer/0.2 CPython/3.11.2
Allow: DELETE, GET, HEAD, MKCALENDAR, MKCOL, MOVE, OPTIONS, POST, PROPFIND, PROPPATCH, PUT, REPORT
DAV: 1, 2, 3, calendar-access, addressbook, extended-mkcol
access-control-allow-origin: *
Content-Length: 0

20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCalDAV->Logon(): User 'x@x.dk' is authenticated on CalDAV 'http://cal.post.itdd.dk:80/x@x.dk/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV->Logon(): User 'x@x.dk' is authenticated on 'http://addr.post.itdd.dk:80/x@x.dk/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::getAddressbookIsIncluded() Include filter '*/addresses/' matches 'http://addr.post.itdd.dk:80/revan%40revan.dk/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::discoverAddressbooks() Included addressbook 'http://addr.post.itdd.dk:80/x@x.dk/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/x@x.dk/addresses-collected/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/x@x.dk/addresses-trusted/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/x@x.dk/addresses-archived/'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] Combined->Logon() success
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] ZPush::CommandNeedsPlainInput(0): false
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I  <Synchronize>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I   <Folders>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I    <Folder>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <SyncKey>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      {52a7cc06-e060-4131-a595-73a280d060d1}1
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     </SyncKey>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <FolderId>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      c/Ccalendar
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     </FolderId>
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SqlStateMachine->GetState(): devid:'androidc1694273380' type:'fd' key:'52a7cc06-e060-4131-a595-73a280d060d1' counter:'false'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SyncParameters->UseCPO('DEFAULT')
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'c/Ccalendar', returning as is.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SyncCollections->AddCollection(): Folder id 'c/Ccalendar' : ref. PolicyKey '148799020', ref. Lifetime '1680', last sync at '1720260440'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SyncCollections->AddCollection(): Updated reference PolicyKey '148799020', reference Lifetime '1680', Last sync at '1720260440'
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <DeletesAsMoves/>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <GetChanges/>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <WindowSize>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      10
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     </WindowSize>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <Options>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      <FilterType>
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] SyncParameters->UseCPO('DEFAULT')
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       4
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      </FilterType>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      <AirSyncBase:BodyPreference>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       <AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        1
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       </AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       <AirSyncBase:TruncationSize>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        200000
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       </AirSyncBase:TruncationSize>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      </AirSyncBase:BodyPreference>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     </Options>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     <Perform>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      <Add>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       <ClientEntryId>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        4fc54a51-6603-4055-927e-e76fe76fbfd5
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       </ClientEntryId>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       <Data>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:Timezone>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         xP///wAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAoAAAAEAAMAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMAAAAFAAIAAAAAAAAAxP///w==
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:Timezone>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:AllDayEvent>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:AllDayEvent>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:StartTime>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         20240816T170000Z
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:StartTime>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:EndTime>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         20240816T180000Z
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:EndTime>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <AirSyncBase:Location>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         <AirSyncBase:DisplayName>
20/08/2024 10:55:25 [4067346] [ERROR] [x@x.dk] WBXMLDecoder->getElementEndTag(): could not read end tag in '/usr/local/lib/z-push/lib/request/sync.php:539'. Please enable the LOGLEVEL_WBXML and send the log to the Z-Push dev team.
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I          Havneplads 1, 8500 Grenaa, Denmark
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         </AirSyncBase:DisplayName>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </AirSyncBase:Location>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:Subject>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         ..... removed .....
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:Subject>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <AirSyncBase:Body>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         <AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I          1
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         </AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         <AirSyncBase:Data>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I          Begivenhed: fb://event/26236185719330506
..... removed .....
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         </AirSyncBase:Data>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </AirSyncBase:Body>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:Reminder>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         30
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:Reminder>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:Attendees/>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:BusyStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         2
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:BusyStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:MeetingStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:MeetingStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        <POOMCAL:Sensitivity>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I        </POOMCAL:Sensitivity>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I       </Data>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I      </Add>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I     </Perform>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I    </Folder>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I   </Folders>
20/08/2024 10:55:25 [4067346] [WBXML] [x@x.dk] I  </Synchronize>
20/08/2024 10:55:25 [4067346] [WARN] [x@x.dk] /usr/local/lib/z-push/lib/wbxml/wbxmldecoder.php:121 Trying to access array offset on value of type null (2)
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] WBXMLException: Unknown error in Sync->Handle() - code: 0 - file: /usr/local/lib/z-push/lib/request/requestprocessor.php:117
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] WBXML 10K debug data: AwFqAEVcT0..... removed .....ABAQEBAQEB
20/08/2024 10:55:25 [4067346] [ INFO] [x@x.dk] User-agent: 'Android-Mail/2024.07.28.660409857.Release'
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 10:55:25 [4067346] [FATAL] [x@x.dk] Request could not be processed correctly due to a WBXMLException. Please report this including the 'WBXML debug data' logged. Be aware that the debug data could contain confidential information.
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] LoopDetection->ProcessLoopDetectionTerminate()
20/08/2024 10:55:25 [4067346] [ INFO] [x@x.dk] cmd='Sync' memory='1.91 MiB/4.00 MiB' time='0.52s' devType='Android' devId='androidc1694273380' getUser='x@x.dk' from='10.10.1.23' idle='0s' version='2.7.3
' method='POST' httpcode='500'
20/08/2024 10:55:25 [4067346] [DEBUG] [x@x.dk] -------- End
20/08/2024 10:55:25 [4067346] [WARN] [x@x.dk] Unknown:0 PHP Request Shutdown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)