Andrew Randrianasulu
2020-Aug-16 12:10 UTC
[Nouveau] Accumulating CPU load from Xorg process with DRI3
? ????????? ?? Sunday 16 August 2020 07:20:18 Ilia Mirkin ???????(?):> Well, if it's easy, try the patches I mailed to nouveau@ for the ddx.I applied patches manually (copy-pasted patches failed to apply by git apply, probably whitespace/end of line issues), and now I see in X log (after I left machine to run alone): [ 3584.553] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.553] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.570] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.586] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.602] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.619] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.635] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.651] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.668] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.684] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.700] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.717] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.733] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.749] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.766] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.782] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument [ 3584.798] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument and around 6mb more of those .... but X still uses small amount of CPU: op - 15:04:41 up 1:32, 2 users, load average: 1,25, 1,67, 1,60 Tasks: 220 total, 2 running, 218 sleeping, 0 stopped, 0 zombie %Cpu(s): 22,8 us, 5,9 sy, 0,3 ni, 69,2 id, 1,4 wa, 0,0 hi, 0,4 si, 0,0 st MiB Mem : 11875,3 total, 7630,1 free, 1967,5 used, 2277,7 buff/cache MiB Swap: 1145,0 total, 1145,0 free, 0,0 used. 9172,1 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2777 guest 20 0 2155076 1,2g 126108 R 84,4 10,7 69:24.46 seamonkey 1991 root 20 0 145764 78444 27936 S 14,6 0,6 6:42.10 Xorg 3697 guest 20 0 61208 17268 13580 S 12,6 0,1 7:34.75 xmms 2045 guest 20 0 6360 3932 2668 S 2,3 0,0 0:35.90 kompmgr 2068 guest 20 0 102664 48952 30764 S 2,3 0,4 2:35.98 ktorrent 2049 guest 20 0 42792 27908 23684 S 1,7 0,2 0:12.72 kicker 2319 guest 20 0 40160 21248 18548 S 1,3 0,2 0:55.63 gkrellm 2064 guest 20 0 50900 31592 23720 S 1,0 0,3 0:25.53 konsole 5086 root 20 0 0 0 0 I 0,7 0,0 0:02.57 kworker/0:2-events 10 root 20 0 0 0 0 I 0,3 0,0 0:09.96 rcu_preempt 1918 root 20 0 0 0 0 I 0,3 0,0 0:04.78 kworker/3:0-events 2240 guest 20 0 59660 37848 30248 S 0,3 0,3 0:02.36 konqueror 2389 guest 20 0 33048 22592 20376 S 0,3 0,2 0:00.24 kdesu with CPU frequency set to 1.4Ghz (minimum possible). Usually around 5.6%-6.0% vblanks still work, at least glxgears from both cards still run at ~60 fps by default I'll run with those patches for few more hours, but so far they seems to be helpful.> > On Sun, Aug 16, 2020 at 12:06 AM Andrew Randrianasulu > <randrianasulu at gmail.com> wrote: > > > > ? ????????? ?? Sunday 16 August 2020 05:49:19 ?? ????????: > > > I've tracked down at least one source of these, which is that we don't > > > handle drmWaitVBlank errors properly in the PRESENT logic (which would > > > be used in conjunction with DRI3). These errors, broadly, will happen > > > while strings are turned off and/or in DPMS sleep. Did your monitors > > > go to sleep while a video was playing? If not, there's another path > > > for it to happen... > > > > yes, X enters dpms OFF state automatically, and sometimes I even force it manually .... > > > > xset q > > Keyboard Control: > > auto repeat: on key click percent: 0 LED mask: 00000000 > > auto repeat delay: 660 repeat rate: 25 > > auto repeating keys: 00ffffffdffffbbf > > fadfffefffedffff > > 9fffffffffffffff > > fff7ffffffffffff > > bell percent: 50 bell pitch: 400 bell duration: 100 > > Pointer Control: > > acceleration: 20/10 threshold: 4 > > Screen Saver: > > prefer blanking: yes allow exposures: no > > timeout: 0 cycle: 600 > > Colors: > > default colormap: 0x65 BlackPixel: 0 WhitePixel: 16777215 > > Font Path: > > /usr/X11R7/lib/X11/fonts/cp1251/misc,/usr/X11R7/lib/X11/fonts/misc,/usr/X11R7/lib/X11/fonts/cp1251/75dpi,/usr/X11R7/lib/X11/fonts/75dpi,/usr/share/fonts/ttf/western,/usr/share/fonts/ttf/decoratives,/usr/share/fonts/TTF,built-ins,/home/guest/.fonts > > DPMS (Energy Star): > > Standby: 600 Suspend: 1200 Off: 1800 > > DPMS is Enabled > > Monitor is On > > Font cache: > > Server does not have the FontCache Extension > > ---- > > > > usually mplayer prevent blanking/dpms off while working, but Seamonkey (+ Youtube) > > strangely not, so after I watch some videos and browse some sites I usually > > leave my machine alone, so dpms kicks in .. after this I may continue to use > > Seamonkey, or try to use mplayer > > > > I also think qemu + display=sdl,gl=on triggers something comparable, in terms of > > CPU usage and sluggish X reaction over time even with DRI2 .... > > > > http://qemu.11.n7.nabble.com/qemu-system-i386-process-with-sdl-gl-on-progressively-consumes-more-and-more-host-cpu-td689409.html > > > > and I think I logged bug at Launchpad for this lately ... > > > > https://lists.gnu.org/archive/html/qemu-devel/2019-10/msg02020.html > > > > > > > > > > Cheers, > > > > > > -ilia > > > > > > On Thu, Aug 13, 2020 at 6:47 PM Ilia Mirkin <imirkin at alum.mit.edu> wrote: > > > > > > > > I'm aware of this issue, and am experiencing it myself. > > > > > > > > The issue is that drmmode_event_handler takes up more and more CPU > > > > time. It seems like some events are being "left behind". I haven't had > > > > time to debug it further yet though. > > > > > > > > I also have DRI3 enabled, but only very rarely do I make use of my > > > > secondary GPUs, and I'm pretty sure I've seen the problem happen > > > > without any PRIME usage. > > > > > > > > Cheers, > > > > > > > > -ilia > > > > > > > > On Thu, Aug 13, 2020 at 6:45 PM Andrew Randrianasulu > > > > <randrianasulu at gmail.com> wrote: > > > > > > > > > > I observed this bug for quite some time, but so far I workarounded it > > > > > with just setting DRI2 (default) in xorg.conf.d/20-nouveau.conf > > > > > > > > > > Now with two GPU i iwsh to use DRI3, so right now it set up like this: > > > > > > > > > > cat /etc/X11/xorg.conf.d/20-nouveau.conf > > > > > Section "Device" > > > > > Identifier "Card0" > > > > > Driver "nouveau" > > > > > Option "PageFlip" "1" > > > > > #Option "AccelMethod" "glamor" > > > > > Option "DRI" "3" > > > > > > > > > > But just after two hours of uptime X already eating some CPU: > > > > > > > > > > > > > > > op - 01:30:49 up 2:45, 1 user, load average: 1,12, 0,93, 0,84 > > > > > Tasks: 210 total, 1 running, 209 sleeping, 0 stopped, 0 zombie > > > > > %Cpu(s): 12,1 us, 3,9 sy, 0,0 ni, 81,7 id, 0,7 wa, 0,0 hi, 1,6 si, 0,0 st > > > > > MiB Mem : 11875,3 total, 6416,4 free, 1634,8 used, 3824,1 buff/cache > > > > > MiB Swap: 1145,0 total, 1145,0 free, 0,0 used. 9969,7 avail Mem > > > > > > > > > > PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND > > > > > 1198 root 20 0 146160 78828 28160 S 35,8 0,6 30:41.37 Xorg > > > > > 1285 guest 20 0 59776 17332 13756 S 11,6 0,1 16:12.83 xmms > > > > > 4006 guest 20 0 1743952 919312 120628 S 10,9 7,6 20:51.01 seamonkey > > > > > 1278 guest 20 0 101508 48528 30496 S 3,0 0,4 4:03.21 ktorrent > > > > > 1274 guest 20 0 43368 31784 23684 S 2,0 0,3 0:29.43 konsole > > > > > 1259 guest 20 0 43092 28232 23640 S 1,3 0,2 0:21.53 kicker > > > > > 1255 guest 20 0 6560 4160 2720 S 1,0 0,0 1:00.90 kompmgr > > > > > 1293 guest 20 0 40164 21328 18636 S 1,0 0,2 1:30.50 gkrellm > > > > > 1254 guest 20 0 31616 21832 18944 S 0,7 0,2 0:06.49 kwin > > > > > > > > > > in ~1 day it will eat full core from my AMD FX-4300 and X will become sluggish ... > > > > > > > > > > I tried to trace it with operf 1.2.0: > > > > > > > > > > operf --pid 1198 > > > > > > > > > > operf: Press Ctl-c or 'kill -SIGINT 7787' to stop profiling > > > > > operf: Profiler started > > > > > ^C > > > > > Profiling done. > > > > > > > > > > root at slax:~# opreport > > > > > Using /root/oprofile_data/samples/ for samples directory. > > > > > CPU: AMD64 family15h, speed 3800 MHz (estimated) > > > > > Counted CPU_CLK_UNHALTED events (CPU Clocks not Halted) with a unit mask of 0x00 (No unit mask) count 100000 > > > > > CPU_CLK_UNHALT...| > > > > > samples| %| > > > > > ------------------ > > > > > 78166 100.000 Xorg > > > > > CPU_CLK_UNHALT...| > > > > > samples| %| > > > > > ------------------ > > > > > 62905 80.4762 nouveau_drv.so > > > > > 5648 7.2256 kallsyms > > > > > 4186 5.3553 Xorg > > > > > 1419 1.8154 libpixman-1.so.0.38.0 > > > > > 1038 1.3279 nouveau > > > > > 687 0.8789 libc-2.30.so > > > > > 632 0.8085 libexa.so > > > > > 510 0.6525 libdrm_nouveau.so.2.0.0 > > > > > 402 0.5143 libfb.so > > > > > 259 0.3313 drm > > > > > 230 0.2942 ttm > > > > > 108 0.1382 libpthread-2.30.so > > > > > 47 0.0601 libdrm.so.2.4.0 > > > > > 34 0.0435 [vdso] (tgid:1198 range:0xf7fbf000-0xf7fbffff) > > > > > 27 0.0345 evdev_drv.so > > > > > 7 0.0090 snd_hda_codec > > > > > 5 0.0064 r8169 > > > > > 5 0.0064 snd_pcm > > > > > 5 0.0064 libXfont2.so.2.0.0 > > > > > 3 0.0038 snd_aloop > > > > > 3 0.0038 libglx.so > > > > > 2 0.0026 kvm > > > > > 2 0.0026 snd_timer > > > > > 1 0.0013 snd_hda_core > > > > > 1 0.0013 snd_hda_intel > > > > > > > > > > so, nouveau_drv itself is major CPU eater .... > > > > > > > > > > I'll try to rebuild it with debug symbols enabled, and hopefully it will be enough > > > > > for at least seeing who eats all those cycles .... > > > > > > > > > > Sorry for so many emails, just i keep discovering new bugs as I try new things! > > > > > _______________________________________________ > > > > > Nouveau mailing list > > > > > Nouveau at lists.freedesktop.org > > > > > https://lists.freedesktop.org/mailman/listinfo/nouveau > > > > > > > >
Ilia Mirkin
2020-Aug-16 17:42 UTC
[Nouveau] Accumulating CPU load from Xorg process with DRI3
On Sun, Aug 16, 2020 at 8:20 AM Andrew Randrianasulu <randrianasulu at gmail.com> wrote:> > ? ????????? ?? Sunday 16 August 2020 07:20:18 Ilia Mirkin ???????(?): > > Well, if it's easy, try the patches I mailed to nouveau@ for the ddx. > > I applied patches manually (copy-pasted patches failed to apply by git apply, > probably whitespace/end of line issues), and now I see in X log (after I left machine to run alone): > > [ 3584.553] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.553] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.570] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.586] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.602] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.619] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.635] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.651] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.668] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.684] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.700] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.717] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.733] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.749] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.766] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.782] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argument > [ 3584.798] (DB) NOUVEAU(0): PRESENT: Wait for VBlank failed: Invalid argumentAha, appears my assumption that X_DEBUG would get skipped under normal Xorg invocations was wrong. I didn't mean for these to appear under normal circumstances. I guess I'll #if 0 it out.> > and around 6mb more of those .... > > but X still uses small amount of CPU: > > op - 15:04:41 up 1:32, 2 users, load average: 1,25, 1,67, 1,60 > Tasks: 220 total, 2 running, 218 sleeping, 0 stopped, 0 zombie > %Cpu(s): 22,8 us, 5,9 sy, 0,3 ni, 69,2 id, 1,4 wa, 0,0 hi, 0,4 si, 0,0 st > MiB Mem : 11875,3 total, 7630,1 free, 1967,5 used, 2277,7 buff/cache > MiB Swap: 1145,0 total, 1145,0 free, 0,0 used. 9172,1 avail Mem > > PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND > 2777 guest 20 0 2155076 1,2g 126108 R 84,4 10,7 69:24.46 seamonkey > 1991 root 20 0 145764 78444 27936 S 14,6 0,6 6:42.10 Xorg > 3697 guest 20 0 61208 17268 13580 S 12,6 0,1 7:34.75 xmms > 2045 guest 20 0 6360 3932 2668 S 2,3 0,0 0:35.90 kompmgr > 2068 guest 20 0 102664 48952 30764 S 2,3 0,4 2:35.98 ktorrent > 2049 guest 20 0 42792 27908 23684 S 1,7 0,2 0:12.72 kicker > 2319 guest 20 0 40160 21248 18548 S 1,3 0,2 0:55.63 gkrellm > 2064 guest 20 0 50900 31592 23720 S 1,0 0,3 0:25.53 konsole > 5086 root 20 0 0 0 0 I 0,7 0,0 0:02.57 kworker/0:2-events > 10 root 20 0 0 0 0 I 0,3 0,0 0:09.96 rcu_preempt > 1918 root 20 0 0 0 0 I 0,3 0,0 0:04.78 kworker/3:0-events > 2240 guest 20 0 59660 37848 30248 S 0,3 0,3 0:02.36 konqueror > 2389 guest 20 0 33048 22592 20376 S 0,3 0,2 0:00.24 kdesu > > with CPU frequency set to 1.4Ghz (minimum possible). Usually around 5.6%-6.0% > vblanks still work, at least glxgears from both cards still run at ~60 fps by default > > I'll run with those patches for few more hours, but so far they seems to be helpful.Great! -ilia