ActiveSync randomly stops working Blackberry 10 since 1.8.17 upgrade - Page 2
Page 2 of 4 FirstFirst 1234 LastLast
Results 11 to 20 of 39

Thread: ActiveSync randomly stops working Blackberry 10 since 1.8.17 upgrade

  1. #11
    Member
    Join Date
    Aug 2013
    Posts
    39
    Quote Originally Posted by Jay View Post
    Hello FiZi,

    From what i can understand from your logs, at 10:50:20 the device changed the retention policy of "/Sent" folder from infinite retention to 23 days, causing tens of ""these messages are out of retention"" replies (SoftDelete) which probably stopped the device from receiving new emails until all messages were reported as out of retention.
    Veeeery interesting. You're right this would explain new e-mails not coming in. It would also explain the high CPU usage as it purges e-mail and probably cleans up some internal database/index.


    Quote Originally Posted by Jay View Post
    Did you actually visit the /Sent folder at 10:50? Was it the first time you did it since you created the account on the device?
    No but Blackberry 10 devices have threaded messaging so in theory anytime I open an e-mail thread that has some previous correspondence I am accessing the sent messages folder.


    Quote Originally Posted by Jay View Post
    Did you change device options at 10:50, even unrelated ones?
    I did not change any device settings at this time. I was listening to Podcasts and noticed my battery had dropped an abnormal amount and figured something had gone wrong with e-mail syncing and the phone was at 100% CPU usage.


    Quote Originally Posted by Jay View Post
    Did you restart mailboxd in the log timeframe?
    I did not and /var/log/zimbra.log doesn't have anything out of the norm in it for mailboxd

    Code:
    Aug 20 03:42:22 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/etc/jetty.xml with mode 440 (0.16 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/web.xml with mode 440 (0.05 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/jetty-env.xml with mode 440 (0.01 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/etc/jetty.properties with mode 440 (0.04 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/etc/krb5.ini with mode 440 (0.02 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/web.xml with mode 440 (0.04 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/etc/spnego.properties with mode 440 (0.01 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/jetty-env.xml with mode 440 (0.01 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/service/WEB-INF/web.xml with mode 440 (0.08 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/etc/spnego.conf with mode 440 (0.00 sec)
    Aug 20 03:42:23 micro zmconfigd[10677]: Rewrote: /opt/zimbra/mailboxd/webapps/zimlet/WEB-INF/web.xml with mode 440 (0.02 sec)
    Aug 20 03:43:24 micro zmconfigd[10677]: Tracking service mailboxd
    Aug 20 03:43:24 micro zmconfigd[10677]: Watchdog: service mailboxd now available for watchdog.
    These entries appear daily at roughly the same time in other zimbra.log files. The day before (August 19th, 2014) I did restart zimbra completely while troubleshooting this issue.


    Quote Originally Posted by Jay View Post
    Do you remember what retentions policies (how many days) were set?
    My phone is set to sync 14 days worth of e-mail and is set to only sync the Inbox, Drafts and Sent messages folder.

    My inbox currently has ~9 e-mails, drafts has 0, sent has 1000's if not 10,000's but only ~50 are in the 14 day sync window



    Update 1 - 2014-08-21 @ 13:12 PST

    The plot thickens.

    My phone started showing high cpu usage around 11:00am PST. I checked and it seems sent items have been sync'd to it all the way back to Sept 28, 2009. The oldest item in the sent messages folder on the server is April 4, 2002.

    My phone is still configured to only sync 14 days worth of e-mail (https://img.fizi.ca/di/TZC6/IMG_20140821_091926.png).

    Unfortunately when I restarted Zimbra on 2014-08-19 it looks like the Account Logger was disabled. I've re-enabled it and so far nothing has been logged yet other then the one line below.

    Code:
    2014-08-21 12:02:28,610 [ZxLink Handler Thread] info Logging myemail@mydomain.com
    I have even sent a test e-mail and it has not sync'd yet likely because the phone is busy doing something with the account.

    I'm going to let things ride out at high-cpu usage for now and see if further sent messages get sync'd or not all the way back to 2002.

    Hopefully we can get to the bottom of this and figure out if it's a bug with BBOS or ZxMobile.

    I can try setting my sync interval to "Forever" if you'd like for testing purposes and remove/re-add my account.



    Update 2 - 2014-08-21 @ 15:54

    After 4 hours and no change to the debug log for the account in question I removed it from my phone. The phone continued to have high CPU utilization. I then removed a second account I have on my phone from my own mail server that uses activesync/zxmobile and the phone went back to being idle.

    That second account has 1 e-mail in the inbox (now deleted), 0 in the drafts and 15 in sent.

    I've removed both accounts from the phone, both sync relationships from ZxMobile, rebooted my phone.

    I am only re-adding the account I believe is the issue which is the one I've been submitting logs for.

    As you can see by this screenshot (https://img.fizi.ca/di/76C4/Untitled.png) the account in the list with the 20,000 sync'd items must be the problem. It is the account I've been submitting logs for.

    I will only re-add my second account as an IMAP account so it bypasses ActiveSync and will not interfere with further troubleshooting.
    Last edited by FiZi; 08-22-2014 at 12:15 AM.

  2. #12
    Member
    Join Date
    Aug 2013
    Posts
    39
    After re-adding just the single ActiveSync account it immediately sync'd 42 messages according to the admin interface.

    Based on a search in Zimbra it should have sync'd 46 messages that fall within the 14 day time window.

    The sync finished with the following log entries:

    Code:
    2014-08-21 16:26:42,997 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug cacheCommand changed: true
    2014-08-21 16:26:42,997 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Drafts folder type: message
    2014-08-21 16:26:42,997 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/6/34/1 S: e36a6ef0108a459cb979cfc7e6603b01/6/34/1 P: Invalid State/-1/0/0
    2014-08-21 16:26:42,998 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/6/34/1
    2014-08-21 16:26:42,998 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:26:43,0 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:26:43,0 [myname@mydomain.com BB2AD68B48] debug [2139] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/6/34/1
    2014-08-21 16:26:43,0 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Sent folder type: message
    2014-08-21 16:26:43,0 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/5/54/6 S: e36a6ef0108a459cb979cfc7e6603b01/5/54/6 P: e36a6ef0108a459cb979cfc7e6603b01/5/54/5
    2014-08-21 16:26:43,0 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/5/54/6
    2014-08-21 16:26:43,0 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:26:43,3 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:26:43,3 [myname@mydomain.com BB2AD68B48] debug [2139] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/5/54/6
    2014-08-21 16:26:43,3 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Inbox folder type: message
    2014-08-21 16:26:43,3 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/2/18/2 S: e36a6ef0108a459cb979cfc7e6603b01/2/18/2 P: e36a6ef0108a459cb979cfc7e6603b01/2/18/1
    2014-08-21 16:26:43,3 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/2/18/2
    2014-08-21 16:26:43,4 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:26:43,5 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:26:43,5 [myname@mydomain.com BB2AD68B48] debug [2139] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/2/18/2
    2014-08-21 16:26:43,6 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Contacts folder type: contact
    2014-08-21 16:26:43,6 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/7/29/6 S: e36a6ef0108a459cb979cfc7e6603b01/7/29/6 P: e36a6ef0108a459cb979cfc7e6603b01/7/29/5
    2014-08-21 16:26:43,6 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/7/29/6
    2014-08-21 16:26:43,6 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-21 16:26:43,9 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:26:43,9 [myname@mydomain.com BB2AD68B48] debug [2139] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/7/29/6
    2014-08-21 16:26:43,9 [myname@mydomain.com BB2AD68B48] debug Sync called using ping mode, Heartbeat 480 seconds
    2014-08-21 16:26:43,10 Sync[2138]: [ZeXtras Activity Thread] debug Continuation: resume
    2014-08-21 16:26:43,11 [qtp1610155881-23539:http://127.0.0.1:65521/Microsoft-Server-ActiveSync?Cmd=Sync&DeviceType=BlackBerry&User=myname%40mydomain.com&DeviceId=BB2AD68B48] debug Continuation: resumed!!
    2014-08-21 16:26:43,11 Sync[2138]: [myname@mydomain.com BB2AD68B48] debug Empty SyncResponse!
    2014-08-21 16:26:43,12 [myname@mydomain.com BB2AD68B48] debug [2138] finalizeChanges
    2014-08-21 16:26:43,16 [myname@mydomain.com BB2AD68B48] debug [2138] cancelChanges
    If I'm reading that right is it saying that my device asked for the sync window to be 23 days on my Inbox, Drafts and Sent items? Instead of the configured 14?

  3. #13
    Member
    Join Date
    Aug 2013
    Posts
    39
    Also after the first 480s passed the following appeared:

    Code:
    2014-08-21 16:32:09,905 [qtp1610155881-23620:http://127.0.0.1:65521/Microsoft-Server-ActiveSync?Cmd=Sync&DeviceType=BlackBerry&User=myname%40mydomain.com&DeviceId=BB2AD68B48] debug Cached auth found for myname@mydomain.com id: e36a6ef0-108a-459c-b979-cfc7e6603b01
    2014-08-21 16:32:09,906 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Base64 rawData: AwFqAAAARVwAAE9LA2UzNmE2ZWYwMTA4YTQ1OWNiOTc5Y2ZjN2U2NjAzYjAxLzcvMjkvNgABUgM3AAETVQMyNQABVwARRUYDMQABRwMxMDQ4NTc2AAEBAQEAAE9LA2UzNmE2ZWYwMTA4YTQ1OWNiOTc5Y2ZjN2U2NjAzYjAxLzIvMTgvMgABUgMyAAETVQMyNQABV1gDNAABABhFAzEAAQAAYgMxAAFjAzcAAQARRUYDMgABAUVGAzEAAQFFRgM0AAFHAzIwMDAwMAABAQEBAABPSwNlMzZhNmVmMDEwOGE0NTljYjk3OWNmYzdlNjYwM2IwMS81LzU0LzYAAVIDNQABE1UDMjUAAVdYAzQAAQAYRQMxAAEAAGIDMQABYwM3AAEAEUVGAzIAAQFFRgMxAAEBRUYDNAABRwMyMDAwMDAAAQEBAQAAT0sDZTM2YTZlZjAxMDhhNDU5Y2I5NzljZmM3ZTY2MDNiMDEvNi8zNC8xAAFSAzYAARNVAzI1AAFXWAM0AAEAGEUDMQABAABiAzEAAWMDNwABABFFRgMyAAEBRUYDMQABAUVGAzQAAUcDMjAwMDAwAAEBAQEBAABpAzMwMAABAQ==
    2014-08-21 16:32:09,908 [myname@mydomain.com BB2AD68B48] debug Device XML Input, EAS version: 14.1
    <?xml version="1.0" standalone="no"?>
    <Sync>
        <Collections>
            <Collection>
                <SyncKey>e36a6ef0108a459cb979cfc7e6603b01/7/29/6</SyncKey>
                <CollectionId>7</CollectionId>
                <GetChanges />
                <WindowSize>25</WindowSize>
                <Options>
                    <BodyPreference>
                        <Type>1</Type>
                        <TruncationSize>1048576</TruncationSize>
                    </BodyPreference>
                </Options>
            </Collection>
            <Collection>
                <SyncKey>e36a6ef0108a459cb979cfc7e6603b01/2/18/2</SyncKey>
                <CollectionId>2</CollectionId>
                <GetChanges />
                <WindowSize>25</WindowSize>
                <Options>
                    <FilterType>4</FilterType>
                    <RightsManagementSupport>1</RightsManagementSupport>
                    <MIMESupport>1</MIMESupport>
                    <MIMETruncation>7</MIMETruncation>
                    <BodyPreference>
                        <Type>2</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>1</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>4</Type>
                        <TruncationSize>200000</TruncationSize>
                    </BodyPreference>
                </Options>
            </Collection>
            <Collection>
                <SyncKey>e36a6ef0108a459cb979cfc7e6603b01/5/54/6</SyncKey>
                <CollectionId>5</CollectionId>
                <GetChanges />
                <WindowSize>25</WindowSize>
                <Options>
                    <FilterType>4</FilterType>
                    <RightsManagementSupport>1</RightsManagementSupport>
                    <MIMESupport>1</MIMESupport>
                    <MIMETruncation>7</MIMETruncation>
                    <BodyPreference>
                        <Type>2</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>1</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>4</Type>
                        <TruncationSize>200000</TruncationSize>
                    </BodyPreference>
                </Options>
            </Collection>
            <Collection>
                <SyncKey>e36a6ef0108a459cb979cfc7e6603b01/6/34/1</SyncKey>
                <CollectionId>6</CollectionId>
                <GetChanges />
                <WindowSize>25</WindowSize>
                <Options>
                    <FilterType>4</FilterType>
                    <RightsManagementSupport>1</RightsManagementSupport>
                    <MIMESupport>1</MIMESupport>
                    <MIMETruncation>7</MIMETruncation>
                    <BodyPreference>
                        <Type>2</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>1</Type>
                    </BodyPreference>
                    <BodyPreference>
                        <Type>4</Type>
                        <TruncationSize>200000</TruncationSize>
                    </BodyPreference>
                </Options>
            </Collection>
        </Collections>
        <HeartbeatInterval>300</HeartbeatInterval>
    </Sync>
    2014-08-21 16:32:09,913 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug cacheCommand changed: true
    2014-08-21 16:32:09,913 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Drafts folder type: message
    2014-08-21 16:32:09,913 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/6/34/1 S: e36a6ef0108a459cb979cfc7e6603b01/6/34/1 P: Invalid State/-1/0/0
    2014-08-21 16:32:09,913 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/6/34/1
    2014-08-21 16:32:09,913 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:32:09,916 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:32:09,916 [myname@mydomain.com BB2AD68B48] debug [2140] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/6/34/1
    2014-08-21 16:32:09,916 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Sent folder type: message
    2014-08-21 16:32:09,916 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/5/54/6 S: e36a6ef0108a459cb979cfc7e6603b01/5/54/6 P: e36a6ef0108a459cb979cfc7e6603b01/5/54/5
    2014-08-21 16:32:09,917 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/5/54/6
    2014-08-21 16:32:09,917 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:32:09,919 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:32:09,919 [myname@mydomain.com BB2AD68B48] debug [2140] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/5/54/6
    2014-08-21 16:32:09,919 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Inbox folder type: message
    2014-08-21 16:32:09,919 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/2/18/2 S: e36a6ef0108a459cb979cfc7e6603b01/2/18/2 P: e36a6ef0108a459cb979cfc7e6603b01/2/18/1
    2014-08-21 16:32:09,919 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/2/18/2
    2014-08-21 16:32:09,920 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 23 days
    2014-08-21 16:32:09,921 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:32:09,922 [myname@mydomain.com BB2AD68B48] debug [2140] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/2/18/2
    2014-08-21 16:32:09,922 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Contacts folder type: contact
    2014-08-21 16:32:09,922 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: e36a6ef0108a459cb979cfc7e6603b01/7/29/6 S: e36a6ef0108a459cb979cfc7e6603b01/7/29/6 P: e36a6ef0108a459cb979cfc7e6603b01/7/29/5
    2014-08-21 16:32:09,922 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: e36a6ef0108a459cb979cfc7e6603b01/7/29/6
    2014-08-21 16:32:09,922 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-21 16:32:09,926 Sync[2140]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 261260
    2014-08-21 16:32:09,926 [myname@mydomain.com BB2AD68B48] debug [2140] setSyncState: e36a6ef0-108a-459c-b979-cfc7e6603b01 => e36a6ef0108a459cb979cfc7e6603b01/7/29/6
    2014-08-21 16:32:09,926 [myname@mydomain.com BB2AD68B48] debug Sync called using ping mode, Heartbeat 300 seconds
    2014-08-21 16:32:09,928 Sync[2139]: [ZeXtras Activity Thread] debug Continuation: resume
    2014-08-21 16:32:09,928 [qtp1610155881-23580:http://127.0.0.1:65521/Microsoft-Server-ActiveSync?Cmd=Sync&DeviceType=BlackBerry&User=myname%40mydomain.com&DeviceId=BB2AD68B48] debug Continuation: resumed!!
    2014-08-21 16:32:09,928 Sync[2139]: [myname@mydomain.com BB2AD68B48] debug Empty SyncResponse!
    2014-08-21 16:32:09,929 [myname@mydomain.com BB2AD68B48] debug [2139] finalizeChanges
    2014-08-21 16:32:09,932 [myname@mydomain.com BB2AD68B48] debug [2139] cancelChanges
    So now the heartbeat is 300s?

    and then after that 300s passed the next log entries said 480s again.....

    This has stayed the same so far though "Device asking for changes with a time window of: 23 days"

  4. #14
    Member
    Join Date
    Aug 2013
    Posts
    39
    So I might have this narrowed down now.

    Not even 2 hours after re-adding my account and the above initial syncing where only 14 days of mail was sync'd my phone has shot off like a rocket and is now syncing further and further back in time.

    I just looked at my work account which is Exchange 2010 and ActiveSync and it only has e-mailed sync'd back to July 21, 2014 and it is set to only sync 30 days worth of e-mail. The account has been on my phone for much longer than 30 days.

    I'm thinking there is now some kind of communication/setting issue between the Blackberry and ZxMobile. What I don't know is if it's a bug in the ActiveSync protocol of ZxMobile or if it's a bug in the Blackberry that causes it to start syncing more e-mail than what it is configured to sync. In my case because I have over 20,000 e-mails in my sent messages I may be hitting some kind of limit in Blackberry OS which causes the high CPU usage and e-mail to stop syncing for all accounts on my device on my server. My Exchange ActiveSync account and another IMAP account are not affected when my ZxMobile accounts go nuts.

    I've removed the account from my phone at this time and can provide fresh logs if you'd like. Let me know what's next. I think we're on the home stretch in diagnosing this.
    Last edited by FiZi; 08-22-2014 at 02:37 AM.

  5. #15
    Wise Guy Participant
    Join Date
    Apr 2011
    Posts
    34
    Hello FiZi .

    Thanks again for the wealth of information you are collecting.
    We are in the process of setting up a BlackBerry 10 Device Simulator in order to review the issue more thoroughly.
    You'll hear something more from us next week ( since it's Friday already ).
    In the meantime, a possible workaround for the humongous Sent folder might be to split up the contents across multiple folders, if that's convenient for you.

    Regards,
    Trantor
    ZeXtras Website # ZeXtras Wiki # ZeXtras Store

    ZeXtras System Administrator and Installer Guru

  6. #16
    Jay
    Jay is offline
    Code Master ZeXtras Employee
    Join Date
    May 2011
    Posts
    26
    Hi FiZi,

    After several hours of testing on BB simulator I still wasn't able to reproduce the bug

    If I'm reading that right is it saying that my device asked for the sync window to be 23 days on my Inbox, Drafts and Sent items? Instead of the configured 14?
    there was a typo in the debug log, 23 days were actually 14!

    The problem in a nutshell is that the time window is not stored in the server and the default (limitless) is used, either the device doesn't send it or the server doesn't store it properly.

    I found a related bug that might be the cause: a time window of a folder is not flushed in the database until a change within a folder is pushed to the device, this means that if you synchronize an empty folder, wait for the device session to expire (or reboot mailboxd), then copy emails inside it, if the device omit the time window in the request for that particular folder then a default timewindow of 0 (synchronize everything) is used, the device will synchronize every new items regardless of its age until the time window is sent again by the device.

    I created a custom build which fix this bug, you can download it here.
    md5: bcc4889ad1adf8a7fb5d170a54e97562

    Let me know if issues still appear with this build.

    Regards,
    Jay
    ZeXtras Website # ZeXtras Wiki # ZeXtras Store

    Head of ZeXtras Suite Developers

  7. #17
    Member
    Join Date
    Aug 2013
    Posts
    39
    Thank you for all of your support.

    Jay - I've installed your patched version of ZxMobile, removed all previous sync relationships with my device and just re-added the account now with a 14 day limit.

    It has just completed syncing 14 days worth of e-mail and I'm watching the debug log to see what happens over the next few hours. The sync interface says 42 e-mails and 102 contacts. As expected.

    What version of Blackberry OS are you using in your emulator? I'm running OS Version 10.2.1.3247. I wonder if the issue is specific to my version of BBOS. Or could it be related to my Apache Proxy?

    I will let you know if I see the problem re-occur in the next few days.


    Trantor - I was thinking of filing my sent messages into sub-folders by year as a potential workaround. I did it this morning and had to restore my mailbox using ZxBackup (which worked AWESOME by the way). Zimbra does some stupid stuff with conversation view and when I filed my sent messages into sub-folders it completely ruined all of the other archived e-mail I had in other folders. I suspect I needed to switch off conversation view before filing the e-mail but I'm concerned that moving all of the messages would break the linkages in my conversation views.

    I can how ever confirm that my sent messages folder has 29340 messages in it. So that lines up with the mass syncing that occurs. Since Zimbra groups things strangely in conversation view I suspect a good chunk of those 29340 messages aren't even "sent" messages and they are just part of an e-mail chain.

  8. #18
    Member
    Join Date
    Aug 2013
    Posts
    39
    Good news right out of the gate. The number of days bug is fixed in your build.

    Code:
    2014-08-22 10:54:33,578 Sync[25]: [myname@mydomain.com BB2AD68B48] debug IsPartial TRUE
    2014-08-22 10:54:33,579 Sync[25]: [myname@mydomain.com BB2AD68B48] debug cacheCommand changed: true
    2014-08-22 10:54:33,579 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Drafts folder type: message
    2014-08-22 10:54:33,579 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/2 S: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/2 P: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/1
    2014-08-22 10:54:33,580 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/2
    2014-08-22 10:54:33,580 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 14 days
    2014-08-22 10:54:33,583 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 41576
    2014-08-22 10:54:33,583 [myname@mydomain.com BB2AD68B48] debug [25] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/2
    2014-08-22 10:54:33,583 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Sent folder type: message
    2014-08-22 10:54:33,583 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/6 S: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/6 P: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/5
    2014-08-22 10:54:33,583 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/6
    2014-08-22 10:54:33,583 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 14 days
    2014-08-22 10:54:33,585 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 41576
    2014-08-22 10:54:33,585 [myname@mydomain.com BB2AD68B48] debug [25] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/6
    2014-08-22 10:54:33,586 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Inbox folder type: message
    2014-08-22 10:54:33,586 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/3 S: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/3 P: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/2
    2014-08-22 10:54:33,586 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/3
    2014-08-22 10:54:33,586 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 14 days
    2014-08-22 10:54:33,588 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 41576
    2014-08-22 10:54:33,589 [myname@mydomain.com BB2AD68B48] debug [25] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/3
    2014-08-22 10:54:33,589 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sync on folder path: /Contacts folder type: contact
    2014-08-22 10:54:33,589 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6 S: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6 P: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/5
    2014-08-22 10:54:33,589 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6
    2014-08-22 10:54:33,589 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-22 10:54:33,594 Sync[25]: [myname@mydomain.com BB2AD68B48] debug Updating sequence to 41576
    2014-08-22 10:54:33,594 [myname@mydomain.com BB2AD68B48] debug [25] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6
    2014-08-22 10:54:33,594 [myname@mydomain.com BB2AD68B48] debug Sync called using ping mode, Heartbeat 480 seconds
    It now properly displays 14 days.

  9. #19
    Member
    Join Date
    Aug 2013
    Posts
    39
    Bad news guys.

    After a few hours my phone sync'd all of my sent items to the beginning of time again. This time it was able to sync ALL of them instead of hanging when it got to 2009. It's still downloading message bodies from the looks of the debug log which I can provide if you'd like.

  10. #20
    Member
    Join Date
    Aug 2013
    Posts
    39
    Looks like my e-mail finished syncing (~29349 messages) and now everything but my Inbox is set to '0' for sync days.

    Code:
    2014-08-22 22:47:25,233 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug cacheCommand changed: true
    2014-08-22 22:47:25,234 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sync on folder path: /Drafts folder type: message
    2014-08-22 22:47:25,234 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/3 S: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/3 P: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/2
    2014-08-22 22:47:25,234 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/3
    2014-08-22 22:47:25,234 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-22 22:47:25,238 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Updating sequence to 41702
    2014-08-22 22:47:25,238 [myemail@mydomain.com BB2AD68B48] debug [1239] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/6/26/3
    2014-08-22 22:47:25,242 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sync on folder path: /Sent folder type: message
    2014-08-22 22:47:25,246 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/1179 S: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/1179 P: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/1178
    2014-08-22 22:47:25,246 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/1179
    2014-08-22 22:47:25,248 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-22 22:47:25,256 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Updating sequence to 41702
    2014-08-22 22:47:25,257 [myemail@mydomain.com BB2AD68B48] debug [1239] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/5/71/1179
    2014-08-22 22:47:25,257 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sync on folder path: /Inbox folder type: message
    2014-08-22 22:47:25,257 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/26 S: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/26 P: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/25
    2014-08-22 22:47:25,257 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/26
    2014-08-22 22:47:25,258 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 14 days
    2014-08-22 22:47:25,260 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Updating sequence to 41702
    2014-08-22 22:47:25,261 [myemail@mydomain.com BB2AD68B48] debug [1239] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/2/72/26
    2014-08-22 22:47:25,261 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sync on folder path: /Contacts folder type: contact
    2014-08-22 22:47:25,261 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Current sync status: D: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6 S: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6 P: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/5
    2014-08-22 22:47:25,261 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Sending server sync state: 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6
    2014-08-22 22:47:25,261 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Device asking for changes with a time window of: 0 days
    2014-08-22 22:47:25,266 Sync[1239]: [myemail@mydomain.com BB2AD68B48] debug Updating sequence to 41702
    2014-08-22 22:47:25,266 [myemail@mydomain.com BB2AD68B48] debug [1239] setSyncState: 9d7fa310-ae0f-4e7a-b062-fefc7e551f48 => 9d7fa310ae0f4e7ab062fefc7e551f48/7/18/6
    2014-08-22 22:47:25,266 [myemail@mydomain.com BB2AD68B48] debug Sync called using ping mode, Heartbeat 480 seconds
    2014-08-22 22:47:25,267 Sync[1238]: [ZeXtras Activity Thread] debug Continuation: resume
    So now I suspect what will happen next is my Blackberry will do some kind of maintenance and purge local messages older than the sync time frame (14 days) and then what ever bug/incompatibility is occurring will cause it to resync everything again, rinse repeat.

    I've set my phones sync limit to "Forever" for now.
    Last edited by FiZi; 08-23-2014 at 07:11 AM.

Page 2 of 4 FirstFirst 1234 LastLast

Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •