Bug 70461

Summary:

[sna suse] ddx assertion hits

Product:

xorg

Reporter:

Jiri Slaby <jirislaby>

Component:

Driver/intel

Assignee:

Chris Wilson <chris>

Status:

RESOLVED FIXED

QA Contact:

Intel GFX Bugs mailing list <intel-gfx-bugs>

Severity:

normal

Priority:

medium

Version:

git

Hardware:

Other

OS:

All

Whiteboard:

i915 platform:

i915 features:

Attachments:

Description	Flags
xorg.log	none
xorg.log full debug	none
pure black	none

Description Jiri Slaby 2013-10-14 18:52:33 UTC

Created attachment 87618 [details]
xorg.log

This a continuation of bug 47597 as it has over 2 hundred entries now.

Today with 2.99.904-20-g9f009c1:

#2  0x00007fdecaec72e2 in __assert_fail_base (fmt=0x7fdecb0051b8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7fdec7ca6418 "bo->rq == ((struct kgem_request *)((uintptr_t)(kgem->next_request) | (kgem->ring)))", file=file@entry=0x7fdec7ca5594 "kgem.c", line=line@entry=4908, function=function@entry=0x7fdec7ca725a <__PRETTY_FUNCTION__.25691> "kgem_add_reloc") at assert.c:92
#3  0x00007fdecaec7392 in __GI___assert_fail (assertion=assertion@entry=0x7fdec7ca6418 "bo->rq == ((struct kgem_request *)((uintptr_t)(kgem->next_request) | (kgem->ring)))", file=file@entry=0x7fdec7ca5594 "kgem.c", line=line@entry=4908, function=function@entry=0x7fdec7ca725a <__PRETTY_FUNCTION__.25691> "kgem_add_reloc") at assert.c:101
#4  0x00007fdec7bb144f in kgem_add_reloc (kgem=kgem@entry=0x7fdeccd58000, pos=pos@entry=16369, bo=<optimized out>, bo@entry=0x243a950, read_write_domain=131074, delta=<optimized out>, delta@entry=0) at kgem.c:4908
#5  0x00007fdec7c79b31 in gen7_bind_bo (sna=sna@entry=0x7fdeccd58000, bo=0x243a950, width=922, height=1080, format=<optimized out>, is_dst=is_dst@entry=true) at gen7_render.c:1301
#6  0x00007fdec7c7aad3 in gen7_emit_fill_state (sna=sna@entry=0x7fdeccd58000, op=op@entry=0x7fffa0feb3a0) at gen7_render.c:3328
#7  0x00007fdec7c802fc in gen7_render_fill (sna=0x7fdeccd58000, alu=3 '\003', dst=0x3254be0, dst_bo=0x243a950, color=16711680, op=0x7fffa0feb3a0) at gen7_render.c:3645
#8  0x00007fdec7be1d40 in sna_fill_init_blt (alu=<optimized out>, fill=0x7fffa0feb3a0, pixel=16711680, bo=<optimized out>, pixmap=<optimized out>, sna=<optimized out>) at sna_accel.c:427
#9  sna_poly_line_blt (clipped=true, extents=0x7fffa0feb360, pt=0x7fffa0fec5e0, n=5, mode=0, pixel=16711680, damage=0x0, bo=<optimized out>, drawable=0x3513330, gc=<optimized out>) at sna_accel.c:8215
#10 sna_poly_line (drawable=0x3513330, gc=0x34e2c70, mode=0, n=5, pt=0x7fffa0fec5e0) at sna_accel.c:8606
#11 0x000000000057c9ba in miPolyRectangle (pDraw=pDraw@entry=0x3513330, pGC=pGC@entry=0x34e2c70, nrects=nrects@entry=1, pRects=pRects@entry=0x35436dc) at mipolyrect.c:171
#12 0x00007fdec7bda3ee in sna_poly_rectangle (drawable=0x3513330, gc=0x34e2c70, n=1, r=0x35436dc) at sna_accel.c:10291
#13 0x000000000051b599 in damagePolyRectangle (pDrawable=0x3513330, pGC=<optimized out>, nRects=1, pRects=0x35436dc) at damage.c:1108
#14 0x0000000000439b1d in ProcPolyRectangle (client=0x34ec490) at dispatch.c:1764
#15 0x000000000043d541 in Dispatch () at dispatch.c:428
#16 0x000000000042c06a in main (argc=9, argv=0x7fffa0fec928, envp=<optimized out>) at main.c:295

Comment 1 Chris Wilson 2013-10-14 22:15:36 UTC

As easy to reproduce as last time? Did I regress when refactoring the gen4+ code? If it is easy to reproduce, a new debug log would be much appreciated again. I wonder how it escaped the net...

Comment 2 Chris Wilson 2013-10-14 22:20:16 UTC

Ok, I think I know the reason... I've added an assert that is likely to explode in lots of places...

Comment 3 Jiri Slaby 2013-10-15 14:10:19 UTC

This is what I got:

#3  0x00007f279b24c392 in __GI___assert_fail (assertion=assertion@entry=0x7f279802da70 "has_coherent_ptr(to_sna_from_pixmap(pixmap), sna_pixmap(pixmap), 0x2)", file=file@entry=0x7f279802bea1 "sna_accel.c", line=line@entry=15036, function=function@entry=0x7f279802f23a <__PRETTY_FUNCTION__.28870> "sna_get_image") at assert.c:101
#4  0x00007f2797f54f4e in sna_get_image (drawable=0x1c540f0, x=<optimized out>, y=<optimized out>, w=22, h=22, format=<optimized out>, mask=4294967295, dst=0x1c54910 "") at sna_accel.c:15036
#5  0x000000000057fbc3 in miSpriteGetImage (pDrawable=0x1c540f0, sx=0, sy=0, w=22, h=22, format=2, planemask=4294967295, pdstLine=0x1c54910 "") at misprite.c:414
#6  0x00000000004ca0b0 in compGetImage (pDrawable=0x1c540f0, sx=<optimized out>, sy=<optimized out>, w=<optimized out>, h=<optimized out>, format=<optimized out>, planemask=4294967295, pdstLine=0x1c54910 "") at compinit.c:148
#7  0x000000000043a701 in DoGetImage (planemask=<optimized out>, height=22, width=<optimized out>, y=<optimized out>, x=0, drawable=<optimized out>, format=2, client=0x16da5e0, im_return=<optimized out>) at dispatch.c:2127
#8  ProcGetImage (client=0x16da5e0) at dispatch.c:2202
#9  0x000000000043d541 in Dispatch () at dispatch.c:428
#10 0x000000000042c06a in main (argc=9, argv=0x7fff340d92a8, envp=<optimized out>) at main.c:295

Comment 4 Chris Wilson 2013-10-15 15:11:51 UTC

Ok, that second assertion should be silenced by

commit 8447e50824d26f3c61e665269534062f34380ef6
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Oct 15 14:39:13 2013 +0100

    sna: Allow read-mappings for has_coherent_ptr() assert
    
    The assertion was a little too specific and disallowed us to have a CPU
    read-only mapping.
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

but please be on the lookout for other new assertions intended to track down the root cause of comment 1.

Comment 5 Jiri Slaby 2013-10-17 09:53:58 UTC

I got this with an older snapshot (c99d44) and I think we haven't seen it yet. Now I'm at ec0866e86d365a to meet the newly addedasserts...

#3  0x00007f0328ee7392 in __GI___assert_fail (assertion=assertion@entry=0x7f0325cc8b78 "priv->cpu == 0 || (priv->mapped && pixmap->devPrivate.ptr == ((void*)((uintptr_t)(priv->gpu_bo->map__cpu) & ~3)))", file=file@entry=0x7f0325cc7aa1 "sna_accel.c", line=line@entry=3674, function=function@entry=0x7f0325cca4a0 <__PRETTY_FUNCTION__.26148> "sna_pixmap_move_to_gpu") at assert.c:101
#4  0x00007f0325be80ff in sna_pixmap_move_to_gpu (pixmap=pixmap@entry=0x2f23cb0, flags=flags@entry=195) at sna_accel.c:3674
#5  0x00007f0325ca5380 in sna_pixmap_set_dri (pixmap=0x2f23cb0, sna=0x7f032ad78000) at sna_dri.c:147
#6  sna_dri_create_buffer (draw=0x2f23cb0, attachment=0, format=32) at sna_dri.c:260
#7  0x000000000056092c in create_buffer (format=32, attachment=0, pDraw=0x2f23cb0) at dri2.c:448
#8  allocate_or_reuse_buffer (pDraw=pDraw@entry=0x2f23cb0, pPriv=pPriv@entry=0x34ad5d0, attachment=attachment@entry=0, format=format@entry=32, dimensions_match=dimensions_match@entry=1, buffer=buffer@entry=0x21610f0, ds=<optimized out>) at dri2.c:495
#9  0x00000000005612c6 in do_get_buffers (pDraw=0x2f23cb0, width=width@entry=0x7fffd36d42e0, height=height@entry=0x7fffd36d42e8, attachments=0x35e9464, attachments@entry=0x35e945c, count=1, out_count=out_count@entry=0x7fffd36d42f0, has_format=has_format@entry=1) at dri2.c:573
#10 0x00000000005616e0 in DRI2GetBuffersWithFormat (pDraw=<optimized out>, width=width@entry=0x7fffd36d42e0, height=height@entry=0x7fffd36d42e8, attachments=attachments@entry=0x35e945c, count=<optimized out>, out_count=out_count@entry=0x7fffd36d42f0) at dri2.c:690
#11 0x0000000000563160 in ProcDRI2GetBuffersWithFormat (client=0x1d85b20) at dri2ext.c:306
#12 ProcDRI2Dispatch (client=0x1d85b20) at dri2ext.c:608
#13 0x000000000043d541 in Dispatch () at dispatch.c:428
#14 0x000000000042c06a in main (argc=9, argv=0x7fffd36d44f8, envp=<optimized out>) at main.c:295

Comment 6 Jiri Slaby 2013-10-17 09:58:40 UTC

(In reply to comment #5)
> I got this with an older snapshot (c99d44) and I think we haven't seen it
> yet. Now I'm at ec0866e86d365a to meet the newly addedasserts...
...
> #4  0x00007f0325be80ff in sna_pixmap_move_to_gpu
> (pixmap=pixmap@entry=0x2f23cb0, flags=flags@entry=195) at sna_accel.c:3674

Ok that one happened with ec0866e86d365a too. Easily reproducible with KDE desktop effects and pressing alt-tab to present windows multiple times...

Comment 7 Chris Wilson 2013-10-17 11:32:25 UTC

Hmm, that is new. I've pushed more assertions to track priv->mapped and priv->cpu to hopefully catch the error earlier.

Comment 8 Jiri Slaby 2013-10-18 09:41:12 UTC

I got this with an updated ddx (2.99.904-38-gf81a7f7):

#3  0x00007f648ddfa392 in __GI___assert_fail (assertion=assertion@entry=0x7f648abdad80 "pixmap->devPrivate.ptr == (priv->cpu ? ((void*)((uintptr_t)(priv->gpu_bo->map__cpu) & ~3)) : ((void*)((uintptr_t)(priv->gpu_bo->map__gtt) & ~3)))", file=file@entry=0x7f648abda54e "sna.h", line=line@entry=502, function=function@entry=0x7f648abdced0 <__PRETTY_FUNCTION__.22810> "sna_pixmap_unmap") at assert.c:101
#4  0x00007f648aacfd23 in sna_pixmap_unmap (pixmap=<optimized out>, pixmap=<optimized out>, priv=<optimized out>) at sna.h:502
#5  0x00007f648aafc955 in pixmap_inplace (flags=<optimized out>, priv=<optimized out>, sna=<optimized out>, pixmap=<optimized out>) at sna_accel.c:1464
#6  _sna_pixmap_move_to_cpu (pixmap=pixmap@entry=0x207cc10, flags=flags@entry=3) at sna_accel.c:1948
#7  0x00007f648aaff209 in sna_drawable_move_region_to_cpu (drawable=<optimized out>, region=region@entry=0x7fffe65c0df0, flags=flags@entry=3) at sna_accel.c:2387
#8  0x00007f648ab4f00a in trapezoid_span_inplace__x8r8g8b8 (op=<optimized out>, op@entry=3 '\003', dst=dst@entry=0x207d5f0, src=src@entry=0x207d540, src_x=src_x@entry=6, src_y=src_y@entry=4, maskFormat=maskFormat@entry=0x1402508, ntrap=ntrap@entry=9, traps=traps@entry=0x2071df4) at sna_trapezoids_imprecise.c:2693
#9  0x00007f648ab50a09 in imprecise_trapezoid_span_inplace (sna=sna@entry=0x7f648fc8b000, op=op@entry=3 '\003', src=src@entry=0x207d540, dst=dst@entry=0x207d5f0, maskFormat=maskFormat@entry=0x1402508, flags=flags@entry=2, src_x=src_x@entry=6, src_y=src_y@entry=4, ntrap=ntrap@entry=9, traps=traps@entry=0x2071df4, fallback=fallback@entry=false) at sna_trapezoids_imprecise.c:2928
#10 0x00007f648ab4371f in trapezoid_span_inplace (fallback=false, traps=0x2071df4, ntrap=9, src_y=4, src_x=6, flags=2, maskFormat=0x1402508, dst=0x207d5f0, src=0x207d540, op=3 '\003', sna=0x7f648fc8b000) at sna_trapezoids.h:155
#11 trapezoid_span_inplace (fallback=false, traps=0x2071df4, ntrap=9, src_y=4, src_x=6, flags=2, maskFormat=0x1402508, dst=0x207d5f0, src=0x207d540, op=3 '\003', sna=0x7f648fc8b000) at sna_trapezoids.c:540
#12 sna_composite_trapezoids (op=3 '\003', src=0x207d540, dst=0x207d5f0, maskFormat=0x1402508, xSrc=6, ySrc=4, ntrap=9, traps=0x2071df4) at sna_trapezoids.c:669
#13 0x00000000005132fb in ProcRenderTrapezoids (client=0x1981e20) at render.c:759
#14 0x000000000043d541 in Dispatch () at dispatch.c:428
#15 0x000000000042c06a in main (argc=9, argv=0x7fffe65c43b8, envp=<optimized out>) at main.c:295

Comment 9 Chris Wilson 2013-10-18 11:37:53 UTC

One step towards tracking down the original bug!

commit dd280a69b500d2187925f67a541e045a7ae24b07
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Oct 18 11:12:51 2013 +0100

    sna: Tighten pixmap map assertions
    
    We need to also take account of upload buffers which include an offset
    to the base map. To do so, we also need to stop conflating the cpu hint
    with the current mapping flag.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 10 Jiri Slaby 2013-10-18 13:28:47 UTC

No crashes so far :). Thanks.

Comment 11 Jiri Slaby 2013-10-19 15:10:16 UTC

This is a new one (with 2.99.904-39-gdd280a6). And reproducible. Happens every time I open http://www.starwoodhotels.com/sheraton/property/area/index.html?propertyID=474&ES=LPS_474_EN_SI_AREA_EDI_NWE_EAME

#7  <signal handler called>
#8  sna_pixmap_unmap (priv=0x2fd3ec0, pixmap=<optimized out>) at sna.h:512
#9  sna_pixmap_undo_cow (sna=sna@entry=0x7fcb81f38000, priv=priv@entry=0x2fd3ec0, flags=flags@entry=0) at sna_accel.c:1727
#10 0x00007fcb7cda3114 in sna_pixmap_free_gpu (sna=sna@entry=0x7fcb81f38000, priv=priv@entry=0x2fd3ec0) at sna_accel.c:448
#11 0x00007fcb7cda51de in try_upload_tiled_x (pixmap=pixmap@entry=0x2fe90a0, region=region@entry=0x7fff90cb2e30, x=x@entry=0, y=y@entry=0, w=w@entry=52, h=h@entry=20, bits=bits@entry=0x7fcb6cc6f000 "\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377_n\233\377\226\247\300\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377"..., stride=stride@entry=208) at sna_accel.c:4194
#12 0x00007fcb7cdae433 in sna_put_zpixmap_blt (drawable=drawable@entry=0x2fe90a0, region=region@entry=0x7fff90cb2e30, x=x@entry=0, y=y@entry=0, w=w@entry=52, h=h@entry=20, bits=bits@entry=0x7fcb6cc6f000 "\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377_n\233\377\226\247\300\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377"..., stride=208, gc=0x2ffdfd0) at sna_accel.c:4322
#13 0x00007fcb7cdbd921 in sna_put_image (drawable=0x2fe90a0, gc=0x2ffdfd0, depth=24, x=0, y=0, w=52, h=20, left=0, format=2, bits=0x7fcb6cc6f000 "\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377_n\233\377\226\247\300\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377"...) at sna_accel.c:4702
#14 0x000000000051caf2 in damagePutImage (pDrawable=0x2fe90a0, pGC=0x2ffdfd0, depth=24, x=0, y=0, w=<optimized out>, h=20, leftPad=0, format=2, pImage=0x7fcb6cc6f000 "\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377_n\233\377\226\247\300\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377\310\331\342\377"...) at damage.c:792
#15 0x00000000004d9c3d in ProcShmPutImage (client=0x2fc7770) at shm.c:584
#16 0x00000000004daad5 in ProcShmDispatch (client=0x2fc7770) at shm.c:1115
#17 0x000000000043d541 in Dispatch () at dispatch.c:428
#18 0x000000000042c06a in main (argc=9, argv=0x7fff90cb3288, envp=<optimized out>) at main.c:295

Comment 12 Chris Wilson 2013-10-19 16:21:33 UTC

Looks to have been just the messenger. Worse, I thought I had all escape routes covered. Very reproducible? A debug log will be great, but realistically I won't be able to do anything before tomorrow.

Comment 13 Jiri Slaby 2013-10-19 21:10:57 UTC

(In reply to comment #12)
> Looks to have been just the messenger. Worse, I thought I had all escape
> routes covered. Very reproducible? A debug log will be great, but
> realistically I won't be able to do anything before tomorrow.

Here you go:
http://www.fi.muni.cz/~xslaby/sklad/Xorg.0.log.old.xz

Comment 14 Chris Wilson 2013-10-19 21:31:55 UTC

Hmm, both times it is the segfault rather than the sigabrt? Hmm. priv->gpu_bo is already NULL here then.

Comment 15 Chris Wilson 2013-10-19 21:40:44 UTC

I think I'm still sober enough to commit...

commit b1ecadd7b44a8e95522cc4a6e4b908b071709e06
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sat Oct 19 22:38:15 2013 +0100

    sna: Unmap pixmap prior to release GPU bo
    
    As the unmap routine will deference the GPu bo in its debugging code, we
    need to be sure that the pointer is still valid at the time of
    unmapping. Hence unmap before release.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 16 Jiri Slaby 2013-10-20 09:34:34 UTC

(In reply to comment #15)
> I think I'm still sober enough to commit...
> 
> commit b1ecadd7b44a8e95522cc4a6e4b908b071709e06
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Sat Oct 19 22:38:15 2013 +0100
> 
>     sna: Unmap pixmap prior to release GPU bo

Fixed, thanks.

Comment 17 Jiri Slaby 2013-10-29 07:53:33 UTC

With 2.99.904-43-g33be42b, when I unplugged the notebook from docking station (including the displayport).

#3  0x00007fc7895bc392 in __GI___assert_fail (assertion=assertion@entry=0x7fc78639dbe8 "priv->cpu == 0 || (priv->mapped && pixmap->devPrivate.ptr == ((void*)((uintptr_t)(priv->gpu_bo->map__cpu) & ~3)))", file=file@entry=0x7fc78639c8ae "sna_accel.c", line=line@entry=3254, function=function@entry=0x7fc78639f5e0 <__PRETTY_FUNCTION__.26132> "sna_drawable_use_bo") at assert.c:101
#4  0x00007fc7862c52be in sna_drawable_use_bo (drawable=0x2ab4d70, flags=flags@entry=7, box=box@entry=0x7fffb61f02a0, damage=damage@entry=0x7fffb61f0498) at sna_accel.c:3254
#5  0x00007fc78636c94e in gen7_composite_set_target (sna=sna@entry=0x7fc78b44d000, op=op@entry=0x7fffb61f0470, dst=dst@entry=0x2d08c40, x=x@entry=980, y=y@entry=1080, w=w@entry=948, h=h@entry=733, partial=true) at gen7_render.c:2113
#6  0x00007fc7863749ab in gen7_render_composite (tmp=0x7fffb61f0470, height=733, width=948, dst_y=1080, dst_x=980, msk_y=9, msk_x=8, src_y=9, src_x=8, dst=0x2d08c40, mask=0x0, src=0x3c8e4c0, op=<optimized out>, sna=0x7fc78b44d000) at gen7_render.c:2433
#7  gen7_render_composite (sna=sna@entry=0x7fc78b44d000, op=<optimized out>, src=src@entry=0x3c8e4c0, mask=mask@entry=0x0, dst=dst@entry=0x2d08c40, src_x=src_x@entry=8, src_y=src_y@entry=9, msk_x=msk_x@entry=8, msk_y=9, dst_x=980, dst_y=1080, width=948, height=733, tmp=tmp@entry=0x7fffb61f0470) at gen7_render.c:2386
#8  0x00007fc7862e31fb in sna_composite (op=<optimized out>, src=<optimized out>, mask=0x0, dst=0x2d08c40, src_x=8, src_y=0, mask_x=0, mask_y=0, dst_x=-8, dst_y=-9, width=964, height=1830) at sna_composite.c:718
#9  0x00000000005197a9 in damageComposite (op=1 '\001', pSrc=0x3c8e4c0, pMask=0x0, pDst=0x2d08c40, xSrc=0, ySrc=0, xMask=0, yMask=0, xDst=-8, yDst=-9, width=964, height=1830) at damage.c:559
#10 0x00000000004cc4d0 in compWindowUpdateAutomatic (pWin=<optimized out>) at compwindow.c:682
#11 compPaintWindowToParent (pWin=0x2603710) at compwindow.c:706
#12 compPaintChildrenToWindow (pWin=pWin@entry=0x2ab4d70) at compwindow.c:721
#13 0x00000000004cc355 in compPaintWindowToParent (pWin=0x2ab4d70) at compwindow.c:700
#14 compPaintChildrenToWindow (pWin=pWin@entry=0x1ff96a0) at compwindow.c:721
#15 0x00000000004ca1cc in compSourceValidate (pDrawable=0x1ff96a0, x=<optimized out>, y=<optimized out>, width=<optimized out>, height=<optimized out>, subWindowMode=<optimized out>) at compinit.c:163
#16 0x00007fc7862b2bfe in sna_do_copy (src=src@entry=0x1ff96a0, dst=dst@entry=0x34045a0, gc=gc@entry=0x1ff8ed0, sx=sx@entry=980, sy=sy@entry=0, width=width@entry=948, height=height@entry=1813, dx=dx@entry=0, dy=dy@entry=0, copy=0x7fc7862ceb20 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:5999
#17 0x00007fc7862b31af in sna_copy_area (src=0x1ff96a0, dst=0x34045a0, gc=0x1ff8ed0, src_x=980, src_y=0, width=948, height=1813, dst_x=0, dst_y=0) at sna_accel.c:6170
#18 0x000000000051c8ad in damageCopyArea (pSrc=0x1ff96a0, pDst=0x34045a0, pGC=0x1ff8ed0, srcx=980, srcy=<optimized out>, width=948, height=1813, dstx=0, dsty=0) at damage.c:821
#19 0x00000000004cc878 in compNewPixmap (pWin=pWin@entry=0x2ab4d70, x=x@entry=980, y=y@entry=0, w=948, h=1813) at compalloc.c:554
#20 0x00000000004cdc1f in compReallocPixmap (pWin=pWin@entry=0x2ab4d70, draw_x=<optimized out>, draw_y=<optimized out>, w=w@entry=948, h=h@entry=1813, bw=bw@entry=0) at compalloc.c:681
#21 0x00000000004cb60c in compConfigNotify (pWin=0x2ab4d70, x=<optimized out>, y=<optimized out>, w=948, h=1813, bw=0, pSib=0x29668f0) at compwindow.c:787
#22 0x00000000004683d9 in ConfigureWindow (pWin=<optimized out>, mask=15, vlist=vlist@entry=0x27d7434, client=client@entry=0x23e7de0) at window.c:2254
#23 0x0000000000437ef4 in ProcConfigureWindow (client=0x23e7de0) at dispatch.c:865
#24 0x000000000043d541 in Dispatch () at dispatch.c:428
#25 0x000000000042c06a in main (argc=9, argv=0x7fffb61f0e48, envp=<optimized out>) at main.c:295

Comment 18 Chris Wilson 2013-10-29 08:09:44 UTC

Ah, those assertions were stale after the priv->mmaped update to be independent of priv->cpu. I silently removed those in 

commit fa2687bdd5a4c8bc608dac8bb711035f0752a725
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Oct 21 18:55:23 2013 +0100

    sna: Eliminate the synchronous wait from inside TearFree

whilst making TearFree happier.

Comment 19 Jiri Slaby 2013-10-29 18:01:02 UTC

Ok, this is with a today's snapshot 2.99.905-31-g9f36e83d76eb:

#3  0x00007f5656927392 in __GI___assert_fail (assertion=assertion@entry=0x7f56537049c6 "bo->base.rq", file=file@entry=0x7f5653704514 "kgem.c", line=line@entry=2455, function=function@entry=0x7f5653706090 <__PRETTY_FUNCTION__.25258> "kgem_finish_buffers") at assert.c:101
#4  0x00007f565360ec49 in kgem_finish_buffers (kgem=0x7f56587b8000) at kgem.c:2455
#5  _kgem_submit (kgem=kgem@entry=0x7f56587b8000) at kgem.c:2883
#6  0x00007f56536407fe in sna_accel_block_handler (sna=0x7f56587b8000, tv=0x7fff1690bdd8) at sna_accel.c:16130
#7  0x0000000000441674 in BlockHandler (pTimeout=pTimeout@entry=0x7fff1690bdd8, pReadmask=pReadmask@entry=0x81bfa0 <LastSelectMask>) at dixutils.c:387
#8  0x000000000058ccc4 in WaitForSomething (pClientsReady=pClientsReady@entry=0x1c0def0) at WaitFor.c:210
#9  0x000000000043d291 in Dispatch () at dispatch.c:357
#10 0x000000000042c06a in main (argc=9, argv=0x7fff1690c1e8, envp=<optimized out>) at main.c:295

Comment 20 Chris Wilson 2013-10-29 18:02:50 UTC

Still playing with these assertions and their fallout. Ouch.

Comment 21 Jiri Slaby 2013-10-29 18:17:18 UTC

Another one:

#3  0x00007effea504392 in __GI___assert_fail (assertion=assertion@entry=0x7effe72e16c4 "bo->rq == (void *)kgem", file=file@entry=0x7effe72e1414 "kgem.c", line=line@entry=2122, function=function@entry=0x7effe72e2dc0 <__PRETTY_FUNCTION__.25177> "kgem_retire__flushing") at assert.c:101
#4  0x00007effe71e2916 in kgem_retire__flushing (kgem=0x7effec395000) at kgem.c:2122
#5  kgem_retire (kgem=0x7effec395000) at kgem.c:2287
#6  0x00007effe721dcb5 in sna_accel_block_handler (sna=0x7effec395000, tv=0x7fff92835818) at sna_accel.c:16121
#7  0x0000000000441674 in BlockHandler (pTimeout=pTimeout@entry=0x7fff92835818, pReadmask=pReadmask@entry=0x81bfa0 <LastSelectMask>) at dixutils.c:387
#8  0x000000000058ccc4 in WaitForSomething (pClientsReady=pClientsReady@entry=0x1cbfef0) at WaitFor.c:210
#9  0x000000000043d291 in Dispatch () at dispatch.c:357
#10 0x000000000042c06a in main (argc=9, argv=0x7fff92835c28, envp=<optimized out>) at main.c:295

Comment 22 Chris Wilson 2013-10-29 18:29:37 UTC

(In reply to comment #21)
> Another one:
> 
> #3  0x00007effea504392 in __GI___assert_fail
> (assertion=assertion@entry=0x7effe72e16c4 "bo->rq == (void *)kgem",
> file=file@entry=0x7effe72e1414 "kgem.c", line=line@entry=2122,
> function=function@entry=0x7effe72e2dc0 <__PRETTY_FUNCTION__.25177>
> "kgem_retire__flushing") at assert.c:101

commit 9352769eee0889dd1c1656829c140384a9e94bcf
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Oct 29 18:27:41 2013 +0000

    sna: Fix assertion checks for fake flushing requests
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>


Hadn't seen that one myself.

Comment 23 Jiri Slaby 2013-10-29 18:45:48 UTC

fixed for now.

Comment 24 Jiri Slaby 2013-12-12 14:23:25 UTC

Today's snapshot:

#3  0x00007fe217f50392 in __GI___assert_fail (assertion=assertion@entry=0x7fe214d3620a "sna->render.nvertex_reloc", file=file@entry=0x7fe214d36178 "gen4_vertex.c", line=line@entry=91, function=function@entry=0x7fe214d364d0 <__PRETTY_FUNCTION__.23486> "gen4_vertex_finish") at assert.c:101
#4  0x00007fe214cd2fc6 in gen4_vertex_finish (sna=sna@entry=0x7fe219de1000) at gen4_vertex.c:91
#5  0x00007fe214c05c3f in gen7_get_rectangles__flush (sna=sna@entry=0x7fe219de1000, op=op@entry=0x7ffff5be49b0) at gen7_render.c:1413
#6  0x00007fe214cefc0f in gen7_get_rectangles (emit_state=0x7fe214cee630 <gen7_emit_composite_state>, want=1, op=0x7ffff5be49b0, sna=0x7fe219de1000) at gen7_render.c:1430
#7  gen7_render_composite_spans_box (sna=0x7fe219de1000, op=0x7ffff5be49b0, box=<optimized out>, opacity=<optimized out>) at gen7_render.c:2598
#8  0x00007fe214c8ac30 in tor_blt (unbounded=0, height=<optimized out>, y=3, span=0x7fe214c883e0 <tor_blt_span__no_damage>, clip=0x7ffff5be4970, op=0x7ffff5be49b0, converter=0x7ffff5be4b80, sna=0x7fe219de1000) at sna_trapezoids_imprecise.c:1128
#9  tor_render (sna=sna@entry=0x7fe219de1000, converter=converter@entry=0x7ffff5be4b80, op=op@entry=0x7ffff5be49b0, clip=clip@entry=0x7ffff5be4970, span=0x7fe214c883e0 <tor_blt_span__no_damage>, unbounded=unbounded@entry=0) at sna_trapezoids_imprecise.c:1231
#10 0x00007fe214c8d94c in imprecise_trapezoid_span_converter (sna=sna@entry=0x7fe219de1000, op=op@entry=3 '\003', src=src@entry=0x2b8f570, dst=dst@entry=0x3c2b240, maskFormat=maskFormat@entry=0x22e75c8, flags=flags@entry=0, src_x=43, src_y=422, ntrap=ntrap@entry=20, traps=traps@entry=0x41c64fc) at sna_trapezoids_imprecise.c:1956
#11 0x00007fe214c7ffc5 in trapezoid_span_converter (traps=0x41c64fc, ntrap=20, src_y=<optimized out>, src_x=<optimized out>, flags=0, maskFormat=0x22e75c8, dst=0x3c2b240, src=0x2b8f570, op=3 '\003', sna=0x7fe219de1000) at sna_trapezoids.h:173
#12 sna_composite_trapezoids (op=3 '\003', src=0x2b8f570, dst=0x3c2b240, maskFormat=0x22e75c8, xSrc=43, ySrc=422, ntrap=20, traps=0x41c64fc) at sna_trapezoids.c:674
#13 0x000000000051330b in ProcRenderTrapezoids (client=0x29b1020) at render.c:759
#14 0x000000000043d541 in Dispatch () at dispatch.c:428
#15 0x000000000042c06a in main (argc=9, argv=0x7ffff5be6728, envp=<optimized out>) at main.c:295

Comment 25 Chris Wilson 2013-12-12 16:54:34 UTC

Ok, twas just a new bogus assert.

commit f350a1369b3bd39ba0db8639f036864fe5df2f98
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Dec 12 16:49:02 2013 +0000

    sna/gen4+: Drop new assertion that we only finish a vbo after use in this batch
    
    A full vbo might not be discarded and so upon first use in the following
    batch we decided to finish the old vbo and allocate a new. This can
    happen before we even emit any relocations and so the assert is bogus.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 26 Jiri Slaby 2014-01-28 16:04:34 UTC

Today with 2.99.907-54-g294180b3bf78, I got:

#3  0x00007fd23f5c16c2 in __GI___assert_fail (assertion=assertion@entry=0x7fd23b6a44d0 "bo->domain == 3 || bo->domain == 0", file=file@entry=0x7fd23b6a3b1a "kgem.c", line=line@entry=2253, function=function@entry=0x7fd23b6a5ba0 <__PRETTY_FUNCTION__.25448> "__kgem_retire_rq") at assert.c:101
#4  0x00007fd23b585900 in __kgem_retire_rq (kgem=kgem@entry=0x7fd241476000, rq=rq@entry=0x11dd0b40) at kgem.c:2253
#5  0x00007fd23b585b9b in kgem_retire__requests_ring (kgem=kgem@entry=0x7fd241476000, ring=ring@entry=0) at kgem.c:2320
#6  0x00007fd23b587cfb in kgem_retire__requests (kgem=0x7fd241476000) at kgem.c:2351
#7  kgem_retire (kgem=0x7fd241476000) at kgem.c:2367
#8  0x00007fd23b5c82cd in sna_accel_block_handler (sna=0x7fd241476000, tv=0x7fff8570a0c8) at sna_accel.c:16964
#9  0x0000000000440c84 in BlockHandler (pTimeout=pTimeout@entry=0x7fff8570a0c8, pReadmask=pReadmask@entry=0x81e160 <LastSelectMask>) at dixutils.c:387
#10 0x0000000000582fe4 in WaitForSomething (pClientsReady=pClientsReady@entry=0x1ef03b0) at WaitFor.c:210
#11 0x000000000043c991 in Dispatch () at dispatch.c:361
#12 0x000000000042c1ba in main (argc=9, argv=0x7fff8570a4d8, envp=<optimized out>) at main.c:298

Comment 27 Chris Wilson 2014-01-28 17:39:47 UTC

Not sure. The scenarios I thought of involved a race with an external client (i.e. GL) or a kernel bug. However,

commit 8b0ebebcab21647348f769c25ca0c1d81d169e75
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Jan 28 16:30:47 2014 +0000

    sna: Be a little more assertive in retiring after set-domain
    
    After a successful set-domain for writing with the CPU, we know that the
    buffer is idle so remove it from our request tracking. (External clients
    complicate matters in that they may keep the bo active even after our
    set-domain.) On the contrary, because of read-read optimisations a bo
    may still be active after a set-domain for reading by the CPU, in which
    we need to remain conservative in retiring the bo.
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

should paper over the assertion.

Comment 28 Chris Wilson 2014-01-29 13:54:16 UTC

And to be sure you were paying attention, I made the patch buggy...

commit d70620d9789da1cf983dac318d9ca9149f11ff20
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Jan 29 13:39:20 2014 +0000

    sna: We can only retire a bo if is not referenced by the current batch
    
    Fixes regression from
    commit 8b0ebebcab21647348f769c25ca0c1d81d169e75
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Tue Jan 28 16:30:47 2014 +0000
    
        sna: Be a little more assertive in retiring after set-domain
    
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=74176
    Reported-by: Jan Alexander Steffens <jan.steffens@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 29 Chris Wilson 2014-02-05 10:48:48 UTC

Poke the bear by declaring that it never happened! (The updated assertions would be good to test out in anger.)

Comment 30 Jiri Slaby 2014-02-10 14:06:38 UTC

I got this today with 2.99.909-17-g823382d28944:

#3  0x00007f42df92e6c2 in __GI___assert_fail (assertion=assertion@entry=0x7f42dba15280 "!(((uintptr_t)(priv->gpu_damage))&1)", file=file@entry=0x7f42dba13080 "sna_accel.c", line=line@entry=2931, function=function@entry=0x7f42dba16f00 <__PRETTY_FUNCTION__.26328> "sna_drawable_move_region_to_cpu") at assert.c:101
#4  0x00007f42db91dc2c in sna_drawable_move_region_to_cpu (drawable=drawable@entry=0x354cd40, region=region@entry=0x7fffba788460, flags=<optimized out>) at sna_accel.c:2931
#5  0x00007f42db9304ce in sna_copy_boxes (src=<optimized out>, dst=<optimized out>, gc=<optimized out>, region=<optimized out>, dx=0, dy=0, bitplane=0, closure=0x0) at sna_accel.c:6218
#6  0x00007f42db908782 in sna_do_copy (src=src@entry=0x382ba50, dst=dst@entry=0x354cd40, gc=gc@entry=0x28894d0, sx=sx@entry=0, sy=sy@entry=0, width=width@entry=27, height=height@entry=27, dx=dx@entry=0, dy=dy@entry=0, copy=0x7f42db92fbf0 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:6411
#7  0x00007f42db908a9b in sna_copy_area (src=0x382ba50, dst=0x354cd40, gc=0x28894d0, src_x=0, src_y=0, width=27, height=27, dst_x=0, dst_y=0) at sna_accel.c:6493
#8  0x0000000000439191 in ProcCopyArea (client=0x2f40df0) at dispatch.c:1626
#9  0x000000000043cc3e in Dispatch () at dispatch.c:432
#10 0x000000000042c1ba in main (argc=9, argv=0x7fffba788738, envp=<optimized out>) at main.c:298

Comment 31 Chris Wilson 2014-02-10 14:22:58 UTC

Spotted one very minor issue that could have lead to that assertion.

commit 2f99070708ce8f591c31e1e908809a0ce551c13f
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Feb 10 14:19:53 2014 +0000

    sna: Clear GPU damage flag for 1x1 writes onto a clear buffer
    
    An optimisation for 1x1 reads of a clear buffer lead to a bug whereby
    the damage for a 1x1 write would not be tracked correctly (conflicting
    full GPU damage vs partial CPU damage).
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Having found one path that could generate the assertion, I'm less confident that they are no others...

Comment 32 Chris Wilson 2014-02-10 14:41:44 UTC

Ok, reasonably confident that was indeed the only possible path to that assert.

Comment 33 Jiri Slaby 2014-02-10 15:18:15 UTC

It still crashes there+1 with 2.99.910-1-g2f99070708ce:

#3  0x00007fd3032f06c2 in __GI___assert_fail (assertion=assertion@entry=0x7fd2ff3d7280 "!(((uintptr_t)(priv->gpu_damage))&1)", file=file@entry=0x7fd2ff3d5080 "sna_accel.c", line=line@entry=2932, function=function@entry=0x7fd2ff3d8f00 <__PRETTY_FUNCTION__.26328> "sna_drawable_move_region_to_cpu") at assert.c:101
#4  0x00007fd2ff2dfc36 in sna_drawable_move_region_to_cpu (drawable=drawable@entry=0x20e8600, region=region@entry=0x7fffa4b1d760, flags=<optimized out>) at sna_accel.c:2932
#5  0x00007fd2ff2f24ce in sna_copy_boxes (src=<optimized out>, dst=<optimized out>, gc=<optimized out>, region=<optimized out>, dx=0, dy=0, bitplane=0, closure=0x0) at sna_accel.c:6219
#6  0x00007fd2ff2ca782 in sna_do_copy (src=src@entry=0x21384b0, dst=dst@entry=0x20e8600, gc=gc@entry=0x20e71d0, sx=sx@entry=0, sy=sy@entry=0, width=width@entry=27, height=height@entry=27, dx=dx@entry=0, dy=dy@entry=0, copy=0x7fd2ff2f1bf0 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:6412
#7  0x00007fd2ff2caa9b in sna_copy_area (src=0x21384b0, dst=0x20e8600, gc=0x20e71d0, src_x=0, src_y=0, width=27, height=27, dst_x=0, dst_y=0) at sna_accel.c:6494
#8  0x0000000000439191 in ProcCopyArea (client=0x1a8dde0) at dispatch.c:1626
#9  0x000000000043cc3e in Dispatch () at dispatch.c:432
#10 0x000000000042c1ba in main (argc=9, argv=0x7fffa4b1da38, envp=<optimized out>) at main.c:298

Comment 34 Chris Wilson 2014-02-10 16:43:14 UTC

I guess this would disappear when debug=full?

Another, much more recent, contender:

commit 5142d1ca3fd877f2ca9277af314f6432580370de
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Feb 10 16:42:06 2014 +0000

    sna: Remove damaged region after converting CPU bo to GPU bo
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 35 Jiri Slaby 2014-02-11 18:59:38 UTC

(In reply to comment #34)
> I guess this would disappear when debug=full?
> 
> Another, much more recent, contender:

It seems to be gone now.

Comment 36 Jiri Slaby 2014-02-22 09:50:44 UTC

Is this a new one or recurrence? (with 2.99.910-49-g0b92b12)

#3  0x00007f6ab08fb6c2 in __GI___assert_fail (assertion=assertion@entry=0x7f6aac9e3a10 "box->x2 <= op->dst.pixmap->drawable.width", file=file@entry=0x7f6aac9e3821 "sna_blt.c", line=line@entry=967, function=function@entry=0x7f6aac9e4090 <__PRETTY_FUNCTION__.23865> "blt_composite_fill_boxes__cpu") at assert.c:101
#4  0x00007f6aac901fb6 in blt_composite_fill_boxes__cpu (sna=<optimized out>, op=0x7fff5cae7950, box=0x1d1f150, n=<optimized out>) at sna_blt.c:967
#5  0x00007f6aac90ecdc in sna_composite (op=<optimized out>, src=<optimized out>, mask=0x0, dst=0x1d708b0, src_x=<optimized out>, src_y=<optimized out>, mask_x=0, mask_y=0, dst_x=-9, dst_y=-9, width=348, height=111) at sna_composite.c:731
#6  0x0000000000511eb2 in damageComposite (op=<optimized out>, pSrc=0x1d31910, pMask=0x0, pDst=0x1d708b0, xSrc=<optimized out>, ySrc=<optimized out>, xMask=0, yMask=0, xDst=-9, yDst=-9, width=348, height=111) at damage.c:563
#7  0x00000000004c8ee2 in compWindowUpdateAutomatic (pWin=<optimized out>) at compwindow.c:682
#8  compPaintWindowToParent (pWin=0x1c5d650) at compwindow.c:706
#9  compPaintChildrenToWindow (pWin=pWin@entry=0x1d6d040) at compwindow.c:721
#10 0x00000000004c8d6d in compPaintWindowToParent (pWin=0x1d6d040) at compwindow.c:700
#11 compPaintChildrenToWindow (pWin=0xb7b6d0) at compwindow.c:721
#12 0x00000000004c93dd in compScreenUpdate (pScreen=0xb49a80) at compalloc.c:54
#13 compBlockHandler (pScreen=0xb49a80, pTimeout=0x7fff5cae7da8, pReadmask=0x81e160 <LastSelectMask>) at compalloc.c:63
#14 0x0000000000440c84 in BlockHandler (pTimeout=pTimeout@entry=0x7fff5cae7da8, pReadmask=pReadmask@entry=0x81e160 <LastSelectMask>) at dixutils.c:387
#15 0x0000000000582fe4 in WaitForSomething (pClientsReady=pClientsReady@entry=0xe435e0) at WaitFor.c:210
#16 0x000000000043c991 in Dispatch () at dispatch.c:361
#17 0x000000000042c1ba in main (argc=7, argv=0x7fff5cae81b8, envp=<optimized out>) at main.c:298

Comment 37 Jiri Slaby 2014-02-22 09:52:11 UTC

(In reply to comment #36)
> Is this a new one or recurrence? (with 2.99.910-49-g0b92b12)
> 
> #3  0x00007f6ab08fb6c2 in __GI___assert_fail
> (assertion=assertion@entry=0x7f6aac9e3a10 "box->x2 <=
> op->dst.pixmap->drawable.width", file=file@entry=0x7f6aac9e3821 "sna_blt.c",
> line=line@entry=967, function=function@entry=0x7f6aac9e4090
> <__PRETTY_FUNCTION__.23865> "blt_composite_fill_boxes__cpu") at assert.c:101
> #4  0x00007f6aac901fb6 in blt_composite_fill_boxes__cpu (sna=<optimized
> out>, op=0x7fff5cae7950, box=0x1d1f150, n=<optimized out>) at sna_blt.c:967

Oh, this is actually bug 73811.

Comment 38 Jiri Slaby 2014-03-31 08:14:54 UTC

I got two today.

One with a273b207b94:
#3  0x00007fa72644f6c2 in __GI___assert_fail (assertion=assertion@entry=0x7fa722539318 "damage->extents.x1 == 0 && damage->extents.y1 == 0 && damage->extents.x2 == width && damage->extents.y2 == height", file=file@entry=0x7fa722538f31 "sna_damage.c", line=line@entry=1051, function=function@entry=0x7fa722539650 <__PRETTY_FUNCTION__.23772> "_sna_damage_is_all") at assert.c:101
#4  0x00007fa722464baf in _sna_damage_is_all (damage=<optimized out>, width=<optimized out>, height=<optimized out>) at sna_damage.c:1048
#5  0x00007fa72243fda7 in sna_damage_is_all (height=<optimized out>, width=<optimized out>, _damage=0x1fd7648) at sna_damage.h:122
#6  sna_pixmap_move_area_to_gpu (pixmap=pixmap@entry=0x27612f0, box=0x7fff30855f30, flags=3) at sna_accel.c:3165
#7  0x00007fa722440b4e in sna_drawable_use_bo (drawable=0x27612f0, flags=7, box=box@entry=0x7fff30855f90, damage=damage@entry=0x7fff30856198) at sna_accel.c:3613
#8  0x00007fa7224f1d51 in gen7_composite_set_target (sna=sna@entry=0x7fa728305000, op=op@entry=0x7fff30856170, dst=dst@entry=0x2b2f990, x=x@entry=1028, y=y@entry=9, w=w@entry=49, h=h@entry=23, partial=true) at gen7_render.c:2137
#9  0x00007fa7224fb817 in gen7_render_composite (sna=sna@entry=0x7fa728305000, op=op@entry=3 '\003', src=src@entry=0x235f160, mask=mask@entry=0x2553a20, dst=dst@entry=0x2b2f990, src_x=<optimized out>, src_y=0, msk_x=0, msk_y=0, dst_x=1028, dst_y=9, width=49, height=23, flags=flags@entry=0, tmp=tmp@entry=0x7fff30856170) at gen7_render.c:2452
#10 0x00007fa722461c6d in sna_composite (op=<optimized out>, src=<optimized out>, mask=0x2553a20, dst=0x2b2f990, src_x=<optimized out>, src_y=<optimized out>, mask_x=0, mask_y=0, dst_x=1028, dst_y=9, width=49, height=23) at sna_composite.c:715
#11 0x0000000000511eb2 in damageComposite (op=<optimized out>, pSrc=0x235f160, pMask=0x2553a20, pDst=0x2b2f990, xSrc=<optimized out>, ySrc=<optimized out>, xMask=0, yMask=0, xDst=1028, yDst=9, width=49, height=23) at damage.c:563
#12 0x000000000050b7aa in ProcRenderComposite (client=0x1a49dc0) at render.c:708
#13 0x000000000043cc3e in Dispatch () at dispatch.c:432
#14 0x000000000042c1ba in main (argc=11, argv=0x7fff30856628, envp=<optimized out>) at main.c:298

Comment 39 Jiri Slaby 2014-03-31 08:16:30 UTC

And the other is with 5c0623b5f36. Looking at the trace, it's exactly the same...

Comment 40 Chris Wilson 2014-03-31 08:33:18 UTC

The warning here is that we added damage beyond the size of the buffer. Bad news. The assertion is of course too late... I think I can add an earlier check, but I thought I had all the renders checked anyway. Anyway, can you please try to find the reproduction steps so that we can test fixes? (Or in the worst case grab a full-debug log.)

Comment 41 Jiri Slaby 2014-03-31 09:25:38 UTC

(In reply to comment #40)
> Anyway, can you
> please try to find the reproduction steps so that we can test fixes? (Or in
> the worst case grab a full-debug log.)

I found a relatively reliable way to reproduce it. I just start KDE4, firefox and clementine. Open clementine's window and play an Internet stream. Then close clementine and wait until it crashes. A full debug log is here:
http://www.fi.muni.cz/~xslaby/sklad/Xorg.0.log.xz

Comment 42 Chris Wilson 2014-03-31 09:47:02 UTC

That's miserable. I need to go and sulk for a while.

Comment 43 Chris Wilson 2014-03-31 11:33:24 UTC

This should basically paper over the bug:

commit c4c8a1b180a9d4c1126ee4fe3120128aa560306c
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Mar 31 11:23:45 2014 +0100

    sna: Discard damage tracking for operations to the whole pixmap
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 44 Chris Wilson 2014-04-03 08:02:15 UTC

Fingers crossed, it is no longer reproducible.

Comment 45 Jiri Slaby 2014-04-03 08:05:13 UTC

(In reply to comment #44)
> Fingers crossed, it is no longer reproducible.

Hopefully, I haven't seen it since then. Thanks.

Comment 46 Jiri Slaby 2014-06-23 08:56:02 UTC

After a while, I am back with abbf6d6b7962650607dc3 :):

#3  0x00007fcc1c4cc6c2 in __GI___assert_fail (assertion=assertion@entry=0x7fcc185bb9d8 "vertex_index * op->floats_per_vertex <= sna->render.vertex_size", file=file@entry=0x7fcc185bb7b8 "gen4_vertex.c", line=line@entry=57, function=function@entry=0x7fcc185bc130 <__PRETTY_FUNCTION__.23837> "gen4_vertex_align") at assert.c:101
#4  0x00007fcc18555407 in gen4_vertex_align (sna=sna@entry=0x7fcc1e382000, op=op@entry=0x7fff9e74f3f0) at gen4_vertex.c:57
#5  0x00007fcc1856b151 in gen7_align_vertex (sna=sna@entry=0x7fcc1e382000, op=op@entry=0x7fff9e74f3f0) at gen7_render.c:1554
#6  0x00007fcc185750af in gen7_align_vertex (op=0x7fff9e74f3f0, sna=0x7fcc1e382000) at gen7_render.c:1551
#7  gen7_render_composite (sna=sna@entry=0x7fcc1e382000, op=op@entry=3 '\003', src=src@entry=0x30aaca0, mask=mask@entry=0x30a42b0, dst=dst@entry=0x22efd10, src_x=<optimized out>, src_y=15, msk_x=0, msk_y=0, dst_x=127, dst_y=0, width=15, height=26, flags=0, tmp=tmp@entry=0x7fff9e74f3f0) at gen7_render.c:2578
#8  0x00007fcc184d5fc7 in sna_composite (op=<optimized out>, src=<optimized out>, mask=0x30a42b0, dst=0x22efd10, src_x=<optimized out>, src_y=<optimized out>, mask_x=0, mask_y=0, dst_x=127, dst_y=0, width=15, height=26) at sna_composite.c:718
#9  0x0000000000511ec2 in damageComposite (op=<optimized out>, pSrc=0x30aaca0, pMask=0x30a42b0, pDst=0x22efd10, xSrc=<optimized out>, ySrc=<optimized out>, xMask=0, yMask=0, xDst=127, yDst=0, width=15, height=26) at damage.c:563
#10 0x000000000050b7ba in ProcRenderComposite (client=0x2e6e590) at render.c:708
#11 0x000000000043cc3e in Dispatch () at dispatch.c:432
#12 0x000000000042c1ba in main (argc=9, argv=0x7fff9e74f8a8, envp=<optimized out>) at main.c:298

Comment 47 Chris Wilson 2014-06-23 09:17:01 UTC

The asserts genuine, but I can't see a rational reason for it to fire. :|

I've pushed

commit e1e853edee67c3ced43d5e4b1fbd52ca4c92966d
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Jun 23 10:14:09 2014 +0100

    sna/gen4+: Add some more asserts around recreating vertex buffers
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c46
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

to add a few more asserts around the place. Are you able to reproduce this? If so, could you add

diff --git a/src/sna/gen4_vertex.c b/src/sna/gen4_vertex.c
index 31044d6..33aca0d 100644
--- a/src/sna/gen4_vertex.c
+++ b/src/sna/gen4_vertex.c
@@ -38,6 +38,9 @@
 #define sse2
 #endif
 
+#undef DBG
+#define DBG(x) ErrorF x
+
 void gen4_vertex_align(struct sna *sna, const struct sna_composite_op *op)
 {
        int vertex_index;
@@ -303,6 +306,9 @@ void gen4_vertex_close(struct sna *sna)
                kgem_bo_destroy(&sna->kgem, free_bo);
 }
 
+#undef DBG
+#define DBG(x)
+
 /* specialised vertex emission routines */
 
 #define OUT_VERTEX(x,y) vertex_emit_2s(sna, x,y) /* XXX assert(!too_large(x, y)); */

and capture the output?

Comment 48 Jiri Slaby 2014-06-23 10:01:21 UTC

(In reply to comment #47)
> The asserts genuine, but I can't see a rational reason for it to fire. :|
> 
> I've pushed
> 
> commit e1e853edee67c3ced43d5e4b1fbd52ca4c92966d
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Mon Jun 23 10:14:09 2014 +0100
> 
>     sna/gen4+: Add some more asserts around recreating vertex buffers
>     
>     References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c46
>     Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> 
> to add a few more asserts around the place. Are you able to reproduce this?

Perhaps. It crashed again, when I was using google picasa. So I updated to the commit above but now I get a crash immediately when starting: 

#3  0x00007f8fdb2576c2 in __GI___assert_fail (assertion=assertion@entry=0x7f8fd7336f16 "kgem->mode == KGEM_NONE", file=file@entry=0x7f8fd73366db "kgem.h", line=line@entry=423, function=function@entry=0x7f8fd7348540 <__PRETTY_FUNCTION__.20622> "_kgem_set_mode") at assert.c:101
#4  0x00007f8fd71fd24b in _kgem_set_mode (mode=KGEM_RENDER, kgem=0x7f8fdd10d000) at kgem.h:423
#5  0x00007f8fd72ff4b0 in _kgem_set_mode (mode=KGEM_RENDER, kgem=0x7f8fdd10d000) at kgem.h:424
#6  gen7_render_copy_boxes (sna=0x7f8fdd10d000, alu=<optimized out>, src=<optimized out>, src_bo=0x19123b0, src_dx=0, src_dy=0, dst=0x1966a70, dst_bo=0x1911710, dst_dx=0, dst_dy=0, box=0x7fff10d9ea70, n=1, flags=0) at gen7_render.c:3087
#7  0x00007f8fd7249dc9 in sna_copy_boxes (src=0x19644b0, dst=0x1966a70, gc=0x1963cc0, region=0x7fff10d9ea70, dx=0, dy=0, bitplane=0, closure=0x0) at sna_accel.c:6267
#8  0x00007f8fd721b7d2 in sna_do_copy (src=src@entry=0x19644b0, dst=dst@entry=0x1966a70, gc=gc@entry=0x1963cc0, sx=sx@entry=0, sy=sy@entry=0, width=width@entry=78, height=height@entry=124, dx=dx@entry=0, dy=dy@entry=0, copy=0x7f8fd72491b0 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:6799
#9  0x00007f8fd721baeb in sna_copy_area (src=0x19644b0, dst=0x1966a70, gc=0x1963cc0, src_x=0, src_y=0, width=78, height=124, dst_x=0, dst_y=0) at sna_accel.c:6881
#10 0x0000000000439191 in ProcCopyArea (client=0x1912030) at dispatch.c:1626
#11 0x000000000043cc3e in Dispatch () at dispatch.c:432
#12 0x000000000042c1ba in main (argc=11, argv=0x7fff10d9ed48, envp=<optimized out>) at main.c:298

> If so, could you add

Should I now, when it crashes so early?

Comment 49 Chris Wilson 2014-06-23 10:03:59 UTC

Ugh. No, that's a new one... Can you give me a --enable-debug=full? (And sorry.)

Comment 50 Jiri Slaby 2014-06-23 10:28:14 UTC

Created attachment 101568 [details]
xorg.log full debug

(In reply to comment #49)
> Ugh. No, that's a new one... Can you give me a --enable-debug=full?

Yep, here you go.

Comment 51 Chris Wilson 2014-06-23 10:32:43 UTC

Found that last one:

commit 6848fb235b1bac84e91d1efde4094540180c4d48
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Jun 23 11:27:20 2014 +0100

    sna: Fix flushing empty batches
    
    A logic inversion in
    
    commit 1909910fdf89216d18703e50728f4604f75d5d66
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Sun Jun 22 20:19:22 2014 +0100
    
        sna: Inject a batch flush before adding a fresh bo
    
    also applied the injection to when the batch was empty.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c48
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 52 Jiri Slaby 2014-06-23 10:37:34 UTC

Created attachment 101570 [details]
pure black

(In reply to comment #51)
> Found that last one:
> 
> commit 6848fb235b1bac84e91d1efde4094540180c4d48
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Mon Jun 23 11:27:20 2014 +0100

Puf, this is what I see now.

Comment 53 Jiri Slaby 2014-06-23 10:39:13 UTC

Comment on attachment 101570 [details]
pure black

x

Comment 54 Chris Wilson 2014-06-23 10:49:16 UTC

/me hangs head in shame

commit 827b89fa2d5fca0ffd709c17bcdbfdaf95da918f
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Jun 23 11:44:22 2014 +0100

    sna/gen6+: Initialise src offset before use
    
    Fixes regression from
    
    commit 30348efd57135edee41fccb87133c572b6473aa8
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Mon Jun 23 11:14:25 2014 +0100
    
        sna/gen6+: Avoid adjusting copy coordinates until commited to using them
    
    which assumed that the render state was being zeroed.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 55 Jiri Slaby 2014-06-23 13:37:57 UTC

(In reply to comment #54)
> commit 827b89fa2d5fca0ffd709c17bcdbfdaf95da918f
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Mon Jun 23 11:44:22 2014 +0100

Seems to be fine now 8-).

Comment 56 Jiri Slaby 2014-06-23 18:52:11 UTC

(In reply to comment #55)
> (In reply to comment #54)
> > commit 827b89fa2d5fca0ffd709c17bcdbfdaf95da918f
> > Author: Chris Wilson <chris@chris-wilson.co.uk>
> > Date:   Mon Jun 23 11:44:22 2014 +0100
> 
> Seems to be fine now 8-).

Too optimistic:

#3  0x00007fd3721c86c2 in __GI___assert_fail (assertion=assertion@entry=0x7fd36e2aafc0 "pixmap_contains_damage(dst_pixmap, priv__->gpu_damage)", file=file@entry=0x7fd36e2a9820 "sna_accel.c", line=line@entry=6150, function=function@entry=0x7fd36e2ad590 <__PRETTY_FUNCTION__.27175> "sna_copy_boxes") at assert.c:101
#4  0x00007fd36e1bc51f in sna_copy_boxes (src=0x25bc500, dst=0x2746190, gc=0x1c8adf0, region=0x7fff90cdf720, dx=-187, dy=8, bitplane=0, closure=0x0) at sna_accel.c:6150
#5  0x00007fd36e18e5b2 in sna_do_copy (src=src@entry=0x25bc500, dst=dst@entry=0x2746190, gc=gc@entry=0x1c8adf0, sx=sx@entry=0, sy=sy@entry=8, width=width@entry=1, height=height@entry=4, dx=dx@entry=187, dy=dy@entry=0, copy=0x7fd36e1bc0d0 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:6840
#6  0x00007fd36e18e8cb in sna_copy_area (src=0x25bc500, dst=0x2746190, gc=0x1c8adf0, src_x=0, src_y=8, width=1, height=4, dst_x=187, dst_y=0) at sna_accel.c:6922
#7  0x0000000000439191 in ProcCopyArea (client=0x1687c40) at dispatch.c:1626
#8  0x000000000043cc3e in Dispatch () at dispatch.c:432
#9  0x000000000042c1ba in main (argc=11, argv=0x7fff90cdf9f8, envp=<optimized out>) at main.c:298

Comment 57 Chris Wilson 2014-06-23 20:12:00 UTC

(In reply to comment #56) 
> Too optimistic:

That means an earlier operation added damage out-of-bounds. It will need a trace from --enable-debug=full to piece together the invalid operation. :(

Comment 58 Jiri Slaby 2014-06-24 08:02:31 UTC

(In reply to comment #57)
> (In reply to comment #56) 
> > Too optimistic:
> 
> That means an earlier operation added damage out-of-bounds. It will need a
> trace from --enable-debug=full to piece together the invalid operation. :(

With full debug I got:
  http://www.fi.muni.cz/~xslaby/sklad/Xorg.0.log.old.xz
and

#4  0x0000000000591638 in FatalError (f=0x7f3c67587960 "%s: damage box is beyond the pixmap: box=(%d, %d), (%d, %d), pixmap=(%d, %d)\n") at log.c:908
#5  0x00007f3c67475f9d in _assert_pixmap_contains_box (pixmap=0x2769220, box=0x7fffbb03ec70, function=0x7f3c67588568 <__FUNCTION__.23671> "apply_damage") at sna_glyphs.c:100
#6  0x00007f3c67476dfd in apply_damage (op=0x7fffbb03ed20, r=0x7fffbb03ed00) at sna_glyphs.c:504
#7  0x00007f3c67478593 in glyphs0_to_dst (sna=0x7f3c6d381000, op=3 '\003', src=0x277fa70, dst=0x27383b0, src_x=0, src_y=0, nlist=0, list=0x7fffbb03f130, glyphs=0x7fffbb03f538) at sna_glyphs.c:903
#8  0x00007f3c6747be5f in sna_glyphs (op=3 '\003', src=0x277fa70, dst=0x27383b0, mask=0x180afe8, src_x=346, src_y=608, nlist=1, list=0x7fffbb03f130, glyphs=0x7fffbb03f530) at sna_glyphs.c:1991
#9  0x0000000000512116 in damageGlyphs (op=<optimized out>, pSrc=0x277fa70, pDst=0x27383b0, maskFormat=0x180afe8, xSrc=<optimized out>, ySrc=<optimized out>, nlist=1, list=0x7fffbb03f130, glyphs=0x7fffbb03f530) at damage.c:629
#10 0x000000000050bcbe in ProcRenderCompositeGlyphs (client=0x1e4d690) at render.c:1390
#11 0x000000000043cc3e in Dispatch () at dispatch.c:432
#12 0x000000000042c1ba in main (argc=11, argv=0x7fffbb03ff28, envp=<optimized out>) at main.c:298

Comment 59 Chris Wilson 2014-06-24 09:57:16 UTC

commit 92119ef0939897dd1850b417d04a2ba558aee8ca
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Jun 24 10:23:03 2014 +0100

    sna/glyphs: Clip damage to dst
    
    We only check if the hardware will automatically discard writes outside
    of the target pixmap, but we must manually clip the damage before adding
    it to our tracker.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Reported-by: Zdenek Kabelac <zkabelac@redhat.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c58
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Should handle that rogue damage.

Comment 60 Chris Wilson 2014-06-25 07:00:43 UTC

Time to poke the bear.

Comment 61 Jiri Slaby 2014-06-25 08:08:58 UTC

(In reply to comment #60)
> Time to poke the bear.

Bear's still hibernated :).

Comment 62 Jiri Slaby 2014-07-15 15:02:03 UTC

With 2.99.912-228-g251bcc32eed3 I got:

#3  0x00007f6edde8b552 in __GI___assert_fail (assertion=assertion@entry=0x7f6edac855d0 "dst->type == 1", file=file@entry=0x7f6edac89540 "gen7_render.c", line=line@entry=3334, function=function@entry=0x7f6edac899f0 <__PRETTY_FUNCTION__.27357> "gen7_render_fill_boxes") at assert.c:101
#4  0x00007f6edac3c02d in gen7_render_fill_boxes (sna=0x7f6edfb2e000, op=1 '\001', format=537036936, color=0x31fbab0, dst=0x7fffd6ad8680, dst_bo=0x31829d0, box=0x7fffd6ad8670, n=1) at gen7_render.c:3334
#5  0x00007f6edabe863f in sna_tiling_fill_boxes (sna=sna@entry=0x7f6edfb2e000, op=op@entry=1 '\001', format=format@entry=537036936, color=color@entry=0x31fbab0, dst=dst@entry=0x3159960, dst_bo=dst_bo@entry=0x3159570, box=box@entry=0x7fffd6ad89b0, n=n@entry=1) at sna_tiling.c:682
#6  0x00007f6edac3bebb in gen7_render_fill_boxes (sna=0x7f6edfb2e000, op=1 '\001', format=537036936, color=0x31fbab0, dst=0x3159960, dst_bo=0x3159570, box=0x7fffd6ad89b0, n=1) at gen7_render.c:3353
#7  0x00007f6edab9dbb3 in sna_composite_rectangles (op=<optimized out>, dst=<optimized out>, color=<optimized out>, num_rects=<optimized out>, rects=<optimized out>) at sna_composite.c:1028
#8  0x000000000050bf11 in ProcRenderFillRectangles (client=0x2187020) at render.c:1427
#9  0x000000000043b70e in Dispatch () at dispatch.c:432
#10 0x000000000043f4ea in dix_main (argc=11, argv=0x7fffd6ad8df8, envp=<optimized out>) at main.c:296
#11 0x00007f6edde7eb05 in __libc_start_main (main=0x42abb0 <main>, argc=11, argv=0x7fffd6ad8df8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffd6ad8de8) at libc-start.c:285
#12 0x000000000042abde in _start () at ../sysdeps/x86_64/start.S:122

Comment 63 Chris Wilson 2014-07-16 06:22:44 UTC

You managed to hit tiling on gen7! That only happens for Windows/Pixmap > 16384! And you won a prize!

commit 34ada63118680bf8ad2ef737fd4a8edfd8246e37
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Jul 16 07:19:03 2014 +0100

    sna/gen2+: Remove assertion on draw->type for fills
    
    I overlooked the tiling-fill path passing down a temporary DrawableRec
    into the fill_boxes callback - invalidating the assertion.
    
    Fixes regression from
    commit 43176b9bfafe389c4b9ed676f4e50e3b06f858c4
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Mon Jun 30 21:01:11 2014 +0100
    
        sna/dri2: Pass around the correct DrawableRec for sampling from the foriegn bo
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c62
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 64 Jiri Slaby 2014-07-16 09:04:46 UTC

Now, with 2.99.912-232-gdd9df24eb523, I see every time on start:
#2  0x00007fd05d9314a6 in __assert_fail_base (fmt=0x7fd05da673e0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7fd05a71ff96 "pixmap->refcnt", file=file@entry=0x7fd05a71f6a0 "sna_accel.c", line=line@entry=1447, function=function@entry=0x7fd05a724520 <__PRETTY_FUNCTION__.26856> "sna_destroy_pixmap") at assert.c:92
#3  0x00007fd05d931552 in __GI___assert_fail (assertion=assertion@entry=0x7fd05a71ff96 "pixmap->refcnt", file=file@entry=0x7fd05a71f6a0 "sna_accel.c", line=line@entry=1447, function=function@entry=0x7fd05a724520 <__PRETTY_FUNCTION__.26856> "sna_destroy_pixmap") at assert.c:101
#4  0x00007fd05a60f5e3 in sna_destroy_pixmap (pixmap=<optimized out>) at sna_accel.c:1447
#5  0x0000000000514cd1 in damageDestroyPixmap (pPixmap=0x2aca630) at damage.c:1473
#6  0x00000000004d7869 in XvDestroyPixmap (pPix=0x2aca630) at xvmain.c:372
#7  0x00000000004d640d in ShmDestroyPixmap (pPixmap=0x2aca630) at shm.c:263
#8  0x0000000000504f48 in FreePicture (value=0x2ace790, pid=<optimized out>) at picture.c:1474
#9  0x000000000045da62 in doFreeResource (res=0x2b065d0, skip=0) at resource.c:873
#10 0x000000000045e4f1 in FreeResource (id=12582915, skipDeleteFuncType=skipDeleteFuncType@entry=0) at resource.c:903
#11 0x000000000050af24 in ProcRenderFreePicture (client=<optimized out>) at render.c:662
#12 0x000000000043b70e in Dispatch () at dispatch.c:432
#13 0x000000000043f4ea in dix_main (argc=11, argv=0x7fff766046f8, envp=<optimized out>) at main.c:296
#14 0x00007fd05d924b05 in __libc_start_main (main=0x42abb0 <main>, argc=11, argv=0x7fff766046f8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff766046e8) at libc-start.c:285
#15 0x000000000042abde in _start () at ../sysdeps/x86_64/start.S:122

Comment 65 Chris Wilson 2014-07-16 11:54:37 UTC

Le sigh.

commit f33d44f41ef0f287375b7a6b1c117abff5a23b19
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Jul 16 12:53:02 2014 +0100

    sna: And remove new bogus assertion
    
    We assert that damage is valid as we delete the Pixmap, and so we cannot
    assert that the Pixmap is still valid itself.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 66 Jiri Slaby 2014-10-03 13:27:58 UTC

I am not sure this makes any sense, but X crashed today with 2.99.916-77-gde7185bbf48c with:

#4  0x0000000000598a08 in FatalError (f=f@entry=0x7f51913685e7 "%s:%d assertion '%s' failed\n") at log.c:924
#5  0x00007f51912429b8 in sna_accel_scanout (sna=<optimized out>, sna=<optimized out>, sna=<optimized out>) at sna_accel.c:17104
#6  0x00007f519127a137 in start_flush (sna=0x7f5196472000) at sna_accel.c:17165
#7  sna_scanout_do_flush (sna=0x7f5196472000) at sna_accel.c:17229
#8  sna_accel_block_handler (sna=0x7f5196472000, tv=<optimized out>) at sna_accel.c:17917
#9  0x000000000043fe84 in BlockHandler (pTimeout=pTimeout@entry=0x7ffff8fc7888, pReadmask=pReadmask@entry=0x828340 <LastSelectMask>) at dixutils.c:387
#10 0x0000000000589654 in WaitForSomething (pClientsReady=pClientsReady@entry=0x2559960) at WaitFor.c:215
#11 0x000000000043b4d1 in Dispatch () at dispatch.c:361
#12 0x000000000043f55a in dix_main (argc=11, argv=0x7ffff8fc7c88, envp=<optimized out>) at main.c:296
#13 0x00007f51947c3b05 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7ffff8fc7c88, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffff8fc7c78) at libc-start.c:285
#14 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 67 Jiri Slaby 2014-10-03 13:30:58 UTC

What I did was to plug a monitor into a power socket. The monitor was connected to a HDMI slot in my notebook. But the monitor was turned off manually before, so when plugged-in to the power socket, it stayed off. Then X crashed, I think.

Comment 68 Chris Wilson 2014-10-03 13:32:03 UTC

What's at sna_accel.c:17104?

Comment 69 Jiri Slaby 2014-10-03 13:33:49 UTC

(In reply to Chris Wilson from comment #68)
> What's at sna_accel.c:17104?

$ git grep -h '.*' 2.99.916-77-gde7185bbf48c -- src/sna/sna_accel.c|sed -n '17104 p'
        assert(sna->vblank_interval);

Comment 70 Chris Wilson 2014-10-03 16:22:40 UTC

(In reply to Jiri Slaby from comment #67)
> What I did was to plug a monitor into a power socket. The monitor was
> connected to a HDMI slot in my notebook. But the monitor was turned off
> manually before, so when plugged-in to the power socket, it stayed off. Then
> X crashed, I think.

See if you can reproduce it. I think

commit 7d60a9be3da1163866573d2ffda9635a914ac795
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Oct 3 17:20:31 2014 +0100

    sna: Update vblank interval after enabling outputs
    
    In a couple of cases we can re-enable CRTC. After doing so we should
    recompute the minimum vblank interval.
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

should be a step in the right direction, but I may have missed something totally fubar.

Comment 71 Jiri Slaby 2014-10-09 21:53:00 UTC

I have updated now. Let's see what will happen with that one.

But being at 2.99.916-90-gc139e2fb95f2 now, when crawling google street maps, I see:
#4  0x0000000000598b28 in FatalError (f=f@entry=0x7f882c14b5e7 "%s:%d assertion '%s' failed\n") at log.c:924
#5  0x00007f882c0b4843 in polygon_add_edge (t=<optimized out>, t=<optimized out>, dy=<optimized out>, dx=<optimized out>, dir=1, edge=<optimized out>, polygon=0x7fff7d087490) at sna_trapezoids_precise.c:578
#6  tor_add_trapezoid (tor=tor@entry=0x7fff7d0874b0, t=<optimized out>, dx=<optimized out>, dy=<optimized out>) at sna_trapezoids_precise.c:1018
#7  0x00007f882c0b4a07 in inplace_thread (arg=arg@entry=0x7fff7d089210) at sna_trapezoids_precise.c:2880
#8  0x00007f882c0b837a in precise_trapezoid_span_inplace (sna=sna@entry=0x7f8831255000, op=op@entry=12 '\f', src=src@entry=0x4521c80, dst=dst@entry=0x376dbb0, maskFormat=maskFormat@entry=0x1eeceb8, flags=flags@entry=0, src_x=src_x@entry=0, src_y=src_y@entry=0, ntrap=ntrap@entry=2, traps=traps@entry=0x4801cf8, fallback=fallback@entry=true) at sna_trapezoids_precise.c:3112
#9  0x00007f882c0988e7 in trapezoid_span_inplace (fallback=true, traps=0x4801cf8, ntrap=2, src_y=<optimized out>, src_x=<optimized out>, flags=0, maskFormat=0x1eeceb8, dst=0x376dbb0, src=0x4521c80, op=<optimized out>, sna=0x7f8831255000) at sna_trapezoids.h:159
#10 sna_composite_trapezoids (op=<optimized out>, src=0x4521c80, dst=0x376dbb0, maskFormat=0x1eeceb8, xSrc=<optimized out>, ySrc=<optimized out>, ntrap=2, traps=0x4801cf8) at sna_trapezoids.c:705
#11 0x000000000050d183 in ProcRenderTrapezoids (client=0x28a8900) at render.c:759
#12 0x000000000043b77e in Dispatch () at dispatch.c:432
#13 0x000000000043f55a in dix_main (argc=11, argv=0x7fff7d08b338, envp=<optimized out>) at main.c:296
#14 0x00007f882f5a6b05 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7fff7d08b338, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff7d08b328) at libc-start.c:285
#15 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 72 Chris Wilson 2014-10-10 06:36:19 UTC

The only think that strikes me is overflow, could you please test:

diff --git a/src/sna/sna_trapezoids_precise.c b/src/sna/sna_trapezoids_precise.c
index c595bfd..f8512e3 100644
--- a/src/sna/sna_trapezoids_precise.c
+++ b/src/sna/sna_trapezoids_precise.c
@@ -555,6 +555,7 @@ polygon_add_edge(struct polygon *polygon,
 
                Ex = (int64_t)(edge->p2.x - edge->p1.x) * SAMPLES_X;
                Ey = (int64_t)(edge->p2.y - edge->p1.y) * SAMPLES_Y * (2 << 16);
+               assert(Ey > 0);
                e->dxdy.quo = Ex * (2 << 16) / Ey;
                e->dxdy.rem = Ex * (2 << 16) % Ey;
 
@@ -566,7 +567,12 @@ polygon_add_edge(struct polygon *polygon,
 
                tmp = (int64_t)edge->p1.x * SAMPLES_X;
                e->x.quo += (tmp >> 16) + dx;
-               e->x.rem += ((tmp & ((1 << 16) - 1)) * Ey) / (1 << 16);
+               tmp &= (1 << 16) - 1;
+               if (Ey < INT64_MAX / (1 << 16))
+                       tmp = (tmp * Ey) / (1 << 16);
+               else /* Handle overflow by sacrificing precision. */
+                       tmp *= Ey / (1 << 16);
+               e->x.rem +=  tmp;
 
                if (e->x.rem < 0) {
                        e->x.quo--;

Comment 73 Jiri Slaby 2014-10-22 19:39:01 UTC

That does not seem to help (or I am seeing something different). This is with 2.99.916-113-ge46f26b9e267:

#3  0x0000000000598af2 in FatalError (f=f@entry=0x7f558b755147 "%s:%d assertion '%s' failed\n") at log.c:927
#4  0x00007f558b610f06 in polygon_add_edge (t=<optimized out>, t=<optimized out>, dy=<optimized out>, dx=<optimized out>, dir=1, edge=0xfffffff9874eb8e0, polygon=0x7fff260bf050) at sna_trapezoids_precise.c:558
#5  0x00007f558b6bc1f1 in polygon_add_edge (t=0xfffffff9874eb8d8, t=0xfffffff9874eb8d8, dy=<optimized out>, dx=<optimized out>, dir=1, edge=0xfffffff9874eb8e0, polygon=0x7fff260bf050) at sna_trapezoids_precise.c:518
#6  tor_add_trapezoid (tor=tor@entry=0x7fff260bf070, t=t@entry=0x1f581c0, dx=<optimized out>, dy=<optimized out>) at sna_trapezoids_precise.c:1026
#7  0x00007f558b6bc2af in span_thread (arg=arg@entry=0x7fff260c2df0) at sna_trapezoids_precise.c:1746
#8  0x00007f558b6beb44 in precise_trapezoid_span_converter (sna=sna@entry=0x7f559089e000, op=<optimized out>, op@entry=12 '\f', src=src@entry=0x1e81450, dst=dst@entry=0x1f27a50, maskFormat=maskFormat@entry=0xdc6f88, flags=flags@entry=0, src_x=src_x@entry=0, src_y=src_y@entry=0, ntrap=ntrap@entry=2, traps=traps@entry=0x1f58198) at sna_trapezoids_precise.c:1930
#9  0x00007f558b6a098f in trapezoid_span_converter (traps=0x1f58198, ntrap=2, src_y=<optimized out>, src_x=<optimized out>, flags=0, maskFormat=0xdc6f88, dst=0x1f27a50, src=0x1e81450, op=<optimized out>, sna=0x7f559089e000) at sna_trapezoids.h:171
#10 sna_composite_trapezoids (op=<optimized out>, src=0x1e81450, dst=0x1f27a50, maskFormat=0xdc6f88, xSrc=<optimized out>, ySrc=<optimized out>, ntrap=2, traps=0x1f58198) at sna_trapezoids.c:691
#11 0x000000000050d183 in ProcRenderTrapezoids (client=0x1778960) at render.c:759
#12 0x000000000043b77e in Dispatch () at dispatch.c:432
#13 0x000000000043f55a in dix_main (argc=11, argv=0x7fff260c5078, envp=<optimized out>) at main.c:296
#14 0x00007f558ebb0b05 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7fff260c5078, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff260c5068) at libc-start.c:285
#15 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 74 Chris Wilson 2014-10-22 19:59:08 UTC

(In reply to Jiri Slaby from comment #73)
> That does not seem to help (or I am seeing something different). This is
> with 2.99.916-113-ge46f26b9e267:

line 519: assert(edge->p2.y > edge->p1.y);
line 558: assert((s64)(edge->p2.y - edge->p1.y) * 17 * (2 << 16) > 0);

That has to be less than 63 bits and positive, since the edge height is 32 bits and the multiplier is 22 bits (i.e. a max of 54 bits).


Could you apply

diff --git a/src/sna/sna_trapezoids_precise.c b/src/sna/sna_trapezoids_precise.c
index 9925654..d5a32db 100644
--- a/src/sna/sna_trapezoids_precise.c
+++ b/src/sna/sna_trapezoids_precise.c
@@ -555,6 +555,9 @@ polygon_add_edge(struct polygon *polygon,
 
                Ex = (int64_t)(edge->p2.x - edge->p1.x) * SAMPLES_X;
                Ey = (int64_t)(edge->p2.y - edge->p1.y) * SAMPLES_Y * (2 << 16);
+               if (Ey <= 0)
+                       ErrorF("bang! Ey=%lld, p1=(%d, %d), p2=(%d, %d)\n",
+                              (long long)Ey, edge->p1.x, edge->p1.y, edge->p2.x, edge->p2.y);
                assert(Ey > 0);
                e->dxdy.quo = Ex * (2 << 16) / Ey;
                e->dxdy.rem = Ex * (2 << 16) % Ey;

and see what that trawls up?

Comment 75 Chris Wilson 2014-10-22 20:00:49 UTC

(In reply to Chris Wilson from comment #74)
> That has to be less than 63 bits and positive, since the edge height is 32
> bits and the multiplier is 22 bits (i.e. a max of 54 bits).

Pedant says the edge height is 33 bits... But we still have bits spare.

Comment 76 Jiri Slaby 2014-10-24 08:16:12 UTC

Bang, bang, my baby shot me down: 

[    67.256] bang! Ey=-3290571913297920, p1=(906408448, -1961036544), p2=(-266457600, 660259328)
[    67.256] bang! Ey=-3290571913297920, p1=(906408448, -1961036544), p2=(-266457600, 660259328)
[    67.256] (EE)[    67.256] (EE)  
Fatal server error:
[    67.256] 
Fatal server error:
[    67.256] (EE)[    67.256] (EE)  polygon_add_edge:563 assertion 'Ey > 0' failed
[    67.256] polygon_add_edge:563 assertion 'Ey > 0' failed

Comment 77 Chris Wilson 2014-10-24 08:40:27 UTC

(In reply to Chris Wilson from comment #75)
> (In reply to Chris Wilson from comment #74)
> > That has to be less than 63 bits and positive, since the edge height is 32
> > bits and the multiplier is 22 bits (i.e. a max of 54 bits).
> 
> Pedant says the edge height is 33 bits... But we still have bits spare.

I really should read what I write at times.

Comment 78 Chris Wilson 2014-10-24 08:57:20 UTC

commit d08a5f555a0c47ae23c0f9a890b512cb23e74feb
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Oct 24 09:53:29 2014 +0100

    sna/trapezoids: Prevent overflow of edge gradient in mono rasteriser
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c76
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

commit f611f9580469661e585f419a7dd033ddffd7e20d
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Oct 24 09:41:47 2014 +0100

    sna/trapezoids: Difference between two 32-bit quantities is 33-bits in size
    
    When computing the edge distance, we subtract on 32-bit quantity from
    another. This requires 33-bits to store the full result so promote the
    subtraction to 64-bits (rather than the result of that subtraction as
    done currently).
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c76
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

That should fix the assertion...

Comment 79 Jiri Slaby 2015-01-22 16:28:01 UTC

Update to 2.99.917-44-gd16ac1f30bb1 and boom, every switch to console or dpms off causes this:
#8  0x0000000000598b38 in FatalError (f=f@entry=0x7f10b580709f "%s:%d assertion '%s' failed\n") at log.c:924
#9  0x00007f10b5735659 in sna_mode_reset (sna=sna@entry=0x7f10ba946000) at sna_display.c:6642
#10 0x00007f10b5738690 in sna_leave_vt (arg=0x20fd0f0) at sna_driver.c:985
#11 0x00007f10b7afd0bd in glxDRILeaveVT (scrn=0x20fd0f0) at glxdri2.c:837
#12 0x00000000004793b7 in xf86VTLeave () at xf86Events.c:504
#13 0x000000000044005d in WakeupHandler (result=result@entry=1, pReadmask=pReadmask@entry=0x828340 <LastSelectMask>) at dixutils.c:423
#14 0x00000000005897ff in WaitForSomething (pClientsReady=pClientsReady@entry=0x2ae3520) at WaitFor.c:229
#15 0x000000000043b4e1 in Dispatch () at dispatch.c:361
#16 0x000000000043f56a in dix_main (argc=11, argv=0x7fff8a018c28, envp=<optimized out>) at main.c:296
#17 0x00007f10b8c63b45 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7fff8a018c28, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff8a018c18) at libc-start.c:289
#18 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 80 Chris Wilson 2015-01-22 16:51:06 UTC

Can you please check that

commit 653b8a4d83210187f6ef90f017598d8ebb45de27
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Jan 22 16:36:27 2015 +0000

    sna: Declare outputs as hidden at start
    
    Required for our internal bookkeeping of DPMS events.
    
    Reported-by: Jiri Slaby <jirislaby:gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c79
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

fixes the assertion(s)?

Comment 81 Jiri Slaby 2015-01-22 17:34:59 UTC

(In reply to Chris Wilson from comment #80)
> Can you please check that
> 
> commit 653b8a4d83210187f6ef90f017598d8ebb45de27
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Thu Jan 22 16:36:27 2015 +0000
> 
>     sna: Declare outputs as hidden at start
>     
>     Required for our internal bookkeeping of DPMS events.
>     
>     Reported-by: Jiri Slaby <jirislaby:gmail.com>
>     References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c79
>     Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> 
> fixes the assertion(s)?

It does not:
#4  0x00007f1c62849659 in sna_mode_reset (sna=0x7f1c67a5a000) at sna_display.c:6643
#5  0x00007f1c6284c690 in describe_kms (scrn=0x7f1c67a5a000) at sna_driver.c:1426
#6  0x00007f1c62849659 in sna_mode_reset (sna=0x3) at sna_display.c:6643
#7  0x00007f1c62849688 in sna_mode_close (sna=0x3cc) at sna_display.c:6093
#8  0x0000000000db1630 in ?? ()
#9  0x00007f1c6284c74e in sna_uevent_fini (sna=<optimized out>, sna=<optimized out>) at sna_driver.c:961
#10 sna_early_close_screen (screen=0x7f1c67a5a000) at sna_driver.c:1011
#11 0x00000000004ada87 in xf86CrtcCloseScreen (screen=0xdb1630) at xf86Crtc.c:734
#12 0x0000000000510aa3 in present_close_screen (screen=0xdb1630) at present_screen.c:63
#13 0x00000000004cb1b8 in CursorCloseScreen (pScreen=0xdb1630) at cursor.c:187
#14 0x000000000050f254 in AnimCurCloseScreen (pScreen=<optimized out>) at animcur.c:106
#15 0x000000000043f677 in dix_main (argc=11, argv=0x7fff4cab28b8, envp=<optimized out>) at main.c:349
#16 0x00007f1c65d77b45 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7fff4cab28b8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff4cab28a8) at libc-start.c:289
#17 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 82 Jiri Slaby 2015-01-22 18:47:58 UTC

(In reply to Jiri Slaby from comment #81)
> It does not:

Actually, the crash is from the previous stop, I suppose. So it is gone, I suppose.

Comment 83 Jiri Slaby 2015-01-22 20:13:01 UTC

But I hit another one:

#5  0x00007ff0b4984446 in __kgem_bo_is_busy (bo=<optimized out>, kgem=0x7ff0b9c14000) at kgem.h:642
#6  0x00007ff0b49ac344 in __kgem_bo_is_busy (bo=<optimized out>, kgem=0x7ff0b9c14000) at sna_accel.c:1539
#7  gpu_bo_download (sna=sna@entry=0x7ff0b9c14000, priv=priv@entry=0x2b0abe0, n=n@entry=1, box=box@entry=0x7fff61889e20, idle=idle@entry=true) at sna_accel.c:1712
#8  0x00007ff0b49b1bd5 in download_boxes (sna=0x7ff0b9c14000, priv=0x2b0abe0, n=1, box=0x7fff61889e20) at sna_accel.c:1809
#9  0x00007ff0b49c309a in sna_drawable_move_region_to_cpu (drawable=drawable@entry=0x2c58130, region=region@entry=0x7fff61889ec0, flags=3) at sna_accel.c:3046
#10 0x00007ff0b49df70a in sna_put_image (drawable=0x2c58130, gc=0x2bf50a0, depth=24, x=775, y=483, w=7, h=9, left=0, format=2, bits=0x2c790f4 "") at sna_accel.c:5615
#11 0x0000000000519639 in damagePutImage (pDrawable=0x2c58130, pGC=0x2bf50a0, depth=24, x=775, y=483, w=<optimized out>, h=9, leftPad=0, format=2, pImage=0x2c790f4 "") at damage.c:735
#12 0x00000000004386d9 in ProcPutImage (client=0x2667be0) at dispatch.c:1967
#13 0x000000000043b78e in Dispatch () at dispatch.c:432
#14 0x000000000043f56a in dix_main (argc=11, argv=0x7fff6188a178, envp=<optimized out>) at main.c:296
#15 0x00007ff0b7f31b45 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7fff6188a178, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff6188a168) at libc-start.c:289
#16 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 84 Chris Wilson 2015-01-22 20:29:06 UTC

(In reply to Jiri Slaby from comment #82)
> (In reply to Jiri Slaby from comment #81)
> > It does not:
> 
> Actually, the crash is from the previous stop, I suppose. So it is gone, I
> suppose.

Do you mind confirming whether I need to investigate this assertion?

Comment 85 Jiri Slaby 2015-01-22 20:30:09 UTC

(In reply to Chris Wilson from comment #84)
> (In reply to Jiri Slaby from comment #82)
> > (In reply to Jiri Slaby from comment #81)
> > > It does not:
> > 
> > Actually, the crash is from the previous stop, I suppose. So it is gone, I
> > suppose.
> 
> Do you mind confirming whether I need to investigate this assertion?

Yes, I think it is gone. I haven't seen it since then and I would have if it was still present.

Comment 86 Chris Wilson 2015-01-22 21:04:59 UTC

(In reply to Jiri Slaby from comment #83)
> But I hit another one:
> 
> #5  0x00007ff0b4984446 in __kgem_bo_is_busy (bo=<optimized out>,
> kgem=0x7ff0b9c14000) at kgem.h:642

Scratching my head on this one. The assertion looks correct, it is checking that having found a bo now idle that after retiring all the requests upto and including that holding the bo, we have marked the bo itself as idle

But the code looks correct.

commit 3cb0672586a55effa89a59c9a97744e225a05dac
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Jan 22 21:02:42 2015 +0000

    sna: Reorganise assertions when retiring idle bo
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c83
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Let's apply that and see if that cleans up the assertion stacktrace a bit.

Comment 87 Chris Wilson 2015-01-22 21:15:30 UTC

(In reply to Jiri Slaby from comment #83)
> But I hit another one:
> 
> #5  0x00007ff0b4984446 in __kgem_bo_is_busy (bo=<optimized out>,
> kgem=0x7ff0b9c14000) at kgem.h:642

Also worth checking which kernel this is. One of the i915.ko backported patches slightly conflicted:

commit d472fcc8379c062bd56a3876fc6ef22258f14a91
Author: Daniel Vetter <daniel.vetter@ffwll.ch>
Date:   Mon Nov 24 11:12:42 2014 +0100

    drm/i915: Disallow pin ioctl completely for kms drivers


It ends up breaking i915_gem_busy_ioctl() instead.

Comment 88 Jiri Slaby 2015-01-22 21:23:16 UTC

(In reply to Chris Wilson from comment #87)
> commit d472fcc8379c062bd56a3876fc6ef22258f14a91
> Author: Daniel Vetter <daniel.vetter@ffwll.ch>
> Date:   Mon Nov 24 11:12:42 2014 +0100
> 
>     drm/i915: Disallow pin ioctl completely for kms drivers
> 
> 
> It ends up breaking i915_gem_busy_ioctl() instead.

It's suse's 3.18.3, I don't see it neither in upstream, nor in suse's repository.

Comment 89 Yi Sun 2015-01-23 00:51:57 UTC

(In reply to Jiri Slaby from comment #88)
> (In reply to Chris Wilson from comment #87)
> > commit d472fcc8379c062bd56a3876fc6ef22258f14a91
> > Author: Daniel Vetter <daniel.vetter@ffwll.ch>
> > Date:   Mon Nov 24 11:12:42 2014 +0100
> > 
> >     drm/i915: Disallow pin ioctl completely for kms drivers
> > 
> > 
> > It ends up breaking i915_gem_busy_ioctl() instead.
> 
> It's suse's 3.18.3, I don't see it neither in upstream, nor in suse's
> repository.

git clone git://anongit.freedesktop.org/drm-intel
git reset --hard d472fcc8379c062bd56a3876fc6ef22258f14a91

Comment 90 Jiri Slaby 2015-01-23 07:27:27 UTC

(In reply to Yi Sun from comment #89)
> (In reply to Jiri Slaby from comment #88)
> > (In reply to Chris Wilson from comment #87)
> > > commit d472fcc8379c062bd56a3876fc6ef22258f14a91
> > > Author: Daniel Vetter <daniel.vetter@ffwll.ch>
> > > Date:   Mon Nov 24 11:12:42 2014 +0100
> > > 
> > >     drm/i915: Disallow pin ioctl completely for kms drivers
> > > 
> > > 
> > > It ends up breaking i915_gem_busy_ioctl() instead.
> > 
> > It's suse's 3.18.3, I don't see it neither in upstream, nor in suse's
> > repository.
> 
> git clone git://anongit.freedesktop.org/drm-intel
> git reset --hard d472fcc8379c062bd56a3876fc6ef22258f14a91

I thought you wanted me to confirm that I *don't* have the patch? Should I try it (it's in the 3.18.4 queue)?

Comment 91 Chris Wilson 2015-01-23 08:06:28 UTC

(In reply to Jiri Slaby from comment #90)
> I thought you wanted me to confirm that I *don't* have the patch? Should I
> try it (it's in the 3.18.4 queue)?

Right, I just wanted to confirm that you didn't have the patch backported yet. (It's hit fedora already and caused upsets there.)

Comment 92 Chris Wilson 2015-01-31 11:00:35 UTC

(In reply to Jiri Slaby from comment #83)
> But I hit another one:
> 
> #5  0x00007ff0b4984446 in __kgem_bo_is_busy (bo=<optimized out>,
> kgem=0x7ff0b9c14000) at kgem.h:642
> #6  0x00007ff0b49ac344 in __kgem_bo_is_busy (bo=<optimized out>,
> kgem=0x7ff0b9c14000) at sna_accel.c:1539

Had some inspiration and guess that this an exported bo becoming rebusy, so


commit dac01d0839123e87ebc04fb2dc046d321805c6db
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sat Jan 31 10:55:44 2015 +0000

    sna: Mark the bo as clean after the kernel reports it idle
    
    After querying for an idle bo and retiring the associated requests, we
    must be careful not to confuse ourselves with exported bo becoming busy
    again.
    
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c83
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

should silence the assertions.

Comment 93 Jiri Slaby 2015-02-18 14:15:55 UTC

An assert was triggered  when I unplugged a VGA connector while the monitors were dpms-aslept. (With 0c2ff5532c79029a8c3c50a83d3f719cc5c5171e.)

#9  0x0000000000598af8 in FatalError (f=f@entry=0x7f73a8db216f "%s:%d assertion '%s' failed\n") at log.c:924
#10 0x00007f73a8cd7fdc in __sna_crtc_disable (sna=sna@entry=0x7f73adef2000, sna_crtc=sna_crtc@entry=0x1b65600) at sna_display.c:1536
#11 0x00007f73a8cd80cf in sna_crtc_disable (crtc=0x1b65720, force=<optimized out>) at sna_display.c:1572
#12 0x00000000004b0dc2 in xf86DisableUnusedFunctions (pScrn=0x1b636f0) at xf86Crtc.c:2992
#13 0x00000000004ba78e in xf86RandR12CrtcSet (pScreen=0x1b6ac90, randr_crtc=0x1b6d380, randr_mode=<optimized out>, x=0, y=0, rotation=<optimized out>, num_randr_outputs=0, randr_outputs=0x0) at xf86RandR12.c:1237
#14 0x00000000004f486a in RRCrtcSet (crtc=0x1b6d380, mode=0x0, x=0, y=0, rotation=rotation@entry=1, numOutputs=numOutputs@entry=0, outputs=outputs@entry=0x0) at rrcrtc.c:574
#15 0x00000000004f5b18 in ProcRRSetCrtcConfig (client=0x26cf4f0) at rrcrtc.c:1173
#16 0x000000000043b78e in Dispatch () at dispatch.c:432
#17 0x000000000043f56a in dix_main (argc=11, argv=0x7ffff3bccda8, envp=<optimized out>) at main.c:296
#18 0x00007f73ac20eb45 in __libc_start_main (main=0x42ac00 <main>, argc=11, argv=0x7ffff3bccda8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffff3bccd98) at libc-start.c:289
#19 0x000000000042ac2e in _start () at ../sysdeps/x86_64/start.S:122

Comment 94 Chris Wilson 2015-02-18 14:19:13 UTC

commit 147e190d1e18d3ac6dc23aa4e493eec28aa75d1d
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Feb 12 09:51:38 2015 +0000

    sna: When turning off outputs whilst DPMS off, update the right counters
    
    Whilst the outputs are hidden, if we want to disable a CRTC, we want to
    manipulate the hidden counter as opposed to current front_active
    counter.
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 95 Jiri Slaby 2015-02-25 17:07:01 UTC

I got a crash with 2.99.917-160-ge55bc7bb1633:
#4  0x00000000005953d8 in FatalError (f=f@entry=0x7f95badd31cf "%s:%d assertion '%s' failed\n") at log.c:925
#5  0x00007f95bad37a96 in polygon_add_edge (t=0xf, t=0xf, dy=1065155837, dx=7012366, dir=1, edge=0x17, polygon=0x6b003c006a000f) at sna_trapezoids_precise.c:518
#6  tor_add_trapezoid (tor=tor@entry=0x7fff00bcb220, t=t@entry=0x4b6d5a4, dx=dx@entry=-102, dy=dy@entry=-15) at sna_trapezoids_precise.c:1026
#7  0x00007f95bad3aaa7 in precise_trapezoid_mask_converter (op=op@entry=3 '\003', src=src@entry=0x367e830, dst=dst@entry=0x4397ca0, maskFormat=maskFormat@entry=0x22023f8, flags=flags@entry=0, src_x=src_x@entry=0, src_y=src_y@entry=0, ntrap=ntrap@entry=100, traps=traps@entry=0x4b6d5a4) at sna_trapezoids_precise.c:2129
#8  0x00007f95bad1b98d in trapezoid_mask_converter (traps=0x4b6d5a4, ntrap=100, src_y=<optimized out>, src_x=<optimized out>, flags=0, maskFormat=0x22023f8, dst=0x4397ca0, src=0x367e830, op=<optimized out>) at sna_trapezoids.h:186
#9  sna_composite_trapezoids (op=<optimized out>, src=0x367e830, dst=0x4397ca0, maskFormat=0x22023f8, xSrc=<optimized out>, ySrc=<optimized out>, ntrap=100, traps=0x4b6d5a4) at sna_trapezoids.c:700
#10 0x000000000050bee3 in ProcRenderTrapezoids (client=0x3fe3900) at render.c:759
#11 0x000000000043c78e in Dispatch () at dispatch.c:432
#12 0x000000000044056b in dix_main (argc=11, argv=0x7fff00bcd1e8, envp=<optimized out>) at main.c:298
#13 0x00007f95be230b45 in __libc_start_main (main=0x42bb80 <main>, argc=11, argv=0x7fff00bcd1e8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff00bcd1d8) at libc-start.c:289
#14 0x000000000042bbae in _start () at ../sysdeps/x86_64/start.S:122

Comment 96 Chris Wilson 2015-02-25 17:10:55 UTC

Just to check: you make that assert(t->bottom > t->top) ?

Comment 97 Jiri Slaby 2015-02-25 17:14:01 UTC

(In reply to Chris Wilson from comment #96)
> Just to check: you make that assert(t->bottom > t->top) ?

Yeah, and this one is 100% reproducible with one odp presentation opened in libreoffice. Need full-debug :)?

Comment 98 Chris Wilson 2015-02-25 17:17:38 UTC

Looks like I lost the xTrapezoidValid() checks:

diff --git a/src/sna/sna_trapezoids_imprecise.c b/src/sna/sna_trapezoids_imprecise.c
index 60c1387..df22add 100644
--- a/src/sna/sna_trapezoids_imprecise.c
+++ b/src/sna/sna_trapezoids_imprecise.c
@@ -962,6 +962,16 @@ tor_add_trapezoid(struct tor *tor,
                  const xTrapezoid *t,
                  int dx, int dy)
 {
+       if (!xTrapezoidValid(t)) {
+               __DBG(("%s: skipping invalid trapezoid: top=%d, bottom=%d, left=(%d, %d), (%d, %d), right=(%d, %d), (%d, %d)\n",
+                      __FUNCTION__,
+                      t->top, t->bottom,
+                      t->left.p1.x, t->left.p1.y,
+                      t->left.p2.x, t->left.p2.y,
+                      t->right.p1.x, t->right.p1.y,
+                      t->right.p2.x, t->right.p2.y));
+               return;
+       }
        polygon_add_edge(tor->polygon, t, &t->left, 1, dx, dy);
        polygon_add_edge(tor->polygon, t, &t->right, -1, dx, dy);
 }
diff --git a/src/sna/sna_trapezoids_precise.c b/src/sna/sna_trapezoids_precise.c
index e7ea433..f1532d3 100644
--- a/src/sna/sna_trapezoids_precise.c
+++ b/src/sna/sna_trapezoids_precise.c
@@ -1023,6 +1023,16 @@ tor_init(struct tor *converter, const BoxRec *box, int num_edges)
 static void
 tor_add_trapezoid(struct tor *tor, const xTrapezoid *t, int dx, int dy)
 {
+       if (!xTrapezoidValid(t)) {
+               __DBG(("%s: skipping invalid trapezoid: top=%d, bottom=%d, left=(%d, %d), (%d, %d), right=(%d, %d), (%d, %d)\n",
+                      __FUNCTION__,
+                      t->top, t->bottom,
+                      t->left.p1.x, t->left.p1.y,
+                      t->left.p2.x, t->left.p2.y,
+                      t->right.p1.x, t->right.p1.y,
+                      t->right.p2.x, t->right.p2.y));
+               return;
+       }
        polygon_add_edge(tor->polygon, t, &t->left, 1, dx, dy);
        polygon_add_edge(tor->polygon, t, &t->right, -1, dx, dy);
 }
~

Contemplating doing something slightly different though.

Comment 99 Chris Wilson 2015-02-25 17:53:40 UTC

I've convinced myself that will be sufficient (and that invalid trapezoids should be rare enough not to optimize for!):

commit ea09d830c8651fe854ba772a9e28e8a5f601b1c1
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Feb 25 17:20:28 2015 +0000

    sna/trapezoids: Restore lost xTrapezoidValid() checks
    
    When fixing up the sample projection of the trapezoids, we lost the
    safety check that the trapezoid was valid.
    
    Fixes regression from
    commit bca08dc4155c0ee304c60340ccf95fe7b03ac11b [2.99.917]
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Mon Sep 29 19:30:03 2014 +0100
    
        sna/trapezoids: Fix loss of precision through projection onto sample grid
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c95
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 100 Jiri Slaby 2015-02-25 17:56:51 UTC

(In reply to Chris Wilson from comment #99)
> commit ea09d830c8651fe854ba772a9e28e8a5f601b1c1
> Author: Chris Wilson <chris@chris-wilson.co.uk>
> Date:   Wed Feb 25 17:20:28 2015 +0000
> 
>     sna/trapezoids: Restore lost xTrapezoidValid() checks

Sure, fixed. Thanks.

Comment 101 Jiri Slaby 2015-02-25 20:03:07 UTC

A new one :)

#4  0x00000000005953d8 in FatalError (f=f@entry=0x7f4d74d1db6f "%s:%d assertion '%s' failed\n") at log.c:925
#5  0x00007f4d74bdcd88 in __kgem_retire_requests_upto (kgem=kgem@entry=0x7f4d79e62000, bo=bo@entry=0x30e17b0) at kgem.c:2853
#6  0x00007f4d74c23d2e in __kgem_bo_is_busy (bo=0x30e17b0, kgem=<optimized out>) at kgem.h:646
#7  use_shm_bo (replaces=<optimized out>, alu=3, priv=0x326fd00, bo=0x30e17b0, sna=<optimized out>) at sna_accel.c:5996
#8  sna_copy_boxes (src=0x30e8360, dst=0x2f92ec0, gc=0x2fb1f90, region=0x7ffffc31a280, dx=-934, dy=-1053, bitplane=0, closure=0x0) at sna_accel.c:6578
#9  0x00007f4d74bf254c in sna_do_copy (src=src@entry=0x30e8360, dst=dst@entry=0x2f92ec0, gc=gc@entry=0x2fb1f90, sx=sx@entry=0, sy=sy@entry=0, width=width@entry=407, height=height@entry=17, dx=934, dx@entry=278, dy=1053, dy@entry=1029, copy=0x7f4d74c216b0 <sna_copy_boxes>, bitPlane=bitPlane@entry=0, closure=closure@entry=0x0) at sna_accel.c:7076
#10 0x00007f4d74bf2771 in sna_copy_area (src=0x30e8360, dst=0x2f92ec0, gc=0x2fb1f90, src_x=0, src_y=0, width=407, height=17, dst_x=278, dst_y=1029) at sna_accel.c:7158
#11 0x0000000000517efc in damageCopyArea (pSrc=0x30e8360, pDst=0x2f92ec0, pGC=0x2fb1f90, srcx=0, srcy=<optimized out>, width=407, height=17, dstx=278, dsty=1029) at damage.c:764
#12 0x0000000000438c6d in ProcCopyArea (client=0x2f6dd80) at dispatch.c:1673
#13 0x000000000043c78e in Dispatch () at dispatch.c:432
#14 0x000000000044056b in dix_main (argc=11, argv=0x7ffffc31a5c8, envp=<optimized out>) at main.c:298
#15 0x00007f4d7817c8c5 in __libc_start_main (main=0x42bb80 <main>, argc=11, argv=0x7ffffc31a5c8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffffc31a5b8) at libc-start.c:289
#16 0x000000000042bbae in _start () at ../sysdeps/x86_64/start.S:122

Comment 102 Chris Wilson 2015-02-25 20:31:03 UTC

That assert there is just a little dangerous, so lets let the code its thing and check afterwards:

commit 53d804b134494be8a324781283faecb2968f6511
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Feb 25 20:25:07 2015 +0000

    sna: Avoid asserting that a foreign bo is idle
    
    Once again we fall foul of a foreign bo that between consecutive calls
    to the busy ioctl may be used by another client. Relax the assertion
    that on the status of the bo being retired and double check afterwards.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c101
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 103 Jiri Slaby 2015-05-18 14:09:50 UTC

With 2.99.917-303-g6d6406375053, I see the one below. With 2.99.917 from my distro I don't.

This is reproducible easily when running firefox and trying to log in to bugs.freedesktop.org or bugs.kde.org. Whenever I hit "enter" to log in, it crashes. Either due to "remember password for this site" fialog or page reload after http POST. 

#4  0x0000000000597288 in FatalError (f=f@entry=0x7f0280a9d56b "%s:%d assertion '%s' failed\n") at log.c:925
#5  0x00007f028098a647 in sna_get_image__fast (flags=<optimized out>, dst=0x29d1630 "", region=0x7ffd1ed4d7d0, pixmap=0x26f9b40) at sna_accel.c:17084
#6  sna_get_image (drawable=0x26f9b40, x=<optimized out>, y=<optimized out>, w=427, h=23, format=<optimized out>, mask=4294967295, dst=0x29d1630 "") at sna_accel.c:17159
#7  0x000000000057a713 in miSpriteGetImage (pDrawable=0x26f9b40, sx=0, sy=0, w=427, h=23, format=2, planemask=4294967295, pdstLine=0x29d1630 "") at misprite.c:405
#8  0x00000000004c7ec5 in compGetImage (pDrawable=0x26f9b40, sx=<optimized out>, sy=<optimized out>, w=<optimized out>, h=<optimized out>, format=<optimized out>, planemask=4294967295, pdstLine=0x29d1630 "") at compinit.c:149
#9  0x000000000043a406 in DoGetImage (planemask=<optimized out>, height=23, width=427, y=0, x=0, drawable=<optimized out>, format=<optimized out>, client=0x14f6260) at dispatch.c:2165
#10 ProcGetImage (client=0x14f6260) at dispatch.c:2228
#11 0x000000000043cf5e in Dispatch () at dispatch.c:432
#12 0x0000000000440d3b in dix_main (argc=11, argv=0x7ffd1ed4db38, envp=<optimized out>) at main.c:298
#13 0x00007f02850dc8c5 in __libc_start_main (main=0x42c340 <main>, argc=11, argv=0x7ffd1ed4db38, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd1ed4db28) at libc-start.c:289
#14 0x000000000042c379 in _start () at ../sysdeps/x86_64/start.S:118

Comment 104 Chris Wilson 2015-05-18 14:20:27 UTC

commit fe64672c83e75ccb3f7a1bf37e05df05d0c05392
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon May 18 09:18:41 2015 +0100

    sna: Wrap GetImage with sigtrap
    
    Mostly for completeness, though it is still remotely possibly for the
    dst pointer to raise a SIGBUS (just less likely since it is not a i915
    bo).
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 105 Jiri Slaby 2015-06-25 09:19:39 UTC

I hit a bug from time to time. But I switched from kdm to sddm, so -core is no longer passed to Xorg and I don't know how to change this :(.

[106837.663] (EE) 
[106837.663] (EE) Backtrace:
[106837.667] (EE) 0: /usr/bin/X (xorg_backtrace+0x48) [0x58a8b8]
[106837.667] (EE) 1: /opt/ddx/lib64/xorg/modules/drivers/intel_drv.so (0x7fcbf4beb000+0x145944) [0x7fcbf4d30944]
[106837.667] (EE) 2: /opt/ddx/lib64/xorg/modules/drivers/intel_drv.so (0x7fcbf4beb000+0x147bce) [0x7fcbf4d32bce]
[106837.667] (EE) 3: /opt/ddx/lib64/xorg/modules/drivers/intel_drv.so (0x7fcbf4beb000+0x149932) [0x7fcbf4d34932]
[106837.667] (EE) 4: /opt/ddx/lib64/xorg/modules/drivers/intel_drv.so (0x7fcbf4beb000+0x91735) [0x7fcbf4c7c735]
[106837.667] (EE) 5: /opt/ddx/lib64/xorg/modules/drivers/intel_drv.so (0x7fcbf4beb000+0x96618) [0x7fcbf4c81618]
[106837.667] (EE) 6: /usr/bin/X (WakeupHandler+0x9c) [0x44194c]
[106837.667] (EE) 7: /usr/bin/X (WaitForSomething+0x1bb) [0x587d4b]
[106837.667] (EE) 8: /usr/bin/X (0x400000+0x3cda1) [0x43cda1]
[106837.667] (EE) 9: /usr/bin/X (0x400000+0x40e2b) [0x440e2b]
[106837.667] (EE) 10: /lib64/libc.so.6 (__libc_start_main+0xf5) [0x7fcbf93958c5]
[106837.667] (EE) 11: /usr/bin/X (_start+0x29) [0x42c469]
[106837.667] (EE) 
[106837.667] (EE) 
Fatal server error:
[106837.667] (EE) sna_dri2_xchg:2122 assertion 'pixmap->drawable.height * back_bo->pitch <= kgem_bo_size(back_bo)' failed

Comment 106 Chris Wilson 2015-06-25 09:38:58 UTC

Ugh, that's a scary/annoying one. At least I can guess the callstack.

Comment 107 Jiri Slaby 2015-06-25 09:41:08 UTC

(In reply to Chris Wilson from comment #106)
> Ugh, that's a scary/annoying one. At least I can guess the callstack.

I updated the driver and:
$ cat /usr/local/bin/X-core 
#!/bin/bash

exec /usr/bin/X $@ -core

$ grep ServerPath /etc/sddm.conf
ServerPath=/usr/local/bin/X-core


So a proper core will be generated eventually :).

Comment 108 Chris Wilson 2015-06-25 10:49:57 UTC

commit f97c6ba9dcb4488615a8f8cc7ad5790cc61f5a9e
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Jun 25 11:47:25 2015 +0100

    sna/dri2: Track original allocated size for copies
    
    When we record the next scanout for display after the following vblank,
    note the size of the allocation as well as its name and bo et al.
    
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c105
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

should be along the right track.

Comment 109 Jiri Slaby 2015-06-25 16:04:22 UTC

Ok, I updated, I cannot even log in :):

#4  0x00000000005972c8 in FatalError (f=f@entry=0x7f07fe62dbef "%s:%d assertion '%s' failed\n") at log.c:925
#5  0x00007f07fe60970c in sna_dri2_xchg (draw=draw@entry=0x1916a90, front=0x1916470, back=back@entry=0x1975a20) at sna_dri2.c:2131
#6  0x00007f07fe60c358 in sna_dri2_schedule_flip (data=0x1916a90, func=0x55f3c0 <DRI2SwapEvent>, current_msc=7728, target_msc=0x7ffe2db28fc8, immediate=true, back=0x1975a20, front=0x1916470, crtc=0xdb8200, draw=0x1916a90, client=0x19558a0) at sna_dri2.c:2982
#7  sna_dri2_schedule_swap (client=0x19558a0, draw=0x1916a90, front=<optimized out>, back=0x1975a20, target_msc=0x7ffe2db28fc8, divisor=<optimized out>, remainder=0, func=0x55f3c0 <DRI2SwapEvent>, data=0x1916a90) at sna_dri2.c:3215
#8  0x000000000055e490 in DRI2SwapBuffers (client=client@entry=0x19558a0, pDraw=0x1916a90, target_msc=7729, divisor=0, remainder=<optimized out>, swap_target=swap_target@entry=0x7ffe2db29058, func=func@entry=0x55f3c0 <DRI2SwapEvent>, data=0x1916a90) at dri2.c:1163
#9  0x000000000055fd63 in ProcDRI2SwapBuffers (client=0x19558a0) at dri2ext.c:416
#10 ProcDRI2Dispatch (client=0x19558a0) at dri2ext.c:613
#11 0x000000000043d04e in Dispatch () at dispatch.c:432
#12 0x0000000000440e2b in dix_main (argc=11, argv=0x7ffe2db29258, envp=<optimized out>) at main.c:298
#13 0x00007f0802c6e8c5 in __libc_start_main (main=0x42c430 <main>, argc=11, argv=0x7ffe2db29258, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe2db29248) at libc-start.c:289
#14 0x000000000042c469 in _start () at ../sysdeps/x86_64/start.S:118

Comment 110 Chris Wilson 2015-06-25 16:11:06 UTC

Sorry, one assertion too many.

commit 6fc7b16b931946995ffab99c5216810417cfeb99
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Jun 25 17:08:59 2015 +0100

    sna/dri2: Remove overzealous assertion
    
    sna_dri2_xchg() is also called on the flip path to do an immediate swap
    of a hidden buffer, in which case can_xchg() returns false as it
    believes that the swap requires a flip.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c109
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 111 Jiri Slaby 2015-06-30 08:39:33 UTC

Nice, we can close now.

Comment 112 Jiri Slaby 2015-07-02 19:07:23 UTC

Yet another one with 2.99.917-373-g6fc7b16b9319:
#5  0x00007ff63b1e5309 in sna_dri2_xchg (draw=draw@entry=0x30eaa60, front=front@entry=0x4288e60, back=back@entry=0x41de0f0) at sna_dri2.c:2138
#6  0x00007ff63b1e761e in chain_swap (chain=0x39b0300) at sna_dri2.c:2369
#7  0x00007ff63b1e9312 in sna_dri2_vblank_handler (event=<optimized out>) at sna_dri2.c:2568
#8  0x00007ff63b130735 in sna_mode_wakeup (sna=sna@entry=0x7ff641c38000) at sna_display.c:8378
#9  0x00007ff63b135618 in sna_wakeup_handler (arg=<optimized out>, result=1, read_mask=0x827300 <LastSelectMask>) at sna_driver.c:732
#10 0x000000000044194c in WakeupHandler (result=result@entry=1, pReadmask=pReadmask@entry=0x827300 <LastSelectMask>) at dixutils.c:426
#11 0x0000000000587d4b in WaitForSomething (pClientsReady=pClientsReady@entry=0x2e96120) at WaitFor.c:229
#12 0x000000000043cda1 in Dispatch () at dispatch.c:361
#13 0x0000000000440e2b in dix_main (argc=11, argv=0x7fff84685eb8, envp=<optimized out>) at main.c:298
#14 0x00007ff63f84a8c5 in __libc_start_main (main=0x42c430 <main>, argc=11, argv=0x7fff84685eb8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff84685ea8) at libc-start.c:289
#15 0x000000000042c469 in _start () at ../sysdeps/x86_64/start.S:118

Comment 113 Chris Wilson 2015-07-02 19:17:35 UTC

Hmm, it may be related to:

commit e5c6e48cc9e11f659d0d9d1b907357e28a554e9f
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sun Jun 28 18:25:37 2015 +0100

    sna/dri2: Discard backbuffer cache on Window resize

So hopefully a pull later it won't reoccur.

Comment 114 Jiri Slaby 2015-07-24 09:43:04 UTC

With 2.99.917-382-g2cd7cb9e9376, I saw this:

#4  0x00000000005995f8 in FatalError (f=f@entry=0x7fe9d5ce503b "%s:%d assertion '%s' failed\n") at log.c:945
#5  0x00007fe9d5b9bd2a in kgem_create_2d (kgem=kgem@entry=0x7fe9dc732000, width=width@entry=1366, height=height@entry=768, bpp=bpp@entry=32, tiling=<optimized out>, flags=530) at kgem.c:5630
#6  0x00007fe9d5cbf88d in sna_dri2_create_buffer (draw=0x4294bc0, attachment=1, format=32) at sna_dri2.c:695
#7  0x000000000055ec3c in create_buffer (ds=0x10, ds=0x10, format=32, attachment=1, pDraw=0x4294bc0) at dri2.c:431
#8  allocate_or_reuse_buffer (pDraw=pDraw@entry=0x4294bc0, ds=ds@entry=0x16ca990, pPriv=pPriv@entry=0x274f8c0, attachment=attachment@entry=1, format=format@entry=32, dimensions_match=dimensions_match@entry=1, buffer=0x3659580) at dri2.c:478
#9  0x000000000055f6e3 in do_get_buffers (pDraw=0x4294bc0, width=width@entry=0x7fff38baae58, height=height@entry=0x7fff38baae60, attachments=0x407d95c, attachments@entry=0x407d954, count=1, out_count=out_count@entry=0x7fff38baae68, has_format=1) at dri2.c:554
#10 0x000000000055fadb in DRI2GetBuffersWithFormat (pDraw=<optimized out>, width=width@entry=0x7fff38baae58, height=height@entry=0x7fff38baae60, attachments=attachments@entry=0x407d954, count=<optimized out>, out_count=out_count@entry=0x7fff38baae68) at dri2.c:671
#11 0x000000000056110c in ProcDRI2GetBuffersWithFormat (client=0x3fd2760) at dri2ext.c:309
#12 ProcDRI2Dispatch (client=0x3fd2760) at dri2ext.c:611
#13 0x000000000043cfef in Dispatch () at dispatch.c:432
#14 0x0000000000440fab in dix_main (argc=11, argv=0x7fff38bab078, envp=<optimized out>) at main.c:298
#15 0x00007fe9da336790 in __libc_start_main (main=0x42c4c0 <main>, argc=11, argv=0x7fff38bab078, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff38bab068) at libc-start.c:289
#16 0x000000000042c4f9 in _start () at ../sysdeps/x86_64/start.S:118

Comment 115 Chris Wilson 2015-07-24 10:32:43 UTC

Wth. It implies that kgem_set_tiling() failed. It does highlight a problem that we can not try and workaround the set-tiling failure on this path, so let's fix that:

commit ad20fd401b8c3ca128bd0fcf5a71ba90beda9d70
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Fri Jul 24 11:30:46 2015 +0100

    sna: Ensure that DRI2 buffers are created with a fence

Comment 116 Chris Wilson 2015-07-24 10:43:10 UTC

A few possible valid causes: invalid tiling parameters or attempting to change tiling on a framebuffer object.
But it is also likely to be an invalid -EIO reported by the kernel. Did you see anything in dmesg?

At any rate I need to rethink set_gpu_tiling() with !kgem->can_fence. Preferrably that should be a per-bo flag in this case. Tricksy tricks are tricksy.

Comment 117 Jiri Slaby 2015-07-24 10:46:50 UTC

(In reply to Chris Wilson from comment #116)
> A few possible valid causes: invalid tiling parameters or attempting to
> change tiling on a framebuffer object.
> But it is also likely to be an invalid -EIO reported by the kernel. Did you
> see anything in dmesg?

Oh, yeah:
[drm:intel_dp_start_link_train [i915]] *ERROR* failed to enable link training
[drm:intel_dp_complete_link_train [i915]] *ERROR* failed to start channel equalization

It was like a was moving monitor here and there. I turned it off, disconnected, closed lid of laptop, connected. Laptop also suspended by closing the lid. So I really don't know what triggered this... It definitely happened 7 seconds before suspend. So we can exclude suspend at least.

Comment 118 Jiri Slaby 2015-08-18 09:58:30 UTC

With 2.99.917-439-g79fc9a923cdf I see too many of:

#4  0x0000000000599b88 in FatalError (f=f@entry=0x7efc2f1f2bfb "%s:%d assertion '%s' failed\n") at log.c:945
#5  0x00007efc2f1d0496 in sna_dri2_schedule_swap (client=0x292bea0, draw=0x2a336a0, front=0x2adb730, back=0x2a0ad70, target_msc=0x7ffc386c49f8, divisor=0, remainder=0, func=0x560f40 <DRI2SwapEvent>, data=0x2a336a0) at sna_dri2.c:3141
#6  0x000000000056003e in DRI2SwapBuffers (client=client@entry=0x292bea0, pDraw=0x2a336a0, target_msc=1, divisor=0, remainder=<optimized out>, swap_target=swap_target@entry=0x7ffc386c4a88, func=0x560f40 <DRI2SwapEvent>, data=0x2a336a0) at dri2.c:1163
#7  0x00000000005618ac in ProcDRI2SwapBuffers (client=0x292bea0) at dri2ext.c:416
#8  ProcDRI2Dispatch (client=0x292bea0) at dri2ext.c:613
#9  0x000000000043cfef in Dispatch () at dispatch.c:432
#10 0x0000000000440fab in dix_main (argc=11, argv=0x7ffc386c4c98, envp=<optimized out>) at main.c:298
#11 0x00007efc33844790 in __libc_start_main (main=0x42c4c0 <main>, argc=11, argv=0x7ffc386c4c98, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc386c4c88) at libc-start.c:289
#12 0x000000000042c4f9 in _start () at ../sysdeps/x86_64/start.S:118

Comment 119 Chris Wilson 2015-08-18 10:10:12 UTC

(In reply to Jiri Slaby from comment #118)
> With 2.99.917-439-g79fc9a923cdf I see too many of:
> 
> #4  0x0000000000599b88 in FatalError (f=f@entry=0x7efc2f1f2bfb "%s:%d
> assertion '%s' failed\n") at log.c:945
> #5  0x00007efc2f1d0496 in sna_dri2_schedule_swap (client=0x292bea0,

Hohum. Do you also get the "stale back buffer" in the full debug log?

Comment 120 Chris Wilson 2015-08-18 11:04:38 UTC

Stabbing in the dark (slightly). Can you please test with

commit b86974ffd435b2339cd873131e0f90aedc9c4a42
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Aug 18 11:36:46 2015 +0100

    sna/dri2: Do full exchanges of back/pending around deferred swaps

Comment 121 Jiri Slaby 2015-08-18 11:23:51 UTC

(In reply to Chris Wilson from comment #119)
> Do you also get the "stale back buffer" in the full debug log?

No:
http://www.fi.muni.cz/~xslaby/sklad/panics/xorg.debug

(In reply to Chris Wilson from comment #120)
> Stabbing in the dark (slightly). Can you please test with
> 
> commit b86974ffd435b2339cd873131e0f90aedc9c4a42

Sure, but it did not help :).

Comment 122 Chris Wilson 2015-08-18 12:55:54 UTC

Grasping at straws!

commit 18e484502727f2e2e16138a3de5b6727f3879a2b
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Aug 18 12:40:39 2015 +0100

    sna/dri2: Transfer the pending back to the new back following the xchg

Comment 123 Chris Wilson 2015-08-19 14:22:09 UTC

Had yet another go, and for fun added lots of assertions then spent the day with valgrind hunting them down:

commit dab1c0f159d74fc82618b88262e064010e6387ec
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Aug 18 23:27:22 2015 +0100

    sna/dri2: Move the pending swap from the buffer to the event
    
    To ease tracking of the next swap, stash it on the event (which is then
    reused) rather than the back buffer (which changes frequently).
    
    In addition, add debug flags and assertions to track event stages (such
    as making sure we do not decouple/free an event that we have sent a
    signal back to the client).

Comment 124 Jiri Slaby 2015-10-09 10:03:27 UTC

Updated to 2.99.917-476-g4e668dd19ca4 and every time I start hexchat, I get:

#5  0x00007fabab20fafc in __kgem_retire_requests_upto (kgem=0x7fabb1e0f000, bo=bo@entry=0x4206cc0) at kgem.c:3263
#6  0x00007fabab20fcd8 in kgem_bo_retire (kgem=<optimized out>, bo=0x4206cc0) at kgem.c:781
#7  0x00007fabab2189fc in kgem_bo_sync__cpu (kgem=kgem@entry=0x7fabb1e0f000, bo=bo@entry=0x4206cc0) at kgem.c:6960
#8  0x00007fabab291710 in write_boxes_inplace__tiled (kgem=kgem@entry=0x7fabb1e0f000, src=src@entry=0x456a670 "\370\372", <incomplete sequence \372>, stride=stride@entry=28, bpp=bpp@entry=32, src_dx=src_dx@entry=-271, src_dy=src_dy@entry=-77, bo=0x4206cc0, dst_dx=0, dst_dy=0, box=0x7ffd6c715fe0, n=1) at sna_io.c:687
#9  0x00007fabab2929f5 in write_boxes_inplace (kgem=kgem@entry=0x7fabb1e0f000, src=src@entry=0x456a670, stride=stride@entry=28, bpp=32, src_dx=src_dx@entry=-271, src_dy=src_dy@entry=-77, bo=0x4206cc0, dst_dx=0, dst_dy=0, box=0x7ffd6c715fe0, n=1) at sna_io.c:732
#10 0x00007fabab295e03 in sna_write_boxes (sna=sna@entry=0x7fabb1e0f000, dst=dst@entry=0x2d95a90, dst_bo=0x4206cc0, dst_dx=dst_dx@entry=0, dst_dy=dst_dy@entry=0, src=0x456a670, stride=28, src_dx=-271, src_dy=-77, box=0x7ffd6c715fe0, nbox=1) at sna_io.c:845
#11 0x00007fabab25b9ce in sna_copy_boxes (src=<optimized out>, dst=<optimized out>, gc=<optimized out>, region=<optimized out>, dx=<optimized out>, dy=<optimized out>, bitplane=0, closure=0x0) at sna_accel.c:6867
#12 0x00007fabab228f72 in sna_do_copy (src=src@entry=0x456a5f0, dst=dst@entry=0x38d0a10, gc=gc@entry=0x37a8fe0, sx=sx@entry=0, sy=sy@entry=0, width=width@entry=7, height=14, dx=549, dy=77, copy=0x7fabab2596d0 <sna_copy_boxes>, bitPlane=0, closure=0x0) at sna_accel.c:7186
#13 0x00007fabab229192 in sna_copy_area (src=0x456a5f0, dst=0x38d0a10, gc=0x37a8fe0, src_x=0, src_y=0, width=7, height=14, dst_x=267, dst_y=51) at sna_accel.c:7277
#14 0x000000000051ab34 in damageCopyArea (pSrc=0x456a5f0, pDst=0x38d0a10, pGC=0x37a8fe0, srcx=0, srcy=<optimized out>, width=7, height=14, dstx=267, dsty=51) at damage.c:764
#15 0x000000000043961e in ProcCopyArea (client=0x3849ed0) at dispatch.c:1673
#16 0x000000000043cfef in Dispatch () at dispatch.c:432
#17 0x0000000000440fab in dix_main (argc=12, argv=0x7ffd6c716338, envp=<optimized out>) at main.c:298
#18 0x00007fabaf9b3610 in __libc_start_main (main=0x42c4c0 <main>, argc=12, argv=0x7ffd6c716338, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd6c716328) at libc-start.c:289
#19 0x000000000042c4f9 in _start () at ../sysdeps/x86_64/start.S:118

Comment 125 Chris Wilson 2015-10-09 10:09:17 UTC

Quick enough to get a full-debug log?

The assertion that fails is that although we have performed an operation should have made the bo idle, after chatting with the kernel we have decided it is not as idle as we would like.

Comment 126 Jiri Slaby 2015-10-09 13:21:38 UTC

Hmm, once I set debug=full I cannot reproduce. Neither with non-full debug.

Comment 127 Jiri Slaby 2015-10-19 07:53:15 UTC

(In reply to Chris Wilson from comment #125)
> Quick enough to get a full-debug log?

Here you go:
http://www.fi.muni.cz/~xslaby/sklad/panics/Xorg.0.log.old.xz

(40M unpacked)

Comment 128 Chris Wilson 2015-10-19 08:52:14 UTC

As expected it says the kernel failed to idle the bo when we tried to move it to the CPU write domain:

[  2836.327] kgem_bo_sync__cpu: handle=21
[  2836.327] __kgem_busy: handle=21, busy=0, wedged=0
[  2836.327] kgem_bo_sync__cpu: SYNC: handle=21, needs_flush? 1, domain? 3, busy
? 0
[  2836.327] __kgem_busy: handle=21, busy=0, wedged=0
[  2836.327] kgem_bo_retire: retiring bo handle=21 (needed flush? 1), rq? 1 [bus
y?=0]
[  2836.327] __kgem_retire_requests_upto(handle=21)
[  2836.327] __kgem_retire_rq: request 1 complete
[  2836.327] __kgem_bo_flush: handle=21, busy=65536, wedged=0
[  2836.327] __kgem_bo_flush: moving 21 to flushing
[  2836.327] __kgem_retire_rq: movied 21 to flushing


Hmm, at the time it should not have been accessible by any other client, but at some point in its past the handle was exported.

This will prevent this assertion from triggering (by papering over the bug):

commit 3656bcf01e78554aaeafc11ecebb0caf7dd12713
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Mon Oct 19 09:34:43 2015 +0100

    sna: Manually clear the GPU bo needs_flush flag after doing an explicit flush
    
    The kernel often gets confused and fails to flush the bo itself, so lets
    just pretend it worked.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    References: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c127
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 129 Jiri Slaby 2015-11-22 16:29:34 UTC

Today, I hit this with 2.99.917-492-g694e9bc4e2e9 (now, I updated to 2.99.917-512-gf6e9316ed44f):
#5  0x00007f72e331e5c6 in kgem_bo_set_purgeable (bo=<optimized out>, kgem=0x7f72e9f1e000) at kgem.c:877
#6  kgem_expire_cache (kgem=kgem@entry=0x7f72e9f1e000) at kgem.c:4369
#7  0x00007f72e336c1e6 in sna_accel_expire (sna=0x7f72e9f1e000) at sna_accel.c:17739
#8  sna_accel_block (sna=0x7f72e9f1e000, tv=0x7ffeb18272f8) at sna_accel.c:18250
#9  0x000000000044196a in BlockHandler (pTimeout=pTimeout@entry=0x7ffeb18272f8, pReadmask=pReadmask@entry=0x82d180 <LastSelectMask>) at dixutils.c:387
#10 0x0000000000589b0b in WaitForSomething (pClientsReady=pClientsReady@entry=0x226f8b0) at WaitFor.c:216
#11 0x000000000043cef1 in Dispatch () at dispatch.c:358
#12 0x000000000044109b in dix_main (argc=12, argv=0x7ffeb1827708, envp=<optimized out>) at main.c:298
#13 0x00007f72e7ac2610 in __libc_start_main (main=0x42c600 <main>, argc=12, argv=0x7ffeb1827708, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffeb18276f8) at libc-start.c:289
#14 0x000000000042c639 in _start () at ../sysdeps/x86_64/start.S:118

Comment 130 Chris Wilson 2015-11-22 18:03:29 UTC

Hopefully the Xorg.log was devoid of other warnings (because it should have only set that after a CPU mmaping failed, I believe):

commit 0995ad221d0bab03e4b4f9c1c36849fda2a51339
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Sun Nov 22 17:59:34 2015 +0000

    sna: Remove obsolete assertion
    
    Once upon a time we only flagged th bo->purged when calling madvise and
    being told by the kernel that the bo was truncated. However, we now also
    preemptively set the flag on buffers we decide cannot be CPU mapped,
    invalidating the assertion.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 131 Jiri Slaby 2016-03-14 14:18:38 UTC

I am hitting bugs less often than before, but todays update leads to:
#5  0x00007fc09f2a3ec6 in sna_dri2_schedule_swap (client=0x27ba3b0, draw=0x278f100, front=0x2a45010, back=0x2dc7f80, target_msc=0x7ffe833d3a08, divisor=0, remainder=0, func=0x561cf0 <DRI2SwapEvent>, data=0x278f100) at sna_dri2.c:3305
#6  0x0000000000560dee in DRI2SwapBuffers (client=client@entry=0x27ba3b0, pDraw=0x278f100, target_msc=2072, divisor=0, remainder=<optimized out>, swap_target=swap_target@entry=0x7ffe833d3a98, func=0x561cf0 <DRI2SwapEvent>, data=0x278f100) at dri2.c:1163
#7  0x000000000056259c in ProcDRI2SwapBuffers (client=0x27ba3b0) at dri2ext.c:424
#8  ProcDRI2Dispatch (client=0x27ba3b0) at dri2ext.c:621
#9  0x00000000004390ff in Dispatch () at dispatch.c:430
#10 0x000000000043cfb3 in dix_main (argc=12, argv=0x7ffe833d3c98, envp=<optimized out>) at main.c:300
#11 0x00007fc0a3707610 in __libc_start_main (main=0x4284d0 <main>, argc=12, argv=0x7ffe833d3c98, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe833d3c88) at libc-start.c:289
#12 0x0000000000428509 in _start () at ../sysdeps/x86_64/start.S:118


Every time I do alt-f2 (krunner) and start typing a command to run.

Comment 132 Chris Wilson 2016-03-14 14:27:09 UTC

If we move the skip-on-stale check ahead of the assert, does that paper over the bug?

diff --git a/src/sna/sna_dri2.c b/src/sna/sna_dri2.c
index 2ed698d..4b6fdad 100644
--- a/src/sna/sna_dri2.c
+++ b/src/sna/sna_dri2.c
@@ -3302,15 +3302,15 @@ sna_dri2_schedule_swap(ClientPtr client, DrawablePtr draw, DRI2BufferPtr front,
        assert(get_private(front)->refcnt);
        assert(get_private(back)->refcnt);
 
-       assert(get_private(back)->bo != get_private(front)->bo);
-       assert(get_private(front)->bo->refcnt);
-       assert(get_private(back)->bo->refcnt);
-
        if (get_private(back)->stale) {
                DBG(("%s: stale back buffer\n", __FUNCTION__));
                goto skip;
        }
 
+       assert(get_private(back)->bo != get_private(front)->bo);
+       assert(get_private(front)->bo->refcnt);
+       assert(get_private(back)->bo->refcnt);
+
        if (draw->type != DRAWABLE_PIXMAP) {
                WindowPtr win = (WindowPtr)draw;
                struct dri2_window *priv = dri2_window(win);

Comment 133 Jiri Slaby 2016-03-14 14:47:50 UTC

(In reply to Chris Wilson from comment #132)
> If we move the skip-on-stale check ahead of the assert, does that paper over
> the bug?

Now I see:
#4  0x000000000059add8 in FatalError (f=0x7f505cec6fa7 "or Intel(R) Iris(TM) Graphics: 5100, 6100\n") at log.c:1015
#5  0x00007f505cea3ec6 in sna_dri2_schedule_swap (client=0x239b730, draw=0x2013480, front=0x200a240, back=0x26f5b80, target_msc=<optimized out>, divisor=<optimized out>, remainder=0, func=0x561cf0 <DRI2SwapEvent>, data=0x2013480) at sna_dri2.c:3435
#6  0x0000000000560dee in DRI2SwapBuffers (client=client@entry=0x200a240, pDraw=0x2013480, target_msc=14781, divisor=0, remainder=<optimized out>, swap_target=swap_target@entry=0x7fffddb32818, func=0x561cf0 <DRI2SwapEvent>, data=0x2013480) at dri2.c:1163

Comment 134 Chris Wilson 2016-03-14 14:53:14 UTC

Hmm, I am definitely confused now. :(

Comment 135 Chris Wilson 2016-03-15 09:24:41 UTC

(In reply to Jiri Slaby from comment #131)
> Every time I do alt-f2 (krunner) and start typing a command to run.

Meh. Obstinately worksforme. KDE4 from F21 (old installation) with current drivers. Could I ask you to kindly capture a debug log?

Comment 136 Jiri Slaby 2016-03-15 16:33:01 UTC

(In reply to Chris Wilson from comment #135)
> drivers. Could I ask you to kindly capture a debug log?

Sure:
http://www.fi.muni.cz/~xslaby/sklad/panics/Xorg.0.log.old.xz

This is with this assert:
#5  0x00007fa2b247dbbd in _sna_dri2_destroy_buffer (sna=0x7fa2b8d9e000, draw=0x15477b0, buffer=0x11af9e0) at sna_dri2.c:881

I also saw the same assert (as in comment#131, with comment#132 applied) at 3310 a second ago:
assert(get_private(back)->bo != get_private(front)->bo);

Comment 137 Chris Wilson 2016-03-15 19:22:40 UTC

(In reply to Jiri Slaby from comment #136)
> (In reply to Chris Wilson from comment #135)
> > drivers. Could I ask you to kindly capture a debug log?
> 
> Sure:
> http://www.fi.muni.cz/~xslaby/sklad/panics/Xorg.0.log.old.xz

Thanks, that is not making a lot of sense either. Yes, it is a double unref, but I haven't yet found the culprit. I think it is more likely to be a use-after-free of the vblank event, so I'm still hunting.

Do you have a few moments for valgrind?

Comment 138 Chris Wilson 2016-03-15 21:14:34 UTC

To try and capture my thoughts:

It appears to be associated with resizing the window.

[ 40132.873] sna_set_window_pixmap: window=23068682, old pixmap=2883 new pixmap=2896
[ 40132.873] sna_dri2_decouple_window: window=23068682
...
[ 40132.877] sna_dri2_create_buffer pixmap=2896, (attachment=1, format=32, drawable=532x495), window?=1
[ 40132.877] sna_dri2_create_buffer: creating back buffer 532x495, suitable for scanout? 0
[ 40132.877] kgem_create_2d(532x495, bpp=32, tiling=1, exact=1, inactive=0, cpu-mapping=0, gtt-mapping=0, scanout?=0, prime?=0, temp?=0)
[ 40132.877] kgem_surface_size: tile_width=512, tile_height=8 => aligned pitch=2560, height=496
[ 40132.878] kgem_set_tiling: handle=42, tiling=1 [1], pitch=2560 [2560]: 1
[ 40132.878] kgem_bo_remove_from_inactive: removing handle=42 from inactive
[ 40132.878]   from inactive: pitch=2560, tiling=1: handle=42, id=1730
[ 40132.878] kgem_bo_flink: flinked handle=42 to name=20, marking non-reusable
[ 40132.878] sna_dri2_create_buffer pixmap=2896, (attachment=0, format=32, drawable=532x495), window?=1
[ 40132.878] sna_pixmap_set_dri: attaching DRI client to pixmap=2896
[ 40132.878] sna_pixmap_move_to_gpu(pixmap=2896, usage=0), flags=c2
[ 40132.878] sna_pixmap_move_to_gpu: already all-damaged
[ 40132.878] sna_pixmap_mark_active: pixmap=2896, handle=50
[ 40132.878] sna_dri2_create_buffer: attaching to front buffer 532x495 [0x14e1030:1], scanout? 0
[ 40132.878] kgem_bo_flink: flinked handle=50 to name=22, marking non-reusable
[ 40132.878] sna_dri2_create_buffer: adding flush hint to handle=50
[ 40132.878] sna_accel_watch_flush: enable=1
[ 40132.878] _sna_dri2_destroy_buffer: 0x11cac10 [handle=37] -- refcnt=1, pixmap=0, proxy?=0
[ 40132.878] sna_dri2_cache_bo(handle=37, name=17)
[ 40132.878] sna_dri2_cache_bo: wrong size [532x42], releasing handle
[ 40132.878] _kgem_bo_destroy: handle=37, proxy? 0
[ 40132.878] __kgem_bo_destroy: handle=37, size=122880
[ 40132.878] __kgem_bo_destroy: handle=37, not reusable
[ 40132.878] kgem_bo_free: handle=37, size=122880
[ 40132.878] kgem_bo_free: releasing 0x0:0x0 vma for handle=37, count=0
[ 40132.878] _sna_dri2_destroy_buffer: 0x11af9e0 [handle=35] -- refcnt=1, pixmap=2883, proxy?=0
[ 40132.878] _sna_dri2_destroy_buffer: removing active_scanout=1 from pixmap handle=35
[ 40132.878] _sna_dri2_destroy_buffer: releasing last DRI pixmap=2883, scanout?=0
[ 40132.878] _sna_dri2_destroy_buffer: dropping flush hint from handle=35
...
[ 40132.886] sna_wakeup_handler
[ 40132.886] _sna_dri2_destroy_buffer: 0x11b1000 [handle=19] -- refcnt=1, pixmap=0, proxy?=0
[ 40132.886] sna_dri2_cache_bo(handle=19, name=3)
[ 40132.886] sna_dri2_cache_bo: not a window, releasing handle=19
[ 40132.886] _kgem_bo_destroy: handle=19, proxy? 0
[ 40132.886] __kgem_bo_destroy: handle=19, size=122880
[ 40132.886] __kgem_bo_destroy: handle=19, not reusable
[ 40132.886] kgem_bo_free: handle=19, size=122880
[ 40132.886] kgem_bo_free: releasing 0x0:0x0 vma for handle=19, count=0
[ 40132.886] _sna_dri2_destroy_buffer: 0x11af9e0 [handle=35] -- refcnt=0, pixmap=2883, proxy?=0
ASSERT!

The oddities that I need to explain:

Where did the last unref come from, the only clue in stacktrace is FreeResource(), suggesting that it came from the DRI2 core.

Why didn't sna_dri2_decouple_window() mark the pending events as dead?

Do I have dangling private pointers from the window?

Comment 139 Chris Wilson 2016-03-15 21:50:41 UTC

(In reply to Chris Wilson from comment #138)
> The oddities that I need to explain:
> 
> Where did the last unref come from, the only clue in stacktrace is
> FreeResource(), suggesting that it came from the DRI2 core.

That appears to be that the named pixmap (for Composite) is used by DRI2 with both the window and as a pixmap. The last free is from destroying the Pixmap.

> Do I have dangling private pointers from the window?

No, the DRI2 buffer is associated with the Pixmap not Window. The resized Window creates a new DRI2Buffer for its new Pixmap and then we destroy the old DRI2Buffer.

Comment 140 Chris Wilson 2016-03-16 06:42:34 UTC

Ok, I think I got it:

commit b6f204b62bbf2d0918761bb7773d2f80fff985fd
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Mar 15 21:24:20 2016 +0000

    sna/dri2: Prevent starting a swap chain for a decoupled Pixmap
    
    When a Window is resized, a new Pixmap is attached to the Window and the
    DRI2 buffers invalidated. However, the client may have requested a swap
    before it is notified of the resize and so we have to discard the stale
    swap. In doing so, we do not want to start a swap chain as it references
    the wrong frontbuffer and causes dire confusion when we start swapping
    for real.
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=70461#c131
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

plus a silly assert(chain->front = info->front) royally breaking things instead of being the warning it was meant to be, which snuck into

commit d1672806a5222f00dcc2eb24ccddd03f727f71bc
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Feb 24 10:33:22 2016 +0000

    sna/dri2: Add active-scanout tracking to single CRTC flips

My task for today is to capture this resize race in tests/dri2-race.

Comment 141 Jiri Slaby 2016-03-16 07:38:53 UTC

Now (2.99.917-570-gb6f204b62bbf), I see:

#5  0x00007f658f4102cb in dri2_chain (d=0x271a880) at sna_dri2.c:377
#6  0x00007f658f41acf0 in sna_dri2_schedule_swap (client=0x27ba720, draw=0x271a880, front=0x2271b30, back=0x2d5dda0, target_msc=0x7ffe2cf56e48, divisor=0, remainder=0, func=0x561cf0 <DRI2SwapEvent>, data=0x271a880) at sna_dri2.c:3358
#7  0x0000000000560dee in DRI2SwapBuffers (client=client@entry=0x27ba720, pDraw=0x271a880, target_msc=1807801, divisor=0, remainder=<optimized out>, swap_target=swap_target@entry=0x7ffe2cf56ed8, func=0x561cf0 <DRI2SwapEvent>, data=0x271a880) at dri2.c:1163
#8  0x000000000056259c in ProcDRI2SwapBuffers (client=0x27ba720) at dri2ext.c:424
#9  ProcDRI2Dispatch (client=0x27ba720) at dri2ext.c:621
#10 0x00000000004390ff in Dispatch () at dispatch.c:430
#11 0x000000000043cfb3 in dix_main (argc=12, argv=0x7ffe2cf570d8, envp=<optimized out>) at main.c:300

debug log here again:
http://www.fi.muni.cz/~xslaby/sklad/panics/Xorg.0.log.old.xz

Comment 142 Chris Wilson 2016-03-16 08:30:00 UTC

Hah, just because it passed the existing tests doesn't mean that it was good - especially as those tests missed the first bug.

commit 4eb2d9dc92cec2053c76df5dc923f5552fd06c9e
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Mar 16 08:27:34 2016 +0000

    sna/dri2: Release the dangling chain after decoupling
    
    After releasing the list, we need to mark it as freed.
    
    Oversight from commit a11cbb6954f08edd0d8fb5eeca1debb289fdb9af
    Author: Chris Wilson <chris@chris-wilson.co.uk>
    Date:   Tue Mar 15 21:11:48 2016 +0000
    
        sna/dri2: Cancel all pending events when the window is resized
    
    which reused the code for destroying the window (where priv->chain will
    not be accessed again afterwards).
    
    Reported-by: Jiri Slaby <jirislaby@gmail.com>
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

Comment 143 Chris Wilson 2016-03-16 09:55:56 UTC

First batch of Composite races written and now I remember why I didn't decouple it earlier:

commit 3f56c3d50cc668e51ee649db8191da28bed3c582
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Wed Mar 16 09:39:10 2016 +0000

    sna/dri2: Flush outstanding signals when decoupling inflight events

Comment 144 Jiri Slaby 2016-03-17 07:34:56 UTC

I am on 2.99.917-578-g68913715a298 and I seem to be flying.

Comment 145 Chris Wilson 2016-03-22 13:22:39 UTC

A few days of grace... Let's hope it remains quiet.

Comment 146 Patrick Welche 2016-06-07 12:10:44 UTC

Seems all still quiet :-) Any thoughts on a 2.99.918 ?

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.