On Tue, Nov 26, 2019 at 12:14:19PM +0100, Andrea Vai wrote: > Il giorno mar, 26/11/2019 alle 17.15 +0800, Ming Lei ha scritto: > > On Tue, Nov 26, 2019 at 08:46:07AM +0100, Andrea Vai wrote: > > > Il giorno mar, 26/11/2019 alle 10.32 +0800, Ming Lei ha scritto: > > > > On Mon, Nov 25, 2019 at 07:51:33PM +0100, Andrea Vai wrote: > > > > > Il giorno lun, 25/11/2019 alle 23.15 +0800, Ming Lei ha > > scritto: > > > > > > On Mon, Nov 25, 2019 at 03:58:34PM +0100, Andrea Vai wrote: > > > > > > > > > > > > [...] > > > > > > > > > > > > > What to try next? > > > > > > > > > > > > 1) cat /sys/kernel/debug/block/$DISK/hctx0/flags > > > > > result: > > > > > > > > > > alloc_policy=FIFO SHOULD_MERGE|2 > > > > > > > > > > > > > > > > > > > > > > > 2) echo 128 > /sys/block/$DISK/queue/nr_requests and run > > your > > > > copy > > > > > > 1GB > > > > > > test again. > > > > > > > > > > done, and still fails. What to try next? > > > > > > > > I just run 256M cp test > > > > > > I would like to point out that 256MB is a filesize that usually > > don't > > > trigger the issue (don't know if it matters, sorry). > > > > OK. > > > > I tested 256M because IO timeout is often triggered in case of > > qemu-ehci, and it is a long-term issue. When setting up the disk > > via xhci-qemu, the max request size is increased to 1MB from 120KB, > > and IO pattern changed too. When the disk is connected via uhci- > > qemu, > > the transfer is too slow(1MB/s) because max endpoint size is too > > small. > > > > However, I just waited 16min and collected all the 1GB IO log by > > connecting disk over uhci-qemu, but the sector of each data IO > > is still in order. > > > > > > > > Another info I would provide is about another strange behavior I > > > noticed: yesterday I ran the test two times (as usual with 1GB > > > filesize) and took 2370s, 1786s, and a third test was going on > > when I > > > stopped it. Then I started another set of 100 trials and let them > > run > > > tonight, and the first 10 trials were around 1000s, then gradually > > > decreased to ~300s, and finally settled around 200s with some > > trials > > > below 70-80s. This to say, times are extremely variable and for > > the > > > first time I noticed a sort of "performance increase" with time. > > > > The 'cp' test is buffered IO, can you reproduce it every time by > > running copy just after fresh mount on the USB disk? > > yes, every time my test script (attached) mounts, copy, unmount (but I > don't unplug and replug the pendrive each time). Is this enough? > > > > > > > > > > to one USB storage device on patched kernel, > > > > and WRITE data IO is really in ascending order. The filesystem > > is > > > > ext4, > > > > and mount without '-o sync'. From previous discussion, looks > > that is > > > > exactly your test setting. The order can be observed via the > > > > following script: > > > > > > > > #!/bin/sh > > > > MAJ=$1 > > > > MIN=$2 > > > > MAJ=$(( $MAJ << 20 )) > > > > DEV=$(( $MAJ | $MIN )) > > > > /usr/share/bcc/tools/trace -t -C \ > > > > 't:block:block_rq_issue (args->dev == '$DEV') "%s %d %d", > > args- > > > > >rwbs, args->sector, args->nr_sector' > > > > > > > > $MAJ & $MIN can be retrieved via lsblk for your USB storage > > disk. > > ok, so I try: > > # lsblk /dev/sdf > NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT > sdf 8:80 1 28,8G 0 disk > └─sdf1 8:81 1 28,8G 0 part > > so I ran your script (the second one, which you sent me in the next > email message) with: > > ./test_ming 8 80 > > but it fails to run (terminal output is in attached errors.txt). > What am I doing wrong? > > It's still not clear to me if I need to start the trace script and > then the test, or the opposite (or doesn't matter). The above errors > are in the former case (I didn't even start the test, actually) > > Thanks, > Andrea > In file included from /virtual/main.c:2: > In file included from /lib/modules/5.4.0+/build/include/linux/ptrace.h:6: > In file included from /lib/modules/5.4.0+/build/include/linux/sched.h:14: > In file included from /lib/modules/5.4.0+/build/include/linux/pid.h:5: > In file included from /lib/modules/5.4.0+/build/include/linux/rculist.h:11: > In file included from /lib/modules/5.4.0+/build/include/linux/rcupdate.h:26: > In file included from /lib/modules/5.4.0+/build/include/linux/irqflags.h:16: > In file included from /lib/modules/5.4.0+/build/arch/x86/include/asm/irqflags.h:9: > In file included from /lib/modules/5.4.0+/build/arch/x86/include/asm/nospec-branch.h:314: > /lib/modules/5.4.0+/build/arch/x86/include/asm/segment.h:254:2: error: expected '(' after 'asm' > alternative_io ("lsl %[seg],%[p]", > ^ > /lib/modules/5.4.0+/build/arch/x86/include/asm/alternative.h:240:2: note: expanded from macro 'alternative_io' > asm_inline volatile (ALTERNATIVE(oldinstr, newinstr, feature) \ > ^ > /lib/modules/5.4.0+/build/include/linux/compiler_types.h:210:24: note: expanded from macro 'asm_inline' > #define asm_inline asm __inline > ^ > In file included from /virtual/main.c:2: > In file included from /lib/modules/5.4.0+/build/include/linux/ptrace.h:6: > In file included from /lib/modules/5.4.0+/build/include/linux/sched.h:14: > In file included from /lib/modules/5.4.0+/build/include/linux/pid.h:5: > In file included from /lib/modules/5.4.0+/build/include/linux/rculist.h:11: > In file included from /lib/modules/5.4.0+/build/include/linux/rcupdate.h:27: > In file included from /lib/modules/5.4.0+/build/include/linux/preempt.h:78: > In file included from /lib/modules/5.4.0+/build/arch/x86/include/asm/preempt.h:7: > In file included from /lib/modules/5.4.0+/build/include/linux/thread_info.h:38: > In file included from /lib/modules/5.4.0+/build/arch/x86/include/asm/thread_info.h:12: > In file included from /lib/modules/5.4.0+/build/arch/x86/include/asm/page.h:12: > /lib/modules/5.4.0+/build/arch/x86/include/asm/page_64.h:49:2: error: expected '(' after 'asm' > alternative_call_2(clear_page_orig, > ^ > /lib/modules/5.4.0+/build/arch/x86/include/asm/alternative.h:256:2: note: expanded from macro 'alternative_call_2' > asm_inline volatile (ALTERNATIVE_2("call %P[old]", "call %P[new1]", feature1,\ > ^ > /lib/modules/5.4.0+/build/include/linux/compiler_types.h:210:24: note: expanded from macro 'asm_inline' > #define asm_inline asm __inline It can be workaround via the following change: /lib/modules/5.4.0+/build/include/generated/autoconf.h: //#define CONFIG_CC_HAS_ASM_INLINE 1 Thanks, Ming