You are not logged in.

#1 2020-04-26 11:19:52

backes
Member
Registered: 2014-07-12
Posts: 9

Firefox extreme lag and tearing when GPU under load

Firefox is basically unusable when my GPU is under full load, it has extreme tearing and lags. It feels like it has a refresh rate of 0.5FPS. 
I found a similar issue in the bugtracker: https://bugs.archlinux.org/task/66029?p … ng=firefox and downgraded mesa as well as firefox but it didn't help. Other GUI applications such as spotify, the wm (bspwm) and X11, pycharm, chromium all work without issues.

I have an nvidia RTX 2080Ti and use it for machine learning. When I use gpustat or nvidia-smi, I don't even see any firefox process that runs on the GPU. I also tried to disable firefox hardware acceleration and disable addons but that didn't help.

The GPU:

$  lspci | grep ' VGA ' 
42:00.0 VGA compatible controller: NVIDIA Corporation TU102 [GeForce RTX 2080 Ti] (rev a1)

Firefox, (downgraded) mesa, and the nvidia driver

$ pacman -Q --info firefox
Name            : firefox
Version         : 75.0-1

$ pacman -Q --info mesa
Name            : mesa
Version         : 19.3.4-2

$ pacman -Q --info nvidia
Name            : nvidia
Version         : 440.82-7

I used the https://profiler.firefox.com/ and profiled a situation where the GPU is free and one where the GPU is under full load and firefox lags. However, I did not see any meaningful difference between the two recordings, but I am also not sure what exactly I should look for. I included the RenderBackend and Renderer in the profiling settings. One difference that I found is long IPC calls. Line 1 is an IPC out call when firefox works, the second line is one when firefox is unusable.  You can find the profiler output from the slow version here https://perfht.ml/2x8qLwL .

0.005ms PCompositorBridge::Msg_DidComposite — sent to Parent Process (Thread ID: 5606)
484.8ms PCompositorBridge::Msg_DidComposite — sent to Parent Process (Thread ID: 5606)

edit: after looking a bit more at the "Marker Table" tab in the profiler, I found other differences: (fast vs slow)

{
  "start": 1111216.0416249998,
  "name": "Composite",
  "dur": 0.13637000019662082,
  "title": null,
  "category": 6,
  "data": {
    "type": "tracing",
    "category": "Paint",
    "interval": "start"
  }
}

{
  "start": 1149354.196149,
  "name": "Composite",
  "dur": 533.4902310001198,
  "title": null,
  "category": 6,
  "data": {
    "type": "tracing",
    "category": "Paint",
    "interval": "start"
  }
}

I also found very long IPC in messages (only messages from the slow profile)

{
  "start": 1140781.206044953,
  "dur": 887.1413930468261,
  "name": "IPCIn",
  "title": "IPC — received from WebExtensions (Thread ID: 5717)",
  "category": 8,
  "data": {
    "type": "IPC",
    "startTime": 1140781.206044953,
    "endTime": 1141668.347438,
    "otherPid": 5717,
    "messageSeqno": -11189,
    "messageType": "PContent::Msg_AsyncMessage",
    "side": "parent",
    "direction": "receiving",
    "sync": false,
    "otherTid": 5717,
    "otherThreadName": "WebExtensions (Thread ID: 5717)"
  }
}

{
  "start": 1140781.494752,
  "dur": 886.9285260001197,
  "name": "IPCIn",
  "title": "IPC — received from Compositor (Thread ID: 5634)",
  "category": 8,
  "data": {
    "type": "IPC",
    "startTime": 1140781.494752,
    "endTime": 1141668.4232780002,
    "otherPid": 5606,
    "messageSeqno": 8632,
    "messageType": "PTexture::Msg___delete__",
    "side": "child",
    "direction": "receiving",
    "sync": false,
    "otherTid": 5634,
    "otherThreadName": "Compositor (Thread ID: 5634)"
  }
}

{
  "start": 1140782.316073,
  "dur": 886.134295000229,
  "name": "IPCIn",
  "title": "IPC — received from Compositor (Thread ID: 5634)",
  "category": 8,
  "data": {
    "type": "IPC",
    "startTime": 1140782.316073,
    "endTime": 1141668.4503680002,
    "otherPid": 5606,
    "messageSeqno": 8633,
    "messageType": "PTexture::Msg___delete__",
    "side": "child",
    "direction": "receiving",
    "sync": false,
    "otherTid": 5634,
    "otherThreadName": "Compositor (Thread ID: 5634)"
  }
}

{
  "start": 1140786.0093319844,
  "dur": 882.4849860155955,
  "name": "IPCIn",
  "title": "IPC — received from Web Content (6/8) (Thread ID: 7231)",
  "category": 8,
  "data": {
    "type": "IPC",
    "startTime": 1140786.0093319844,
    "endTime": 1141668.494318,
    "otherPid": 7231,
    "messageSeqno": -50,
    "messageType": "PNecko::Msg_GetExtensionFD",
    "side": "parent",
    "direction": "receiving",
    "sync": false,
    "otherTid": 7231,
    "otherThreadName": "Web Content (6/8) (Thread ID: 7231)"
  }
}

{
  "start": 1140786.215763,
  "dur": 882.3291149998549,
  "name": "IPCOut",
  "title": "IPC — sent to Parent Process (Thread ID: 5606)",
  "category": 8,
  "data": {
    "type": "IPC",
    "startTime": 1140786.215763,
    "endTime": 1141668.544878,
    "otherPid": 5606,
    "messageSeqno": -116,
    "messageType": "PWindowGlobal::Msg_UpdateDocumentTitle",
    "side": "child",
    "direction": "sending",
    "sync": false,
    "otherTid": 5606,
    "otherThreadName": "Parent Process (Thread ID: 5606)"
  }
}
etc.

As well as some other long calls that are maybe not related to the Compositor (only slow profile)

{
  "start": 1143331.883306,
  "dur": 467.08539799999994,
  "title": "467.09ms event processing delay",
  "name": "Jank",
  "category": 1,
  "data": null
}

{
  "start": 1143331.922216,
  "dur": 467.2804279997945,
  "name": "LongTask",
  "category": 1,
  "data": {
    "type": "MainThreadLongTask",
    "startTime": 1143331.922216,
    "endTime": 1143799.2026439998,
    "category": "LongTask"
  },
  "title": null
}

{
  "start": 1143331.925876,
  "name": "RefreshDriverTick",
  "dur": 467.27433799998835,
  "title": null,
  "category": 6,
  "data": {
    "type": "tracing",
    "category": "Paint",
    "interval": "start"
  }
}

{
  "start": 1143334.377645,
  "name": "DispatchSynthMouseMove",
  "dur": 460.38300899998285,
  "title": null,
  "category": 6,
  "data": {
    "type": "tracing",
    "innerWindowID": 2,
    "category": "Paint",
    "interval": "start"
  }
}

It looks like 5606 is the parent process:

$ pstree -p | grep "firefox"
           |-firefox(5606)-+-Web Content(5667)-+-{Web Content}(5670)
           |               |-{firefox}(5610)
           |               |-{firefox}(5611)
           |               |-{firefox}(5612)
           |               |-{firefox}(5613)
           |               |-{firefox}(5614)

How can I debug or solve this?

edit: added more output from the profiler and the profile link

Last edited by backes (2020-04-26 11:38:55)

Offline

#2 2020-04-26 14:57:52

Ropid
Member
Registered: 2015-03-09
Posts: 1,069

Re: Firefox extreme lag and tearing when GPU under load

I battled with this kind of thing on an NVIDIA GTX 560Ti and a GTX 680 4G a while ago. I couldn't really find a solution for the problem. At the time, setting Firefox to software rendering worked for me for Firefox but not for the rest of the desktop. I had problems with the desktop in general while the GPU was under heavy load. For example switching workspaces or moving windows around would have crazy stutter.

My guess is that this is just something about how the Nvidia driver works together with Xorg. I could see the Xorg process hit 100% CPU usage while I was trying to move windows around with the GPU under load.

Nvidia has a Linux support team. You could try to find out how to open a support/bug ticket with them.

There's an official Nvidia Linux forum here:

https://forums.developer.nvidia.com/c/g … /linux/148

Offline

#3 2020-05-04 15:15:22

backes
Member
Registered: 2014-07-12
Posts: 9

Re: Firefox extreme lag and tearing when GPU under load

Thanks for your answer. I wasn't aware that Nvidia has an official Linux forum. I initially cross-posted this to Firefox https://bugzilla.mozilla.org/show_bug.cgi?id=1633256 because I don't think that it's an Nvidia issue. Indeed, it looks like they relate this to an issue of coordinate transformations on X11 https://bugzilla.mozilla.org/show_bug.cgi?id=1635153 .

Offline

Board footer

Powered by FluxBB