Bug 9969

Summary: Heavy MGA DRI use causes Xorg lock
Product: Mesa Reporter: Oleg Sapon <xsov>
Component: Drivers/DRI/MGAAssignee: Default DRI bug account <dri-devel>
Status: RESOLVED WONTFIX QA Contact:
Severity: normal    
Priority: medium CC: xsov
Version: 6.5   
Hardware: x86 (IA32)   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:

Description Oleg Sapon 2007-02-13 19:25:21 UTC
Similar by symptoms bugs were described here:
http://bugs.freedesktop.org/show_bug.cgi?id=8666
http://bugs.freedesktop.org/show_bug.cgi?id=473

1. How to reproduce: 
start sauerbraten, play in ffa MP mode, jump much and shoot much, then get console lock in 7-15 minutes. Cube works well for hours ;-)

2. What report application:
mga_get_buffer_ioctl: flush return = Device or resource busy (16), flags = 0x00000006

3. What reports Xorg (>3000 times):
(EE) MGA(0): [dri] Idle timed out, resetting engine...

4. What can i do:
ssh from other system to this locked, then reboot it. I can't switch to other VT (Ctrl-Alt-F2 for ex.), after such attempt system hangs.

5. System info:
- MB: ASUS A7V-E VIA133
- Video: Matrox G450 32Mb AGP 2xVGA;

6. Version info (tried all listed below):
- kernel: 2.6.19, 2.6.20 (matroxfb/mga-drm/mga_vid/i2c-matrox modules loaded);
- Xorg: 6.9.0, 7.1.0;
- libdrm: 2.0.0, 2.3.0;
- Mesa(GL&glut): standard for Xorg 6.9.0 in Slackware, 6.5.2;
- mga_drv: 1.3.x(including matrox site version), 1.4.6.1;
- sauerbraten: 2006_12_04.

Sometimes i see when lock occur at syslog/dmesg (using ssh):
Feb 11 22:47:58 mmx kernel: DMA per-cpu:
Feb 11 22:47:58 mmx kernel: CPU    0: Hot: hi:    0, btch:   1 usd:   0   Cold: hi:    0, btch:   1 usd:   0
Feb 11 22:47:58 mmx kernel: Normal per-cpu:
Feb 11 22:47:58 mmx kernel: CPU    0: Hot: hi:  186, btch:  31 usd:  18   Cold: hi:   62, btch:  15 usd:   7
Feb 11 22:47:58 mmx kernel: Active:6652 inactive:3747 dirty:70 writeback:0 unstable:0 free:116188 slab:1565 mappe
d:927 pagetables:54
Feb 11 22:47:58 mmx kernel: DMA free:11676kB min:88kB low:108kB high:132kB active:0kB inactive:0kB present:16256k
B pages_scanned:0 all_unreclaimable? no
Feb 11 22:47:58 mmx kernel: lowmem_reserve[]: 0 492
Feb 11 22:47:58 mmx kernel: Normal free:453076kB min:2792kB low:3488kB high:4188kB active:26608kB inactive:14988k
B present:503860kB pages_scanned:0 all_unreclaimable? no
Feb 11 22:47:58 mmx kernel: lowmem_reserve[]: 0 0
Feb 11 22:47:58 mmx kernel: DMA: 3*4kB 4*8kB 3*16kB 2*32kB 4*64kB 2*128kB 1*256kB 1*512kB 0*1024kB 1*2048kB 2*409
6kB = 11676kB
Feb 11 22:47:58 mmx kernel: Normal: 1*4kB 0*8kB 1*16kB 20*32kB 17*64kB 8*128kB 5*256kB 3*512kB 1*1024kB 0*2048kB
109*4096kB = 453076kB
Feb 11 22:47:58 mmx kernel: Swap cache: add 0, delete 0, find 0/0, race 0+0
Feb 11 22:47:58 mmx kernel: Free swap  = 618460kB
Feb 11 22:47:58 mmx kernel: Total swap = 618460kB
Feb 11 23:37:38 mmx kernel: [drm:drm_lock_take] *ERROR* 1 holds heavyweight lock

I can try to debug, if you'll describe how. Have enough skills in C/C++.
Comment 1 Oleg Sapon 2007-03-06 18:18:11 UTC
Same problem with latest software:
- Xorg 7.2
- mga_drv 1.4.6.1
- Mesa 6.5.2
- kernel 2.6.20
- Matrox card BIOS - latest

I tried to disable buggy for me COMPOSITE extension, bug still exist.
Comment 2 Oleg Sapon 2007-03-14 15:06:46 UTC
Tried latest drm from freedesktop.org git reposotory and disabled preemption in kernel, still no results.

P.S. Does someone read my messages or this bug list is dead? Seriously.
Comment 3 Ian Romanick 2007-03-14 15:29:55 UTC
(In reply to comment #2)
> Tried latest drm from freedesktop.org git reposotory and disabled preemption in
> kernel, still no results.

What AGP mode are you using?  I know that there are some buggy interactions between MGA and certain Via chipsets.  Have you tried 1x?

> P.S. Does someone read my messages or this bug list is dead? Seriously.

Yes, sorry.  I just haven't had a chance to dig into it yet.
Comment 4 Oleg Sapon 2007-03-14 18:32:57 UTC
> What AGP mode are you using?  I know that there are some buggy interactions
between MGA and certain Via chipsets.  Have you tried 1x?

Moreover, i've tried next configuration:
- no matroxfb;
- no mga_vid;
- no i2c;
- no preemption;
- no options for section "Device" in /etc/X11/xorg.conf except "AGPMode" "1" and "DRI" "True";
- disabled AIGLX and Composite extension.
I've checked that all options is setted via dmesg and Xorg.log.

Bug still here :(

I've tried to debug and got 332Mb file, i see this in the end of it, repeating many times:

Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x6442, nr=0x42, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_do_dma_reset]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:44:32 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_dma_flush] idle,
Mar 15 04:44:32 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x6442, nr=0x42, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_do_dma_reset]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:44:32 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_dma_flush] idle,
Mar 15 04:44:32 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x6442, nr=0x42, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_do_dma_reset]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:44:32 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:44:32 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:44:32 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Comment 5 Oleg Sapon 2007-03-14 18:41:23 UTC
This how log was changed prior to that cicle.

Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0xc0286429, nr=0x29, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    tail=0x0fd174 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    head=0x0fd0dc 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get] returning NULL!
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] ret = fffffff5
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0xc0286429, nr=0x29, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    tail=0x0fd174 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    head=0x0fd0dc 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get] returning NULL!
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] ret = fffffff5
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:38 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:42:38 mmx kernel: [drm:drm_lock] 1 interrupted
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] ret = fffffe00
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x4008642a, nr=0x2a, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:drm_lock] 1 (pid 1031) requests lock (0xc0000003), flags = 0x00000000
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:38 mmx kernel: [drm:mga_do_wait_for_idle]
...
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:41 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:41 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:41 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:41 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:42:41 mmx kernel: [drm:drm_lock] 1 interrupted
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] ret = fffffe00
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x4008642a, nr=0x2a, dev 0xe200, auth=1
Mar 15 04:42:41 mmx kernel: [drm:drm_lock] 1 (pid 1031) requests lock (0xc0000003), flags = 0x00000000
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:41 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:41 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:42:41 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:42:41 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:42:41 mmx kernel: [drm:mga_do_wait_for_idle]
...
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:03 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:03 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:03 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:03 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:03 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:03 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:03 mmx kernel: [drm:drm_vm_close] 0xb3cb5000,0x00800000
Mar 15 04:43:03 mmx kernel: [drm:drm_vm_close] 0xb44b5000,0x002fb000
Mar 15 04:43:03 mmx kernel: [drm:drm_vm_close] 0xb47b0000,0x02000000
Mar 15 04:43:03 mmx kernel: [drm:drm_vm_shm_close] 0xb7e73000,0x00002000
Mar 15 04:43:03 mmx kernel: [drm:drm_release] open_count = 2
Mar 15 04:43:03 mmx kernel: [drm:drm_release] pid = 1139, device = 0xe200, open_count = 2
Mar 15 04:43:03 mmx kernel: [drm:drm_fasync] fd = -1, device = 0xe200
Mar 15 04:43:03 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:03 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:03 mmx kernel: [drm:mga_do_wait_for_idle]
...
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:22 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:22 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_dma_flush] idle,
Mar 15 04:43:22 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x6442, nr=0x42, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_do_dma_reset]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_dma_flush] flush, idle,
Mar 15 04:43:22 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] pid=1031, cmd=0x40086441, nr=0x41, dev 0xe200, auth=1
Mar 15 04:43:22 mmx kernel: [drm:mga_dma_flush] idle,
Mar 15 04:43:22 mmx kernel: [drm:mga_do_wait_for_idle]
Mar 15 04:43:22 mmx kernel: [drm:drm_ioctl] ret = fffffff0
Comment 6 Oleg Sapon 2007-03-14 18:43:36 UTC
Prior to all last writed here log messages there was:

Mar 15 04:42:38 mmx kernel: [drm:mga_dma_dispatch_vertex] vertex: buf=38 used=840
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_put] age=0x0078b4 wrap=205
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0xc0286429, nr=0x29, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    tail=0x0fcfbc 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    head=0x0fd0dc 205
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x400c6445, nr=0x45, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_dma_dispatch_vertex] vertex: buf=39 used=3120
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_put] age=0x007a1c wrap=205
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0xc0286429, nr=0x29, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    tail=0x0fd05c 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    head=0x0fd0dc 205
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0x400c6445, nr=0x45, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_dma_dispatch_vertex] vertex: buf=40 used=5040
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_put] age=0x007b84 wrap=205
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] pid=1135, cmd=0xc0286429, nr=0x29, dev 0xe200, auth=1
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    tail=0x0fd174 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get]    head=0x0fd0dc 205
Mar 15 04:42:38 mmx kernel: [drm:mga_freelist_get] returning NULL!
Mar 15 04:42:38 mmx kernel: [drm:drm_ioctl] ret = fffffff5
Comment 7 Oleg Sapon 2007-03-15 17:25:13 UTC
(In reply to comment #3)
> What AGP mode are you using?  I know that there are some buggy interactions
> between MGA and certain Via chipsets.  Have you tried 1x?
Yes, even in 1x mode bug appear. I incorrectly post some drm debug logs here: https://bugs.freedesktop.org/show_bug.cgi?id=9969 Sorry for that.
Comment 8 Ian Romanick 2015-11-30 23:49:08 UTC
The MGA driver longer exists in Mesa.

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.