On 2022/08/16 14:36, Dave Voutila wrote: > > Stuart Henderson <[email protected]> writes: > > > On 2022-08-15, gwes <[email protected]> wrote: > >> Unexpected behavior: > >> When I try to chain three programs together with pipes moving lots > >> of data spin time goes up on most or all CPUs. > >> Is this known or expected? > >> > >> the chain [shortened] was > >> find /someplace -maxdepth 2 -type f -name '*.flac' -exec \ > >> metaflac -list --block-type=VORBIS_COMMENT {} + | \ > >> awk '{mangle}' | \ > >> sed -e 's/foo/bar/' | \ > >> sort -o outfile > >> > >> On a slow (1.6GHz 8GB) system with an SSD the spin times went > >> as high as 50% on all cpus. When that happens the sys times > >> also go very high rendering the system effectively > >> unusable. Swap space used = 0. > >> That system is no longer available for testing. > >> > >> This is a simplified example on a Ryzen 3600G w/64MB ram & reasonable > >> rotating rust: > >> The test file is 3.6G > >> Under some test cases the spin times go as high as 20% on two or three CPUs > >> simultaneously. Those are transient and hard to capture. > >> I can rerun this using -CURRENT if that would give better information. > >> > >> Rsults have been more or less the same 6.9, 7.0, 7.1 > >> > >> 11881$ cat m2abc.txz m2abc.txz m2abc.txz | cat | cat | cat > xx > > > > -current looks similar. (I catted /bsd a few times to make a test file, > > in this case the filesystem is on softraid crypto over nvme). > > > > CPU0: 0.0% user, 0.0% nice, 45.1% sys, 15.7% spin, 23.5% intr, 15.7% idle > > CPU1: 0.0% user, 0.0% nice, 33.3% sys, 41.2% spin, 0.0% intr, 25.5% idle > > CPU2: 2.0% user, 0.0% nice, 39.2% sys, 23.5% spin, 0.0% intr, 35.3% idle > > CPU3: 2.0% user, 0.0% nice, 29.4% sys, 27.5% spin, 0.0% intr, 41.2% idle > > Memory: Real: 5172M/15G act/tot Free: 654M Cache: 6685M Swap: 22M/2048M > > > > "yes | cat | cat | cat > xx" doesn't hit it. > > > > Don't know if it gives any clues but a flamegraph generated while > > running the multiple cat pipe on my laptop looks like > > https://junkpile.org/cat-spin-flame.svg > > _kernel_lock() was in 24% of the samples. If you add up the spin you get > about 90%, which is ~24% of 400%...the max possible sum of spin across 4 > cpus. > > Comes from the dofilereadv() -> vn_read() -> _kernel_lock() chain. > > I think that explains why your `yes | cat...` example doesn't hit
Yes, agreed. > it. I'm not on/near a machine with btrace available to generate a > flamegraph for that example but curious what it looks like. https://junkpile.org/yes-flame.svg
