Bug#987599: linux-image-5.10.0-6-amd64: regression, diskstats show unrealistic values

From	jaroslav@thinline.cz
Newsgroups	linux.debian.bugs.dist, linux.debian.kernel
Subject	Bug#987599: linux-image-5.10.0-6-amd64: regression, diskstats show unrealistic values
Date	2021-04-26 10:20 +0200
Message-ID	<C84Df-1H7-1@gated-at.bofh.it> (permalink)
Organization	linux.* mail to news gateway

Cross-posted to 2 groups.

Show all headers | View raw

Package: src:linux
Version: 5.10.28-1
Severity: normal

Hello,

after upgrading some of our servers to Debian testing I noticed that 
their reported disk utilization increased significantly. Since there was 
no other indication of them being under load and since I had a prior 
knowledge of similar bug reported few years ago, I investigated the 
source of the data and discovered that the values shown are inflated.

Steps to reproduce:

Using FIO I tried to find out some kind of maximum IOPS the drives (two 
SSDs in RAID1) can perform:

[global]
name=fio-rand-write
filename=fio-rand-write
rw=randwrite
bs=4K
direct=1
numjobs=1
time_based=1
runtime=900

[file1]
size=1G
ioengine=libaio
iodepth=16

FIO output while running was showing about 30k IOPS:

Jobs: 1 (f=1): [w(1)][0.8%][w=116MiB/s][w=29.7k IOPS][eta 14m:53s]

Drive utilization was 100% as expected, 10th column (time spent doing 
I/O in milliseconds) was increasing by 1000 each second

# while sleep 1 ; do cat /sys/block/sda/stat  ; done
     4845     2532   264597     1489  5509215   237957 56950332   268397  
       0   334780   274445    11847        0 161240352     3823    17304  
     734
     4845     2532   264597     1489  5529013   237960 57108732   269200  
       0   335780   275249    11847        0 161240352     3823    17306  
     734
     4845     2532   264597     1489  5548918   237960 57267972   270008  
       0   336784   276056    11847        0 161240352     3823    17306  
     734
     4845     2532   264597     1489  5568868   237960 57427572   270815  
       0   337788   276863    11847        0 161240352     3823    17306  
     734

After that I added IOPS limit to FIO configuration (limit max reading, 
writing, discarding IOPS):

rate_iops=100,100,100

This took effect in performance reported by FIO

Jobs: 1 (f=1), 0-100 IOPS: [w(1)][1.2%][w=400KiB/s][w=100 IOPS][eta 
14m:49s]

And increments in time spent doing I/O dropped to 400ms each second.

# while sleep 1 ; do cat /sys/block/sda/stat  ; done
     5067     2602   265364     1511  6587946   239193 65578139   314735  
       0   428856   320973    11931        0 161241296     3847    20712  
     879
     5067     2602   265364     1511  6588046   239193 65578939   314742  
       0   429256   320981    11931        0 161241296     3847    20712  
     879
     5067     2602   265364     1511  6588146   239193 65579739   314750  
       0   429656   320989    11931        0 161241296     3847    20712  
     879

I tried to increase IOPS limit by factor of 2.5 to 250 and at that point 
the drive load went back to full (ie. time spent doing I/O in 
milliseconds incrementing by 1000 each second.) Both of those values 
seem way off, it isn't likely that an SSD would need 4ms to write a 
small chunk of data. That's rotating drive level of performance.

All drives I tested showed the same behaviour, regardless of them being 
single drives or part of an MD array. Drives are two different brands.

This is a regression from Debian Stable kernel, where insignificant load 
(from the perspective of an SSD) didn't increase the "time spent doing 
I/O" counter at all. Which is IMO the sensible thing to do as you 
usually don't care if the drive reports zero load when the actual load 
is slightly more than zero. Current (testing) kernel version on the 
other hand causes "drives fully loaded" alerts when the drives are in 
reality almost idle.

Meaning of the 10th column is taken from 
https://www.kernel.org/doc/Documentation/iostats.txt

This issue is similar to 
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=927184 , but unlike 
that bug - which could be worked around by choosing mq-deadline 
scheduler - it affects mq-deadline as well. This is why I reported this 
separately as a regression.

(I removed PCI information included by reportbug since I don't think 
this is a hardware-related issue. If needed, I can provide it.)


-- Package-specific info:
** Version:
Linux version 5.10.0-6-amd64 (debian-kernel@lists.debian.org) (gcc-10 
(Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 
2.35.2) #1 SMP Debian 5.10.28-1 (2021-04-09)

** Command line:
BOOT_IMAGE=/boot/vmlinuz-5.10.0-6-amd64 
root=UUID=bc4aa9fd-9c63-445e-aeae-2147798879f4 ro amd_iommu=on 
intel_iommu=on net.ifnames=0

** Not tainted

** Kernel log:
[    4.185348] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 
Rodolfo Giometti <giometti@linux.it>
[    4.191508] PTP clock support registered
[    4.194579] ccp 0000:42:00.1: SEV API:0.24 build:3
[    4.264204] checking generic (b6000000 300000) vs hw (b6000000 
1000000)
[    4.264207] fb0: switching to astdrmfb from EFI VGA
[    4.268024] Console: switching to colour dummy device 80x25
[    4.268247] ast 0000:c4:00.0: [drm] P2A bridge disabled, using 
default configuration
[    4.268250] ast 0000:c4:00.0: [drm] AST 2500 detected
[    4.268257] ast 0000:c4:00.0: [drm] Analog VGA only
[    4.268259] ast 0000:c4:00.0: [drm] dram MCLK=800 Mhz type=1 
bus_width=16
[    4.268804] [TTM] Zone  kernel: Available graphics memory: 131929092 
KiB
[    4.268807] [TTM] Zone   dma32: Available graphics memory: 2097152 
KiB
[    4.268808] [TTM] Initializing pool allocator
[    4.268812] [TTM] Initializing DMA pool allocator
[    4.269010] [drm] Initialized ast 0.1.0 20120228 for 0000:c4:00.0 on 
minor 0
[    4.273003] fbcon: astdrmfb (fb0) is primary device
[    4.284407] Console: switching to colour frame buffer device 128x48
[    4.286804] ast 0000:c4:00.0: [drm] fb0: astdrmfb frame buffer device
[    4.295928] tg3 0000:c6:00.0 eth0: Tigon3 [partno(BCM95720) rev 
5720000] (PCI Express) MAC address ac:1f:6b:e5:e1:7e
[    4.296009] tg3 0000:c6:00.0 eth0: attached PHY is 5720C 
(10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[    4.296060] tg3 0000:c6:00.0 eth0: RXcsums[1] LinkChgREG[0] MIirq[0] 
ASF[1] TSOcap[1]
[    4.296102] tg3 0000:c6:00.0 eth0: dma_rwctrl[00000001] 
dma_mask[64-bit]
[    4.312469] tg3 0000:c6:00.1 eth1: Tigon3 [partno(BCM95720) rev 
5720000] (PCI Express) MAC address ac:1f:6b:e5:e1:7f
[    4.312529] tg3 0000:c6:00.1 eth1: attached PHY is 5720C 
(10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[    4.312582] tg3 0000:c6:00.1 eth1: RXcsums[1] LinkChgREG[0] MIirq[0] 
ASF[1] TSOcap[1]
[    4.312625] tg3 0000:c6:00.1 eth1: dma_rwctrl[00000001] 
dma_mask[64-bit]
[    4.320397] input: PC Speaker as 
/devices/platform/pcspkr/input/input3
[    4.329707] RAPL PMU: API unit is 2^-32 Joules, 1 fixed counters, 
163840 ms ovfl timer
[    4.329951] RAPL PMU: hw unit of domain package 2^-16 Joules
[    4.336927] pstore: ignoring unexpected backend 'efi'
[    4.339850] cryptd: max_cpu_qlen set to 1000
[    4.350152] AVX2 version of gcm_enc/dec engaged.
[    4.350175] AES CTR mode by8 optimization enabled
[    4.543242] kvm: Nested Virtualization enabled
[    4.543417] SVM: kvm: Nested Paging enabled
[    4.543430] SVM: Virtual VMLOAD VMSAVE supported
[    4.543444] SVM: Virtual GIF supported
[    4.548630] MCE: In-kernel MCE decoding enabled.
[    4.551186] EDAC amd64: F17h_M30h detected (node 0).
[    4.560369] EDAC amd64: Node 0: DRAM ECC enabled.
[    4.561135] EDAC amd64: MCT channel count: 8
[    4.562760] EDAC MC0: Giving out device to module amd64_edac 
controller F17h_M30h: DEV 0000:00:18.3 (INTERRUPT)
[    4.566733] EDAC MC: UMC0 chip selects:
[    4.566735] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.567578] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.569941] EDAC MC: UMC1 chip selects:
[    4.569942] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.570596] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.574730] EDAC MC: UMC2 chip selects:
[    4.574730] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.575524] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.576192] EDAC MC: UMC3 chip selects:
[    4.576193] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.576827] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.578239] EDAC MC: UMC4 chip selects:
[    4.578239] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.578800] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.582730] EDAC MC: UMC5 chip selects:
[    4.582730] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.583439] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.586536] EDAC MC: UMC6 chip selects:
[    4.586536] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.587094] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.590729] EDAC MC: UMC7 chip selects:
[    4.590730] EDAC amd64: MC: 0: 16384MB 1: 16384MB
[    4.591410] EDAC amd64: MC: 2:     0MB 3:     0MB
[    4.591964] EDAC amd64: using x16 syndromes.
[    4.592496] EDAC PCI0: Giving out device to module amd64_edac 
controller EDAC PCI controller: DEV 0000:00:18.0 (POLLED)
[    4.593049] AMD64 EDAC driver v3.5.0
[    4.658759] ipmi_si dmi-ipmi-si.0: The BMC does not support clearing 
the recv irq bit, compensating, but the BMC needs to be fixed.
[    4.734200] ipmi_si dmi-ipmi-si.0: IPMI message handler: Found new 
BMC (man_id: 0x002a7c, prod_id: 0x1b2b, dev_id: 0x20)
[    4.776164] ipmi_si dmi-ipmi-si.0: IPMI kcs interface initialized
[    4.781864] ipmi_ssif: IPMI SSIF Interface driver
[    6.762142] EXT4-fs (md0): re-mounted. Opts: 
discard,errors=remount-ro
[    7.103635] loop: module loaded
[    7.156394] tun: Universal TUN/TAP device driver, 1.6
[    7.205055] bridge: filtering via arp/ip/ip6tables is no longer 
available by default. Update your scripts to load br_netfilter if you 
need this.
[    7.214580] Bridge firewalling registered
[    7.274324] VFIO - User Level meta-driver version: 0.3
[    7.590700] br0: port 1(eth0) entered blocking state
[    7.591734] br0: port 1(eth0) entered disabled state
[    7.594832] device eth0 entered promiscuous mode
[   11.342993] tg3 0000:c6:00.0 eth0: Link is up at 1000 Mbps, full 
duplex
[   11.344061] tg3 0000:c6:00.0 eth0: Flow control is on for TX and on 
for RX
[   11.345061] tg3 0000:c6:00.0 eth0: EEE is disabled
[   11.346066] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   11.347147] br0: port 1(eth0) entered blocking state
[   11.348115] br0: port 1(eth0) entered forwarding state
[   11.357391] IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
[   12.677107] br1: port 1(eth1) entered blocking state
[   12.678069] br1: port 1(eth1) entered disabled state
[   12.679060] device eth1 entered promiscuous mode
[   16.220975] tg3 0000:c6:00.1 eth1: Link is up at 1000 Mbps, full 
duplex
[   16.221879] tg3 0000:c6:00.1 eth1: Flow control is off for TX and off 
for RX
[   16.222719] tg3 0000:c6:00.1 eth1: EEE is disabled
[   16.223562] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[   16.224486] br1: port 1(eth1) entered blocking state
[   16.225316] br1: port 1(eth1) entered forwarding state
[   16.234489] IPv6: ADDRCONF(NETDEV_CHANGE): br1: link becomes ready
[   18.474085]  sdj:

** Model information
sys_vendor: Supermicro
product_name: Super Server
product_version: 0123456789
chassis_vendor: Supermicro
chassis_version: 0123456789
bios_vendor: American Megatrends Inc.
bios_version: 1.2
board_vendor: Supermicro
board_name: H12SSW-iN
board_version: 1.01

** Loaded modules:
nf_conntrack_netlink
nft_chain_nat
nf_nat
nft_reject_inet
nf_reject_ipv4
nf_reject_ipv6
nft_reject
nf_log_ipv6
nf_log_ipv4
nf_log_common
nft_log
nft_limit
nft_counter
nft_ct
nls_ascii
nls_cp437
vfat
fat
nf_tables
nfnetlink
sch_hfsc
sch_fq_codel
efivarfs
vfio_pci
vfio_virqfd
vfio_iommu_type1
vfio
nf_conntrack_ftp
br_netfilter
bridge
stp
llc
nf_conntrack
nf_defrag_ipv6
nf_defrag_ipv4
vhost_net
tun
vhost
vhost_iotlb
tap
bonding
loop
ipmi_ssif
amd64_edac_mod
edac_mce_amd
amd_energy
kvm_amd
kvm
irqbypass
crc32_pclmul
ghash_clmulni_intel
aesni_intel
libaes
crypto_simd
cryptd
glue_helper
rapl
efi_pstore
pcspkr
ast
drm_vram_helper
drm_ttm_helper
ttm
drm_kms_helper
tg3
cec
libphy
drm
ptp
pps_core
i2c_algo_bit
sp5100_tco
ccp
watchdog
sg
rng_core
joydev
i2c_piix4
k10temp
acpi_ipmi
ipmi_si
button
ipmi_devintf
ipmi_msghandler
acpi_cpufreq
ext4
crc16
mbcache
jbd2
raid10
raid456
libcrc32c
crc32c_generic
async_raid6_recov
async_memcpy
async_pq
async_xor
xor
async_tx
evdev
hid_generic
usbhid
hid
raid6_pq
raid0
multipath
linear
raid1
md_mod
sd_mod
t10_pi
crc_t10dif
crct10dif_generic
crct10dif_pclmul
crct10dif_common
crc32c_intel
xhci_pci
xhci_hcd
ahci
libahci
libata
usbcore
scsi_mod
usb_common

** PCI devices:
00:00.0 Host bridge [0600]: Advanced Micro Devices, Inc. [AMD] 
Starship/Matisse Root Complex [1022:1480]
	Subsystem: Super Micro Computer Inc Starship/Matisse Root Complex 
[15d9:1b2b]
	Control: I/O- Mem- BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- 
<MAbort- >SERR- <PERR- INTx-


** USB devices:
not available


-- System Information:
Debian Release: bullseye/sid
   APT prefers testing
   APT policy: (500, 'testing')
Architecture: amd64 (x86_64)

Kernel: Linux 5.10.0-6-amd64 (SMP w/64 CPU threads)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE 
not set
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)

Versions of packages linux-image-5.10.0-6-amd64 depends on:
ii  initramfs-tools [linux-initramfs-tool]  0.140
ii  kmod                                    28-1
ii  linux-base                              4.6

Versions of packages linux-image-5.10.0-6-amd64 recommends:
pn  apparmor             <none>
pn  firmware-linux-free  <none>

Versions of packages linux-image-5.10.0-6-amd64 suggests:
pn  debian-kernel-handbook  <none>
ii  grub-efi-amd64          2.04-17
pn  linux-doc-5.10          <none>

Versions of packages linux-image-5.10.0-6-amd64 is related to:
pn  firmware-amd-graphics     <none>
pn  firmware-atheros          <none>
pn  firmware-bnx2             <none>
pn  firmware-bnx2x            <none>
pn  firmware-brcm80211        <none>
pn  firmware-cavium           <none>
pn  firmware-intel-sound      <none>
pn  firmware-intelwimax       <none>
pn  firmware-ipw2x00          <none>
pn  firmware-ivtv             <none>
pn  firmware-iwlwifi          <none>
pn  firmware-libertas         <none>
pn  firmware-linux-nonfree    <none>
pn  firmware-misc-nonfree     <none>
pn  firmware-myricom          <none>
pn  firmware-netxen           <none>
pn  firmware-qlogic           <none>
pn  firmware-realtek          <none>
pn  firmware-samsung          <none>
pn  firmware-siano            <none>
pn  firmware-ti-connectivity  <none>
pn  xen-hypervisor            <none>

-- no debconf information

Back to linux.debian.kernel | Previous | Next | Find similar | Unroll thread

Thread

Bug#987599: linux-image-5.10.0-6-amd64: regression, diskstats show unrealistic values jaroslav@thinline.cz - 2021-04-26 10:20 +0200

csiph-web