yuhsuan@ would be nice to have all chrome bug-related info here, including traces.

Sorry here is a trace dump I mentioned above.

Deleted: trace3.json.gz 3.1 MB

trace3.json.gz 3.1 MB Download

The easier reproduce way is using stress test. (like run yes in terminal)
I can get obvious result by this way.

The trace1 is running in the normal situation.
The trace2 is running with yes and trigger issue sometimes.
We can see the different between the Audio Player program.
The trace1 run it regular period (fig1.png) but trace2 didn't (fig2.png).
It seems the browser made an influence on audio player(fig3.png). I think it's a problem of chrome's performance.

Deleted: trace1.json.gz 1.7 MB

trace1.json.gz 1.7 MB Download

Deleted: trace2.json.gz 2.5 MB

trace2.json.gz 2.5 MB Download

Deleted: fig1.png 28.7 KB

	fig1.png 28.7 KB View Download

Deleted: fig2.png 29.0 KB

	fig2.png 29.0 KB View Download

Deleted: fig3.png 224 KB

	fig3.png 224 KB View Download

Thanks yuhsuan@. Are you able to repro it on Stable Chrome as well?

What I see:
(1) the browser-side audio thread (AudioThread, tid 12695) - prio 89
(2) renderer-side thread (AudioOutputDevice, tid 12694) - prio 110.
(4) Browser-side IO thread (Chrome_IOThread, tid 1402) - prio 112
(3) cras - prio 87
(4) yes - prio 120

One core of CPU is busy with yes, another core mostly runs "chrome" threads with prio 112-120.

(1) and (2) are "real-time" audio threads.

(2) with prio 89 gets descheduled while (4) with prio 120 runs. Looks like the whole renderer process (pid 1203) is assigned to one CPU and never gets cycles from another?

Is strong CPU-affinity an expected side-effect of running yes? Could you point me to its documentation? (it's kind of hard to google it by name :) )

Looking at trace3.

Browser-side audio thread signals renderer-side audio thread though a sync socket to request the data.

Renderer-side audio threads are not scheduled (for all renderers), despite they are high priority; while browser-side threads get CPU time for all priority range (89-120).

Looks as if all renderer processes get backgrounded. Were you switching between audio player/yahoo tabs when doing trace recording?

Deleted: B1aNKvvwYAs.png 175 KB

	B1aNKvvwYAs.png 175 KB View Download

Yes, I were.
For trace3, I didn't run any stress program and just reloaded some pages and switched between them. Is it a normal situation?

For yes command: https://en.wikipedia.org/wiki/Yes_(Unix)
Is this what you want?

I didn't have chance to run it on Stable Chrome now. Maybe next week.
Thanks for your assistance!

Still can reproduce it on stable Chrome (71.0.3578.71 (Official Build) unknown (64-bit))

The attachment is the trace file about it. The glitch happened at 15,700 ms.

Deleted: trace4.json.gz 2.5 MB

trace4.json.gz 2.5 MB Download

Thanks yuhsuan@, yes I see it.

So we see renderer process gets descheduled while playing audio. Max, could you double-check that backgrounding logic is correct?

It's strange that the AudioOutputDevice thread is shown as being in uninterruptible sleep for 2 s starting at 14377 ms, but we can see it waking up several times during that time. Maybe the state is just periodically sampled so that it misses short wakeups? (In which case we should just avoid looking at that data). I'm also pretty sure that read() from a socket is interruptible, so I don't understand why it would ever be marked as uninterruptible in the trace.

I also saw another curious thing. https://screenshot.googleplex.com/udSZJ84i4td.png There always seem to be a kernel thread running shortly before AudioOutputDevice is scheduled (like "kworker/1:1"). Maybe this thread has to run to notice that AudioOutputDevice is runnable? Since the kernel thread has normal priority, it may take a long time for it to be scheduled. This is just an idea though, maybe some kernel expert can have a look at that?

Will have a closer look at the backgrounding code tomorrow.

+cychiang can you follow up on the scheduling issues from the Chrome OS side?

maxmorin, can you capture any cras* threads in the systrace as well to make sure that they are being scheduled in time?

Sorry, I misunderstood.
The glitch in trace4 should happened at 10,275 ms.
14,377 ms is when we stopped playing audio.

I don't actually have a device to repro this on, but it seems pretty clear that the issue is that the callback threads in the renderer process don't get scheduled.