Bug#671689: [regression 3.2->3.3.4] sata_sil (on sil 3512) hotplug broken again
Hi Jonathan,
Am 06.05.2012 08:18, schrieb Jonathan Nieder:
Hi Michael,
Michael Schmitt wrote:
I tend to hotswap sata drives with a frameless-sata-hotswap-enclosure connected
to a Silicon Image 3512 controller on a regular basis and have to report...
broken again. :)
The last 3.2 kernel did work, the first 3.3 image did break it. I had
that problem once before (even if I do not find the ticket anymore) and it got
fixed rather fast. I do not even know anymore if I did report it upstream or in
the Debian BTS, but as I am not sure if a Debian patch may be responsible I
report it here.
Thanks for reporting it. Weird --- can you say a little more about
the nature of the breakage? In particular, please indicate:
- steps to reproduce
- how reproducible this is (100% of the time? 80% of the time?)
- expected result, actual result, and how the difference indicates a bug
- full "dmesg" output from booting and reproducing the problem
- which kernel versions you have tested and what happened with each
Very simple, it is reproducible 100% of the time, but I must admit I did
just try it a few times and there it did always happen. But if it helps
I am willing to test that a bit further and let's say make 20 test-runs.
It happend like this. Installed 3.3.3 (iirc ) a few days back, did some
hdd shuffling a few days later, realized a modprobe -r; modprobe was
necessary all the time (maybe 5 hotswap events), rebooted to the last
3.2 kernel, worked like a charm (again maybe 5 hotswap events), wanted
to report it immediately but reportbug (madison) said there would be a
newer kernel available (3.3.4), installed that and it happend again with
this one and as it seemed this time even a reboot was necessary as the
module sata_sil was busy. The last thing for now... let's call it a
maybe, I did not test that very thoroughly as reboots are not that funny
as I am used to hibernate / suspend these days. :)
There haven't been any changes to the sata_sil driver since v3.2.
That is indeed strange... bottom line, I will get the last few 3.3.x
kernels from snapshot.d.o and test the whole issue a bit further and
report back then.
For a start of logs, see attached: dmesg_hotswap_3.2_3.2.16-1.txt (some
hotswap events with kernel image 3.2.0-2-686-pae (changelog indicates
3.2.16-1)
regards
Michael
Curious,
Jonathan
[ 4121.428002] ata5: exception Emask 0x10 SAct 0x0 SErr 0x50000 action 0xe frozen
[ 4121.428022] ata5: SError: { PHYRdyChg CommWake }
[ 4121.428039] ata5: hard resetting link
[ 4127.192021] ata5: link is slow to respond, please be patient (ready=-19)
[ 4129.208054] ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 4129.216331] ata5.00: ATA-7: SAMSUNG HD502IJ, 1AA01113, max UDMA7
[ 4129.216336] ata5.00: 976773168 sectors, multi 0: LBA48 NCQ (depth 0/32)
[ 4129.224310] ata5.00: configured for UDMA/100
[ 4129.224320] ata5: EH complete
[ 4129.224473] scsi 4:0:0:0: Direct-Access ATA SAMSUNG HD502IJ 1AA0 PQ: 0 ANSI: 5
[ 4129.224830] sd 4:0:0:0: [sdg] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[ 4129.224900] sd 4:0:0:0: [sdg] Write Protect is off
[ 4129.224904] sd 4:0:0:0: [sdg] Mode Sense: 00 3a 00 00
[ 4129.224934] sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 4129.234487] sdg: sdg1
[ 4129.234814] sd 4:0:0:0: [sdg] Attached SCSI disk
[ 4158.530545] Btrfs loaded
[ 4158.531219] device label samsung_S13TJ1CQC01999 devid 1 transid 9 /dev/mapper/udisks-luks-uuid-fdabd147-01a5-4a16-84a5-5a27a3cebebc-uid1000
[ 4158.531806] btrfs: disk space caching is enabled
[ 4180.809393] ata5: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xe frozen
[ 4180.809399] ata5: SError: { PHYRdyChg }
[ 4180.809411] ata5: hard resetting link
[ 4181.532033] ata5: SATA link down (SStatus 0 SControl 310)
[ 4186.532026] ata5: hard resetting link
[ 4186.852027] ata5: SATA link down (SStatus 0 SControl 310)
[ 4191.852023] ata5: hard resetting link
[ 4192.172032] ata5: SATA link down (SStatus 0 SControl 310)
[ 4192.172043] ata5.00: disabled
[ 4192.172054] ata5: EH complete
[ 4192.172065] ata5.00: detaching (SCSI 4:0:0:0)
[ 4192.173078] sd 4:0:0:0: [sdg] Synchronizing SCSI cache
[ 4192.173113] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 4192.173117] sd 4:0:0:0: [sdg] Stopping disk
[ 4192.173125] sd 4:0:0:0: [sdg] START_STOP FAILED
[ 4192.173127] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 4237.416151] ata5: exception Emask 0x10 SAct 0x0 SErr 0x50000 action 0xe frozen
[ 4237.416157] ata5: SError: { PHYRdyChg CommWake }
[ 4237.416172] ata5: hard resetting link
[ 4243.180095] ata5: link is slow to respond, please be patient (ready=-19)
[ 4245.308041] ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 4245.316309] ata5.00: ATA-7: SAMSUNG HD502IJ, 1AA01113, max UDMA7
[ 4245.316314] ata5.00: 976773168 sectors, multi 0: LBA48 NCQ (depth 0/32)
[ 4245.324309] ata5.00: configured for UDMA/100
[ 4245.324319] ata5: EH complete
[ 4245.324464] scsi 4:0:0:0: Direct-Access ATA SAMSUNG HD502IJ 1AA0 PQ: 0 ANSI: 5
[ 4245.324827] sd 4:0:0:0: [sdg] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[ 4245.324898] sd 4:0:0:0: [sdg] Write Protect is off
[ 4245.324902] sd 4:0:0:0: [sdg] Mode Sense: 00 3a 00 00
[ 4245.324932] sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 4245.333449] sdg: sdg1
[ 4245.333758] sd 4:0:0:0: [sdg] Attached SCSI disk
[ 4562.887575] device label samsung_S13TJ90QB19095 devid 1 transid 10 /dev/mapper/udisks-luks-uuid-fd6f38f6-51be-4982-b5de-adf76a66b419-uid1000
[ 4562.888392] btrfs: disk space caching is enabled
[ 4590.033991] ata5: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xe frozen
[ 4590.033997] ata5: SError: { PHYRdyChg }
[ 4590.034009] ata5: hard resetting link
[ 4590.756046] ata5: SATA link down (SStatus 0 SControl 310)
[ 4595.756036] ata5: hard resetting link
[ 4596.076030] ata5: SATA link down (SStatus 0 SControl 310)
[ 4601.076030] ata5: hard resetting link
[ 4601.396031] ata5: SATA link down (SStatus 0 SControl 310)
[ 4601.396044] ata5.00: disabled
[ 4601.396056] ata5: EH complete
[ 4601.396067] ata5.00: detaching (SCSI 4:0:0:0)
[ 4601.397768] sd 4:0:0:0: [sdg] Synchronizing SCSI cache
[ 4601.397810] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 4601.397816] sd 4:0:0:0: [sdg] Stopping disk
[ 4601.397828] sd 4:0:0:0: [sdg] START_STOP FAILED
[ 4601.397831] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 4803.529675] ata5: exception Emask 0x10 SAct 0x0 SErr 0x50000 action 0xe frozen
[ 4803.529681] ata5: SError: { PHYRdyChg CommWake }
[ 4803.529695] ata5: hard resetting link
[ 4809.292024] ata5: link is slow to respond, please be patient (ready=-19)
[ 4812.708038] ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 4812.732307] ata5.00: ATA-8: SAMSUNG HD501LJ, CR100-10, max UDMA7
[ 4812.732312] ata5.00: 976773168 sectors, multi 0: LBA48 NCQ (depth 0/32)
[ 4812.740300] ata5.00: configured for UDMA/100
[ 4812.740310] ata5: EH complete
[ 4812.740463] scsi 4:0:0:0: Direct-Access ATA SAMSUNG HD501LJ CR10 PQ: 0 ANSI: 5
[ 4812.740890] sd 4:0:0:0: [sdg] 976773168 512-byte logical blocks: (500 GB/465 GiB)
[ 4812.740960] sd 4:0:0:0: [sdg] Write Protect is off
[ 4812.740964] sd 4:0:0:0: [sdg] Mode Sense: 00 3a 00 00
[ 4812.740994] sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 4812.749161] sdg: sdg1
[ 4812.749470] sd 4:0:0:0: [sdg] Attached SCSI disk
[ 4824.803410] device label samsung_S0MUJ1MP893478 devid 1 transid 9 /dev/mapper/udisks-luks-uuid-9875f298-b88e-4fce-b5d7-4830ed30a4d0-uid1000
[ 4824.803738] btrfs: disk space caching is enabled
[ 4878.228490] ata5: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xe frozen
[ 4878.228496] ata5: SError: { PHYRdyChg }
[ 4878.228508] ata5: hard resetting link
[ 4878.952036] ata5: SATA link down (SStatus 0 SControl 310)
[ 4880.616869] ata5: hard resetting link
[ 4885.976021] ata5: link is slow to respond, please be patient (ready=-19)
[ 4887.096046] ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 4887.112304] ata5.00: configured for UDMA/100
[ 4887.112313] ata5: EH complete
[ 4996.917632] ata5: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xe frozen
[ 4996.917638] ata5: SError: { PHYRdyChg }
[ 4996.917650] ata5: hard resetting link
[ 4997.640026] ata5: SATA link down (SStatus 0 SControl 310)
[ 5002.640026] ata5: hard resetting link
[ 5002.960030] ata5: SATA link down (SStatus 0 SControl 310)
[ 5007.960027] ata5: hard resetting link
[ 5008.280042] ata5: SATA link down (SStatus 0 SControl 310)
[ 5008.280055] ata5.00: disabled
[ 5008.280066] ata5: EH complete
[ 5008.280077] ata5.00: detaching (SCSI 4:0:0:0)
[ 5008.282263] sd 4:0:0:0: [sdg] Synchronizing SCSI cache
[ 5008.282300] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 5008.282306] sd 4:0:0:0: [sdg] Stopping disk
[ 5008.282316] sd 4:0:0:0: [sdg] START_STOP FAILED
[ 5008.282319] sd 4:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 5095.205241] ata5: exception Emask 0x10 SAct 0x0 SErr 0x50000 action 0xe frozen
[ 5095.205247] ata5: SError: { PHYRdyChg CommWake }
[ 5095.205261] ata5: hard resetting link
[ 5100.968022] ata5: link is slow to respond, please be patient (ready=-19)
[ 5105.224024] ata5: COMRESET failed (errno=-16)
[ 5105.224035] ata5: hard resetting link
[ 5108.692064] ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 5108.728044] ata5.00: ATA-8: ST31000340NS, SN06, max UDMA/133
[ 5108.728048] ata5.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 0/32)
[ 5108.787809] ata5.00: configured for UDMA/100
[ 5108.787822] ata5: EH complete
[ 5108.787980] scsi 4:0:0:0: Direct-Access ATA ST31000340NS SN06 PQ: 0 ANSI: 5
[ 5108.788394] sd 4:0:0:0: [sdg] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[ 5108.788464] sd 4:0:0:0: [sdg] Write Protect is off
[ 5108.788468] sd 4:0:0:0: [sdg] Mode Sense: 00 3a 00 00
[ 5108.788498] sd 4:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 5108.815022] sdg: sdg1
[ 5108.815338] sd 4:0:0:0: [sdg] Attached SCSI disk
[ 5119.160199] device label seagate_9QJ28AV9 devid 1 transid 13 /dev/mapper/udisks-luks-uuid-9744a2a1-b734-4791-874b-0da4e913b695-uid1000
[ 5119.160710] btrfs: disk space caching is enabled
[ 5705.342421] ata6: exception Emask 0x10 SAct 0x0 SErr 0x50000 action 0xe frozen
[ 5705.342427] ata6: SError: { PHYRdyChg CommWake }
[ 5705.342441] ata6: hard resetting link
[ 5711.104038] ata6: link is slow to respond, please be patient (ready=-19)
[ 5711.272031] ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 5711.281309] ata6.00: ATA-7: Maxtor 6B120M0, BANC1980, max UDMA/133
[ 5711.281314] ata6.00: 240121728 sectors, multi 0: LBA NCQ (not used)
[ 5711.297143] ata6.00: configured for UDMA/100
[ 5711.297153] ata6: EH complete
[ 5711.297297] scsi 5:0:0:0: Direct-Access ATA Maxtor 6B120M0 BANC PQ: 0 ANSI: 5
[ 5711.297557] sd 5:0:0:0: [sdh] 240121728 512-byte logical blocks: (122 GB/114 GiB)
[ 5711.297627] sd 5:0:0:0: [sdh] Write Protect is off
[ 5711.297631] sd 5:0:0:0: [sdh] Mode Sense: 00 3a 00 00
[ 5711.297661] sd 5:0:0:0: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 5711.318990] sdh: sdh1
[ 5711.319263] sd 5:0:0:0: [sdh] Attached SCSI disk
[ 5719.198415] kjournald starting. Commit interval 5 seconds
[ 5719.204153] EXT3-fs (dm-6): using internal journal
[ 5719.204158] EXT3-fs (dm-6): mounted filesystem with ordered data mode
[ 5729.170484] device label seagate_9QJ28AV9 devid 1 transid 16 /dev/mapper/udisks-luks-uuid-9744a2a1-b734-4791-874b-0da4e913b695-uid1000
[ 5729.170833] btrfs: disk space caching is enabled
mschmitt@adrastea:~$
Reply to: