Possible 7.0 showstopper: SATA/eSATA are unable to init hot-plugs

From: Dmitry Morozovsky <marck_at_rinet.ru>
Date: Fri, 7 Sep 2007 19:38:03 +0400 (MSD)
Dear colleagues,

on most (possibly all, but I'm not fully sure and a bit limited in testing) 
motherboard/controller configuration I've tested so far -current is unable to 
properly attach hot-plugged disks. Sometimes even atacontrol detach/atacontrol 
attach sequence can't bring disk into working state (only reboot does).

One example (today's current/amd64, verbose boot): 

[attach on the fly to eSATA port]

Sep  7 16:56:08 <kern.crit> hamster kernel: ata7: CONNECT requested
Sep  7 16:56:08 <kern.crit> hamster kernel: ata7: CONNECTED
Sep  7 16:56:08 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 16:56:08 <kern.crit> hamster kernel: ata7: reset tp1 mask=00 ostat0=ff 
ostat1=00
Sep  7 16:56:24 <kern.crit> hamster kernel: ata7: DISCONNECT requested
Sep  7 16:56:24 <kern.crit> hamster kernel: ata7: DISCONNECTED
Sep  7 16:56:33 <kern.crit> hamster kernel: ata7: CONNECT requested
Sep  7 16:56:33 <kern.crit> hamster kernel: ata7: CONNECTED
Sep  7 16:56:33 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 16:56:33 <kern.crit> hamster kernel: ata7: reset tp1 mask=00 ostat0=ff 
ostat1=00
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=50 
ostat1=00
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: stat0=0x50 err=0x01 lsb=0x00 
msb=0x00
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: reset tp2 stat0=50 stat1=00 
devices=0x1<ATA_MASTER>
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: [MPSAFE]
Sep  7 16:57:00 <kern.crit> hamster kernel: ata7: [ITHREAD]
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: reiniting channel ..
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=58 
ostat1=00
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: stat0=0xd8 err=0x00 lsb=0x00 
msb=0x00
Sep  7 16:57:34 <kern.crit> hamster last message repeated 232 times
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: stat0=0xd8 err=0x00 lsb=0x00 
msb=0x00
Sep  7 16:57:34 <kern.crit> hamster last message repeated 76 times
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: reset tp2 stat0=d8 stat1=00 
devices=0x0
Sep  7 16:57:34 <kern.crit> hamster kernel: ata7: reinit done ..
Sep  7 16:57:34 <kern.crit> hamster kernel: unknown: timeout waiting to issue 
command
Sep  7 16:57:34 <kern.crit> hamster kernel: unknown: error issuing ATA_IDENTIFY 
command

Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=d8 
ostat1=00
Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: stat0=0xd8 err=0x00 lsb=0x00 
msb=0x00
Sep  7 16:58:14 <kern.crit> hamster last message repeated 309 times
Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: reset tp2 stat0=d8 stat1=00 
devices=0x0
Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: [MPSAFE]
Sep  7 16:58:14 <kern.crit> hamster kernel: ata7: [ITHREAD]
Sep  7 17:08:02 <kern.crit> hamster kernel: ata7: DISCONNECT requested
Sep  7 17:08:02 <kern.crit> hamster kernel: ata7: DISCONNECTED
Sep  7 17:08:28 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:08:28 <kern.crit> hamster kernel: ata7: reset tp1 mask=00 ostat0=ff 
ostat1=00
Sep  7 17:08:28 <kern.crit> hamster kernel: ata7: [MPSAFE]
Sep  7 17:08:28 <kern.crit> hamster kernel: ata7: [ITHREAD]
Sep  7 17:08:36 <kern.crit> hamster kernel: ata7: reiniting channel ..
Sep  7 17:08:36 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:08:36 <kern.crit> hamster kernel: ata7: reset tp1 mask=00 ostat0=ff 
ostat1=00
Sep  7 17:08:36 <kern.crit> hamster kernel: ata7: reinit done ..
Sep  7 17:08:42 <kern.crit> hamster kernel: ata7: DISCONNECT requested
Sep  7 17:08:42 <kern.crit> hamster kernel: ata7: DISCONNECTED
Sep  7 17:08:46 <kern.crit> hamster kernel: ata7: CONNECT requested
Sep  7 17:08:46 <kern.crit> hamster kernel: ata7: CONNECTED
Sep  7 17:08:46 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:08:46 <kern.crit> hamster kernel: ata7: reset tp1 mask=00 ostat0=ff 
ostat1=00


[reboot]

Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: <Promise PDC40718 SATA300 
controller> port 0xa800-0xa87f,0xa400-0xa4ff mem 
0xfdffe000-0xfdffefff,0xfdfc0000-0xfdfdffff irq 16 at device 7.0 on pci1
Sep  7 17:13:27 <kern.crit> hamster kernel: pci1: child atapci3 requested type 
4 for rid 0x20, but the BAR says it is an memio
Sep  7 17:13:27 <kern.crit> hamster kernel: ioapic0: routing intpin 16 (PCI IRQ 
16) to vector 53
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: [MPSAFE]
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: [ITHREAD]
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: Reserved 0x20000 bytes for 
rid 0x20 type 3 at 0xfdfc0000
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: Reserved 0x1000 bytes for 
rid 0x1c type 3 at 0xfdffe000
Sep  7 17:13:27 <kern.crit> hamster kernel: ioapic0: routing intpin 16 (PCI IRQ 
16) to vector 53
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: [MPSAFE]
Sep  7 17:13:27 <kern.crit> hamster kernel: atapci3: [ITHREAD]
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: <ATA channel 1> on atapci3
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=50 
ostat1=00
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: stat0=0x50 err=0x01 lsb=0x00 
msb=0x00
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: reset tp2 stat0=50 stat1=00 
devices=0x1<ATA_MASTER>
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: [MPSAFE]
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7: [ITHREAD]
Sep  7 17:13:27 <kern.crit> hamster kernel: ata7-master: pio=PIO4 wdma=WDMA2 
udma=UDMA133 cable=40 wire
Sep  7 17:13:27 <kern.crit> hamster kernel: ad14: 381554MB <SAMSUNG HD403LJ 
CT100-10> at ata7-master SATA150
Sep  7 17:13:27 <kern.crit> hamster kernel: ad14: 781422768 sectors 
[775221C/16H/63S] 16 sectors/interrupt 1 depth queue
Sep  7 17:13:27 <kern.crit> hamster kernel: GEOM: new disk ad14
Sep  7 17:16:35 <kern.crit> hamster kernel: ad14: detached
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=50 
ostat1=00
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: stat0=0x50 err=0x01 lsb=0x00 
msb=0x00
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: reset tp2 stat0=50 stat1=00 
devices=0x1<ATA_MASTER>
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: [MPSAFE]
Sep  7 17:16:40 <kern.crit> hamster kernel: ata7: [ITHREAD]
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: reiniting channel ..
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=58 
ostat1=00
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: stat0=0xd8 err=0x00 lsb=0x00 
msb=0x00
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: reset tp2 stat0=d8 stat1=00 
devices=0x0
Sep  7 17:17:14 <kern.crit> hamster kernel: ata7: reinit done ..
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: reiniting channel ..
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: SATA connect time=0ms
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: reset tp1 mask=01 ostat0=d8 
ostat1=00
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: stat0=0xd8 err=0x00 lsb=0x00 
msb=0x00
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: reset tp2 stat0=d8 stat1=00 
devices=0x0
Sep  7 17:22:27 <kern.crit> hamster kernel: ata7: reinit done ..

RELENG_6 usually does attach successfully (can't check right now, but hopefully 
will do this weekend).

Any hints?


Sincerely,
D.Marck                                     [DM5020, MCK-RIPE, DM3-RIPN]
[ FreeBSD committer:				     marck_at_FreeBSD.org ]
------------------------------------------------------------------------
*** Dmitry Morozovsky --- D.Marck --- Wild Woozle --- marck_at_rinet.ru ***
------------------------------------------------------------------------
Received on Fri Sep 07 2007 - 13:38:06 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:17 UTC