Navigation

    Kopano
    • Register
    • Login
    • Search
    • Categories
    • Get Official Kopano Support
    • Recent
    Statement regarding the closure of the Kopano community forum and the end of the community edition

    Timeout message when fetching mails - empty inbox

    Z-Push when using other backends
    3
    6
    429
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • elan
      elan last edited by

      Hi,
      I’m trying to use z-push for Android clients (Outlook App or the Gmail App). Currently, I disabled other backends except IMAP, to isolate the problem of sync->disappearance of data->sync cycle.
      I found this message in the log

      02/04/2020 00:17:14 [114165] [ INFO] [feuerstein] StatusException: SyncCollections->CheckForChanges(): Timeout forced after 174s from 470s due to other process - code: 3 - file: /appl/httpd/z-push/inst/lib/core/synccollections.php:579

      Is anyone familiar with this problem? Is the problem with my config or is it with the IMAP server? The only other message I found in the log that looked relevant was

      Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command

      I could send Email though.

      Thank you very much,
      Elan

      liverpoolfcfan 1 Reply Last reply Reply Quote 0
      • liverpoolfcfan
        liverpoolfcfan @elan last edited by

        @elan The timeout message just indicates that a second ping was started before the previous one ended. This can happen when individual folders are synced, and it should be expected once in a while. It should not be the norm though.

        Typically when clients drop everything and resync it is because one or more needed folder is not syncing.

        I am not familiar with the IMAP backend but, at a minimum, have you defined folders for Inbox, Outbox, Sent, and Trash. If any of them is missing this could be the problem.

        1 Reply Last reply Reply Quote 0
        • elan
          elan last edited by

          @liverpoolfcfan , Thank you for the reply. The timeout with long wait periods seems to be happening all the time. The call to FoldersSync does not seem to return.
          When I check with telnet, the IMAP seems to have INBOX/Sent, INBOX/Trash, INBOX/Drafts and INBOX. I configured these in the backend/imap/config.php.
          The config file also IMAP_FOLDER_SPAM and IMAP_FOLDER_ARCHIVE. These I configured to be INBOX/SPAM and INBOX/ARCHIVE, assuming that the IMAP Server will create them when required. Still the same problem. I commented out these lines, didn’t make a difference.
          Thanks for the input, I’ll look in this direction. I have z-push 2.5.1. Will also try with the latest update.

          1 Reply Last reply Reply Quote 0
          • Manfred
            Manfred Kopano last edited by

            Hi @elan,

            is the issue that no emails are synced and all email folders are empty? Was the folder structure synced correctly to your mobile?

            What exactly are Outlook App and Gmail App you’re referring to? Did you try to configure an ActiveSync account using the default email app using Settings->Accounts?

            It would help more if you would post the complete WBXML level log of a Sync request.

            Manfred

            1 Reply Last reply Reply Quote 0
            • elan
              elan last edited by

              Hi @Manfred ,
              Thanks for the reply. The newer version of Android (on a Samsung) seems to have removed the option of removed the option “Microsoft Exchange ActiveSync” under Settings->Account. Instead, the Gmail App offers to add an Exchange account. I used this one. The other options was to download the Outlook App from the Play store.
              For test, I found an older device, Samsung Galaxy Note 4 now. Made a fresh install of z-push 2.5.2 on my server and configured as before and added a “Microsoft Exchange ActiveSync” account via Settings->Accounts.
              When I open the default Email App, there are no Emails. The client seems to be synchronizing the INBOX. On the menu, I could click on “Show all folders” and the folder listing is right.
              Here is the log when I open the App and the App tries to sync.

              08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] -------- Start
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] cmd='FolderSync' devType='SAMSUNGSMNF' devId='sec1c00ccb91b75f' getUser='mail_test' from='192.168.213.3' version='GIT' method='POST'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] Used timezone 'Europe/Amsterdam'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] Request::ProcessHeaders() ASVersion: 14.0
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ZPush::CommandNeedsProvisioning(9): true
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->GetState() read '2946' bytes from file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-devicedata'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ASDevice data loaded for user: 'mail_test'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] InterProcessData:__construct type: 'sec1c00ccb91b75f'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] TopCollector(): Initialized mutexid Resource id #20 and memid Resource id #21.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] InterProcessData:__construct type: 'sec1c00ccb91b75f'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] LoopDetection(): Initialized mutexid Resource id #25 and memid Resource id #26.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ZPush::HierarchyCommand(9): true
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] DeviceManager->ProvisioningRequired('868885463') saved device key '868885463': false
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] DeviceManager->getPolicyName(): determined policy name: 'default'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ZPush::CommandNeedsAuthentication(9): true
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->Logon(): User 'mail_test' is authenticated on '{polaris.SERVER.com:143/imap/notls/norsh}'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ZPush::CommandNeedsPlainInput(9): false
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] I  <FolderHierarchy:FolderSync>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] I   <FolderHierarchy:SyncKey>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] I    {d072e011-9d05-4bca-9edd-1ef59e402111}1
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] I   </FolderHierarchy:SyncKey>
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] StateManager->loadHierarchyCache(): 'sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-hc-1'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->GetState() read '1345' bytes from file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-hc-1'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->GetState() read '603' bytes from file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-1'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->GetState() read '379' bytes from file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-fd'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] SyncParameters->UseCPO('DEFAULT')
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 7
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] I  </FolderHierarchy:FolderSync>
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ExportChangesDiff->InitializeExporter(): Initializing folder diff engine
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->GetState() read '1075' bytes from file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-bs-1586298301'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('Trash') = 09ee7691
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('Trash') = 09ee7691
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('Sent') = 514979a2
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('Sent') = 514979a2
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Test3.newfldintest3') = 890fc6ac
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Test3.newfldintest3') = 890fc6ac
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Gesendete Objekte') = 8727f8e2
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Gesendete Objekte') = 8727f8e2
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Gel&APY-schte Objekte') = 414da2d7
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Gel&APY-schte Objekte') = 414da2d7
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Entw&APw-rfe') = 3c3cfb64
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Entw&APw-rfe') = 3c3cfb64
08/04/2020 00:26:09 [19530] [ INFO] [mail_test] ExportChangesDiff->InitializeExporter(): Found '8' changes for 'hierarchy'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('68f4348a') = INBOX
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('68f4348a'): 'SyncFolder (
	(S) serverid => 68f4348a
	(S) parentid => 0
	(S) displayname => INBOX
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('68f4348a') = INBOX
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('68f4348a'): 'SyncFolder (
	(S) serverid => 68f4348a
	(S) parentid => 0
	(S) displayname => INBOX
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'INBOX' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('09ee7691') = Trash
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('09ee7691'): 'SyncFolder (
	(S) serverid => 09ee7691
	(S) parentid => 0
	(S) displayname => Trash
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('09ee7691') = Trash
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('09ee7691'): 'SyncFolder (
	(S) serverid => 09ee7691
	(S) parentid => 0
	(S) displayname => Trash
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Trash' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('514979a2') = Sent
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('514979a2'): 'SyncFolder (
	(S) serverid => 514979a2
	(S) parentid => 0
	(S) displayname => Sent
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('514979a2') = Sent
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('514979a2'): 'SyncFolder (
	(S) serverid => 514979a2
	(S) parentid => 0
	(S) displayname => Sent
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Sent' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('890fc6ac') = INBOX.Test3.newfldintest3
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('890fc6ac'): 'SyncFolder (
	(S) serverid => 890fc6ac
	(S) parentid => 0c6d560b
	(S) displayname => newfldintest3
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('890fc6ac') = INBOX.Test3.newfldintest3
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX.Test3') = 0c6d560b
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('890fc6ac'): 'SyncFolder (
	(S) serverid => 890fc6ac
	(S) parentid => 0c6d560b
	(S) displayname => newfldintest3
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] HierarchyCache: AddFolder() serverid: 890fc6ac displayname: newfldintest3
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('0c6d560b') = INBOX.Test3
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('0c6d560b'): 'SyncFolder (
	(S) serverid => 0c6d560b
	(S) parentid => 68f4348a
	(S) displayname => Test3
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('0c6d560b') = INBOX.Test3
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('0c6d560b'): 'SyncFolder (
	(S) serverid => 0c6d560b
	(S) parentid => 68f4348a
	(S) displayname => Test3
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Test3' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('8727f8e2') = INBOX.Gesendete Objekte
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('8727f8e2'): 'SyncFolder (
	(S) serverid => 8727f8e2
	(S) parentid => 68f4348a
	(S) displayname => Gesendete Objekte
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('8727f8e2') = INBOX.Gesendete Objekte
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('8727f8e2'): 'SyncFolder (
	(S) serverid => 8727f8e2
	(S) parentid => 68f4348a
	(S) displayname => Gesendete Objekte
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Gesendete Objekte' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('414da2d7') = INBOX.Gel&APY-schte Objekte
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('414da2d7'): 'SyncFolder (
	(S) serverid => 414da2d7
	(S) parentid => 68f4348a
	(S) displayname => Gelöschte Objekte
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('414da2d7') = INBOX.Gel&APY-schte Objekte
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('414da2d7'): 'SyncFolder (
	(S) serverid => 414da2d7
	(S) parentid => 68f4348a
	(S) displayname => Gelöschte Objekte
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Gelöschte Objekte' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('3c3cfb64') = INBOX.Entw&APw-rfe
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('3c3cfb64'): 'SyncFolder (
	(S) serverid => 3c3cfb64
	(S) parentid => 68f4348a
	(S) displayname => Entwürfe
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getImapIdFromFolderId('3c3cfb64') = INBOX.Entw&APw-rfe
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->getFolderIdFromImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->convertImapId('INBOX') = 68f4348a
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->GetFolder('3c3cfb64'): 'SyncFolder (
	(S) serverid => 3c3cfb64
	(S) parentid => 68f4348a
	(S) displayname => Entwürfe
	(S) type => 12
	(S) Store => null
	(S) NoBackendFolder => null
	(S) BackendId => null
	(S) Flags => null
	(S) TypeReal => null
	unsetVars(Array) size: 0
	supportsPrivateStripping => false
	flags => false
	content => null
)'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ChangesMemoryWrapper->ImportFolderChange(): Change for folder 'Entwürfe' will not be sent as modification is not relevant.
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O  <FolderHierarchy:FolderSync>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   <FolderHierarchy:Status>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   1
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   </FolderHierarchy:Status>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   <FolderHierarchy:SyncKey>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   {d072e011-9d05-4bca-9edd-1ef59e402111}2
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   </FolderHierarchy:SyncKey>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   <FolderHierarchy:Changes>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O    <FolderHierarchy:Count>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O    1
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O    </FolderHierarchy:Count>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O    <FolderHierarchy:Add>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     <FolderHierarchy:ServerEntryId>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     890fc6ac
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     </FolderHierarchy:ServerEntryId>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     <FolderHierarchy:ParentId>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     0c6d560b
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     </FolderHierarchy:ParentId>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     <FolderHierarchy:DisplayName>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     newfldintest3
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     </FolderHierarchy:DisplayName>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     <FolderHierarchy:Type>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     12
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O     </FolderHierarchy:Type>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O    </FolderHierarchy:Add>
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O   </FolderHierarchy:Changes>
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 8
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->SetState() written 1537 bytes on file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-hc-2'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->SetState() written 696 bytes on file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-2'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] SyncCollections::InvalidatePingableFlags(): Invalidating now
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->SetState() written 379 bytes on file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-d072e011-9d05-4bca-9edd-1ef59e402111-fd'
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] O  </FolderHierarchy:FolderSync>
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] WBXMLEncoder->endTag() WBXML output completed
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] WBXML-OUT: AwFqAAAHVkwDMQABUgN7ZDA3MmUwMTEtOWQwNS00YmNhLTllZGQtMWVmNTllNDAyMTExfTIAAU5XAzEAAU9IAzg5MGZjNmFjAAFJAzBjNmQ1NjBiAAFHA25ld2ZsZGludGVzdDMAAUoDMTIAAQEBAQ==
08/04/2020 00:26:09 [19530] [WBXML] [mail_test] WBXML-IN : AwFqAAAHVlIDe2QwNzJlMDExLTlkMDUtNGJjYS05ZWRkLTFlZjU5ZTQwMjExMX0xAAEB
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->close_connection(): IMAP said: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] BackendIMAP->close_connection(): disconnected from IMAP server
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->SetState() written 1075 bytes on file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-bs-1586298301'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] DeviceManager->Save(): Device data changed
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] FileStateMachine->SetState() written 2982 bytes on file: '/var/www/zpush.SERVER.com/state/f/5/sec1c00ccb91b75f-devicedata'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] DeviceManager->Save(): Device data saved
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] LoopDetection->ProcessLoopDetectionTerminate()
08/04/2020 00:26:09 [19530] [ INFO] [mail_test] cmd='FolderSync' memory='2.07 MiB/2.00 MiB' time='0.11s' devType='SAMSUNGSMNF' devId='sec1c00ccb91b75f' getUser='mail_test' from='192.168.213.3' idle='0s' version='GIT' method='POST' httpcode='200'
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] -------- End

              The error log does not produce new messages during this sync phase. The only entries are from the account creation phase, which is as follows.

              08/04/2020 00:25:00 [ 3979] [WARN] [mail_test] Unknown:0 Unknown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)
08/04/2020 00:25:00 [ 3993] [FATAL] [mail_test] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command
08/04/2020 00:25:11 [20279] [WARN] [mail_test] Unknown:0 Unknown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)

              I would be grateful for pointers as to what is going wrong.
              Thank you,
              Elan

              1 Reply Last reply Reply Quote 0
              • Manfred
                Manfred Kopano last edited by

                Hi @elan,

                @elan said in Timeout message when fetching mails - empty inbox:

                Hi @Manfred ,
                Thanks for the reply. The newer version of Android (on a Samsung) seems to have removed the option of removed the option “Microsoft Exchange ActiveSync” under Settings->Account. Instead, the Gmail App offers to add an Exchange account. I used this one. The other options was to download the Outlook App from the Play store.

                That’s strange. I have a Samsung device with Android 10 and there’s “Microsoft Exchange ActiveSync” type if I select “Add account”.

                For test, I found an older device, Samsung Galaxy Note 4 now. Made a fresh install of z-push 2.5.2 on my server and configured as before and added a “Microsoft Exchange ActiveSync” account via Settings->Accounts.
                When I open the default Email App, there are no Emails. The client seems to be synchronizing the INBOX. On the menu, I could click on “Show all folders” and the folder listing is right.
                Here is the log when I open the App and the App tries to sync.

                08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] -------- Start
08/04/2020 00:26:09 [19530] [DEBUG] [mail_test] cmd='FolderSync' devType='SAMSUNGSMNF' devId='sec1c00ccb91b75f' getUser='mail_test' from='192.168.213.3' version='GIT' method='POST'

                That’s a FolderSync request, not Sync and though not helpful.

                Manfred

                1 Reply Last reply Reply Quote 0
                • First post
                  Last post