1707762 - Common system calls are delayed by a large amount on Windows 10 on a machine running Carbon Black

Status: NEW

(External Software Affecting Firefox :: Other, defect)

Description

[alex_mayorga]

¡Hola y'all!

Having terrible stuttering on Spotify web player randomly on Nightly today.

Here's a profile FWIWI: https://share.firefox.dev/3dRxVbe

Hope y'all can make it better.

¡Gracias!
Alex

Comment 1

[Jim Mathies [:jimm]]

Hey Alex,

Do you have any webextensions that might be doing something here? I don't see much in this profile related to gfx or media playback. Could you p[ost your about support text?

Comment 2

[alex_mayorga]

Attachment: about support text

Comment 3

[alex_mayorga]

¡Hola Jim!

Thanks for looking into this.

I've attached the data requested.

Please let me know if anything further is needed on this bug report.

¡Gracias!
Alex

Comment 4

[Paul Adenot (:padenot)]

Alex, is this with your bluetooth device (Arctis 3 headphones) that I see in about:support ?

So weird. Your audio output frequently stops requesting new data, and I don't know that anything changed in this range. Matthew, any idea what could have changed 15 days ago ?

See the profile, lane AudioIPC0 in process 9088, marker charts: there are long pauses, and then a data request for 90ms worth of audio, while the regular callback is 10ms, like it's usually the case on Windows.

Comment 5

[Matthew Gregan [:kinetik]]

I'm not aware of any changes around 27th April that would explain this.

I notice there are instances of the DataCallback taking up to 318ms (around 6.77-7.08s) in process 9596, as well as similarly slow GetPosition calls (291ms) in process 9088 (starting around 7.07s). It's possible the audio remoting is getting into a bad state with entrained tasks as a downstream result of the slow DataCallbacks in 9596, but I'm not sure.

If Alex can reproduce this in a current nightly, it might be useful to temporarily set media.cubeb.sandbox to false, restart Firefox, and see if the problem still occurs.

Comment 6

[alex_mayorga]

¡Hola Paul, Matthew!

Thanks for looking into this.

The issue is not Bluetooth related as I use the headphones wired.

I captured another profile today FWIW:

https://share.firefox.dev/3wsl6dZ

I will try again tomorrow with media.cubeb.sandbox to false so keeping the ni? in place for now.

¡Gracias!
Alex

Comment 7

[Matthew Gregan [:kinetik]]

Thanks for the new profile, Alex. Unfortunately I can't see an obvious cause. Unlike in comment 5, there's no evidence of the strange audio remoting behaviour in this one (e.g. no slow GetPosition calls), so that may have been related to whatever was happening in process 9596 in the first profile (this behaviour doesn't appear in the new profile at all). Given that, I doubt flipping the media.cubeb.sandbox pref will affect this at all, but it may still be a useful data point.

What spec machine are you testing on? I notice the GPU in about:support is an integrated Intel HD 620, so I guess this a 2 core/4 thread 7xxx series CPU?

Have you tried reproducing this with all extensions disabled? Also, do you experience the stuttering in a release Firefox 88 build?

Comment 8

[alex_mayorga]

¡Hola Matthew!

As mentioned in https://matrix.to/#/#perf:mozilla.org?via=mozilla.org media.cubeb.sandbox set to false seems to make this better.

Captured a profile at https://share.firefox.dev/3fRB1vI FWIW

What spec machine are you testing on? I notice the GPU in about:support is an integrated Intel HD 620, so I guess this a 2 core/4 thread 7xxx series CPU?

Processor Intel(R) Core(TM) i7-7600U CPU @ 2.80GHz 2.90 GHz
Installed RAM 24.0 GB (23.8 GB usable)
System type 64-bit operating system, x64-based processor

Have you tried reproducing this with all extensions disabled?

Not really, the web is a hostile place sans' uBlock Origin =)

do you experience the stuttering in a release Firefox 88 build?

Life's too short to run Release =)
Will be giving this a go next week once Proton releases so keeping the ni? here for now.

Please let me know if you need anything further from the profile or device.

¡Gracias!
Alex

Comment 9

[alex_mayorga]

¡Hola Matthew!

Hope these lines find you well.

Managed to reproduce the bug in Firefox Release built from https://hg.mozilla.org/releases/mozilla-release/rev/1ce0b546a957ed918a0b1f5476786864fbce87e1 as well and captured this profile:

https://share.firefox.dev/3piQ3ip

Please let me know if you need anything further from the profile or device.

¡Gracias!
Alex

Comment 10

[Paul Adenot (:padenot)]

Discussing on chat.m.o, this might be caused by a piece of software called Carbon Black.

about:third-party doesn't show much (attached).

https://share.firefox.dev/34LaD1w is another profile on the same machine (just browsing twitter), where some normal system calls are taking half a dozen seconds.

Comment 11

[Paul Adenot (:padenot)]

Attachment: about:third-party

gcp says that this is only showing RDD and that this is strange, and wanted to have someone investigate.

Comment 12

[Toshihito Kikuchi [:toshi]]

As discussed in #perf channel, it's normal to see modules only loaded into RDD.

Can you temporarily disable Carbon Black to see if the issue is resolved or not, or add firefox.exe to a sort of Carbon Black's exception list?

Comment 13

[alex_mayorga]

¡Hola Toshihito!

Unfortunately I don't have control of the device to try any of those suggestions.

Is there another way for me to confirm that's in fact the root cause of the issue somehow?

I was perusing about: pages and noticed that about:checkerboard has the following:

Checkerboard recording is enabled.

Most severe checkerboarding reports

Severity 1332 at Tue Jun 08 2021 01:32:50 GMT+0000 (Greenwich Mean Time)
Severity 1265 at Tue Jun 08 2021 01:32:50 GMT+0000 (Greenwich Mean Time)
Severity 950 at Tue Jun 08 2021 02:19:38 GMT+0000 (Greenwich Mean Time)
Severity 517 at Tue Jun 08 2021 01:32:50 GMT+0000 (Greenwich Mean Time)
Severity 507 at Tue Jun 08 2021 01:32:50 GMT+0000 (Greenwich Mean Time)

Most recent checkerboarding reports

Severity 116 at Mon Jun 07 2021 23:18:36 GMT+0000 (Greenwich Mean Time)

Would this be related perhaps?

Should I click on the [Toggle it!] button to disable this and see if performance increases?

¡Gracias!
Alex

Comment 14

[Toshihito Kikuchi [:toshi]]

I asked our graphics team about checkerboarding. Checkerboarding is what happens when the compositor displays content before the main thread is able to paint it. It can be caused by the delay somewhere, but it's not the root cause, so disabling the reporting will not help.

Comment 15

[alex_mayorga]

¡Hola Paul, Toshihito!

Hope these lines find you well.

Can y'all take a look into this new profile, por favor?

https://share.firefox.dev/3A3MW2b

A bit of context, this is from a new beefier device:

Processor 11th Gen Intel(R) Core(TM) i7-1185G7 @ 3.00GHz 1.80 GHz
Installed RAM 32.0 GB (31.7 GB usable)
System type 64-bit operating system, x64-based processor
Pen and touch No pen or touch input is available for this display

The profile was captured when https://open.spotify.com/album/5HnvoKpp1JTDYP3SNWvl2V went silent for about 5 seconds yet the UI showed the progress bar moving along just normal.

Audio playback resumed eventually but figured I share the profile in case it is helpful.

¡Gracias!
Alex

Comment 16

[alex_mayorga]

¡Hola y'all!

This is happening again this morning.

This track https://open.spotify.com/track/5mDOxSFtO6zkQFUJfOsRA0?si=73e6594fc2294245 playbacks silently starting from 0:10.

I captured another profile: https://share.firefox.dev/3fj0zT2

Hope this is helpful at pinning down the issue.

¡Gracias!
Alex

Comment 17

[Paul Adenot (:padenot)]

Nothing looks weird on those profiles, no errors, and unlike with your previous machine, everything takes the amount of time it should take. This track plays correctly here on Nightly.

I think the problem might be elsewhere, but I'm not sure where. I'm trying to think about how to debug this, because as far as the profiler is concerned, everything is working: audio is being decoded and played out.

Comment 18

[BugBot [:suhaib / :marco/ :calixte]]

Clear a needinfo that is pending on an inactive user.

Inactive users most likely will not respond; if the missing information is essential and cannot be collected another way, the bug maybe should be closed as INCOMPLETE.

For more information, please visit auto_nag documentation.