testcase ======== original kernel :: latest cosmic version: ---------------------------------------- $ uname -rv 4.18.0-18-generic #19-Ubuntu SMP Tue Apr 2 18:13:16 UTC 2019 [ 654.491029] kprobe_test: loading out-of-tree module taints kernel. [ 654.493322] kprobe_test: module verification failed: signature and/or required key missing - tainting kernel [ 654.497033] mod_init():158 :: hello [ 654.497976] mod_init():183 :: kernel version: orig/-18/cosmic [ 694.254271] Program running, TID = 3292 [ 694.256600] kp1_pre_handler():070 :: state 0 .... :: pid = 3292, mapping = 0xffff962333263730, comm = 'test' [ 694.260870] kp1_pre_handler():079 :: state 0 -> 1 :: pid = 3292, mapping = 0xffff962333263730 [ 694.262710] kp2_pre_handler():119 :: state 1 .... :: pid = 3292, page index = 1 [ 694.264264] kp3_pre_handler():144 :: state 1 .... :: pid = 3292, page index = 1, calling writepage() [ 694.266641] kp2_pre_handler():119 :: state 1 .... :: pid = 3292, page index = 2 [ 694.268456] kp3_pre_handler():144 :: state 1 .... :: pid = 3292, page index = 2, calling writepage() [ 695.276320] Thread 0 running, TID = 3293! [ 695.281210] kp1_pre_handler():070 :: state 1 .... :: pid = 1165, mapping = 0xffff962333263730, comm = 'kworker/u4:2' [ 695.299026] kp1_pre_handler():101 :: state 1 -> 2 :: pid = 1165, mapping = 0xffff962333263730, comm ('kworker/u4:2') is kworker AND wbc->range_cyclic (0x1) is true AND mapping->writeback_index (0x2) is 0x2. [ 695.314808] kp2_pre_handler():119 :: state 2 .... :: pid = 1165, page index = 2 [ 695.322822] kp3_pre_handler():144 :: state 2 .... :: pid = 1165, page index = 2, calling writepage() [ 695.330308] kp2_pre_handler():119 :: state 2 .... :: pid = 1165, page index = 1 [ 695.334355] kp2_pre_handler():123 :: state 2 -> 3 :: pid = 1165, page index = 1, spin 5 seconds before lock_page()... [ 696.283747] Thread 1 running, TID = 3295! [ 696.284623] kp1_pre_handler():070 :: state 3 .... :: pid = 3295, mapping = 0xffff962333263730, comm = 'test' [ 696.286726] kp2_pre_handler():119 :: state 3 .... :: pid = 3295, page index = 1 [ 696.288392] kp3_pre_handler():144 :: state 3 .... :: pid = 3295, page index = 1, calling writepage() [ 696.290018] kp2_pre_handler():119 :: state 3 .... :: pid = 3295, page index = 2 [ 697.283941] Thread 2 running, TID = 3296! [ 697.284859] kp1_pre_handler():070 :: state 3 .... :: pid = 3296, mapping = 0xffff962333263730, comm = 'test' [ 697.287246] kp2_pre_handler():119 :: state 3 .... :: pid = 3296, page index = 1 [ 700.302756] kp2_pre_handler():127 :: state 3 -> 4 :: pid = 1165, page index = 1, spun 5 seconds before lock_page(). [ 715.716717] INFO: task kworker/u4:2:1165 blocked for more than 10 seconds. [ 715.725486] Tainted: G OE 4.18.0-18-generic #19-Ubuntu [ 715.732832] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 715.740500] kworker/u4:2 D 0 1165 2 0x80000000 [ 715.745615] Workqueue: writeback wb_workfn (flush-7:1) [ 715.750736] Call Trace: [ 715.753270] __schedule+0x29e/0x840 [ 715.756493] schedule+0x2c/0x80 [ 715.759369] io_schedule+0x16/0x40 [ 715.762044] __lock_page+0x101/0x150 [ 715.764729] ? page_cache_tree_insert+0xe0/0xe0 [ 715.773625] write_cache_pages+0x283/0x4e0 [ 715.782547] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.792525] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.798175] ? write_cache_pages+0x5/0x4e0 [ 715.803180] xfs_vm_writepages+0x6b/0xa0 [xfs] [ 715.807087] do_writepages+0x41/0xd0 [ 715.810416] __writeback_single_inode+0x40/0x360 [ 715.813588] ? fprop_fraction_percpu+0x26/0x80 [ 715.816686] writeback_sb_inodes+0x211/0x520 [ 715.819584] __writeback_inodes_wb+0x67/0xb0 [ 715.822661] wb_writeback+0x25f/0x2f0 [ 715.824963] ? get_nr_dirty_inodes+0x46/0x70 [ 715.827180] wb_workfn+0x175/0x3f0 [ 715.829225] process_one_work+0x20f/0x410 [ 715.830964] worker_thread+0x34/0x400 [ 715.832646] kthread+0x120/0x140 [ 715.834551] ? pwq_unbound_release_workfn+0xd0/0xd0 [ 715.836902] ? kthread_bind+0x40/0x40 [ 715.838772] ret_from_fork+0x35/0x40 [ 715.840579] INFO: task test:3293 blocked for more than 10 seconds. [ 715.842927] Tainted: G OE 4.18.0-18-generic #19-Ubuntu [ 715.845279] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 715.847771] test D 0 3293 3291 0x00000000 [ 715.849826] Call Trace: [ 715.851266] __schedule+0x29e/0x840 [ 715.853289] schedule+0x2c/0x80 [ 715.855069] wb_wait_for_completion+0x64/0x90 [ 715.857179] ? wait_woken+0x80/0x80 [ 715.858973] sync_inodes_sb+0xc7/0x290 [ 715.860754] sync_inodes_one_sb+0x15/0x20 [ 715.862383] iterate_supers+0xaa/0x100 [ 715.863938] ? default_file_splice_write+0x30/0x30 [ 715.865666] ksys_sync+0x42/0xb0 [ 715.867082] __ia32_sys_sync+0xe/0x20 [ 715.869122] do_syscall_64+0x5a/0x110 [ 715.871041] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 715.872974] RIP: 0033:0x7f571c1d5287 [ 715.874414] Code: Bad RIP value. [ 715.875746] RSP: 002b:00007f571c0bced8 EFLAGS: 00000217 ORIG_RAX: 00000000000000a2 [ 715.877851] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f571c1d5287 [ 715.880027] RDX: 000000000000000b RSI: 000055eee9f43f48 RDI: 0000000000000000 [ 715.882158] RBP: 00007f571c0bcef0 R08: 0000000000000000 R09: 0000000000000000 [ 715.884884] R10: 0000000000000000 R11: 0000000000000217 R12: 00007f571c0bcfc0 [ 715.887568] R13: 0000000000000000 R14: 0000000000000000 R15: 00007ffc53c52020 [ 715.890129] INFO: task test:3295 blocked for more than 10 seconds. [ 715.892430] Tainted: G OE 4.18.0-18-generic #19-Ubuntu [ 715.894823] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 715.897474] test D 0 3295 3291 0x00000000 [ 715.899546] Call Trace: [ 715.901264] __schedule+0x29e/0x840 [ 715.903339] ? kp2_pre_handler.cold.1+0x33/0xd7 [kprobe_test] [ 715.905540] schedule+0x2c/0x80 [ 715.907029] io_schedule+0x16/0x40 [ 715.908846] wait_on_page_bit+0xf7/0x140 [ 715.910379] ? page_cache_tree_insert+0xe0/0xe0 [ 715.911952] write_cache_pages+0x3ec/0x4e0 [ 715.913511] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.915821] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.918031] ? write_cache_pages+0x5/0x4e0 [ 715.919799] xfs_vm_writepages+0x6b/0xa0 [xfs] [ 715.921751] do_writepages+0x41/0xd0 [ 715.923322] ? iomap_file_buffered_write+0x6e/0xa0 [ 715.925086] ? iomap_dirty_actor+0x220/0x220 [ 715.926871] ? xfs_iunlock+0xf8/0x100 [xfs] [ 715.928506] __filemap_fdatawrite_range+0xc5/0x100 [ 715.930294] file_write_and_wait_range+0x5a/0xb0 [ 715.932318] xfs_file_fsync+0x5f/0x230 [xfs] [ 715.934120] vfs_fsync_range+0x48/0x80 [ 715.935814] ? __fget_light+0x54/0x60 [ 715.937488] do_fsync+0x3d/0x70 [ 715.938920] __x64_sys_fsync+0x14/0x20 [ 715.940507] do_syscall_64+0x5a/0x110 [ 715.942050] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 715.943793] RIP: 0033:0x7f571c4c0b07 [ 715.945345] Code: Bad RIP value. [ 715.946757] RSP: 002b:00007f571b8bbec0 EFLAGS: 00000293 ORIG_RAX: 000000000000004a [ 715.949159] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f571c4c0b07 [ 715.951646] RDX: 0000000000000000 RSI: 000055eee9f43f48 RDI: 0000000000000003 [ 715.954258] RBP: 00007f571b8bbef0 R08: 0000000000000000 R09: 0000000000000000 [ 715.956484] R10: 0000000000000000 R11: 0000000000000293 R12: 00007f571b8bbfc0 [ 715.958650] R13: 0000000000000000 R14: 0000000000000000 R15: 00007ffc53c52020 [ 715.960822] INFO: task test:3296 blocked for more than 10 seconds. [ 715.963048] Tainted: G OE 4.18.0-18-generic #19-Ubuntu [ 715.965231] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 715.967405] test D 0 3296 3291 0x00000000 [ 715.969468] Call Trace: [ 715.970835] __schedule+0x29e/0x840 [ 715.972453] ? __switch_to_asm+0x34/0x70 [ 715.973969] ? __switch_to_asm+0x40/0x70 [ 715.975433] schedule+0x2c/0x80 [ 715.976915] io_schedule+0x16/0x40 [ 715.978400] wait_on_page_bit+0xf7/0x140 [ 715.980281] ? page_cache_tree_insert+0xe0/0xe0 [ 715.982226] write_cache_pages+0x3ec/0x4e0 [ 715.984178] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.986189] ? xfs_vm_readpage+0x80/0x80 [xfs] [ 715.987733] ? write_cache_pages+0x5/0x4e0 [ 715.989244] xfs_vm_writepages+0x6b/0xa0 [xfs] [ 715.990798] do_writepages+0x41/0xd0 [ 715.992261] ? iomap_file_buffered_write+0x6e/0xa0 [ 715.993940] ? iomap_dirty_actor+0x220/0x220 [ 715.995557] ? xfs_iunlock+0xf8/0x100 [xfs] [ 715.997147] __filemap_fdatawrite_range+0xc5/0x100 [ 715.998849] file_write_and_wait_range+0x5a/0xb0 [ 716.000724] xfs_file_fsync+0x5f/0x230 [xfs] [ 716.002367] vfs_fsync_range+0x48/0x80 [ 716.004082] ? __fget_light+0x54/0x60 [ 716.005492] do_fsync+0x3d/0x70 [ 716.006851] __x64_sys_fsync+0x14/0x20 [ 716.008342] do_syscall_64+0x5a/0x110 [ 716.010189] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 716.012084] RIP: 0033:0x7f571c4c0b07 [ 716.013603] Code: Bad RIP value. [ 716.015091] RSP: 002b:00007f571b0baec0 EFLAGS: 00000293 ORIG_RAX: 000000000000004a [ 716.017558] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f571c4c0b07 [ 716.019800] RDX: 0000000000000000 RSI: 000055eee9f43f48 RDI: 0000000000000003 [ 716.022123] RBP: 00007f571b0baef0 R08: 0000000000000000 R09: 0000000000000000 [ 716.024160] R10: 0000000000000000 R11: 0000000000000293 R12: 00007f571b0bafc0 [ 716.026345] R13: 0000000000000000 R14: 0000000000000000 R15: 00007ffc53c52020 $ ps -eLo pid,tid,state,comm | grep D | grep -e test -e kworker 1165 1165 D kworker/u4:2+fl 3292 3293 D test 3292 3295 D test 3292 3296 D test