Obnoxious, but this is only an extra-paranoid level of assertions, to verify that our inactive list really is inactive from the kernel perspective as well.

However, from a brief glance over the callchain I have to agree that the assertion is valid. In this case, that bo is actually a partial buffer and so should still be referenced from the buffer cache. Hmm.

I have the suspicion this assertion is whatis keeping X crashing about once a day for the last few weeks - however until now it was a bit shy when I worked with a debugger attached ;)

just hit the assetion again, this time while reading a pdf using evince:

#0  0x007fd416 in __kernel_vsyscall ()
#1  0x426b698f in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0x426b82d5 in __GI_abort () at abort.c:91
#3  0x426af6a5 in __assert_fail_base (
    fmt=0x427f0e48 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=0x36e4cc "!kgem_busy(kgem, bo->handle)", file=0x36e346 "kgem.c", line=1035,
    function=0x36f2ec "kgem_bo_move_to_inactive") at assert.c:94
#4  0x426af757 in __GI___assert_fail (assertion=0x36e4cc "!kgem_busy(kgem, bo->handle)",
    file=0x36e346 "kgem.c", line=1035, function=0x36f2ec "kgem_bo_move_to_inactive")
    at assert.c:103
#5  0x002a0641 in kgem_bo_move_to_inactive (kgem=<optimized out>, bo=<optimized out>)
    at kgem.c:1035
#6  kgem_bo_move_to_inactive (bo=0x8588bb0, kgem=0x8266270) at kgem.c:1087
#7  __kgem_bo_destroy (kgem=0x8266270, bo=0x8588bb0) at kgem.c:1196
#8  0x002a1ad0 in _kgem_bo_destroy (kgem=0x8266270, bo=0x87a8250) at kgem.c:2915
#9  0x002b7194 in kgem_bo_destroy (bo=<optimized out>, kgem=<optimized out>) at kgem.h:284
#10 sna_drawable_use_bo (drawable=<optimized out>, box=0xbf878fd0, damage=0xbf878fdc)
    at sna_accel.c:1936
#11 0x002c3b8f in sna_poly_fill_rect (draw=0x849c7a0, gc=0x82bca10, n=1, rect=0x871f638)
    at sna_accel.c:10068
#12 0x08157fcb in damagePolyFillRect (pDrawable=0x849c7a0, pGC=0x82bca10, nRects=1,
    pRects=0x871f638) at damage.c:1309
#13 0x081ace4e in miPaintWindow (pWin=<optimized out>, prgn=0xbf879134, what=0)
    at miexpose.c:674
#14 0x081c488c in miClearToBackground (pWin=0x849c7a0, x=0, y=0, w=22, h=22,
    generateExposures=0) at miwindow.c:118
#15 0x08071adb in ProcClearToBackground (client=0x8456790) at dispatch.c:1617
#16 0x08076195 in Dispatch () at dispatch.c:439
#17 0x0806439a in main (argc=7, argv=0xbf879314, envp=0xbf879334) at main.c:287

I haven't yet reproduced this, but I think the grey area is if we reuse an upload bo that has cached references for readback and do not manage to reap those references.

commit 701473d20485a0557b4fb36efcbfbb8656e2f619
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sun Apr 8 10:09:42 2012 +0100

    sna: Release cached upload buffers when reusing a write buffer for readback
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=48400
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Should take care of that. However, I'm not 100% convinced that is the problem here.

Thanks - I haven't hit that assertion yet with the patch - however I got a random crash at X startup:

Backtrace:
[    20.334] 0: /usr/bin/X (xorg_backtrace+0x3c) [0x80a86ac]
[    20.334] 1: /usr/bin/X (0x8047000+0x664d6) [0x80ad4d6]
[    20.334] 2: (vdso) (__kernel_rt_sigreturn+0x0) [0xfc340c]
[    20.334] 3: /usr/lib/xorg/modules/drivers/intel_drv.so (0xd68000+0x34ec0) [0xd9cec0]
[    20.334] 4: /usr/lib/xorg/modules/drivers/intel_drv.so (0xd68000+0x36ad0) [0xd9ead0]
[    20.334] 5: /usr/lib/xorg/modules/drivers/intel_drv.so (0xd68000+0x4c204) [0xdb4204]
[    20.334] 6: /usr/lib/xorg/modules/drivers/intel_drv.so (0xd68000+0x58bff) [0xdc0bff]
[    20.334] 7: /usr/bin/X (0x8047000+0x110fcb) [0x8157fcb]
[    20.334] 8: /usr/bin/X (miPaintWindow+0x1ce) [0x81ace4e]
[    20.334] 9: /usr/bin/X (miClearToBackground+0x11c) [0x81c488c]
[    20.334] 10: /usr/bin/X (0x8047000+0x2aadb) [0x8071adb]
[    20.335] 11: /usr/bin/X (0x8047000+0x2f195) [0x8076195]
[    20.335] 12: /usr/bin/X (0x8047000+0x1d39a) [0x806439a]
[    20.335] 13: /lib/libc.so.6 (__libc_start_main+0xf3) [0x426a06b3]
[    20.335] 14: /usr/bin/X (0x8047000+0x1d6c9) [0x80646c9]
[    20.335] Segmentation fault at address 0x4
[    20.335] 
Fatal server error:
[    20.335] Caught signal 11 (Segmentation fault). Server aborting

Unfortunatly I don't know how to get a better stacktrace.

Try: addr2line -e  /usr/lib/xorg/modules/drivers/intel_drv.so 0x34ec0 0x36ad0 0x4c204 0x58bff

/usr/include/xorg/list.h:136
/home/ce/xf86-video-intel/src/sna/kgem.c:975
/home/ce/xf86-video-intel/src/sna/kgem.h:284
/home/ce/xf86-video-intel/src/sna/sna_accel.c:10068

Hmm, that doesn't make much sense. How are you starting X that triggers the crash?

X was started by systemd at boot. At the next boot, everything worked as expected.

Hmm, lets write that off as some library update bogosity and wait to see if the assertion (or similar) manifests itself again.

yep, got another weird crash like this ony (also in xorg's list functions) - seems somehow this binary was broken so I recompiled.

ok, the bug is still there - with the same stacktrace:

#0  0x003c3416 in __kernel_vsyscall ()
#1  0x426b698f in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0x426b82d5 in __GI_abort () at abort.c:91
#3  0x426af6a5 in __assert_fail_base (fmt=0x427f0e48 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=0xbfe58c "!kgem_busy(kgem, bo->handle)", file=0xbfe406 "kgem.c", line=1035,
    function=0xbff3ac "kgem_bo_move_to_inactive") at assert.c:94
#4  0x426af757 in __GI___assert_fail (assertion=0xbfe58c "!kgem_busy(kgem, bo->handle)", file=0xbfe406 "kgem.c",
    line=1035, function=0xbff3ac "kgem_bo_move_to_inactive") at assert.c:103
#5  0x00b30641 in kgem_bo_move_to_inactive (kgem=<optimized out>, bo=<optimized out>) at kgem.c:1035
#6  kgem_bo_move_to_inactive (bo=0x99b5068, kgem=0x9391270) at kgem.c:1087
#7  __kgem_bo_destroy (kgem=0x9391270, bo=0x99b5068) at kgem.c:1196
#8  0x00b31ad0 in _kgem_bo_destroy (kgem=0x9391270, bo=0x966ad50) at kgem.c:2921
#9  0x00b47204 in kgem_bo_destroy (bo=<optimized out>, kgem=<optimized out>) at kgem.h:284
#10 sna_drawable_use_bo (drawable=<optimized out>, box=0xbff24310, damage=0xbff2431c) at sna_accel.c:1936
#11 0x00b53bff in sna_poly_fill_rect (draw=0x95ddf58, gc=0x93e7a10, n=1, rect=0x9b057c8) at sna_accel.c:10068
#12 0x08157fcb in damagePolyFillRect (pDrawable=0x95ddf58, pGC=0x93e7a10, nRects=1, pRects=0x9b057c8)
    at damage.c:1309
#13 0x081ace4e in miPaintWindow (pWin=<optimized out>, prgn=0xbff24474, what=0) at miexpose.c:674
#14 0x081c488c in miClearToBackground (pWin=0x95ddf58, x=0, y=0, w=22, h=22, generateExposures=0)
    at miwindow.c:118
#15 0x08071adb in ProcClearToBackground (client=0x9584a50) at dispatch.c:1617
#16 0x08076195 in Dispatch () at dispatch.c:439
#17 0x0806439a in main (argc=7, argv=0xbff24654, envp=0xbff24674) at main.c:287

I've added a few more assertions, that hopefully will confirm the original assertion failure.

commit 0464e93a088a9e8bc29ad8b36b6e12c3dda32ec6
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sun Apr 8 17:16:03 2012 +0100

    sna: Add some assertions for misuse of proxies
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=48400
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk

#0  0x003f1416 in __kernel_vsyscall ()
#1  0x426b698f in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0x426b82d5 in __GI_abort () at abort.c:91
#3  0x426af6a5 in __assert_fail_base (
    fmt=0x427f0e48 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=0x2eab50 "priv->gpu_bo->proxy->rq", file=0x2ea865 "sna_accel.c", line=1936,
    function=0x2eb60c "sna_drawable_use_bo") at assert.c:94
#4  0x426af757 in __GI___assert_fail (assertion=0x2eab50 "priv->gpu_bo->proxy->rq",
    file=0x2ea865 "sna_accel.c", line=1936, function=0x2eb60c "sna_drawable_use_bo")
    at assert.c:103
#5  0x002325f2 in sna_drawable_use_bo (drawable=<optimized out>, box=0xbf936948,
    damage=0xbf93695c) at sna_accel.c:1936
#6  0x0023ed99 in sna_poly_fill_rect (draw=0x8d427c0, gc=0x8b50a10, n=1, rect=0x9096c18)
    at sna_accel.c:10081
#7  0x08157fcb in damagePolyFillRect (pDrawable=0x8d427c0, pGC=0x8b50a10, nRects=1,
    pRects=0x9096c18) at damage.c:1309
#8  0x081ace4e in miPaintWindow (pWin=<optimized out>, prgn=0xbf936ab4, what=0)
    at miexpose.c:674
#9  0x081c488c in miClearToBackground (pWin=0x8d427c0, x=0, y=0, w=22, h=22,
    generateExposures=0) at miwindow.c:118
#10 0x08071adb in ProcClearToBackground (client=0x8cecf68) at dispatch.c:1617
#11 0x08076195 in Dispatch () at dispatch.c:439
#12 0x0806439a in main (argc=7, argv=0xbf936c94, envp=0xbf936cb4) at main.c:287

More assertions:

commit dd093eafb9b94b8e4cd8853d74078c3aa7e72f57
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Apr 9 14:09:42 2012 +0100

    sna: Add assertions around proxy list handling
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=48400
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

At least the last set confirms that the cached upload buffer is not being released upon retirement (as I had intended).

ok, another backtrace with latest assertions added:

#0  0x0040f416 in __kernel_vsyscall ()
#1  0x426b698f in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0x426b82d5 in __GI_abort () at abort.c:91
#3  0x426af6a5 in __assert_fail_base (
    fmt=0x427f0e48 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=0x675c50 "priv->gpu_bo->proxy->rq", file=0x675965 "sna_accel.c", line=1936,
    function=0x67670c "sna_drawable_use_bo") at assert.c:94
#4  0x426af757 in __GI___assert_fail (assertion=0x675c50 "priv->gpu_bo->proxy->rq",
    file=0x675965 "sna_accel.c", line=1936, function=0x67670c "sna_drawable_use_bo")
    at assert.c:103
#5  0x005bd612 in sna_drawable_use_bo (drawable=<optimized out>, box=0xbfa260d8,
    damage=0xbfa260ec) at sna_accel.c:1936
#6  0x005c9db9 in sna_poly_fill_rect (draw=0x9ea0098, gc=0x9d0ba10, n=1, rect=0xa1fba08)
    at sna_accel.c:10081
#7  0x08157fcb in damagePolyFillRect (pDrawable=0x9ea0098, pGC=0x9d0ba10, nRects=1,
    pRects=0xa1fba08) at damage.c:1309
#8  0x081ace4e in miPaintWindow (pWin=<optimized out>, prgn=0xbfa26244, what=0)
    at miexpose.c:674
#9  0x081c488c in miClearToBackground (pWin=0x9ea0098, x=0, y=0, w=22, h=22,
    generateExposures=0) at miwindow.c:118
#10 0x08071adb in ProcClearToBackground (client=0x9ee2350) at dispatch.c:1617
#11 0x08076195 in Dispatch () at dispatch.c:439
#12 0x0806439a in main (argc=7, argv=0xbfa26424, envp=0xbfa26444) at main.c:287

Hmm, no closer yet. The only thing that is certain so far is that I've been searching in the wrong direction.

just have seen you added a bit of new code involving buffer management - should I test again with those patches? The last bt was generated with "sna: Add assertions around proxy list handling" only.

No, they're unrelated patches. 778232e3d2fb may have been but should have been caught by the recent assertions if it actually was relevant.

Clemens, can I ask you to go up into the sna_drawable_use_bo frame and p *pixmap, p *priv, p *priv->gpu_bo, and p *priv->gpu_bo->proxy?

Sure, if you could give me a short crash course how to do that - I have never used gdb for any real debugging...

In your last backtrace, that would be:

$ frame 5  # or equivalently up 4 times
$ p *pixmap
$ p *priv
$ p *priv->gpu_bo
$ p *priv->gpu_bo->proxy

Appears the compiler was trying to tell me something:

commit 755a7107aed268d87c5cc0feb1ba388b0cb7fc59
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Apr 10 15:19:19 2012 +0100

    sna: Fix typo and use the right pointer for kgem_bo_destroy
    
    Useless warnings in xorg headers ftl.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=48400
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

I got the call wrong, so hopefully this was accumulated damage...

Almost thought its fixed, after I didn't run into this problem for about 2 hours.

Hope this helps:

#0  0x0036a416 in __kernel_vsyscall ()
#1  0x426b698f in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2  0x426b82d5 in __GI_abort () at abort.c:91
#3  0x426af6a5 in __assert_fail_base (fmt=0x427f0e48 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=0x708c98 "priv->gpu_bo->proxy->rq", file=0x7089ad "sna_accel.c", line=1936,
    function=0x70974c "sna_drawable_use_bo") at assert.c:94
#4  0x426af757 in __GI___assert_fail (assertion=0x708c98 "priv->gpu_bo->proxy->rq", file=0x7089ad "sna_accel.c",
    line=1936, function=0x70974c "sna_drawable_use_bo") at assert.c:103
#5  0x00650652 in sna_drawable_use_bo (drawable=<optimized out>, box=0xbf97ffe8, damage=0xbf97fffc)
    at sna_accel.c:1936
#6  0x0065ce01 in sna_poly_fill_rect (draw=0x85a1bc8, gc=0x83bba10, n=1, rect=0x8a13ed0) at sna_accel.c:10085
#7  0x08157fcb in damagePolyFillRect (pDrawable=0x85a1bc8, pGC=0x83bba10, nRects=1, pRects=0x8a13ed0)
    at damage.c:1309
#8  0x081ace4e in miPaintWindow (pWin=<optimized out>, prgn=0xbf980154, what=0) at miexpose.c:674
#9  0x081c488c in miClearToBackground (pWin=0x85a1bc8, x=0, y=0, w=22, h=22, generateExposures=0)
    at miwindow.c:118
#10 0x08071adb in ProcClearToBackground (client=0x854c200) at dispatch.c:1617
#11 0x08076195 in Dispatch () at dispatch.c:439
#12 0x0806439a in main (argc=7, argv=0xbf980334, envp=0xbf980354) at main.c:287
(gdb) frame 5
#5  0x00650652 in sna_drawable_use_bo (drawable=<optimized out>, box=0xbf97ffe8, damage=0xbf97fffc)
    at sna_accel.c:1936
1936                    assert(priv->gpu_bo->proxy->rq);

(gdb) p *pixmap
$1 = {drawable = {type = 1 '\001', class = 0 '\000', depth = 24 '\030', bitsPerPixel = 32 ' ', id = 0, x = 0,
    y = 0, width = 22, height = 22, pScreen = 0x83775a0, serialNumber = 2478850}, devPrivates = 0x8626438,
  refcnt = 1, devKind = 88, devPrivate = {ptr = 0x8626450, val = 140665936, uval = 140665936, fptr = 0x8626450},
  screen_x = 1101, screen_y = 771, usage_hint = 0}

(gdb) p *priv
$3 = {pixmap = 0x8626408, gpu_bo = 0x854aa98, cpu_bo = 0x0, gpu_damage = 0x0, cpu_damage = 0x8625ae9, ptr = 0x0,
  list = {next = 0x85a7d20, prev = 0x85a7d20}, inactive = {next = 0x85a7d28, prev = 0x85a7d28}, stride = 0,
  clear_color = 15395562, flush = 0, source_count = 5, pinned = 0 '\000', mapped = 0 '\000', clear = 0 '\000',
  undamaged = 0 '\000', create = 0 '\000', header = 0 '\000'}

(gdb) p *priv->gpu_bo
$4 = {proxy = 0x8ceb930, list = {next = 0x854aa9c, prev = 0x854aa9c}, request = {next = 0x854aaa4,
    prev = 0x854aaa4}, vma = {next = 0x8ceb944, prev = 0x8ceb944}, map = 0x85a7d0c, rq = 0x0, exec = 0x733320,
  binding = {next = 0x0, format = 0, offset = 0}, unique_id = 1251459, refcnt = 1, handle = 11,
  presumed_offset = 0, delta = 0, size = {pages = {count = 1936, bucket = 0}, bytes = 1936}, pitch = 88,
  tiling = 0, reusable = 0, dirty = 0, domain = 3, needs_flush = 0, vmap = 0, io = 1, flush = 0, scanout = 0,
  sync = 0, purged = 0}
  
(gdb) p *priv->gpu_bo->proxy
$5 = {proxy = 0x0, list = {next = 0x8ceb934, prev = 0x8ceb934}, request = {next = 0x8ceb93c, prev = 0x8ceb93c},
  vma = {next = 0x854aaac, prev = 0x854aaac}, map = 0xb7240001, rq = 0x0, exec = 0x0, binding = {next = 0x0,
    format = 0, offset = 0}, unique_id = 0, refcnt = 1, handle = 11, presumed_offset = 219156480, delta = 0,
  size = {pages = {count = 64, bucket = 6}, bytes = 805306432}, pitch = 0, tiling = 0, reusable = 0, dirty = 0,
  domain = 0, needs_flush = 0, vmap = 0, io = 1, flush = 0, scanout = 0, sync = 0, purged = 0}
(gdb)

I wonder if we are now back to a genuine NULL rq. Can you delete the assertion at sna_accel.c:1936 and see if the original assertion returns?

Without the assertion at sna_accel.c:1936 my system ran almost stable the last few days (1-2 crashes, unfourtunatly no debugger attached).

Do you have the xdm.log to see if those crashes were similar?

unfourtunatly not, I'll simply keep the debugger attached the next few days

I don't think any harm will come from removing that assertion, having the fixed the typos. However, that assertion is still unexpected and implies some slightly less than ideal behaviour (or rather something I haven't considered yet).

commit caf9144271a10f90ea580c246b2df3f69a10b7a0
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Apr 20 17:15:37 2012 +0100

    sna: Remove the assertions that the cached upload buffers are active
    
    These were added to track down some corruption, but the assertions
    themselves are incorrect, just very rare. The upload buffer may
    genuinely be cached if we abort the render operation after uploading the
    source data, leaving the proxy not coupled to any request.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=48400
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>