i386/58749: lock order reversal with heavy IO on ar0 (VIA 8237 SATA150)

[Meno Abels]

>Number:         58749
>Category:       i386
>Synopsis:       lock order reversal with heavy IO on ar0 (VIA 8237 SATA150)
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    freebsd-i386
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Thu Oct 30 22:10:17 PST 2003
>Closed-Date:
>Last-Modified:
>Originator:     Meno Abels
>Release:        FreeBSD 5.1-CURRENT
>Organization:
Adviser COM
>Environment:
System: FreeBSD race 5.1-CURRENT FreeBSD 5.1-CURRENT #0: Thu Oct 30 16:19:50 GMT 2003 root at bike:/usr/obj/usr/src/sys/GENERIC i386

	Mainboard: MSI KT6 Delta
	CPU      : Athlon-XP 2GHz
        Memory   : 512MB Memory
	IDE-Controller Info on Startup:
Oct 31 05:37:08 neo kernel: atapci0: <VIA 8237 SATA150 controller> port 0xd800-0xd8ff,0xdc00-0xdc0f,0xe000-0xe003,0xe400-0xe407,0xe800-0xe803,0xec00-0xec07 irq 11 at device 15.0 on pci0
Oct 31 05:37:08 neo kernel: atapci0: [MPSAFE]
Oct 31 05:37:08 neo kernel: ata2: at 0xec00 on atapci0
Oct 31 05:37:08 neo kernel: ata2: [MPSAFE]
Oct 31 05:37:08 neo kernel: ata3: at 0xe400 on atapci0
Oct 31 05:37:08 neo kernel: ata3: [MPSAFE]
Oct 31 05:37:08 neo kernel: atapci1: <VIA 8237 UDMA133 controller> port 0xfc00-0xfc0f at device 15.1 on pci0
Oct 31 05:37:08 neo kernel: ata0: at 0x1f0 irq 14 on atapci1
Oct 31 05:37:08 neo kernel: ata0: [MPSAFE]
Oct 31 05:37:08 neo kernel: ata1: at 0x170 irq 15 on atapci1
Oct 31 05:37:08 neo kernel: ata1: [MPSAFE]
	Disk Reports on Startup:
Oct 31 06:02:58 neo kernel: GEOM: create disk ad0 dp=0xc720a070
Oct 31 06:02:58 neo kernel: ad0: 117246MB <Maxtor 6Y120L0> [238216/16/63] at ata0-master UDMA133
Oct 31 06:02:58 neo kernel: GEOM: create disk ad2 dp=0xc7209c70
Oct 31 06:02:58 neo kernel: ad2: 58644MB <IBM-DTLA-307060> [119150/16/63] at ata1-master UDMA100
Oct 31 06:02:58 neo kernel: GEOM: create disk ad4 dp=0xc7209a70
Oct 31 06:02:58 neo kernel: ad4: 78167MB <Maxtor 6Y080M0> [158816/16/63] at ata2-master UDMA133
Oct 31 06:02:58 neo kernel: GEOM: create disk ad6 dp=0xc7209870
Oct 31 06:02:58 neo kernel: ad6: 78167MB <Maxtor 6Y080M0> [158816/16/63] at ata3-master UDMA133
Oct 31 06:02:58 neo kernel: GEOM: create disk ar0 dp=0xc7110de0 
Oct 31 06:02:58 neo kernel: ar0: 78167MB <ATA RAID1 array> [9964/255/63] status: READY subdisks:
Oct 31 06:02:58 neo kernel: disk0 READY on ad4 at ata2-master   
Oct 31 06:02:58 neo kernel: disk1 READY on ad6 at ata3-master 
>Description:
	if i do heavy IO such as using cp to copy data to these
        raid-1 i will get these lines:
Oct 31 06:16:36 neo kernel: lock order reversal
Oct 31 06:16:36 neo kernel: 1st 0xc86f86f0 vm object (vm object) @ /usr/src/sys/vm/swap_pager.c:1319
Oct 31 06:16:36 neo kernel: 2nd 0xc0934f80 swap_pager swhash (swap_pager swhash) @ /usr/src/sys/vm/swap_pager.c:1835
Oct 31 06:16:36 neo kernel: 3rd 0xc103565c vm object (vm object) @ /usr/src/sys/vm/uma_core.c:876
Oct 31 06:16:36 neo kernel: Stack backtrace:
	If I make the same on the not SATA connected devices without raid it works fine.
	If I don't halt the system directly after the occurs, all filesystem will be left as
        marked dirty on the next startup. There are no panic happend, if i don't shutdown directly
        I get a lot of strange messages printed on the console but nothing in the messageslogs 
	during the shutdown.  Theses messages has been totaly different the two times I tried it. 
>How-To-Repeat:
	Use cp or cpio to copy data to these ar0 device. It happens to me on my system
        now four times. There was no test where these phenomena didn't happens. If a
        leave the disk mounted but untouched everything is ok.
>Fix:
	unknown, i don't had a closer look it. If there are any proposals what
        i can do to track down the problem. I will go for further tests.


>Release-Note:
>Audit-Trail:
>Unformatted: