Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
ray-magini opened this issue Aug 11, 2024 · 3 comments
Open

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

ray-magini opened this issue Aug 11, 2024 · 3 comments

Comments

@ray-magini
Copy link
Contributor

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):

  • OS: Debian 12.6 (latest Updates)
  • Client: iPhone iOS 17.6.1 (latest)
  • PHP Version: 8.3.10
  • Z-Push: Latest GIT

Smartphone (please complete the following information):

  • Device: iPhone
  • OS: iOS 17.6.1 (latest)
  • Mail App: Apple Mail/Calendar

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
Copy link
Collaborator

matidau commented Aug 16, 2024

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 matidau mentioned this issue Aug 20, 2024
Merged
@ray-magini
Copy link
Contributor Author

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
Copy link
Contributor

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

20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] CalDAVClient->DoRequest: Response from http://cal.post.itdd.dk:80/[email protected]/:
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] [[email protected]] BackendCalDAV->Logon(): User '[email protected]' is authenticated on CalDAV 'http://cal.post.itdd.dk:80/[email protected]/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV->Logon(): User '[email protected]' is authenticated on 'http://addr.post.itdd.dk:80/[email protected]/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::getAddressbookIsIncluded() Include filter '*/addresses/' matches 'http://addr.post.itdd.dk:80/revan%40revan.dk/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::discoverAddressbooks() Included addressbook 'http://addr.post.itdd.dk:80/[email protected]/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/[email protected]/addresses-collected/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/[email protected]/addresses-trusted/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::getAddressbookIsIncluded() Include filter is a string '*/addresses/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] BackendCardDAV::discoverAddressbooks() Excluded addressbook 'http://addr.post.itdd.dk:80/[email protected]/addresses-archived/'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] Combined->Logon() success
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] ZPush::CommandNeedsPlainInput(0): false
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I  <Synchronize>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I   <Folders>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I    <Folder>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <SyncKey>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      {52a7cc06-e060-4131-a595-73a280d060d1}1
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     </SyncKey>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <FolderId>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      c/Ccalendar
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     </FolderId>
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] SqlStateMachine->GetState(): devid:'androidc1694273380' type:'fd' key:'52a7cc06-e060-4131-a595-73a280d060d1' counter:'false'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] SyncParameters->UseCPO('DEFAULT')
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'c/Ccalendar', returning as is.
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] SyncCollections->AddCollection(): Folder id 'c/Ccalendar' : ref. PolicyKey '148799020', ref. Lifetime '1680', last sync at '1720260440'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] SyncCollections->AddCollection(): Updated reference PolicyKey '148799020', reference Lifetime '1680', Last sync at '1720260440'
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <DeletesAsMoves/>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <GetChanges/>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <WindowSize>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      10
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     </WindowSize>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <Options>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      <FilterType>
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] SyncParameters->UseCPO('DEFAULT')
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       4
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      </FilterType>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      <AirSyncBase:BodyPreference>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       <AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        1
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       </AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       <AirSyncBase:TruncationSize>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        200000
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       </AirSyncBase:TruncationSize>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      </AirSyncBase:BodyPreference>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     </Options>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     <Perform>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      <Add>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       <ClientEntryId>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        4fc54a51-6603-4055-927e-e76fe76fbfd5
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       </ClientEntryId>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       <Data>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:Timezone>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         xP///wAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAoAAAAEAAMAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMAAAAFAAIAAAAAAAAAxP///w==
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:Timezone>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:AllDayEvent>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:AllDayEvent>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:StartTime>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         20240816T170000Z
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:StartTime>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:EndTime>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         20240816T180000Z
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:EndTime>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <AirSyncBase:Location>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         <AirSyncBase:DisplayName>
20/08/2024 10:55:25 [4067346] [ERROR] [[email protected]] 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] [[email protected]] I          Havneplads 1, 8500 Grenaa, Denmark
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         </AirSyncBase:DisplayName>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </AirSyncBase:Location>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:Subject>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         ..... removed .....
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:Subject>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <AirSyncBase:Body>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         <AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I          1
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         </AirSyncBase:Type>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         <AirSyncBase:Data>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I          Begivenhed: fb://event/26236185719330506
..... removed .....
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         </AirSyncBase:Data>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </AirSyncBase:Body>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:Reminder>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         30
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:Reminder>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:Attendees/>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:BusyStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         2
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:BusyStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:MeetingStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:MeetingStatus>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        <POOMCAL:Sensitivity>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I         0
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I        </POOMCAL:Sensitivity>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I       </Data>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I      </Add>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I     </Perform>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I    </Folder>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I   </Folders>
20/08/2024 10:55:25 [4067346] [WBXML] [[email protected]] I  </Synchronize>
20/08/2024 10:55:25 [4067346] [WARN] [[email protected]] /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] [[email protected]] 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] [[email protected]] WBXML 10K debug data: AwFqAEVcT0..... removed .....ABAQEBAQEB
20/08/2024 10:55:25 [4067346] [ INFO] [[email protected]] User-agent: 'Android-Mail/2024.07.28.660409857.Release'
20/08/2024 10:55:25 [4067346] [FATAL] [[email protected]] Exception: (WBXMLException) - Unknown error in Sync->Handle()
20/08/2024 10:55:25 [4067346] [FATAL] [[email protected]] 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] [[email protected]] LoopDetection->ProcessLoopDetectionTerminate()
20/08/2024 10:55:25 [4067346] [ INFO] [[email protected]] cmd='Sync' memory='1.91 MiB/4.00 MiB' time='0.52s' devType='Android' devId='androidc1694273380' getUser='[email protected]' from='10.10.1.23' idle='0s' version='2.7.3
' method='POST' httpcode='500'
20/08/2024 10:55:25 [4067346] [DEBUG] [[email protected]] -------- End
20/08/2024 10:55:25 [4067346] [WARN] [[email protected]] Unknown:0 PHP Request Shutdown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)

@ray-magini ray-magini changed the title Error once and iOS created appointment is pushed to Z-Push Error once an iOS created appointment is pushed to Z-Push Aug 20, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@rpc-scandinavia @ray-magini @matidau