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

Issue 807034 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner: ----
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 3
Type: Bug
Hotlist-MemoryInfra



Sign in to add a comment

Multiple pending trace events can't have the same name

Project Member Reported by dskiba@chromium.org, Jan 29 2018

Issue description

I have startup profiling enabled, and occasionally (not always) Chrome crashes with the following exception:

01-29 22:21:52.107 20004 20113 E AndroidRuntime: FATAL EXCEPTION: AsyncTask #4
01-29 22:21:52.107 20004 20113 E AndroidRuntime: Process: com.google.android.apps.chrome, PID: 20004
01-29 22:21:52.107 20004 20113 E AndroidRuntime: java.lang.RuntimeException: An error occurred while executing doInBackground()
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at android.os.AsyncTask$3.done(AsyncTask.java:325)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:354)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.FutureTask.setException(FutureTask.java:223)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.FutureTask.run(FutureTask.java:242)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.lang.Thread.run(Thread.java:761)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: Caused by: java.lang.IllegalArgumentException: Multiple pending trace events can't have the same name
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.EarlyTraceEvent.begin(EarlyTraceEvent.java:31)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.TraceEvent.begin(TraceEvent.java:44)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.TraceEvent.<init>(TraceEvent.java:4)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.TraceEvent.scoped(TraceEvent.java:14)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.library_loader.LibraryLoader$LibraryPrefetchTask.doInBackground$51DKOQJ1EPGIUR31DPJIULJFD5I3MAACD9GNCO9FDHGMSPPFAPNMIP1R0(LibraryLoader.java:4)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at org.chromium.base.library_loader.LibraryLoader$LibraryPrefetchTask.doInBackground(LibraryLoader.java:22)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at android.os.AsyncTask$2.call(AsyncTask.java:305)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
01-29 22:21:52.107 20004 20113 E AndroidRuntime: 	... 3 more

The stacktrace claims that LibraryPrefetchTask.doInBackground() called itself recursively, but there is no such path. I suspect this has something to do with ART. This is on Nexus 5X running N2G47F.

 
Components: Internals>Instrumentation>Memory
Labels: Stability
I think I found the issue - EarlyTraceEvent hashes pending events by name, while it should be hashing by name+tid.

I.e. methods like this:

void foo() {
   try (TraceEvent te = TraceEvent.scoped("foo")) {
       synchronized (mLock) {
           doLotsOfWork();
       }
   }
}


will cause the issue when launched from multiple threads.
Project Member

Comment 3 by bugdroid1@chromium.org, May 15 2018

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

commit c6d31e97721f9982a5a7bcaad534fda6763e2e80
Author: Dmitry Skiba <dskiba@chromium.org>
Date: Tue May 15 21:04:47 2018

Key pending EarlyTraceEvents by name+tid.

Chrome tracing allows starting similarly named events from different
threads. EarlyTraceEvents throws an exception in this case because it
keys pending events by name only.

This CL changes pending events key to be name+tid, separating events
from different threads.

Bug:  807034 
Change-Id: Ia6d4ac740ec028a14c5269d09148db4d1a5d33ce
Reviewed-on: https://chromium-review.googlesource.com/1055941
Commit-Queue: Dmitry Skiba <dskiba@chromium.org>
Reviewed-by: agrieve <agrieve@chromium.org>
Cr-Commit-Position: refs/heads/master@{#558829}
[modify] https://crrev.com/c6d31e97721f9982a5a7bcaad534fda6763e2e80/base/android/java/src/org/chromium/base/EarlyTraceEvent.java
[modify] https://crrev.com/c6d31e97721f9982a5a7bcaad534fda6763e2e80/base/android/javatests/src/org/chromium/base/EarlyTraceEventTest.java

Comment 4 by dskiba@chromium.org, May 15 2018

Status: Fixed (was: Untriaged)

Sign in to add a comment