On 18/02/2018 18:02, Laurence Oberman wrote: > 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 Hi Laurence, Yep, reverting it fixes the issue. > > Thanks > Laurence > Mark
