Open Bug 1412652 Opened 2 years ago Updated Last month

Intermittent PROCESS-CRASH | remoteautomation.py | application crashed [@ libc.so + 0x1b2d8] [@ libc.so + 0x245c0]

Categories

(Testing :: General, defect, P5, critical)

defect

Tracking

(Not tracked)

REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Not sure what the right component is here but its almost certainly not WebExtensions.
Component: WebExtensions: General → General
Product: Toolkit → Testing
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=180304431&repo=mozilla-central&lineNumber=1575

[task 2018-05-25T18:53:48.750Z] 18:53:48     INFO -  REFTEST INFO | Running with e10s: False
[task 2018-05-25T18:53:48.957Z] 18:53:48     INFO -  launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_PROCESS_LOG=/tmp/tmpIwgMBzpidlog --es env8 NO_EM_RESTART=1 --es args '-no-remote -profile /sdcard/tests/reftest/profile/' --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env2 R_LOG_VERBOSE=1 --es env1 XPCOM_DEBUG_BREAK=stack --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_CRASHREPORTER_NO_REPORT=1 --es env6 R_LOG_DESTINATION=stderr --es env5 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env4 MOZ_IN_AUTOMATION=1 --es env10 R_LOG_LEVEL=6
[task 2018-05-25T18:54:02.600Z] 18:54:02     INFO -  INFO | automation.py | Application pid: 791
[task 2018-05-25T18:56:56.622Z] 18:56:56     INFO -  REFTEST INFO | Reading manifest http://10.0.2.2:8888/../jsreftest/tests/jstests.list
[task 2018-05-25T18:56:56.623Z] 18:56:56     INFO -  REFTEST INFO | Dumping JSON representation of sandbox
[task 2018-05-25T18:56:56.625Z] 18:56:56     INFO -  REFTEST INFO | {"isDebugBuild":true,"xulRuntime":{"widgetToolkit":"android","OS":"Android","XPCOMABI":"arm-eabi-gcc3"},"smallScreen":false,"d2d":false,"dwrite":false,"gpuProcess":false,"azureCairo":false,"azureSkia":true,"skiaContent":true,"azureSkiaGL":1,"contentSameGfxBackendAsCanvas":true,"layersGPUAccelerated":true,"d3d11":false,"d3d9":false,"layersOpenGL":true,"webrender":false,"layersOMTC":true,"advancedLayers":false,"layerChecksEnabled":true,"retainedDisplayList":false,"Android":true,"cocoaWidget":false,"gtkWidget":false,"qtWidget":false,"winWidget":false,"transparentScrollbars":false,"AndroidVersion":18,"AddressSanitizer":false,"webrtc":true,"retainedDisplayLists":false,"compareRetainedDisplayLists":false,"stylo":true,"skiaPdf":false,"release_or_beta":false,"http":{"userAgent":"Mozilla/5.0 (Android 4.3.1; Mobile; rv:62.0) Gecko/62.0 Firefox/62.0","appName":"Mozilla","appVersion":"5.0","platform":"Android 4.3.1","oscpu":"Linux armv7l","misc":"rv:62.0"},"haveTestPlugin":false,"windowsDefaultTheme":false,"nativeThemePref":false,"gpuProcessForceEnabled":false,"prefs":{},"browserIsRemote":false,"asyncPan":true,"usesRepeatResampling":false,"verify":false}
[task 2018-05-25T19:09:57.092Z] 19:09:57     INFO -  Browser unexpectedly found running. Killing...
[task 2018-05-25T19:09:57.093Z] 19:09:57     INFO -  REFTEST TEST-INFO | started process screentopng
[task 2018-05-25T19:09:57.682Z] 19:09:57     INFO -  REFTEST TEST-INFO | screentopng: exit 0
[task 2018-05-25T19:10:13.244Z] 19:10:13  WARNING -  TEST-UNEXPECTED-FAIL | remoteautomation.py | application timed out after 670 seconds withno output
[task 2018-05-25T19:10:13.245Z] 19:10:13     INFO -  INFO | automation.py | Application ran for: 0:16:24.493102
[task 2018-05-25T19:10:13.245Z] 19:10:13     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpIwgMBzpidlog
[task 2018-05-25T19:10:13.559Z] 19:10:13     INFO -  Contents of /data/anr/traces.txt:
[task 2018-05-25T19:10:13.559Z] 19:10:13     INFO -  ----- pid 791 at 2018-05-25 12:09:57 -----
[task 2018-05-25T19:10:13.560Z] 19:10:13     INFO -  Cmd line: org.mozilla.fennec_aurora
[task 2018-05-25T19:10:13.561Z] 19:10:13     INFO -  JNI: CheckJNI is on; workarounds are off; pins=0; globals=285
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
The recent failures recorded here are actually no-output timeouts, as in bug 1414495. They were mis-categorized because of a typo in the error message - bug 1464866.
Status: REOPENED → RESOLVED
Closed: 2 years agoLast year
Resolution: --- → INCOMPLETE
New log file and snippet with the failure:
https://treeherder.mozilla.org/logviewer.html#?job_id=181855173&repo=mozilla-inbound&lineNumber=1263

[task 2018-06-05T09:50:21.490Z] 09:50:21     INFO -  NATIVE THREADS:
[task 2018-06-05T09:50:21.491Z] 09:50:21     INFO -  "<no name>" sysTid=857 nice=0 sched=0/0 cgrp=apps
[task 2018-06-05T09:50:21.491Z] 09:50:21     INFO -    | state=S schedstat=( 5985309 83454647 3 ) utm=0 stm=0 core=0
[task 2018-06-05T09:50:21.491Z] 09:50:21     INFO -  "<no name>" sysTid=858 nice=0 sched=0/0 cgrp=apps
[task 2018-06-05T09:50:21.492Z] 09:50:21     INFO -    | state=S schedstat=( 15475838 25595118 3 ) utm=0 stm=1 core=0
[task 2018-06-05T09:50:21.492Z] 09:50:21     INFO -  "<no name>" sysTid=859 nice=0 sched=0/0 cgrp=apps
[task 2018-06-05T09:50:21.492Z] 09:50:21     INFO -    | state=S schedstat=( 4169955 41882538185 8 ) utm=0 stm=0 core=0
[task 2018-06-05T09:50:21.493Z] 09:50:21     INFO -  "<no name>" sysTid=860 nice=0 sched=0/0 cgrp=apps
[task 2018-06-05T09:50:21.493Z] 09:50:21     INFO -    | state=S schedstat=( 1591839 3506310 1 ) utm=0 stm=0 core=0
[task 2018-06-05T09:50:21.493Z] 09:50:21     INFO -  "<no name>" sysTid=861 nice=0 sched=0/0 cgrp=apps
[task 2018-06-05T09:50:21.493Z] 09:50:21     INFO -    | state=S schedstat=( 127685 4868902 1 ) utm=0 stm=0 core=0
[task 2018-06-05T09:50:21.494Z] 09:50:21     INFO -  ----- end 806 -----
[task 2018-06-05T09:50:21.727Z] 09:50:21     INFO -  /data/tombstones does not exist; tombstone check skipped
[task 2018-06-05T09:50:22.347Z] 09:50:22     INFO -  mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpk0sTEL/17988434-3d73-7e1d-ae59-3606355cc664.dmp /builds/worker/workspace/build/symbols
[task 2018-06-05T09:50:32.404Z] 09:50:32     INFO -  mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/17988434-3d73-7e1d-ae59-3606355cc664.dmp
[task 2018-06-05T09:50:32.405Z] 09:50:32     INFO -  mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/17988434-3d73-7e1d-ae59-3606355cc664.extra
[task 2018-06-05T09:50:32.407Z] 09:50:32  WARNING -  PROCESS-CRASH | remoteautomation.py | application crashed [@ libc.so + 0x1b2d8]
[task 2018-06-05T09:50:32.407Z] 09:50:32     INFO -  Crash dump filename: /tmp/tmpk0sTEL/17988434-3d73-7e1d-ae59-3606355cc664.dmp
[task 2018-06-05T09:50:32.407Z] 09:50:32     INFO -  Operating system: Android
[task 2018-06-05T09:50:32.408Z] 09:50:32     INFO -                    0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l
[task 2018-06-05T09:50:32.409Z] 09:50:32     INFO -  CPU: arm
[task 2018-06-05T09:50:32.409Z] 09:50:32     INFO -       ARMv7 ARM Cortex-A8 features: swp,half,thumb,fastmult,vfpv2,edsp,neon,vfpv3
[task 2018-06-05T09:50:32.409Z] 09:50:32     INFO -       1 CPU
[task 2018-06-05T09:50:32.409Z] 09:50:32     INFO -  GPU: UNKNOWN
[task 2018-06-05T09:50:32.409Z] 09:50:32     INFO -  Crash reason:  SIGABRT
[task 2018-06-05T09:50:32.410Z] 09:50:32     INFO -  Crash address: 0x37e
[task 2018-06-05T09:50:32.410Z] 09:50:32     INFO -  Process uptime: not available
[task 2018-06-05T09:50:32.410Z] 09:50:32     INFO -  Thread 0 (crashed)
[task 2018-06-05T09:50:32.410Z] 09:50:32     INFO -   0  libc.so + 0x1b2d8
[task 2018-06-05T09:50:32.410Z] 09:50:32     INFO -       r0 = 0xfffffffc    r1 = 0xc0186201    r2 = 0xbe887360    r3 = 0xbe887358
[task 2018-06-05T09:50:32.411Z] 09:50:32     INFO -       r4 = 0x2a04f610    r5 = 0x2a04f5e0    r6 = 0x2a04f640    r7 = 0x00000036
[task 2018-06-05T09:50:32.411Z] 09:50:32     INFO -       r8 = 0x00000001    r9 = 0x00007205   r10 = 0x00007206   r12 = 0x00000001
[task 2018-06-05T09:50:32.411Z] 09:50:32     INFO -       fp = 0x00007211    sp = 0xbe887348    lr = 0x4005294f    pc = 0x400422d8
[task 2018-06-05T09:50:32.412Z] 09:50:32     INFO -      Found by: given as instruction pointer in context
[task 2018-06-05T09:50:32.412Z] 09:50:32     INFO -   1  libbinder.so + 0x1b53b
[task 2018-06-05T09:50:32.412Z] 09:50:32     INFO -       sp = 0xbe887354    pc = 0x400f753d
[task 2018-06-05T09:50:32.412Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.412Z] 09:50:32     INFO -   2  libbinder.so + 0x1ba25
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -       sp = 0xbe887390    pc = 0x400f7a27
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -   3  libbinder.so + 0x1e803
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -       sp = 0xbe8873a0    pc = 0x400fa805
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -   4  libbinder.so + 0x1b687
[task 2018-06-05T09:50:32.413Z] 09:50:32     INFO -       sp = 0xbe8873b0    pc = 0x400f7689
[task 2018-06-05T09:50:32.414Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.414Z] 09:50:32     INFO -   5  binder + 0x6a
[task 2018-06-05T09:50:32.414Z] 09:50:32     INFO -       sp = 0xbe8873b4    pc = 0x51aac06c
[task 2018-06-05T09:50:32.414Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.414Z] 09:50:32     INFO -   6  libbinder.so + 0x1bc2d
[task 2018-06-05T09:50:32.415Z] 09:50:32     INFO -       sp = 0xbe887400    pc = 0x400f7c2f
[task 2018-06-05T09:50:32.415Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.415Z] 09:50:32     INFO -   7  libbinder.so + 0x1e707
[task 2018-06-05T09:50:32.416Z] 09:50:32     INFO -       sp = 0xbe887410    pc = 0x400fa709
[task 2018-06-05T09:50:32.416Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.416Z] 09:50:32     INFO -   8  libc.so + 0xd9ab
[task 2018-06-05T09:50:32.417Z] 09:50:32     INFO -       sp = 0xbe887418    pc = 0x400349ad
[task 2018-06-05T09:50:32.417Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.417Z] 09:50:32     INFO -   9  libbinder.so + 0x1e731
[task 2018-06-05T09:50:32.417Z] 09:50:32     INFO -       sp = 0xbe887420    pc = 0x400fa733
[task 2018-06-05T09:50:32.418Z] 09:50:32     INFO -      Found by: stack scanning
[task 2018-06-05T09:50:32.418Z] 09:50:32     INFO -  10  libbinder.so + 0x1848b
[task 2018-06-05T09:50:32.418Z] 09:50:32     INFO -       sp = 0xbe887460    pc = 0x400f448d
[task 2018-06-05T09:50:32.419Z] 09:50:32     INFO -      Found by: stack scanning
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Crash Signature: [@ libc.so + 0x1b2d8] → [@ libc.so + 0x1b2d8] [@ libc.so + 0x245c0]
[task 2018-06-06T18:24:18.821Z] 18:24:18     INFO -  Test root: /sdcard/tests
[task 2018-06-06T18:24:23.293Z] 18:24:23     INFO -  chmod -R 777 /sdcard/tests/reftest/profile: Ignoring Error: args: adb -s emulator-5554 wait-for-device shell chmod -R 777 /sdcard/tests/reftest/profile; echo rc=$?, exitcode: 10, stdout: Unable to chmod /sdcard/tests/reftest/profile: No such file or directory
[task 2018-06-06T18:24:27.630Z] 18:24:27     INFO -  REFTEST INFO | Running with e10s: False
[task 2018-06-06T18:24:27.835Z] 18:24:27     INFO -  launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_PROCESS_LOG=/tmp/tmpNs5HuDpidlog --es env8 NO_EM_RESTART=1 --es args '-no-remote -profile /sdcard/tests/reftest/profile/' --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env2 R_LOG_VERBOSE=1 --es env1 XPCOM_DEBUG_BREAK=stack --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_CRASHREPORTER_NO_REPORT=1 --es env6 R_LOG_DESTINATION=stderr --es env5 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env4 MOZ_IN_AUTOMATION=1 --es env10 R_LOG_LEVEL=6
[task 2018-06-06T18:24:36.760Z] 18:24:36     INFO -  INFO | automation.py | Application pid: 771
[task 2018-06-06T18:25:42.267Z] 18:25:42     INFO -  INFO | automation.py | Application ran for: 0:01:14.636513
[task 2018-06-06T18:25:42.268Z] 18:25:42     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpNs5HuDpidlog
[task 2018-06-06T18:25:42.885Z] 18:25:42     INFO -  /data/tombstones does not exist; tombstone check skipped
[task 2018-06-06T18:25:43.602Z] 18:25:43     INFO -  REFTEST INFO | Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpcVBVrC/638e555a-817b-6c22-fce8-3e1913293a00.dmp /builds/worker/workspace/build/symbols
[task 2018-06-06T18:25:53.697Z] 18:25:53     INFO -  REFTEST INFO | Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/638e555a-817b-6c22-fce8-3e1913293a00.dmp
[task 2018-06-06T18:25:53.698Z] 18:25:53     INFO -  REFTEST INFO | Saved app info as /builds/worker/workspace/build/blobber_upload_dir/638e555a-817b-6c22-fce8-3e1913293a00.extra
[task 2018-06-06T18:25:53.701Z] 18:25:53     INFO -  REFTEST PROCESS-CRASH | remoteautomation.py | application crashed [@ libc.so + 0x245c0]
06-05 02:47:33.045   806   826 I Gecko   : [806, Unnamed thread 52d11080] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 195
06-05 02:47:34.524   806   826 I Gecko:DumpUtils: Fifo watcher disabled via pref.
06-05 02:47:34.865   806   819 D GeckoSearchEngineManager: Found default engine name in list.json.
06-05 02:47:35.015   806   806 D GeckoToolbar: onTabChanged: ADDED
06-05 02:47:35.015   806   806 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: ADDED
06-05 02:47:35.035   806   819 I dalvikvm: Could not find method android.content.Context.getSystemService, referenced from method org.mozilla.gecko.util.ShortcutUtils.createHomescreenIcon26
06-05 02:47:35.035   806   819 W dalvikvm: VFY: unable to resolve virtual method 522: Landroid/content/Context;.getSystemService (Ljava/lang/Class;)Ljava/lang/Object;
06-05 02:47:35.045   806   819 D dalvikvm: VFY: replacing opcode 0x6e at 0x0007
06-05 02:47:35.056   806   819 I dalvikvm: Could not find method android.content.Context.getSystemService, referenced from method org.mozilla.gecko.util.ShortcutUtils.isPinShortcutSupported26
06-05 02:47:35.068   806   819 W dalvikvm: VFY: unable to resolve virtual method 522: Landroid/content/Context;.getSystemService (Ljava/lang/Class;)Ljava/lang/Object;
06-05 02:47:35.068   806   819 D dalvikvm: VFY: replacing opcode 0x6e at 0x000c
06-05 02:47:35.095   806   819 D GeckoTelemetryUploadSer: Telemetry upload feature is disabled by intent (in testing?)
06-05 02:47:35.095   806   819 D GeckoTelemetryCorePingD: Core ping upload disabled by profile config. Returning.
06-05 02:47:35.236   806   806 D GeckoToolbar: onTabChanged: SELECTED
06-05 02:47:35.305   806   806 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: SELECTED
06-05 02:47:36.015   806   806 I Choreographer: Skipped 45 frames!  The application may be doing too much work on its main thread.
06-05 02:48:18.946   806   810 D dalvikvm: GC_CONCURRENT freed 1299K, 18% free 6512K/7884K, paused 13ms+15ms, total 42588ms
06-05 02:48:18.946   806   806 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 42575ms
06-05 02:48:19.116   806   806 I Choreographer: Skipped 2585 frames!  The application may be doing too much work on its main thread.
06-05 02:50:03.534   806   806 I Choreographer: Skipped 6216 frames!  The application may be doing too much work on its main thread.
06-05 02:50:03.544   806   819 E SQLiteLog: (1) no such table: bookmarks
06-05 02:50:03.925   806   806 D GeckoToolbar: onTabChanged: MENU_UPDATED
06-05 02:50:03.925   806   806 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
06-05 02:50:05.725   277   280 D dalvikvm: GC_CONCURRENT freed 668K, 40% free 5547K/9236K, paused 9ms+17ms, total 331ms
06-05 02:50:06.334   806   811 I dalvikvm: threadid=3: reacting to signal 3
06-05 02:50:06.594   806   811 I dalvikvm: Wrote stack traces to '/data/anr/traces.txt'
06-05 02:50:07.725   806   826 I Gecko   : AndroidBridge::Init
06-05 02:50:07.745   806   826 D dalvikvm: GREF has increased to 201
06-05 02:50:07.745   806   826 D GeckoThread: State changed to JNI_READY
06-05 02:50:09.384   806   826 I Gecko   : [806, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/dom/base/nsFrameMessageManager.cpp, line 1329
06-05 02:50:15.185   806   806 W google-breakpad: ExceptionHandler::GenerateDump cloned child 
06-05 02:50:15.194   806   806 W google-breakpad: 896
06-05 02:50:15.194   806   806 W google-breakpad: 
06-05 02:50:15.194   806   806 W google-breakpad: ExceptionHandler::SendContinueSignalToChild sent continue signal to child
06-05 02:50:15.205   896   896 W google-breakpad: ExceptionHandler::WaitForContinueSignal waiting for continue signal...
06-05 02:50:16.564    38    38 D Zygote  : Process 806 terminated by signal (6)
06-05 02:50:16.574   277   289 I ActivityManager: Process org.mozilla.fennec_aurora (pid 806) has died.

Interesting pause in startup between 02:47:35.305 and 02:50:03.544 -- perhaps the timeout evident at 02:50:06.334 was premature? Had we waited a little longer, would this run have succeeded? On the other hand, I don't think this was a normal 370 second timeout, but rather a 2x timeout waiting for get_top_activity.
Summary: Intermittent PROCESS-CRASH | remoteautomation.py | application crashed [@ libc.so + 0x1b2d8] → Intermittent PROCESS-CRASH | remoteautomation.py | application crashed [@ libc.so + 0x1b2d8] [@ libc.so + 0x245c0]
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: Last yearLast year
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
See Also: → 1516860
Status: REOPENED → RESOLVED
Closed: Last year6 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.