New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 710591 link

Starred by 2 users

Issue metadata

Status: Verified
Owner:
Closed: Nov 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 1
Type: Bug



Sign in to add a comment

Tracing broadcast crashes GPU process with UnsatisfiedLinkError

Project Member Reported by klausw@chromium.org, Apr 11 2017

Issue description

Chrome Version: ToT 59.0.3068.0 + 2b4707869c4c04d0e32a10217eaf422a42f1c95b
OS: Android

What steps will reproduce the problem?
(1) Open https://webvr.info/samples/03-vr-presentation.html
(2) Click "Enter VR"
(3) Do a trace from command line: 
$ build/android/adb_profile_chrome --browser chromium --time 2

What is the expected result?
Trace is collected as usual

What happens instead?

GPU process crashes in TracingBroadcastReceiver.onReceive:

https://cs.chromium.org/chromium/src/content/public/android/java/src/org/chromium/content/browser/TracingControllerAndroid.java?l=280

java.lang.UnsatisfiedLinkError: No implementation found for java.lang.String org.chromium.content.browser.TracingControllerAndroid.nativeGetDefaultCategories() (tried Java_org_chromium_content_browser_TracingControllerAndroid_nativeGetDefaultCategories and Java_org_chromium_content_browser_TracingControllerAndroid_nativeGetDefaultCategories__)


I'm not sure what's different as far as tracing is concerned during VR presentation, but apparently the broadcast ends up being handled by the GPU process which doesn't have the necessary native libraries loaded.

I've worked around it by adding a try..catch(java.lang.UnsatisfiedLinkError) block around the onReceive method. 
 

Comment 1 by klausw@chromium.org, Apr 12 2017

Proposed workaround in http://crrev.com/2809043005 .

Tracing actually works fine, I see data from CrGpuMain in the output. The
problem seems to be the broadcast for getting categories. With my patch in
place, I get an identical list of categories including "gpu" when running
"build/android/adb_profile_chrome --browser chromium -c list".

Below is an extract from a logfile with the workaround included, the full log is attached.

04-12 10:19:42.216  1074  2033 I ActivityManager: Start proc 15229:org.chromium.chrome:privileged_process0/u0a115 for service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService0

04-12 10:19:42.273 15229 15229 I cr_CommandLineInitUtil: Using alternative command line file in /data/local/tmp/chrome-command-line
04-12 10:19:42.276 15229 15229 I cr_ChildProcessService: Creating new ChildProcessService pid=15229

04-12 10:20:02.934 15557 15557 D AndroidRuntime: Calling main entry com.android.commands.am.Am
04-12 10:20:02.942  1074 15300 E ActivityManager: Sending non-protected broadcast org.chromium.chrome.GPU_PROFILER_LIST_CATEGORIES from system uid 0 pkg null
04-12 10:20:02.942  1074 15300 E ActivityManager: java.lang.Throwable
04-12 10:20:02.942  1074 15300 E ActivityManager:       at com.android.server.am.ActivityManagerService.checkBroadcastFromSystem(ActivityManagerService.java:17932)
04-12 10:20:02.942  1074 15300 E ActivityManager:       at com.android.server.am.ActivityManagerService.broadcastIntentLocked(ActivityManagerService.java:18499)
04-12 10:20:02.942  1074 15300 E ActivityManager:       at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:18590)
04-12 10:20:02.942  1074 15300 E ActivityManager:       at android.app.ActivityManagerNative.onTransact(ActivityManagerNative.java:499)
04-12 10:20:02.942  1074 15300 E ActivityManager:       at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2806)
04-12 10:20:02.942  1074 15300 E ActivityManager:       at android.os.Binder.execTransact(Binder.java:565)
04-12 10:20:02.955 15229 15229 E art     : No implementation found for long org.chromium.content.browser.TracingControllerAndroid.nativeInit() (tried Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit and Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit__)
04-12 10:20:02.956 15229 15229 W cr_TracingController: onReceive(action=org.chromium.chrome.GPU_PROFILER_LIST_CATEGORIES) failed: java.lang.UnsatisfiedLinkError: No implementation found for long org.chromium.content.browser.TracingControllerAndroid.nativeInit() (tried Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit and Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit__)
04-12 10:20:02.956 15229 15229 W cr_TracingController: java.lang.UnsatisfiedLinkError: No implementation found for long org.chromium.content.browser.TracingControllerAndroid.nativeInit() (tried Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit and Java_org_chromium_content_browser_TracingControllerAndroid_nativeInit__)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at org.chromium.content.browser.TracingControllerAndroid.nativeInit(Native Method)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at org.chromium.content.browser.TracingControllerAndroid.initializeNativeControllerIfNeeded(TracingControllerAndroid.java:162)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at org.chromium.content.browser.TracingControllerAndroid$TracingBroadcastReceiver.onReceive(TracingControllerAndroid.java:2237)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:1122)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at android.os.Handler.handleCallback(Handler.java:751)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at android.os.Handler.dispatchMessage(Handler.java:95)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at android.os.Looper.loop(Looper.java:154)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at android.app.ActivityThread.main(ActivityThread.java:6121)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at java.lang.reflect.Method.invoke(Native Method)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:889)
04-12 10:20:02.956 15229 15229 W cr_TracingController:  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:779)
04-12 10:20:02.962 15557 15557 D AndroidRuntime: Shutting down VM
04-12 10:20:03.073 15163 15163 W chromium: [WARNING:tracing_controller_android.cc(109)] {"traceCategoriesList": ["Blob","IndexedDB","Java","ServiceWorker","WebCore,benchmark,rail","audio","benchmark","benchmark,latencyInfo,rail","benchmark,rail","blink","blink,benchmark","blink,benchmark,rail,disabled-by-default-blink.debug.layout","blink,blink_style","blink,devtools.timeline","blink,loader","blink,loading","blink,rail","blink.net","blink.user_timing","blink.user_timing,rail","blink_gc","blink_gc,devtools.timeline","browser","browser,navigation","browser,startup","cc","cc,benchmark","cc,disabled-by-default-devtools.timeline","cdp.perf","compositor","devtools.timeline","devtools.timeline,rail","devtools.timeline,v8","devtools.timeline.async","disabled-by-default-blink.debug","disabled-by-default-blink.debug.layout","disabled-by-default-blink.debug.layout.trees","disabled-by-default-blink.feature_usage","disabled-by-default-blink.invalidation","disabled-by-default-blink_gc","disabled-by-default-cc.debug","disabled-by-default-cc.debug,disabled-by-default-cc.debug.quads,disabled-by-default-devtools.timeline.layers","disabled-by-default-cc.debug.cdp-perf","disabled-by-default-cc.debug.display_items","disabled-by-default-cc.debug.display_items,disabled-by-default-cc.debug.picture,disabled-by-default-devtools.timeline.picture","disabled-by-default-cc.debug.overdraw","disabled-by-default-cc.debug.quads","disabled-by-default-cc.debug.scheduler","disabled-by-default-cc.debug.scheduler.frames","disabled-by-default-cc.debug.scheduler.now","disabled-by-default-compositor-worker","disabled-by-default-devtools.timeline","disabled-by-default-devtools.timeline.frame","disabled-by-default-devtools.timeline.invalidationTracking","disabled-by-default-devtools.timeline.stack","disabled-by-default-file","disabled-by-default-gpu.debug","disabled-by-default-gpu.device","disabled-by-default-gpu.service","disabled-by-default-gpu_decoder","disabled-by-default-ipc.flow","disabled-by-default-loading","disabled-by-default-memory-infra","disabled-by-default-net","disabled-by-default-network","disabled-by-default-renderer.scheduler","disabled-by-default-renderer.scheduler.debug","disabled-by-default-skia","disabled-by-default-system_stats","disabled-by-default-toplevel.flow","disabled-by-default-v8.compile","disabled-by-default-v8.cpu_profiler","disabled-by-default-v8.cpu_profiler.hires","disabled-by-default-v8.gc","disabled-by-default-v8.gc_stats","disabled-by-default-v8.ic_stats","disabled-by-default-v8.runtime","disabled-by-default-v8.runtime_stats","disabled-by-default-v8.runtime_stats_sampling","disabled-by-default-worker.scheduler","disabled-by-default-worker.scheduler.debug","event","gpu","gpu,startup","input","input,benchmark","input,benchmark,devtools.timeline","input,benchmark,rail","input,rail","io","ipc","ipc,toplevel","jni","leveldb","loader","loading","loading,devtools.timeline","media","mojom","native","navigation","navigation,benchmark,rail","navigation,rail","netlog","rail","rail,devtools.timeline","renderer","renderer,benchmark,rail","renderer.scheduler","renderer_host","renderer_host,navigation","service_manager","skia","startup","startup,benchmark,rail","startup,rail","task_scheduler","test_fps,benchmark","test_gpu","test_tracing","ui","v8","v8,devtools.timeline","v8.execute"]}

log-unsatisfiedlinkerror.txt
108 KB View Download

Comment 2 by klausw@chromium.org, Apr 12 2017

Cc: skyos...@chromium.org
Components: Speed>Tracing

Comment 4 by klausw@chromium.org, Apr 13 2017

Cc: primiano@chromium.org
The one unusual thing I can think of for WebVR's use of the GL process is that it creates a separate context in the browser process via content::Compositor::CreateContextProvider as introduced in http://crrev.com/2731833002. See https://cs.chromium.org/chromium/src/chrome/browser/android/vr_shell/mailbox_to_surface_bridge.cc?q=mailboxtosurfa+package:%5Echromium$&l=206 .

I was under the impression that this only creates a new IPC channel to the existing GPU process, is it possible that this has unexpected side effects?
Components: -Platform>DevTools>Tracing
Cc: -vr-bugs@chromium.org aelias@chromium.org
In https://codereview.chromium.org/2809043005/#msg8, primiano@ wrote:
>Also, hold on, how do we end up hitting
>content/**browser**/TracingControllerAndroid.java in the GPU process in the
>first place?

It is included in content/public here: https://cs.chromium.org/chromium/src/content/public/android/java/src/org/chromium/content/app/ContentApplication.java?type=cs&q=TracingControllerAndroid&sq=package:chromium&l=14

This seems wrong, but I didn't find a path that would get it into the GPU process. However, the crashing process is started as org.chromium.content.app.PrivilegedProcessService0 as shown in the log above.
https://cs.chromium.org/chromium/src/content/public/android/java/src/org/chromium/content/app/ContentApplication.java?type=cs&q=TracingControllerAndroid&sq=package:chromium&l=14
That one seems to be just about the shell (i.e. that should really be the browser process). I can't see how that explains TracingControllerAndroid to be hit by the gpu pocess.

> However, the crashing process is started as org.chromium.content.app.PrivilegedProcessService0 as shown in the log above.
Well somebody should probably investigate this then instead of adding a blanket try...catch. It is possible that a more substantial bug is hiding under the hoods in the VR ap.
Can you try adding an assert in the ctor of TracingControllerAndroid so we can see where that is instantiated from in the gpu process?
Labels: -M-59 M-60

Comment 9 by klausw@chromium.org, May 23 2017

Since this crash seems to happen only in WebVR mode and not in VrShell mode, I'm suspecting it's related to the way WebVR establishes a GPU command buffer channel.

For background, WebVR's MailboxToSurfaceBridge uses Android compositor's CreateContextProvider as introduced in https://codereview.chromium.org/2731833002 . It's possible we're the only users of this API call at this point, and that it's doing something strange.

Call sequence:
https://cs.chromium.org/chromium/src/chrome/browser/android/vr_shell/mailbox_to_surface_bridge.cc?type=cs&q=CreateContextProvider+package:%5Echromium$&l=207

https://cs.chromium.org/chromium/src/content/browser/renderer_host/compositor_impl_android.cc?type=cs&q=CreateContextProvider+package:%5Echromium$&l=393

This is just a hypothesis at this point, but I think it's the main GPU related code that is used in WebVR but not VrShell for 2D browsing.
Cc: amp@chromium.org khushals...@chromium.org
+khushalsagar, do you think it's possible that the new CreateContextProvider and its call to EstablishGPUChannel may be doing something weird that could break tracing? See previous comment.
The path that this call uses is the same that the non-VR mode uses in Clank for creating a GPU command buffer.
Here's what I'm seeing.

When we start up, we have several ContentApplications created (seemingly a random number of them, but usually 2-3, sometimes 4 or more):
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at org.chromium.content.app.ContentApplication.<init>(ContentApplication.java:33)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at org.chromium.content.app.ContentApplication.<init>(ContentApplication.java:27)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at org.chromium.chrome.browser.ChromeApplication.<init>(ChromeApplication.java:36)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at java.lang.Class.newInstance(Native Method)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.Instrumentation.newApplication(Instrumentation.java:1101)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.Instrumentation.newApplication(Instrumentation.java:1086)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.LoadedApk.makeApplication(LoadedApk.java:942)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.ActivityThread.handleBindApplication(ActivityThread.java:5764)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.ActivityThread.-wrap1(Unknown Source:0)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1661)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.os.Handler.dispatchMessage(Handler.java:105)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.os.Looper.loop(Looper.java:164)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at android.app.ActivityThread.main(ActivityThread.java:6540)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at java.lang.reflect.Method.invoke(Native Method)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
05-25 16:38:46.106 21029 21029 E cr_billorr: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)

These each handle an onCreate method call, and registers an onIdle callback.
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at org.chromium.content.app.ContentApplication.onCreate(ContentApplication.java:46)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at org.chromium.chrome.browser.ChromeApplication.onCreate(ChromeApplication.java:63)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1118)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.app.ActivityThread.handleBindApplication(ActivityThread.java:5790)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.app.ActivityThread.-wrap1(Unknown Source:0)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1661)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.os.Handler.dispatchMessage(Handler.java:105)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.os.Looper.loop(Looper.java:164)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at android.app.ActivityThread.main(ActivityThread.java:6540)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at java.lang.reflect.Method.invoke(Native Method)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
05-25 16:38:46.113 21029 21029 E cr_billorr: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)

0-1 of them actually have the idle callback called, which creates/initialized TracingControllerAndroid:
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at org.chromium.content.browser.TracingControllerAndroid.<init>(TracingControllerAndroid.java:79)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at org.chromium.content.app.ContentApplication.getTracingController(ContentApplication.java:38)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at org.chromium.content.app.ContentApplication$1.queueIdle(ContentApplication.java:58)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at android.os.MessageQueue.next(MessageQueue.java:394)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at android.os.Looper.loop(Looper.java:142)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at android.app.ActivityThread.main(ActivityThread.java:6540)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at java.lang.reflect.Method.invoke(Native Method)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
05-25 16:39:07.495 21051 21051 E cr_billorr: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)

When we enter VR, the others have the idle callback called, so other TracingControllerAndroid's are initialized.  I'm not yet sure why.

Finally when I take the trace using the instructions Klaus added above, I'm hitting a DCHECK:
05-25 16:41:09.411 21051 21051 F chromium: [FATAL:sequenced_task_runner_handle.cc(54)] Check failed: pool. 
...
05-25 16:41:09.412 21051 21051 F libc    : Fatal signal 6 (SIGABRT), code -6 in tid 21051 (ileged_process0)
05-25 16:41:09.424 20824 21034 D RenderScript: Successfully queried cache dir: /data/user_de/0/org.chromium.chrome/code_cache
05-25 16:41:09.424 20824 21034 D RenderScript: Setting cache dir: /data/user_de/0/org.chromium.chrome/code_cache
05-25 16:41:09.511 21363 21363 I crash_dump32: obtaining output fd from tombstoned
05-25 16:41:09.512   735   735 I /system/bin/tombstoned: received crash request for pid 21051
05-25 16:41:09.514 21363 21363 I crash_dump32: performing dump of process 21051 (target tid = 21051)
05-25 16:41:09.515 21363 21363 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
05-25 16:41:09.516 21363 21363 F DEBUG   : Build fingerprint: 'google/marlin/marlin:8.0.0/OPR1.170518.002/4024270:userdebug/dev-keys'
05-25 16:41:09.516 21363 21363 F DEBUG   : Revision: '0'
05-25 16:41:09.516 21363 21363 F DEBUG   : ABI: 'arm'
05-25 16:41:09.516 21363 21363 F DEBUG   : pid: 21051, tid: 21051, name: ileged_process0  >>> org.chromium.chrome:privileged_process0 <<<
05-25 16:41:09.516 21363 21363 F DEBUG   : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
05-25 16:41:09.518 21363 21363 F DEBUG   : Abort message: '[FATAL:sequenced_task_runner_handle.cc(54)] Check failed: pool. 
05-25 16:41:09.518 21363 21363 F DEBUG   : #00 0xc8cdf687 /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so+0x00095687
05-25 16:41:09.518 21363 21363 F DEBUG   : #01 0xc8cf55f5 /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so+0x000ab5f5
05-25 16:41:09.518 21363 21363 F DEBUG   : #02 0xc8d3aa95 /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so+0x000f0a95
05-25 16:41:09.518 21363 21363 F DEBUG   : #03 0xc8d3daa9 /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so+0x000f3aa9
05-25 16:41:09.518 21363 21363 F DEBUG   : #04 0xc0f7a2f9 /da
05-25 16:41:09.518 21363 21363 F DEBUG   :     r0 00000000  r1 0000523b  r2 00000006  r3 00000008
05-25 16:41:09.518 21363 21363 F DEBUG   :     r4 0000523b  r5 0000523b  r6 ffbb5da8  r7 0000010c
05-25 16:41:09.518 21363 21363 F DEBUG   :     r8 ffbb5e08  r9 ffbb5f1c  sl c8dbbc04  fp ffbb6360
05-25 16:41:09.518 21363 21363 F DEBUG   :     ip 00000000  sp ffbb5d98  lr e696c4a7  pc e699ca7c  cpsr 200f0010
05-25 16:41:09.528 21363 21363 F DEBUG   : 
05-25 16:41:09.528 21363 21363 F DEBUG   : backtrace:
05-25 16:41:09.528 21363 21363 F DEBUG   :     #00 pc 0004aa7c  /system/lib/libc.so (tgkill+12)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #01 pc 0001a4a3  /system/lib/libc.so (abort+54)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #02 pc 00095647  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so (_ZN4base5debug13BreakDebuggerEv+18)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #03 pc 000ab85d  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so (_ZN7logging10LogMessageD1Ev+840)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #04 pc 000f0a93  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so (_ZN4base25SequencedTaskRunnerHandle3GetEv+262)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #05 pc 000f3aa7  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libbase.cr.so (_ZN4base19SequencedWorkerPoolC2EjRKNSt6__ndk112basic_stringIcNS1_11char_traitsIcEENS1_9allocatorIcEEEENS_12TaskPriorityE+34)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #06 pc 007db2f7  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libcontent.cr.so
05-25 16:41:09.528 21363 21363 F DEBUG   :     #07 pc 007dc42b  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libcontent.cr.so (_ZN7content13BrowserThread11CurrentlyOnENS0_2IDE+22)
05-25 16:41:09.528 21363 21363 F DEBUG   :     #08 pc 00a5a66d  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libcontent.cr.so
05-25 16:41:09.529 21363 21363 F DEBUG   :     #09 pc 00aa39af  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libcontent.cr.so
05-25 16:41:09.529 21363 21363 F DEBUG   :     #10 pc 00aa3a75  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/lib/arm/libcontent.cr.so (Java_org_chromium_content_browser_TracingControllerAndroid_nativeStartTracing+132)
05-25 16:41:09.529 21363 21363 F DEBUG   :     #11 pc 000791d9  /data/app/org.chromium.chrome-b0drBZXLyDcfbjoT6IqNIg==/oat/arm/base.odex (offset 0x48000)


Two followup questions:
* why do we have multiple (random number) of ContentApplication's being created?
* why does starting vr trigger the idle callbacks?

My understanding is that we have multiple ContentApplications (one per process), including gpu and renderer processes (however the different processes will host different activities/services).  During initialization, these register an idle handler that performs the following code:

// Will retry if the native library has not been initialized.
if (!LibraryLoader.isInitialized()) return true;
try {
    getTracingController().registerReceiver(ContentApplication.this);
} catch (SecurityException e) {
    // Happens if the process is isolated. Ignore.
}

Typically, the library is loaded for the browser process, but not others the first time through.  Vr somehow triggers the idle handler for the other processes to run again, hitting the exception.

The bug is that the getTracingController().registerReceiver(ContentApplication.this) seems to still partially initialize things, even when the rest of tracing isn't fully initialized/ready to handle tracing starting.

I don't believe the fact that idle callbacks are triggered again when VR is entered is relevant.  In particular, I could repro the DCHECK by starting chrome, switching tabs, hitting the home button, going back to chrome (I did switch orientation, and navigate a few times, but don't think it is relevant).
Cc: billorr@chromium.org
Cc: vollick@chromium.org
+vollick@, you mentioned you know some tracing experts who may be able to help investigate this? As billorr@ said in comment #13, this seems to be a pre-existing issue and not VR specific after all, though we seem to trigger the problem more consistently from VR mode.
Cc: chiniforooshan@chromium.org
Yep, I was wondering if chiniforooshan@ might have some advice.
Cc: yfried...@chromium.org wangxianzhu@chromium.org
Ao, there are two tracing controllers in the app and both register broadcast receivers? If so, it does indeed look wrong.

I can try to understand what's going on, but I'm not very familiar with that part of the code. +Xianzhu and Yaron (from https://codereview.chromium.org/26740005).
Cc: dtrainor@chromium.org
(+dtrainer@ for the question about LibraryLoader.isInitialized())

I think it's correct to have multiple tracing controllers given that each process have only one.

The problems seem that:
1. The idle handler is called more than once after the library is loaded, causing the receiver is registered more than once;
2. The receiver is called a) before the library is loaded or b) after the library is unloaded.

I don't see any possibility of 2 a). For 2 b), is it possible that the application is being force-stopped for some reason and the receiver is called after the library is unloaded?

Another speculation is about LibraryLoader.isInitialized(). dtrainor@, why does https://codereview.chromium.org/2804743002 use BrowserStartupController instead of LibraryLoader.isInitialized()?
Status: Available (was: Untriaged)
Labels: -M-60 M-61
Not sure if this helps at all, but I'm still seeing crashes on stopping tracing even with the very hackish workaround from http://crrev.com/2809043005 (wrapping an exception handler) included.

In the full log (attached), I see "privileged_process0" being launched and later killed with SIGSEGV. The log should contain the full history of this Chrome instance, does this help show any extra processes or libraries being launched/killed/reloaded?

The "61.0.3132.0" library loading message is for the GVR library that's supposed to be loaded into the browser process.


Some log excerpts included here, see the attachment for context.

06-15 17:03:35.274   907 28431 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=org.chromium.chrome/com.google.android.apps.chrome.Main bnds=[1134,1242][1410,1614]} from uid 10032

$ egrep 'PrivilegedProcess|20785' ~/Downloads/crash-on-stop-tracing.txt

06-15 17:04:13.320   907  6897 I ActivityManager: Start proc 20785:org.chromium.chrome:privileged_process0/u0a133 for service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService0
06-15 17:04:13.386 20785 20785 I cr_CommandLineInitUtil: Initializing command line from alternative file /data/local/tmp/chrome-command-line
06-15 17:04:13.390 20785 20785 I cr_ChildProcessService: Creating new ChildProcessService pid=20785
06-15 17:04:13.483 20785 20806 I cr_LibraryLoader: Time to load native libraries: 47 ms (timestamps 580-627)
06-15 17:04:13.484 20785 20806 I cr_LibraryLoader: Using linker: org.chromium.base.library_loader.ModernLinker
06-15 17:04:13.486 20785 20806 I chromium: [INFO:library_loader_hooks.cc(144)] Chromium logging enabled: level = -1, default verbosity = 1
06-15 17:04:13.487 20785 20806 I cr_LibraryLoader: Expected native library version number "61.0.3132.0", actual native library version number "61.0.3132.0"
06-15 17:04:13.498 20785 20806 I Adreno  : QUALCOMM build                   : bd51b6f, Iceb07a594c
06-15 17:04:13.498 20785 20806 I Adreno  : Build Date                       : 05/08/17
06-15 17:04:13.498 20785 20806 I Adreno  : OpenGL ES Shader Compiler Version: EV031.17.00.01
06-15 17:04:13.498 20785 20806 I Adreno  : Local Branch                     : O8A
06-15 17:04:13.498 20785 20806 I Adreno  : Remote Branch                    : 
06-15 17:04:13.498 20785 20806 I Adreno  : Remote Branch                    : 
06-15 17:04:13.498 20785 20806 I Adreno  : Reconstruct Branch               : 
06-15 17:04:13.516 20785 20806 I Adreno  : PFP: 0x005ff087, ME: 0x005ff063
06-15 17:04:13.601 20785 20806 W VideoCapabilities: Unrecognized profile 2130706433 for video/avc
06-15 17:04:13.601 20785 20806 W VideoCapabilities: Unrecognized profile 2130706434 for video/avc
06-15 17:04:13.688 20785 20806 I VideoCapabilities: Unsupported profile 4 for video/mp4v-es
06-15 17:04:13.906 20785 20806 V chromium: [VERBOSE1:gles2_cmd_decoder.cc(3373)] GL_OES_packed_depth_stencil supported.
...
06-15 17:04:19.285 20785 20806 E chromium: [ERROR:gles2_cmd_decoder.cc(9720)] [.Offscreen-For-WebGL-0xcab1d000]RENDER WARNING: texture bound to texture unit 0 is not renderable. It maybe non-power-of-2 and have incompatible texture filtering.
06-15 17:04:55.549 20785 20785 W chromium: [WARNING:tracing_controller_android.cc(47)] Logging performance trace to file
06-15 17:04:55.550 20785 20785 W chromium: [WARNING:trace_event_android.cc(37)] Failed to write buffer 'trace_event_clock_sync: parent_ts=15732.693470
06-15 17:04:55.550 20785 20785 W chromium: ' to /sys/kernel/debug/tracing/trace_marker: Bad file descriptor
06-15 17:04:55.551 20785 20785 I cr_TracingController: Profiler started: 
06-15 17:04:57.549 20785 21336 D OpenGLRenderer: HWUI GL Pipeline
06-15 17:04:57.596 20785 21336 I OpenGLRenderer: Initialized EGL, version 1.4
06-15 17:04:57.597 20785 21336 D OpenGLRenderer: Swap behavior 2
06-15 17:04:58.712 20785 20785 F libc    : Fatal signal 11 (SIGSEGV), code 1, fault addr 0x0 in tid 20785 (ileged_process0)
06-15 17:04:58.917   733   733 I /system/bin/tombstoned: received crash request for pid 20785
06-15 17:04:58.923 21358 21358 I crash_dump32: performing dump of process 20785 (target tid = 20785)
06-15 17:04:58.926 21358 21358 F DEBUG   : pid: 20785, tid: 20785, name: ileged_process0  >>> org.chromium.chrome:privileged_process0 <<<
06-15 17:05:00.321   907  1447 I ActivityManager: Process org.chromium.chrome:privileged_process0 (pid 20785) has died: fore TOP 
06-15 17:05:00.321   907  1447 W ActivityManager: Scheduling restart of crashed service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService0 in 1000ms
06-15 17:05:00.328 20722 20748 W cr_ChildProcessConn: onServiceDisconnected (crash or killed by oom): pid=20785
06-15 17:05:00.552   907   942 E zygote64: failed to kill 1 processes for processgroup 20785
06-15 17:05:00.613 20722 20722 W chromium: [WARNING:compositor_view.cc(255)] Child process disconnected (type=9) pid=20785)
06-15 17:05:00.630   580   580 I Zygote  : Process 20785 exited due to signal (11)
06-15 17:05:00.662   907 26451 I ActivityManager: Start proc 21377:org.chromium.chrome:privileged_process1/u0a133 for service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService1


Decoded crash address:

signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
     r0 00000000  r1 31a741a5  r2 0000000a  r3 00000000
     r4 cb5913a9  r5 c8bb2120  r6 ffb10e08  r7 cb5b1e99
     r8 00000000  r9 ffb10fe4  sl cb58f3ef  fp ffb11118
     ip 00000076  sp ffb10d78  lr cc4275e1  pc cc4275e2

Stack Trace:
  RELADDR   FUNCTION                                                                      FILE:LINE
  0117a5e2  GenerateTracingMetadataDict                                                   /usr/local/google/home/klausw/chromium2/src/content/browser/tracing/tracing_controller_impl.cc:887
  0117a129  StopTracing                                                                   /usr/local/google/home/klausw/chromium2/src/content/browser/tracing/tracing_controller_impl.cc:314
  011a29c7  StopTracing                                                                   /usr/local/google/home/klausw/chromium2/src/content/browser/android/tracing_controller_android.cc:60
  011a2951  Java_org_chromium_content_browser_TracingControllerAndroid_nativeStopTracing  /usr/local/google/home/klausw/chromium2/src/out/Mono2/gen/content/public/android/content_jni_headers/content/jni/TracingControllerAndroid_jni.h:76
  0007ec07  offset 0x45000                                                                /data/app/org.chromium.chrome-4RqvhBMqdy3FLKpaJbmpXA==/oat/arm/base.odex

crash-on-stop-tracing.txt
418 KB View Download
To clarify, yes, the error I got in comment #21 was using the command line tool:

$ build/android/adb_profile_chrome --browser chromium --time 3 

Using the "trace" link from chrome://inspect/?tracing#devices works, I don't get a crash when I do that.
Cc: tedc...@chromium.org
Sorry for the delayed reply!

@18: I actually think you're hitting 2.a!  My understanding is (and I may be incorrect, adding tedchoc@ who gave me advice about the API) that the LibraryLoader.isInitialized() only means the native libraries have been loaded and the JNI hooks are done.  It doesn't mean the browser process has been completely initialized yet.  So you're probably calling down to native and crashing because none of the stuff we expect to just be there is actually there yet.
dtrainor - I'm confused, how could the browser process not be completely initialized yet? In the scenarios I've been seeing, it's been running and rendering WebGL for ~40 seconds already at the time I'm taking the trace, so it would seem odd if it still hadn't finished initializing at the time.

I found something potentially interesting in the logs from comment #21:

Browser starts, browser process PID=20722:

06-15 17:04:12.643   907  1516 I ActivityManager: Start proc 20722:org.chromium.chrome/u0a133 for activity org.chromium.chrome/com.google.android.apps.chrome.Main

Browser process PID=20722 initializes a native GL context for TID=20756. Note that the "Initialized EGL" message immediately follows the earlier Adreno logs:

06-15 17:04:13.128 20722 20756 D OpenGLRenderer: HWUI GL Pipeline
06-15 17:04:13.161 20722 20756 I Adreno  : QUALCOMM build                   : bd51b6f, Iceb07a594c
06-15 17:04:13.161 20722 20756 I Adreno  : Build Date                       : 05/08/17
06-15 17:04:13.161 20722 20756 I Adreno  : OpenGL ES Shader Compiler Version: EV031.17.00.01
06-15 17:04:13.161 20722 20756 I Adreno  : Local Branch                     : O8A
06-15 17:04:13.161 20722 20756 I Adreno  : Remote Branch                    : 
06-15 17:04:13.161 20722 20756 I Adreno  : Remote Branch                    : 
06-15 17:04:13.161 20722 20756 I Adreno  : Reconstruct Branch               : 
06-15 17:04:13.173 20722 20756 I Adreno  : PFP: 0x005ff087, ME: 0x005ff063
06-15 17:04:13.176 20722 20756 I OpenGLRenderer: Initialized EGL, version 1.4
06-15 17:04:13.177 20722 20756 D OpenGLRenderer: Swap behavior 2

GPU process starts with PID=20785:

06-15 17:04:13.320   907  6897 I ActivityManager: Start proc 20785:org.chromium.chrome:privileged_process0/u0a133 for service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService0
06-15 17:04:13.487 20785 20806 I cr_LibraryLoader: Expected native library version number "61.0.3132.0", actual native library version number "61.0.3132.0"
06-15 17:04:13.498 20785 20806 I Adreno  : QUALCOMM build                   : bd51b6f, Iceb07a594c
06-15 17:04:13.498 20785 20806 I Adreno  : Build Date                       : 05/08/17
06-15 17:04:13.498 20785 20806 I Adreno  : OpenGL ES Shader Compiler Version: EV031.17.00.01
06-15 17:04:13.498 20785 20806 I Adreno  : Local Branch                     : O8A
06-15 17:04:13.498 20785 20806 I Adreno  : Remote Branch                    : 
06-15 17:04:13.498 20785 20806 I Adreno  : Remote Branch                    : 
06-15 17:04:13.498 20785 20806 I Adreno  : Reconstruct Branch               : 

GPU process does stuff:

06-15 17:04:13.906 20785 20806 V chromium: [VERBOSE1:gles2_cmd_decoder.cc(3373)] GL_OES_packed_depth_stencil supported.


Later, tracing starts for browser (PID=20722) and GPU process (PID=20785):

06-15 17:04:55.489 20722 20722 W chromium: [WARNING:tracing_controller_android.cc(47)] Logging performance trace to file
06-15 17:04:55.549 20785 20785 W chromium: [WARNING:tracing_controller_android.cc(47)] Logging performance trace to file


Here's the odd thing. GPU process prints the "OpenGLRenderer: Initialized EGL, version 1.4" message shortly after tracing started, even though it's already been happily rendering for a while:

06-15 17:04:57.549 20785 21336 D OpenGLRenderer: HWUI GL Pipeline
06-15 17:04:57.596 20785 21336 I OpenGLRenderer: Initialized EGL, version 1.4
06-15 17:04:57.597 20785 21336 D OpenGLRenderer: Swap behavior 2

... and the GPU process (PID=20785) crashes a second after that:

06-15 17:04:58.712 20785 20785 F libc    : Fatal signal 11 (SIGSEGV), code 1, fault addr 0x0 in tid 20785 (ileged_process0)

Does this match the theory of incomplete initialization?
Ah wow I didn't realize it was up for that long.  Sadly I'm not sure what the initialization path is for the GL context here.
@dtrainor, some more details for the path are in comment #9, and in comment #11 khushalsagar@ said "The path that this call uses is the same that the non-VR mode uses in Clank for creating a GPU command buffer".

So it shouldn't be an unusual path as such, but maybe the Clank usage is followed by other calls that complete the missing initialization steps that aren't being called yet when used for VR compositing?

Comment 28 by bshe@chromium.org, Jul 5 2017

For WebVR, the context is created on GL thread instead of UI thread. Not sure if this is the root cause. You can probably apply this patch: https://codereview.chromium.org/2969153002/ and see if the problem still reproduce afterwards.
Owner: klausw@chromium.org
Status: Assigned (was: Available)
klausw: The patch above has landed. Please see whether that solves the issue. If not, let's find an owner for M62.
Status: Available (was: Assigned)
Still crashing using a ToT build (f554301a3f844613539ae835ec0fdfbbd78202ee as of Fri Jul 14 23:49:17 2017 +0000), but I'm not seeing a Java exception this time:

07-14 17:49:13.642 32573 32573 W chromium: [WARNING:tracing_controller_android.cc(47)] Logging performance trace to file
07-14 17:49:13.642 32573 32573 W chromium: [WARNING:trace_event_android.cc(37)] Failed to write buffer 'trace_event_clock_sync: parent_ts=6373.241376
07-14 17:49:13.642 32573 32573 W chromium: ' to /sys/kernel/debug/tracing/trace_marker: Bad file descriptor
--------- beginning of crash
07-14 17:49:13.644 32573 32573 F libc    : Fatal signal 11 (SIGSEGV), code 1, fault addr 0xc in tid 32573 (ileged_process0)
07-14 17:49:13.717   753   753 I crash_dump32: obtaining output fd from tombstoned
07-14 17:49:13.718   758   758 I /system/bin/tombstoned: received crash request for pid 32573
07-14 17:49:13.724   753   753 I crash_dump32: performing dump of process 32573 (target tid = 32573)
07-14 17:49:13.725   753   753 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
07-14 17:49:13.725   753   753 F DEBUG   : Build fingerprint: 'google/marlin/marlin:8.0.0/OPR1.170623.011/4160747:userdebug/dev-keys'
07-14 17:49:13.725   753   753 F DEBUG   : Revision: '0'
07-14 17:49:13.725   753   753 F DEBUG   : ABI: 'arm'
07-14 17:49:13.726   753   753 F DEBUG   : pid: 32573, tid: 32573, name: ileged_process0  >>> org.chromium.chrome:privileged_process0 <<<
07-14 17:49:13.726   753   753 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xc
07-14 17:49:13.726   753   753 F DEBUG   : Cause: null pointer dereference
07-14 17:49:13.726   753   753 F DEBUG   :     r0 ff80a130  r1 ff80a178  r2 00000000  r3 00000001
07-14 17:49:13.726   753   753 F DEBUG   :     r4 cb118984  r5 00000000  r6 c735ecc0  r7 00000000
07-14 17:49:13.726   753   753 F DEBUG   :     r8 ff80a130  r9 00000000  sl 01c9c380  fp ff80a394
07-14 17:49:13.726   753   753 F DEBUG   :     ip c8996959  sp ff80a120  lr c83bc565  pc c83bc564  cpsr 60000030
07-14 17:49:13.729   753   753 F DEBUG   : 
07-14 17:49:13.729   753   753 F DEBUG   : backtrace:
07-14 17:49:13.729   753   753 F DEBUG   :     #00 pc 0037d564  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/base.apk (offset 0xe90000)
07-14 17:49:13.730   753   753 F DEBUG   :     #01 pc 00349469  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/base.apk (offset 0xe90000)
07-14 17:49:13.730   753   753 F DEBUG   :     #02 pc 0119188b  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/base.apk (offset 0xe90000)
07-14 17:49:13.730   753   753 F DEBUG   :     #03 pc 011baa85  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/base.apk (offset 0xe90000)
07-14 17:49:13.730   753   753 F DEBUG   :     #04 pc 011ba9f5  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/base.apk (offset 0xe90000)
07-14 17:49:13.730   753   753 F DEBUG   :     #05 pc 000bacf1  /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/oat/arm/base.odex (offset 0x45000)
07-14 17:49:14.387   758   758 E /system/bin/tombstoned: Tombstone written to: /data/tombstones//tombstone_07
07-14 17:49:14.395   949  1021 I BootReceiver: Copying /data/tombstones/tombstone_07 to DropBox (SYSTEM_TOMBSTONE)
07-14 17:49:14.422 32511 32511 W chromium: [WARNING:tracing_controller_android.cc(47)] Logging performance trace to file
07-14 17:49:14.431   949  2116 I ActivityManager: Process org.chromium.chrome:privileged_process0 (pid 32573) has died: fore TOP 
07-14 17:49:14.431 32511 32511 W chromium: [WARNING:trace_event_android.cc(37)] Failed to write buffer 'trace_event_clock_sync: parent_ts=6374.030465
07-14 17:49:14.431 32511 32511 W chromium: ' to /sys/kernel/debug/tracing/trace_marker: Bad file descriptor
07-14 17:49:14.432   949  2116 W ActivityManager: Scheduling restart of crashed service org.chromium.chrome/org.chromium.content.app.PrivilegedProcessService0 in 1000ms

Decoded trace:

Stack Trace:
  RELADDR   FUNCTION                                                                                                                                                                                                                                     FILE:LINE
  v------>  std::__ndk1::unique_ptr<base::SequencedWorkerPool::Inner, std::__ndk1::default_delete<base::SequencedWorkerPool::Inner> >::operator->() const                                                                                                /usr/local/google/home/klausw/chromium2/src/third_party/android_tools/ndk/sources/cxx-stl/llvm-libc++/libcxx/include/memory:2608
  v------>  base::SequencedWorkerPool::PostDelayedSequencedWorkerTask(base::SequencedWorkerPool::SequenceToken, tracked_objects::Location const&, base::Callback<void (), (base::internal::CopyMode)0, (base::internal::RepeatMode)0>, base::TimeDelta)  /usr/local/google/home/klausw/chromium2/src/base/threading/sequenced_worker_pool.cc:1571
  0037d564  base::SequencedWorkerPool::PoolSequencedTaskRunner::PostDelayedTask(tracked_objects::Location const&, base::Callback<void (), (base::internal::CopyMode)0, (base::internal::RepeatMode)0>, base::TimeDelta)                                  /usr/local/google/home/klausw/chromium2/src/base/threading/sequenced_worker_pool.cc:240
  00349469  base::Timer::PostNewScheduledTask(base::TimeDelta)                                                                                                                                                                                           /usr/local/google/home/klausw/chromium2/src/base/timer/timer.cc:201
  0119188b  content::TracingControllerImpl::StartTracing(base::trace_event::TraceConfig const&, base::Callback<void (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&)                                                              /usr/local/google/home/klausw/chromium2/src/content/browser/tracing/tracing_controller_impl.cc:255
  011baa85  content::TracingControllerAndroid::StartTracing(_JNIEnv*, base::android::JavaParamRef<_jobject*> const&, base::android::JavaParamRef<_jstring*> const&, base::android::JavaParamRef<_jstring*> const&)                                       /usr/local/google/home/klausw/chromium2/src/content/browser/android/tracing_controller_android.cc:49
  011ba9f5  Java_org_chromium_content_browser_TracingControllerAndroid_nativeStartTracing                                                                                                                                                                /usr/local/google/home/klausw/chromium2/src/out/Mono2/gen/content/public/android/content_jni_headers/content/jni/TracingControllerAndroid_jni.h:63
  000bacf1  offset 0x45000                                                                                                                                                                                                                               /data/app/org.chromium.chrome-GnGDuH5hjS6GOs1jdPGYSg==/oat/arm/base.odex

Labels: -M-61 M-62
Labels: -M-62 M-63
Labels: -M-63 M-64
Owner: chiniforooshan@chromium.org
Status: Assigned (was: Available)
Ehsan, could you please take a look?
Status: Started (was: Assigned)
Re comment #18: excuse my unfamiliarity with the android code. Could you please explain why it is OK to have tracing controllers in processes other than the browser process?

As far as I understand, TracingControllerAndroid.java talks with the native code tracing_controller_android.cc which forwards calls to TracingController::GetInstance(). I'm pretty sure that on the C++ side, tracing controller is only available (linked) to the browser process.
So, I created a (speculative) fix CL, with my limited understanding of the clank code: https://chromium-review.googlesource.com/c/chromium/src/+/705758

Can someone let me know how I can build VR-enabled chrome and depoly it on a device? I built chromium without VR with my patch. The GPU process does not crash with adb_profile_chrome and the trace file looks OK.

Comment 36 by klausw@google.com, Oct 6 2017

Current top-of-tree Chrome includes WebVR support for Android, so you shouldn't need any special build settings.

Just for reference, here's how I usually build it:

ffmpeg_branding = "Chrome"
is_component_build = false
is_debug = false
is_official_build = true
proprietary_codecs = true
symbol_level = 1
target_cpu = "arm"
target_os = "android"
use_goma = true
enable_resource_whitelist_generation = false

To test, open a WebVR page such as https://webvr.info/samples/03-vr-presentation.html and press the "Enter VR" button. 

I tried this just now on a Pixel XL, and got a GPU crash with this command line:

$ build/android/adb_profile_chrome --browser chromium --time 2 --atrace-categories=gfx,view,input,freq,sched,irq,workq

A Daydream ready device isn't required, but you need to have Google VR Services on the phone. (Chrome should prompt you to install it if you don't.)
Ehsan, any update on this?
Let me know if you need help to test on a device.
The fix in #35 works for me. I didn't land it since I didn't know how to verify it does not break anything in CastApplication and I'm a bit swamped with other work. I just added someone from the cast team to the CL. Meanwhile, you should be able to patch the CL to use tracing; please let me know if there is any issues.
Project Member

Comment 39 by bugdroid1@chromium.org, Nov 4 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5e3127a5b92a14a0c83283d73bed03dbc63eb4c0

commit 5e3127a5b92a14a0c83283d73bed03dbc63eb4c0
Author: Ehsan Chiniforooshan <chiniforooshan@chromium.org>
Date: Fri Nov 03 23:11:06 2017

Android: init TracingController only in browser

Tested by deploying chromium with this patch on a device and
verifying that the following command does not cause crashes
while browsing the webvr.info page and successfully captures
a trace file:

build/android/adb_profile_chrome --browser chromium --time 2

Bug= 710591 

Change-Id: I7d733c94511492350c8c08e584dfa8c594c6de6f
Reviewed-on: https://chromium-review.googlesource.com/705758
Reviewed-by: Xianzhu Wang <wangxianzhu@chromium.org>
Reviewed-by: Bo <boliu@chromium.org>
Commit-Queue: Ehsan Chiniforooshan <chiniforooshan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#513948}
[modify] https://crrev.com/5e3127a5b92a14a0c83283d73bed03dbc63eb4c0/content/public/android/java/src/org/chromium/content/app/ContentApplication.java
[modify] https://crrev.com/5e3127a5b92a14a0c83283d73bed03dbc63eb4c0/content/public/android/java/src/org/chromium/content/browser/BrowserStartupController.java

Status: Fixed (was: Started)
Status: Verified (was: Fixed)
Thank you! Works for me too in Chrome Canary 64.0.3266.0.

Sign in to add a comment