[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

iowait

Ciao a tutti, ho creato un server fisico con 2 dischi meccanici da 14T (MG07ACA14TE) che dovrebbe servire per memorizzare grandi quantità di dati relativi a files che cambiano poco di frequente (1 volta al giorno circa, sono principalmente files di backup). Mi sembrava quindi che non dovessi preoccuparmi troppo delle performance... ma a quanto pare mi sbagliavo!
...ora sto cercando di fare un rsync di una cartella remota con 2.7T di dati e le performance sono disastrose; ad esempio iostat ora mi mostra una percentuale di iowait pari al 52,16%, atop lampeggia di rosso nei 2 dischi con un busy time anche maggiore del 100%; periodicamente anche il volume logico su cui l'rsync scrive si colora di rosso mostrando un busy time spessissimo superiore al 90%...
Che sia dovuto al fatto che il volume logico è in mirror? Avete qualche consiglio su come poter accelerare la copia dei 2.7T di dati o su come testare la velocità di scrittura?
Mi sono accorto ora che finalmente anche il kernel si accorge che c'è qualcosa che non va. Queste sono le ultime righe nel kern.log:
Sep 27 10:55:57 backup-server kernel: [10150.695843] INFO: task jbd2/dm-23-8:1568 blocked for more than 120 seconds. Sep 27 10:55:57 backup-server kernel: [10150.695871] Tainted: G          I       5.10.0-8-amd64 #1 Debian 5.10.46-4 Sep 27 10:55:57 backup-server kernel: [10150.695892] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Sep 27 10:55:57 backup-server kernel: [10150.695935] task:jbd2/dm-23-8    state:D stack:    0 pid: 1568 ppid:     2 flags:0x00004000 
Sep 27 10:55:57 backup-server kernel: [10150.695939] Call Trace:
Sep 27 10:55:57 backup-server kernel: [10150.695950] __schedule+0x282/0x870 Sep 27 10:55:57 backup-server kernel: [10150.695955]  ? out_of_line_wait_on_bit_lock+0xb0/0xb0 
Sep 27 10:55:57 backup-server kernel: [10150.695957] schedule+0x46/0xb0
Sep 27 10:55:57 backup-server kernel: [10150.695960] io_schedule+0x42/0x70
Sep 27 10:55:57 backup-server kernel: [10150.695962] bit_wait_io+0xd/0x50
Sep 27 10:55:57 backup-server kernel: [10150.695965] __wait_on_bit+0x2a/0x90 Sep 27 10:55:57 backup-server kernel: [10150.695968] out_of_line_wait_on_bit+0x92/0xb0 Sep 27 10:55:57 backup-server kernel: [10150.695973]  ? var_wake_function+0x20/0x20 Sep 27 10:55:57 backup-server kernel: [10150.695984] jbd2_journal_commit_transaction+0x11a7/0x1ad0 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.695996] kjournald2+0xab/0x270 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696000]  ? add_wait_queue_exclusive+0x70/0x70 Sep 27 10:55:57 backup-server kernel: [10150.696007]  ? load_superblock.part.0+0xb0/0xb0 [jbd2] 
Sep 27 10:55:57 backup-server kernel: [10150.696011] kthread+0x11b/0x140
Sep 27 10:55:57 backup-server kernel: [10150.696013]  ? __kthread_bind_mask+0x60/0x60 Sep 27 10:55:57 backup-server kernel: [10150.696017] ret_from_fork+0x22/0x30 Sep 27 10:55:57 backup-server kernel: [10150.696024] INFO: task rsync:1880 blocked for more than 120 seconds. Sep 27 10:55:57 backup-server kernel: [10150.696060] Tainted: G          I       5.10.0-8-amd64 #1 Debian 5.10.46-4 Sep 27 10:55:57 backup-server kernel: [10150.696100] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Sep 27 10:55:57 backup-server kernel: [10150.696142] task:rsync           state:D stack:    0 pid: 1880 ppid:  1878 flags:0x00004000 
Sep 27 10:55:57 backup-server kernel: [10150.696145] Call Trace:
Sep 27 10:55:57 backup-server kernel: [10150.696149] __schedule+0x282/0x870 Sep 27 10:55:57 backup-server kernel: [10150.696152]  ? sugov_update_single+0xca/0x1f0 Sep 27 10:55:57 backup-server kernel: [10150.696155]  ? out_of_line_wait_on_bit_lock+0xb0/0xb0 
Sep 27 10:55:57 backup-server kernel: [10150.696157] schedule+0x46/0xb0
Sep 27 10:55:57 backup-server kernel: [10150.696160] io_schedule+0x42/0x70
Sep 27 10:55:57 backup-server kernel: [10150.696162] bit_wait_io+0xd/0x50
Sep 27 10:55:57 backup-server kernel: [10150.696164] __wait_on_bit+0x2a/0x90 Sep 27 10:55:57 backup-server kernel: [10150.696167] out_of_line_wait_on_bit+0x92/0xb0 Sep 27 10:55:57 backup-server kernel: [10150.696170]  ? var_wake_function+0x20/0x20 Sep 27 10:55:57 backup-server kernel: [10150.696177] do_get_write_access+0x276/0x3d0 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696185] jbd2_journal_get_write_access+0x63/0x80 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696212] __ext4_journal_get_write_access+0x77/0x120 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696235] ext4_reserve_inode_write+0x7f/0xb0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696256] __ext4_mark_inode_dirty+0x57/0x210 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696274]  ? __ext4_journal_start_sb+0xf3/0x110 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696295] ext4_dirty_inode+0x5f/0x80 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696299] __mark_inode_dirty+0x24f/0x340 Sep 27 10:55:57 backup-server kernel: [10150.696303] generic_write_end+0xee/0x160 Sep 27 10:55:57 backup-server kernel: [10150.696320]  ? __ext4_journal_start_sb+0xf3/0x110 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696340] ext4_da_write_end+0x98/0x2f0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696345]  ? iov_iter_copy_from_user_atomic+0xe0/0x3a0 Sep 27 10:55:57 backup-server kernel: [10150.696349] generic_perform_write+0x103/0x1c0 Sep 27 10:55:57 backup-server kernel: [10150.696369] ext4_buffered_write_iter+0xa7/0x160 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696374] new_sync_write+0x11c/0x1b0 
Sep 27 10:55:57 backup-server kernel: [10150.696378] vfs_write+0x1c2/0x260
Sep 27 10:55:57 backup-server kernel: [10150.696380] ksys_write+0x5f/0xe0
Sep 27 10:55:57 backup-server kernel: [10150.696383] do_syscall_64+0x33/0x80 Sep 27 10:55:57 backup-server kernel: [10150.696387] entry_SYSCALL_64_after_hwframe+0x44/0xa9 Sep 27 10:55:57 backup-server kernel: [10150.696390] RIP: 0033:0x7feeab1b0f33 Sep 27 10:55:57 backup-server kernel: [10150.696392] RSP: 002b:00007ffef85496d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 Sep 27 10:55:57 backup-server kernel: [10150.696395] RAX: ffffffffffffffda RBX: 00005639ef415bc0 RCX: 00007feeab1b0f33 Sep 27 10:55:57 backup-server kernel: [10150.696396] RDX: 0000000000040000 RSI: 00005639ef415bc0 RDI: 0000000000000003 Sep 27 10:55:57 backup-server kernel: [10150.696398] RBP: 0000000000000003 R08: 0000000000008000 R09: 0000000000008000 Sep 27 10:55:57 backup-server kernel: [10150.696399] R10: 000000000658aeb7 R11: 0000000000000246 R12: 0000000000008000 Sep 27 10:55:57 backup-server kernel: [10150.696401] R13: 0000000000040000 R14: 00005639f07883d0 R15: 00007ffef85497c8 Sep 27 10:55:57 backup-server kernel: [10150.696405] INFO: task kworker/u16:4:2042 blocked for more than 120 seconds. Sep 27 10:55:57 backup-server kernel: [10150.696444] Tainted: G          I       5.10.0-8-amd64 #1 Debian 5.10.46-4 Sep 27 10:55:57 backup-server kernel: [10150.696484] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Sep 27 10:55:57 backup-server kernel: [10150.696526] task:kworker/u16:4   state:D stack:    0 pid: 2042 ppid:     2 flags:0x00004000 Sep 27 10:55:57 backup-server kernel: [10150.696533] Workqueue: writeback wb_workfn (flush-253:23) 
Sep 27 10:55:57 backup-server kernel: [10150.696536] Call Trace:
Sep 27 10:55:57 backup-server kernel: [10150.696539] __schedule+0x282/0x870 Sep 27 10:55:57 backup-server kernel: [10150.696542]  ? out_of_line_wait_on_bit_lock+0xb0/0xb0 
Sep 27 10:55:57 backup-server kernel: [10150.696544] schedule+0x46/0xb0
Sep 27 10:55:57 backup-server kernel: [10150.696547] io_schedule+0x42/0x70
Sep 27 10:55:57 backup-server kernel: [10150.696549] bit_wait_io+0xd/0x50
Sep 27 10:55:57 backup-server kernel: [10150.696551] __wait_on_bit+0x2a/0x90 Sep 27 10:55:57 backup-server kernel: [10150.696554] out_of_line_wait_on_bit+0x92/0xb0 Sep 27 10:55:57 backup-server kernel: [10150.696557]  ? var_wake_function+0x20/0x20 Sep 27 10:55:57 backup-server kernel: [10150.696564] do_get_write_access+0x276/0x3d0 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696571] jbd2_journal_get_write_access+0x63/0x80 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696591] __ext4_journal_get_write_access+0x77/0x120 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696612] ext4_mb_mark_diskspace_used+0x7a/0x420 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696634] ext4_mb_new_blocks+0x473/0xea0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696652]  ? ext4_find_extent+0x3e8/0x450 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696656]  ? release_pages+0x3d8/0x450 Sep 27 10:55:57 backup-server kernel: [10150.696674] ext4_ext_map_blocks+0x85d/0x1890 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696678]  ? release_pages+0x3d8/0x450 Sep 27 10:55:57 backup-server kernel: [10150.696682]  ? __pagevec_release+0x1c/0x50 Sep 27 10:55:57 backup-server kernel: [10150.696702] ext4_map_blocks+0x18e/0x590 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696722] ext4_writepages+0x72e/0xfc0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696727]  ? __find_get_block+0xb6/0x2c0 Sep 27 10:55:57 backup-server kernel: [10150.696729]  ? _cond_resched+0x16/0x40 Sep 27 10:55:57 backup-server kernel: [10150.696732]  ? __getblk_gfp+0x27/0x60 Sep 27 10:55:57 backup-server kernel: [10150.696752]  ? ext4_mark_iloc_dirty+0x721/0xa00 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.696757] do_writepages+0x34/0xc0 Sep 27 10:55:57 backup-server kernel: [10150.696760]  ? __find_get_block+0xb6/0x2c0 Sep 27 10:55:57 backup-server kernel: [10150.696763] __writeback_single_inode+0x39/0x2a0 Sep 27 10:55:57 backup-server kernel: [10150.696766] writeback_sb_inodes+0x200/0x470 Sep 27 10:55:57 backup-server kernel: [10150.696770] __writeback_inodes_wb+0x4c/0xe0 Sep 27 10:55:57 backup-server kernel: [10150.696773] wb_writeback+0x1d8/0x290 
Sep 27 10:55:57 backup-server kernel: [10150.696776] wb_workfn+0x292/0x4d0
Sep 27 10:55:57 backup-server kernel: [10150.696781]  ? __switch_to_asm+0x42/0x70 Sep 27 10:55:57 backup-server kernel: [10150.696785] process_one_work+0x1b6/0x350 Sep 27 10:55:57 backup-server kernel: [10150.696789] worker_thread+0x53/0x3e0 Sep 27 10:55:57 backup-server kernel: [10150.696792]  ? process_one_work+0x350/0x350 
Sep 27 10:55:57 backup-server kernel: [10150.696794] kthread+0x11b/0x140
Sep 27 10:55:57 backup-server kernel: [10150.696797]  ? __kthread_bind_mask+0x60/0x60 Sep 27 10:55:57 backup-server kernel: [10150.696800] ret_from_fork+0x22/0x30 Sep 27 10:55:57 backup-server kernel: [10150.696803] INFO: task kworker/u16:6:2071 blocked for more than 120 seconds. Sep 27 10:55:57 backup-server kernel: [10150.696842] Tainted: G          I       5.10.0-8-amd64 #1 Debian 5.10.46-4 Sep 27 10:55:57 backup-server kernel: [10150.696882] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Sep 27 10:55:57 backup-server kernel: [10150.696924] task:kworker/u16:6   state:D stack:    0 pid: 2071 ppid:     2 flags:0x00004000 Sep 27 10:55:57 backup-server kernel: [10150.696949] Workqueue: ext4-rsv-conversion ext4_end_io_rsv_work [ext4] 
Sep 27 10:55:57 backup-server kernel: [10150.696950] Call Trace:
Sep 27 10:55:57 backup-server kernel: [10150.696954] __schedule+0x282/0x870 
Sep 27 10:55:57 backup-server kernel: [10150.696958]  ? xas_load+0x5/0x70
Sep 27 10:55:57 backup-server kernel: [10150.696961]  ? out_of_line_wait_on_bit_lock+0xb0/0xb0 
Sep 27 10:55:57 backup-server kernel: [10150.696963] schedule+0x46/0xb0
Sep 27 10:55:57 backup-server kernel: [10150.696965] io_schedule+0x42/0x70
Sep 27 10:55:57 backup-server kernel: [10150.696968] bit_wait_io+0xd/0x50
Sep 27 10:55:57 backup-server kernel: [10150.696970] __wait_on_bit+0x2a/0x90 Sep 27 10:55:57 backup-server kernel: [10150.696973] out_of_line_wait_on_bit+0x92/0xb0 Sep 27 10:55:57 backup-server kernel: [10150.696976]  ? var_wake_function+0x20/0x20 Sep 27 10:55:57 backup-server kernel: [10150.696982] do_get_write_access+0x276/0x3d0 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.696989] jbd2_journal_get_write_access+0x63/0x80 [jbd2] Sep 27 10:55:57 backup-server kernel: [10150.697007] __ext4_journal_get_write_access+0x77/0x120 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697027] ext4_reserve_inode_write+0x7f/0xb0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697047] __ext4_mark_inode_dirty+0x57/0x210 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697065] ext4_ext_map_blocks+0xf1d/0x1890 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697069]  ? check_preempt_curr+0x29/0x60 Sep 27 10:55:57 backup-server kernel: [10150.697071]  ? ttwu_do_wakeup+0x17/0x130 Sep 27 10:55:57 backup-server kernel: [10150.697074]  ? __wake_up_common_lock+0x8a/0xc0 Sep 27 10:55:57 backup-server kernel: [10150.697093] ext4_map_blocks+0x18e/0x590 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697112] ext4_convert_unwritten_extents+0x15c/0x220 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697131] ext4_convert_unwritten_io_end_vec+0x60/0xe0 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697152] ext4_end_io_rsv_work+0xf6/0x190 [ext4] Sep 27 10:55:57 backup-server kernel: [10150.697157] process_one_work+0x1b6/0x350 Sep 27 10:55:57 backup-server kernel: [10150.697160] worker_thread+0x53/0x3e0 Sep 27 10:55:57 backup-server kernel: [10150.697163]  ? process_one_work+0x350/0x350 
Sep 27 10:55:57 backup-server kernel: [10150.697165] kthread+0x11b/0x140
Sep 27 10:55:57 backup-server kernel: [10150.697168]  ? __kthread_bind_mask+0x60/0x60 Sep 27 10:55:57 backup-server kernel: [10150.697171] ret_from_fork+0x22/0x30 
secondo voi cosa sta succedendo?

Grazie

Piviul
Reply to: