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

    Problems with z-push, Zarafa and Android 6

    Z-Push when using Kopano
    3
    9
    2321
    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.
    • itserv
      itserv last edited by

      Setup:
      Host 1: Zarafa 7.2.4 on Debian 7
      Host 2: Apache Websver 2.4 running z-push 2.3.6 with z-push-backend-kopano

      I’m trying to make it work for the first time.

      When I set up my Sony Xperia Z3 with Android 6.0.1, I can go through the Mobile setup procedure. After (sucessfully) logging in using Exchange ActiveSync, I have to answer multiple question, for example I have to allow remove wiping, disableing the camera and so on. I also see in the Debug log reading my mailbox folders (my mailbox is huge!).

      After some time of syncing, my mobile says “Syncronisation: The account could not be created. Try again later” (Das Konto konnte nicht erstellt werden. Versuchen Sie es später erneut)

      What can I do?

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

        Hi itserv,

        I moved the topic because Zarafa and Kopano are the same backend.

        How long does the FolderSync request take (you can see that information on INFO log level)? Android devices have a hard-coded timeout of 30 seconds and if the request takes longer than that, they will start over.

        How big is your mailbox? Are you syncing everything or do you limit the data to 1 week or 1 month etc?

        Are there any errors in Z-Push and / or apache logs?

        Manfred

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

          The FolderSync Request, if I get you right, takes log lines like these:

          26/05/2017 15:39:26 [ 7635] [DEBUG] [pbauer] HierarchyCache: AddFolder() serverid: Udaf36 displayname: RVI
          26/05/2017 15:39:26 [ 7632] [DEBUG] [pbauer] HierarchyCache: AddFolder() serverid: U172ec displayname: Immobilie
          26/05/2017 15:39:26 [32638] [DEBUG] [pbauer] HierarchyCache: AddFolder() serverid: Ub8da7 displayname: DLH
          26/05/2017 15:39:26 [17780] [DEBUG] [pbauer] HierarchyCache: AddFolder() serverid: U29d03 displayname: Gesendete Objekte

          The errorlog contains lines like these:

          26/05/2017 15:36:28 [23923] [FATAL] [pbauer] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command
          26/05/2017 15:37:16 [16492] [FATAL] [pbauer] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command
          26/05/2017 15:37:22 [16019] [FATAL] [pbauer] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command

          It’s very hard to decide how long the foldersync runs, as it is started over and over again, reading more and more of my mailbox - even when I disable E-Mail sync.

          In total, a FolderSync takes more than 10 Minutes, I’d guess.

          The total size of my mailbox (reported by Outlook) is 3.2GB, but I could experiment with a much smaller mbox.

          In the meantime, I could manage to have the account created by tapping on “create another account” while the one created is still syncing. But that’s unstable.

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

            Well, it looks with a smaller mailbox with far less objects, it seems to work.

            I will do further investigation.

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

              Hi itserv,

              there’s a log line which says how long a request took.

              25/05/2017 16:39:03 [11525] [ INFO] [samsung] cmd=‘FolderSync’ memory=‘2.10 MiB/4.00 MiB’ time=‘0.24s’ devType=‘SAMSUNGSMGF’ devId=‘123’ getUser=‘samsung’ from=‘192.168.1.73’ idle=‘0s’ version=‘develop-2.3.4beta1-261-g0e4a1a3’ method=‘POST’ httpcode=‘200’

              It’s right before the “-------- End”.
              Manfred

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

                Manfred,

                first, thank you for your help.

                next, I made z-push work with a test user using the same (default, except for the MAPI_SERVER setting) configuration I struggled with. So I can clearly say: z-push works with my setup for a small account.

                Now, I switch to my production account I run into trouble with. I’m only interested in syncing contacts and appointments. I don’t want to sync my 3.2 GB Mailbox with hundreds of folders and subfolders.

                So I cleaned up my device (removed ActiveSync account, stopped Calendar and cleared it’s data, and did the same for Contacts). Then, I added my production account.

                The settings become checked, and then I reach the “Sychronisation” page. I keep “push” activated, but disable E-Mail-sync, Task-Sync and Download attachments. Only Contacs and Calendar stays checked.

                After saving the account as a new name , I have to confirm the security settings (remote wipe and so on), and FolderSync starts

                28/05/2017 12:12:41 [ 1789] [DEBUG] [user.name] cmd='FolderSync' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' version='2.3.6+0' method='POST'

                Now, looking in what’s going on by opening the new account and seeing a sync is in process, I see an E-Mail-Sync running (I definetly disabled E-mail sync), and after a few minutes, the device says “E-Mail sync OFF”, but the server is still doing a foldersync.

                Looking at the duration(s) a folderSync takes, I see multiple lines:

                28/05/2017 12:15:53 [ 1791] [ INFO] [user.name] cmd='FolderSync' memory='7.77 MiB/8.25 MiB' time='222.17s' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' idle='0s' version='2.3.6+0' method='POST' httpcode='200'

28/05/2017 12:16:12 [ 1789] [ INFO] [user.name] cmd='FolderSync' memory='7.63 MiB/8.25 MiB' time='210.89s' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' idle='0s' version='2.3.6+0' method='POST' httpcode='200'

28/05/2017 12:16:41 [ 6951] [ INFO] [user.name] cmd='FolderSync' memory='7.63 MiB/8.25 MiB' time='209.26s' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' idle='0s' version='2.3.6+0' method='POST' httpcode='200'

28/05/2017 12:18:34 [ 1788] [ INFO] [user.name] cmd='FolderSync' memory='7.63 MiB/8.25 MiB' time='229.46s' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' idle='0s' version='2.3.6+0' method='POST' httpcode='200'

                All of these FolderSyncs do stuff like these:

                28/05/2017 12:18:30 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Uaadfb displayname: Internet Access
28/05/2017 12:18:30 [ 1788] [DEBUG] [user.name] ASDevice->GetFolderIdForBackendId(): generated new folderid 'U286b1' for backend-folderid 'e145b78f5634408f9a731e5aa829b81295be0c000000'
28/05/2017 12:18:30 [ 1788] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U286b1 displayname: 01-xx Lagento Sanitär
28/05/2017 12:18:31 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Ubee1d displayname: Telefonie
28/05/2017 12:18:31 [ 1788] [DEBUG] [user.name] ASDevice->GetFolderIdForBackendId(): generated new folderid 'U4a4aa' for backend-folderid 'e145b78f5634408f9a731e5aa829b812638205000000'
28/05/2017 12:18:31 [ 1788] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:18:31 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U281c1 displayname: AVIRA

                Then, the log entries change:

                28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 472
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] FileStateMachine->SetState() written 123855 bytes on file: '/var/lib/z-push/5/1/androidc118021415-da1bab6c-6957-486b-82ea-cdbcb60eaba2-hc-1'
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] FileStateMachine->SetState() written 15 bytes on file: '/var/lib/z-push/5/1/androidc118021415-da1bab6c-6957-486b-82ea-cdbcb60eaba2-1'
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] SyncCollections::InvalidatePingableFlags(): Invalidating now
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] FileStateMachine->SetState() written 379 bytes on file: '/var/lib/z-push/5/1/androidc118021415-da1bab6c-6957-486b-82ea-cdbcb60eaba2-fd'
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] WBXMLEncoder->endTag() WBXML output completed
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] DeviceManager->Save(): Device data changed
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] FileStateMachine->SetState() written 40544 bytes on file: '/var/lib/z-push/5/1/androidc118021415-devicedata'
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] DeviceManager->Save(): Device data saved
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] LoopDetection->ProcessLoopDetectionTerminate()
28/05/2017 12:18:34 [ 1788] [ INFO] [user.name] cmd='FolderSync' memory='7.63 MiB/8.25 MiB' time='229.46s' devType='SonyD' devId='androidc118021415' getUser='user.name' from='x.x.x.x' idle='0s' version='2.3.6+0' method='POST' httpcode='200'
28/05/2017 12:18:34 [ 1788] [DEBUG] [user.name] -------- End
28/05/2017 12:18:34 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U9b43e displayname: BrainBench
28/05/2017 12:18:34 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Ue9e7a displayname: RedHat
28/05/2017 12:18:35 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U7303f displayname: Oracle
28/05/2017 12:18:36 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Ubde87 displayname: Solaris 11 Upgrade
28/05/2017 12:18:36 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U12c5f displayname: FireBrand
28/05/2017 12:18:37 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Ub04f5 displayname: Maxpert
28/05/2017 12:18:38 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Uec122 displayname: _Wärmepumpe
28/05/2017 12:18:39 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U3ea7e displayname: Deutsche Bank Darlehen
28/05/2017 12:18:40 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U32790 displayname: PV-Anlage
28/05/2017 12:18:40 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U6f222 displayname: Gold- und Silber
28/05/2017 12:18:41 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Ue0d61 displayname: 2013

                So, I’d think, the first FolderSync starts at 12:15:53 and ends at 12:18:34, but after this, FolderSyncs are run again and again.

                And it adds the same objects over and over again:

                root@border:/var/log/z-push# grep MultiVendor z-push.log
28/05/2017 12:15:51 [ 1791] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:16:09 [ 1789] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:16:38 [ 6951] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:18:31 [ 1788] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:22:20 [ 1856] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:27:37 [ 8398] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:36:14 [14814] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:40:52 [14814] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:41:08 [14813] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:41:56 [18297] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:42:26 [14815] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:43:47 [ 1806] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:44:30 [ 1868] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:46:55 [19175] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor
28/05/2017 12:47:39 [18715] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4a4aa displayname: MultiVendor

                When I manually start a resync on the mobile, z-push seems to scan through my mail folders over and over again:

                28/05/2017 12:41:44 [14815] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U52475 displayname: 06-09 Platinen
28/05/2017 12:41:44 [18297] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U9dff3 displayname: 05-16 Spiel
28/05/2017 12:41:44 [ 1806] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U74097 displayname: BMC
28/05/2017 12:41:44 [ 1868] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U4bb12 displayname: _ALLE
28/05/2017 12:41:44 [14815] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U8a6af displayname: 06-10 Kunststoffpinzetten
28/05/2017 12:41:44 [18297] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U7de63 displayname: 05-21 Amazon
28/05/2017 12:41:44 [ 1806] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: U55ed9 displayname: Fujitsu
28/05/2017 12:41:45 [14815] [DEBUG] [user.name] HierarchyCache: AddFolder() serverid: Uef33d displayname: 06-23 Druckerfolien

                The logs stop growing 10 minutes after I manually started the sync
                While the logs on the server still grow, my device claims to have finished syncing. Last successful sync: 28.05.17 12:11 (this is before the initial FolderSync). The clocks on the server and the mobile are in sync.

                There is a 2MBit DSL line between the zarafa server and z-push. Could it help if I put them on the same host?

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

                  OK, I did a quick re-installation of the software directly on my Zarafa server, and connected my mobile device directly to this server, and everything works quick and flawless.

                  There seems to be a problem with the timing, I think.

                  I will do further investigation and come back here to report, but please give me a few days as I can only work on this during my spare time.

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

                    OK, i did now change the setup in this way:

                    Webserver & Apache reverseProxy---->======2MBit DSL=====—> z-push&zarafa.

                    This works well, even with my 3GB zarafa account.

                    My first setup which failed was

                    Webserver & z-push ---->======2MBit DSL=====—> zarafa.

                    Obvisiusly, it’s very important that z-push and zarafa can talk in high speed with each other. Timing on FolderSync seems to be an issue.

                    All works well at my side now. Thank you for your support.

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

                      Well, in one of yours posts it says that your foldersync takes 220 seconds. That’s way too long, especially as Androids have a hard timeout of 30 seconds (for the request to end).

                      Improving speed between components is definetely the best way to deal with that. You can also enable the USE_PARTIAL_FOLDERSYNC feature in your config that actively terminates your requests if they would take too long.

                      Good that it’s solved.

                      Cheers,
                      Sebastian

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