Re: Tweaks to avoid ide timeouts under qemu?

[Paul Ripke <stix%stix.id.au@localhost>]

On Sun, Mar 22, 2020 at 12:46:22PM +0100, Jarom?r Dole?ek wrote:
> Hello,
> 
> can you please compile your kernel with ATADEBUG option, then for
> running system with new kernel set wdcdebug_wd_mask variable to '2'
> via ddb before the daily run, and then collect the output after it
> hangs again? Beware it's going to be a lot of messages.

Done & done. I couldn't figure out changing wdcdebug_wd_mask via ddb,
but gdb kvm did the job.

The last chunk of console log:

[ 12949.2799985] wdc_ata_bio_intr piixide0:0:0
[ 12949.2799985] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 12949.2799985] wdc_ata_done: drv_done
[ 12949.2799985] atastart from wdc_ata_done, flags 0x0
[ 12949.2799985] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0xb c_flags 0x8 ch_flags 0x0
[ 12949.2799985] _wdc_ata_bio_start piixide0:0:0
[ 12949.3503532] wdc_ata_bio_intr piixide0:0:0
[ 12949.3503532] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 12949.3503532] wdc_ata_done: drv_done
[ 12949.3503532] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0xb c_flags 0x8 ch_flags 0x0
[ 12949.3503532] _wdc_ata_bio_start piixide0:0:0
[ 12949.3503532] atastart from wdc_ata_done, flags 0x30
[ 12949.4650540] wdc_ata_bio_intr piixide0:0:0
[ 12949.4650540] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 12949.4650540] wdc_ata_done: drv_done
[ 12949.4650540] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0xb c_flags 0x8 ch_flags 0x0
[ 12949.4650540] _wdc_ata_bio_start piixide0:0:0
[ 12949.4650540] atastart from wdc_ata_done, flags 0x30
[ 12949.4650540] wdc_ata_bio_intr piixide0:0:0
[ 12949.4650540] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 12949.4650540] wdc_ata_done: drv_done
[ 12949.4650540] atastart from wdc_ata_done, flags 0x0
[ 12949.5444478] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0xb c_flags 0x8 ch_flags 0x0
[ 12949.5444478] _wdc_ata_bio_start piixide0:0:0
piixide0:0:0: lost interrupt
[ 12969.4636331]        type: ata tc_bcount: 65536 tc_skip: 0
piixide0:0:0: bus-master DMA error: missing interrupt, status=0x21
[ 12969.8228294] wdc_ata_bio_intr piixide0:0:0
[ 12969.8228294] wdc_ata_bio_done piixide0:0:0: flags 0xa
[ 12969.8228294] wdc_ata_done: drv_done
[ 12969.8228294] wd0b: DMA error writing fsbn 24576 of 24576-24703 (wd0 bn 3956799; cn 1932 tn 1 sn 31), xfer 38, retry 0
[ 12969.8228294] atastart from wdc_ata_done, flags 0x2010
[ 12971.8238280] wdc_ata_bio_start piixide0:0:0 state 0 drive_flags 0x80b c_flags 0x8 ch_flags 0x100
[ 12971.8238280] _wdc_ata_bio_start piixide0:0:0
[ 12983.1760184] wdc_ata_bio_intr piixide0:0:0
[ 12983.1760184] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 12983.1760184] wdc_ata_done: drv_done
[ 12983.1760184] wd0: soft error (corrected) xfer 38
[ 12983.1866158] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x80b c_flags 0x8 ch_flags 0x0
[ 12983.1866158] _wdc_ata_bio_start piixide0:0:0
[ 12983.1866158] atastart from wdc_ata_done, flags 0x30
piixide0:0:0: lost interrupt
[ 13003.1408517]        type: ata tc_bcount: 65536 tc_skip: 0
piixide0:0:0: bus-master DMA error: missing interrupt, status=0x21
[ 13003.5688149] wdc_ata_bio_intr piixide0:0:0
[ 13003.5688149] wdc_ata_bio_done piixide0:0:0: flags 0xa
[ 13003.5688149] wdc_ata_done: drv_done
[ 13003.5894496] wd0b: DMA error writing fsbn 24704 of 24704-24831 (wd0 bn 3956927; cn 1932 tn 5 sn 31), xfer 38, retry 0
[ 13003.5894496] atastart from wdc_ata_done, flags 0x10
[ 13004.5688368] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x80b c_flags 0x8 ch_flags 0x10
[ 13004.5688368] _wdc_ata_bio_start piixide0:0:0
piixide0:0:0: lost interrupt
[ 13024.5022731]        type: ata tc_bcount: 65536 tc_skip: 0
piixide0:0:0: bus-master DMA error: missing interrupt, status=0x21
[ 13025.0756554] wdc_ata_bio_intr piixide0:0:0
[ 13025.0756554] wdc_ata_bio_done piixide0:0:0: flags 0xa
[ 13025.0853785] wdc_ata_done: drv_done
[ 13025.0853785] wd0b: DMA error writing fsbn 24704 of 24704-24831 (wd0 bn 3956927; cn 1932 tn 5 sn 31), xfer 38, retry 1
[ 13025.0853785] atastart from wdc_ata_done, flags 0x10
[ 13026.0754400] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x80b c_flags 0x8 ch_flags 0x10
[ 13026.0754400] _wdc_ata_bio_start piixide0:0:0
[ 13035.5002971] wdc_ata_bio_intr piixide0:0:0
[ 13035.5002971] wdc_ata_bio_done piixide0:0:0: flags 0x8
[ 13035.5002971] wdc_ata_done: drv_done
[ 13035.5002971] wd0: soft error (corrected) xfer 38
[ 13035.5002971] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x80b c_flags 0x8 ch_flags 0x0
[ 13035.5002971] _wdc_ata_bio_start piixide0:0:0
[ 13035.5002971] atastart from wdc_ata_done, flags 0x30
piixide0:0:0: lost interrupt
[ 13055.0390722]        type: ata tc_bcount: 65536 tc_skip: 0
piixide0:0:0: bus-master DMA error: missing interrupt, status=0x21
[ 13055.3585934] wdc_ata_bio_intr piixide0:0:0
[ 13055.3585934] wd0: transfer error, downgrading to PIO mode 4
[ 13055.3585934] wdc_ata_bio_done piixide0:0:0: flags 0xa
[ 13055.3585934] wdc_ata_done: drv_done
[ 13055.3585934] wd0b: DMA error writing fsbn 24832 of 24832-24959 (wd0 bn 3957055; cn 1932 tn 9 sn 31), xfer 38, retry 0
[ 13055.3585934] atastart from wdc_ata_done, flags 0x210
[ 13057.3221359] wdc_ata_bio_start piixide0:0:0 state 0 drive_flags 0x809 c_flags 0x0 ch_flags 0x100
[ 13057.3221359] _wdc_ata_bio_start piixide0:0:0
piixide0:0:0: lost interrupt
[ 13076.7432727]        type: ata tc_bcount: 65536 tc_skip: 0
[ 13076.7432727] wdc_ata_bio_intr piixide0:0:0
[ 13076.7432727] wdc_ata_bio_done piixide0:0:0: flags 0x2
[ 13076.7432727] wdc_ata_done: drv_done
[ 13076.7432727] wd0b: device timeout writing fsbn 24832 of 24832-24959 (wd0 bn 3957055; cn 1932 tn 9 sn 31), xfer 38, retry 1
[ 13076.7432727] atastart from wdc_ata_done, flags 0x10
[ 13077.7437205] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x809 c_flags 0x0 ch_flags 0x10
[ 13077.7437205] _wdc_ata_bio_start piixide0:0:0
[ 13077.7437205] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x809 c_flags 0x0 ch_flags 0x110
[ 13077.7437205] _wdc_ata_bio_start piixide0:0:0
[ 13089.4969043] wdc_ata_bio_intr piixide0:0:0
[ 13089.4969043] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x809 c_flags 0x0 ch_flags 0x100
[ 13089.4969043] _wdc_ata_bio_start piixide0:0:0
[ 13089.9851915] wdc_ata_bio_intr piixide0:0:0
[ 13089.9851915] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x809 c_flags 0x0 ch_flags 0x100
[ 13089.9851915] _wdc_ata_bio_start piixide0:0:0
[ 13097.2427013] piixide0:0:0: not ready, st=0xd0, err=0x00
[ 13097.2427013] wdc_ata_bio_done piixide0:0:0: flags 0x0
[ 13097.2427013] wdc_ata_done: drv_done
[ 13097.2427013] wd0b: device timeout writing fsbn 24864 of 24832-24959 (wd0 bn 3957087; cn 1932 tn 10 sn 31), xfer 38, retry 2
[ 13097.2427013] atastart from wdc_ata_done, flags 0x110
[ 13098.2231482] wdc_ata_bio_start piixide0:0:0 state 1 drive_flags 0x809 c_flags 0x0 ch_flags 0x10
[ 13098.2231482] _wdc_ata_bio_start piixide0:0:0
[ 13098.2231482] piixide0:0:0: timeout waiting for DRQ, st=0xd0, err=0x00
[ 13098.2231482] wdc_ata_bio_done piixide0:0:0: flags 0x0
[ 13098.2231482] wdc_ata_done: drv_done

[...hung... unresponsive to break and cnmagic, can'd get to ddb...]

-- 
Paul Ripke
"Great minds discuss ideas, average minds discuss events, small minds
 discuss people."
-- Disputed: Often attributed to Eleanor Roosevelt. 1948.