847178 - NullPointerException at org.mozilla.gecko.sync.CryptoRecord.fromJSONRecord

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Android Sync, defect)

Description

[hermann]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:19.0) Gecko/20100101 Firefox/19.0
Build ID: 20130227155931

Steps to reproduce:

I configured Firefox 20.0 Beta to synchronize Tabs, Passwords,.. with the Mozilla Sync Service (see http://apps.owncloud.com/content/show.php/Mozilla+Sync+Service?content=155251) from owncloud instance. 
I imported my self-signed certificate for ssl and entered the recovery key correctly. I am already synchronizing two Firefox desktop instances.


Actual results:

On first syncronizing the log shows a NullPointerException:
03-03 16:52:03.820 W/GeckoAnnounce(31204): firefox_beta :: GlobalSession :: Aborting sync: Failure fetching meta/global.
03-03 16:52:03.820 W/GeckoAnnounce(31204): java.lang.NullPointerException
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.CryptoRecord.fromJSONRecord(CryptoRecord.java:151)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.MetaGlobal.handleDownloadSuccess(MetaGlobal.java:268)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.MetaGlobal.handleRequestSuccess(MetaGlobal.java:257)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:110)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:261)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:296)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:302)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:167)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at org.mozilla.gecko.sync.net.SyncStorageRecordRequest$1.run(SyncStorageRecordRequest.java:101)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:390)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at java.util.concurrent.FutureTask.run(FutureTask.java:234)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
03-03 16:52:03.820 W/GeckoAnnounce(31204): 	at java.lang.Thread.run(Thread.java:856)
03-03 16:52:03.820 I/GeckoAnnounce(31204): firefox_beta :: GlobalSession :: Not uploading updated meta/global record since there are no engines requesting upload.
03-03 16:52:03.820 I/GeckoAnnounce(31204): firefox_beta :: SyncAdapter :: GlobalSession indicated error.
03-03 16:52:03.820 E/GeckoAnnounce(31204): firefox_beta :: SyncAdapter :: Unknown exception. Aborting sync.


Expected results:

There should be no null pointer exception. All the synchronized data (bookmarks, passwords) should be loaded on the firefox for android

Comment 1

[Nick Alexander :nalexander [he/him]]

I hypothesize that owncloud formats data differently than Android Sync expects, and that we have scope to be more defensive.

Comment 2

[Thomasy]

Attachment: tcpdump package of FxSync

The tcpdump package of FxSync is attached. Hope that will help.

Comment 3

[Nick Alexander :nalexander [he/him]]

(In reply to Thomasy from comment #2)
> Created attachment 761019 [details]
> tcpdump package of FxSync
> 
> The tcpdump package of FxSync is attached. Hope that will help.

Interesting, I'll take a look.

Comment 4

[Thomasy]

(In reply to Nick Alexander :nalexander from comment #3)
> (In reply to Thomasy from comment #2)
> > Created attachment 761019 [details]
> > tcpdump package of FxSync
> > 
> > The tcpdump package of FxSync is attached. Hope that will help.
> 
> Interesting, I'll take a look.

After tracing part of the code I found that the problem is at 

http://dxr.mozilla.org/mozilla-central/source/mobile/android/base/sync/CryptoRecord.java#l151

150    if (jsonRecord.containsKey(KEY_MODIFIED)) {
151      record.lastModified = jsonRecord.getTimestamp(KEY_MODIFIED);
152    }


W/FxSync  (16706): java.lang.NullPointerException
W/FxSync  (16706):      at org.mozilla.gecko.sync.CryptoRecord.fromJSONRecord(CryptoRecord.java:151)
W/FxSync  (16706):      at org.mozilla.gecko.sync.MetaGlobal.handleDownloadSuccess(MetaGlobal.java:269)
W/FxSync  (16706):      at org.mozilla.gecko.sync.MetaGlobal.handleRequestSuccess(MetaGlobal.java:258)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:110)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:261)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:296)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:302)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:167)
W/FxSync  (16706):      at org.mozilla.gecko.sync.net.SyncStorageRecordRequest$1.run(SyncStorageRecordRequest.java:101)
W/FxSync  (16706):      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:390)
W/FxSync  (16706):      at java.util.concurrent.FutureTask.run(FutureTask.java:234)
W/FxSync  (16706):      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
W/FxSync  (16706):      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
W/FxSync  (16706):      at java.lang.Thread.run(Thread.java:856)


http://dxr.mozilla.org/mozilla-central/source/mobile/android/base/sync/ExtendedJSONObject.java#l223

I think that maybe jsonRecord is null.

But I see the other problem that the JSON data of owncloud give 
,"modified":"1370689360.28"} 

instead of 

,"modified":1370689360.28}

will that matter? ( "1370689360.28" instanceof String instead of Double ?)

http://docs.services.mozilla.com/storage/apis-1.1.html#id2

same problem appears at "sortindex"

Comment 5

[Nick Alexander :nalexander [he/him]]

Thanks for doing detective work for us.

> will that matter? ( "1370689360.28" instanceof String instead of Double ?)

I'm afraid this is an issue with the owncloud storage server: both https://docs.services.mozilla.com/storage/apis-1.0.html and https://docs.services.mozilla.com/storage/apis-1.1.html are clear that the "modified" field must be present and should be a number (float, 2 decimal places) and not a string.

Android Sync shouldn't throw an Exception on bad input, but we also shouldn't cater to servers that don't serve the spec API.  I'm going to leave this ticket open, meaning "don't throw an Exception", but I am WONTFIXing parsing strings as floats in Android Sync.  I could be swayed on the latter point, especially because owncloud does work with desktop Firefox.

Comment 6

[Richard Newman [:rnewman]]

(In reply to Nick Alexander :nalexander from comment #5)

> I could be swayed on
> the latter point, especially because owncloud does work with desktop Firefox.

Nope. It just happens that desktop is implemented in JS, so this kind of thing can slip quietly by.

[09:18:04.486] "5" < 3
[09:18:04.488] false

If anything this just points to a lack of error checking in the desktop client, which is a separate bug, rather than a justification for this behavior!

Comment 7

[Nick Alexander :nalexander [he/him]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/632e3a94bd22

Comment 8

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/632e3a94bd22

Comment 9

[meanderingcode]

Attachment: adb trace of continued NullPointerException

The two commits linked thus far in this ticket indicate to me that i should see messages or exceptions about parsing the JSON, but I am still getting the NullPointerException.

I have not done a tcpdump or similar to intercept the JSON that is being received by my device.

I am using latest Firefox Mobile (23.0) from the Google Play Store.  I see that the milestone is version 25, but this was marked resolved three months ago, so i assume that code is in the latest Play Store release?

I, too, am using OwnCloud.  The adb logcat snip i'm uploading was filtered on "FxSync".

Comment 10

[Richard Newman [:rnewman]]

(In reply to meanderingcode from comment #9)

> I am using latest Firefox Mobile (23.0) from the Google Play Store.  I see
> that the milestone is version 25, but this was marked resolved three months
> ago, so i assume that code is in the latest Play Store release?

Target milestone is the release with the fix, unless something like status-firefox24=fixed. You won't get the fix until you're using Firefox 25, which will shortly be Firefox Beta in the Play store.

If you need a fix sooner, you'll need to fix OwnCloud to behave like the mainline Sync server.