Using ActiveSync on Android 4.4.2, if some contacts have a birthday field filled in it will cause the Exchange service to crash and fail to sync any contacts. Appears to have an issue parsing the date.
Created a test account with one contact. Without filling in the Birthday field contacts sync nicely, however when adding the field and deleting/recreating the account on the phone the exchange service will crash:
04-24 18:31:49.323: E/AndroidRuntime(5222): FATAL EXCEPTION: SyncAdapterThread-3
04-24 18:31:49.323: E/AndroidRuntime(5222): Process: com.google.android.exchange, PID: 5222
04-24 18:31:49.323: E/AndroidRuntime(5222): java.lang.NumberFormatException: Invalid int: "T0"
04-24 18:31:49.323: E/AndroidRuntime(5222): at java.lang.Integer.invalidInt(Integer.java:137)
04-24 18:31:49.323: E/AndroidRuntime(5222): at java.lang.Integer.parse(Integer.java:374)
04-24 18:31:49.323: E/AndroidRuntime(5222): at java.lang.Integer.parseInt(Integer.java:365)
04-24 18:31:49.323: E/AndroidRuntime(5222): at java.lang.Integer.parseInt(Integer.java:331)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.emailcommon.utility.Utility.parseEmailDateTimeToMillis(Utility.java:365)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.adapter.ContactsSyncParser$ContactOperations.addBirthday(ContactsSyncParser.java:1047)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.adapter.ContactsSyncParser.addData(ContactsSyncParser.java:283)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.adapter.ContactsSyncParser.addParser(ContactsSyncParser.java:405)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.adapter.ContactsSyncParser.commandsParser(ContactsSyncParser.java:501)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.adapter.AbstractSyncParser.parse(AbstractSyncParser.java:177)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.service.EasSyncHandler.parse(EasSyncHandler.java:302)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.service.EasSyncHandler.performOneSync(EasSyncHandler.java:363)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.service.EasSyncHandler.performSync(EasSyncHandler.java:428)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.service.EmailSyncAdapterService$SyncAdapterImpl.syncMailbox(EmailSyncAdapterService.java:866)
04-24 18:31:49.323: E/AndroidRuntime(5222): at com.android.exchange.service.EmailSyncAdapterService$SyncAdapterImpl.onPerformSync(EmailSyncAdapterService.java:781)
04-24 18:31:49.323: E/AndroidRuntime(5222): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:259)
The following also appears in the SOGo log:
2014-04-25 02:32:32.668 sogod[21779] Sleeping 10 seconds while detecting changes...
2014-04-25 02:32:42.709 sogod[21779] Sleeping 10 seconds while detecting changes...
2014-04-25 02:32:52.790 sogod[21779] Sleeping 10 seconds while detecting changes...
Apr 25 02:33:02 sogod [21779]: |SOGo| request took 30.353780 seconds to execute
49.196.128.126 - - [25/Apr/2014:02:33:02 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=as_test%40tribalchicken.com.au&DeviceId=androidc1137557421&DeviceType=Android HTTP/1.1" 200 47/71 30.355 - - 0
Apr 25 02:33:04 sogod [21779]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=as_test%40tribalchicken.com.au&DeviceId=androidc1137557421&DeviceType=Android'
2014-04-25 02:33:04.276 sogod[21779] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.2-EAS-1.3'
Apr 25 02:33:04 sogod [21779]: <0x0x7fe19e1a8178[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
2014-04-25 02:33:04.570 sogod[21779] Sleeping 10 seconds while detecting changes...
Apr 25 02:33:14 sogod [21779]: <0x0x7fe19e1a8178[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
2014-04-25 02:33:14.690 sogod[21779] Sleeping 10 seconds while detecting changes...
Apr 25 02:33:24 sogod [21779]: <0x0x7fe19e1a8178[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
2014-04-25 02:33:24.810 sogod[21779] Sleeping 10 seconds while detecting changes...
Apr 25 02:33:34 sogod [21779]: |SOGo| request took 30.537931 seconds to execute
49.196.128.126 - - [25/Apr/2014:02:33:34 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=as_test%40tribalchicken.com.au&DeviceId=androidc1137557421&DeviceType=Android HTTP/1.1" 200 45/69 30.539 - - 0
Apr 25 02:33:36 sogod [21779]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=as_test%40tribalchicken.com.au&DeviceId=androidc1137557421&DeviceType=Android'
2014-04-25 02:33:36.352 sogod[21779] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.2-EAS-1.3'
2014-04-25 02:33:36.355 sogod[21779] Sleeping 10 seconds while detecting changes...
2014-04-25 02:33:46.356 sogod[21779] Sleeping 10 seconds while detecting changes...
2014-04-25 02:33:56.357 sogod[21779] Sleeping 10 seconds while detecting changes...
Apr 25 02:34:06 sogod [21779]: |SOGo| request took 30.005250 seconds to execute
Interesting that it takes 30 seconds.
Unsure if this is SOGo sending something incorrectly or if it's perhaps Android not interpreting something correctly.
Not 100% sure what data will be useful so let me know if more logs, etc are required.
Workaround is to remove birthday fields from the contacts - Works beautifully once birthday is removed. |