On Tue, Dec 10, 2019 at 08:35:43AM +0100, Andrea Vai wrote: > Il giorno mar, 03/12/2019 alle 10.23 +0800, Ming Lei ha scritto: > > On Fri, Nov 29, 2019 at 03:41:01PM +0100, Andrea Vai wrote: > > > Il giorno ven, 29/11/2019 alle 10.35 +0800, Ming Lei ha scritto: > > > > On Fri, Nov 29, 2019 at 08:57:34AM +0800, Ming Lei wrote: > > > > > > > > > [...] > > > > > > > > > Andrea, can you collect the following log when running the > > test > > > > > on current new(bad) kernel? > > > > > > > > > > /usr/share/bcc/tools/stackcount -K > > blk_mq_make_request > > > > > > > > Instead, please run the following trace, given insert may be > > > > called from other paths, such as flush plug: > > > > > > > > /usr/share/bcc/tools/stackcount -K t:block:block_rq_insert > > > > > > Attached, for new (patched) bad kernel. > > > > > > Produced by: start the trace script (with the pendrive already > > > plugged), wait some seconds, run the test (1 trial, 1 GB), wait > > for > > > the test to finish, stop the trace. > > > > > > The copy took ~1700 seconds. > > > > See the two path[1][2] of inserting request, and path[1] is > > triggered > > 4358 times, and the path[2] is triggered 5763 times. > > > > The path[2] is expected behaviour. Not sure path [1] is correct, > > given > > ext4_release_file() is supposed to be called when this inode is > > released. That means the file is closed 4358 times during 1GB file > > copying to usb storage. > > > > Cc filesystem list. > > > > > > [1] insert requests when returning to user mode from syscall > > > > b'blk_mq_sched_request_inserted' > > b'blk_mq_sched_request_inserted' > > b'dd_insert_requests' > > b'blk_mq_sched_insert_requests' > > b'blk_mq_flush_plug_list' > > b'blk_flush_plug_list' > > b'io_schedule_prepare' > > b'io_schedule' > > b'rq_qos_wait' > > b'wbt_wait' > > b'__rq_qos_throttle' > > b'blk_mq_make_request' > > b'generic_make_request' > > b'submit_bio' > > b'ext4_io_submit' > > b'ext4_writepages' > > b'do_writepages' > > b'__filemap_fdatawrite_range' > > b'ext4_release_file' > > b'__fput' > > b'task_work_run' > > b'exit_to_usermode_loop' > > b'do_syscall_64' > > b'entry_SYSCALL_64_after_hwframe' > > 4358 > > > > [2] insert requests from writeback wq context > > > > b'blk_mq_sched_request_inserted' > > b'blk_mq_sched_request_inserted' > > b'dd_insert_requests' > > b'blk_mq_sched_insert_requests' > > b'blk_mq_flush_plug_list' > > b'blk_flush_plug_list' > > b'io_schedule_prepare' > > b'io_schedule' > > b'rq_qos_wait' > > b'wbt_wait' > > b'__rq_qos_throttle' > > b'blk_mq_make_request' > > b'generic_make_request' > > b'submit_bio' > > b'ext4_io_submit' > > b'ext4_bio_write_page' > > b'mpage_submit_page' > > b'mpage_process_page_bufs' > > b'mpage_prepare_extent_to_map' > > b'ext4_writepages' > > b'do_writepages' > > b'__writeback_single_inode' > > b'writeback_sb_inodes' > > b'__writeback_inodes_wb' > > b'wb_writeback' > > b'wb_workfn' > > b'process_one_work' > > b'worker_thread' > > b'kthread' > > b'ret_from_fork' > > 5763 > > > > Thanks, > > Ming > > > > Is there any update on this? Sorry if I am making noise, but I would > like to help to improve the kernel (or fix it) if I can help. > Otherwise, please let me know how to consider this case, IMO, the extra write path from exit_to_usermode_loop() isn't expected, that should be the reason why write IO order is changed, then performance drops on your USB storage. We need our fs/ext4 experts to take a look. Or can you reproduce the issue on xfs or btrfs? Thanks, Ming
