Closed Bug 1587692 Opened 6 years ago Closed 6 years ago

Intermittent Tier 2 Android backgrounds/fixed-bg-border-radius.html == backgrounds/fixed-bg-border-radius-ref.html | application timed out after 370 seconds with no output (with crash in RasterImage::DecodeMetadata on null-deref)

Categories

(Core :: Graphics: ImageLib, defect, P5)

Product:
Core
Component:
Graphics: ImageLib
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=270579578&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/A0uYEGU5SNWI9Nfnn2IGog/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/A0uYEGU5SNWI9Nfnn2IGog/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2019-10-09T22:28:31.558Z] 22:21:02 INFO - REFTEST TEST-START | http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius.html == http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius-ref.html
[task 2019-10-09T22:28:31.558Z] 22:21:02 INFO - REFTEST TEST-LOAD | http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius.html | 1749 / 1974 (88%)
[task 2019-10-09T22:28:31.558Z] 22:28:12 INFO - wait for org.mozilla.geckoview.test complete; top activity=org.mozilla.geckoview.test
[task 2019-10-09T22:28:31.558Z] 22:28:12 INFO - org.mozilla.geckoview.test unexpectedly found running. Killing...
[task 2019-10-09T22:28:31.558Z] 22:28:13 INFO - REFTEST TEST-INFO | started process screencap
[task 2019-10-09T22:28:31.558Z] 22:28:13 INFO - REFTEST TEST-INFO | screencap: exit 0
[task 2019-10-09T22:28:31.558Z] 22:28:25 WARNING - TEST-UNEXPECTED-FAIL | http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius.html == http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius-ref.html | application timed out after 370 seconds with no output
[task 2019-10-09T22:28:31.558Z] 22:28:25 INFO - remoteautomation.py | Application ran for: 0:16:47.301622
[task 2019-10-09T22:28:31.558Z] 22:28:26 INFO - REFTEST INFO | Copy/paste: /builds/task_1570658898/workspace/build/linux64-minidump_stackwalk /tmp/tmp6yMg4v/124e0310-6f2f-ccfc-88f0-656db26b496d.dmp /builds/task_1570658898/workspace/build/symbols
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - REFTEST INFO | Saved minidump as /builds/task_1570658898/workspace/build/blobber_upload_dir/124e0310-6f2f-ccfc-88f0-656db26b496d.dmp
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - REFTEST INFO | Saved app info as /builds/task_1570658898/workspace/build/blobber_upload_dir/124e0310-6f2f-ccfc-88f0-656db26b496d.extra
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - REFTEST PROCESS-CRASH | http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius.html == http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius-ref.html | application crashed [@ libc.so + 0x48eb8]
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - Crash dump filename: /tmp/tmp6yMg4v/124e0310-6f2f-ccfc-88f0-656db26b496d.dmp
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - Operating system: Android
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - 0.0.0 Linux 4.4.56-g594d847d09a1 #1 SMP PREEMPT Thu Oct 26 22:34:08 UTC 2017 armv8l
[task 2019-10-09T22:28:31.558Z] 22:28:31 INFO - CPU: arm
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - ARMv1 Qualcomm part(0x51008010) features: half,thumb,fastmult,vfpv2,edsp,neon,vfpv3,tls,vfpv4,idiva,idivt
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - 8 CPUs
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - GPU: UNKNOWN
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Crash reason: SIGABRT
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Crash address: 0x1c37
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Process uptime: not available
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Thread 0 (crashed)
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - 0 libc.so + 0x48eb8
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - r0 = 0xfffffffc r1 = 0xff8d6658 r2 = 0x00000010 r3 = 0xffffffff
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - r4 = 0x00000000 r5 = 0x00000008 r6 = 0x00000000 r7 = 0x0000015a
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - r8 = 0xff8d6658 r9 = 0xeeab28cc r10 = 0x00000000 r12 = 0xff8d6618
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - fp = 0xeeab2880 sp = 0xff8d6608 lr = 0xeeb2179d pc = 0xeeb4eeb8
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Found by: given as instruction pointer in context
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - 1 system@framework@boot-framework.art + 0x39224a
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - sp = 0xff8d662c pc = 0x712a924c
[task 2019-10-09T22:28:31.562Z] 22:28:31 INFO - Found by: stack scanning
[...]

Here's the bit of the log with the actual backtrace for the crash, I think:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=270579578&repo=mozilla-central&lineNumber=18958
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - REFTEST PROCESS-CRASH | http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius.html == http://10.7.205.206:8854/tests/layout/reftests/backgrounds/fixed-bg-border-radius-ref.html | application crashed [@ mozilla::image::RasterImage::DecodeMetadata(unsigned int)]
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Crash dump filename: /tmp/tmp6yMg4v/7699b908-79b2-5c19-62b8-dd6ebaad2c3a.dmp
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Operating system: Android
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - 0.0.0 Linux 4.4.56-g594d847d09a1 #1 SMP PREEMPT Thu Oct 26 22:34:08 UTC 2017 armv8l
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - CPU: arm
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - ARMv1 Qualcomm part(0x51008010) features: half,thumb,fastmult,vfpv2,edsp,neon,vfpv3,tls,vfpv4,idiva,idivt
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - 8 CPUs
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - GPU: UNKNOWN
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Crash address: 0x0
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Process uptime: not available
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Thread 28 (crashed)
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - 0 libxul.so!mozilla::image::RasterImage::DecodeMetadata(unsigned int) [RasterImage.cpp:cad27f93a9869351457fc5d5290777420068e173 : 1267 + 0x22]
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - r0 = 0x00000000 r1 = 0xd22d9e6f r2 = 0xfbb7fe1c r3 = 0xfbb7fe1c
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - r4 = 0x000004f3 r5 = 0x00000000 r6 = 0xbd411780 r7 = 0xe19d2098
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - r8 = 0x00000000 r9 = 0xbc482c40 r10 = 0x80004005 r12 = 0xf1258fb8
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - fp = 0xbd3db940 sp = 0xe19d2078 lr = 0xf211f59d pc = 0xceafedba
[task 2019-10-09T22:28:37.351Z] 22:28:37 INFO - Found by: given as instruction pointer in context
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 1 libxul.so!mozilla::image::RasterImage::OnImageDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) [RasterImage.cpp:cad27f93a9869351457fc5d5290777420068e173 : 949 + 0x7]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xbd411780 r5 = 0x00000000 r6 = 0x00001c48 r7 = 0xe19d20a8
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xeeb9e1b8 r9 = 0xbc482c40 r10 = 0x000000e6 fp = 0xbd3db940
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d20a0 lr = 0xceafeeff pc = 0xceafeeff
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 2 libxul.so!imgRequest::OnDataAvailable(nsIRequest*, nsIInputStream*, unsigned long long, unsigned int) [imgRequest.cpp:cad27f93a9869351457fc5d5290777420068e173 : 1061 + 0x1b]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xceafeec1 r5 = 0x00000000 r6 = 0x00001c48 r7 = 0xe19d21d8
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xeeb9e1b8 r9 = 0xbc482c40 r10 = 0x000000e6 fp = 0xbd3db940
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d20b0 lr = 0xceb22ae1 pc = 0xceb22ae1
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 3 libxul.so!mozilla::net::HttpChannelChild::DoOnDataAvailable(nsIRequest*, nsISupports*, nsIInputStream*, unsigned long long, unsigned int) [HttpChannelChild.cpp:cad27f93a9869351457fc5d5290777420068e173 : 987 + 0x11]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xbe344800 r5 = 0x00001c48 r6 = 0xeeb9e1b8 r7 = 0xe19d2218
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xbc482c40 r9 = 0xbe344850 r10 = 0x00000000 fp = 0x000003b8
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d21e0 lr = 0xce2b5c0f pc = 0xce2b5c0f
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 4 libxul.so!mozilla::net::HttpChannelChild::OnTransportAndData(nsresult const&, nsresult const&, unsigned long long const&, unsigned int const&, nsTString<char> const&) [HttpChannelChild.cpp:cad27f93a9869351457fc5d5290777420068e173 : 876 + 0x17]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xbe344800 r5 = 0xe19d2248 r6 = 0x00000000 r7 = 0xe19d22a0
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xbe5490c0 r9 = 0xeeb9e1b8 r10 = 0xbe5490b0 fp = 0xbe5490c8
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d2220 lr = 0xce2b7e67 pc = 0xce2b7e67
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 5 libxul.so!mozilla::net::TransportAndDataEvent::Run() [HttpChannelChild.cpp:cad27f93a9869351457fc5d5290777420068e173 : 734 + 0x15]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xbd48b700 r5 = 0xbd48b71c r6 = 0xe19d22d0 r7 = 0xe19d22b0
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xe19d22c8 r9 = 0x00000000 r10 = 0xe19d22d4 fp = 0x00000000
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d22a8 lr = 0xce2daee7 pc = 0xce2daee7
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 6 libxul.so!mozilla::net::ChannelEventQueue::FlushQueue() [ChannelEventQueue.cpp:cad27f93a9869351457fc5d5290777420068e173 : 90 + 0xb]
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r4 = 0xbd48b700 r5 = 0xbd48b71c r6 = 0xe19d22d0 r7 = 0xe19d2300
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - r8 = 0xe19d22c8 r9 = 0x00000000 r10 = 0xe19d22d4 fp = 0x00000000
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - sp = 0xe19d22b8 lr = 0xce34d63b pc = 0xce34d63b
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - Found by: call frame info
[task 2019-10-09T22:28:37.354Z] 22:28:37 INFO - 7 libxul.so!mozilla::net::ChannelEventQueue::MaybeFlushQueue() [ChannelEventQueue.h:cad27f93a9869351457fc5d5290777420068e173 : 314 + 0x5]

Component: Layout → ImageLib
Summary: Intermittent Tier 2 Android backgrounds/fixed-bg-border-radius.html == backgrounds/fixed-bg-border-radius-ref.html | application timed out after 370 seconds with no output → Intermittent Tier 2 Android backgrounds/fixed-bg-border-radius.html == backgrounds/fixed-bg-border-radius-ref.html | application timed out after 370 seconds with no output (with crash in RasterImage::DecodeMetadata on null-deref)

If the crashing line is correct it is this

https://searchfox.org/mozilla-central/rev/5e830ac8f56fe191cb58a264e01cdbf6b6e847bd/image/RasterImage.cpp#1267

MOZ_ASSERT(!mHasSize, "Should not do unnecessary metadata decodes");

inside DecodeMetadata. DecodeMetadata is called off main thread via the stack here, ie when we get a OnDataAvailable call. It is also called on main thread from OnStopRequest. So potentially if crashing thread here had OnDataAvailable called on it and then it gets suspended or context switched away from before it gets to the DecodeMetadata call, and then the main thread gets OnStopRequest and starts and finishes a metadata decode we could hit this. That would require that the networking layer can deliver OnStopRequest before the last OnDataAvailable call returns, which I do not know if that is the case or not.

If it is the case then we need more synchronization in RasterImage.

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.