Suspend/Resumes fails early with r600(RV710) in "unpin not necessary"

[Manuel Krause]

Hi, and many Thanks for your reply!

I preliminarily only sent a quick copy&paste of docs that may be 
of any interest. May have been a mistake. But I want to help with 
anything better, if I knew.


On 2012-03-19 12:16, Michel Dänzer wrote:
> On Sam, 2012-03-17 at 20:48 +0100, Manuel Krause wrote:
>>
>> EE opt_core.c:2986 r600_shader_optimize - shader optimization:
>> unsupported chip
>
> WTH is this? I can't find any opt_core.c file or r600_shader_optimize
> function in upstream Mesa Git, and Google doesn't know much about it
> either.

This appears when Firefox/Seamonkey/Thunderbird are starting up. 
Or glxinfo, glxgears.

> If your X session uses OpenGL when you try to suspend/resume (e.g. if
> you're using an OpenGL compositing manager such as kwin, gnome-shell or
> compiz), you might want to investigate this.

I have a KDE 4.7.4 in use but without compositing or any effects.

>> Mar 14 01:50:51 COOLHEAD kernel: agpgart-via 0000:00:00.0:
>> Refused to change power state, currently in D0
>
> Does radeon.agpmode=-1 help at all?

As this may reduce agp rate I don't like to try it. ;-)
I'll come back on that later.

>> Mar 14 01:50:51 COOLHEAD kernel: PM: Creating hibernation image:
>> Mar 14 01:50:51 COOLHEAD kernel: PM: Need to copy 270062 pages
>> Mar 14 01:50:51 COOLHEAD kernel: PM: Not enough free memory
>> Mar 14 01:50:51 COOLHEAD kernel: PM: Error -12 creating
>> hibernation image
>> Mar 14 01:50:51 COOLHEAD kernel: ACPI: Waking up from system
>> sleep state S4
>
> This looks like it fails to enter hibernation in the first place.

Yes, I've obviously sent too many lines of logs. The thing seen 
above happens, if I had a large file in /dev/shm. That's a 
different 'construction area' than what matters here.

>> Mar 14 01:51:23 COOLHEAD kernel: radeon 0000:01:00.0: GPU lockup
>> CP stall for more than 10000msec
>> Mar 14 01:51:23 COOLHEAD kernel: GPU lockup (waiting for
>> 0x004EBE11 last fence id 0x004EBE10)
>> Mar 14 01:51:23 COOLHEAD kernel: radeon 0000:01:00.0: f7227600
>> unpin not necessary
>
> FWIW, the 'unpin not necessary' message itself is usually harmless, the
> problem is the GPU lockups.
>
>
>> After eight times I switched to tty1 and was able to reboot in
>> blindness.
>
> After eight times of what? GPU lockup/reset?

In this situation the screen changes from scrambled X to black 
and so on every approx. 10 seconds, while I still can switch VTs 
(at the beginning of black). And the text based ones are 
displayed fine with 10s intervals. Text input works.

This afternoon I updated to a newer jobermayr MESA and the 
related drivers+libs.


This is what dmesg showed after startup+hibernate+resume:
=========================================================
microcode: CPU0 sig=0x6b4, pf=0x10, revision=0x1
microcode: Microcode Update Driver: v2.00 
<tigran at aivazian.fsnet.co.uk>, Peter Oruba
BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
EDD information not available.
tulip 0000:00:06.0: eth0: tulip_stop_rxtx() failed (CSR5 
0xfc664010 CSR6 0xff972113)
net eth0: Setting full-duplex based on MII#1 link partner 
capability of 41e1
spurious 8259A interrupt: IRQ7.
tulip 0000:00:06.0: eth0: tulip_stop_rxtx() failed (CSR5 
0xfc06c012 CSR6 0xff970111)
Syncing filesystems ... done.
Freezing user space processes ... (elapsed 0.01 seconds) done.
PM: Preallocating image memory... done (allocated 172463 pages)
PM: Allocated 689852 kbytes in 0.15 seconds (4599.01 MB/s)
Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Suspending console(s) (use no_console_suspend to debug)
sd 0:0:0:0: [sda] Synchronizing SCSI cache
serial 00:09: disabled
serial 00:09: wake-up capability disabled by ACPI
snd_cmipci 0000:00:09.0: PCI INT A disabled
ACPI handle has no context!
tulip 0000:00:06.0: PCI INT A disabled
ACPI handle has no context!
agpgart-via 0000:00:00.0: Refused to change power state, 
currently in D0
radeon 0000:01:00.0: f722d600 unpin not necessary
PM: freeze of devices complete after 2237.826 msecs
PM: late freeze of devices complete after 0.333 msecs
ACPI: Preparing to enter system sleep state S4
PM: Saving platform NVS memory
PM: Creating hibernation image:
PM: Need to copy 206448 pages
PM: Restoring platform NVS memory
ACPI: Waking up from system sleep state S4
agpgart-via 0000:00:00.0: restoring config space at offset 0x1 
(was 0x22100006, writing 0x32100006)
parport_pc 0000:00:04.0: Disabling VIA external APIC routing
pata_via 0000:00:04.1: restoring config space at offset 0x1 (was 
0x2900083, writing 0x2900087)
snd_cmipci 0000:00:09.0: restoring config space at offset 0x1 
(was 0x2100085, writing 0x2100081)
PM: early restore of devices complete after 0.526 msecs
pci 0000:00:01.0: setting latency timer to 64
usb usb1: root hub lost power or was reset
usb usb2: root hub lost power or was reset
snd_cmipci 0000:00:09.0: PCI INT A -> Link[LNKD] -> GSI 4 (level, 
low) -> IRQ 4
[drm] AGP mode requested: 4
agpgart-via 0000:00:00.0: AGP 2.0 bridge
agpgart-via 0000:00:00.0: putting AGP V2 device into 4x mode
radeon 0000:01:00.0: putting AGP V2 device into 4x mode
radeon 0000:01:00.0: GTT: 256M 0xE0000000 - 0xEFFFFFFF
radeon 0000:01:00.0: WB disabled
sd 0:0:0:0: [sda] Starting disk
sd 1:0:0:0: [sdb] Starting disk
serial 00:09: activated
[drm] ring test succeeded in 0 usecs
[drm] ib test succeeded in 0 usecs
ata2.01: ACPI cmd ef/03:43:00:00:00:b0 (SET FEATURES) filtered out
ata2.01: ACPI cmd ef/03:0c:00:00:00:b0 (SET FEATURES) filtered out
ata1.00: ACPI cmd ef/03:45:00:00:00:a0 (SET FEATURES) filtered out
ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
ata1.00: configured for UDMA/100
ata2.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
ata2.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
ata2.00: configured for UDMA/33
ata2.01: configured for UDMA/66
PM: restore of devices complete after 1132.229 msecs
Restarting kernel threads ... done.
snapshot_ioctl: ioctl '4004330c' is deprecated and will be 
removed soon, update your suspend-to-disk utilities
Restarting tasks ...
cmipci: invalid PCM pointer: 0x3ffa
done.
tulip 0000:00:06.0: eth0: tulip_stop_rxtx() failed (CSR5 
0xfc664010 CSR6 0xff972113)
net eth0: Setting full-duplex based on MII#1 link partner 
capability of 41e1
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x000044FD last fence id 0x000044FC)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
eth0: no IPv6 routers present
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x00004517 last fence id 0x00004516)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x0000451F last fence id 0x0000451E)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x00004522 last fence id 0x0000451F)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x00004525 last fence id 0x00004522)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x00004526 last fence id 0x00004525)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x00004527 last fence id 0x00004526)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs
radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
GPU lockup (waiting for 0x0000452B last fence id 0x00004527)
radeon 0000:01:00.0: f722d600 unpin not necessary
radeon 0000:01:00.0: GPU softreset
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0xA27034A4
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000102
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0:   R_008020_GRBM_SOFT_RESET=0x00007FEE
radeon 0000:01:00.0: R_008020_GRBM_SOFT_RESET=0x00000001
radeon 0000:01:00.0:   R_008010_GRBM_STATUS=0x00003028
radeon 0000:01:00.0:   R_008014_GRBM_STATUS2=0x00000002
radeon 0000:01:00.0:   R_000E50_SRBM_STATUS=0x200000C0
radeon 0000:01:00.0: GPU reset succeed
radeon 0000:01:00.0: WB disabled
[drm] ring test succeeded in 1 usecs
[drm] ib test succeeded in 2 usecs


Best regards,

Manuel Krause