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
CPU00 states: 0.0% user, 0.0% nice, 0.6% sys, 10.0% spin, 0.0% intr,
89.4% idle
CPU01 states: 0.0% user, 0.0% nice, 1.8% sys, 9.5% spin, 0.0% intr,
88.8% idle
CPU02 states: 0.0% user, 0.0% nice, 4.8% sys, 8.4% spin, 0.0% intr,
86.9% idle
CPU03 states: 0.2% user, 0.0% nice, 2.7% sys, 4.3% spin, 0.0% intr,
92.8% idle
CPU04 states: 0.0% user, 0.0% nice, 16.0% sys, 2.6% spin, 0.0% intr,
81.5% idle
CPU05 states: 0.0% user, 0.0% nice, 0.8% sys, 9.3% spin, 0.0% intr,
89.9% idle
Using two pipes only trivial spin times show.
If this is unexpected is it worth pursuing?
thanks
Geoff Steckel
11897$ dmesg
OpenBSD 7.1 (GENERIC.MP) #3: Sun May 15 10:27:01 MDT 2022
[email protected]:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 67997949952 (64847MB)
avail mem = 65919873024 (62866MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 3.3 @ 0xe6cc0 (33 entries)
bios0: vendor American Megatrends International, LLC. version "P2.10"
date 08/02/2021
bios0: ASRock B550 Phantom Gaming 4
acpi0 at bios0: ACPI 6.0
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP SSDT SSDT SSDT FIDT MCFG AAFT HPET TPM2 SSDT
CRAT CDIT SSDT SSDT SSDT SSDT WSMT APIC SSDT SSDT SSDT SSDT FPDT
acpi0: wakeup devices GP17(S4) XHC0(S4) XHC1(S4) GPP0(S4) GPP3(S4)
PTXH(S4) PT20(S4) PT24(S4) PT26(S4) PT27(S4) PT28(S4) PT29(S4)
acpitimer0 at acpi0: 3579545 Hz, 32 bits
acpimcfg0 at acpi0
acpimcfg0: addr 0xf0000000, bus 0-127
acpihpet0 at acpi0: 14318180 Hz
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: AMD Ryzen 5 5600G with Radeon Graphics, 3893.25 MHz, 19-50-00
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,FMA3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,RDRAND,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TCE,TOPEXT,CPCTR,DBKP,PCTRL3,MWAITX,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,PQM,RDSEED,ADX,SMAP,CLFLUSHOPT,CLWB,SHA,UMIP,PKU,IBPB,IBRS,STIBP,SSBD,XSAVEOPT,XSAVEC,XGETBV1,XSAVES
cpu0: 32KB 64b/line 8-way I-cache, 32KB 64b/line 8-way D-cache, 512KB
64b/line 8-way L2 cache
cpu0: ITLB 64 4KB entries fully associative, 64 4MB entries fully
associative
cpu0: DTLB 64 4KB entries fully assoccpu1: ITLB 64 4KB entries fully
associative, 64 4MB entries fully associative
cpu1: DTLB 64 4KB entries fully associative, 64 4MB entries fully
associative
cpu1: smt 0, core 1, package 0
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,FMA3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,RDRAND,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TCE,TOPEXT,CPCTR,DBKP,PCTRL3,MWAITX,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,PQM,RDSEED,ADX,SMAP,CLFLUSHOPT,CLWB,SHA,UMIP,PKU,IBPB,IBRS,STIBP,SSBD,XSAVEOPT,XSAVEC,XGETBV1,XSAVES
cpu1: 32KB 64b/line 8-way I-cache, 32KB 64b/line 8-way D-cache, 512KB
64b/line 8-way L2 cache
[[ 11 more ]]
ioapic0 at mainbus0: apid 13 pa 0xfec00000, version 21, 24 pins
ioapic1 at mainbus0: apid 14 pa 0xfec01000, version 21, 32 pins
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus -1 (GPP6)
acpiprt2 at acpi0: bus -1 (GPP7)
acpiprt3 at acpi0: bus -1 (GPP8)
acpiprt4 at acpi0: bus -1 (GPP9)
acpiprt5 at acpi0: bus 4 (GP17)
acpiprt6 at acpi0: bus -1 (GPP0)
acpiprt7 at acpi0: bus -1 (GP18)
acpiprt8 at acpi0: bus -1 (GPP4)
acpiprt9 at acpi0: bus -1 (GPP5)
acpiprt10 at acpi0: bus 1 (GPP3)
acpipci0 at acpi0 PCI0: 0x00000010 0x00000011 0x00000000
acpicmos0 at acpi0
com0 at acpi0 UAR1 addr 0x3f8/0x8 irq 4: ns16550a, 16 byte fifo
acpibtn0 at acpi0: PWRB
amdgpio0 at acpi0 GPIO uid 0 addr 0xfed81500/0x400 irq 7, 184 pins
tpm0 at acpi0 TPM_: unsupported TPM2 start method 2
"ACPI0010" at acpi0 not configured
acpicpu0 at acpi0: C1(@1 halt!), PSS
acpicpu1 at acpi0: C1(@1 halt!), PSS
acpicpu2 at acpi0: C1(@1 halt!), PSS
acpicpu3 at acpi0: C1(@1 halt!), PSS
acpicpu4 at acpi0: C1(@1 halt!), PSS
acpicpu5 at acpi0: C1(@1 halt!), PSS
acpicpu6 at acpi0: C1(@1 halt!), PSS
acpicpu7 at acpi0: C1(@1 halt!), PSS
acpicpu8 at acpi0: C1(@1 halt!), PSS
acpicpu9 at acpi0: C1(@1 halt!), PSS
acpicpu10 at acpi0: C1(@1 halt!), PSS
acpicpu11 at acpi0: C1(@1 halt!), PSS
"AMDIF030" at acpi0 not configured
"PNP0C14" at acpi0 not configured
acpipwrres0 at acpi0: PRWL
acpivideo0 at acpi0: VGA_
acpivout0 at acpivideo0: LCD_cpu0: 3893 MHz: speeds: 3900 1700 1400 MHz
pci0 at mainbus0 bus 0
ksmn0 at pci0 dev 0 function 0 "AMD 17h/6xh Root Complex" rev 0x00
pchb0 at pci0 dev 1 function 0 "AMD 17h/6xh Host" rev 0x00
pchb1 at pci0 dev 2 function 0 "AMD 17h/6xh Host" rev 0x00
ppb0 at pci0 dev 2 function 1 "AMD 17h/6xh PCIE" rev 0x00: msi
pci1 at ppb0 bus 1
xhci0 at pci1 dev 0 function 0 "AMD 500 Series xHCI" rev 0x00: msi, xHCI
1.10
usb0 at xhci0: USB revision 3.0
uhub0 at usb0 configuration 1 interface 0 "AMD xHCI root hub" rev
3.00/1.00 addr 1
ahci0 at pci1 dev 0 function 1 "AMD 500 Series AHCI" rev 0x00: msi, AHCI
1.3.1
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 0: 6.0Gb/s
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 1: 6.0Gb/s
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 2: 6.0Gb/s
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 3: 6.0Gb/s
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 4: 6.0Gb/s
ahci0: port busy after first PMP probe FIS
ahci0: port busy after first PMP probe FIS
ahci0: port 5: 1.5Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 0 lun 0: <ATA, MKNSSDRW240GB, S123>
naa.588891410069c4cc
sd0: 228936MB, 512 bytes/sector, 468862128 sectors, thin
sd1 at scsibus1 targ 1 lun 0: <ATA, WDC WD60EFRX-68L, 82.0>
naa.50014ee2653f328f
sd1: 5723166MB, 512 bytes/sector, 11721045168 sectors
sd2 at scsibus1 targ 2 lun 0: <ATA, TOSHIBA HDWQ140, FJ1M>
naa.5000039a5b900807
sd2: 3815447MB, 512 bytes/sector, 7814037168 sectors
sd3 at scsibus1 targ 3 lun 0: <ATA, WDC WD30EZRX-00D, 80.0>
naa.50014ee0590e892f
sd3: 2861588MB, 512 bytes/sector, 5860533168 sectors
sd4 at scsibus1 targ 4 lun 0: <ATA, TOSHIBA HDWQ140, FJ1M>
naa.5000039a4b780d58
sd4: 3815447MB, 512 bytes/sector, 7814037168 sectors
cd0 at scsibus1 targ 5 lun 0: <hp, DVD-RAM SW810, HA02> removable
ppb1 at pci1 dev 0 function 2 "AMD 500 Series PCIE" rev 0x00
pci2 at ppb1 bus 2
ppb2 at pci2 dev 8 function 0 "AMD 500 Series PCIE" rev 0x00: msi
pci3 at ppb2 bus 3
re0 at pci3 dev 0 function 0 "Realtek 8168" rev 0x15: RTL8168H/8111H
(0x5400), msi, address 70:85:c2:96:b0:5c
rgephy0 at re0 phy 7: RTL8251 PHY, rev. 0
pchb2 at pci0 dev 8 function 0 "AMD 17h/6xh Host" rev 0x00
ppb3 at pci0 dev 8 function 1 "AMD 17h/6xh PCIE" rev 0x00
pci4 at ppb3 bus 4
amdgpu0 at pci4 dev 0 function 0 "ATI Cezanne" rev 0xc9
drm0 at amdgpu0
amdgpu0: msi
azalia0 at pci4 dev 0 function 1 "ATI Renoir HD Audio" rev 0x00: msi
azalia0: no supported codecs
ccp0 at pci4 dev 0 function 2 "AMD 17h/1xh Crypto" rev 0x00
xhci1 at pci4 dev 0 function 3 "AMD 17h/6xh xHCI" rev 0x00: msi, xHCI 1.10
usb1 at xhci1: USB revision 3.0
uhub1 at usb1 configuration 1 interface 0 "AMD xHCI root hub" rev
3.00/1.00 addr 1
xhci2 at pci4 dev 0 function 4 "AMD 17h/6xh xHCI" rev 0x00: msi, xHCI 1.10
usb2 at xhci2: USB revision 3.0
xhci2 at pci4 dev 0 function 4 "AMD 17h/6xh xHCI" rev 0x00: msi, xHCI 1.10
usb2 at xhci2: USB revision 3.0
uhub2 at usb2 configuration 1 interface 0 "AMD xHCI root hub" rev
3.00/1.00 addr 1
azalia1 at pci4 dev 0 function 6 "AMD 17h/1xh HD Audio" rev 0x00: apic
14 int 12
azalia1: codecs: Realtek ALC1200
audio0 at azalia1
piixpm0 at pci0 dev 20 function 0 "AMD FCH SMBus" rev 0x51: polling
iic0 at piixpm0
iic1 at piixpm0
pcib0 at pci0 dev 20 function 3 "AMD FCH LPC" rev 0x51
pchb3 at pci0 dev 24 function 0 "AMD 19h/5xh Data Fabric" rev 0x00
pchb4 at pci0 dev 24 function 1 "AMD 19h/5xh Data Fabric" rev 0x00
pchb5 at pci0 dev 24 function 2 "AMD 19h/5xh Data Fabric" rev 0x00
pchb6 at pci0 dev 24 function 3 "AMD 19h/5xh Data Fabric" rev 0x00
pchb7 at pci0 dev 24 function 4 "AMD 19h/5xh Data Fabric" rev 0x00
pchb8 at pci0 dev 24 function 5 "AMD 19h/5xh Data Fabric" rev 0x00
pchb9 at pci0 dev 24 function 6 "AMD 19h/5xh Data Fabric" rev 0x00
pchb10 at pci0 dev 24 function 7 "AMD 19h/5xh Data Fabric" rev 0x00
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: SVM/RVI
efifb at mainbus0 not configured
uhidev0 at uhub0 port 14 configuration 1 interface 0 "ASRock LED
Controller" rev 1.10/0.00 addr 2
uhidev0: iclass 3/0
uhid0 at uhidev0: input=64, output=64, feature=0
uhub3 at uhub1 port 1 configuration 1 interface 0 "vendor 0x214b USB2.0
HUB" rev 2.00/1.00 addr 2
uhidev1 at uhub3 port 1 configuration 1 interface 0 " USB Keyboard" rev
1.10/4.06 addr 3
uhidev1: iclass 3/1
ukbd0 at uhidev1: 8 variable keys, 6 key codes
wskbd1 at ukbd0 mux 1
uhidev2 at uhub3 port 1 configuration 1 interface 1 " USB Keyboard" rev
1.10/4.06 addr 3
uhidev2: iclass 3/0, 2 report ids
uhid1 at uhidev2 reportid 1: input=1, output=0, feature=0
ucc0 at uhidev2 reportid 2: 4 usages, 4 keys, array
wskbd2 at ucc0 mux 1
uhidev3 at uhub3 port 2 configuration 1 interface 0 "Logitech USB
Trackball" rev 1.10/14.00 addr 4
uhidev3: iclass 3/1
ums0 at uhidev3: 5 buttons
wsmouse0 at ums0 mux 0
uaudio0 at uhub2 port 2 configuration 1 interface 1 "Burr-Brown from TI
USB Audio CODEC" rev 1.10/1.00 addr 2
uaudio0: class v1, full-speed, sync, channels: 2 play, 2 rec, 3 ctls
audio1 at uaudio0
uhidev4 at uhub2 port 2 configuration 1 interface 3 "Burr-Brown from TI
USB Audio CODEC" rev 1.10/1.00 addr 2
uhidev4: iclass 3/0
ucc1 at uhidev4: 3 usages, 3 keys, enum
wskbd3 at ucc1 mux 1
vscsi0 at root
scsibus2 at vscsi0: 256 targets
