Bug 72716

Created attachment 90785 [details]
Xorg.0.log

I forgot to mention: 3.9.9-tuxonice does not have this problem.

I wonder whether this message during resume has anything to do with it (see appended dmsg):

[  864.574325] radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
[  864.574328] radeon 0000:01:00.0: GPU lockup (waiting for 0x0000000000000004 last fence id 0x0000000000000002)
[  864.574331] [drm:uvd_v1_0_ib_test] *ERROR* radeon: fence wait failed (-35).
[  864.574334] [drm:radeon_ib_ring_tests] *ERROR* radeon: failed testing IB on ring 5 (-35).

Created attachment 91087 [details]
syslog on modprobe -rv radeon

OK, so I thought about: unload radeon.ko, patch source for printk debugging, compile and load to see where the culprit is, but modprobe -rv radeon rendered my machine basically useless; seems this banana is not ripe yet.

Does it work correctly without tuxonice?  sigbus is usually a sign that the cpu is trying to access a non-CPU visible region of vram.

(In reply to comment #5)
> Does it work correctly without tuxonice? 

No, vanilla 3.12.4 has exactly the same problems:
boot => suspend to disk => resume => start X => run firefox => SIGBUS in EVERGREENUploadToScreen

(In case it is related: As on 3.12.4-tuxonice modprobe -r radeon oopses an “BUG: unable to handle kernel paging request”, even without ever starting X.)

I admit I didn’t try X before a suspend/resume cycle.

Correct me if I’m wrong, but if I understand the driver code correctly, the SIGBUS is delivered because of the following chain of function calls:

ttm_bo_move_buffer(bo, {fpfn = 0x0, lpfn = 0x10000, num_placement = 1, num_busy_placement = 1}, 0, 0) = -12
ttm_bo_validate
radeon_bo_fault_reserve_notify (as bdev->driver->fault_reserve_notify
ttm_bo_vm_fault (as ttm_vm_ops->fault)
radeon_ttm_fault

where the return value from ttm_bo_move_buffer (-ENOMEM) is moved up to ttm_bo_vm_fault, which then returns VM_FAULT_SIGBUS.

During the many cycles of “printk, compile, reboot, suspend, resume, crash X” I’ve found that the problem may have to do with the fact that I load radeon.ko during my initramfs before attempting resume by echoing into /sys/power/resume or /sys/power/tuxonice/do_resume.

If I do *not* load radeon.ko into the “booting” kernel (i.e., the one which is then replaced by the “resuming” kernel), I couldn’t reproduce the crash. Furthermore, I do *not* get these four messages from the “resuming” kernel about a lockup:

[  864.574325] radeon 0000:01:00.0: GPU lockup CP stall for more than 10000msec
[  864.574328] radeon 0000:01:00.0: GPU lockup (waiting for 0x0000000000000004 last fence id 0x0000000000000002)
[  864.574331] [drm:uvd_v1_0_ib_test] *ERROR* radeon: fence wait failed (-35).
[  864.574334] [drm:radeon_ib_ring_tests] *ERROR* radeon: failed testing IB on ring 5 (-35).

(In reply to comment #8)
> During the many cycles of “printk, compile, reboot, suspend, resume, crash
> X” I’ve found that the problem may have to do with the fact that I load
> radeon.ko during my initramfs before attempting resume by echoing into
> /sys/power/resume or /sys/power/tuxonice/do_resume.
> 
> If I do *not* load radeon.ko into the “booting” kernel (i.e., the one which
> is then replaced by the “resuming” kernel), I couldn’t reproduce the crash.
> Furthermore, I do *not* get these four messages from the “resuming” kernel
> about a lockup:
> 
> [  864.574325] radeon 0000:01:00.0: GPU lockup CP stall for more than
> 10000msec
> [  864.574328] radeon 0000:01:00.0: GPU lockup (waiting for
> 0x0000000000000004 last fence id 0x0000000000000002)
> [  864.574331] [drm:uvd_v1_0_ib_test] *ERROR* radeon: fence wait failed
> (-35).
> [  864.574334] [drm:radeon_ib_ring_tests] *ERROR* radeon: failed testing IB
> on ring 5 (-35).

I think what's happening is that when you get the GPU lockup, the driver can't reset the GPU properly so it has no way to migrate data from non-CPU accessible vram to CPU accessible vram and you end up with the SIGBUS when the CPU tries to access the non-CPU accessible vram.

I'm not quite following what you mean by booting vs. resuming kernel.

> I'm not quite following what you mean by booting vs. resuming kernel.

I resume by echoing into /sys/power/resume from an initramfs. The kernel which is in charge before I called the “booting” kernel. When I echo into /sys/power/resume, my naive understanding is that the old kernel (the one which save a memory image to swap) is taking over control again (the “resuming” kernel).

I suppose that’s not exactly what happens (is the kernel which just booted really kicked out of existence or does it keep on running and take over the memory image from the kernel which was suspended ?). But my point was that when radeon.ko is loaded before the initramfs echoes into /sys/power/resume, the lookup and the SIGBUS happen, whereas if it is not loaded, everything’s fine.

(In reply to comment #10)
> I suppose that’s not exactly what happens (is the kernel which just booted
> really kicked out of existence or does it keep on running and take over the
> memory image from the kernel which was suspended ?). But my point was that
> when radeon.ko is loaded before the initramfs echoes into /sys/power/resume,
> the lookup and the SIGBUS happen, whereas if it is not loaded, everything’s
> fine.

Does the booting kernel unload the radeon driver prior to switching to the resuming kernel?  If not, the resuming kernel may take over before the radeon driver has finished loading in the boot kernel, or in the middle of some operation which leaves the GPU in a bad state when the resuming kernel takes over.

I don't want to tangle this bug completely; but I get something similar, 100% reproducibly; my sin being just to login under XFCE, or to launch an app under gnome-shell ;-)

Program received signal SIGBUS, Bus error.
0xb7274907 in memcpy () from /lib/libc.so.6
(gdb) bt
#0  0xb7274907 in memcpy () from /lib/libc.so.6
#1  0xb6cc0b97 in memcpy (__len=7680, __src=0xb41b6008, __dest=0xb377c000) at
/usr/include/bits/string3.h:51
#2  EVERGREENUploadToScreen (pDst=pDst@entry=0xa5689c0, x=0, y=y@entry=0,
w=1920, h=1200, 
    src=0xb41b6008
"\020\017\v\377\021\020\f\377\020\016\f\377\016\r\v\377\f\r\n\377\021\021\016"..., src_pitch=7680) at evergreen_exa.c:1721
#3  0xb6c7c506 in exaCopyDirty (migrate=migrate@entry=0xbfdd50a0,
pValidDst=pValidDst@entry=0xa568a34, pValidSrc=pValidSrc@entry=0xa568a28, 
    transfer=0xb6cc0820 <EVERGREENUploadToScreen>,
fallback_index=fallback_index@entry=0, sync=sync@entry=0x0) at
exa_migration_classic.c:220
#4  0xb6c7c9e6 in exaCopyDirtyToFb (migrate=migrate@entry=0xbfdd50a0) at
exa_migration_classic.c:303
#5  0xb6c7e92f in exaDoMigration_mixed (pixmaps=0xbfdd5090, npixmaps=2,
can_accel=1) at exa_migration_mixed.c:118
#6  0xb6c7b17f in exaDoMigration (pixmaps=pixmaps@entry=0xbfdd5090,
npixmaps=npixmaps@entry=2, can_accel=can_accel@entry=1) at exa.c:1134
#7  0xb6c81218 in exaFillRegionTiled (pDrawable=pDrawable@entry=0xa5b9f38,
pRegion=pRegion@entry=0xa6cce40, pTile=0xa5689c0, 
    pPatOrg=pPatOrg@entry=0xa207ce8, planemask=4294967295, alu=3,
clientClipType=0) at exa_accel.c:1124
#8  0xb6c81d58 in exaPolyFillRect (pDrawable=0xa5b9f38, pGC=0xa207cc0, nrect=1,
prect=0xa5daff0) at exa_accel.c:821
#9  0x08163a67 in damagePolyFillRect (pDrawable=0xa5b9f38, pGC=0xa207cc0,
nRects=1, pRects=0xa5daff0) at damage.c:1254
#10 0x081bffa8 in miPaintWindow (pWin=<optimized out>, pWin@entry=0xa5b9f38,

I wonder if it could be related, very happy to help debug/test patches etc. as I say it's very easy to reproduce, no suspend/resume required =)

*** This bug has been marked as a duplicate of bug 44099 ***

(In reply to comment #13)
> 
> *** This bug has been marked as a duplicate of bug 44099 ***

I can confirm that with the patch posted there (#91541) applied the X server does no longer crash.

However, if I may be so bold to ask, does this patch actually solve the problem, or does it simply avoid it?