Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

merge(f17533334cb7a4ae25c2913d1f5d1c3582670ff6) and current master branch drops to dracut while booting on Power8 #204

Closed
sathnaga opened this issue Nov 2, 2018 · 7 comments
Closed

merge(f17533334cb7a4ae25c2913d1f5d1c3582670ff6) and current master branch drops to dracut while booting on Power8 #204

sathnaga opened this issue Nov 2, 2018 · 7 comments

Comments

@sathnaga
Copy link

sathnaga commented Nov 2, 2018

Env: Power8
Host base distribution: Fedora rawhide

[   42.219901] sd 1:2:0:0: [sdc] Attached SCSI disk
[   42.219972] sd 1:2:1:0: [sdd] Attached SCSI disk
[   43.259168] device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.259212] device-mapper: table: unable to determine table type
[   43.270811] device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.270837] device-mapper: table: unable to determine table type
[   43.282094] device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.282126] device-mapper: table: unable to determine table type
[  148.464379] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  149.093541] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  149.684020] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  150.273386] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  150.874038] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  151.463399] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  152.054215] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  152.643486] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts
[  153.224326] dracut-initqueue[1313]: Warning: dracut-initqueue timeout - starting timeout scripts

Last known working commit:
Merge: 6080ad3a9941

kernel config used:
config-4.19.0-0.rc5.git3.1.fc30.ppc64le.txt
@sathnaga
Copy link
Author

sathnaga commented Nov 2, 2018

@mpe during bisect I hit at a new issue with commit 953923c09fe83255ae11845db1c9eb576ba73df8

ERROR [1419.207s]: runTest (testcases.InstallUpstreamKernel.InstallUpstreamKernel)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/jenkins/workspace/kvmci/testcases/InstallUpstreamKernel.py", line 112, in runTest
    self.cv_SYSTEM.goto_state(OpSystemState.OS)
  File "/home/jenkins/workspace/kvmci/common/OpTestSystem.py", line 339, in goto_state
    self.state = self.stateHandlers[self.state](state)
  File "/home/jenkins/workspace/kvmci/common/OpTestSystem.py", line 719, in run_BOOTING
    raise my_exception
UnknownStateTransition: Something happened system state="8" and we transitioned to UNKNOWN state.  Review the following for more details
Message="OpTestSystem in run_IPLing and Exception="Hard lockup (machine in state '5'): watchdog: CPU 30 detected hard LOCKUP on other CPUs 0
[   54.162069] watchdog: CPU 30 TB:77165016843, last SMP heartbeat TB:69469645551 (15030ms ago)
[   55.271533] watchdog: CPU 7 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.271542] watchdog: CPU 7 TB:75300603764, last heartbeat TB:69838290862 (10668ms ago)
[   55.271553] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.271588] irq event stamp: 2998
[   55.271592] hardirqs last  enabled at (2997): [<c000000000d80758>] _raw_spin_unlock_irq+0x48/0x80
[   55.271598] hardirqs last disabled at (2998): [<c000000000d76a6c>] __schedule+0x12c/0xf30
[   55.271603] softirqs last  enabled at (1624): [<c000000000b14880>] peernet2id+0x60/0x80
[   55.271606] softirqs last disabled at (1622): [<c000000000b14858>] peernet2id+0x38/0x80
[   55.271626] CPU: 7 PID: 1742 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.271632] NIP:  c0000000001c9f60 LR: c000000000d803d8 CTR: c0000000006feb90
[   55.271638] REGS: c0000007ffe3bd80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.271640] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.271669] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.271676] GPR00: c000000000d803d8 c0000007d44ab3f0 c0000000019e7c00 c0000007d5a7cf38 
[   55.271692] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.271714] GPR08: 0000000000000000 0000000080000000 0000000080000007 d000000015655ca0 
[   55.271751] GPR12: 0000000000004400 c0000007ffff7f00 f000000001f41108 c0000007d9f1ac10 
[   55.271794] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d9f1ac08 
[   55.271829] GPR20: c000000001a242a4 c0000007d3b43200 0000000000000004 0000000000000001 
[   55.271877] GPR24: 0000000000000001 0000000000000000 c0000007d44ab5a0 0000000000480020 
[   55.271919] GPR28: 0000000000000000 c0000007d5a7cf38 c000000001a23d78 c0000007d5a7cf38 
[   55.271950] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.271953] LR [c000000000d803d8] _raw_spin_lock_irq+0xd8/0x110
[   55.271961] Call Trace:
[   55.271966] [c0000007d44ab420] [c000000000d803cc] _raw_spin_lock_irq+0xcc/0x110
[   55.271993] [c0000007d44ab460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.271999] [c0000007d44ab4b0] [d0000000156536b4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.272020] [c0000007d44ab540] [c000000000a6fb60] dm_mq_queue_rq+0x120/0x6c0
[   55.272033] [c0000007d44ab600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.272047] [c0000007d44ab6c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.272075] [c0000007d44ab730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.272093] [c0000007d44ab790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.272115] [c0000007d44ab820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.272128] [c0000007d44ab870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.272138] [c0000007d44ab8b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.272146] [c0000007d44ab900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.272155] [c0000007d44ab9a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.272162] [c0000007d44aba20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.272176] [c0000007d44aba40] [c000000000393060] read_pages+0xa0/0x280
[   55.272178] [c0000007d44abae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.272186] [c0000007d44abbc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.272191] [c0000007d44abc20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.272200] [c0000007d44abce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.272206] [c0000007d44abd00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.272208] [c0000007d44abd90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.272214] [c0000007d44abde0] [c00000000049d564] ksys_read+0x64/0x110
[   55.272221] [c0000007d44abe30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.272223] Instruction dump:
[   55.272225] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.272235] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.272485] watchdog: CPU 15 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.272488] watchdog: CPU 15 TB:75305723953, last heartbeat TB:69715410677 (10918ms ago)
[   55.272489] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.272493] irq event stamp: 1980
[   55.272493] hardirqs last  enabled at (1979): [<c000000000d806d4>] _raw_spin_unlock_irqrestore+0x94/0xd0
[   55.272494] hardirqs last disabled at (1980): [<c000000000d76a6c>] __schedule+0x12c/0xf30
[   55.272494] softirqs last  enabled at (1538): [<c000000000b14880>] peernet2id+0x60/0x80
[   55.272495] softirqs last disabled at (1536): [<c000000000b14858>] peernet2id+0x38/0x80
[   55.272496] CPU: 15 PID: 1745 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.272496] NIP:  c0000000001c9f60 LR: c000000000d803d8 CTR: c0000000006feb90
[   55.272497] REGS: c0000007ffddbd80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.272497] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.272508] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.272509] GPR00: c000000000d803d8 c0000007d44d73f0 c0000000019e7c00 c0000007d5a7cf38 
[   55.272512] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.272514] GPR08: 0000000000000000 0000000080000000 000000008000000f d000000015655ca0 
[   55.272516] GPR12: 0000000000004400 c0000007fffeeb00 f000000001f418c8 c0000007d9f1d610 
[   55.272518] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d9f1d608 
[   55.272523] GPR20: c000000001a242a4 c0000007d3b4a400 0000000000000004 0000000000000001 
[   55.272528] GPR24: 0000000000000001 0000000000000000 c0000007d44d75a0 0000000000480020 
[   55.272532] GPR28: 0000000000000000 c0000007d5a7cf38 c000000001a23d78 c0000007d5a7cf38 
[   55.272539] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.272540] LR [c000000000d803d8] _raw_spin_lock_irq+0xd8/0x110
[   55.272540] Call Trace:
[   55.272541] [c0000007d44d7420] [c000000000d803cc] _raw_spin_lock_irq+0xcc/0x110
[   55.272545] [c0000007d44d7460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.272546] [c0000007d44d74b0] [d0000000156536b4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.272547] [c0000007d44d7540] [c000000000a6fb60] dm_mq_queue_rq+0x120/0x6c0
[   55.272548] [c0000007d44d7600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.272549] [c0000007d44d76c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.272550] [c0000007d44d7730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.272551] [c0000007d44d7790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.272552] [c0000007d44d7820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.272552] [c0000007d44d7870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.272553] [c0000007d44d78b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.272554] [c0000007d44d7900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.272558] [c0000007d44d79a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.272559] [c0000007d44d7a20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.272563] [c0000007d44d7a40] [c000000000393060] read_pages+0xa0/0x280
[   55.272564] [c0000007d44d7ae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.272565] [c0000007d44d7bc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.272566] [c0000007d44d7c20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.272567] [c0000007d44d7ce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.272568] [c0000007d44d7d00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.272569] [c0000007d44d7d90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.272570] [c0000007d44d7de0] [c00000000049d564] ksys_read+0x64/0x110
[   55.272570] [c0000007d44d7e30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.272571] Instruction dump:
[   55.272572] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.272579] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.272597] watchdog: CPU 35 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.272598] watchdog: CPU 35 TB:75310843500, last heartbeat TB:69915113750 (10538ms ago)
[   55.272599] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.272608] irq event stamp: 733
[   55.272608] hardirqs last  enabled at (733): [<c0000000004c8944>] d_alloc_parallel+0x3d4/0xc10
[   55.272609] hardirqs last disabled at (732): [<c0000000004c86b0>] d_alloc_parallel+0x140/0xc10
[   55.272610] softirqs last  enabled at (0): [<c000000000125100>] copy_process.isra.4.part.5+0x650/0x1f20
[   55.272613] softirqs last disabled at (0): [<0000000000000000>]           (null)
[   55.272614] CPU: 35 PID: 1758 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.272614] NIP:  c0000000001c9f60 LR: c000000000d803d8 CTR: c0000000006feb90
[   55.272615] REGS: c0000007ffcebd80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.272615] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.272620] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.272621] GPR00: c000000000d803d8 c0000007d448f3f0 c0000000019e7c00 c0000007d5a7cf38 
[   55.272623] GPR04: c0000007d5a7cf50 0000000000000001 c0000007d448f3d0 0000000000000001 
[   55.272628] GPR08: 0000000000000000 0000000080000000 0000000080000023 d000000015655ca0 
[   55.272635] GPR12: 0000000000004400 c0000007fffd7900 f000000001f42e48 c0000007d9f1ca10 
[   55.272640] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d9f1ca08 
[   55.272642] GPR20: c000000001a242a4 c0000007d3b42800 0000000000000004 0000000000000001 
[   55.272644] GPR24: 0000000000000001 0000000000000000 c0000007d448f5a0 0000000000480020 
[   55.272647] GPR28: 0000000000000000 c0000007d5a7cf38 c000000001a23d78 c0000007d5a7cf38 
[   55.272649] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.272650] LR [c000000000d803d8] _raw_spin_lock_irq+0xd8/0x110
[   55.272652] Call Trace:
[   55.272653] [c0000007d448f420] [c000000000d803cc] _raw_spin_lock_irq+0xcc/0x110
[   55.272654] [c0000007d448f460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.272658] [c0000007d448f4b0] [d0000000156536b4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.272659] [c0000007d448f540] [c000000000a6fb60] dm_mq_queue_rq+0x120/0x6c0
[   55.272660] [c0000007d448f600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.272661] [c0000007d448f6c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.272662] [c0000007d448f730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.272663] [c0000007d448f790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.272664] [c0000007d448f820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.272665] [c0000007d448f870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.272666] [c0000007d448f8b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.272667] [c0000007d448f900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.272668] [c0000007d448f9a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.272669] [c0000007d448fa20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.272672] [c0000007d448fa40] [c000000000393060] read_pages+0xa0/0x280
[   55.272673] [c0000007d448fae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.272677] [c0000007d448fbc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.272678] [c0000007d448fc20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.272679] [c0000007d448fce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.272680] [c0000007d448fd00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.272681] [c0000007d448fd90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.272682] [c0000007d448fde0] [c00000000049d564] ksys_read+0x64/0x110
[   55.272682] [c0000007d448fe30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.272683] Instruction dump:
[   55.272684] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.272687] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.272699] watchdog: CPU 39 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.272701] watchdog: CPU 39 TB:75305723948, last heartbeat TB:69879254926 (10598ms ago)
[   55.272702] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.272706] irq event stamp: 1886
[   55.272706] hardirqs last  enabled at (1885): [<c000000000d806d4>] _raw_spin_unlock_irqrestore+0x94/0xd0
[   55.272707] hardirqs last disabled at (1886): [<c000000000d76a6c>] __schedule+0x12c/0xf30
[   55.272707] softirqs last  enabled at (1556): [<c000000000b14880>] peernet2id+0x60/0x80
[   55.272708] softirqs last disabled at (1554): [<c000000000b14858>] peernet2id+0x38/0x80
[   55.272708] CPU: 39 PID: 1751 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.272709] NIP:  c0000000001c9f60 LR: c000000000d803d8 CTR: c0000000006feb90
[   55.272710] REGS: c0000007ffcbbd80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.272710] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.272720] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.272722] GPR00: c000000000d803d8 c0000007d44c73f0 c0000000019e7c00 c0000007d5a7cf38 
[   55.272724] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.272726] GPR08: 0000000000000000 0000000080000000 0000000080000027 d000000015655ca0 
[   55.272729] GPR12: 0000000000004400 c0000007fffd2f00 f000000001f41c88 c0000007d9f15e10 
[   55.272731] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d9f15e08 
[   55.272737] GPR20: c000000001a242a4 c0000007d3b49400 0000000000000004 0000000000000001 
[   55.272742] GPR24: 0000000000000001 0000000000000000 c0000007d44c75a0 0000000000480020 
[   55.272747] GPR28: 0000000000000000 c0000007d5a7cf38 c000000001a23d78 c0000007d5a7cf38 
[   55.272753] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.272754] LR [c000000000d803d8] _raw_spin_lock_irq+0xd8/0x110
[   55.272754] Call Trace:
[   55.272755] [c0000007d44c7420] [c000000000d803cc] _raw_spin_lock_irq+0xcc/0x110
[   55.272756] [c0000007d44c7460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.272757] [c0000007d44c74b0] [d0000000156536b4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.272758] [c0000007d44c7540] [c000000000a6fb60] dm_mq_queue_rq+0x120/0x6c0
[   55.272759] [c0000007d44c7600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.272759] [c0000007d44c76c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.272760] [c0000007d44c7730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.272761] [c0000007d44c7790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.272762] [c0000007d44c7820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.272766] [c0000007d44c7870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.272767] [c0000007d44c78b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.272769] [c0000007d44c7900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.272772] [c0000007d44c79a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.272773] [c0000007d44c7a20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.272774] [c0000007d44c7a40] [c000000000393060] read_pages+0xa0/0x280
[   55.272775] [c0000007d44c7ae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.272776] [c0000007d44c7bc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.272777] [c0000007d44c7c20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.272778] [c0000007d44c7ce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.272779] [c0000007d44c7d00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.272780] [c0000007d44c7d90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.272780] [c0000007d44c7de0] [c00000000049d564] ksys_read+0x64/0x110
[   55.272781] [c0000007d44c7e30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.272782] Instruction dump:
[   55.272784] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.272793] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
<class 'pexpect.exceptions.TIMEOUT'>" caused the system to go to UNKNOWN_BAD and the system will be stopping."

@sathnaga
Copy link
Author

sathnaga commented Nov 2, 2018

Again, I hit with above trace with 6a23e05c2fe3c64ec012fd81e51e3ab51e4f2f9f

UnknownStateTransition: Something happened system state="8" and we transitioned to UNKNOWN state.  Review the following for more details
Message="OpTestSystem in run_IPLing and Exception="Hard lockup (machine in state '5'): watchdog: CPU 30 detected hard LOCKUP on other CPUs 0
[   54.158854] watchdog: CPU 30 TB:77080881115, last SMP heartbeat TB:69380181751 (15040ms ago)
[   55.293571] watchdog: CPU 1 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.293577] watchdog: CPU 1 TB:75267453118, last heartbeat TB:69871699982 (10538ms ago)
[   55.293581] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.293609] irq event stamp: 15996
[   55.293611] hardirqs last  enabled at (15995): [<c000000000d807b8>] _raw_spin_unlock_irq+0x48/0x80
[   55.293615] hardirqs last disabled at (15996): [<c000000000d76acc>] __schedule+0x12c/0xf30
[   55.293618] softirqs last  enabled at (15026): [<c000000000d81b58>] __do_softirq+0x338/0x6b8
[   55.293621] softirqs last disabled at (15009): [<c000000000133e04>] irq_exit+0xe4/0x1a0
[   55.293624] CPU: 1 PID: 1733 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.293627] NIP:  c0000000001c9f60 LR: c000000000d80438 CTR: c0000000006feb90
[   55.293629] REGS: c0000007ffe83d80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.293631] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.293656] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.293661] GPR00: c000000000d80438 c0000007d20b73f0 c0000000019e7c00 c0000007d53c31a8 
[   55.293670] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.293678] GPR08: 0000000000000000 0000000080000000 0000000080000001 d000000015655cf0 
[   55.293683] GPR12: 0000000000004400 c0000007ffffee00 f000000001f3ae88 c0000007d0008e10 
[   55.293688] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d0008e08 
[   55.293693] GPR20: c000000001a242a4 c0000007d3cc8400 0000000000000004 0000000000000001 
[   55.293698] GPR24: 0000000000000001 0000000000000000 c0000007d20b75a0 0000000000480020 
[   55.293703] GPR28: 0000000000000000 c0000007d53c31a8 c000000001a23d78 c0000007d53c31a8 
[   55.293709] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.293710] LR [c000000000d80438] _raw_spin_lock_irq+0xd8/0x110
[   55.293711] Call Trace:
[   55.293713] [c0000007d20b7420] [c000000000d8042c] _raw_spin_lock_irq+0xcc/0x110
[   55.293715] [c0000007d20b7460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.293717] [c0000007d20b74b0] [d0000000156536d4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.293720] [c0000007d20b7540] [c000000000a6fbc0] dm_mq_queue_rq+0x120/0x6c0
[   55.293722] [c0000007d20b7600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.293724] [c0000007d20b76c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.293727] [c0000007d20b7730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.293729] [c0000007d20b7790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.293731] [c0000007d20b7820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.293733] [c0000007d20b7870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.293736] [c0000007d20b78b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.293738] [c0000007d20b7900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.293740] [c0000007d20b79a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.293743] [c0000007d20b7a20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.293745] [c0000007d20b7a40] [c000000000393060] read_pages+0xa0/0x280
[   55.293747] [c0000007d20b7ae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.293750] [c0000007d20b7bc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.293752] [c0000007d20b7c20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.293755] [c0000007d20b7ce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.293758] [c0000007d20b7d00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.293761] [c0000007d20b7d90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.293763] [c0000007d20b7de0] [c00000000049d564] ksys_read+0x64/0x110
[   55.293766] [c0000007d20b7e30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.293768] Instruction dump:
[   55.293771] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.293780] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.293806] watchdog: CPU 14 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.293807] watchdog: CPU 14 TB:75267453122, last heartbeat TB:69666900414 (10938ms ago)
[   55.293808] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.293816] irq event stamp: 10123
[   55.293818] hardirqs last  enabled at (10123): [<c00000000037f634>] bad_range+0x1a4/0x200
[   55.293820] hardirqs last disabled at (10122): [<c00000000037f50c>] bad_range+0x7c/0x200
[   55.293821] softirqs last  enabled at (9738): [<c000000000d81b58>] __do_softirq+0x338/0x6b8
[   55.293823] softirqs last disabled at (9733): [<c000000000133e04>] irq_exit+0xe4/0x1a0
[   55.293824] CPU: 14 PID: 1746 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.293826] NIP:  c0000000001c9f60 LR: c000000000d80438 CTR: c0000000006feb90
[   55.293827] REGS: c0000007ffde7d80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.293828] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.293838] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.293840] GPR00: c000000000d80438 c0000007d23673f0 c0000000019e7c00 c0000007d53c31a8 
[   55.293846] GPR04: c0000007d53c31c0 0000000000000001 c0000007d23673d0 0000000000000001 
[   55.293852] GPR08: 0000000000000000 0000000080000000 000000008000000e d000000015655cf0 
[   55.293858] GPR12: 0000000000004400 c0000007fffefd80 f000000001f3ae48 c0000007d0002210 
[   55.293863] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d0002208 
[   55.293868] GPR20: c000000001a242a4 c0000007d3cd2e00 0000000000000004 0000000000000001 
[   55.293874] GPR24: 0000000000000001 0000000000000000 c0000007d23675a0 0000000000480020 
[   55.293879] GPR28: 0000000000000000 c0000007d53c31a8 c000000001a23d78 c0000007d53c31a8 
[   55.293884] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.293886] LR [c000000000d80438] _raw_spin_lock_irq+0xd8/0x110
[   55.293887] Call Trace:
[   55.293888] [c0000007d2367420] [c000000000d8042c] _raw_spin_lock_irq+0xcc/0x110
[   55.293890] [c0000007d2367460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.293893] [c0000007d23674b0] [d0000000156536d4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.293895] [c0000007d2367540] [c000000000a6fbc0] dm_mq_queue_rq+0x120/0x6c0
[   55.293897] [c0000007d2367600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.293900] [c0000007d23676c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.293902] [c0000007d2367730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.293904] [c0000007d2367790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.293907] [c0000007d2367820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.293909] [c0000007d2367870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.293911] [c0000007d23678b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.293913] [c0000007d2367900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.293916] [c0000007d23679a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.293918] [c0000007d2367a20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.293920] [c0000007d2367a40] [c000000000393060] read_pages+0xa0/0x280
[   55.293922] [c0000007d2367ae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.293925] [c0000007d2367bc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.293927] [c0000007d2367c20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.293929] [c0000007d2367ce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.293931] [c0000007d2367d00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.293934] [c0000007d2367d90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.293936] [c0000007d2367de0] [c00000000049d564] ksys_read+0x64/0x110
[   55.293938] [c0000007d2367e30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.293940] Instruction dump:
[   55.293942] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.293949] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.293973] watchdog: CPU 32 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.293975] watchdog: CPU 32 TB:75267452690, last heartbeat TB:69912654061 (10458ms ago)
[   55.293976] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.293984] irq event stamp: 9012
[   55.293985] hardirqs last  enabled at (9011): [<c000000000d80734>] _raw_spin_unlock_irqrestore+0x94/0xd0
[   55.293987] hardirqs last disabled at (9012): [<c000000000d76acc>] __schedule+0x12c/0xf30
[   55.293988] softirqs last  enabled at (8072): [<c000000000d81b58>] __do_softirq+0x338/0x6b8
[   55.293990] softirqs last disabled at (8063): [<c000000000133e04>] irq_exit+0xe4/0x1a0
[   55.293991] CPU: 32 PID: 1744 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.293993] NIP:  c0000000001c9f60 LR: c000000000d80438 CTR: c0000000006feb90
[   55.293994] REGS: c0000007ffd0fd80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.293995] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.294005] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.294008] GPR00: c000000000d80438 c0000007d23773f0 c0000000019e7c00 c0000007d53c31a8 
[   55.294013] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.294018] GPR08: 0000000000000000 0000000080000000 0000000080000020 d000000015655cf0 
[   55.294023] GPR12: 0000000000004400 c0000007fffdb080 f000000001f3af48 c0000007d000ca10 
[   55.294029] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d000ca08 
[   55.294034] GPR20: c000000001a242a4 c0000007d3cd3000 0000000000000004 0000000000000001 
[   55.294039] GPR24: 0000000000000001 0000000000000000 c0000007d23775a0 0000000000480020 
[   55.294044] GPR28: 0000000000000000 c0000007d53c31a8 c000000001a23d78 c0000007d53c31a8 
[   55.294050] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.294051] LR [c000000000d80438] _raw_spin_lock_irq+0xd8/0x110
[   55.294052] Call Trace:
[   55.294054] [c0000007d2377420] [c000000000d8042c] _raw_spin_lock_irq+0xcc/0x110
[   55.294056] [c0000007d2377460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.294058] [c0000007d23774b0] [d0000000156536d4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.294061] [c0000007d2377540] [c000000000a6fbc0] dm_mq_queue_rq+0x120/0x6c0
[   55.294063] [c0000007d2377600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.294065] [c0000007d23776c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.294068] [c0000007d2377730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.294070] [c0000007d2377790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.294072] [c0000007d2377820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.294075] [c0000007d2377870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.294077] [c0000007d23778b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.294079] [c0000007d2377900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.294081] [c0000007d23779a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.294084] [c0000007d2377a20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.294086] [c0000007d2377a40] [c000000000393060] read_pages+0xa0/0x280
[   55.294088] [c0000007d2377ae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.294091] [c0000007d2377bc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.294093] [c0000007d2377c20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.294095] [c0000007d2377ce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.294097] [c0000007d2377d00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.294099] [c0000007d2377d90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.294102] [c0000007d2377de0] [c00000000049d564] ksys_read+0x64/0x110
[   55.294104] [c0000007d2377e30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.294106] Instruction dump:
[   55.294107] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.294115] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 
[   55.294125] watchdog: CPU 34 self-detected hard LOCKUP @ do_raw_spin_lock+0x140/0x230
[   55.294126] watchdog: CPU 34 TB:75267452632, last heartbeat TB:69871720453 (10538ms ago)
[   55.294127] Modules linked in: dm_service_time crc32c_vpmsum ipr dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua
[   55.294135] irq event stamp: 10047
[   55.294137] hardirqs last  enabled at (10047): [<c000000000d807b8>] _raw_spin_unlock_irq+0x48/0x80
[   55.294139] hardirqs last disabled at (10046): [<c000000000d8039c>] _raw_spin_lock_irq+0x3c/0x110
[   55.294140] softirqs last  enabled at (8904): [<c000000000b148e0>] peernet2id+0x60/0x80
[   55.294142] softirqs last disabled at (8902): [<c000000000b148b8>] peernet2id+0x38/0x80
[   55.294143] CPU: 34 PID: 1743 Comm: systemd-udevd Not tainted 4.19.0-rc7+ #1
[   55.294145] NIP:  c0000000001c9f60 LR: c000000000d80438 CTR: c0000000006feb90
[   55.294146] REGS: c0000007ffcf7d80 TRAP: 0900   Not tainted  (4.19.0-rc7+)
[   55.294147] MSR:  9000000000009033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: 24024844  XER: 00000000
[   55.294157] CFAR: c0000000001c9f84 IRQMASK: 1 
[   55.294159] GPR00: c000000000d80438 c0000007d230b3f0 c0000000019e7c00 c0000007d53c31a8 
[   55.294165] GPR04: c0000000006fece8 0000000000000000 0000000000000000 0000000000000001 
[   55.294170] GPR08: 0000000000000000 0000000080000000 0000000080000022 d000000015655cf0 
[   55.294175] GPR12: 0000000000004400 c0000007fffd8b80 f000000001f3ac48 c0000007d0003410 
[   55.294180] GPR16: c0000000003933d0 c000000000393350 c00000000193b06c c0000007d0003408 
[   55.294186] GPR20: c000000001a242a4 c0000007d3cdd800 0000000000000004 0000000000000001 
[   55.294191] GPR24: 0000000000000001 0000000000000000 c0000007d230b5a0 0000000000480020 
[   55.294196] GPR28: 0000000000000000 c0000007d53c31a8 c000000001a23d78 c0000007d53c31a8 
[   55.294202] NIP [c0000000001c9f60] do_raw_spin_lock+0x140/0x230
[   55.294203] LR [c000000000d80438] _raw_spin_lock_irq+0xd8/0x110
[   55.294204] Call Trace:
[   55.294205] [c0000007d230b420] [c000000000d8042c] _raw_spin_lock_irq+0xcc/0x110
[   55.294208] [c0000007d230b460] [c0000000006fece8] blk_get_request+0x158/0x260
[   55.294210] [c0000007d230b4b0] [d0000000156536d4] multipath_clone_and_map+0xbc/0x280 [dm_multipath]
[   55.294212] [c0000007d230b540] [c000000000a6fbc0] dm_mq_queue_rq+0x120/0x6c0
[   55.294215] [c0000007d230b600] [c000000000715f20] blk_mq_dispatch_rq_list+0x470/0x760
[   55.294217] [c0000007d230b6c0] [c00000000071c508] blk_mq_do_dispatch_sched+0x98/0x190
[   55.294219] [c0000007d230b730] [c00000000071d238] blk_mq_sched_dispatch_requests+0x148/0x230
[   55.294221] [c0000007d230b790] [c000000000712ecc] __blk_mq_run_hw_queue+0xcc/0x1e0
[   55.294224] [c0000007d230b820] [c000000000713268] __blk_mq_delay_run_hw_queue+0x288/0x2b0
[   55.294226] [c0000007d230b870] [c00000000071337c] blk_mq_run_hw_queue+0x9c/0x120
[   55.294228] [c0000007d230b8b0] [c00000000071d86c] blk_mq_sched_insert_requests+0xec/0x110
[   55.294231] [c0000007d230b900] [c000000000716b9c] blk_mq_flush_plug_list+0x22c/0x580
[   55.294233] [c0000007d230b9a0] [c000000000702dd4] blk_flush_plug_list+0x164/0x350
[   55.294235] [c0000007d230ba20] [c0000000007038e4] blk_finish_plug+0x34/0x50
[   55.294237] [c0000007d230ba40] [c000000000393060] read_pages+0xa0/0x280
[   55.294240] [c0000007d230bae0] [c0000000003934a0] __do_page_cache_readahead+0x260/0x400
[   55.294242] [c0000007d230bbc0] [c00000000039421c] force_page_cache_readahead+0xcc/0x1d0
[   55.294244] [c0000007d230bc20] [c000000000376654] generic_file_read_iter+0x584/0xc40
[   55.294247] [c0000007d230bce0] [c000000000508da0] blkdev_read_iter+0x50/0x80
[   55.294249] [c0000007d230bd00] [c00000000049cc34] __vfs_read+0x174/0x1d0
[   55.294251] [c0000007d230bd90] [c00000000049cd4c] vfs_read+0xbc/0x1a0
[   55.294253] [c0000007d230bde0] [c00000000049d564] ksys_read+0x64/0x110
[   55.294255] [c0000007d230be30] [c00000000000bbe4] system_call+0x5c/0x70
[   55.294257] Instruction dump:
[   55.294259] 2fa30000 409e00bc e8010040 7c0803a6 4bffff30 60000000 60000000 60000000 
[   55.294266] fbc10020 3fc20004 3bdec178 7c210b78 <e93e0000> 75290010 41820014 e92d0000 ```

@sathnaga
Copy link
Author

sathnaga commented Nov 2, 2018

now the bisect end unsuccessful with above two commit issues.

$ git bisect start

$ git bisect good 6080ad3a9941e4707bb929445b813fadca9a27ff

$ git bisect bad 71f4d95b23654ec2b347bd15b1260d68ca9ea5ea
Bisecting: 6 revisions left to test after this (roughly 3 steps)
[800a7340ab7dd667edf95e74d8e4f23a17e87076] dm ioctl: harden copy_params()'s copy_from_user() from malicious users

$ git bisect bad
Bisecting: 3 revisions left to test after this (roughly 2 steps)
[cef6f55a9fb4f6d6f9df0f772aa64cf159997466] dm table: require that request-based DM be layered on blk-mq devices

$ git bisect bad
Bisecting: 0 revisions left to test after this (roughly 1 step)
[953923c09fe83255ae11845db1c9eb576ba73df8] dm: rename DM_TYPE_MQ_REQUEST_BASED to DM_TYPE_REQUEST_BASED

$ git bisect skip
Bisecting: 1 revision left to test after this (roughly 1 step)
[6a23e05c2fe3c64ec012fd81e51e3ab51e4f2f9f] dm: remove legacy request-based IO path
You have new mail in /var/spool/mail/satheesh

$ git bisect skip
There are only 'skip'ped commits left to test.
The first bad commit could be any of:
6a23e05c2fe3c64ec012fd81e51e3ab51e4f2f9f
953923c09fe83255ae11845db1c9eb576ba73df8
cef6f55a9fb4f6d6f9df0f772aa64cf159997466
We cannot bisect more!

@sathnaga
Copy link
Author

sathnaga commented Nov 5, 2018

@mpe even the current merge 4e121c73d3f05cbd3af122f4bde181e56036d4da commit drops to dracut

[   41.767251] localhost kernel: sd 1:2:0:0: [sdc] 139466752 4096-byte logical blocks: (571 GB/532 GiB)
[   41.767307] localhost kernel: sd 1:2:1:0: [sdd] 2231484416 512-byte logical blocks: (1.14 TB/1.04 TiB)
[   41.767320] localhost kernel: sd 1:2:1:0: [sdd] 4096-byte physical blocks
[   41.767363] localhost kernel: sd 1:2:0:0: [sdc] Write Protect is off
[   41.767375] localhost kernel: sd 1:2:0:0: [sdc] Mode Sense: 0b 00 00 08
[   41.767425] localhost kernel: sd 1:2:1:0: [sdd] Write Protect is off
[   41.767438] localhost kernel: sd 1:2:1:0: [sdd] Mode Sense: 0b 00 00 08
[   41.886870] localhost kernel:  sda: sda1 sda2 sda3 sda4 < sda5 sda6 >
[   41.935668] localhost kernel: sd 0:2:0:0: [sda] Attached SCSI disk
[   41.955808] localhost kernel:  sdb: sdb1 sdb2 sdb3
[   41.955605] localhost multipathd[1344]: sda: fail to get serial
[   41.975531] localhost kernel: sd 1:2:0:0: [sdc] Cache data unavailable
[   41.975551] localhost kernel: sd 1:2:1:0: [sdd] Cache data unavailable
[   41.975556] localhost kernel: sd 1:2:0:0: [sdc] Assuming drive cache: write through
[   41.975563] localhost kernel: sd 1:2:1:0: [sdd] Assuming drive cache: write through
[   41.987016] localhost kernel: device-mapper: multipath service-time: version 0.3.0 loaded
[   41.975800] localhost multipathd[1344]: mpathb: failed in domap for addition of new path sda
[   41.975800] localhost multipathd[1344]: uevent trigger error
[   41.987715] localhost kernel: device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   41.987748] localhost kernel: device-mapper: table: unable to determine table type
[   42.005652] localhost kernel: sd 0:2:1:0: [sdb] Attached SCSI disk
[   42.217687] localhost kernel:  sdd: sdd1 sdd2 sdd3
[   42.219176] localhost kernel:  sdc: sdc1 sdc2 sdc3 sdc4 < sdc5 sdc6 >
[   42.241715] localhost kernel: sd 1:2:1:0: [sdd] Attached SCSI disk
[   42.243891] localhost kernel: sd 1:2:0:0: [sdc] Attached SCSI disk
[   43.263460] localhost multipathd[1344]: sdb: fail to get serial
[   43.268762] localhost multipathd[1344]: mpatha: failed in domap for addition of new path sdb
[   43.268762] localhost multipathd[1344]: uevent trigger error
[   43.282065] localhost kernel: device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.282096] localhost kernel: device-mapper: table: unable to determine table type
[   43.275898] localhost multipathd[1344]: sdd: fail to get serial
[   43.282597] localhost multipathd[1344]: mpatha: failed in domap for addition of new path sdd
[   43.282642] localhost multipathd[1344]: uevent trigger error
[   43.286540] localhost multipathd[1344]: sdc: fail to get serial
[   43.296366] localhost kernel: device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.296392] localhost kernel: device-mapper: table: unable to determine table type
[   43.292218] localhost multipathd[1344]: mpathb: failed in domap for addition of new path sdc
[   43.292218] localhost multipathd[1344]: uevent trigger error
[   43.306193] localhost kernel: device-mapper: table: table load rejected: not all devices are blk-mq request-stackable
[   43.306212] localhost kernel: device-mapper: table: unable to determine table type
[  150.523303] localhost dracut-initqueue[1325]: Warning: dracut-initqueue timeout - starting timeout scripts
[  151.163482] localhost dracut-initqueue[1325]: Warning: dracut-initqueue timeout - starting timeout scripts
[  151.773044] localhost dracut-initqueue[1325]: Warning: dracut-initqueue timeout - starting timeout scripts

0
[console-expect]#2018-11-05 14:40:36,479:op-test.common.OpTestSystem:run_POWERING_OFF:INFO:System is in standby/Soft-off state
   1 | 11/05/2018 | 09:10:26 | System Event #0x65 | Transition to Power Off | Asserted
ERROR (1396.015s)

======================================================================
ERROR [1396.015s]: runTest (testcases.InstallUpstreamKernel.InstallUpstreamKernel)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/jenkins/workspace/kvmci/testcases/InstallUpstreamKernel.py", line 112, in runTest
    self.cv_SYSTEM.goto_state(OpSystemState.OS)
  File "/home/jenkins/workspace/kvmci/common/OpTestSystem.py", line 353, in goto_state
    self.state = self.stateHandlers[self.state](state)
  File "/home/jenkins/workspace/kvmci/common/OpTestSystem.py", line 733, in run_BOOTING
    raise my_exception
UnknownStateTransition: Something happened system state="8" and we transitioned to UNKNOWN state.  Review the following for more details
Message="OpTestSystem in run_IPLing and Exception="Something unexpected happened in State="8" Review the following for more details
Message="We hit the dracut_callback value=dracut:/#, manually restart the system
"" caused the system to go to UNKNOWN_BAD and the system will be stopping."

----------------------------------------------------------------------
Ran 1 test in 1396.015s

FAILED (errors=1)```

@mpe
Copy link
Member

mpe commented Nov 5, 2018 

# lsblk
NAME                             MAJ:MIN RM  SIZE RO TYPE  MOUNTPOINT
sda                                8:0    0  532G  0 disk  
└─mpathb                         253:0    0  532G  0 mpath 
  ├─mpathb1                      253:3    0    4M  0 part  
  ├─mpathb2                      253:6    0    1G  0 part  
  ├─mpathb3                      253:7    0    4G  0 part  
  ├─mpathb4                      253:8    0    4K  0 part  
  ├─mpathb5                      253:9    0   50G  0 part  
  └─mpathb6                      253:10   0  477G  0 part  
sdb                                8:16   0    1T  0 disk  
└─mpatha                         253:1    0    1T  0 mpath 
  ├─mpatha1                      253:2    0    4M  0 part  
  ├─mpatha2                      253:4    0    1G  0 part  /boot
  └─mpatha3                      253:5    0    1T  0 part  
    ├─fedora_ltc--test--ci2-root 253:11   0   50G  0 lvm   /
    ├─fedora_ltc--test--ci2-swap 253:12   0    4G  0 lvm   [SWAP]
    └─fedora_ltc--test--ci2-home 253:13   0 1009G  0 lvm   /home
sdc                                8:32   0  532G  0 disk  
└─mpathb                         253:0    0  532G  0 mpath 
  ├─mpathb1                      253:3    0    4M  0 part  
  ├─mpathb2                      253:6    0    1G  0 part  
  ├─mpathb3                      253:7    0    4G  0 part  
  ├─mpathb4                      253:8    0    4K  0 part  
  ├─mpathb5                      253:9    0   50G  0 part  
  └─mpathb6                      253:10   0  477G  0 part  
sdd                                8:48   0    1T  0 disk  
└─mpatha                         253:1    0    1T  0 mpath 
  ├─mpatha1                      253:2    0    4M  0 part  
  ├─mpatha2                      253:4    0    1G  0 part  /boot
  └─mpatha3                      253:5    0    1T  0 part  
    ├─fedora_ltc--test--ci2-root 253:11   0   50G  0 lvm   /
    ├─fedora_ltc--test--ci2-swap 253:12   0    4G  0 lvm   [SWAP]
    └─fedora_ltc--test--ci2-home 253:13   0 1009G  0 lvm   /home

@sathnaga
Copy link
Author

sathnaga commented Nov 5, 2018

with same kernel config(https://github.com/linuxppc/linux/files/2548075/config-4.19.0-0.rc5.git3.1.fc30.ppc64le.txt) and same kernel commit 4e121c73d3f05cbd3af122f4bde181e56036d4da used, another Power 8 box boots fine,

# uname -a
Linux x.x.x.x 4.20.0-rc1+ #1 SMP Mon Nov 5 05:24:30 EST 2018 ppc64le ppc64le ppc64le GNU/Linux
# lsblk
NAME              MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
sda                 8:0    0  130G  0 disk 
├─sda1              8:1    0    4M  0 part 
├─sda2              8:2    0    1G  0 part /boot
└─sda3              8:3    0  129G  0 part 
  ├─fedora_9-root 253:0    0  100G  0 lvm  /
  └─fedora_9-swap 253:1    0   13G  0 lvm  [SWAP]

# cat /etc/os-release 
NAME=Fedora
VERSION="28 (Twenty Eight)"
ID=fedora
VERSION_ID=28
PLATFORM_ID="platform:f28"

@mpe
Copy link
Member

mpe commented Nov 12, 2018

This a config problem, the kernel needs to be built with CONFIG_SCSI_MQ_DEFAULT.

https://lore.kernel.org/lkml/20181105135157.GA11485@redhat.com/

@mpe mpe closed this as completed Nov 12, 2018
@mpe mpe transferred this issue from linuxppc/linux Jan 7, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
linuxppc backlog
Status: ✅ Done
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mpe @sathnaga