Hi,

How could we help solving this ?

Thanks

Hi,
I have post a video on comments #11 with a video that shows this very strange bug of audio on mac and Chrome 
Chrome : https://www.youtube.com/watch?v=bbAhIkkYSfY&feature=youtu.be

I add today a link with the same fiddle but on firefox, no comparison as you can see.
Firefox : https://www.youtube.com/watch?v=ocmQgyZYYcc

So it's working on firefox and not on Chrome, so bad...

What shall we do for that to be fixed ?

Best regards,

My guess right now is that there's a timing difference between WebAudio and the MediaStreamDestination.

Hi guys,

According to Hongchan Choi's advise, I've reset all flags in Chrome. The problem still remains.

Here's my new GPU log:


Graphics Feature Status
Canvas: Hardware accelerated
CheckerImaging: Disabled
Flash: Hardware accelerated
Flash Stage3D: Hardware accelerated
Flash Stage3D Baseline profile: Hardware accelerated
Compositing: Hardware accelerated
Multiple Raster Threads: Disabled
Native GpuMemoryBuffers: Software only. Hardware acceleration disabled
Rasterization: Hardware accelerated
Video Decode: Hardware accelerated
Video Encode: Hardware accelerated
WebGL: Hardware accelerated
WebGL2: Hardware accelerated
Driver Bug Workarounds
clear_uniforms_before_first_program_use
decode_encode_srgb_for_generatemipmap
disable_accelerated_vpx_decode
disable_delayed_copy_nv12
disable_direct_composition
disable_discard_framebuffer
disable_dxgi_zero_copy_video
disable_framebuffer_cmaa
disable_larger_than_screen_overlays
exit_on_context_lost
force_cube_complete
msaa_is_slow
scalarize_vec_and_mat_constructor_args
texsubimage_faster_than_teximage
Problems Detected
Some drivers are unable to reset the D3D device in the GPU process sandbox
Applied Workarounds: exit_on_context_lost
TexSubImage is faster for full uploads on ANGLE
Applied Workarounds: texsubimage_faster_than_teximage
Clear uniforms before first program use on all platforms: 124764, 349137
Applied Workarounds: clear_uniforms_before_first_program_use
Always rewrite vec/mat constructors to be consistent: 398694
Applied Workarounds: scalarize_vec_and_mat_constructor_args
ANGLE crash on glReadPixels from incomplete cube map texture: 518889
Applied Workarounds: force_cube_complete
On Intel GPUs MSAA performance is not acceptable for GPU rasterization: 527565
Applied Workarounds: msaa_is_slow
Framebuffer discarding can hurt performance on non-tilers: 570897
Applied Workarounds: disable_discard_framebuffer
Direct composition flashes black initially on Win <10: 588588
Applied Workarounds: disable_direct_composition
Zero copy DXGI video hangs on shutdown on Win < 8.1: 621190
Applied Workarounds: disable_dxgi_zero_copy_video
Use GL_INTEL_framebuffer_CMAA on ChromeOS: 535198
Applied Workarounds: disable_framebuffer_cmaa
Disable KHR_blend_equation_advanced until cc shaders are updated: 661715
Applied Workarounds: disable(GL_KHR_blend_equation_advanced), disable(GL_KHR_blend_equation_advanced_coherent)
Decode and Encode before generateMipmap for srgb format textures on Windows: 634519
Applied Workarounds: decode_encode_srgb_for_generatemipmap
VPx decoding isn't supported well before Windows 10 creators update.: 616318, 667532
Applied Workarounds: disable_accelerated_vpx_decode
Accelerated VPx decoding is hanging on some videos.: 654111
Applied Workarounds: disable_accelerated_vpx_decode
Overlay sizes bigger than screen aren't accelerated on some Intel drivers: 720059
Applied Workarounds: disable_larger_than_screen_overlays
Delayed copy NV12 crashes on Intel on Windows <= 8.1.: 727216
Applied Workarounds: disable_delayed_copy_nv12
Raster is using a single thread.
Disabled Features: multiple_raster_threads
Native GpuMemoryBuffers have been disabled, either via about:flags or command line.
Disabled Features: native_gpu_memory_buffers
Checker-imaging has been disabled via finch trial or the command line.
Disabled Features: checker_imaging
Version Information
Data exported	10/30/2017, 12:50:15 PM
Chrome version	Chrome/63.0.3239.18
Operating system	Windows NT 6.1.7601 SP1
Software rendering list version	13.13
Driver bug list version	10.33
ANGLE commit id	c3bc98415696
2D graphics backend	Skia/63 5a13102e94e12ff900097e61d53f84029196a104-
Command Line	"C:\Program Files (x86)\Google\Chrome\Application\chrome.exe" --flag-switches-begin --flag-switches-end
Driver Information
Initialization time	114
In-process GPU	false
Passthrough Command Decoder	false
Supports overlays	false
Sandboxed	false
GPU0	VENDOR = 0x8086, DEVICE= 0x0402
Optimus	false
Optimus	false
AMD switchable	false
Desktop compositing	Aero Glass
Diagonal Monitor Size of \\.\DISPLAY1	21.5"
Driver vendor	Intel Corporation
Driver version	9.18.10.3186
Driver date	5-17-2013
Pixel shader version	5.0
Vertex shader version	5.0
Max. MSAA samples	8
Machine model name	
Machine model version	
GL_VENDOR	Google Inc.
GL_RENDERER	ANGLE (Intel(R) HD Graphics Direct3D11 vs_5_0 ps_5_0)
GL_VERSION	OpenGL ES 3.0 (ANGLE 2.1.0.c3bc98415696)
GL_EXTENSIONS	GL_ANGLE_client_arrays GL_ANGLE_depth_texture GL_ANGLE_framebuffer_blit GL_ANGLE_framebuffer_multisample GL_ANGLE_instanced_arrays GL_ANGLE_lossy_etc_decode GL_ANGLE_multiview GL_ANGLE_pack_reverse_row_order GL_ANGLE_program_cache_control GL_ANGLE_request_extension GL_ANGLE_robust_client_memory GL_ANGLE_texture_compression_dxt3 GL_ANGLE_texture_compression_dxt5 GL_ANGLE_texture_usage GL_ANGLE_translated_shader_source GL_CHROMIUM_bind_generates_resource GL_CHROMIUM_bind_uniform_location GL_CHROMIUM_color_buffer_float_rgb GL_CHROMIUM_color_buffer_float_rgba GL_CHROMIUM_copy_compressed_texture GL_CHROMIUM_copy_texture GL_CHROMIUM_sync_query GL_EXT_blend_minmax GL_EXT_color_buffer_float GL_EXT_color_buffer_half_float GL_EXT_debug_marker GL_EXT_discard_framebuffer GL_EXT_disjoint_timer_query GL_EXT_draw_buffers GL_EXT_frag_depth GL_EXT_map_buffer_range GL_EXT_occlusion_query_boolean GL_EXT_read_format_bgra GL_EXT_robustness GL_EXT_sRGB GL_EXT_shader_texture_lod GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_s3tc_srgb GL_EXT_texture_filter_anisotropic GL_EXT_texture_format_BGRA8888 GL_EXT_texture_norm16 GL_EXT_texture_rg GL_EXT_texture_storage GL_EXT_unpack_subimage GL_KHR_debug GL_NV_EGL_stream_consumer_external GL_NV_fence GL_NV_pack_subimage GL_NV_pixel_buffer_object GL_OES_EGL_image GL_OES_EGL_image_external GL_OES_EGL_image_external_essl3 GL_OES_compressed_ETC1_RGB8_texture GL_OES_depth32 GL_OES_element_index_uint GL_OES_get_program_binary GL_OES_mapbuffer GL_OES_packed_depth_stencil GL_OES_rgb8_rgba8 GL_OES_standard_derivatives GL_OES_surfaceless_context GL_OES_texture_float GL_OES_texture_float_linear GL_OES_texture_half_float GL_OES_texture_half_float_linear GL_OES_texture_npot GL_OES_vertex_array_object
Disabled Extensions	GL_KHR_blend_equation_advanced GL_KHR_blend_equation_advanced_coherent
Window system binding vendor	Google Inc. (adapter LUID: 000000000000821e)
Window system binding version	1.4 (ANGLE 2.1.0.c3bc98415696)
Window system binding extensions	EGL_EXT_create_context_robustness EGL_ANGLE_d3d_share_handle_client_buffer EGL_ANGLE_d3d_texture_client_buffer EGL_ANGLE_surface_d3d_texture_2d_share_handle EGL_ANGLE_query_surface_pointer EGL_ANGLE_window_fixed_size EGL_ANGLE_keyed_mutex EGL_ANGLE_surface_orientation EGL_NV_post_sub_buffer EGL_KHR_create_context EGL_EXT_device_query EGL_KHR_image EGL_KHR_image_base EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_get_all_proc_addresses EGL_KHR_stream EGL_KHR_stream_consumer_gltexture EGL_NV_stream_consumer_gltexture_yuv EGL_ANGLE_flexible_surface_compatibility EGL_ANGLE_create_context_webgl_compatibility EGL_CHROMIUM_create_context_bind_generates_resource EGL_EXT_pixel_format_float EGL_KHR_surfaceless_context EGL_ANGLE_display_texture_share_group EGL_ANGLE_create_context_client_arrays EGL_ANGLE_program_cache_control EGL_ANGLE_robust_resource_initialization
Direct rendering	Yes
Reset notification strategy	0x8252
GPU process crash count	0
Compositor Information
Tile Update Mode	One-copy
Partial Raster	Enabled
GpuMemoryBuffers Status
ATC	Software only
ATCIA	Software only
DXT1	Software only
DXT5	Software only
ETC1	Software only
R_8	Software only
R_16	Software only
RG_88	Software only
BGR_565	Software only
RGBA_4444	Software only
RGBX_8888	Software only
RGBA_8888	Software only
BGRX_8888	Software only
BGRA_8888	Software only
RGBA_F16	Software only
YVU_420	Software only
YUV_420_BIPLANAR	Software only
UYVY_422	Software only
Display(s) Information
Info	Display[2528732444] bounds=0,0 1920x1080, workarea=0,0 1920x1040, scale=1, external
Color space information	{primaries:BT709, transfer:IEC61966_2_1, matrix:RGB, range:FULL, icc_profile_id:0}
Bits per color component	8
Bits per pixel	24
Diagnostics
0
b3DAccelerationEnabled	true
b3DAccelerationExists	true
bAGPEnabled	true
bAGPExistenceValid	true
bAGPExists	true
bCanRenderWindow	true
bDDAccelerationEnabled	true
bDriverBeta	false
bDriverDebug	false
bDriverSigned	false
bDriverSignedValid	false
bNoHardware	false
dwBpp	32
dwDDIVersion	11
dwHeight	1080
dwRefreshRate	60
dwWHQLLevel	0
dwWidth	1920
iAdapter	0
lDriverSize	8645120
lMiniVddSize	0
szAGPStatusEnglish	Enabled
szAGPStatusLocalized	Enabled
szChipType	Intel(R) HD Graphics Family
szD3DStatusEnglish	Enabled
szD3DStatusLocalized	Enabled
szDACType	Internal
szDDIVersionEnglish	11
szDDIVersionLocalized	11
szDDStatusEnglish	Enabled
szDDStatusLocalized	Enabled
szDXVAHDEnglish	Supported
szDXVAModes	ModeMPEG2_A ModeMPEG2_C ModeWMV9_C ModeVC1_C
szDescription	Intel(R) HD Graphics
szDeviceId	0x0402
szDeviceIdentifier	{D7B78E66-4742-11CF-F97B-0A24BBC2C435}
szDeviceName	\\.\DISPLAY1
szDisplayMemoryEnglish	1760 MB
szDisplayMemoryLocalized	1760 MB
szDisplayModeEnglish	1920 x 1080 (32 bit) (60Hz)
szDisplayModeLocalized	1920 x 1080 (32 bit) (60Hz)
szDriverAssemblyVersion	9.18.10.3186
szDriverAttributes	Final Retail
szDriverDateEnglish	5/17/2013 22:20:50
szDriverDateLocalized	5/17/2013 10:20:50 PM
szDriverLanguageEnglish	English
szDriverLanguageLocalized	English
szDriverModelEnglish	WDDM 1.1
szDriverModelLocalized	WDDM 1.1
szDriverName	igdumdim64.dll,igd10iumd64.dll,igd10iumd64.dll,igdumdim32,igd10iumd32,igd10iumd32
szDriverNodeStrongName	oem8.inf:IntelGfx.NTamd64.6.1:iHSWD_w7:9.18.10.3186:pci\ven_8086&dev_0402
szDriverSignDate	
szDriverVersion	9.18.0010.3186
szKeyDeviceID	Enum\PCI\VEN_8086&DEV_0402&SUBSYS_04021849&REV_06
szKeyDeviceKey	\Registry\Machine\System\CurrentControlSet\Control\Video\{2F129920-6981-4730-909B-23C05E139AD4}\0000
szManufacturer	Intel Corporation
szMiniVdd	n/a
szMiniVddDateEnglish	n/a
szMiniVddDateLocalized	n/a
szMonitorMaxRes	
szMonitorName	Generic PnP Monitor
szNotesEnglish	No problems found.
szNotesLocalized	No problems found.
szOverlayEnglish	Supported
szRankOfInstalledDriver	00E02001
szRegHelpText	
szRevision	
szRevisionId	0x0006
szSubSysId	0x04021849
szTestResultD3D7English	Not run
szTestResultD3D7Localized	Not run
szTestResultD3D8English	Not run
szTestResultD3D8Localized	Not run
szTestResultD3D9English	Not run
szTestResultD3D9Localized	Not run
szTestResultDDEnglish	Not run
szTestResultDDLocalized	Not run
szVdd	n/a
szVendorId	0x8086
Log Messages
GpuProcessHostUIShim: The GPU process exited normally. Everything is okay.

Thanks

@Raymond,

Indeed, when we're not using the MediaStreamDestination, it all works fine. Here's a working snippet:

https://jsfiddle.net/dLvLr0n7/3/

Thanks

hameshiv@

So it is not using any AudioWorklet feature (experimental features off) and MediaStreamDestination code has not been touched for a while. Do you think this is a recent regression? If so, when did it start on your end?

We've reproduced it on an old version of our web application, some 18 months ago. Starting from the first implementation of MediaStreamDestination, we can spot this issue.

It seems we had this problem more often lately, let's say from Chrome 60. I don't really know of a simple way to downgrade my Chrome install and test it over earlier versions...

Thanks

As you probably did also, I just got an automatic notification about a related issue, from one year ago: https://bugs.chromium.org/p/chromium/issues/detail?id=638823

Isn't it strongly connected ?

I've tested now on Chrome 57, it all works totally fine.

@Raymond: Would it be linked in any way to the switch we've made from 16 bits audio to 24 bits ?

Thanks

Sorry, I don't know what this switch from 16 to 24 means?  Something on your side? Some on Chrome's side?

And Chrome 57 is old enough that we kind of don't care.  What about current stable or beta? I was seeing the issue with beta.

(Sorry, haven't had a chance to look into this much.)

Hi Raymond,

24 bits audio was one of your epic achievements: https://bugs.chromium.org/p/chromium/issues/detail?id=659641

Remember ?

Ah, ok.  That was a small tweak, and only at the final output to the audio device.  This is something different because we pass floats everywhere.

Dear people,

Had a very interesting case today with one of our users. Because of her zoom ration on Chrome, the scrolling bar was showing back and forth, causing the display to "jump". 

Guess what? Yes, the sound was also lagging.

Corrected the zoom to default, sound got smooth again.

Hence my conclusion: this issue is definitely related to display. Am I mistaken?

Hi Raymond,

Seeing that the issue has been assigned to you feels us with hope.

Let me know if we can be on any help.

Thanks

Hi, 
Are there any updates regarding this issue?

Our system needs the web-audio sound to be very very accurate.
It looks like chrome browser is not trusty, since many times the sound comes out distorted .
Even though this is a major bug of chrome, it seems like there is no progress, like it's just being ignored.

Raymond, Hongchan,

May it be an happy new year!

We finally found the first branch point that causes the problem to appear.

It's 467821 from version 60.0.3083.

Reviewing the commits, I feel that this one is to blame: https://chromium.googlesource.com/chromium/src/+/1492075fce7add79a11e13a3c40d55261f4ae89d

We hope to hear from you soon, and we're definitely glad to have been of some help here.

Thanks

The CL you're referencing is actually not relevant to your application at all. The WebThread is only activated when you're using AudioWorklet. If you don't explicitly call "audioWorklet.addModule()", WebAudio does not use this new threading mechanism.

This can be easily verified via chrome://tracing. As long as AudioWorklet is not touched, WebAudio runs on the single thread mode - and the thread is a RT priority thread, so there is no conflict with the display rendering tasks.

Hi,

I get your point.

Anyway,  this is the first position at which the audio lag appears.

Can you track the exact change that causes it?

Also,  please forget about the relation to display rendering.

Audio is unstable after a short time, even if nothing is done, or using an
app like cpukiller to emphasis the bug on purpose.

hameshiv@ could you please do trace recording while observing the issue?
https://www.chromium.org/developers/how-tos/trace-event-profiling-tool/recording-tracing-runs

@olka

Trace is attached

Thanks

Deleted: trace_20180401-1639.json.gz 4.0 MB

trace_20180401-1639.json.gz 4.0 MB Download

hameshiv:  What test did you run to get this trace? https://jsfiddle.net/dLvLr0n7/?

Yes, exactly

To simplify the code under test, I ripped out the parts from the fiddle and served up the page from a local http server. (See attached file.)

Surprisingly, when I press play on the fiddle, I get a certain pitch. When I run the page locally, I get a *different* pitch.  Whaaattt?

The pitch change takes a lot longer to happen now on the jsfiddle page than I remember too.  But I think my version of chrome (beta) has changed since I last ran it.

Deleted: fiddle.html 1.0 KB

fiddle.html 1.0 KB View Download

Weirder and weirder. Using the jsfiddle, I can toggle play and each time the pitch changes.  But if I do the same thing with fiddle.html, the pitch stays constant between toggles as expected.

Something weird about how jsfiddle works.

Oh, and the trace file captured in c#40 is missing information about the audio device thread and web audio.  When capturing the trace, you need to edit the categories, scroll down to the bottom and select webaudio and probably webrtc.

Hi Raymond and thanks for your efforts.

Sorry to say, but this has absolutely nothing to do with jsfiddle or any other variable.

- We know for sure that CPU performance has major impact on any audio being redirected to audio element
- This can be reproduced by running our application or our fiddle, together with Cpukiller3 for CPU load simulation
- This happens only for Chromium after branch point 467821 and is totally working before this point

I invite you to forget about all false tracks we've been on before, such as display or jsfiddle related issue. We know for sure how to show the bug, and at which point it started to happen.

Regarding the trace, I'll upload a better one soon.

Thanks

Here's the tracing with webaudio checked.

Didn't find the webrtc option there.

Thanks

Deleted: trace_10012018.json.gz 6.9 MB

trace_10012018.json.gz 6.9 MB Download

Thanks for the update.  I still find it odd that my local file vs jsfiddle produces different frequencies.  That doesn't happen with plain webaudio oscillators; only when a MediaStreamAudioDestinationNode is used does it become a problem.

I don't think any is debating that CPU load can affect audio. But I see the weird effects on jsfiddle on my lightly loaded Z840 (load avg 0.5, 56 cores).

I am intrigued that this was fine before r467821 and bad afterwards.  Have you tried a bisect to find the exact version that this changed? Is it 467821?

Exactly, this is the first point.

By the way we've performed the search manually (installing one after the other until we found), we don't have complete bisect logs.

Still, it makes no doubt this started there.

Oh, sorry you did the bisect by hand.  I use https://www.chromium.org/developers/bisect-builds-py to do that.  Testing is done by hand, but the manual labor of bisection is done by the script.

Any way, I'll do a bisect myself to see if we can isolate when this happened.  That would be really helpful.

Oops.  For tracing, you also need to enable audio.  Hongchan can provide more details on exactly what needs to be done.

But I can do my own tracing here.

Just to clarify, you ran the jsfiddle repro case, started tracing, and pressed the toggle button to hear the pitch changes?

Here's the new trace with the following steps:

- At start, the oscillator is already playing
- After a few seconds, I slow down the CPU using cpukiller3. Sound changes pitch and becomes hashed.
- Then I disable the slow-down, sound is continuous yet down-pitched
- After a few seconds it recovers back

Deleted: trace_10012018b.json.gz 4.5 MB

trace_10012018b.json.gz 4.5 MB Download

Ok, first off, I kind of don't care about the case where the CPU is not powerful enough to run the test case (for this bug). (Which you simulate by running cpukiller3).  There are lots of webaudio apps that don't run if your cpu is not powerful enough.  We can optimize the code more but it won't solve all the weak cpu problems.

Is this bug about weak cpus not working? Or is it the pitch change?

However, I am concerned about the pitch change that I see without using cpukiller.  What's troubling there is that I can't reproduce the pitch change running the test locally.  Something about jsfiddle.net makes the pitch change happen.  But jsfiddle has all kinds of things running on the page too.

And a bisect (in progress) shows that r466267 also has the pitch change issue on jsfiddle.net.

I'm not sure if the jsfiddle.net is really representative of the actual issue anymore.  Ideally we should run the actual code that you're running.  (Well, a  simplified version because we don't want to debug the full app either.)

My guess is that AudioShifter is causing the pitch to change because the push and pull aren't happening at the same rate.  okla@ can say more about that.

The bug is really about audio frequency and speed being dependent on system performance.

That wasn't the case before Chrome 60, but it is definitely now. It affects some of our users in real life, with not so bad configurations, and makes web audio somehow unreliable as far as we're concerned.

The jsfiddle is really representative of the issue, even more than our full application would be. The point is that when the browser gets a bit busy (running features of jsfiddle or anything else), the audio is slowing. It's nothing specific of jsfiddle, but could be reproduced in a lot of ways, for sure.

One more thing: it's not about optimization, but it's a yes or no issue. Before Chrome 60, it just won't happen, ever. After it, it always happens. 

It would be great to hear some WebRTC insight about this.

Thanks to all

Let's leave jsfiddle for now.

It's fully reproduced on this hosted page: http://lesgold.com/rtoy/fiddle.html

Enjoy

Thanks for the clarifications. I understand better the problem that you're seeing.

For the new hosted page, I don't have any issues with it. I assume you are because you're running cpukiller?

If so, I do think the underlying problem is in AudioShifter which is trying to match up the push and pull rates.

With webaudio, low cpu will just cause glitches in the audio; there won't be a pitch change.  Because you hear a pitch change (and maybe glitching), the connection between webaudio and MediaStreamAudioDestination (audio tag) is causing the problem.  

WDYT okla@?

"Because you hear a pitch change (and maybe glitching), the connection between webaudio and MediaStreamAudioDestination (audio tag) is causing the problem."

I can only confirm that. We've been suspecting that for a long time, as you know.

So we'll wait for olka@ ?

In the trace from #51 around 3 seconds when cpukiller kicks in, you can see Media and Main calls become more rear, and both CPUs are busy with cpukiller (which apparently has a higher priority) - see slow_down.png.
"Media" calls are AudioDestination::Render calls initiated by a fake worker thread and are supposed to fill in the audio shifter - but fail, because they are not scheduled.

Audio callbacks from the sound card are not slowed down - they run on a real-time thread. So they pull data from the audio shifter, which underruns because of the above. And the audio shifter does what it is meant to do in this situation: stretches audio to compensate.

So this is WAD from the audio pipeline perspective.

There probably was some change regarding how WebAudio calls are scheduled.

There was also scheduling issue I'll check tomorrow - I don't remember which milestone it hit.

Deleted: slow_down.png 100 KB

	slow_down.png 100 KB View Download

At this point I wonder why WebAudio rendering is driven by a fake worker.
It looks like SilentSinkSuspender [1] is working, which is supposed to the the case only if AudioContext is silent.

rtoy@:
I'm totally unfamiliar with WebAudio API - is AudioContext expected to be silent in lesgold.com/rtoy/fiddle.html from #54?
Or is there an issue with how suspending works?

SilentSinkSuspender on systems other than Android was introduced in [2], which landed on Jul 14 and got into M62.
We may want to consider reverting [2].
+dalecurtis@

[1] https://cs.chromium.org/chromium/src/media/base/silent_sink_suspender.h?gsn=SilentSinkSuspender&l=33
[2] https://chromium-review.googlesource.com/c/chromium/src/+/568817

A question re #53:
"That wasn't the case before Chrome 60, but it is definitely now"

The original report is M62. What was the last working version of Chrome?

It's unlikely we'd revert the silent suspender change, the abuse of idle WebAudio contexts is too rampant unfortunately and the power draw due to it too high. If there's a bug though, we can certainly fix that.

Silent sink suspender is fairly simple though, it only kicks in when zero-valued sound is produced. That test site might result int he silent suspender being invoked if you take too long to click the play button, but that doesn't seem to be a problem; it correctly switches back to a normal sink when you do.

Correction for #58: the CL in question landed in M61.

Olga,

Since original report, we've tracked the issue back to 60.0.3083.

Any stable version starting from 60 will show the bug.

Thanks

Dale, do you have any idea why WebAudio is being rendered by a fake sink in traces #51?

hameshiv@ Could you do a trace recording for 60.0.3083? (same style as M51)

I mean same style as #51

Re c#58. In the example, the oscillator is constantly playing after pressing toggle play. When you press toggle to stop it, the oscillator is stopped and disconnected from the graph.  When play is pressed again, a new oscillator is created.

So during the time between these, the context is producing silence so the SilentSinkSuspender will eventually kick in. (30 sec or so, IIRC?)

I still don't understand why I can't get the pitch change from http://lesgold.com/rtoy/fiddle.html but do when I use jsfiddle.net.

olka@ I'll be able to do so only tomorrow morning. Not at my usual workstation now (middle of the night)

rtoy@ I guess there's some performance difference between the whole JSfiddle interface and a nude page. That's why we use a soft to simulate some load and cause the problem to be loud and clear.

Hard to say; if play is clicked immediately the _SilentSinkSuspender_ should never be invoked. If some time elapses (30 seconds) before clicking play it will kick in.

There are other routes to getting the fake sink though; bad/missing audio parameters, etc. I.e. AudioManager may use one if no stream can be created. Do you know where the fake sink is being created? If AudioManager does it, there should be a log:

      LOG(ERROR) << "Invalid audio output parameters received; using fake "
                 << "audio path. Channels: " << output_params.channels() << ", "
                 << "Sample Rate: " << output_params.sample_rate() << ", "
                 << "Bits Per Sample: " << output_params.bits_per_sample()
                 << ", Frames Per Buffer: "
                 << output_params.frames_per_buffer();

But it may also be requested by the renderer side code if the browser sets the params should be FAKE; though I forget who sets that now. chrome://media-internals should show fake for the audio side of things if so.

Yes, I looked at the other places but AudioOutputDevice seems to be working fine here, which is confusing.

rtoy@ have you checked what is going on in #51 on CrRendererMain with BaseAudioContext::ScheduleMainThreadCleanup calls, which also become less periodic when CPU is under load?

No, I've been kind of ignoring the loading issue because I was able to hear the pitch changes from jsfiddle.net, so it's not a load problem.

Except I just tried again, and I can't hear the pitch changes anymore.  Toggling play used to be pretty reliable in producing different pitches.

I advise to wait about 30 seconds. The pitch slide isn't happening at once if you use a "normal" workstation.

Dale, do I read the code correctly:
When suspender is switched to the fake worker, the fake worker keeps calling Render() with the same (last known) timestamp [1]. After it switches back to the real sink, real timestamps (which are way ahead now) start coming again.

If so, can it be that AudioShifter occasionally becomes unhappy after such jumps?


[1] https://cs.chromium.org/chromium/src/media/base/silent_sink_suspender.cc?type=cs&l=135

No, sorry, looks like #74 is incorrect: time stamp always advances.

Olka,

Following your request, please find in attachment the two tracing, for branch points 467800 (working fine) and 467821 (failing upon CPU load).

Please update us on how we could help further.

Thanks

Deleted: trace_467800.json.gz 2.7 MB

trace_467800.json.gz 2.7 MB Download

Deleted: trace_467821.json.gz 4.3 MB

trace_467821.json.gz 4.3 MB Download

Thanks hameshiv@!

The difference I see:

In 467800 TrackAudioRenderer::CaptureData() runs on (one of two) AudioOutputDevice threads (priority 15).

In 467821 TrackAudioRenderer::CaptureData() runs on "WebAudio rendering thread" (priority 9).

In both cases cpukiller is priority 15. So in 467821 it just does not give CaptureData() a chance to run.

rtoy@ could you figure out how WebAudio thread got involved?

The dual-thread rendering was introduced by the revision 467819:
https://codereview.chromium.org/2777903005/

Please note that this is version 60 we're talking about. The change in 467819 was effectively reverted by the revision 497109 (which is v62):
https://chromium-review.googlesource.com/c/chromium/src/+/617588

So let me clarify the situation once more -
1. Unless the user code explicitly call audioWorklet.addModule(), WebAudio runs on the AudioDeviceThread - as in a single thread.
2. If you want to bisect the problem correctly, your last known good revision should be after 497109, not the some revision from v60.

Hongchan,

I attach here the tracing from 497118. 

This is definitely not working back then. I still maintain that the last good version is 467800.

Thanks all for your efforts

Deleted: trace_497118.json.gz 4.3 MB

trace_497118.json.gz 4.3 MB Download

Thanks hameshiv@ for providing valuable data.
In #80 We have
TrackAudioRenderer::Render() driven by AudioOutputDevice (real-time thread) - as in all cases above.

On the other hand,
AudioDestination::Render() -> AudioDestination::RequestRender() -> AudioDestinationHandler::Render() -> TrackAudioRenderer::Capture()
call stack is driven by fake audio worker (priority 10) - which gets de-scheduled when cpukiller with priority 15 kicks in.

Correction in #81: TrackAudioRenderer::Capture() is TrackAudioRenderer::OnData()

It looks like TrackAudioRenderer::OnData() is driven by SilentSinkSuspender (We should probably add traces to it).
Which means AudioDestination::Render replies with an empty buffer when being called by RendererWebAudioDeviceImpl.
Which means fifo_Pull in AudioDestination constantly feeds an empty buffer into |output_bus_| [1].

Why do we first pull data from FIFO (which should be empty when rendering starts) and only then try to fill it in with RequestRender [2]?
Should it be reversed?

I would also recommend to add traces into PushPullFIFO.

[1] https://cs.chromium.org/chromium/src/third_party/WebKit/Source/platform/audio/AudioDestination.cpp?type=cs&sq=package:chromium&l=130
[2] https://cs.chromium.org/chromium/src/third_party/WebKit/Source/platform/audio/AudioDestination.cpp?type=cs&sq=package:chromium&l=142

Re #80:

Thanks for your data, but the revert of dual-thread rendering is in 62.0.3198.0. The revision 497118 is 62.0.3196.0. Is there any reason that you can't test the app with the current stable version?

Re #83:

> call stack is driven by fake audio worker (priority 10)

Why WebAudio gets pulled by Fake Audio Worker? Not sure what that means.

> Why do we first pull data from FIFO (which should be empty when rendering starts) and only then try to fill it in with RequestRender [2]? Should it be reversed?

Because AudioDestination needs to support dual thread rendering when it's requested. The code is arranged to support the change from single to dual thread rendering dynamically.

For the single-thread mode there isn't much of difference except that you get the silence for the first pull. The data will be available in the next pull.

> I would also recommend to add traces into PushPullFIFO.

You mean Push() and Pull()? Sure. Let's do that.

Hongchan,

Attachments per your request: 497674 (first point for 62.0.3198.0) and 508578 (current stable).

Both are still choppy.

Good luck

Deleted: trace_497674.json.gz 4.1 MB

trace_497674.json.gz 4.1 MB Download

Deleted: trace_508578.json.gz 4.1 MB

trace_508578.json.gz 4.1 MB Download

hameshiv@

Thanks! This is really helpful.

In 497674, I can clearly see that the first 2 seconds of no glitch - when things are called by AudioOutputDevice. This is what is supposed to be. Fake Audio Worker, however, kicks in around 2 second and then things start get choppy. I am not really sure what is causing this.

In 508578, actually everything runs on Fake Audio Worker. It also gets choppy around 2.5sec.

FWIW, the WebAudio renderer is finishing the task requested much earlier than its deadline in both traces. So I strongly believe that this is neither "dual-thread" rendering issue nor WebAudio underflow issue.

From what I see, the problem is MessageLoop::RunTask (in fake_audio_workler) is behaving badly. It is going ~100ms of normal state and then it's blocked for the next ~100ms.


olka@

What is fake_audio_worker and when is it being used? What might be the reason of this "burst and blocked" pattern?

Honchan, Olga,

I must remind you of the scenario we use here: Trace is started with the sound already playing. Then after a few seconds (yes, around 2s), I slow down the CPU by 50%. Then I shutdown the killer and wait a few more seconds for the audio to "recover".

So it's clear that the first second without glitch are part of the period before I slow down the CPU on purpose.

By the way, I also need to say again that before 467821, this procedure arises absolutely no issue.

Hope this helps.

Also, let me ask: since we know the exact branch point where the problem appears (and I'm still quite certain of it, despite all other propositions that proved wrong - with all respect), shouldn't we look for the root cause around there ?

Re #88:

So this Fake Audio Worker might be the side effect from CPU killer. Have you found something by comparing the trace between 467821 and the current stable?


Re #89:

The revision 467821 seems quite random to me. I think it's better to diagnose what's happening now and fix the cause in the current system.

In browser, so many things are change fast in different layers. Even if you find something to fix in M60's code, there is no way to revert the whole 4 versions of changes to fix this specific issue.

Also a reminder: one doesn't need to use specifically cpukiller to
reproduce the issue.

On average to weak configurations, resizing the window or scrolling will
impact the audio pretty well.

I'm not able by myself to analyse the traces but this I can tell: Chromium
had problems dealing with cpu load and audio for at least three versions.

Re #85:
>> Why WebAudio gets pulled by Fake Audio Worker? Not sure what that means.

Please see #58, #60, #68, #83.

Why is the SilentSinkSuspender running? I thought that only happened if the audio is silent for at least 30 sec.

I wish I knew. Can you repro it locally?
+miu for TrackAudioRenderer.

I'm using ToT from today with https://jsfiddle.net/dLvLr0n7/ as the test URL.  I'm running on my (mostly) unloaded Linux machine.

To run this, I now now have to press the Run button on the page ("AudioContext must be created or resumed after the document received a user gesture").

Press "Toggle play". I hear a 440 Hz sine wave.  Press again to stop.  Wait a couple of seconds.  I hear a different, lower pitch.

When I look at chrome://media-internals, I see there are two output controllers. One has frames_per_buffer = 512.  The other has 441.  Otherwise, the controllers appear to have the same parameters.

If I go to a different (dev console) window and do:

c = new AudioContext();
o = new OscillatorNode(c);
o.connect(c.destination);
o.start();

I hear a nice 440 Hz tone.  Then do o.frequency.value *= 441/512.0;  I hear the same lower pitched tone.

Could chrome be somehow switching between the two controllers for output?

Could you upload traces and media-internals?

Hi,

Any news on this important issue?

Thanks

Raymond, Olga... Looking forward to hear some updates...

To get the test URL working again (auto-play changes in Chrome 66), I created a new one to start playing from a user gesture:  https://jsfiddle.net/rtoy/wq9beefw/3/

With this URL, here's the media-internals for the two controllers (while the tone is playing):

Controller 4:2
channel_layout: STEREO
channels: 2
component_id: 2
component_type: 1
device_id: default
device_type: pcm_low_latency
effects: NO_EFFECTS
frames_per_buffer: 512
owner_id: 4
sample_rate: 44100
status: started
render_process_id: 13
web_contents_title: Reuse Audio Stream - JSFiddle

Controler 4:3
channel_layout: STEREO
channels: 2
component_id: 3
component_type: 1
device_id: default
device_type: pcm_low_latency
effects: NO_EFFECTS
frames_per_buffer: 441
owner_id: 4
sample_rate: 44100
status: started
render_process_id: 13
web_contents_title: Reuse Audio Stream - JSFiddle
volume: 1

The trace file is attached.  I pressed toggle play to start playing. I let it play for about 5 sec, and pressed toggle to stop.  I waited for about 5 sec and press play again.  The second play results in a tone with lower frequency.

All this was done using ToT chromium from this morning. (Chrome 66 canary, roughly).

Deleted: trace_766198-m66.json.gz 836 KB

trace_766198-m66.json.gz 836 KB Download

Using ToT from this morning, I did a debug build and ran https://jsfiddle.net/rtoy/wq9beefw/3/.  Press play and wait a bit. A nice 440 Hz tone is played.  Press play to stop. Wait 5-10 sec.  Press play.  Crash.  Backtrace is:

[27322:27322:0213/122003.673478:INFO:CONSOLE(52)] "URL.createObjectURL with media streams is deprecated and will be removed in M68, around July 2018. Please use HTMLMediaElement.srcObject instead. See https://www.chromestatus.com/features/5618491470118912 for more details.", source: https://fiddle.jshell.net/rtoy/wq9beefw/3/show/ (52)
[27805:27910:0213/122005.459120:WARNING:PushPullFIFO.cpp(190)] PushPullFIFO: underflow while pulling (underflowCount=1, availableFrames=0, requestedFrames=512, fifoLength=12288)
[27805:27908:0213/122036.365342:FATAL:track_audio_renderer.cc(75)] Check failed: audio_thread_checker_.CalledOnValidThread(). 
#0 0x7fa43275d9fd base::debug::StackTrace::StackTrace()
#1 0x7fa43275beec base::debug::StackTrace::StackTrace()
#2 0x7fa4327e493a logging::LogMessage::~LogMessage()
#3 0x7fa42e0be9b2 content::TrackAudioRenderer::OnData()
#4 0x7fa42e0725c3 content::MediaStreamAudioDeliverer<>::OnData()
#5 0x7fa42e0710b3 content::MediaStreamAudioTrack::OnData()
#6 0x7fa42e06df1b content::MediaStreamAudioDeliverer<>::OnData()
#7 0x7fa42e06b9ef content::MediaStreamAudioSource::DeliverDataToTracks()
#8 0x7fa42e0e8cb4 content::WebAudioMediaStreamSource::DeliverRebufferedAudio()
#9 0x7fa42d5d485f void base::internal::FunctorTraits<void (content::PepperTCPServerSocketMessageFilter::*)(ppapi::host::ReplyMessageContext const&, int), void>::Invoke<content::PepperTCPServerSocketMessageFilter*, ppapi::host::ReplyMessageContext const&, int>(void (content::PepperTCPServerSocketMessageFilter::*)(ppapi::host::ReplyMessageContext const&, int), content::PepperTCPServerSocketMessageFilter*&&, ppapi::host::ReplyMessageContext const&, int&&)
#10 0x7fa42d5d47ba void base::internal::InvokeHelper<false, void>::MakeItSo<void (content::PepperTCPServerSocketMessageFilter::* const&)(ppapi::host::ReplyMessageContext const&, int), content::PepperTCPServerSocketMessageFilter*, ppapi::host::ReplyMessageContext const&, int>(void (content::PepperTCPServerSocketMessageFilter::* const&)(ppapi::host::ReplyMessageContext const&, int), content::PepperTCPServerSocketMessageFilter*&&, ppapi::host::ReplyMessageContext const&, int&&)
#11 0x7fa42e0ea085 void base::internal::Invoker<base::internal::BindState<void (content::WebAudioMediaStreamSource::*)(media::AudioBus const&, int), base::internal::UnretainedWrapper<content::WebAudioMediaStreamSource> >, void (media::AudioBus const&, int)>::RunImpl<void (content::WebAudioMediaStreamSource::* const&)(media::AudioBus const&, int), std::__1::tuple<base::internal::UnretainedWrapper<content::WebAudioMediaStreamSource> > const&, 0ul>(void (content::WebAudioMediaStreamSource::* const&)(media::AudioBus const&, int), std::__1::tuple<base::internal::UnretainedWrapper<content::WebAudioMediaStreamSource> > const&, std::__1::integer_sequence<unsigned long, 0ul>, media::AudioBus const&, int&&)
#12 0x7fa42e0ea003 base::internal::Invoker<base::internal::BindState<void (content::WebAudioMediaStreamSource::*)(media::AudioBus const&, int), base::internal::UnretainedWrapper<content::WebAudioMediaStreamSource> >, void (media::AudioBus const&, int)>::Run(base::internal::BindStateBase*, media::AudioBus const&, int)
#13 0x7fa428baea16 base::RepeatingCallback<void (media::AudioBus const&, int)>::Run(media::AudioBus const&, int) const &
#14 0x7fa428bae856 media::AudioPushFifo::Push()
#15 0x7fa42e0e9e56 content::WebAudioMediaStreamSource::ConsumeAudio()
#16 0x7fa41d2e84d3 blink::ConsumerWrapper::ConsumeAudio()
#17 0x7fa41d6a4543 blink::MediaStreamSource::ConsumeAudio()
#18 0x7fa41c700511 blink::MediaStreamAudioDestinationHandler::Process()
#19 0x7fa41c689b25 blink::AudioHandler::ProcessIfNecessary()
#20 0x7fa41c6f1617 blink::DeferredTaskHandler::ProcessAutomaticPullNodes()
#21 0x7fa41c683c22 blink::AudioDestinationHandler::Render()
#22 0x7fa41d22211f blink::AudioDestination::RequestRender()
#23 0x7fa41d221825 blink::AudioDestination::Render()
#24 0x7fa42de6a7ff content::RendererWebAudioDeviceImpl::Render()
#25 0x7fa428c5351f media::SilentSinkSuspender::Render()
#26 0x7fa428c558cf int base::internal::FunctorTraits<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*), void>::Invoke<media::SilentSinkSuspender*, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&>(int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*), media::SilentSinkSuspender*&&, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&)
#27 0x7fa428c557d1 void base::internal::FunctorTraits<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)>, void>::Invoke<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, media::SilentSinkSuspender*, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&>(base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, media::SilentSinkSuspender*&&, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&)
#28 0x7fa428c5571d void base::internal::InvokeHelper<false, void>::MakeItSo<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, media::SilentSinkSuspender*, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&>(base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, media::SilentSinkSuspender*&&, base::TimeDelta const&, base::TimeTicks const&, int const&, decltype(nullptr) const&)
#29 0x7fa428c5569d void base::internal::Invoker<base::internal::BindState<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)>, base::internal::UnretainedWrapper<media::SilentSinkSuspender>, base::TimeDelta, base::TimeTicks, int, decltype(nullptr)>, void ()>::RunImpl<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, std::__1::tuple<base::internal::UnretainedWrapper<media::SilentSinkSuspender>, base::TimeDelta, base::TimeTicks, int, decltype(nullptr)> const&, 0ul, 1ul, 2ul, 3ul, 4ul>(base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)> const&, std::__1::tuple<base::internal::UnretainedWrapper<media::SilentSinkSuspender>, base::TimeDelta, base::TimeTicks, int, decltype(nullptr)> const&, std::__1::integer_sequence<unsigned long, 0ul, 1ul, 2ul, 3ul, 4ul>)
#30 0x7fa428c554ac base::internal::Invoker<base::internal::BindState<base::internal::IgnoreResultHelper<int (media::SilentSinkSuspender::*)(base::TimeDelta, base::TimeTicks, int, media::AudioBus*)>, base::internal::UnretainedWrapper<media::SilentSinkSuspender>, base::TimeDelta, base::TimeTicks, int, decltype(nullptr)>, void ()>::Run(base::internal::BindStateBase*)
#31 0x7fa428ada94d base::RepeatingCallback<void ()>::Run() const &
#32 0x7fa428bdf28e media::FakeAudioWorker::Worker::DoRead()
#33 0x7fa428af738f void base::internal::FunctorTraits<void (media::AudioInputController::*)(), void>::Invoke<scoped_refptr<media::AudioInputController>>(void (media::AudioInputController::*)(), scoped_refptr<media::AudioInputController>&&)
#34 0x7fa428af7304 void base::internal::InvokeHelper<false, void>::MakeItSo<void (media::AudioInputController::*)(), scoped_refptr<media::AudioInputController> >(void (media::AudioInputController::*&&)(), scoped_refptr<media::AudioInputController>&&)
#35 0x7fa428af72b0 void base::internal::Invoker<base::internal::BindState<void (media::AudioInputController::*)(), scoped_refptr<media::AudioInputController> >, void ()>::RunImpl<void (media::AudioInputController::*)(), std::__1::tuple<scoped_refptr<media::AudioInputController> >, 0ul>(void (media::AudioInputController::*&&)(), std::__1::tuple<scoped_refptr<media::AudioInputController> >&&, std::__1::integer_sequence<unsigned long, 0ul>)
#36 0x7fa428affffc base::internal::Invoker<base::internal::BindState<void (media::AudioInputDevice::*)(), scoped_refptr<media::AudioInputDevice> >, void ()>::Run(base::internal::BindStateBase*)
#37 0x7fa428ada94d base::RepeatingCallback<void ()>::Run() const &
#38 0x7fa428b63cd5 void base::internal::CancelableCallbackImpl<base::RepeatingCallback<void ()> >::ForwardRepeating<>()
#39 0x7fa428ade5ef void base::internal::FunctorTraits<void (media::AliveChecker::*)(), void>::Invoke<base::WeakPtr<media::AliveChecker>>(void (media::AliveChecker::*)(), base::WeakPtr<media::AliveChecker>&&)
#40 0x7fa428ade50a void base::internal::InvokeHelper<true, void>::MakeItSo<void (media::AliveChecker::*)(), base::WeakPtr<media::AliveChecker>>(void (media::AliveChecker::*&&)(), base::WeakPtr<media::AliveChecker>&&)
#41 0x7fa428ade4a0 void base::internal::Invoker<base::internal::BindState<void (media::AliveChecker::*)(), base::WeakPtr<media::AliveChecker> >, void ()>::RunImpl<void (media::AliveChecker::*)(), std::__1::tuple<base::WeakPtr<media::AliveChecker> >, 0ul>(void (media::AliveChecker::*&&)(), std::__1::tuple<base::WeakPtr<media::AliveChecker> >&&, std::__1::integer_sequence<unsigned long, 0ul>)
#42 0x7fa428b63d9c base::internal::Invoker<base::internal::BindState<void (base::internal::CancelableCallbackImpl<base::RepeatingCallback<void ()> >::*)(), base::WeakPtr<base::internal::CancelableCallbackImpl<base::RepeatingCallback<void ()> > > >, void ()>::Run(base::internal::BindStateBase*)
#43 0x7fa43270c1b1 base::OnceCallback<void ()>::Run() &&
#44 0x7fa43276192a base::debug::TaskAnnotator::RunTask()
#45 0x7fa432801209 base::internal::IncomingTaskQueue::RunTask()
#46 0x7fa43280a5fb base::MessageLoop::RunTask()
#47 0x7fa43280a898 base::MessageLoop::DeferOrRunPendingTask()
#48 0x7fa43280aedb base::MessageLoop::DoDelayedWork()
#49 0x7fa43280d79a base::MessagePumpDefault::Run()
#50 0x7fa432809dbc base::MessageLoop::Run()
#51 0x7fa4328c133d base::RunLoop::Run()
#52 0x7fa432986568 base::Thread::Run()
#53 0x7fa4329871d5 base::Thread::ThreadMain()
#54 0x7fa43296cfad base::(anonymous namespace)::ThreadFunc()
#55 0x7fa432cc4494 start_thread
#56 0x7fa4182cfa8f clone

Note that SilentSinkSuspender::Render is in the backtrace.  I only paused for at most 10 sec which shouldn't be long enough for the silent sink to be running.

re #99:

There is no AudioShifter in the traces, and audio rendering pipeline is totally fine. How do media internals look like when the tone is not playing?
Could you measure the actual tone frequency before the pause and after the resume?

--

Why AudioDestination chooses to open audio output device at 512 frames per buffer for 44.1 kHz stream? And why does it have to open a physical device if rendering is actually performed by TrackAudioRenderer?

miu@ could you comment?

Looks like the problem is not the buffer sizes at all (that could just be start-up jank). This part of the log in #c100 seems most relevant:

[27805:27908:0213/122036.365342:FATAL:track_audio_renderer.cc(75)] Check failed: audio_thread_checker_.CalledOnValidThread().
<STACK TRACE FOLLOWS>

So, it seems the wrong thread is calling into TrackAudioRenderer. Why is that? (Perhaps find out where the task is being posted from and `git log -- FILE(s)` to determine what code change caused this issue?)

Hi,

The problem is still here after 7 months, and no solution at the horizon.

Please let us know if there's some hope to produce descent audio on Chrome.

Thanks

Using a chromium build from this morning, I can no longer reproduce the issue using https://jsfiddle.net/dLvLr0n7/ or https://jsfiddle.net/rtoy/wq9beefw/3/

Pressing play multiple times (with pauses or not between them) produces a nice 440 Hz tone now. I can't get the pitch change anymore.

hameshiv@ If you haven't, can you retest with Chrome canary?

There have been a few changes to webaudio, but I don't think any of them should affect this.

Raymond,

Tested just now on Canary 67.0.3376.1 - The problem's still the same.

I've attached the trace.

Thanks

Deleted: trace_2003canary.json.gz 3.5 MB

trace_2003canary.json.gz 3.5 MB Download

I still cannot reproduce this.  From the trace file in c#105, I do see that AudioOutputDevice is call very regularly except for a few places where it seems the call is delayed by almost one period.  That's not expected, but I think having the cpukiller running can totally mess things up.

Did play around a little with the cpukiller on my Windows machine.  I set it up cpukiller to cause audio to glitch.  But didn't really notice any other artifact, except, perhaps a very slight pitch change.  Nothing like I was seeing before on my linux machine without any kind of cpu killer.  Sadly that old effect isn't reproducible on my machines.

Hi Raymond,

On my side the pitch change is significant (see earlier videos). I guess you have some good hardware then...

It's important to keep in mind that before 60 it was totally fine.

How does all this get us closer to a fix?

Thanks for your efforts

I do not know.  The first step is being able to reproduce it reliably.  It was reliable for a bit but now I can't reproduce this at all.  I will keep trying, but until we can reproduce somewhat reliably, it's going to be very hard to figure out.  I wish I had a better answer.

Sorry, but I really don't understand what is the issue about reproducing.

I've made a new video now on Canary 68: starting Cpukiller at 50% makes the bug appear at once. Turning it off makes audio recover after some time.

https://youtu.be/Bh5GHO4XeDU

What is not reproduced at your side?

I did try cpukiller. I could reproduce the glitches but not the pitch change. I will try again.  

I am reluctant to take any action if it can only be reproduced using cpukiller.  And I know that wasn't a requirement before because I could reproduce the pitch change, but can't anymore, sadly.

I'm also reluctant dig into the case with cpukiller running.  If it reproduces only if your machine is overloaded, there's not a lot we can do about it.  (But again, I know it's not just because it's overloaded because my machine wasn't when I was able to repro the issue.)

I should have taken a closer look when I could see the issue, but I had other things I really needed to be done then.

I will continue to try to reproduce this somehow.

To get things clear: cpukiller is only a way to ensure that the anomaly happens every time. 
On my computer, the bug occurs even without it, and so does it on a significant share of our users.

Bottom line, the audio is not reliable (not enough) on Chromium, and that should worry everyone of us.