On Sun, 2018-02-18 at 17:03 +0200, Mark Bloch wrote: > Hi, > > Trying to boot 4.16-rc1 I'm hitting this: > > [ 68.600133] hpsa 0000:02:00.0: scsi 2:1:0:0: resetting > logical Direct-Access HP LOGICAL VOLUME RAID-0 > SSDSmartPathCap- En- Exp=1 > [ 97.391584] systemd-udevd[361]: seq 3310 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda7' is taking a long time > [ 97.464708] systemd-udevd[361]: seq 3308 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda5' is taking a long time > [ 97.529588] systemd-udevd[361]: seq 3307 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda2' is taking a long time > [ 97.594326] systemd-udevd[361]: seq 3306 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda1' is taking a long time > [ 97.661573] systemd-udevd[361]: seq 3309 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda6' is taking a long time > [ 217.391581] systemd-udevd[361]: seq 3306 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda1' killed > [ 217.456892] systemd-udevd[361]: seq 3308 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda5' killed > [ 217.519926] systemd-udevd[361]: seq 3310 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda7' killed > [ 217.579005] systemd-udevd[361]: seq 3307 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda2' killed > [ 217.638554] systemd-udevd[361]: seq 3309 > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda6' killed > [ 217.697731] systemd-udevd[361]: worker [392] terminated by signal > 9 > (Killed) > > [ 217.731567] systemd-udevd[361]: worker [392] failed while handling > '/devices/pci0000:00/0000:00:02.2/0000:02:00.0/host2/target2:1:0/2:1: > 0:0/block/sda/sda1' > [ 242.652048] INFO: task scsi_eh_2:405 blocked for more than 120 > seconds. > > [ 242.687059] Not tainted 4.16.0-rc1+ > #20 > > [ 242.710430] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 242.748217] scsi_eh_2 D 0 405 2 > 0x80000000 > > [ 242.776101] Call > Trace: > > [ 242.789343] ? > __schedule+0x3cb/0x850 > > > [ 242.808664] schedule+0x32/0x80 > > > [ 242.824328] hpsa_eh_device_reset_handler+0x6b2/0x720 > [hpsa] > > [ 242.851889] ? > wait_woken+0x80/0x80 > > > [ 242.870089] scsi_eh_ready_devs+0x35a/0xc10 > > > [ 242.890486] ? > __pm_runtime_resume+0x54/0x70 > > > [ 242.911263] scsi_error_handler+0x4dc/0x5d0 > > > [ 242.931646] kthread+0xf5/0x130 > > > [ 242.947270] ? > scsi_eh_get_sense+0x210/0x210 > > > [ 242.968063] ? > kthread_create_worker_on_cpu+0x70/0x70 > > > [ 242.992494] ret_from_fork+0x35/0x40 > > > [ 363.484028] INFO: task systemd-udevd:379 blocked for more than 120 > seconds. > > [ 363.521118] Not tainted 4.16.0-rc1+ > #20 > > [ 363.545331] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 363.583333] systemd-udevd D 0 379 361 > 0x80000006 > > [ 363.609509] Call > Trace: > > [ 363.621716] ? > __schedule+0x3cb/0x850 > > > [ 363.639944] schedule+0x32/0x80 > > > [ 363.655934] io_schedule+0x12/0x40 > > > [ 363.672515] __lock_page+0xfb/0x140 > > > [ 363.689496] ? > page_cache_tree_insert+0xe0/0xe0 > > > [ 363.711315] truncate_inode_pages_range+0x4ef/0x880 > > > [ 363.734728] ? > select_task_rq_fair+0x4b3/0xc10 > > > [ 363.756522] ? > find_get_pages_range_tag+0x189/0x240 > > > [ 363.779725] ? > show_free_areas+0x461/0x900 > > > [ 363.799331] ? > pagevec_lookup_range_tag+0x24/0x30 > > > [ 363.821747] ? > __filemap_fdatawait_range+0x7d/0x130 > > > [ 363.844956] ? > cpumask_next_and+0x1a/0x20 > > > [ 363.864801] ? > smp_call_function_many+0x5b/0x250 > > > [ 363.887130] ? > __brelse+0x20/0x20 > > > [ 363.903152] ? > __brelse+0x20/0x20 > > > [ 363.919106] ? > on_each_cpu_mask+0x23/0x60 > > > [ 363.938325] ? > proc_ns_fget+0x40/0x40 > > > [ 363.955719] ? > on_each_cpu_cond+0xb2/0x140 > > > [ 363.975129] __blkdev_put+0x76/0x200 > > > [ 363.992096] ? > disk_flush_events+0x5c/0x60 > > > [ 364.012562] blkdev_close+0x21/0x30 > > > [ 364.029730] __fput+0xd5/0x210 > > > [ 364.045169] task_work_run+0x84/0xa0 > > > [ 364.062456] do_exit+0x2e0/0xae0 > > > [ 364.079953] ? > touch_atime+0xc1/0xd0 > > > [ 364.098231] do_group_exit+0x3a/0xa0 > > > [ 364.116796] get_signal+0x29b/0x610 > > > [ 364.134796] do_signal+0x36/0x6a0 > > > [ 364.151819] ? > vfs_read+0x91/0x130 > > > [ 364.167945] exit_to_usermode_loop+0x88/0xc0 > > > [ 364.188401] do_syscall_64+0xe7/0x120 > > > [ 364.205569] entry_SYSCALL_64_after_hwframe+0x21/0x86 > > > [ 364.229235] RIP: > 0033:0x7f332b31f6d0 > > [ 364.246045] RSP: 002b:00007ffff0bce8e8 EFLAGS: 00000246 ORIG_RAX: > 0000000000000000 > > [ 364.281274] RAX: fffffffffffffffc RBX: 0000559be683fb10 RCX: > 00007f332b31f6d0 > > [ 364.314540] RDX: 0000000000000400 RSI: 0000559be683fb38 RDI: > 000000000000000d > > [ 364.347939] RBP: 0000559be6835cd0 R08: 00007f332b309ee8 R09: > 0000000000000000 > > [ 364.381191] R10: 000000000000006b R11: 0000000000000246 R12: > 0000000000000000 > > [ 364.414513] R13: 0000000000000400 R14: 0000559be6835d20 R15: > 0000000000000400 > > [ 364.450149] INFO: task systemd-udevd:383 blocked for more than 120 > seconds. > > [ 364.484411] Not tainted 4.16.0-rc1+ > #20 > > [ 364.504947] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 364.541386] systemd-udevd D 0 383 361 > 0x80000006 > > [ 364.567293] Call > Trace: > > [ 364.578993] ? > __schedule+0x3cb/0x850 > > > [ 364.597658] schedule+0x32/0x80 > > > [ 364.614136] io_schedule+0x12/0x40 > > > [ 364.631998] __lock_page+0xfb/0x140 > > > [ 364.650190] ? > page_cache_tree_insert+0xe0/0xe0 > > > [ 364.674101] truncate_inode_pages_range+0x4ef/0x880 > > > [ 364.696914] ? > select_task_rq_fair+0x4b3/0xc10 > > > [ 364.717758] ? > find_get_pages_range_tag+0x189/0x240 > > > [ 364.740645] ? > show_free_areas+0x461/0x900 > > > [ 364.760003] ? > pagevec_lookup_range_tag+0x24/0x30 > > > [ 364.782208] ? > __filemap_fdatawait_range+0x7d/0x130 > > > [ 364.805078] ? > cpumask_next_and+0x1a/0x20 > > > [ 364.823888] ? > smp_call_function_many+0x5b/0x250 > > > [ 364.845497] ? > __brelse+0x20/0x20 > > > [ 364.861105] ? > __brelse+0x20/0x20 > > > [ 364.876728] ? > on_each_cpu_mask+0x23/0x60 > > > [ 364.896769] ? > proc_ns_fget+0x40/0x40 > > > [ 364.914174] ? > on_each_cpu_cond+0xb2/0x140 > > > [ 364.933370] __blkdev_put+0x76/0x200 > > > [ 364.950209] ? > disk_flush_events+0x5c/0x60 > > > [ 364.969419] blkdev_close+0x21/0x30 > > > [ 364.985873] __fput+0xd5/0x210 > > > [ 365.000261] task_work_run+0x84/0xa0 > > > [ 365.017090] do_exit+0x2e0/0xae0 > > > [ 365.032296] ? > touch_atime+0xc1/0xd0 > > > [ 365.049108] do_group_exit+0x3a/0xa0 > > > [ 365.066216] get_signal+0x29b/0x610 > > > [ 365.083800] do_signal+0x36/0x6a0 > > > [ 365.100525] ? > vfs_read+0x91/0x130 > > > [ 365.118129] exit_to_usermode_loop+0x88/0xc0 > > > [ 365.140427] do_syscall_64+0xe7/0x120 > > > [ 365.159571] entry_SYSCALL_64_after_hwframe+0x21/0x86 > > > [ 365.185726] RIP: > 0033:0x7f332b31f6d0 > > [ 365.204122] RSP: 002b:00007ffff0bce918 EFLAGS: 00000246 ORIG_RAX: > 0000000000000000 > > [ 365.241380] RAX: fffffffffffffffc RBX: 0000559be683fba0 RCX: > 00007f332b31f6d0 > > [ 365.274783] RDX: 0000000000000040 RSI: 0000559be683fbc8 RDI: > 000000000000000d > > [ 365.308016] RBP: 0000559be683fc50 R08: 00007f332b30a148 R09: > 0000000000000070 > > [ 365.341263] R10: 000000000000006b R11: 0000000000000246 R12: > 00000000772f0000 > > [ 365.374685] R13: 00000000772f0040 R14: 0000559be683fca0 R15: > 0000000000000040 > > [ 365.407915] INFO: task systemd-udevd:387 blocked for more than 120 > seconds. > > [ 365.447179] Not tainted 4.16.0-rc1+ > #20 > > [ 365.467796] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 365.504458] systemd-udevd D 0 387 361 > 0x80000006 > > [ 365.530259] Call > Trace: > > [ 365.541876] ? > __schedule+0x3cb/0x850 > > > [ 365.559052] schedule+0x32/0x80 > > > [ 365.573895] io_schedule+0x12/0x40 > > > [ 365.589900] __lock_page+0xfb/0x140 > > > [ 365.606318] ? > page_cache_tree_insert+0xe0/0xe0 > > > [ 365.627558] truncate_inode_pages_range+0x4ef/0x880 > > > [ 365.650815] ? > select_task_rq_fair+0x4b3/0xc10 > > > [ 365.673259] ? > find_get_pages_range_tag+0x189/0x240 > > > [ 365.698674] ? > show_free_areas+0x461/0x900 > > > [ 365.720046] ? > pagevec_lookup_range_tag+0x24/0x30 > > > [ 365.742103] ? > __filemap_fdatawait_range+0x7d/0x130 > > > [ 365.765514] ? > cpumask_next_and+0x1a/0x20 > > > [ 365.784341] ? > smp_call_function_many+0x5b/0x250 > > > [ 365.805952] ? > __brelse+0x20/0x20 > > > [ 365.821575] ? > __brelse+0x20/0x20 > > > [ 365.837174] ? > on_each_cpu_mask+0x23/0x60 > > > [ 365.855979] ? > proc_ns_fget+0x40/0x40 > > > [ 365.873223] ? > on_each_cpu_cond+0xb2/0x140 > > > [ 365.892436] __blkdev_put+0x76/0x200 > > > [ 365.910691] ? > disk_flush_events+0x5c/0x60 > > > [ 365.930074] blkdev_close+0x21/0x30 > > > [ 365.946488] __fput+0xd5/0x210 > > > [ 365.960952] task_work_run+0x84/0xa0 > > > [ 365.977945] do_exit+0x2e0/0xae0 > > > [ 365.993173] ? > touch_atime+0xc1/0xd0 > > > [ 366.009982] do_group_exit+0x3a/0xa0 > > > [ 366.026783] get_signal+0x29b/0x610 > > > [ 366.043198] do_signal+0x36/0x6a0 > > > [ 366.058814] ? > vfs_read+0x91/0x130 > > > [ 366.074833] exit_to_usermode_loop+0x88/0xc0 > > > [ 366.094861] do_syscall_64+0xe7/0x120 > > > [ 366.112088] entry_SYSCALL_64_after_hwframe+0x21/0x86 > > > [ 366.137357] RIP: > 0033:0x7f332b31f6d0 > > [ 366.155255] RSP: 002b:00007ffff0bce868 EFLAGS: 00000246 ORIG_RAX: > 0000000000000000 > > [ 366.201501] RAX: fffffffffffffffc RBX: 0000559be6836040 RCX: > 00007f332b31f6d0 > > [ 366.238422] RDX: 0000000000000040 RSI: 0000559be6836068 RDI: > 000000000000000d > > [ 366.275081] RBP: 0000559be683fcb0 R08: 00007f332b30a128 R09: > 0000000000000070 > > [ 366.308324] R10: 000000000000006b R11: 0000000000000246 R12: > 0000000a7a1f0000 > > [ 366.341360] R13: 0000000a7a1f0040 R14: 0000559be683fd00 R15: > 0000000000000040 > > [ 366.374789] INFO: task systemd-udevd:402 blocked for more than 120 > seconds. > > [ 366.407232] Not tainted 4.16.0-rc1+ > #20 > > [ 366.427637] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 366.464095] systemd-udevd D 0 402 361 > 0x80000006 > > [ 366.489925] Call > Trace: > > [ 366.501537] ? > __schedule+0x3cb/0x850 > > > [ 366.518933] schedule+0x32/0x80 > > > [ 366.535436] io_schedule+0x12/0x40 > > > [ 366.552261] __lock_page+0xfb/0x140 > > > [ 366.569671] ? > page_cache_tree_insert+0xe0/0xe0 > > > [ 366.591036] truncate_inode_pages_range+0x4ef/0x880 > > > [ 366.613648] ? > select_task_rq_fair+0x4b3/0xc10 > > > [ 366.634697] ? > find_get_pages_range_tag+0x189/0x240 > > > [ 366.657686] ? > show_free_areas+0x461/0x900 > > > [ 366.676903] ? > pagevec_lookup_range_tag+0x24/0x30 > > > [ 366.698918] ? > __filemap_fdatawait_range+0x7d/0x130 > > > [ 366.723657] ? > cpumask_next_and+0x1a/0x20 > > > [ 366.744559] ? > smp_call_function_many+0x5b/0x250 > > > [ 366.769116] ? > __brelse+0x20/0x20 > > > [ 366.786240] ? > __brelse+0x20/0x20 > > > [ 366.801838] ? > on_each_cpu_mask+0x23/0x60 > > > [ 366.820652] ? > proc_ns_fget+0x40/0x40 > > > [ 366.837871] ? > on_each_cpu_cond+0xb2/0x140 > > > [ 366.857074] __blkdev_put+0x76/0x200 > > > [ 366.873914] ? > disk_flush_events+0x5c/0x60 > > > [ 366.893340] blkdev_close+0x21/0x30 > > > [ 366.909954] __fput+0xd5/0x210 > > > [ 366.924823] task_work_run+0x84/0xa0 > > > [ 366.942276] do_exit+0x2e0/0xae0 > > > [ 366.957594] ? > touch_atime+0xc1/0xd0 > > > [ 366.974420] do_group_exit+0x3a/0xa0 > > > [ 366.991233] get_signal+0x29b/0x610 > > > [ 367.007710] do_signal+0x36/0x6a0 > > > [ 367.023499] ? > vfs_read+0x91/0x130 > > > [ 367.039482] exit_to_usermode_loop+0x88/0xc0 > > > [ 367.059507] do_syscall_64+0xe7/0x120 > > > [ 367.076718] entry_SYSCALL_64_after_hwframe+0x21/0x86 > > > [ 367.100443] RIP: > 0033:0x7f332b31f6d0 > > [ 367.117380] RSP: 002b:00007ffff0bce918 EFLAGS: 00000246 ORIG_RAX: > 0000000000000000 > > [ 367.152690] RAX: fffffffffffffffc RBX: 0000559be68677a0 RCX: > 00007f332b31f6d0 > > [ 367.187303] RDX: 0000000000000040 RSI: 0000559be68677c8 RDI: > 000000000000000e > > [ 367.223247] RBP: 0000559be6867660 R08: 00007f332b30a2c8 R09: > 0000000000000070 > > [ 367.260423] R10: 000000000000006b R11: 0000000000000246 R12: > 000000804e2f0000 > > [ 367.297417] R13: 000000804e2f0040 R14: 0000559be68676b0 R15: > 0000000000000040 > > [ 367.330436] INFO: task scsi_eh_2:405 blocked for more than 120 > seconds. > > [ 367.361467] Not tainted 4.16.0-rc1+ > #20 > > [ 367.381702] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this > message. > > [ 367.418428] scsi_eh_2 D 0 405 2 > 0x80000000 > > [ 367.444172] Call > Trace: > > [ 367.455964] ? > __schedule+0x3cb/0x850 > > > [ 367.473156] schedule+0x32/0x80 > > > [ 367.487976] hpsa_eh_device_reset_handler+0x6b2/0x720 > [hpsa] > > [ 367.514412] ? > wait_woken+0x80/0x80 > > > [ 367.530819] scsi_eh_ready_devs+0x35a/0xc10 > > > [ 367.550454] ? > __pm_runtime_resume+0x54/0x70 > > > [ 367.570472] scsi_error_handler+0x4dc/0x5d0 > > > [ 367.590109] kthread+0xf5/0x130 > [ 367.604912] ? scsi_eh_get_sense+0x210/0x210 > [ 367.624934] ? kthread_create_worker_on_cpu+0x70/0x70 > [ 367.648558] ret_from_fork+0x35/0x40 > [ 367.665362] INFO: task kworker/u130:1:413 blocked for more than > 120 seconds. > [ 367.697847] Not tainted 4.16.0-rc1+ #20 > [ 367.718529] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" > disables this message. > [ 367.758398] kworker/u130:1 D 0 413 2 0x80000000 > [ 367.787859] Workqueue: events_freezable_power_ disk_events_workfn > [ 367.824862] Call Trace: > [ 367.837554] ? __schedule+0x3cb/0x850 > [ 367.859785] ? __slab_free+0x11c/0x330 > [ 367.881283] schedule+0x32/0x80 > [ 367.898395] scsi_block_when_processing_errors+0xd4/0x110 > [ 367.925576] ? wait_woken+0x80/0x80 > [ 367.942277] sd_check_events+0xe6/0x1a0 > [ 367.961470] disk_check_events+0x63/0x150 > [ 367.980183] process_one_work+0x1e3/0x3c0 > [ 367.999215] worker_thread+0x4a/0x410 > [ 368.016884] kthread+0xf5/0x130 > [ 368.031813] ? rescuer_thread+0x380/0x380 > [ 368.050844] ? kthread_create_worker_on_cpu+0x70/0x70 > [ 368.074696] ? kthread_create_worker_on_cpu+0x70/0x70 > [ 368.098503] ret_from_fork+0x35/0x40 > > > On the same machine 4.15 works without issues, the server is ProLiant > DL380p Gen8, > I believe the smart array is P420i. if any additional information > is needed I'm more than happy to provide it. > > Mark > Hi Mark Can you try please revert this commit and see if it works. commit 84676c1f21e8ff54befe985f4f14dc1edc10046b Thanks Laurence
