View Issue Details

IDProjectCategoryView StatusLast Update
0002733SOGoActiveSyncpublic2014-04-24 08:00
Reportertribalchicken Assigned Toludovic  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
Platform[Client] GoogleOSAndroidOS VersionKit Kat
Product Versionnightly v2 
Fixed in Version2.2.4 
Summary0002733: Contacts with "birthday" field causes Exchange service on Android 4.4.2 to crash
Description

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.

Steps To Reproduce

Using Android 4.4.2, I can reproduce this by adding a birthday to any contact. Removing the birthday allows the contacts to sync just fine.

Additional Information

sogo-activesync-2.2.3.20140424-1.centos6.x86_64
sogo-2.2.3.20140424-1.centos6.x86_64
sope49-xml-4.9-20140404_1664.el6.1.x86_64
sope49-appserver-4.9-20140404_1664.el6.1.x86_64
sope49-gdl1-contentstore-2.2.3.20140424-1.centos6.x86_64
sope49-core-4.9-20140404_1664.el6.1.x86_64
sope49-gdl1-4.9-20140404_1664.el6.1.x86_64
sope49-gdl1-mysql-4.9-20140404_1664.el6.1.x86_64
sope49-ldap-4.9-20140404_1664.el6.1.x86_64
sope49-sbjson-2.3.1-20140404_1664.el6.1.x86_64
sope49-mime-4.9-20140404_1664.el6.1.x86_64
sope49-cards-2.2.3.20140424-1.centos6.x86_64

TagsNo tags attached.

Activities

ludovic

ludovic

2014-04-24 08:00

administrator   ~0006957

Fix pushed:

https://github.com/inverse-inc/sogo/commit/ba7b65cf7bd15425ee9eab1e3e94e52ba54d4df9

Please try the upcoming nightly build (or build it yourself to test) and report your findings.

Issue History

Date Modified Username Field Change
2014-04-24 07:15 tribalchicken New Issue
2014-04-24 08:00 ludovic Note Added: 0006957
2014-04-24 08:00 ludovic Status new => closed
2014-04-24 08:00 ludovic Assigned To => ludovic
2014-04-24 08:00 ludovic Resolution open => fixed
2014-04-24 08:00 ludovic Fixed in Version => 2.2.4