Closed Bug 970832 Opened 11 years ago Closed 11 years ago

[Contacts] Photos of Contacts aren't imported to device

Categories

(Firefox OS Graveyard :: Gaia::Contacts, defect)

Product:
Firefox OS Graveyard
Component:
Gaia::Contacts
Platform:
x86
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(blocking-b2g:1.3+, b2g-v1.3 fixed, b2g-v1.3T fixed, b2g-v1.4 fixed)

Status:
VERIFIED FIXED
Milestone:
1.4 S2 (28feb)
Project Flags:
blocking-b2g 1.3+
Tracking Flags:
Tracking Status
b2g-v1.3 --- fixed
b2g-v1.3T --- fixed
b2g-v1.4 --- fixed

People

(Reporter: lolimartinezcr, Assigned: gerard-majax)

References

Details

(Keywords: dataloss, regression, Whiteboard: [systemsfe] [p=3])

Attachments

(5 files)

logs-gtorodelvalle.txt
2.90 KB, text/plain
Details
Netwerk logs
26.96 KB, text/plain
Details
VID_0029.3gp
5.15 MB, video/3gpp
Details
Link to Github https://github.com/mozilla-b2g/gaia/pull/16721
46 bytes, text/x-github-pull-request
arcturus
: review+
crdlc
: review+
fabrice
: approval-gaia-v1.3+
Details | Review
VID_0001.3gp
6.44 MB, video/3gpp
Details
Tested (02/11/2014) 1.3 Gecko:06f88fa Gaia:00cd1ae Pre-requisites: Email with a lot of contacts created (tested with 1943 contacts) Data conection active Steps: 1. Press contacts aplication. 2. Press "settings" 3. Press "Import" contacts 4. Press "Gmail" option 5. Insert Login and password and press "OK" button (appear a screen "Please hold on..." 6. Select 10 contacts with photo and import it Actual result: Only are imported a few photos some contacts. Expecte result: All photos of contacts should be imported
blocking-b2g: --- → 1.3?
Keywords: regression
I have my doubts this is a bug. Probably the other photos weren't imported due to timeouts
Also tested with Outlook and this bug is reproducible.
Attached file logs-gtorodelvalle.txt —
Although it could be a timeout issue, it is really weird that no matter which 10 contacts with photo I select, I always (which means in 100% of the cases :p) get only 5 of them with photo and the other 5 without it :-S
This bug depend of number of contacts in email server. It is necesary a lot of contacts
Today (02/12/2014) i have tested with 200 contacts in gmail server, and this bug is reproducible 100% 1.3 Gecko: 3820ecd Gaia: 01e9da4 Steps: 1. Press contacts aplication. 2. Press "settings" 3. Press "Import" contacts 4. Press "Gmail" option 5. Insert Login and password and press "OK" button (appear a screen "Please hold on..." 6. Select 10 contacts with photo and import it Actual result: Only are imported a 5 photos contacts. Expecte result: All photos of selected contacts should be imported
Can we check what happens on a 1.1 device?
Keywords: regressionwindow-wanted → qawanted
(In reply to Loli from comment #0) > Tested (02/11/2014) > 1.3 > Gecko:06f88fa > Gaia:00cd1ae > > Pre-requisites: > Email with a lot of contacts created (tested with 1943 contacts) > Data conection active > > Steps: > 1. Press contacts aplication. > 2. Press "settings" > 3. Press "Import" contacts > 4. Press "Gmail" option > 5. Insert Login and password and press "OK" button (appear a screen "Please > hold on..." > 6. Select 10 contacts with photo and import it > Couldn't reproduce it. Followed the STR, took 10 gmail contacts out of a few hundreds, only contacts with pictures, and all 10 of them appear correctly after the import. There's probably another detail causing this bug to happen not sure what.
Tested this bug, with same steps and same email server and it is working (not in 1.3) 1.2 Gecko 7375ace Gaia 724d367
Triage - steps-wanted. We need clearer STR here to move this forward.
Keywords: regressionwindow-wanted → steps-wanted
I was able to reproduce with these STR from comment 0. 1) Open contacts app. 2) Select settings, Import Contacts > Gmail. 3) Make sure the Gmail account has more than 1000 contacts. 4) Select 10 contacts with pictures. 5) Import those contacts. Performing a factory reset after each attempt, 100% repro that some of the contacts will not have their pictures properly imported. Varied from importing 3 - 5 pictures each attempt. 3/3
QA Contact: rkunkel
This issue was found to reproduce in the earliest v1.3 build. 9/19 Environmental Variables: Device: Buri 1.3 MOZ BuildID: 20130919040201 Gaia: 0dedb5b3789afc638a0c7c67652937fcb30e77d2 Gecko: 803189f35921 Version: 27.0a1 Firmware Version: V1.2-device.cfg
Keywords: regressionwindow-wanted
as for triage, we would not block this bug, waiting for regression window.
I have tested with contacts with photo in the account provided by Loli and all the photos were imported. The reported issues might be realted to a 3G issue or due to a Google service problem.
(In reply to David Scravaglieri [:scravag] from comment #12) > as for triage, we would not block this bug, waiting for regression window. Triage disagrees. This is data loss - we're losing pictures randomly on import & it's confirmed to be reproducible. We're blocking this bug.
blocking-b2g: 1.3? → 1.3+
Keywords: dataloss
Assignee: nobody → jmcf
Attached file Netwerk logs —
I've been taking a look at this, and it doesn't seem to be a Gaia bug (although it could probably be mitigated at gaia). The problem is that some connections are being closed with a 0x804B0002 error. I haven't been able to determine why those connections are cancelled though. Even when downloading exactly the same set of contacts they're not cancelled always, and when they're cancelled not always the same set of images are cancelled. Although when they are cancelled, they seem to be cancelled in a batch (so it can fail for 2-8 images that are requested in a sequence). There's another error shown on the log: 02-18 14:06:57.899 I/Gecko ( 1477): nsHttpTransaction::OnSocketStatus [this=0xab1c2b20 status=804b0005 progress=584] 02-18 14:06:57.899 I/Gecko ( 1477): nsHttpTransaction::OnSocketStatus [this=0xab1c2b20 status=804b000a progress=0] Just before each of the failures. Note that those same URIs that fail at that point work some other times (in fact, the more traces I activate the more it seemed to work...).
Component: Gaia::Contacts → Networking: HTTP
Product: Firefox OS → Core
It seems that the problem can be mitigated in Gaia by delaying a bit the burst of requests made to download the contact images. I'm going to provide a patch that can serve to fix this in 1.3 timeframe. Nonetheless, first I would like QA to test it thoroughly before we close this bug and open a new bug for the HTTP component.
(In reply to Jose M. Cantera from comment #16) > It seems that the problem can be mitigated in Gaia by delaying a bit the > burst of requests made to download the contact images. I'm going to provide > a patch that can serve to fix this in 1.3 timeframe. Nonetheless, first I > would like QA to test it thoroughly before we close this bug and open a new > bug for the HTTP component. I rectify myself. The delay solution is not gonna work. As per Antonio's advice We are going to try to fix this in Gecko and as a last resort if we cannot fix it in Gecko will try a workaround in Gaia, for instance, having a retry policy for image requests
removing myself as assignee, would take over if it needs a Gaia patch later.
Assignee: jmcf → nobody
I will try to look into this.
Assignee: nobody → lissyx+mozillians
Whiteboard: [systemsfe]
Target Milestone: --- → 1.4 S2 (28feb)
That may be a long shot, but I'm curious how importing from Google works. I've noticed that at some point on 1.3, I got my Fil@Tours scrapping app broken on some XHR request that relies on resending a cookie and some values.
Flags: needinfo?(jmcf)
Flags: needinfo?(amac)
I think JM told me that importing from Google was failing in the same way, but I only ran tests with Facebook. Anyway, and from the way it was failing, I don't think it's a problem with XHR and or/cookies. It seems to be a underlying problem when making lots of connections concurrently. The import code launches the XHRs on batches on 5 and when it failed it failed a complete batch. From the logs, I would get 5 02-18 14:06:57.899 I/Gecko ( 1477): nsHttpTransaction::OnSocketStatus [this=0xab1c2b20 status=804b0005 progress=584] 02-18 14:06:57.899 I/Gecko ( 1477): nsHttpTransaction::OnSocketStatus [this=0xab1c2b20 status=804b000a progress=0] which then would give five 0x804B0002 errors (which would be propagated to the originating XHR). There is a test I wanted to run but didn't had time which was trying to disable SPDY (according to the logs it was being setup at least) and seeing if the error still happened.
Flags: needinfo?(amac)
The window vs. 1.2 testing doesn't align. Please clarify again if this reproduces on 1.2 or not.
Keywords: qawanted
Flags: needinfo?(jmcf)
I don't know if it's my network or a manifestation of the bug on my Buri running 1.3, but I have a very hard time reaching accounts.google.com.
(In reply to Loli from comment #5) > Today (02/12/2014) i have tested with 200 contacts in gmail server, and this > bug is reproducible 100% > 1.3 > Gecko: 3820ecd > Gaia: 01e9da4 > > Steps: > 1. Press contacts aplication. > 2. Press "settings" > 3. Press "Import" contacts > 4. Press "Gmail" option > 5. Insert Login and password and press "OK" button (appear a screen "Please > hold on..." > 6. Select 10 contacts with photo and import it > > Actual result: > Only are imported a 5 photos contacts. > > Expecte result: > All photos of selected contacts should be imported I don't seem to be able to reproduce on my Buri running 1.3 when connecting to my account. Plus, your description of the actual result is not very clear. I have 100+ contacts, and about half with a photo, and I do see the picture when scrolling the list. It appears correctly when we stop scrolling.
Flags: needinfo?(lolimartinezcr)
Keywords: qawanted
Attached video VID_0029.3gp —
Flags: needinfo?(lolimartinezcr)
I have attached an video, that you can see 9 contacts with photo to import it and only are imported 2 photos (VID_0029.3gp) Email server (Gmail) has a lot of contacts created (1943 contacts) Tested 1.3 Gecko 9eaf096 Gaia dd2e075
(In reply to Loli from comment #26) > I have attached an video, that you can see 9 contacts with photo to import > it and only are imported 2 photos (VID_0029.3gp) > > Email server (Gmail) has a lot of contacts created (1943 contacts) > > Tested 1.3 > Gecko 9eaf096 > Gaia dd2e075 And those two imported photos seems to match the contacts that are first hidden: photos appears when scrolling.
(In reply to Alexandre LISSY :gerard-majax from comment #27) > (In reply to Loli from comment #26) > > I have attached an video, that you can see 9 contacts with photo to import > > it and only are imported 2 photos (VID_0029.3gp) > > > > Email server (Gmail) has a lot of contacts created (1943 contacts) > > > > Tested 1.3 > > Gecko 9eaf096 > > Gaia dd2e075 > > And those two imported photos seems to match the contacts that are first > hidden: photos appears when scrolling. Alexandre, i know that photos appears when scrolling but not more photos have been imported (only two in this case)
Yes, well, sorry for trying to understand what happens, since so far I'm not able to correctly understand what I am supposed to see and what really happens.
Can you try loading some webpages too ? Specifically, the mozilla.org webpage. For now, it seems I reproduce the issue on my Buri only: Buri, Desire Z and Nexus S all connected to the same WiFi network. Only buri is unable to properly load the mozilla.org web page.
Flags: needinfo?(lolimartinezcr)
Hi Antonio, any progress regarding the test you were mentioning in comment 21 regarding disabling SPDY? :-)
Flags: needinfo?(amac)
(In reply to Alexandre LISSY :gerard-majax from comment #30) > Can you try loading some webpages too ? Specifically, the mozilla.org > webpage. > > For now, it seems I reproduce the issue on my Buri only: Buri, Desire Z and > Nexus S all connected to the same WiFi network. Only buri is unable to > properly load the mozilla.org web page. With my buri is enable to properly load the mozilla.org web page.
Flags: needinfo?(lolimartinezcr)
Finally getting some error: E/GeckoConsole( 1308): Content JS ERROR at app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:237 in window.Rest</Rest.prototype.get/xhr.onerror: Error while execu ting HTTP GET: https://www.google.com/m8/feeds/photos/media/XXXXX%40gmail.com/3fdd34ae0a6b7743?access_token=ya29.1.AADtN_WYF6lOZpGmRtVVf6APQyyPJ8lC6sCtzS4A8Jdw50MHvgoqZnEAXF fYIQ : [object XrayWrapper [object ProgressEvent]] E/GeckoConsole( 1308): Content JS ERROR at app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:247 in pictureError: Error while getting picture for contact:
(In reply to gtorodelvalle from comment #31) > Hi Antonio, any progress regarding the test you were mentioning in comment > 21 regarding disabling SPDY? :-) Sorry, didn't had time to look into this still. (In reply to Alexandre LISSY :gerard-majax from comment #33) > Finally getting some error: > E/GeckoConsole( 1308): Content JS ERROR at > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:237 > in window.Rest</Rest.prototype.get/xhr.onerror: Error while execu > ting HTTP GET: > https://www.google.com/m8/feeds/photos/media/XXXXX%40gmail.com/ > 3fdd34ae0a6b7743?access_token=ya29.1. > AADtN_WYF6lOZpGmRtVVf6APQyyPJ8lC6sCtzS4A8Jdw50MHvgoqZnEAXF > fYIQ : [object XrayWrapper [object ProgressEvent]] > E/GeckoConsole( 1308): Content JS ERROR at > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:247 > in pictureError: Error while getting picture for contact: I have been using an OpenC with 1.3 to test this, and that's the error. If you dig more (that is, if you enable logs on netwerk/protocol/http you'll see that the progressevent error is actually a 0x804B0002 error.
Flags: needinfo?(amac)
(In reply to Antonio Manuel Amaya Calvo (:amac) from comment #34) > (In reply to gtorodelvalle from comment #31) > > Hi Antonio, any progress regarding the test you were mentioning in comment > > 21 regarding disabling SPDY? :-) > > Sorry, didn't had time to look into this still. > > (In reply to Alexandre LISSY :gerard-majax from comment #33) > > Finally getting some error: > > E/GeckoConsole( 1308): Content JS ERROR at > > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:237 > > in window.Rest</Rest.prototype.get/xhr.onerror: Error while execu > > ting HTTP GET: > > https://www.google.com/m8/feeds/photos/media/XXXXX%40gmail.com/ > > 3fdd34ae0a6b7743?access_token=ya29.1. > > AADtN_WYF6lOZpGmRtVVf6APQyyPJ8lC6sCtzS4A8Jdw50MHvgoqZnEAXF > > fYIQ : [object XrayWrapper [object ProgressEvent]] > > E/GeckoConsole( 1308): Content JS ERROR at > > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:247 > > in pictureError: Error while getting picture for contact: > > I have been using an OpenC with 1.3 to test this, and that's the error. If > you dig more (that is, if you enable logs on netwerk/protocol/http you'll > see that the progressevent error is actually a 0x804B0002 error. I can't find any trace of an error code 0x804B0002 in the source code.
(In reply to Alexandre LISSY :gerard-majax from comment #35) > (In reply to Antonio Manuel Amaya Calvo (:amac) from comment #34) > > (In reply to gtorodelvalle from comment #31) > > > Hi Antonio, any progress regarding the test you were mentioning in comment > > > 21 regarding disabling SPDY? :-) > > > > Sorry, didn't had time to look into this still. > > > > (In reply to Alexandre LISSY :gerard-majax from comment #33) > > > Finally getting some error: > > > E/GeckoConsole( 1308): Content JS ERROR at > > > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:237 > > > in window.Rest</Rest.prototype.get/xhr.onerror: Error while execu > > > ting HTTP GET: > > > https://www.google.com/m8/feeds/photos/media/XXXXX%40gmail.com/ > > > 3fdd34ae0a6b7743?access_token=ya29.1. > > > AADtN_WYF6lOZpGmRtVVf6APQyyPJ8lC6sCtzS4A8Jdw50MHvgoqZnEAXF > > > fYIQ : [object XrayWrapper [object ProgressEvent]] > > > E/GeckoConsole( 1308): Content JS ERROR at > > > app://communications.gaiamobile.org/contacts/gaia_build_defer_import.js:247 > > > in pictureError: Error while getting picture for contact: > > > > I have been using an OpenC with 1.3 to test this, and that's the error. If > > you dig more (that is, if you enable logs on netwerk/protocol/http you'll > > see that the progressevent error is actually a 0x804B0002 error. > > I can't find any trace of an error code 0x804B0002 in the source code. If http://james-ross.co.uk/mozilla/misc/nserror?0x804B0002 is correct, that's a NS_BINDING_ABORTED error (I assumed as much when looking into this...) and there are lots of places that send a cancel with that value. I added logs for some of them but couldn't find the origin of the error. You can see the detailed logs I got on the attachment from comment#15.
I could gdb into it: Breakpoint 1, mozilla::net::HttpChannelChild::OnStopRequest (this=0x441cf000, statusCode=@0xbecf0910) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:449 449 LOG(("HttpChannelChild::OnStopRequest BAD THINGS HAPPENS")); (gdb) bt #0 mozilla::net::HttpChannelChild::OnStopRequest (this=0x441cf000, statusCode=@0xbecf0910) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:449 #1 0x408f0b30 in mozilla::net::HttpChannelChild::RecvOnStopRequest (this=0x441cf000, statusCode=@0xbecf0910) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:437 #2 0x409cd51a in mozilla::net::PHttpChannelChild::OnMessageReceived (this=0x441cf000, __msg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PHttpChannelChild.cpp:516 #3 0x409b9934 in mozilla::dom::PContentChild::OnMessageReceived (this=0x40442c18, __msg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PContentChild.cpp:3170 #4 0x4098761e in mozilla::ipc::MessageChannel::DispatchAsyncMessage (this=0x40442c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1126 #5 0x40989176 in mozilla::ipc::MessageChannel::DispatchMessage (this=0x40442c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1044 #6 0x4098920e in mozilla::ipc::MessageChannel::OnMaybeDequeueOne (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1027 #7 0x409872ee in DispatchToMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)()> (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/tuple.h:383 #8 RunnableMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)(), Tuple0>::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/task.h:307 #9 0x40987230 in mozilla::ipc::MessageChannel::RefCountedTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:371 #10 mozilla::ipc::MessageChannel::DequeueTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:388 #11 0x4098081c in MessageLoop::RunTask (this=0xbecf17ec, task=0xbecf0dec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:340 #12 0x40981586 in MessageLoop::DeferOrRunPendingTask (this=0x40442c48, pending_task=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:348 #13 0x40982144 in MessageLoop::DoWork (this=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:448 #14 0x4098a6f0 in mozilla::ipc::DoWorkRunnable::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:45 #15 0x4085f144 in nsThread::ProcessNextEvent (this=0x40416880, mayWait=<value optimized out>, result=0xbecf0edf) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #16 0x40833090 in NS_ProcessNextEvent (thread=0x40442c48, mayWait=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #17 0x4098a838 in mozilla::ipc::MessagePump::Run (this=0x40402ac0, aDelegate=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:85 #18 0x4098a906 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40402ac0, aDelegate=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:250 #19 0x409807e0 in MessageLoop::RunInternal (this=0x1000000) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #20 0x4098085e in MessageLoop::RunHandler (this=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #21 MessageLoop::Run (this=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #22 0x40d40414 in nsBaseAppShell::Run (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #23 0x4134a042 in XRE_RunAppShell () at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:679 #24 0x4098a8d4 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40402ac0, aDelegate=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:217 #25 0x409807e0 in MessageLoop::RunInternal (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #26 0x4098085e in MessageLoop::RunHandler (this=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #27 MessageLoop::Run (this=0xbecf17ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #28 0x4134a4b0 in XRE_InitChildProcess (aArgc=-1093723768, aArgv=0xbecf18fc, aProcess=1078209536) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:516 #29 0x00008750 in main (argc=8, argv=0xbecf1984) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/app/MozillaRuntimeMain.cpp:137 (gdb) print statusCode $1 = (const nsresult &) @0xbecf0910: 2152398850
The error code is comming from a SendOnStopRequest() call.
Backtrace on the parent side: Breakpoint 1, mozilla::net::HttpChannelParent::OnStopRequest (this=<value optimized out>, aRequest=<value optimized out>, aContext=<value optimized out>, aStatusCode=0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParent.cpp:514 514 { (gdb) bt #0 mozilla::net::HttpChannelParent::OnStopRequest (this=<value optimized out>, aRequest=<value optimized out>, aContext=<value optimized out>, aStatusCode=0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParent.cpp:514 #1 0x40f79846 in mozilla::net::HttpChannelParentListener::OnStopRequest (this=0x44af2970, aRequest=0x487dac30, aContext=0x0, aStatusCode=0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParentListener.cpp:66 #2 0x40f27746 in nsStreamListenerTee::OnStopRequest (this=0x471b7780, request=0x487dac30, context=0x0, status=0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsStreamListenerTee.cpp:53 #3 0x40f82a8e in mozilla::net::nsHttpChannel::OnStopRequest (this=0x487dac00, request=<value optimized out>, ctxt=<value optimized out>, status=0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/nsHttpChannel.cpp:5178 #4 0x40f1b12e in nsInputStreamPump::OnStateStop (this=0x468a3dc0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsInputStreamPump.cpp:703 #5 0x40f1b4d8 in nsInputStreamPump::OnInputStreamReady (this=0x468a3dc0, stream=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsInputStreamPump.cpp:438 #6 0x40edc042 in nsInputStreamReadyEvent::Run (this=0x471b7220) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/io/nsStreamUtils.cpp:163 #7 0x40ee5144 in nsThread::ProcessNextEvent (this=0x4041e940, mayWait=<value optimized out>, result=0xbee1a75f) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #8 0x40eb9090 in NS_ProcessNextEvent (thread=0x468a3dc0, mayWait=true) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #9 0x4101088c in mozilla::ipc::MessagePump::Run (this=0x40402d30, aDelegate=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:124 #10 0x410067e0 in MessageLoop::RunInternal (this=0x1000001) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #11 0x4100685e in MessageLoop::RunHandler (this=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #12 MessageLoop::Run (this=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #13 0x413c6414 in nsBaseAppShell::Run (this=0x436534c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #14 0x419f5698 in nsAppStartup::Run (this=0x4365b040) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/components/startup/nsAppStartup.cpp:276 #15 0x419cd340 in XREMain::XRE_mainRun (this=0xbee1a994) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4059 #16 0x419cfd12 in XREMain::XRE_main (this=0xbee1a994, argc=<value optimized out>, argv=<value optimized out>, aAppData=0x21170) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4127 #17 0x419cfe7c in XRE_main (argc=1, argv=0xbee1cb74, aAppData=0x21170, aFlags=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4337 #18 0x000098de in do_main (argc=1, argv=0xbee1cb74) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/b2g/app/nsBrowserApp.cpp:163 #19 main (argc=1, argv=0xbee1cb74) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/b2g/app/nsBrowserApp.cpp:256
Alexandre, the backtrace on the parent side is showing a status code of 0, not NS_BINDING_ABORTED.
If you do find the correct backtrace on the parent, it would be worth looking higher in the stack than HTTPChannelParent to see where the status code is coming from.
And thinking out loud some more, looking for any calls to nsHttpChannel::Cancel for the same channel that eventually reports NS_BINDING_ABORTED could be useful.
> 449 LOG(("HttpChannelChild::OnStopRequest BAD THINGS HAPPENS")); There's no such line in HttpChannelChild.cpp, and "hg grep THINGS" is telling me there never has been one in the entire directory. What tree is this built from?
Flags: needinfo?(lissyx+mozillians)
(In reply to Jason Duell (:jduell) from comment #43) > > 449 LOG(("HttpChannelChild::OnStopRequest BAD THINGS HAPPENS")); > > There's no such line in HttpChannelChild.cpp, and "hg grep THINGS" is > telling me there never has been one in the entire directory. What tree is > this built from? Sorry, this is just a local change to make it easier to follow. Tree is gecko 28 for b2g 1.3, checkedout a couple of hours ago.
Flags: needinfo?(lissyx+mozillians)
(In reply to Josh Matthews [:jdm] (on vacation until 2/19) from comment #40) > Alexandre, the backtrace on the parent side is showing a status code of 0, > not NS_BINDING_ABORTED. Gasp you're right, I've been too fast.
I have enabled the IPC logs for the Msg_Cancel, and... I/Gecko ( 5813): [time:1393354860284423][5813][PHttpChannelChild] Sending Msg_Cancel([TODO]) I/Gecko ( 5521): [time:1393354860285010][5521][PHttpChannelParent] Received Msg_Cancel([TODO]) I/Gecko ( 5521): HttpChannelParent::RecvCancel [this=0xa93ed710, status=0x804b0002] it seems that the one actually cancelling the connection is the child process. That's before the child onStopRequest (in fact that onStopRequest is generated from the parent after the cancel is processed). I've added some logs to the HttpChannelChild to try to see why and where it's calling Cancel, but... I haven't been able to make it fail after that. I'll continue tomorrow if nothing new appears here :).
Ah, comment 46 looks crucial. note that it's totally normal for the HttpChannelParent to send an OnStopRequest with status=0 (NS_OK) even though the child sends it a SendCancel (the SendOnStopRequest just probably happened before it got the RecvCancel). Looks like the key here is to figure out what's canceling on the child.
On the parent process, Breakpoint 1, mozilla::net::HttpChannelParent::OnStopRequest (this=0x4877ea90, aRequest=<value optimized out>, aContext=<value optimized out>, aStatusCode=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParent.cpp:519 519 LOG(("HttpChannelChild::OnStopRequest BAD THINGS HAPPENS")); (gdb) bt #0 mozilla::net::HttpChannelParent::OnStopRequest (this=0x4877ea90, aRequest=<value optimized out>, aContext=<value optimized out>, aStatusCode=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParent.cpp:519 #1 0x40f4e872 in mozilla::net::HttpChannelParentListener::OnStopRequest (this=0x4877ea90, aRequest=0x47343430, aContext=0x0, aStatusCode=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelParentListener.cpp:66 #2 0x40efc746 in nsStreamListenerTee::OnStopRequest (this=0x470a7b20, request=0x47343430, context=0x0, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsStreamListenerTee.cpp:53 #3 0x40f57ab6 in mozilla::net::nsHttpChannel::OnStopRequest (this=0x47343400, request=<value optimized out>, ctxt=<value optimized out>, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/nsHttpChannel.cpp:5178 #4 0x40ef012e in nsInputStreamPump::OnStateStop (this=0x470c3340) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsInputStreamPump.cpp:703 #5 0x40ef04d8 in nsInputStreamPump::OnInputStreamReady (this=0x470c3340, stream=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsInputStreamPump.cpp:438 #6 0x40eb1042 in nsInputStreamReadyEvent::Run (this=0x470a7bc0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/io/nsStreamUtils.cpp:163 #7 0x40eba144 in nsThread::ProcessNextEvent (this=0x4041e940, mayWait=<value optimized out>, result=0xbe88475f) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #8 0x40e8e090 in NS_ProcessNextEvent (thread=0x470c3340, mayWait=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #9 0x40fe5860 in mozilla::ipc::MessagePump::Run (this=0x40402d30, aDelegate=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:85 #10 0x40fdb808 in MessageLoop::RunInternal (this=0x1000000) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #11 0x40fdb886 in MessageLoop::RunHandler (this=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #12 MessageLoop::Run (this=0x404470c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #13 0x4139b454 in nsBaseAppShell::Run (this=0x43753520) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #14 0x419ca6f0 in nsAppStartup::Run (this=0x437570a0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/components/startup/nsAppStartup.cpp:276 #15 0x419a2390 in XREMain::XRE_mainRun (this=0xbe884994) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4059 #16 0x419a4d62 in XREMain::XRE_main (this=0xbe884994, argc=<value optimized out>, argv=<value optimized out>, aAppData=0x21170) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4127 #17 0x419a4ecc in XRE_main (argc=1, argv=0xbe886b74, aAppData=0x21170, aFlags=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsAppRunner.cpp:4337 #18 0x000098de in do_main (argc=1, argv=0xbe886b74) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/b2g/app/nsBrowserApp.cpp:163 #19 main (argc=1, argv=0xbe886b74) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/b2g/app/nsBrowserApp.cpp:256
On the child, from HttpChannelChild::Cancel(): Breakpoint 1, mozilla::net::HttpChannelChild::Cancel (this=0x4047e000, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:936 936 LOG(("HttpChannelChild::Cancel BAD THINGS HAPPENS")); (gdb) bt #0 mozilla::net::HttpChannelChild::Cancel (this=0x4047e000, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:936 #1 0x408f0d06 in mozilla::net::HttpChannelChild::OnTransportAndData (this=0x4047e000, status=<value optimized out>, progress=<value optimized out>, progressMax=@0xbee258d0, data=..., offset=@0xbee258d8, count=@0xbee2590c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:413 #2 0x408f0db4 in mozilla::net::HttpChannelChild::RecvOnTransportAndData (this=0x4047e000, status=@0xbee25910, progress=@0xbee258f0, progressMax=<value optimized out>, data=..., offset=@0xbee258d8, count=@0xbee2590c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:343 #3 0x409cd514 in mozilla::net::PHttpChannelChild::OnMessageReceived (this=0x4047e000, __msg=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PHttpChannelChild.cpp:490 #4 0x409b998c in mozilla::dom::PContentChild::OnMessageReceived (this=0x40442c18, __msg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PContentChild.cpp:3170 #5 0x40987676 in mozilla::ipc::MessageChannel::DispatchAsyncMessage (this=0x40442c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1126 #6 0x409891ce in mozilla::ipc::MessageChannel::DispatchMessage (this=0x40442c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1044 #7 0x40989266 in mozilla::ipc::MessageChannel::OnMaybeDequeueOne (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1027 #8 0x40987346 in DispatchToMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)()> (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/tuple.h:383 #9 RunnableMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)(), Tuple0>::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/task.h:307 #10 0x40987288 in mozilla::ipc::MessageChannel::RefCountedTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:371 #11 mozilla::ipc::MessageChannel::DequeueTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:388 #12 0x40980874 in MessageLoop::RunTask (this=0xbee267ec, task=0xbee25dec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:340 #13 0x409815de in MessageLoop::DeferOrRunPendingTask (this=0x40442c48, pending_task=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:348 #14 0x4098219c in MessageLoop::DoWork (this=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:448 #15 0x4098a748 in mozilla::ipc::DoWorkRunnable::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:45 #16 0x4085f144 in nsThread::ProcessNextEvent (this=0x40416880, mayWait=<value optimized out>, result=0xbee25edf) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #17 0x40833090 in NS_ProcessNextEvent (thread=0x40442c48, mayWait=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #18 0x4098a890 in mozilla::ipc::MessagePump::Run (this=0x40402ac0, aDelegate=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:85 #19 0x4098a95e in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40402ac0, aDelegate=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:250 #20 0x40980838 in MessageLoop::RunInternal (this=0x1000000) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #21 0x409808b6 in MessageLoop::RunHandler (this=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #22 MessageLoop::Run (this=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #23 0x40d40494 in nsBaseAppShell::Run (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #24 0x4134a0b2 in XRE_RunAppShell () at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:679 #25 0x4098a92c in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40402ac0, aDelegate=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:217 #26 0x40980838 in MessageLoop::RunInternal (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #27 0x409808b6 in MessageLoop::RunHandler (this=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #28 MessageLoop::Run (this=0xbee267ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #29 0x4134a520 in XRE_InitChildProcess (aArgc=-1092458104, aArgv=0xbee268fc, aProcess=1078209536) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:516 #30 0x00008750 in main (argc=8, argv=0xbee26984) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/app/MozillaRuntimeMain.cpp:137
(gdb) f 2 #2 0x408f0db4 in mozilla::net::HttpChannelChild::RecvOnTransportAndData (this=0x4047e000, status=@0xbee25910, progress=@0xbee258f0, progressMax=<value optimized out>, data=..., offset=@0xbee258d8, count=@0xbee2590c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:343 343 OnTransportAndData(status, progress, progressMax, data, offset, count); (gdb) l 338 if (mEventQ->ShouldEnqueue()) { 339 mEventQ->Enqueue(new TransportAndDataEvent(this, status, progress, 340 progressMax, data, offset, 341 count)); 342 } else { 343 OnTransportAndData(status, progress, progressMax, data, offset, count); 344 } 345 return true; 346 } 347 (gdb) print status $1 = (const nsresult &) @0xbee25910: 2152398854 (gdb) f 1 #1 0x408f0d06 in mozilla::net::HttpChannelChild::OnTransportAndData (this=0x4047e000, status=<value optimized out>, progress=<value optimized out>, progressMax=@0xbee258d0, data=..., offset=@0xbee258d8, count=@0xbee2590c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:413 413 Cancel(rv); (gdb) l 408 409 rv = mListener->OnDataAvailable(this, mListenerContext, 410 stringStream, offset, count); 411 stringStream->Close(); 412 if (NS_FAILED(rv)) { 413 Cancel(rv); 414 } 415 } 416 417 class StopRequestEvent : public ChannelEvent (gdb) print status $2 = <value optimized out> (gdb) print rv $3 = 2152398850
Gerard, the 'status' argument to OnTransportAndData() is a different kind of status (for calling OnStatus(): i.e. values like NS_NET_STATUS_RECEIVING_FROM.). It's not the status of the channel (nor an nsresult). It looks like either NS_NewByteInputStream() is failing, or the listener has returned an error code from OnDataAvailable() (which is equivalent to Cancel()ing the channel, so we call Cancel). Set a breakpoint where we call OnDataAvailable (or better yet, if you know the listener, set it its OnDataAvailable, else you may have to wade through a *lot* of call sites). I suspect something above the necko layer is canceling here, via an error return from ODA.
I started by adding some debug: alex@portable-alex:~/codaz/Mozilla/b2g/devices/Buri/B2G$ grep --color 'mListener->OnDataAvailable' gmail.6.log | grep -c 'returned 0' 65 alex@portable-alex:~/codaz/Mozilla/b2g/devices/Buri/B2G$ grep --color 'mListener->OnDataAvailable' gmail.6.log | grep -c 'returned 804b0002' 99 This is huge :(
(In reply to Jason Duell (:jduell) from comment #51) > Gerard, > > the 'status' argument to OnTransportAndData() is a different kind of status > (for calling OnStatus(): i.e. values like NS_NET_STATUS_RECEIVING_FROM.). > It's not the status of the channel (nor an nsresult). > > It looks like either NS_NewByteInputStream() is failing, or the listener has > returned an error code from OnDataAvailable() (which is equivalent to > Cancel()ing the channel, so we call Cancel). Set a breakpoint where we > call OnDataAvailable (or better yet, if you know the listener, set it its > OnDataAvailable, else you may have to wade through a *lot* of call sites). > > I suspect something above the necko layer is canceling here, via an error > return from ODA. From the logging of necko I have, I can't see anything related to ::OnDataAvailable that appears. Logging is performed by exporting: NSPR_LOG_MODULES=timestamp,nsHttp:5,nsSocketTransport:5,nsStreamPump:5,nsHostResolver:5,nsRedirect:5,nsStandardURL:5
Looks like we have some NS_BINDING_ABORTED that comes from http://dxr.mozilla.org/mozilla-central/source/netwerk/protocol/http/HttpChannelChild.cpp#792 But I only see one call like this, whereas I see a lot of failures.
I see a lot of the errors coming from nsHTTPCompressConv::do_OnDataAvailable(), where there is just a mListener->OnDataAvailable() call :D.
Breakpoint 1, nsHTTPCompressConv::do_OnDataAvailable (this=0x44de1680, request=0x47a18450, context=0x0, offset=0, buffer=0x45013b00 "Photo not found", count=15) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/converters/nsHTTPCompressConv.cpp:343 343 printf_stderr("nsHTTPCompressConv::OnDataAvailable returned 0x804b0002\n"); (gdb) bt #0 nsHTTPCompressConv::do_OnDataAvailable (this=0x44de1680, request=0x47a18450, context=0x0, offset=0, buffer=0x45013b00 "Photo not found", count=15) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/converters/nsHTTPCompressConv.cpp:343 #1 0x407bd14e in nsHTTPCompressConv::OnDataAvailable (this=0x44de1680, request=0x47a18450, aContext=0x0, iStr=<value optimized out>, aSourceOffset=0, aCount=35) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/converters/nsHTTPCompressConv.cpp:271 #2 0x407f0dd2 in mozilla::net::HttpChannelChild::OnTransportAndData (this=0x47a18400, status=<value optimized out>, progress=<value optimized out>, progressMax=@0xbe87d8d0, data=..., offset=@0xbe87d8d8, count=@0xbe87d90c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:417 #3 0x407f0ef0 in mozilla::net::HttpChannelChild::RecvOnTransportAndData (this=0x47a18400, status=@0xbe87d910, progress=@0xbe87d8f0, progressMax=<value optimized out>, data=..., offset=@0xbe87d8d8, count=@0xbe87d90c) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:346 #4 0x408cd75c in mozilla::net::PHttpChannelChild::OnMessageReceived (this=0x47a18400, __msg=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PHttpChannelChild.cpp:490 #5 0x408b9bd4 in mozilla::dom::PContentChild::OnMessageReceived (this=0x40342c18, __msg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PContentChild.cpp:3170 #6 0x408878be in mozilla::ipc::MessageChannel::DispatchAsyncMessage (this=0x40342c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1126 #7 0x40889416 in mozilla::ipc::MessageChannel::DispatchMessage (this=0x40342c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1044 #8 0x408894ae in mozilla::ipc::MessageChannel::OnMaybeDequeueOne (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1027 #9 0x4088758e in DispatchToMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)()> (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/tuple.h:383 #10 RunnableMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)(), Tuple0>::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/task.h:307 #11 0x408874d0 in mozilla::ipc::MessageChannel::RefCountedTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:371 #12 mozilla::ipc::MessageChannel::DequeueTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:388 #13 0x40880abc in MessageLoop::RunTask (this=0xbe87e7ec, task=0xbe87ddec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:340 #14 0x40881826 in MessageLoop::DeferOrRunPendingTask (this=0x40342c48, pending_task=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:348 #15 0x408823e4 in MessageLoop::DoWork (this=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:448 #16 0x4088a990 in mozilla::ipc::DoWorkRunnable::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:45 #17 0x4075f144 in nsThread::ProcessNextEvent (this=0x40316880, mayWait=<value optimized out>, result=0xbe87dedf) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #18 0x40733090 in NS_ProcessNextEvent (thread=0x40342c48, mayWait=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #19 0x4088aad8 in mozilla::ipc::MessagePump::Run (this=0x40302ac0, aDelegate=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:85 #20 0x4088aba6 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40302ac0, aDelegate=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:250 #21 0x40880a80 in MessageLoop::RunInternal (this=0x1000000) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #22 0x40880afe in MessageLoop::RunHandler (this=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #23 MessageLoop::Run (this=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #24 0x40c406dc in nsBaseAppShell::Run (this=0x42ec52e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #25 0x4124a302 in XRE_RunAppShell () at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:679 #26 0x4088ab74 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40302ac0, aDelegate=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:217 #27 0x40880a80 in MessageLoop::RunInternal (this=0x42ec52e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #28 0x40880afe in MessageLoop::RunHandler (this=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #29 MessageLoop::Run (this=0xbe87e7ec) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #30 0x4124a770 in XRE_InitChildProcess (aArgc=-1098389112, aArgv=0xbe87e8fc, aProcess=1077160960) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:516 #31 0x00008750 in main (argc=8, argv=0xbe87e984) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/app/MozillaRuntimeMain.cpp:137
This lead me to http://dxr.mozilla.org/mozilla-central/source/image/src/imgRequest.cpp#830 where we return NS_BINDING_ABORTED.
grgrgrgr: Breakpoint 2, nsHTTPCompressConv::do_OnDataAvailable (this=0x43f39300, request=0x436ae050, context=0x0, offset=0, buffer=0x40384740 "Temporary problem - please try again later and consider using batch operations. The user is over quota.A", count=103) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/converters/nsHTTPCompressConv.cpp:340
Francisco, since you wrote the Gmail importer code, maybe you can help us understanding the architecture and what happens ?
Flags: needinfo?(francisco.jordano)
(In reply to Alexandre LISSY :gerard-majax from comment #58) > grgrgrgr: > > Breakpoint 2, nsHTTPCompressConv::do_OnDataAvailable (this=0x43f39300, > request=0x436ae050, context=0x0, offset=0, > buffer=0x40384740 "Temporary problem - please try again later and > consider using batch operations. The user is over quota.A", count=103) > at > /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/ > converters/nsHTTPCompressConv.cpp:340 That's a 503, according to https://groups.google.com/forum/#!msg/google-contacts-api/e0W9rmlvvVI/kk_XmumWGCwJ so you should be getting that on the XHR as status (and you should not get a BINDING_ABORTED error). Besides, I was testing this with Facebook all the time...
I'm also getting into the image code on other error, "Photo not found": Breakpoint 2, nsHTTPCompressConv::do_OnDataAvailable (this=0x44014400, request=0x4367cc50, context=0x0, offset=0, buffer=0x450138d0 "Photo not found", count=15) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/streamconv/converters/nsHTTPCompressConv.cpp:340 340 offset, count); (gdb) s ProxyListener::OnDataAvailable (this=0x43f229d0, aRequest=0x4367cc50, ctxt=0x0, inStr=0x43646610, sourceOffset=0, count=15) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/image/src/imgLoader.cpp:2108 2108 if (!mDestListener) (gdb) n 2107 { (gdb) 2108 if (!mDestListener) (gdb) 2111 return mDestListener->OnDataAvailable(aRequest, ctxt, inStr, sourceOffset, count); (gdb) s imgRequest::OnDataAvailable (this=0x44d23880, aRequest=0x4367cc50, ctxt=0x0, inStr=0x43646610, sourceOffset=0, count=15) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/image/src/imgRequest.cpp:733 733 {
I had a look at the XHR object we receive when the error happens. It's always for photos requests, and the XHR status field is always 0. This should be the HTTP status code. At first I thought there was some issue with the responseType, since all photos query are done with 'blob', but forcing text does not help.
is the server sending back a 200 but this unexpected text in the body? That's kind of what it sounds like..
I've setup a ssl proxy to intercept the trafic. So far: - I get a bunch of 404 errors on some requests for photos - I see a couple of 503 errors Both have a correct Content-Type header. But, I can't see in the proxy logs the request which returns a status of 0 and that is visible in the logcat. That makes me believe that this one is actually never sent.
Flags: needinfo?(jduell.mcbugs)
Flags: needinfo?(honzab.moz)
XHR with http status 0 at readystate == 4 means there were either a network error (like unknown host, net interrupt, net timeout or reset) or we failed to create the request from some other reason.
Flags: needinfo?(honzab.moz)
For example, CORS failures yield status 0.
> I can't see in the proxy logs the request which returns a status of 0 and that > is visible in the logcat. That makes me believe that this one is actually never sent. It's certainly possible that something cancels the request (or it otherwise fails) before we hit the network. I wish I had something specific to offer as a lead for tracking that down :( But if the logs are clearly showing that to be the case, let's see if we can 1) isolate the failure down to specific URIs/requests and see if they fail reproducibly and without causing network traffic, and maybe we can start to guess where the failure is from the URI/request contents. I don't know XHR well, but IIRC it has some sort of timeout? Is it possible that we're simply launching lots of XHRs with a timeout that expires before we get around to hitting the network for the request? (we only launch 6 HTTP/XHR connections per hostname, so if they're all to the same hostname, the rest will sit in a queue until earlier ones complete).
Flags: needinfo?(jduell.mcbugs)
(In reply to Honza Bambas (:mayhemer) from comment #65) > XHR with http status 0 at readystate == 4 means there were either a network > error (like unknown host, net interrupt, net timeout or reset) or we failed > to create the request from some other reason. Agreed, and since I see no trace of the request in the proxy logs, I would incline to think that we never sent the request.
I've augmented XHR timeouts to some impossible value (250000), but no impact. I noticed that the readyState transitions are differents for requests that succeeds and fails: - successfull request goes through readyState 2 (sent), then 3 (receiving), then 4 (received) - failed request goes through readyState 2 (sent), then 4 (received)
We don't see state 3 because of the request cancelation, that propagates up to http://dxr.mozilla.org/mozilla-central/source/content/base/src/nsXMLHttpRequest.cpp#2153 which calls a transition to the state 4. Backtraceon the child upon this 2 -> 4 transition shows that we are being stopped by a stop request coming from an IPC message from the parent process.
I've added breakpoints everywhere in content/base/src/ where I could see meaningful NS_BINDING_ABORTED calls. I ended with this backtrace: Breakpoint 6, nsImageLoadingContent::CancelImageRequests (this=0x44772320, aNotify=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsImageLoadingContent.cpp:943 943 ClearPendingRequest(NS_BINDING_ABORTED, REQUEST_DISCARD); (gdb) bt #0 nsImageLoadingContent::CancelImageRequests (this=0x44772320, aNotify=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsImageLoadingContent.cpp:943 #1 0x40e5cc0a in mozilla::dom::HTMLInputElement::AfterSetAttr (this=0x447722c0, aNameSpaceID=0, aName=0x42e46de0, aValue=0xbed1ed10, aNotify=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/html/content/src/HTMLInputElement.cpp:1375 #2 0x40dbb888 in mozilla::dom::Element::SetAttrAndNotify (this=0x447722c0, aNamespaceID=0, aName=0x42e46de0, aPrefix=<value optimized out>, aOldValue=..., aParsedValue=..., aModType=2 '\002', aFireMutation=false, aNotify=false, aCallAfterSetAttr=true) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/Element.cpp:1846 #3 0x40dbbbf8 in mozilla::dom::Element::SetAttr (this=0x447722c0, aNamespaceID=0, aName=0x42e46de0, aPrefix=0x0, aValue=..., aNotify=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/Element.cpp:1744 #4 0x40e7d78c in nsGenericHTMLElement::SetAttr (this=0x447722c0, aNameSpaceID=0, aName=0x42e46de0, aPrefix=<value optimized out>, aValue=..., aNotify=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/html/content/src/nsGenericHTMLElement.cpp:961 #5 0x40e7f5b4 in nsGenericHTMLElement::CopyInnerTo (this=<value optimized out>, aDst=0x447722c0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/html/content/src/nsGenericHTMLElement.cpp:300 #6 0x40e5dd10 in mozilla::dom::HTMLInputElement::Clone (this=0x40384f20, aNodeInfo=<value optimized out>, aResult=0xbed1efe8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/html/content/src/HTMLInputElement.cpp:1241 #7 0x40df24ae in nsNodeUtils::CloneAndAdopt (aNode=0x40384f20, aClone=true, aDeep=<value optimized out>, aNewNodeInfoManager=<value optimized out>, aReparentScope=..., aNodesWithProperties=..., aParent=0x470379a0, aResult=0xbed1f070) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsNodeUtils.cpp:450 #8 0x40df27ac in nsNodeUtils::CloneAndAdopt (aNode=0x436a5280, aClone=true, aDeep=<value optimized out>, aNewNodeInfoManager=<value optimized out>, aReparentScope=..., aNodesWithProperties=..., aParent=0x0, aResult=0xbed1f0bc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsNodeUtils.cpp:566 #9 0x40df2ab2 in nsNodeUtils::Clone (aNode=0x436a5280, aDeep=true, aCallUserDataHandlers=true, aResult=0xbed1f0e4) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsNodeUtils.h:156 #10 nsNodeUtils::CloneNodeImpl (aNode=0x436a5280, aDeep=true, aCallUserDataHandlers=true, aResult=0xbed1f0e4) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsNodeUtils.cpp:380 #11 0x40de974c in nsINode::CloneNode (this=0x436a5280, aDeep=true, aError=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsINode.cpp:2627 #12 0x40b1e260 in cloneNode (cx=0x431aac90, obj=..., self=<value optimized out>, args=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/NodeBinding.cpp:785 #13 0x40b14406 in genericMethod (cx=0x431aac90, argc=<value optimized out>, vp=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/NodeBinding.cpp:1412 #14 0x4161a5b8 in CallJSNative (cx=0x431aac90, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jscntxtinlines.h:220 #15 Invoke (cx=0x431aac90, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:463 #16 0x41617920 in Interpret (cx=0x431aac90, state=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:2511 #17 0x4161ba5e in RunScript (cx=0x431aac90, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed1f830, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:420 #18 Invoke (cx=0x431aac90, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed1f830, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:482 #19 Invoke (cx=0x431aac90, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed1f830, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:519 #20 0x415685d0 in JS_CallFunctionValue (cx=0x431aac90, objArg=<value optimized out>, fval=..., argc=1, argv=0xbed1f830, rval=0xbed1f888) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jsapi.cpp:5001 #21 0x40a8e6a6 in mozilla::dom::EventHandlerNonNull::Call (this=0x47024340, cx=0x431aac90, aThisObj=..., event=..., aRv=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/EventHandlerBinding.cpp:35 #22 0x40d32e28 in Call<nsISupports*> (this=0x4714d160, aEvent=0x47011940) at ../../../dist/include/mozilla/dom/EventHandlerBinding.h:60 #23 nsJSEventListener::HandleEvent (this=0x4714d160, aEvent=0x47011940) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/src/events/nsJSEventListener.cpp:238 #24 0x40e439fe in nsEventListenerManager::HandleEventSubType (this=0x47031460, aListenerStruct=<value optimized out>, aDOMEvent=0x47011940, aCurrentTarget=0x4708bf80, aPusher=0xbed1fcb8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.cpp:930 #25 0x40e43c74 in nsEventListenerManager::HandleEventInternal (this=0x47031460, aPresContext=<value optimized out>, aEvent=0x457fd6f0, aDOMEvent=0xbed1fd1c, aCurrentTarget=0x4708bf80, aEventStatus=0xbed1fd20, aPusher=0xbed1fcb8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.cpp:1007 #26 0x40e42230 in nsEventListenerManager::HandleEvent (this=<value optimized out>, aVisitor=<value optimized out>, aCd=<value optimized out>, aPusher=0xbed1fcb8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.h:326 #27 nsEventTargetChainItem::HandleEvent (this=<value optimized out>, aVisitor=<value optimized out>, aCd=<value optimized out>, aPusher=0xbed1fcb8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:197 #28 0x40e4232e in nsEventTargetChainItem::HandleEventTargetChain (aChain=..., aVisitor=..., aCallback=0x0, aCd=<value optimized out>, aPusher=0xbed1fcb8) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:292 #29 0x40e42b98 in nsEventDispatcher::Dispatch (aTarget=<value optimized out>, aPresContext=0x0, aEvent=0x457fd6f0, aDOMEvent=<value optimized out>, aEventStatus=0xbed1fdb4, aCallback=0x0, aTargets=0x0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:609 #30 0x40e42d16 in nsEventDispatcher::DispatchDOMEvent (aTarget=0x4708bf80, aEvent=0x457fd6f0, aDOMEvent=0x47011940, aPresContext=0x0, aEventStatus=0xbed1fdb4) ---Type <return> to continue, or q <return> to quit--- at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:676 #31 0x40cf90d0 in nsWindowRoot::DispatchEvent (this=<value optimized out>, aEvt=<value optimized out>, aRetVal=0xbed1fdcf) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/nsWindowRoot.cpp:80 #32 0x40cd4d82 in mozilla::dom::DOMRequest::DispatchEvent (this=0xbed1fdb4, evt=0x47011940, _retval=0xbed1fdcf) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/DOMRequest.h:31 #33 0x40cd638e in mozilla::dom::DOMRequest::FireEvent (this=0x4708bf80, aType=..., aBubble=false, aCancelable=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/DOMRequest.cpp:186 #34 0x40cd63ec in mozilla::dom::DOMRequest::FireSuccess (this=0x4708bf80, aResult=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/DOMRequest.cpp:126 #35 0x40cd641e in mozilla::dom::DOMRequestService::FireSuccess (this=<value optimized out>, aRequest=<value optimized out>, aResult=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/DOMRequest.cpp:222 #36 0x407620ee in NS_InvokeByIndex (that=<value optimized out>, methodIndex=<value optimized out>, paramCount=<value optimized out>, params=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/reflect/xptcall/src/md/unix/xptcinvoke_arm.cpp:164 #37 0x40c752c4 in CallMethodHelper::Invoke (ccx=<value optimized out>, mode=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/xpconnect/src/XPCWrappedNative.cpp:2567 #38 CallMethodHelper::Call (ccx=<value optimized out>, mode=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1907 #39 XPCWrappedNative::CallMethod (ccx=<value optimized out>, mode=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1873 #40 0x40c793e2 in XPC_WN_CallMethod (cx=0x42e51060, argc=2, vp=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:1301 #41 0x4161a5b8 in CallJSNative (cx=0x42e51060, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jscntxtinlines.h:220 #42 Invoke (cx=0x42e51060, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:463 #43 0x41617920 in Interpret (cx=0x42e51060, state=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:2511 #44 0x4161ba5e in RunScript (cx=0x42e51060, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed20858, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:420 #45 Invoke (cx=0x42e51060, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed20858, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:482 #46 Invoke (cx=0x42e51060, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbed20858, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:519 #47 0x415685d0 in JS_CallFunctionValue (cx=0x42e51060, objArg=<value optimized out>, fval=..., argc=1, argv=0xbed20858, rval=0xbed20860) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jsapi.cpp:5001 #48 0x40de554c in nsFrameMessageManager::ReceiveMessage (this=<value optimized out>, aTarget=<value optimized out>, aMessage=<value optimized out>, aIsSync=<value optimized out>, aCloneData=0xbed20924, aCpows=0xbed20918, aPrincipal=0x0, aJSONRetVal=0x0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/base/src/nsFrameMessageManager.cpp:1020 #49 0x40c14160 in mozilla::dom::ContentChild::RecvAsyncMessage (this=0x40342c18, aMsg=..., aData=..., aCpows=..., aPrincipal=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/ipc/ContentChild.cpp:1232 #50 0x408bb9c8 in mozilla::dom::PContentChild::OnMessageReceived (this=0x40342c18, __msg=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/ipc/ipdl/PContentChild.cpp:4239 #51 0x408878be in mozilla::ipc::MessageChannel::DispatchAsyncMessage (this=0x40342c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1126 #52 0x40889416 in mozilla::ipc::MessageChannel::DispatchMessage (this=0x40342c48, aMsg=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1044 #53 0x408894ae in mozilla::ipc::MessageChannel::OnMaybeDequeueOne (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessageChannel.cpp:1027 #54 0x4088758e in DispatchToMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)()> (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/tuple.h:383 #55 RunnableMethod<mozilla::ipc::MessageChannel, void (mozilla::ipc::MessageChannel::*)(), Tuple0>::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/task.h:307 #56 0x408874d0 in mozilla::ipc::MessageChannel::RefCountedTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:371 #57 mozilla::ipc::MessageChannel::DequeueTask::Run (this=<value optimized out>) at ../../dist/include/mozilla/ipc/MessageChannel.h:388 #58 0x40880abc in MessageLoop::RunTask (this=0xbed217fc, task=0xbed20dfc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:340 #59 0x40881826 in MessageLoop::DeferOrRunPendingTask (this=0x40342c48, pending_task=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:348 #60 0x408823e4 in MessageLoop::DoWork (this=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:448 #61 0x4088a990 in mozilla::ipc::DoWorkRunnable::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:45 #62 0x4075f144 in nsThread::ProcessNextEvent (this=0x40316880, mayWait=<value optimized out>, result=0xbed20eef) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsThread.cpp:612 #63 0x40733090 in NS_ProcessNextEvent (thread=0x40342c48, mayWait=false) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/glue/nsThreadUtils.cpp:263 #64 0x4088aad8 in mozilla::ipc::MessagePump::Run (this=0x40302ac0, aDelegate=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:85 #65 0x4088aba6 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40302ac0, aDelegate=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:250 #66 0x40880a80 in MessageLoop::RunInternal (this=0x1000000) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #67 0x40880afe in MessageLoop::RunHandler (this=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #68 MessageLoop::Run (this=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 ---Type <return> to continue, or q <return> to quit--- #69 0x40c406dc in nsBaseAppShell::Run (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/widget/xpwidgets/nsBaseAppShell.cpp:161 #70 0x4124a372 in XRE_RunAppShell () at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:679 #71 0x4088ab74 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x40302ac0, aDelegate=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/glue/MessagePump.cpp:217 #72 0x40880a80 in MessageLoop::RunInternal (this=0x42ecc2e0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:222 #73 0x40880afe in MessageLoop::RunHandler (this=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:215 #74 MessageLoop::Run (this=0xbed217fc) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/chromium/src/base/message_loop.cc:189 #75 0x4124a7e0 in XRE_InitChildProcess (aArgc=-1093527144, aArgv=0xbed2190c, aProcess=1077160960) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/toolkit/xre/nsEmbedFunctions.cpp:516 #76 0x00008750 in main (argc=8, argv=0xbed21994) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/ipc/app/MozillaRuntimeMain.cpp:137
From frame #16: (gdb) print script.ptr->scriptSource()->filename_ $35 = 0x43614180 "app://communications.gaiamobile.org/contacts/js/views/list.js" (gdb) print *(script.ptr) $33 = {<js::gc::BarrieredCell<JSScript>> = {<js::gc::Cell> = {<No data fields>}, <No data fields>}, static stepFlagMask = <optimized out>, static stepCountMask = <optimized out>, bindings = { callObjShape_ = {<js::BarrieredPtr<js::Shape, unsigned int>> = {{value = 0x43042e08, other = 1124347400}}, <No data fields>}, bindingArrayAndFlag_ = 1142634032, numArgs_ = 1, numVars_ = 2, static TEMPORARY_STORAGE_BIT = 1}, code_ = 0x433fc049 "\210", data = 0x441b3630 "\240\264\374B\241Y\361B\241\005\376B", atoms = 0x433fc0c0, compartment_ = 0x42d37ca0, types = 0x0, sourceObject_ = {<js::BarrieredPtr<JSObject, unsigned int>> = {{value = 0x4302e340, other = 1124262720}}, <No data fields>}, function_ = {<js::BarrieredPtr<JSFunction, unsigned int>> = {{ value = 0x4306ea60, other = 1124526688}}, <No data fields>}, enclosingScopeOrOriginalFunction_ = {<js::BarrieredPtr<JSObject, unsigned int>> = {{value = 0x43067de0, other = 1124498912}}, <No data fields>}, ion = 0x0, baseline = 0x0, parallelIon = 0x0, baselineOrIonRaw = 0x0, baselineOrIonSkipArgCheck = 0x0, length_ = 92, dataSize = 12, lineno = 1368, column = 46, mainOffset = 0, natoms = 4, sourceStart = 41357, sourceEnd = 41824, useCount = 1, PADDING16 = 0, version = 0, funLength = 1, nfixed = 2, nTypeSets = 9, nslots = 7, staticLevel = 2, hasArrayBits = 0 '\000', generatorKindBits_ = 0 '\000', padToByte_ = 0 '\000', noScriptRval = false, savedCallerFun = false, strict = true, explicitUseStrict = false, compileAndGo = true, selfHosted = false, bindingsAccessedDynamically = false, funHasExtensibleScope = false, funNeedsDeclEnvObject = false, funHasAnyAliasedFormal = false, warnedAboutUndefinedProp = false, hasSingletons = false, treatAsRunOnce = false, hasRunOnce = false, hasBeenCloned = true, isActiveEval = false, isCachedEval = false, directlyInsideEval = false, usesArgumentsAndApply = false, shouldCloneAtCallsite = false, isCallsiteClone = false, shouldInline = false, uninlineable = false, failedBoundsCheck = false, failedShapeGuard = false, hadFrequentBailouts = false, invalidatedIdempotentCache = false, isGeneratorExp = false, hasScriptCounts = false, hasDebugScript = false, hasFreezeConstraints = false, argsHasVarBinding_ = false, needsArgsAnalysis_ = false, needsArgsObj_ = false} So this NS_BINDING_ABORTED we catch comes from app://communications.gaiamobile.org/contacts/js/views/list.js:1368:46
is the image code canceling the channels because some response came back with that quota message instead of genuine image data? You ought to be able to find that quota message in the packet capture - necko sure didn't create it.
I'm slightly doubtful that the backtrace above is a culprint, since it's coming from a call to cloneNode (so we clone the attributes on some image input element which triggers the image-related content code to stop any pending image loads). It may be worth stepping through ClearPendingRequest to see what actually happens.
(In reply to Josh Matthews [:jdm] from comment #74) > I'm slightly doubtful that the backtrace above is a culprint, since it's > coming from a call to cloneNode (so we clone the attributes on some image > input element which triggers the image-related content code to stop any > pending image loads). It may be worth stepping through ClearPendingRequest > to see what actually happens. On your suggestion, I added a breakpoint on HttpChannelChild::Cancel(), after loading the list of contacts to sync and checking one, but prior to taping the 'Save' button. The following is the matching backtrace: Breakpoint 12, mozilla::net::HttpChannelChild::Cancel (this=0x43b1e000, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:950 950 if (status == 0x804b0002) { (gdb) bt #0 mozilla::net::HttpChannelChild::Cancel (this=0x43b1e000, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/protocol/http/HttpChannelChild.cpp:950 #1 0x40796a86 in nsLoadGroup::Cancel (this=0x433fcb80, status=2152398850) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/netwerk/base/src/nsLoadGroup.cpp:295 #2 0x4096ac00 in nsDocLoader::Stop (this=0x44367400) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/uriloader/base/nsDocLoader.cpp:268 #3 0x4119b2e2 in nsDocShell::Stop (this=0x0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/docshell/base/nsDocShell.h:177 #4 0x4119ec5a in nsDocShell::Stop (this=0x44367400, aStopFlags=3) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/docshell/base/nsDocShell.cpp:4862 #5 0x40cbf954 in nsGlobalWindow::Stop (this=<value optimized out>, aError=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/nsGlobalWindow.cpp:6511 #6 0x40cbf936 in nsGlobalWindow::Stop (this=<value optimized out>, aError=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/dom/base/nsGlobalWindow.cpp:6507 #7 0x40bcfdb2 in stop (cx=0x44715270, obj=<value optimized out>, self=0x44ffbf10, args=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/WindowBinding.cpp:915 #8 0x40bc537c in genericMethod (cx=0x44715270, argc=<value optimized out>, vp=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/WindowBinding.cpp:10617 #9 0x4161a5b8 in CallJSNative (cx=0x44715270, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jscntxtinlines.h:220 #10 Invoke (cx=0x44715270, args=..., construct=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:463 #11 0x41617920 in Interpret (cx=0x44715270, state=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:2511 #12 0x4161ba5e in RunScript (cx=0x44715270, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbe928850, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:420 #13 Invoke (cx=0x44715270, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbe928850, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:482 #14 Invoke (cx=0x44715270, thisv=<value optimized out>, fval=..., argc=<value optimized out>, argv=0xbe928850, rval=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:519 #15 0x415685d0 in JS_CallFunctionValue (cx=0x44715270, objArg=<value optimized out>, fval=..., argc=1, argv=0xbe928850, rval=0xbe9288a0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/jsapi.cpp:5001 #16 0x40a8e55c in mozilla::dom::EventListener::HandleEvent (this=0x477a2790, cx=0x44715270, aThisObj=..., event=..., aRv=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/objdir-gecko/dom/bindings/EventListenerBinding.cpp:41 #17 0x40e439e8 in HandleEvent<mozilla::dom::EventTarget*> (this=0x45bc84c0, aListenerStruct=<value optimized out>, aDOMEvent=<value optimized out>, aCurrentTarget=0x4493e790, aPusher=0xbe928aa0) at ../../../dist/include/mozilla/dom/EventListenerBinding.h:51 #18 nsEventListenerManager::HandleEventSubType (this=0x45bc84c0, aListenerStruct=<value optimized out>, aDOMEvent=<value optimized out>, aCurrentTarget=0x4493e790, aPusher=0xbe928aa0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.cpp:927 #19 0x40e43c74 in nsEventListenerManager::HandleEventInternal (this=0x45bc84c0, aPresContext=<value optimized out>, aEvent=0xbe928b68, aDOMEvent=0xbe928b04, aCurrentTarget=0x4493e790, aEventStatus=0xbe928b08, aPusher=0xbe928aa0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.cpp:1007 #20 0x40e42230 in nsEventListenerManager::HandleEvent (this=<value optimized out>, aVisitor=<value optimized out>, aCd=<value optimized out>, aPusher=0xbe928aa0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventListenerManager.h:326 #21 nsEventTargetChainItem::HandleEvent (this=<value optimized out>, aVisitor=<value optimized out>, aCd=<value optimized out>, aPusher=0xbe928aa0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:197 #22 0x40e4232e in nsEventTargetChainItem::HandleEventTargetChain (aChain=..., aVisitor=..., aCallback=0x0, aCd=<value optimized out>, aPusher=0xbe928aa0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:292 #23 0x40e42b98 in nsEventDispatcher::Dispatch (aTarget=<value optimized out>, aPresContext=0x436b3400, aEvent=0xbe928b68, aDOMEvent=<value optimized out>, aEventStatus=0xbe928bbc, aCallback=0x0, aTargets=0x0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/content/events/src/nsEventDispatcher.cpp:609 #24 0x41066a88 in mozilla::ScrollFrameHelper::FireScrollEvent (this=0x488b61a0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/generic/nsGfxScrollFrame.cpp:3262 #25 0x41066aa2 in mozilla::ScrollFrameHelper::ScrollEvent::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/generic/nsGfxScrollFrame.cpp:3238 #26 0x410404ce in nsRootPresContext::FlushWillPaintObservers (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsPresContext.cpp:3000 #27 0x40fffc04 in PresShell::WillPaint (this=0x42e69d60) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsPresShell.cpp:7678 #28 0x40d9418e in nsViewManager::CallWillPaintOnObservers (this=0x43392820) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/view/src/nsViewManager.cpp:1083 #29 0x40d94d86 in nsViewManager::ProcessPendingUpdates (this=0x43392820) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/view/src/nsViewManager.cpp:1051 #30 0x4100921a in nsRefreshDriver::Tick (this=0x403d5500, aNowEpoch=1393517927963653, aNowTime=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsRefreshDriver.cpp:1208 #31 0x410094b2 in mozilla::RefreshDriverTimer::TickDriver (aTimer=<value optimized out>, aClosure=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsRefreshDriver.cpp:168 #32 mozilla::RefreshDriverTimer::Tick (aTimer=<value optimized out>, aClosure=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsRefreshDriver.cpp:160 #33 mozilla::RefreshDriverTimer::TimerTick (aTimer=<value optimized out>, aClosure=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/layout/base/nsRefreshDriver.cpp:185 #34 0x40760a26 in nsTimerImpl::Fire (this=0x436132b0) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsTimerImpl.cpp:551 #35 0x40760ad6 in nsTimerEvent::Run (this=<value optimized out>) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/xpcom/threads/nsTimerImpl.cpp:635 ---Type <return> to continue, or q <return> to quit---q Quit (gdb) f 11 #11 0x41617920 in Interpret (cx=0x44715270, state=...) at /home/alex/codaz/Mozilla/b2g/devices/Buri/B2G/gecko/js/src/vm/Interpreter.cpp:2511 2511 if (!Invoke(cx, args)) (gdb) print script $82 = {<js::RootedBase<JSScript*>> = {<No data fields>}, ptr = 0x44ac0d30} (gdb) print script.ptr $83 = (JSScript *) 0x44ac0d30 (gdb) print *(script.ptr) $84 = {<js::gc::BarrieredCell<JSScript>> = {<js::gc::Cell> = {<No data fields>}, <No data fields>}, static stepFlagMask = <optimized out>, static stepCountMask = <optimized out>, bindings = { callObjShape_ = {<js::BarrieredPtr<js::Shape, unsigned int>> = {{value = 0x48a56df0, other = 1218801136}}, <No data fields>}, bindingArrayAndFlag_ = 1077000684, numArgs_ = 0, numVars_ = 0, static TEMPORARY_STORAGE_BIT = 1}, code_ = 0x4563c989 "\210", data = 0x4031b9ec "", atoms = 0x4563ca0c, compartment_ = 0x44ffc0e0, types = 0x43b700e0, sourceObject_ = {<js::BarrieredPtr<JSObject, unsigned int>> = {{value = 0x48a297c0, other = 1218615232}}, <No data fields>}, function_ = {<js::BarrieredPtr<JSFunction, unsigned int>> = {{ value = 0x48a8f620, other = 1219032608}}, <No data fields>}, enclosingScopeOrOriginalFunction_ = {<js::BarrieredPtr<JSObject, unsigned int>> = {{value = 0x48a8f580, other = 1219032448}}, <No data fields>}, ion = 0x0, baseline = 0x0, parallelIon = 0x0, baselineOrIonRaw = 0x0, baselineOrIonSkipArgCheck = 0x0, length_ = 104, dataSize = 0, lineno = 45, column = 21, mainOffset = 0, natoms = 5, sourceStart = 1203, sourceEnd = 1747, useCount = 1, PADDING16 = 0, version = 0, funLength = 0, nfixed = 0, nTypeSets = 13, nslots = 5, staticLevel = 2, hasArrayBits = 0 '\000', generatorKindBits_ = 0 '\000', padToByte_ = 0 '\000', noScriptRval = false, savedCallerFun = false, strict = true, explicitUseStrict = false, compileAndGo = true, selfHosted = false, bindingsAccessedDynamically = false, funHasExtensibleScope = false, funNeedsDeclEnvObject = false, funHasAnyAliasedFormal = false, warnedAboutUndefinedProp = false, hasSingletons = false, treatAsRunOnce = false, hasRunOnce = false, hasBeenCloned = false, isActiveEval = false, isCachedEval = false, directlyInsideEval = false, usesArgumentsAndApply = false, shouldCloneAtCallsite = false, isCallsiteClone = false, shouldInline = false, uninlineable = false, failedBoundsCheck = false, failedShapeGuard = false, hadFrequentBailouts = false, invalidatedIdempotentCache = false, isGeneratorExp = false, hasScriptCounts = false, hasDebugScript = false, hasFreezeConstraints = false, argsHasVarBinding_ = false, needsArgsAnalysis_ = false, needsArgsObj_ = false} (gdb) print *(script.ptr)->scriptSource() $85 = {data = { source = 0x4499b000 u"'use strict';\n\nif (!window.ImageLoader) {\n var ImageLoader = function ImageLoader(pContainer, pItems) {\n var container, items, itemsSelector, lastScrollTime, scrollLatency = 100,\n scrollTim"..., compressed = 0x4499b000 "'"}, refs = 1, length_ = 4409, compressedLength_ = 0, filename_ = 0x44986b50 "app://communications.gaiamobile.org/contacts/js/utilities/image_loader.js", sourceURL_ = 0x0, sourceMapURL_ = 0x0, originPrincipals_ = 0x43bc0fe4, sourceRetrievable_ = false, argumentsNotIncluded_ = false, ready_ = true} So we are getting in this state at app://communications.gaiamobile.org/contacts/js/utilities/image_loader.js:45 https://github.com/mozilla-b2g/gaia/blob/v1.3/apps/communications/contacts/js/utilities/image_loader.js#L45 There we can see that the code does a "window.stop()" call.
I do confirm that commenting the "window.stop()" call makes the import being done correctly. Any of you knows why this code is here ? The comment on it is clearly stating that it does want to stop images from loading.
Flags: needinfo?(jmcf)
Flags: needinfo?(francisco.jordano)
Flags: needinfo?(crdlc)
Flags: needinfo?(bkelly)
Yes, it was done for that reason thought 27 months ago. https://github.com/mozilla-b2g/gaia/commit/f3e8915917804c647452283457b9214d4dcbd995 (2012-12-11)
Flags: needinfo?(crdlc)
Hi, not much to add here, we just perform a 'GET' request to the photo url (adding the valid access_token parameter). That request is make asking for a responseType blob. Also seeing how a whole batch of request (we do batches of 5) is drop. Sorry for not adding more info :(
Hi, not much to add here, we just perform a 'GET' request to the photo url (adding the valid access_token parameter). That request is make asking for a responseType blob. Also seeing how a whole batch of request (we do batches of 5) is drop. Sorry for not adding more info :(
(In reply to Cristian Rodriguez (:crdlc) from comment #77) > Yes, it was done for that reason thought 27 months ago. > > https://github.com/mozilla-b2g/gaia/commit/ > f3e8915917804c647452283457b9214d4dcbd995 (2012-12-11) Can you document more ? What is this onScroll attached to ? Any idea why it's triggered at the end of the import?
Flags: needinfo?(francisco.jordano)
Flags: needinfo?(crdlc)
Going onto the gmail contacts to select those to sync, checking one contact, I'm getting one UIEvent when I tap on 'Save'.
Looks like the imgsLoading condition is broken because of unbalanced ++ and --.
I do have a fix: imgsLoading incrementations and decrementations are unbalanced, causing the window.scroll() to get called and thus killing importations/updating of pictures.
Flags: needinfo?(jmcf)
Flags: needinfo?(francisco.jordano)
Flags: needinfo?(crdlc)
Flags: needinfo?(bkelly)
Component: Networking: HTTP → Gaia::Contacts
Product: Core → Firefox OS
Please find attached a PR that fixes the issue. I found no test on this image_uploader.js code and I barely see how we can test this specific case in such a short time, but if you have any idea, I'd be happy to implement :).
Attachment #8383257 - Flags: review?(etienne)
Comment on attachment 8383257 [details] [review] Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 Changing the reviewer, etienne was suggested by Bugzilla but he's not a peer ...
Attachment #8383257 - Flags: review?(etienne) → review?(francisco.jordano)
Francisco, turns out when I first looked at the code I was probably not thinking clearly. Tests are 100% do-able, I'm updating the PR with some.
Nice work finding this Alexandre! Epic amount of debugging :)
Comment on attachment 8383257 [details] [review] Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 adding Cristian to the review as he was the original author of the image loader component
Attachment #8383257 - Flags: review?(crdlc)
Comment on attachment 8383257 [details] [review] Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 Good job! Thanks a lot and excellent catch! I wrote an additional code on Github that you could add if you're agree with. Thx
Attachment #8383257 - Flags: review?(crdlc) → review+
(In reply to Cristian Rodriguez (:crdlc) from comment #90) > Comment on attachment 8383257 [details] [review] > Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 > > Good job! Thanks a lot and excellent catch! I wrote an additional code on > Github that you could add if you're agree with. Thx Thanks, that is a nice idea I also had while fixing this, I'll add it.
(In reply to Alexandre LISSY :gerard-majax from comment #91) > (In reply to Cristian Rodriguez (:crdlc) from comment #90) > > Comment on attachment 8383257 [details] [review] > > Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 > > > > Good job! Thanks a lot and excellent catch! I wrote an additional code on > > Github that you could add if you're agree with. Thx > > Thanks, that is a nice idea I also had while fixing this, I'll add it. While thinking at it, I think that we should rather do a follow up for this, to reduce the amount of code for v1.3 and limit the risks.
Blocks: 978011
Flags: in-testsuite+
Comment on attachment 8383257 [details] [review] Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 Tried on the phone and working pretty good. Thanks for filling the follow up, I already requested to be fixed in 1.4 time frame. r=me Thanks!
Attachment #8383257 - Flags: review?(francisco.jordano) → review+
Landed on master: https://github.com/mozilla-b2g/gaia/commit/d4d879e7f82e26c1239ae6561edffa6c49faaf6f Great work Alexandre!
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Comment on attachment 8383257 [details] [review] Link to Github https://github.com/mozilla-b2g/gaia/pull/16721 NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings. [Approval Request Comment] [Bug caused by] (feature/regressing bug #): We have that bug while ago, introduced probably in 1.2 when we added the performance works regarding the scrolling in the contact list. [User impact] if declined: Huge, user data lost, since images won't be downloaded. [Testing completed]: Asking for verify, did a smoke test in both master and 1.3 [Risk to taking this patch] (and alternatives if risky): Risk is minimun, as you can see is a simple fix, one line. [String changes made]:
Attachment #8383257 - Flags: approval-gaia-v1.3?(fabrice)
Asking for verifyme so we feel more confortable to uplift to 1.3
Keywords: verifyme
I'm testing with the latest 1.4 and I do not see it working. I have ~30 contacts; only 22 are imported and, of those, about 5 are in my actual gmail contacts(1). Also, there are no pictures imported for the contacts at all. aia 9422aca1931ba6c68784f9e80bb1b6a7fcfd92e3 Gecko https://hg.mozilla.org/mozilla-central/rev/58eca03214a6 BuildID 20140228040203 Version 30.0a1 ro.build.version.incremental=324 ro.build.date=Thu Dec 19 14:04:55 CST 2013
(In reply to John Hammink from comment #97) > I'm testing with the latest 1.4 and I do not see it working. > > I have ~30 contacts; only 22 are imported and, of those, about 5 are in my > actual gmail contacts(1). > Mentioned to John in person - this list is derived from https://www.google.com/contacts, not gtalk. He's double checking this again.
Ok, my bad. I didn't have a good contact list with pictures to test - and I was looking in the wrong place.
This works fine for me on today's trunk build on Buri. I tested this with an account with a 105 contacts & saw my photos preloaded correctly.
Status: RESOLVED → VERIFIED
Keywords: verifyme
Attachment #8383257 - Flags: approval-gaia-v1.3?(fabrice) → approval-gaia-v1.3+
Whiteboard: [systemsfe] → [systemsfe] [p=3]
v1.3: a364889457107f082ab3758502fc241ff0eaa5e6
status-b2g-v1.3: affected → fixed
status-b2g-v1.4: --- → fixed
Attached video VID_0001.3gp —
(In reply to Jason Smith [:jsmith] from comment #100) > This works fine for me on today's trunk build on Buri. I tested this with an > account with a 105 contacts & saw my photos preloaded correctly. With 1951 contacts in gmail server and selecting 10 contacts with photo to import I can't see all photos (Video attached:VID_0001.3gp) Tested Device: Hamachi Platform version: 28.0 Build ID: 20140306111624 GIT Commit: 8aed4faf
Loli, could this be cause of the unstability of last week builds? The video shows weird behaviors I didn't see before.
(In reply to Francisco Jordano [:arcturus] from comment #104) > Loli, could this be cause of the unstability of last week builds? > > The video shows weird behaviors I didn't see before. I have seen this behavior in days before, perhaps it is by unstability of last week but this behavior is in last version build for this reason i have attached video.
(In reply to Loli from comment #105) > (In reply to Francisco Jordano [:arcturus] from comment #104) > > Loli, could this be cause of the unstability of last week builds? > > > > The video shows weird behaviors I didn't see before. > > I have seen this behavior in days before, perhaps it is by unstability of > last week but this behavior is in last version build for this reason i have > attached video. I don't think this is due to the instability earlier this week - that's resolved now. What I think is being seen might align with what I saw - I noticed that the photos for a bunch of contacts right after they were immediately imported didn't initially show up. They took a while performance wise to render, but they did eventually show up.
(In reply to Jason Smith [:jsmith] from comment #106) > (In reply to Loli from comment #105) > > (In reply to Francisco Jordano [:arcturus] from comment #104) > > > Loli, could this be cause of the unstability of last week builds? > > > > > > The video shows weird behaviors I didn't see before. > > > > I have seen this behavior in days before, perhaps it is by unstability of > > last week but this behavior is in last version build for this reason i have > > attached video. > > I don't think this is due to the instability earlier this week - that's > resolved now. > > What I think is being seen might align with what I saw - I noticed that the > photos for a bunch of contacts right after they were immediately imported > didn't initially show up. They took a while performance wise to render, but > they did eventually show up. Actually I was wrong - I can reproduce what Loli is seeing here. I think I know why I didn't reproduce this initially - I tested this via importing all of my contacts, not 10 specifically. When I did 10 specifically, I only got 5 out of 10 contacts with photos. It persists on a phone restart as well. Looks like we need to back out then - this is an incorrect fix. Flagging checkin-needed to backout on all branches.
Status: VERIFIED → RESOLVED
Closed: 11 years ago → 11 years ago
Keywords: checkin-needed
Maybe with both patches, this one and this bug 978011, the problem will disappear
(In reply to Jason Smith [:jsmith] from comment #107) > (In reply to Jason Smith [:jsmith] from comment #106) > > (In reply to Loli from comment #105) > > > (In reply to Francisco Jordano [:arcturus] from comment #104) > > > > Loli, could this be cause of the unstability of last week builds? > > > > > > > > The video shows weird behaviors I didn't see before. > > > > > > I have seen this behavior in days before, perhaps it is by unstability of > > > last week but this behavior is in last version build for this reason i have > > > attached video. > > > > I don't think this is due to the instability earlier this week - that's > > resolved now. > > > > What I think is being seen might align with what I saw - I noticed that the > > photos for a bunch of contacts right after they were immediately imported > > didn't initially show up. They took a while performance wise to render, but > > they did eventually show up. > > Actually I was wrong - I can reproduce what Loli is seeing here. I think I > know why I didn't reproduce this initially - I tested this via importing all > of my contacts, not 10 specifically. When I did 10 specifically, I only got > 5 out of 10 contacts with photos. It persists on a phone restart as well. > > Looks like we need to back out then - this is an incorrect fix. Flagging > checkin-needed to backout on all branches. I did my testing with a couple of contacts, as both of you documents, and I was never able to see the exposed behavior. Are we sure there is no other issue ? It would help a lot if people gave more info like logcat ...
On 1.3 from update.boot2gecko.org on buri: https://drive.google.com/file/d/0B1U1Qmjcn5OOZmVDa1dFS20ycUE/edit?usp=sharing
I'm going to open a followup for this instead of backing this out.
Keywords: checkin-needed
Depends on: 980539
Tested and working Hamachi Platform version: 30.0a1 Build ID: 20140307120944 Git commig 5bc9b5c3
Status: RESOLVED → VERIFIED
(In reply to Loli from comment #112) > Tested and working > Hamachi > Platform version: 30.0a1 > Build ID: 20140307120944 > Git commig > 5bc9b5c3 adding to this comment that once Bug 978011 has been also landed in master this issue can't be reproduced anymore (please refer to comment 108)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: