RE: fsync stuck at jbd2_log_wait_commit on NVMe devices

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

 



Hi Ted, 

    I got some JBD2 tracing log by running our test program, most of them will take 10 seconds or so.  Compared to the normal system, this test only takes 2 seconds.
    We saw the spike of running, but checking with kernel source. I don't get  what it means.  Any insights?

           <...>-220601 [015] .... 181555.139321: jbd2_run_stats: dev 259,3 tid 1064541 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 4 blocks 1 blocks_logged 2
           <...>-220601 [015] .... 181555.141161: jbd2_run_stats: dev 259,3 tid 1064542 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 4 blocks 1 blocks_logged 2
           <...>-220601 [015] .... 181555.143399: jbd2_run_stats: dev 259,3 tid 1064543 wait 0 request_delay 0 running 1 locked 0 flushing 0 logging 0 handle_count 4 blocks 3 blocks_logged 4
           <...>-220601 [015] .... 181555.143710: jbd2_run_stats: dev 259,3 tid 1064544 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 4 blocks 1 blocks_logged 2
           <...>-220601 [015] .... 181555.143840: jbd2_run_stats: dev 259,3 tid 1064545 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 1 blocks 4 blocks_logged 5
           <...>-220601 [015] .... 181555.176298: jbd2_run_stats: dev 259,3 tid 1064546 wait 0 request_delay 0 running 32 locked 0 flushing 0 logging 0 handle_count 31 blocks 5 blocks_logged 6
 jbd2/nvme0n1p1--964   [014] .... 181555.189997: jbd2_run_stats: dev 259,1 tid 293294 wait 0 request_delay 0 running 5000 locked 0 flushing 0 logging 0 handle_count 15613 blocks 4 blocks_logged 5
           <...>-220601 [015] .... 181556.126407: jbd2_run_stats: dev 259,3 tid 1064547 wait 0 request_delay 0 running 929 locked 0 flushing 0 logging 0 handle_count 30 blocks 3 blocks_logged 4
           <...>-220601 [014] .... 181556.159874: jbd2_run_stats: dev 259,3 tid 1064548 wait 0 request_delay 0 running 10 locked 0 flushing 0 logging 0 handle_count 29 blocks 1 blocks_logged 2
           <...>-220601 [000] .... 181557.123872: jbd2_run_stats: dev 259,3 tid 1064549 wait 0 request_delay 0 running 941 locked 0 flushing 0 logging 0 handle_count 30 blocks 3 blocks_logged 4
           <...>-220601 [015] .... 181558.135168: jbd2_run_stats: dev 259,3 tid 1064550 wait 0 request_delay 1 running 1 locked 0 flushing 0 logging 0 handle_count 8 blocks 6 blocks_logged 7
           <...>-220601 [015] .... 181558.138895: jbd2_run_stats: dev 259,3 tid 1064551 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 1 blocks 4 blocks_logged 5
           <...>-220601 [015] .... 181558.139091: jbd2_run_stats: dev 259,3 tid 1064552 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 1 handle_count 2 blocks 4 blocks_logged 5
           <...>-220601 [015] .... 181558.139886: jbd2_run_stats: dev 259,3 tid 1064553 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 12 blocks 6 blocks_logged 7
           <...>-220601 [015] .... 181558.147189: jbd2_run_stats: dev 259,3 tid 1064554 wait 0 request_delay 0 running 0 locked 0 flushing 0 logging 0 handle_count 1 blocks 4 blocks_logged 5

   Thanks,
    Roy

----------------------------------------
> From: bsdnet@xxxxxxxxxxx
> To: tytso@xxxxxxx
> CC: linux-ext4@xxxxxxxxxxxxxxx
> Subject: RE: fsync stuck at jbd2_log_wait_commit on NVMe devices
> Date: Wed, 12 Aug 2015 12:28:10 -0700
>
> Hi Ted,
>
> I will collect some info about jbd2 and get back to this list.
>
> To answer your questions, our workload is mostly sequential writes from a couple of daemons.
> Every second, we will create 6 to 10 files, and write around 8M bytes into them. We only
> do extend or truncate when needed, but I am sure we rarely do this on NVMe devices.
>
> Reading the kernel document, I also see ext4 ordered option will combine metadata and data blocks
> for journaling. If the data block is big, and the workload is heavy, will JBD2 be soaked?
>
> Thanks,
>
> Roy
>
> ----------------------------------------
>> Date: Wed, 12 Aug 2015 14:37:50 -0400
>> From: tytso@xxxxxxx
>> To: bsdnet@xxxxxxxxxxx
>> CC: linux-ext4@xxxxxxxxxxxxxxx
>> Subject: Re: fsync stuck at jbd2_log_wait_commit on NVMe devices
>>
>> Hi Roy,
>>
>> My suggestion is to collect information from the jbd2_run_stats and
>> jbd2_checkpoint_stats tracepoints.
>>
>> cd /sys/kernel/debug/tracing
>> echo 1> events/jbd2/jbd2_run_stats/enable
>> echo 1> events/jbd2/jbd2_checkpoint_stats/enable
>> cat trace_pipe> /tmp/traces &
>> tail -f /tmp/traces
>>
>> The jbd2_handle_stats tracepoint can be informative, but it's also far
>> more voluminous.
>>
>> That will give us a hint where things are getting bottlenecked.
>>
>> What sort of workload is your application doing? Is it just primarily
>> doing random writes into a preallocated file? Is it creating or
>> deleting files? Extending or truncating files? etc.
>>
>> - Ted
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-ext4" in
>> the body of a message to majordomo@xxxxxxxxxxxxxxx
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
> --
> To unsubscribe from this list: send the line "unsubscribe linux-ext4" in
> the body of a message to majordomo@xxxxxxxxxxxxxxx
> More majordomo info at http://vger.kernel.org/majordomo-info.html
 		 	   		  --
To unsubscribe from this list: send the line "unsubscribe linux-ext4" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Reiser Filesystem Development]     [Ceph FS]     [Kernel Newbies]     [Security]     [Netfilter]     [Bugtraq]     [Linux FS]     [Yosemite National Park]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Device Mapper]     [Linux Media]

  Powered by Linux