You are not logged in.
Hi,
I made a fresh installation on my x280 using grub + dmcrypt + LVM + ext4 layout on a NVME SSD.
- When i made huge file copy inside my encrypted partition using rsync my system is coming more and more slow an nearly hangs until the copy his done. I get dmesg stack traces that indicate that the kernel code is blocked inside ext4 filesystem.
The statistics of the copy :
sent 4,720,278,622 bytes received 35 bytes 5,802,432.28 bytes/sec
total size is 11,526,537,216 speedup is 2.44-I observe the same behavior when i made a copy from an external un-ciphered HDD to my internal NVME SSD
sent 4,739,240,065 bytes received 35 bytes 6,272,984.91 bytes/sec
total size is 11,526,471,680 speedup is 2.43- copy from my NVME SSD to the external HDD is normal
sent 4,720,278,622 bytes received 35 bytes 38,220,879.81 bytes/sec
total size is 11,526,537,216 speedup is 2.44- copy from my external HDD to my external HDD is normal too :
sent 4,739,240,065 bytes received 35 bytes 15,771,181.70 bytes/sec
total size is 11,526,471,680 speedup is 2.43I assuming that the writes are slow due to dm-crypt.
The cryptsetup luksDump
cipher: aes-xts-plain64
sector: 512 [bytes]The cryptsetup benchmark
aes-xts 512b 1565,9 MiB/s 1610,6 MiB/sThank you for your help
The stack trace
[27647.778482] INFO: task ThreadPoolForeg:17005 blocked for more than 122 seconds.
[27647.778490] Not tainted 5.9.14-arch1-1 #1
[27647.778494] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27647.778498] task:ThreadPoolForeg state:D stack: 0 pid:17005 ppid: 1771 flags:0x00004080
[27647.778504] Call Trace:
[27647.778521] __schedule+0x292/0x830
[27647.778531] ? out_of_line_wait_on_bit_lock+0xb0/0xb0
[27647.778536] schedule+0x46/0xf0
[27647.778541] io_schedule+0x42/0x70
[27647.778547] bit_wait_io+0xd/0x50
[27647.778552] __wait_on_bit+0x2a/0x90
[27647.778559] out_of_line_wait_on_bit+0x92/0xb0
[27647.778566] ? var_wake_function+0x20/0x20
[27647.778583] do_get_write_access+0x2a9/0x440 [jbd2]
[27647.778598] jbd2_journal_get_write_access+0x4f/0x80 [jbd2]
[27647.778637] __ext4_journal_get_write_access+0x72/0x120 [ext4]
[27647.778675] ? __ext4_new_inode+0x1650/0x1700 [ext4]
[27647.778713] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27647.778719] ? get_acl+0x1a/0x160
[27647.778755] __ext4_mark_inode_dirty+0x73/0x270 [ext4]
[27647.778791] __ext4_new_inode+0x1650/0x1700 [ext4]
[27647.778836] ext4_create+0xd1/0x1a0 [ext4]
[27647.778846] path_openat+0xda7/0x10b0
[27647.778856] do_filp_open+0x9c/0x140
[27647.778870] do_sys_openat2+0xb1/0x160
[27647.778877] __x64_sys_openat+0x54/0x90
[27647.778884] do_syscall_64+0x33/0x40
[27647.778889] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[27647.778895] RIP: 0033:0x7f8f763f3774
[27647.778899] RSP: 002b:00007f8f6a188da0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[27647.778903] RAX: ffffffffffffffda RBX: 0000000000008048 RCX: 00007f8f763f3774
[27647.778905] RDX: 0000000000000241 RSI: 000024edec58c8c0 RDI: 00000000ffffff9c
[27647.778908] RBP: 000024edec58c8c0 R08: 0000000000000000 R09: 00000000000000c5
[27647.778910] R10: 0000000000000180 R11: 0000000000000293 R12: 0000000000000241
[27647.778912] R13: 0000000000000241 R14: 00007f8f763f36a0 R15: 00007f8f763f6010
[27647.778922] INFO: task ThreadPoolForeg:17039 blocked for more than 122 seconds.
[27647.778927] Not tainted 5.9.14-arch1-1 #1
[27647.778929] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27647.778933] task:ThreadPoolForeg state:D stack: 0 pid:17039 ppid: 1771 flags:0x00004080
[27647.778936] Call Trace:
[27647.778944] __schedule+0x292/0x830
[27647.778951] schedule+0x46/0xf0
[27647.778956] io_schedule+0x42/0x70
[27647.778961] wait_on_page_bit_common+0x129/0x3d0
[27647.778967] ? file_fdatawait_range+0x20/0x20
[27647.778972] __filemap_fdatawait_range+0x8c/0xf0
[27647.778982] file_write_and_wait_range+0x8c/0xb0
[27647.779015] ext4_sync_file+0x109/0x390 [ext4]
[27647.779024] __x64_sys_fdatasync+0x47/0x80
[27647.779030] do_syscall_64+0x33/0x40
[27647.779034] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[27647.779037] RIP: 0033:0x7f8f723c1e4b
[27647.779039] RSP: 002b:00007f8f6b98be10 EFLAGS: 00000293 ORIG_RAX: 000000000000004b
[27647.779043] RAX: ffffffffffffffda RBX: 00007f8f6b98be50 RCX: 00007f8f723c1e4b
[27647.779045] RDX: 0000000000000002 RSI: 00007f8f6b98bbf8 RDI: 000000000000001a
[27647.779047] RBP: 00007f8f6b98bed0 R08: 0000000000000000 R09: 000000000000001e
[27647.779049] R10: 00007ffe55fcd080 R11: 0000000000000293 R12: 00007f8f763f6010
[27647.779051] R13: 000000000000016e R14: 00007f8f6b98c000 R15: 00007f8f723c1e10
[27647.779165] INFO: task kworker/u16:1:15946 blocked for more than 122 seconds.
[27647.779169] Not tainted 5.9.14-arch1-1 #1
[27647.779171] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27647.779174] task:kworker/u16:1 state:D stack: 0 pid:15946 ppid: 2 flags:0x00004080
[27647.779218] Workqueue: ext4-rsv-conversion ext4_end_io_rsv_work [ext4]
[27647.779221] Call Trace:
[27647.779228] __schedule+0x292/0x830
[27647.779236] ? out_of_line_wait_on_bit_lock+0xb0/0xb0
[27647.779241] schedule+0x46/0xf0
[27647.779245] io_schedule+0x42/0x70
[27647.779251] bit_wait_io+0xd/0x50
[27647.779256] __wait_on_bit+0x2a/0x90
[27647.779262] out_of_line_wait_on_bit+0x92/0xb0
[27647.779267] ? var_wake_function+0x20/0x20
[27647.779280] do_get_write_access+0x2a9/0x440 [jbd2]
[27647.779293] jbd2_journal_get_write_access+0x4f/0x80 [jbd2]
[27647.779323] __ext4_journal_get_write_access+0x72/0x120 [ext4]
[27647.779355] ? ext4_ext_map_blocks+0x10bc/0x1b10 [ext4]
[27647.779389] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27647.779423] __ext4_mark_inode_dirty+0x73/0x270 [ext4]
[27647.779456] ext4_ext_map_blocks+0x10bc/0x1b10 [ext4]
[27647.779464] ? ttwu_do_wakeup+0x19/0x160
[27647.779505] ? _raw_spin_unlock_irqrestore+0x20/0x40
[27647.779510] ? __wake_up_common_lock+0x8b/0xc0
[27647.779548] ext4_map_blocks+0x119/0x5a0 [ext4]
[27647.779582] ext4_convert_unwritten_extents+0x176/0x230 [ext4]
[27647.779614] ext4_convert_unwritten_io_end_vec+0x60/0xe0 [ext4]
[27647.779651] ext4_end_io_rsv_work+0xfb/0x190 [ext4]
[27647.779661] process_one_work+0x1da/0x3d0
[27647.779667] worker_thread+0x4d/0x3d0
[27647.779673] ? rescuer_thread+0x410/0x410
[27647.779679] kthread+0x142/0x160
[27647.779685] ? __kthread_bind_mask+0x60/0x60
[27647.779693] ret_from_fork+0x22/0x30
[27647.779711] INFO: task rsync:16975 blocked for more than 122 seconds.
[27647.779715] Not tainted 5.9.14-arch1-1 #1
[27647.779717] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27647.779720] task:rsync state:D stack: 0 pid:16975 ppid: 16974 flags:0x00004080
[27647.779724] Call Trace:
[27647.779731] __schedule+0x292/0x830
[27647.779738] ? out_of_line_wait_on_bit_lock+0xb0/0xb0
[27647.779743] schedule+0x46/0xf0
[27647.779748] io_schedule+0x42/0x70
[27647.779753] bit_wait_io+0xd/0x50
[27647.779758] __wait_on_bit+0x2a/0x90
[27647.779764] out_of_line_wait_on_bit+0x92/0xb0
[27647.779769] ? var_wake_function+0x20/0x20
[27647.779780] do_get_write_access+0x2a9/0x440 [jbd2]
[27647.779793] jbd2_journal_get_write_access+0x4f/0x80 [jbd2]
[27647.779823] __ext4_journal_get_write_access+0x72/0x120 [ext4]
[27647.779859] ? ext4_dirty_inode+0x5f/0x80 [ext4]
[27647.779892] ext4_reserve_inode_write+0x93/0xc0 [ext4]
[27647.779926] __ext4_mark_inode_dirty+0x73/0x270 [ext4]
[27647.779957] ? __ext4_journal_start_sb+0x74/0x130 [ext4]
[27647.779991] ext4_dirty_inode+0x5f/0x80 [ext4]
[27647.779998] __mark_inode_dirty+0x281/0x3e0
[27647.780006] generic_write_end+0xf1/0x160
[27647.780041] ext4_da_write_end+0xac/0x2c0 [ext4]
[27647.780049] generic_perform_write+0x112/0x1e0
[27647.780083] ext4_buffered_write_iter+0x9f/0x150 [ext4]
[27647.780092] new_sync_write+0x156/0x1f0
[27647.780100] vfs_write+0x1a9/0x210
[27647.780105] ksys_write+0x67/0xe0
[27647.780112] do_syscall_64+0x33/0x40
[27647.780116] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[27647.780120] RIP: 0033:0x7f3bd42a3f67
[27647.780122] RSP: 002b:00007ffea2436038 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[27647.780126] RAX: ffffffffffffffda RBX: 000056183a4e6410 RCX: 00007f3bd42a3f67
[27647.780128] RDX: 0000000000040000 RSI: 000056183a4e6410 RDI: 0000000000000003
[27647.780130] RBP: 0000000000000003 R08: 0000000000020000 R09: 0000000000020000
[27647.780133] R10: 0000000000000080 R11: 0000000000000246 R12: 0000000000020000
[27647.780135] R13: 0000000000040000 R14: 000056183a4a6400 R15: 00007ffea2436128Last edited by MickeyMouse (2020-12-30 23:09:22)
Offline