Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux
1
fork

Configure Feed

Select the types of activity you want to include in your feed.

f2fs: dump more information when checkpoint was blocked for long time

generic/299 w/ mode=lfs will cause long time latency of checkpoint,
let's dump more information once we hit case.

CP merge:
- Queued : 0
- Issued : 1
- Total : 1
- Cur time : 9765(ms)
- Peak time : 9765(ms)

F2FS-fs (vdc): blocked on checkpoint for 9765 ms
CPU: 11 UID: 0 PID: 237 Comm: kworker/u128:29 Tainted: G O 6.16.0-rc3+ #409 PREEMPT(voluntary)
Tainted: [O]=OOT_MODULE
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-debian-1.16.3-2 04/01/2014
Workqueue: writeback wb_workfn (flush-253:32)
Call Trace:
<TASK>
dump_stack_lvl+0x6e/0xa0
f2fs_issue_checkpoint+0x268/0x280
f2fs_write_node_pages+0x6a/0x2c0
do_writepages+0xd0/0x170
__writeback_single_inode+0x56/0x4c0
writeback_sb_inodes+0x22a/0x550
__writeback_inodes_wb+0x4c/0xf0
wb_writeback+0x300/0x400
wb_workfn+0x3de/0x500
process_one_work+0x230/0x5c0
worker_thread+0x1da/0x3d0
kthread+0x10d/0x250
ret_from_fork+0x164/0x190
ret_from_fork_asm+0x1a/0x30

Cc: Jan Prusakowski <jprusakowski@google.com>
Signed-off-by: Chao Yu <chao@kernel.org>
Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org>

authored by

Chao Yu and committed by
Jaegeuk Kim
3fcf228b 8f5ae30d

+14 -1
+7
fs/f2fs/checkpoint.c
··· 1778 1778 llist_for_each_entry_safe(req, next, dispatch_list, llnode) { 1779 1779 diff = (u64)ktime_ms_delta(ktime_get(), req->queue_time); 1780 1780 req->ret = ret; 1781 + req->delta_time = diff; 1781 1782 complete(&req->wait); 1782 1783 1783 1784 sum_diff += diff; ··· 1873 1872 wait_for_completion(&req.wait); 1874 1873 else 1875 1874 flush_remained_ckpt_reqs(sbi, &req); 1875 + 1876 + if (unlikely(req.delta_time >= CP_LONG_LATENCY_THRESHOLD)) { 1877 + f2fs_warn_ratelimited(sbi, 1878 + "blocked on checkpoint for %u ms", cprc->peak_time); 1879 + dump_stack(); 1880 + } 1876 1881 1877 1882 return req.ret; 1878 1883 }
+7 -1
fs/f2fs/f2fs.h
··· 334 334 struct completion wait; /* completion for checkpoint done */ 335 335 struct llist_node llnode; /* llist_node to be linked in wait queue */ 336 336 int ret; /* return code of checkpoint */ 337 - ktime_t queue_time; /* request queued time */ 337 + union { 338 + ktime_t queue_time; /* request queued time */ 339 + ktime_t delta_time; /* time in queue */ 340 + }; 338 341 }; 339 342 340 343 struct ckpt_req_control { ··· 352 349 unsigned int cur_time; /* cur wait time in msec for currently issued checkpoint */ 353 350 unsigned int peak_time; /* peak wait time in msec until now */ 354 351 }; 352 + 353 + /* a time threshold that checkpoint was blocked for, unit: ms */ 354 + #define CP_LONG_LATENCY_THRESHOLD 5000 355 355 356 356 /* for the bitmap indicate blocks to be discarded */ 357 357 struct discard_entry {