Hi,
We're seeing an odd rare interaction between rescan-scsi-bus and arcmsr,
which manifests as these log messages, then a hang/panic:
Feb 9 18:51:19 Space kernel: [ 2624.283565] arcmsr: abort
scsi_cmnd(0xffff8807d06cc900), cmnd[0x8a,0x 0,0x 0,0x 0,0x 0,0x 1,0x
8,0xc0,0x2b,0xe8,0x 0,0x 0], scsi_id = 0x 0, scsi_lun = 0x 0.
Feb 9 18:51:19 Space kernel: [ 2624.283604] arcmsr0: to abort
command(0xffff8807d06cc900), ccb = 0xffff881058b11180
Feb 9 18:51:21 Space kernel: [ 2625.924838] arcmsr0: abort ccb =
0xffff881058b11180 not done yet, do not force aborting command!
--- Snip many more ---
On the (seemingly less common) occasion that it panics rather than
hangs, it looks like this:
Feb 9 11:55:05 Space kernel: [58801.943419] arcmsr9: abort
scsi_cmnd(0xffff881027968900), cmnd[0x 0,0x 0,0x 0,0x 0,0x 0,0x 0,0x
0,0x 0,0x 0,0x 0,0x 0,0x 0], scsi_id = 0x 0, scsi_lun = 0x 0.
Feb 9 11:55:05 Space kernel: [58801.943427] arcmsr9: to abort
command(0xffff881027968900), ccb = 0xffff88085864a580
Feb 9 11:55:05 Space kernel: [58801.943429] arcmsr9: scsi id = 0 lun =
0 ccb = '0xffff88085864a580' polling a done ccb, abort successfully
Feb 9 11:55:05 Space kernel: [58801.943460] BUG: scheduling while
atomic: ksoftirqd/19/85/0x00000100
Feb 9 11:55:05 Space kernel: [58801.943463] Modules linked in: xfs
libcrc32c mlx4_ib ib_sa ib_mad ib_core ib_addr mlx4_en mlx4_core
myri10ge bonding target_core_mod configfs ip6table_filter ip6_tables
iptable_filter ip_tables ebtable_nat ebtables x_tables dm_crypt
ipmi_ssif x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm
crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64
lrw gf128mul glue_helper ablk_helper cryptd sb_edac microcode edac_core
lpc_ich ioatdma tpm_tis ipmi_si ipmi_msghandler 8250_fintek mac_hid nfsd
auth_rpcgss pcspkr nfs_acl nfs lockd grace sunrpc fscache ext2 mlx5_core
raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor
async_tx xor raid6_pq raid1 raid0 multipath linear vxlan ip6_udp_tunnel
udp_tunnel bcache hid_generic igb isci usbhid i2c_algo_bit libsas ahci
dca hid libahci ptp scsi_transport_sas pps_core arcmsr(OE) [last
unloaded: mlx4_core]
Feb 9 11:55:05 Space kernel: [58801.943511] CPU: 19 PID: 85 Comm:
ksoftirqd/19 Tainted: G OE 3.19.0-21-spacev3 #160915
Feb 9 11:55:05 Space kernel: [58801.943512] Hardware name: GBLabs
Space+/X9DRH-7TF/7F/iTF/iF, BIOS 3.2 06/04/2015
Feb 9 11:55:05 Space kernel: [58801.943514] ffff88105bd13a08
ffff88105bd13948 ffffffffaf6e521c 0000000000000000
Feb 9 11:55:05 Space kernel: [58801.943516] ffff88107fcf29c0
ffff88105bd13958 ffffffffaf6dfa07 ffff88105bd139c8
Feb 9 11:55:05 Space kernel: [58801.943517] ffffffffaf6e84fc
ffff88105bcb41a0 00000000000129c0 ffff88105bd13fd8
Feb 9 11:55:05 Space kernel: [58801.943519] Call Trace:
Feb 9 11:55:05 Space kernel: [58801.943528] [<ffffffffaf6e521c>]
dump_stack+0x45/0x57
Feb 9 11:55:05 Space kernel: [58801.943533] [<ffffffffaf6dfa07>]
__schedule_bug+0x4b/0x59
Feb 9 11:55:05 Space kernel: [58801.943535] [<ffffffffaf6e84fc>]
__schedule+0x75c/0x780
Feb 9 11:55:05 Space kernel: [58801.943537] [<ffffffffaf6e8549>]
schedule+0x29/0x70
Feb 9 11:55:05 Space kernel: [58801.943540] [<ffffffffaf6eb45b>]
schedule_timeout+0x10b/0x210
Feb 9 11:55:05 Space kernel: [58801.943544] [<ffffffffaf0b0180>] ?
internal_add_timer+0x80/0x80
Feb 9 11:55:05 Space kernel: [58801.943546] [<ffffffffaf0b14e7>]
msleep+0x37/0x50
Feb 9 11:55:05 Space kernel: [58801.943552] [<ffffffffc0342af2>]
arcmsr_queue_command+0x82/0xf40 [arcmsr]
Feb 9 11:55:05 Space kernel: [58801.943553] [<ffffffffaf6e2637>] ?
__slab_free+0x101/0x2c1
Feb 9 11:55:05 Space kernel: [58801.943555] [<ffffffffaf6e2637>] ?
__slab_free+0x101/0x2c1
Feb 9 11:55:05 Space kernel: [58801.943561] [<ffffffffaf4bae0f>]
scsi_dispatch_cmd+0xaf/0x310
Feb 9 11:55:05 Space kernel: [58801.943563] [<ffffffffaf4bdca0>]
scsi_request_fn+0x4f0/0x7e0
Feb 9 11:55:05 Space kernel: [58801.943566] [<ffffffffaf31ecf7>]
__blk_run_queue+0x37/0x50
Feb 9 11:55:05 Space kernel: [58801.943568] [<ffffffffaf31ed86>]
blk_run_queue+0x26/0x40
Feb 9 11:55:05 Space kernel: [58801.943570] [<ffffffffaf4ba970>]
scsi_run_queue+0x230/0x2d0
Feb 9 11:55:05 Space kernel: [58801.943572] [<ffffffffaf4b311d>] ?
scsi_put_command+0x7d/0xd0
Feb 9 11:55:05 Space kernel: [58801.943575] [<ffffffffaf4bb992>]
scsi_end_request+0x142/0x1e0
Feb 9 11:55:05 Space kernel: [58801.943576] [<ffffffffaf4be119>]
scsi_io_completion+0x109/0x6b0
Feb 9 11:55:05 Space kernel: [58801.943578] [<ffffffffaf4b36ff>]
scsi_finish_command+0xcf/0x130
Feb 9 11:55:05 Space kernel: [58801.943580] [<ffffffffaf4bd787>]
scsi_softirq_done+0x137/0x160
Feb 9 11:55:05 Space kernel: [58801.943583] [<ffffffffaf328f13>]
blk_done_softirq+0x83/0xa0
Feb 9 11:55:05 Space kernel: [58801.943587] [<ffffffffaf060aa4>]
__do_softirq+0xe4/0x270
Feb 9 11:55:05 Space kernel: [58801.943588] [<ffffffffaf060c59>]
run_ksoftirqd+0x29/0x40
Feb 9 11:55:05 Space kernel: [58801.943593] [<ffffffffaf07d7f3>]
smpboot_thread_fn+0x143/0x1b0
Feb 9 11:55:05 Space kernel: [58801.943596] [<ffffffffaf07d6b0>] ?
SyS_setgroups+0x180/0x180
Feb 9 11:55:05 Space kernel: [58801.943598] [<ffffffffaf079a02>]
kthread+0xd2/0xf0
Feb 9 11:55:05 Space kernel: [58801.943600] [<ffffffffaf079930>] ?
kthread_create_on_node+0x1c0/0x1c0
Feb 9 11:55:05 Space kernel: [58801.943602] [<ffffffffaf6ec618>]
ret_from_fork+0x58/0x90
Feb 9 11:55:05 Space kernel: [58801.943604] [<ffffffffaf079930>] ?
kthread_create_on_node+0x1c0/0x1c0
We originally saw this in the wild very rarely, but have now replicated
it fairly reliably on an internal test system. The basic overview seems
to be:
1) Start an ton of simultaneous rescan-scsi-bus processes in a loop.
2) Apply a large load to the block device. It doesn't seem to matter
exactly what this load is, but anecdotally the error seems to occur more
quickly when reading/writing lots of small files rather than a few big
files.
3) ???
4) arcmsr shits the bed.
This has happened on a few different software/hardware flavours out in
the field, but on this particular test system we're using:
- kernel 3.19
- arcmsr v1.30.0X.20-20150342 (notably we've also seen this on
v1.30.0X.27-20170206 in the field)
- ARC-1883LP Raid Controller
- Supermicro 12G SAS Backplane
- 8x Samsung SAS SSDs (MZILS480HCGR/003)
Other details:
- There seems to be about ~30 gap where the entire system hangs just
before the arcmsr abort errors show up in the logs.
- Previously (and out in the field) we have LVM in the storage stack
(BD -> LVM -> XFS), but we've also replicated this with just XFS (or
EXT4) directly on the BD.
Any ideas?
Many thanks,
- Alex.
--
Alex Richman
alex.r@xxxxxxxxxxxx
