On Fri, Aug 2, 2024 at 3:36 PM Ojaswin Mujoo <ojaswin@xxxxxxxxxxxxx> wrote: > > On Fri, Aug 02, 2024 at 10:28:47AM +0200, Max Schulze wrote: > > Hello, > > > > so I have an embedded application with limited flash write cycles. I am writing 2 blocks to disk 5 times a second (ext4, block size 1024). > > The data written is binary and fixed size and to date I open the files with (O_CREAT | O_WRONLY | O_DSYNC | O_TRUNC). > > > > I set out to measure whether this O_TRUNC leads to an extra write (because I might be able to do without - data is fixed size) and understand the linux tooling around for inspection. > > > > I wrote a test script, that creates a 2MB ext4 file system on a separate block device, so I can trace with blktrace -d /dev/sdc > > > > If somebody please could have a look if the interpretation of the traces is correct and what the missing identifiers are. > > > > > > Below is the output from blkparse for the moments where I write with open (DSYNC | TRUNC) > > > > > > > > 8,32 2 152 8.831293895 22900 C RAM 2060 + 2 [0] <-- previous _C_omplete > > > 8,32 10 2 9.245982628 14449 D N 0 [kworker/u40:2] <-- D =issued > > > 8,32 2 153 9.246369033 22900 C N [0] <-- C_omplete > > > 8,32 0 200 9.268019255 15706 A RM 2062 + 2 <- (8,33) 14 <-- A = remap > > > 8,32 0 201 9.268020922 15706 Q RM 2062 + 2 [writerdt] <-- Queued > > > 8,32 0 202 9.268034745 15706 G RM 2062 + 2 [writerdt] <-- Get = allocate Req. > > > 8,32 0 203 9.268051167 15706 I RM 2062 + 2 [writerdt] <-- I_nserted in Queue > > > 8,32 0 204 9.268107127 161 D RM 2062 + 2 [kworker/0:1H] <-- D issued "R"ead > > > 8,32 2 154 9.268704050 22900 C RM 2062 + 2 [0] > > > 8,32 0 205 9.268881750 15706 A WS 2160 + 2 <- (8,33) 112 > > > 8,32 0 206 9.268882510 15706 Q WS 2160 + 2 [writerdt] > > > 8,32 0 207 9.268890935 15706 G WS 2160 + 2 [writerdt] > > > 8,32 0 208 9.268891685 15706 P N [writerdt] > > > 8,32 0 209 9.268892510 15706 U N [writerdt] 1 > > > 8,32 0 210 9.268895672 15706 I WS 2160 + 2 [writerdt] > > > 8,32 0 211 9.268913234 15706 D WS 2160 + 2 [writerdt] <-- D issued "W"rite "S"ynchronous > > > 8,32 2 155 9.271009859 22900 C WS 2160 + 2 [0] > > > 8,32 0 212 9.271041534 15706 A WSM 2126 + 2 <- (8,33) 78 > > > 8,32 0 213 9.271041910 15706 Q WSM 2126 + 2 [writerdt] > > > 8,32 0 214 9.271051615 15706 G WSM 2126 + 2 [writerdt] > > > 8,32 0 215 9.271053774 15706 I WSM 2126 + 2 [writerdt] > > > 8,32 0 216 9.271075678 161 D WSM 2126 + 2 [kworker/0:1H] <-- D issued "W"rite "S"ynchronous > > > 8,32 2 156 9.273122709 22900 C WSM 2126 + 2 [0] > > > 8,32 4 67 10.277429577 13420 A WM 2050 + 2 <- (8,33) 2 > > > > > > -> What are M and N in the "rwbs" field? I could not find this in the manpage. > > Hey Max, > > I had the same confusion sometime back and had to dig in the kernel > code. All the rwbs values the latest kernel supports can be found > in this function [1]. > > So 'M' is added for metadata requests eg when FS is reading some > metadata blocks. 'N' is added when the request is neither > read/write/discard etc. I'm not sure what kind of IO results in N though > so maybe someone else might be able to add to this. > > [1] > https://github.com/torvalds/linux/blob/master/kernel/trace/blktrace.c#L1875 > > (I'll try to go through the trace you provided when i find some time and > update here) > > Regards, > ojaswin > I did a presentation on blktrace / blkparse at DevConf.US 2019, so that presentation PDF might be useful [1]. The "N" is shown mainly for "queue plug" or "queue unplug" events: P N (queue was plugged) U N (queue was unplugged) UT N (queue was unplugged by timer) [1] https://devconfus2019.sched.com/event/RknY/block-storage-tracing-in-the-linux-kernel Thanks, Bryan
