evergreen: after resume from suspend-to-ram operation is really slow with the latest DPM changes + gpu lockup
Submitted by jac..@..il.com
Assigned to Default DRI bug account
Description
Using the drm-code from drm-fixes-3.11 branch (http://cgit.freedesktop.org/~agd5f/linux/log/?h=drm-fixes-3.11) against a 3.10 final kernel as explained in following post (http://phoronix.com/forums/showthread.php?82357-drm-fixes-3-11-with-3-10-stable-kernel-patch-repo)
the card used is a HD5850, evergreen; ~amd64 Gentoo Linux, Intel Core i7 860, gcc 4.8.1, 2.17
I tested suspend-to-ram which in a prior state of drm-next would lock up the box (so much progress has been made - yay ! :) ):
via following command:
pm-suspend --quirk-dpms-on --quirk-s3-mode --quirk-vbe-post --quirk-vga-mode3
launched from VT1 (no X running)
first things noticable:
it takes longer (compared to the non-DPM driver) to turn off the computer so I first thought that it had hardlocked (fans were still spinning, screen turned off, harddisks +/- off - after some time the box went to suspend/sleep)
it also takes longer to resume and for the screen to turn on
following behavior is observable after the resume from suspend-to-ram:
dmesg shows:
[ 178.031724] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 178.430546] e1000e: eth0 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx
[ 178.430652] e1000e 0000:00:19.0 eth0: 10/100 speed: disabling TSO
[ 179.052821] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 180.073918] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 181.095014] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 182.116110] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 182.120733] ata1: link is slow to respond, please be patient (ready=0)
[ 182.122735] ata3: link is slow to respond, please be patient (ready=0)
[ 182.128740] ata5: link is slow to respond, please be patient (ready=0)
[ 182.130763] ata6: link is slow to respond, please be patient (ready=0)
[ 183.137207] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 184.158303] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 185.179399] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 186.200496] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 186.817477] ata1: COMRESET failed (errno=-16)
[ 186.819524] ata3: COMRESET failed (errno=-16)
[ 186.825487] ata5: COMRESET failed (errno=-16)
[ 186.827492] ata6: COMRESET failed (errno=-16)
[ 187.221593] [drm:r600_uvd_init] ERROR UVD not responding, trying to reset the VCPU!!!
[ 187.241615] [drm:r600_uvd_init] ERROR UVD not responding, giving up!!!
[ 187.241618] [drm:evergreen_startup] ERROR radeon: error initializing UVD (-1).
[ 187.241650] [drm] ib test on ring 0 succeeded in 0 usecs
[ 187.241683] [drm] ib test on ring 3 succeeded in 1 usecs
[ 187.246731] switching from power state:
[ 187.246732] ui class: none
[ 187.246733] internal class: boot
[ 187.246733] caps: video
[ 187.246734] uvd vclk: 0 dclk: 0
[ 187.246734] power level 0 sclk: 40000 mclk: 90000 vddc: 1000 vddci: 0
[ 187.246735] power level 1 sclk: 40000 mclk: 90000 vddc: 1000 vddci: 0
[ 187.246735] power level 2 sclk: 40000 mclk: 90000 vddc: 1000 vddci: 0
[ 187.246736] status: c b
[ 187.246736] switching to power state:
[ 187.246737] ui class: performance
[ 187.246737] internal class: none
[ 187.246738] caps: single_disp video
[ 187.246738] uvd vclk: 0 dclk: 0
[ 187.246739] power level 0 sclk: 15700 mclk: 30000 vddc: 950 vddci: 1100
[ 187.246739] power level 1 sclk: 55000 mclk: 90000 vddc: 1038 vddci: 1100
[ 187.246740] power level 2 sclk: 72500 mclk: 100000 vddc: 1088 vddci: 1100
[ 187.246740] status: r
[ 188.350006] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 188.380064] ata3.00: configured for UDMA/133
[ 188.380117] sd 2:0:0:0: [sdb] Starting disk
[ 188.511188] ata6: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 188.523242] ata6.00: configured for UDMA/133
[ 188.523276] sd 5:0:0:0: [sdd] Starting disk
[ 190.500189] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 190.513376] ata5.00: configured for UDMA/133
[ 190.513455] sd 4:0:0:0: [sdc] Starting disk
[ 191.462213] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 191.506493] ata1.00: configured for UDMA/133
[ 191.506573] sd 0:0:0:0: [sda] Starting disk
[ 192.356977] [drm:atom_op_jump] ERROR atombios stuck in loop for more than 5secs aborting
[ 192.356978] [drm:atom_execute_table_locked] ERROR atombios stuck executing D3DE (len 55, WS 0, PS 0) @ 0xD401
[ 192.376632] PM: resume of devices complete after 15600.251 msecs
so suspend & resume works but with caveats - now wanted to see how X is running:
launched up lightdm & logged into xfce4.10 :
compiz-fusion (0.8*)/compositing is very very slow: e.g. when grabbing a window at the top with left mouse button and trying to move it - it moves only for several millimeters on screen (22'' screen with 1920x1080 resolution) - thus unusable
when switching to xfwm4 (running Xfce4.10) moving windows around is somewhat acceptable - appears even fluid, launching up chromium and switching between tabs via ctrl + pgup/pgdown is noticably laggy
launching glxgears via gnome-terminal - it seemingly looks ok (gears smoothly turning) [FPS locked to around 60]
running glxgears via: R600_LLVM=0 vblank_mode=0 glxgears
there's noticable, "micro"-stuttering and the FPS is around 260-290 if I recall correctly
echo low > /sys/class/drm/card0/device/power_dpm_force_performance_level
or
echo high > /sys/class/drm/card0/device/power_dpm_force_performance_level
doesn't make a difference - also FPS is significantly lower compared to "normal" operation (around 10x faster, e.g. 2900-3600 FPS with the non-DPM and "high" profile)
next step was launching gnome-terminal from the below panel, then after sudo su -> dmesg
and wanted to do further tests (e.g. sensors output)
-> X crashed
[ 973.217246] radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
[ 973.217254] radeon 0000:01:00.0: GPU lockup (waiting for 0x0000000000000199 last fence id 0x0000000000000198)
X (or lightdm) couldn't be launched after that anymore, VT output was still shown - so I restarted via shutdown -r now
hope that information helps in tracking down this issue
I really love this new driver - now only operation after resume needs to work also, since I used it quite a lot :) (it does work with the non-DPM)
similar message and behavior was seen on july 3rd/4th after several hours of operation & uptime (no suspend and resume):
[ 973.217246] radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
[ 973.217254] radeon 0000:01:00.0: GPU lockup (waiting for 0x0000000000000199 last fence id 0x0000000000000198)