Bug 29 - Syncronization error on Windows Phone 7.5 Mango (Nokia Lumia 800)
Summary: Syncronization error on Windows Phone 7.5 Mango (Nokia Lumia 800)
Status: RESOLVED INVALID
Alias: None
Product: ZeXtras
Classification: Unclassified
Component: ZxMobile (show other bugs)
Version: 1.2.3
Hardware: -- Linux
: Low minor
Assignee: ZeXtras Bugzilla Admin
QA Contact:
URL:
Depends on:
Blocks:
 
Reported: 2012-02-14 14:18 CET by sergio tarrago
Modified: 2012-03-06 13:02 CET (History)
3 users (show)

See Also:
Browser: ---
Zimlet Chat version: ---
Zimbra Version: ---


Attachments
Pic of the error on the phone (1.39 MB, image/jpeg)
2012-02-28 09:07 CET, sergio tarrago
Details
Log on /opt/zimbra/sync.log when the error appears on the phone (32.51 KB, text/plain)
2012-02-28 09:08 CET, sergio tarrago
Details

Note You need to log in before you can comment on or make changes to this bug.
Description sergio tarrago 2012-02-14 14:18:54 CET
We are getting erros when trying to syncronize Windows Phone 7.5 Mando on a Nokia Lumia 800 with Zimbra ZxMobile. 

The errors on the /opt/zimbra/log/sync.log are the following.

2012-02-14 08:44:19,070 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:19,070 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:19,070 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:19,855 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:19,855 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:19,855 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:19,855 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:19,856 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:19,856 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:19,856 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:19,856 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:20,412 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,035 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,036 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,036 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,656 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,656 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 08:44:21,656 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '0/0/00'
2012-02-14 08:44:21,656 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '1/1/4501'
2012-02-14 10:56:23,551 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '05/04/2004'
2012-02-14 10:56:31,751 WARN  [ZxMobile Handler Thread] [] sync - Unable to parse date: '09/11/2004'

It seems to be a problem with the date format. Error occurs sometimes and on some accounts, randomly, Android sync goes fine, but WP not.
Comment 1 D0s0n 2012-02-14 15:08:25 CET
Can you set the logging level to DEBUG? We need more detailed info.
Comment 2 sergio tarrago 2012-02-21 16:11:24 CET
¿logging level to DEBUG?

On zimbra?.. on zextras? How?
Comment 3 Cine 2012-02-21 16:42:47 CET
(In reply to comment #2)
> ¿logging level to DEBUG?
> 
> On zimbra?.. on zextras? How?

Hello Sergio,

D0s0n meant the ZeXtras logging level, which can be set in the ZeXtras Administration Zimlet, Core section...

Please change this setting, retry to synchronize the phone and post again the synchronization part of the sync.log along with any exceptions that might appear.

Have a nice day,
Cine
Comment 4 sergio tarrago 2012-02-27 09:14:41 CET
After some days working ok here is the problem again. When i remove the account and add it again it works fine, but after some days the problem comes again.

 tail -f /opt/zimbra/log/sync.log

17285081
2012-02-27 09:03:50,497 INFO  [ZxMobile Handler Thread] [] sync - ZESessionCache: session expired: fadeb6d6-0fb8-4865-8c08-8122284f0971\androidc1510099697
2012-02-27 09:03:50,498 INFO  [ZxMobile Handler Thread] [] sync - Device XML Input: <?xml version="1.0" standalone="no"?><FolderSync><SyncKey>9e41c04553a34d5f9095a99523ad0e27/0/0/28/2</SyncKey></FolderSync>
2012-02-27 09:03:50,498 INFO  [ZxMobile Handler Thread] [] sync - FolderSync: cmdSchema:SyncKey
2012-02-27 09:03:50,498 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: [85.62.233.161] ZxMobile Command FolderSync on account xxxxxx@domain.es from device WindowsPhone/ED2695E1708CB9DE6D8E6F1055DB711B
2012-02-27 09:03:50,499 INFO  [ZxMobile Handler Thread] [] sync - [15695] setSyncState: 9e41c045-53a3-4d5f-9095-a99523ad0e27 => 9e41c04553a34d5f9095a99523ad0e27/0/0/28/2
2012-02-27 09:03:50,529 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Debug Response: <?xml version="1.0" standalone="no"?><FolderSync><Status>1</Status><SyncKey>9e41c04553a34d5f9095a99523ad0e27/0/0/28/2</SyncKey><Changes><Count>0</Count></Changes></FolderSync>
2012-02-27 09:03:50,529 INFO  [ZxMobile Handler Thread] [] sync - [15695] finalizeChanges
2012-02-27 09:03:50,529 INFO  [ZxMobile Handler Thread] [] sync - [15695] cancelChanges
2012-02-27 09:03:51,553 INFO  [ZeXtras Real Time Notifier Thread] [] sync - ZxMobile Real Time Notifier: found opcode: SetConfig
2012-02-27 09:03:51,854 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Starting ZEMobileHandler
2012-02-27 09:03:51,854 INFO  [ZxMobile Handler Thread] [] sync - Cached auth found for xxxxxx@domain.es id: 9e41c045-53a3-4d5f-9095-a99523ad0e27
2012-02-27 09:03:51,856 INFO  [ZxMobile Handler Thread] [] sync - Device XML Input: <?xml version="1.0" standalone="no"?><GetItemEstimate><Collections><Collection><Class>Calendar</Class><CollectionId>10</CollectionId><FilterType>4</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/10/11795/18/67</SyncKey></Collection><Collection><Class>Tasks</Class><CollectionId>15</CollectionId><FilterType>0</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/15/9687/91/8</SyncKey></Collection><Collection><Class>Email</Class><CollectionId>2</CollectionId><FilterType>3</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/2/11835/35/727</SyncKey></Collection><Collection><Class>Email</Class><CollectionId>5</CollectionId><FilterType>3</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/5/11779/4/97</SyncKey></Collection><Collection><Class>Contacts</Class><CollectionId>7</CollectionId><FilterType>0</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462</SyncKey></Collection></Collections></GetItemEstimate>
2012-02-27 09:03:51,856 INFO  [ZxMobile Handler Thread] [] sync - GetItemEstimate: cmdSchema:Collections
2012-02-27 09:03:51,857 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: [85.62.233.161] ZxMobile Command GetItemEstimate on account xxxxxx@domain.es from device WindowsPhone/ED2695E1708CB9DE6D8E6F1055DB711B
2012-02-27 09:03:51,857 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462



2012-02-27 09:04:35,558 INFO  [ZeXtras Real Time Notifier Thread] [] sync - Removing folder changes: {84=[3]} from {84=[3]}
2012-02-27 09:04:35,558 INFO  [ZeXtras Real Time Notifier Thread] [] sync - Removing item changes: {} from {}
2012-02-27 09:04:35,558 INFO  [ZeXtras Real Time Notifier Thread] [] sync - Removing folder changes: {84=[3]} from {}
2012-02-27 09:04:39,890 INFO  [btpool0-4483://webmail.gestinpe.net/Microsoft-Server-ActiveSync?User=correo&DeviceId=ED2695E1708CB9DE6D8E6F1055DB711B&DeviceType=WindowsPhone] [] sync - [85.62.233.161] ZxMobile device MSFT-WP/7.10.7740 asking for server configuration
2012-02-27 09:04:40,645 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Starting ZEMobileHandler
2012-02-27 09:04:40,645 INFO  [ZxMobile Handler Thread] [] sync - Cached auth found for xxxxxx@domain.es id: 9e41c045-53a3-4d5f-9095-a99523ad0e27
2012-02-27 09:04:40,647 INFO  [ZxMobile Handler Thread] [] sync - Device XML Input: <?xml version="1.0" standalone="no"?><FolderSync><SyncKey>9e41c04553a34d5f9095a99523ad0e27/0/0/28/2</SyncKey></FolderSync>
2012-02-27 09:04:40,647 INFO  [ZxMobile Handler Thread] [] sync - FolderSync: cmdSchema:SyncKey
2012-02-27 09:04:40,648 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: [85.62.233.161] ZxMobile Command FolderSync on account xxxxxx@domain.es from device WindowsPhone/ED2695E1708CB9DE6D8E6F1055DB711B
2012-02-27 09:04:40,649 INFO  [ZxMobile Handler Thread] [] sync - [15701] setSyncState: 9e41c045-53a3-4d5f-9095-a99523ad0e27 => 9e41c04553a34d5f9095a99523ad0e27/0/0/28/2
2012-02-27 09:04:40,689 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Debug Response: <?xml version="1.0" standalone="no"?><FolderSync><Status>1</Status><SyncKey>9e41c04553a34d5f9095a99523ad0e27/0/0/28/2</SyncKey><Changes><Count>0</Count></Changes></FolderSync>
2012-02-27 09:04:40,689 INFO  [ZxMobile Handler Thread] [] sync - [15701] finalizeChanges
2012-02-27 09:04:40,689 INFO  [ZxMobile Handler Thread] [] sync - [15701] cancelChanges
2012-02-27 09:04:41,559 INFO  [ZeXtras Real Time Notifier Thread] [] sync - ZxMobile Real Time Notifier: found opcode: SetConfig
2012-02-27 09:04:41,926 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Starting ZEMobileHandler
2012-02-27 09:04:41,926 INFO  [ZxMobile Handler Thread] [] sync - Cached auth found for xxxxxx@domain.es id: 9e41c045-53a3-4d5f-9095-a99523ad0e27
2012-02-27 09:04:41,927 INFO  [ZxMobile Handler Thread] [] sync - Device XML Input: <?xml version="1.0" standalone="no"?><GetItemEstimate><Collections><Collection><Class>Calendar</Class><CollectionId>10</CollectionId><FilterType>4</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/10/11795/18/67</SyncKey></Collection><Collection><Class>Tasks</Class><CollectionId>15</CollectionId><FilterType>0</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/15/9687/91/8</SyncKey></Collection><Collection><Class>Email</Class><CollectionId>2</CollectionId><FilterType>3</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/2/11835/35/727</SyncKey></Collection><Collection><Class>Email</Class><CollectionId>5</CollectionId><FilterType>3</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/5/11779/4/97</SyncKey></Collection><Collection><Class>Contacts</Class><CollectionId>7</CollectionId><FilterType>0</FilterType><SyncKey>9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462</SyncKey></Collection></Collections></GetItemEstimate>
2012-02-27 09:04:41,928 INFO  [ZxMobile Handler Thread] [] sync - GetItemEstimate: cmdSchema:Collections
2012-02-27 09:04:41,928 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: [85.62.233.161] ZxMobile Command GetItemEstimate on account xxxxxx@domain.es from device WindowsPhone/ED2695E1708CB9DE6D8E6F1055DB711B
2012-02-27 09:04:41,928 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/7/10078/94/462
2012-02-27 09:04:42,061 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/5/11779/4/97 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/5/11779/4/97
2012-02-27 09:04:42,061 INFO  [ZxMobile Handler Thread] [] sync - GetItemEstimate: Getting items older(or newer) than 7 days
2012-02-27 09:04:42,071 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/2/11835/35/727 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/2/11821/35/724
2012-02-27 09:04:42,071 INFO  [ZxMobile Handler Thread] [] sync - GetItemEstimate: Sync states not equals
2012-02-27 09:04:42,071 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/15/9687/91/8 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/15/9687/91/8
2012-02-27 09:04:42,073 INFO  [ZxMobile Handler Thread] [] sync - ### deviceSyncState: 9e41c04553a34d5f9095a99523ad0e27/10/11795/18/67 - serverSyncState: 9e41c04553a34d5f9095a99523ad0e27/10/11795/18/67
2012-02-27 09:04:42,073 INFO  [ZxMobile Handler Thread] [] sync - GetItemEstimate: Getting items older(or newer) than 14 days
2012-02-27 09:04:42,130 INFO  [ZxMobile Handler Thread] [] sync - ZxMobile Handler: Debug Response: <?xml version="1.0" standalone="no"?><GetItemEstimate><Response><Status>1</Status><Collection><Class>Contacts</Class><CollectionId>7</CollectionId><Estimate>0</Estimate></Collection></Response><Response><Status>1</Status><Collection><Class>Email</Class><CollectionId>5</CollectionId><Estimate>8</Estimate></Collection></Response><Response><Status>4</Status></Response><Response><Status>1</Status><Collection><Class>Tasks</Class><CollectionId>15</CollectionId><Estimate>0</Estimate></Collection></Response><Response><Status>1</Status><Collection><Class>Calendar</Class><CollectionId>10</CollectionId><Estimate>0</Estimate></Collection></Response></GetItemEstimate>
2012-02-27 09:04:42,130 INFO  [ZxMobile Handler Thread] [] sync - [15702] finalizeChanges
2012-02-27 09:04:42,130 INFO  [ZxMobile Handler Thread] [] sync - [15702] cancelChanges
2012-02-27 09:04:43,559 INFO  [ZeXtras Real Time Notifier Thread] [] sync - ZxMobile Real Time Notifier: found opcode: SetConfig
Comment 5 kral 2012-02-27 10:30:48 CET
Hi Sergio,

I'm Marco, one of the ZeXtras developers. I can't find any sign of the error you mention before on the last log you've posted.

Can you please isolate the points where the error occurs and post it?

Thanks,
Comment 6 sergio tarrago 2012-02-28 09:07:55 CET
Created attachment 2 [details]
Pic of the error on the phone

Pic of the error on the phone
Comment 7 sergio tarrago 2012-02-28 09:08:37 CET
Created attachment 3 [details]
Log on /opt/zimbra/sync.log when the error appears on the phone

Log on /opt/zimbra/sync.log when the error appears on the phone
Comment 8 sergio tarrago 2012-02-28 09:09:58 CET
Attached the log at the moment of the error on the phone, and a pic of the phone with the error number. If i remove the account on the phone and create it again it works for some days, but the error appears again.
Comment 9 Cine 2012-03-06 13:02:47 CET
Marking as invalid as the error code on the device leads back to a common deviceside problem.