Bug 202441
| Summary: | Possibly vfs cache related replicable xfs regression since 4.19.0 on sata hdd:s | ||
|---|---|---|---|
| Product: | File System | Reporter: | Roger (rogan6710) |
| Component: | XFS | Assignee: | FileSystem/XFS Default Virtual Assignee (filesystem_xfs) |
| Status: | NEW --- | ||
| Severity: | normal | CC: | david, hvtaifwkbgefbaei |
| Priority: | P1 | ||
| Hardware: | x86-64 | ||
| OS: | Linux | ||
| Kernel Version: | 4.19.0 - 5.0-rc3 | Subsystem: | |
| Regression: | Yes | Bisected commit-id: | |
| Attachments: |
meminfo and xfs_info 4.19.0-rc1
dmesg with sysrq show blocked state for a run on 4.19.0-rc1 revert patch |
||
|
Description
Roger
2019-01-28 20:41:36 UTC
Hi roger, On Mon, Jan 28, 2019 at 08:41:36PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 [...] > I have a file system related problem where a compile job on a sata hdd almost > stops and ui becomes unresponsive when copying large files at the same time, > regardless of to what disk or from where they are copied. Thanks for the detailed bug report! I'll need some more information about your system and storage to understand (and hopefully reproduce) the symptoms you are seeing. Can you provide the information listed here, please? http://xfs.org/index.php/XFS_FAQ#Q:_What_information_should_I_include_when_reporting_a_problem.3F > All testing has been done on "bare metal" without even md, lvm or similar. > I have done a lot of testing of many different kernel versions on two > different > systems (Slackware 14.2 and "current") and I feel confident that this is a > kernel regression. > > The problem is _very_ pronounced when using xfs and it is only present from > kernel version 4.19.0 and all following versions NOT before (I have not > tested > any 4.19 rc versions). I have tested many of them including the latest > 4.19.18 > and 5.0-rc3 with varying configurations and some very limited testing on > 4.20.4. > > It affects jfs, ext2, ext3, ext4 also but to a much lesser extent. > btrfs and reiserfs does not seem to be affected at all, at least not on the > 4.19 series. Ok, that's interesting, because it's the second report of similar problems on 4.19: https://bugzilla.kernel.org/show_bug.cgi?id=202349 I've not been able to reproduce the problems as documented in that bug because all my test systems are headless, but in trying to reproduce it I have seen some concerning behaviour that leads to massive slowdowns that I don't ever recall seeing before. I'm hoping that your problem is what I've seen, and not something different. > After adding another 16GB ram on one of my testing machines I noticed that it > took much more time before the compile job slowed down and ui became > unresponsive, so I suspected some cache related issue. > I made a few test runs and while watching "top" I observed that as soon as > buff/cache passed ~ 23G (total 24G) while copying, the compile job slowed > down > to almost a halt, while the copying also slowed down significantly. > > After echo 0 >/proc/sys/vm/vfs_cache_pressure the compilation runs without > slowdown all the way through, while copying retains its steady +100MB/sec. > This "solution" is tested on 4.19.17-18 with "generic" Slackware config > and 5.0-rc3 both on xfs. Ok, so you turn off inode reclaim, and so page cache pressure doesn't cause inodes to be reclaimed anymore. That's something I've tested, and while it does alleviate the symptoms it eventually ends up OOM killing the test machines dead because the inode cache takes all of memory and can't be reclaimed. This is a documented side effect of this modification - Documentation/sysctl/vm.txt: [....] When vfs_cache_pressure=0, the kernel will never reclaim dentries and inodes due to memory pressure and this can easily lead to out-of-memory conditions. [....] > Here's how I hit this issue every time on a pre-zen AMD: > > 1. A decent amount of data to copy, probably at least 5-10 times as much as > ram > and reasonably fast media (~100Mb/sec) to copy from and to (Gbit nfs mount, > usb3 drive, regular hard drive...). Ok, so you add a large amount of page cache pressure, some dirty inodes. > 2. A dedicated xfs formatted regular rotating hard drive for the compile job > (I > suppose any io-latency sensitive parallellizable job will do), This problem > is > probably present for ssd's as well, but because they are so fast, cache > becomes > less of an issue and you will maybe not notice much, at least I don't. Ok, so now you add memory pressure (gcc) along with temporary and dirty XFS inodes. Is the system swapping? Can you get me the dmesg output of several samples (maybe 10?) of "echo w > /sysrq/trigger" a few seconds apart when the compile job is running? > Under these circumstances a defconfig kernel compile (ver 4.19.17) takes > about > 3min 35s on 4.18.20 (xfs) and sometimes more than an hour using any version > after it. On Slackware "current" I use gcc 8.2.0 multilib, on 14.2 regular > gcc > 5.5.0 which seemed to produce slightly better results. I note that in 4.19 there was a significant rework of the mm/ code that drives the shrinkers that do inode cache reclaim. I suspect we are seeing the fallout of these changes - are you able to confirm that the change occurred between 4.18 and 4.19-rc1 and perhaps run a bisect on the mm/ directory over that window? Thanks again for the detailed bug report! Cheers, Dave.
Hello Dave !
Thanks for the really fast reply :)
Here is most of the (rather lengthy) system information:
Single "eight" core processor:
rogan@trooper:~$ uname -a
Linux trooper.morgoth.org 4.19.18 #2 SMP Sat Jan 26 13:43:16 CST 2019 x86_64 AMD FX(tm)-9590 Eight-Core Processor AuthenticAMD GNU/Linux
root@trooper:~# xfs_repair -V
xfs_repair version 4.19.0
root@trooper:~# cat /proc/meminfo
MemTotal: 24645396 kB
MemFree: 358452 kB
MemAvailable: 22044292 kB
Buffers: 3152 kB
Cached: 22005216 kB
SwapCached: 0 kB
Active: 1713092 kB
Inactive: 21824100 kB
Active(anon): 1157816 kB
Inactive(anon): 555736 kB
Active(file): 555276 kB
Inactive(file): 21268364 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 8388604 kB
SwapFree: 8388604 kB
Dirty: 5980 kB
Writeback: 0 kB
AnonPages: 1528944 kB
Mapped: 531340 kB
Shmem: 254920 kB
Slab: 565012 kB
SReclaimable: 502684 kB
SUnreclaim: 62328 kB
KernelStack: 10448 kB
PageTables: 18100 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 20711300 kB
Committed_AS: 5195092 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 0 kB
VmallocChunk: 0 kB
Percpu: 3232 kB
HardwareCorrupted: 0 kB
AnonHugePages: 0 kB
ShmemHugePages: 0 kB
ShmemPmdMapped: 0 kB
CmaTotal: 0 kB
CmaFree: 0 kB
DirectMap4k: 2698836 kB
DirectMap2M: 22364160 kB
DirectMap1G: 0 kB
root@trooper:~# cat /proc/mounts
proc /proc proc rw,relatime 0 0
sysfs /sys sysfs rw,relatime 0 0
tmpfs /run tmpfs rw,nosuid,nodev,noexec,relatime,size=32768k,mode=755 0 0
devtmpfs /dev devtmpfs rw,relatime,size=8192k,nr_inodes=3070316,mode=755 0 0
/dev/sda1 / xfs rw,relatime,attr2,inode64,noquota 0 0
devpts /dev/pts devpts rw,relatime,gid=5,mode=620,ptmxmode=000 0 0
tmpfs /dev/shm tmpfs rw,relatime 0 0
cgroup_root /sys/fs/cgroup tmpfs rw,relatime,size=8192k,mode=755 0 0
cpuset /sys/fs/cgroup/cpuset cgroup rw,relatime,cpuset,clone_children 0 0
cpu /sys/fs/cgroup/cpu cgroup rw,relatime,cpu 0 0
cpuacct /sys/fs/cgroup/cpuacct cgroup rw,relatime,cpuacct 0 0
blkio /sys/fs/cgroup/blkio cgroup rw,relatime,blkio 0 0
memory /sys/fs/cgroup/memory cgroup rw,relatime,memory 0 0
devices /sys/fs/cgroup/devices cgroup rw,relatime,devices 0 0
freezer /sys/fs/cgroup/freezer cgroup rw,relatime,freezer 0 0
net_cls /sys/fs/cgroup/net_cls cgroup rw,relatime,net_cls 0 0
perf_event /sys/fs/cgroup/perf_event cgroup rw,relatime,perf_event,release_agent=/run/cgmanager/agents/cgm-release-agent.perf_event 0 0
net_prio /sys/fs/cgroup/net_prio cgroup rw,relatime,net_prio 0 0
pids /sys/fs/cgroup/pids cgroup rw,relatime,pids,release_agent=/run/cgmanager/agents/cgm-release-agent.pids 0 0
/dev/sdb1 /home xfs rw,nosuid,nodev,relatime,attr2,inode64,noquota 0 0
192.168.1.2:/export/vol0 /export/vol0 nfs rw,relatime,vers=3,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,timeo=10,retrans=2,sec=sys,mountaddr=192.168.1.2,mountvers=3,mountport=887,mountproto=tcp,local_lock=none,addr=192.168.1.2 0 0
192.168.1.2:/export/vol1 /export/vol1 nfs rw,relatime,vers=3,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,timeo=10,retrans=2,sec=sys,mountaddr=192.168.1.2,mountvers=3,mountport=887,mountproto=tcp,local_lock=none,addr=192.168.1.2 0 0
192.168.1.2:/export/vol2 /export/vol2 nfs rw,relatime,vers=3,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,timeo=10,retrans=2,sec=sys,mountaddr=192.168.1.2,mountvers=3,mountport=887,mountproto=tcp,local_lock=none,addr=192.168.1.2 0 0
192.168.1.2:/export/vol3 /export/vol3 nfs rw,relatime,vers=3,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,timeo=10,retrans=2,sec=sys,mountaddr=192.168.1.2,mountvers=3,mountport=887,mountproto=tcp,local_lock=none,addr=192.168.1.2 0 0
192.168.1.2:/export/vol4 /export/vol4 nfs rw,relatime,vers=3,rsize=8192,wsize=8192,namlen=255,hard,proto=tcp,timeo=10,retrans=2,sec=sys,mountaddr=192.168.1.2,mountvers=3,mountport=887,mountproto=tcp,local_lock=none,addr=192.168.1.2 0 0
devpts /dev/pts devpts rw,relatime,gid=5,mode=620,ptmxmode=000 0 0
fusectl /sys/fs/fuse/connections fusectl rw,relatime 0 0
gvfsd-fuse /home/rogan/.gvfs fuse.gvfsd-fuse rw,nosuid,nodev,relatime,user_id=1000,group_id=100 0 0
/dev/sdc1 /mnt/d0 xfs rw,relatime,attr2,inode64,noquota 0 0
/dev/sdd1 /mnt/d1 xfs rw,relatime,attr2,inode64,noquota 0 0
/dev/sde1 /mnt/d2 xfs rw,relatime,attr2,inode64,noquota 0 0
root@trooper:~# cat /proc/partitions
major minor #blocks name
1 0 16384 ram0
1 1 16384 ram1
1 2 16384 ram2
1 3 16384 ram3
1 4 16384 ram4
1 5 16384 ram5
1 6 16384 ram6
1 7 16384 ram7
1 8 16384 ram8
1 9 16384 ram9
1 10 16384 ram10
1 11 16384 ram11
1 12 16384 ram12
1 13 16384 ram13
1 14 16384 ram14
1 15 16384 ram15
8 0 244198584 sda
8 1 244198535 sda1
8 16 468851544 sdb
8 17 468851495 sdb1
8 32 976762584 sdc
8 33 976761560 sdc1
8 48 976762584 sdd
8 49 976761560 sdd1
8 64 976762584 sde
8 65 976761560 sde1
11 0 1048575 sr0
root@trooper:~# hdparm -I /dev/sd[abcde]
/dev/sda:
ATA device, with non-removable media
Model Number: WDC WDS250G2B0A-00SM50
Serial Number: 173859420723
Firmware Revision: X61130WD
Media Serial Num:
Media Manufacturer:
Transport: Serial, ATA8-AST, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
Used: unknown (minor revision code 0x005e)
Supported: 11 10 9 8 7 6 5
Likely used: 11
Configuration:
Logical max current
cylinders 16383 0
heads 16 0
sectors/track 63 0
--
LBA user addressable sectors: 268435455
LBA48 user addressable sectors: 488397168
Logical Sector size: 512 bytes
Physical Sector size: 512 bytes
Logical Sector-0 offset: 0 bytes
device size with M = 1024*1024: 238475 MBytes
device size with M = 1000*1000: 250059 MBytes (250 GB)
cache/buffer size = unknown
Form Factor: 2.5 inch
Nominal Media Rotation Rate: Solid State Device
Capabilities:
LBA, IORDY(can be disabled)
Queue depth: 32
Standby timer values: spec'd by Standard, no device specific minimum
R/W multiple sector transfer: Max = 1 Current = 1
Advanced power management level: 128
DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
Cycle time: min=120ns recommended=120ns
PIO: pio0 pio1 pio2 pio3 pio4
Cycle time: no flow control=120ns IORDY flow control=120ns
Commands/features:
Enabled Supported:
* SMART feature set
Security Mode feature set
* Power Management feature set
* Write cache
* Look-ahead
* WRITE_BUFFER command
* READ_BUFFER command
* DOWNLOAD_MICROCODE
* Advanced Power Management feature set
* 48-bit Address feature set
* Mandatory FLUSH_CACHE
* FLUSH_CACHE_EXT
* SMART error logging
* SMART self-test
* General Purpose Logging feature set
* 64-bit World wide name
* WRITE_UNCORRECTABLE_EXT command
* {READ,WRITE}_DMA_EXT_GPL commands
* Segmented DOWNLOAD_MICROCODE
unknown 119[8]
* Gen1 signaling speed (1.5Gb/s)
* Gen2 signaling speed (3.0Gb/s)
* Gen3 signaling speed (6.0Gb/s)
* Native Command Queueing (NCQ)
* Phy event counters
* READ_LOG_DMA_EXT equivalent to READ_LOG_EXT
* DMA Setup Auto-Activate optimization
Device-initiated interface power management
Asynchronous notification (eg. media change)
* Software settings preservation
Device Sleep (DEVSLP)
* SANITIZE feature set
* BLOCK_ERASE_EXT command
* DOWNLOAD MICROCODE DMA command
* WRITE BUFFER DMA command
* READ BUFFER DMA command
* Data Set Management TRIM supported (limit 8 blocks)
* Deterministic read ZEROs after TRIM
Security:
Master password revision code = 65534
supported
not enabled
not locked
frozen
not expired: security count
supported: enhanced erase
2min for SECURITY ERASE UNIT. 2min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 5001b444a973c828
NAA : 5
IEEE OUI : 001b44
Unique ID : 4a973c828
Device Sleep:
DEVSLP Exit Timeout (DETO): 30 ms (drive)
Minimum DEVSLP Assertion Time (MDAT): 30 ms (drive)
Checksum: correct
/dev/sdb:
ATA device, with non-removable media
Model Number: INTEL SSDSC2KW480H6
Serial Number: CVLT62460810480EGN
Firmware Revision: LSF031C
Transport: Serial, ATA8-AST, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
Used: unknown (minor revision code 0xffff)
Supported: 10 9 8 7 6 5
Likely used: 10
Configuration:
Logical max current
cylinders 16383 16383
heads 16 16
sectors/track 63 63
--
CHS current addressable sectors: 16514064
LBA user addressable sectors: 268435455
LBA48 user addressable sectors: 937703088
Logical Sector size: 512 bytes
Physical Sector size: 512 bytes
Logical Sector-0 offset: 0 bytes
device size with M = 1024*1024: 457862 MBytes
device size with M = 1000*1000: 480103 MBytes (480 GB)
cache/buffer size = unknown
Form Factor: 2.5 inch
Nominal Media Rotation Rate: Solid State Device
Capabilities:
LBA, IORDY(can be disabled)
Queue depth: 32
Standby timer values: spec'd by Standard, no device specific minimum
R/W multiple sector transfer: Max = 16 Current = 16
Advanced power management level: 254
DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
Cycle time: min=120ns recommended=120ns
PIO: pio0 pio1 pio2 pio3 pio4
Cycle time: no flow control=120ns IORDY flow control=120ns
Commands/features:
Enabled Supported:
* SMART feature set
Security Mode feature set
* Power Management feature set
* Write cache
* Look-ahead
* Host Protected Area feature set
* WRITE_BUFFER command
* READ_BUFFER command
* NOP cmd
* DOWNLOAD_MICROCODE
* Advanced Power Management feature set
* 48-bit Address feature set
* Mandatory FLUSH_CACHE
* FLUSH_CACHE_EXT
* SMART error logging
* SMART self-test
* General Purpose Logging feature set
* WRITE_{DMA|MULTIPLE}_FUA_EXT
* 64-bit World wide name
* IDLE_IMMEDIATE with UNLOAD
* WRITE_UNCORRECTABLE_EXT command
* {READ,WRITE}_DMA_EXT_GPL commands
* Segmented DOWNLOAD_MICROCODE
* Gen1 signaling speed (1.5Gb/s)
* Gen2 signaling speed (3.0Gb/s)
* Gen3 signaling speed (6.0Gb/s)
* Native Command Queueing (NCQ)
* Host-initiated interface power management
* Phy event counters
* DMA Setup Auto-Activate optimization
Device-initiated interface power management
* Software settings preservation
Device Sleep (DEVSLP)
* SMART Command Transport (SCT) feature set
* SCT Error Recovery Control (AC3)
* SCT Features Control (AC4)
* SCT Data Tables (AC5)
* SANITIZE feature set
* CRYPTO_SCRAMBLE_EXT command
* BLOCK_ERASE_EXT command
* reserved 69[4]
* DOWNLOAD MICROCODE DMA command
* WRITE BUFFER DMA command
* READ BUFFER DMA command
* Data Set Management TRIM supported (limit 8 blocks)
* Deterministic read data after TRIM
Security:
Master password revision code = 65534
supported
not enabled
not locked
frozen
not expired: security count
supported: enhanced erase
4min for SECURITY ERASE UNIT. 2min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 55cd2e414d07e84e
NAA : 5
IEEE OUI : 5cd2e4
Unique ID : 14d07e84e
Device Sleep:
DEVSLP Exit Timeout (DETO): 20 ms (drive)
Minimum DEVSLP Assertion Time (MDAT): 31 ms (drive)
Checksum: correct
/dev/sdc:
ATA device, with non-removable media
Model Number: ST1000DM003-1ER162
Serial Number: Z4Y5FJF6
Firmware Revision: CC45
Transport: Serial, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
Used: unknown (minor revision code 0x001f)
Supported: 9 8 7 6 5
Likely used: 9
Configuration:
Logical max current
cylinders 16383 16383
heads 16 16
sectors/track 63 63
--
CHS current addressable sectors: 16514064
LBA user addressable sectors: 268435455
LBA48 user addressable sectors: 1953525168
Logical Sector size: 512 bytes
Physical Sector size: 4096 bytes
Logical Sector-0 offset: 0 bytes
device size with M = 1024*1024: 953869 MBytes
device size with M = 1000*1000: 1000204 MBytes (1000 GB)
cache/buffer size = unknown
Form Factor: 3.5 inch
Nominal Media Rotation Rate: 7200
Capabilities:
LBA, IORDY(can be disabled)
Queue depth: 32
Standby timer values: spec'd by Standard, no device specific minimum
R/W multiple sector transfer: Max = 16 Current = 16
Advanced power management level: 254
Recommended acoustic management value: 208, current value: 208
DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
Cycle time: min=120ns recommended=120ns
PIO: pio0 pio1 pio2 pio3 pio4
Cycle time: no flow control=120ns IORDY flow control=120ns
Commands/features:
Enabled Supported:
* SMART feature set
Security Mode feature set
* Power Management feature set
* Write cache
* Look-ahead
* Host Protected Area feature set
* WRITE_BUFFER command
* READ_BUFFER command
* DOWNLOAD_MICROCODE
* Advanced Power Management feature set
Power-Up In Standby feature set
* SET_FEATURES required to spinup after power up
SET_MAX security extension
* 48-bit Address feature set
* Device Configuration Overlay feature set
* Mandatory FLUSH_CACHE
* FLUSH_CACHE_EXT
* SMART error logging
* SMART self-test
* General Purpose Logging feature set
* WRITE_{DMA|MULTIPLE}_FUA_EXT
* 64-bit World wide name
Write-Read-Verify feature set
* WRITE_UNCORRECTABLE_EXT command
* {READ,WRITE}_DMA_EXT_GPL commands
* Segmented DOWNLOAD_MICROCODE
* unknown 119[6]
* Gen1 signaling speed (1.5Gb/s)
* Gen2 signaling speed (3.0Gb/s)
* Gen3 signaling speed (6.0Gb/s)
* Native Command Queueing (NCQ)
* Phy event counters
* READ_LOG_DMA_EXT equivalent to READ_LOG_EXT
* DMA Setup Auto-Activate optimization
Device-initiated interface power management
* Software settings preservation
unknown 78[7]
* SMART Command Transport (SCT) feature set
* SCT Write Same (AC2)
unknown 206[7]
unknown 206[12] (vendor specific)
* SANITIZE feature set
* OVERWRITE_EXT command
Security:
Master password revision code = 65534
supported
not enabled
not locked
frozen
not expired: security count
supported: enhanced erase
100min for SECURITY ERASE UNIT. 100min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 5000c5007aab9de1
NAA : 5
IEEE OUI : 000c50
Unique ID : 07aab9de1
Checksum: correct
/dev/sdd:
ATA device, with non-removable media
Model Number: ST1000DM003-1ER162
Serial Number: Z4Y1SAVG
Firmware Revision: CC43
Transport: Serial, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
Used: unknown (minor revision code 0x001f)
Supported: 9 8 7 6 5
Likely used: 9
Configuration:
Logical max current
cylinders 16383 16383
heads 16 16
sectors/track 63 63
--
CHS current addressable sectors: 16514064
LBA user addressable sectors: 268435455
LBA48 user addressable sectors: 1953525168
Logical Sector size: 512 bytes
Physical Sector size: 4096 bytes
Logical Sector-0 offset: 0 bytes
device size with M = 1024*1024: 953869 MBytes
device size with M = 1000*1000: 1000204 MBytes (1000 GB)
cache/buffer size = unknown
Form Factor: 3.5 inch
Nominal Media Rotation Rate: 7200
Capabilities:
LBA, IORDY(can be disabled)
Queue depth: 32
Standby timer values: spec'd by Standard, no device specific minimum
R/W multiple sector transfer: Max = 16 Current = 16
Advanced power management level: 254
Recommended acoustic management value: 208, current value: 208
DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
Cycle time: min=120ns recommended=120ns
PIO: pio0 pio1 pio2 pio3 pio4
Cycle time: no flow control=120ns IORDY flow control=120ns
Commands/features:
Enabled Supported:
* SMART feature set
Security Mode feature set
* Power Management feature set
* Write cache
* Look-ahead
* Host Protected Area feature set
* WRITE_BUFFER command
* READ_BUFFER command
* DOWNLOAD_MICROCODE
* Advanced Power Management feature set
Power-Up In Standby feature set
* SET_FEATURES required to spinup after power up
SET_MAX security extension
* 48-bit Address feature set
* Device Configuration Overlay feature set
* Mandatory FLUSH_CACHE
* FLUSH_CACHE_EXT
* SMART error logging
* SMART self-test
* General Purpose Logging feature set
* WRITE_{DMA|MULTIPLE}_FUA_EXT
* 64-bit World wide name
Write-Read-Verify feature set
* WRITE_UNCORRECTABLE_EXT command
* {READ,WRITE}_DMA_EXT_GPL commands
* Segmented DOWNLOAD_MICROCODE
* unknown 119[6]
* Gen1 signaling speed (1.5Gb/s)
* Gen2 signaling speed (3.0Gb/s)
* Gen3 signaling speed (6.0Gb/s)
* Native Command Queueing (NCQ)
* Phy event counters
* READ_LOG_DMA_EXT equivalent to READ_LOG_EXT
* DMA Setup Auto-Activate optimization
Device-initiated interface power management
* Software settings preservation
unknown 78[7]
* SMART Command Transport (SCT) feature set
* SCT Write Same (AC2)
unknown 206[7]
unknown 206[12] (vendor specific)
* SANITIZE feature set
* OVERWRITE_EXT command
* reserved 69[7]
Security:
Master password revision code = 65534
supported
not enabled
not locked
frozen
not expired: security count
supported: enhanced erase
98min for SECURITY ERASE UNIT. 98min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 5000c500793959c3
NAA : 5
IEEE OUI : 000c50
Unique ID : 0793959c3
Checksum: correct
/dev/sde:
ATA device, with non-removable media
Model Number: ST1000DM003-1ER162
Serial Number: Z4Y9C367
Firmware Revision: CC45
Transport: Serial, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6, SATA Rev 3.0
Standards:
Used: unknown (minor revision code 0x001f)
Supported: 9 8 7 6 5
Likely used: 9
Configuration:
Logical max current
cylinders 16383 16383
heads 16 16
sectors/track 63 63
--
CHS current addressable sectors: 16514064
LBA user addressable sectors: 268435455
LBA48 user addressable sectors: 1953525168
Logical Sector size: 512 bytes
Physical Sector size: 4096 bytes
Logical Sector-0 offset: 0 bytes
device size with M = 1024*1024: 953869 MBytes
device size with M = 1000*1000: 1000204 MBytes (1000 GB)
cache/buffer size = unknown
Form Factor: 3.5 inch
Nominal Media Rotation Rate: 7200
Capabilities:
LBA, IORDY(can be disabled)
Queue depth: 32
Standby timer values: spec'd by Standard, no device specific minimum
R/W multiple sector transfer: Max = 16 Current = 16
Advanced power management level: 254
Recommended acoustic management value: 208, current value: 208
DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6
Cycle time: min=120ns recommended=120ns
PIO: pio0 pio1 pio2 pio3 pio4
Cycle time: no flow control=120ns IORDY flow control=120ns
Commands/features:
Enabled Supported:
* SMART feature set
Security Mode feature set
* Power Management feature set
* Write cache
* Look-ahead
* Host Protected Area feature set
* WRITE_BUFFER command
* READ_BUFFER command
* DOWNLOAD_MICROCODE
* Advanced Power Management feature set
Power-Up In Standby feature set
* SET_FEATURES required to spinup after power up
SET_MAX security extension
* 48-bit Address feature set
* Device Configuration Overlay feature set
* Mandatory FLUSH_CACHE
* FLUSH_CACHE_EXT
* SMART error logging
* SMART self-test
* General Purpose Logging feature set
* WRITE_{DMA|MULTIPLE}_FUA_EXT
* 64-bit World wide name
Write-Read-Verify feature set
* WRITE_UNCORRECTABLE_EXT command
* {READ,WRITE}_DMA_EXT_GPL commands
* Segmented DOWNLOAD_MICROCODE
* unknown 119[6]
* Gen1 signaling speed (1.5Gb/s)
* Gen2 signaling speed (3.0Gb/s)
* Gen3 signaling speed (6.0Gb/s)
* Native Command Queueing (NCQ)
* Phy event counters
* READ_LOG_DMA_EXT equivalent to READ_LOG_EXT
* DMA Setup Auto-Activate optimization
Device-initiated interface power management
* Software settings preservation
unknown 78[7]
* SMART Command Transport (SCT) feature set
* SCT Write Same (AC2)
unknown 206[7]
unknown 206[12] (vendor specific)
* SANITIZE feature set
* OVERWRITE_EXT command
Security:
Master password revision code = 65534
supported
not enabled
not locked
frozen
not expired: security count
supported: enhanced erase
104min for SECURITY ERASE UNIT. 104min for ENHANCED SECURITY ERASE UNIT.
Logical Unit WWN Device Identifier: 5000c50086e4bcd4
NAA : 5
IEEE OUI : 000c50
Unique ID : 086e4bcd4
Checksum: correct
xfs_info /dev/sdc1
xfs_info: /dev/sdc1 contains a mounted filesystem
fatal error -- couldn't initialize XFS library
hmm ?
root@trooper:~# umount /mnt/d0/
root@trooper:~# umount /mnt/d1/
root@trooper:~# umount /mnt/d2/
root@trooper:~# xfs_info /dev/sdc1
meta-data=/dev/sdc1 isize=512 agcount=4, agsize=61047598 blks
= sectsz=4096 attr=2, projid32bit=1
= crc=1 finobt=1, sparse=1, rmapbt=0
= reflink=0
data = bsize=4096 blocks=244190390, imaxpct=25
= sunit=0 swidth=0 blks
naming =version 2 bsize=4096 ascii-ci=0, ftype=1
log =internal log bsize=4096 blocks=119233, version=2
= sectsz=4096 sunit=1 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
xfs_info /dev/sdd1
meta-data=/dev/sdd1 isize=512 agcount=4, agsize=61047598 blks
= sectsz=4096 attr=2, projid32bit=1
= crc=1 finobt=1, sparse=1, rmapbt=0
= reflink=0
data = bsize=4096 blocks=244190390, imaxpct=25
= sunit=0 swidth=0 blks
naming =version 2 bsize=4096 ascii-ci=0, ftype=1
log =internal log bsize=4096 blocks=119233, version=2
= sectsz=4096 sunit=1 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
root@trooper:~# xfs_info /dev/sde1
meta-data=/dev/sde1 isize=512 agcount=4, agsize=61047598 blks
= sectsz=4096 attr=2, projid32bit=1
= crc=1 finobt=1, sparse=1, rmapbt=0
= reflink=0
data = bsize=4096 blocks=244190390, imaxpct=25
= sunit=0 swidth=0 blks
naming =version 2 bsize=4096 ascii-ci=0, ftype=1
log =internal log bsize=4096 blocks=119233, version=2
= sectsz=4096 sunit=1 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
/home and / (on ssd's) are made with the older version of mkfs.xfs so they
don't have the sparse inode feature enabled. And I have tested both versions of mkfs.xfs with the exact same result unfortunately. Otherwise all systems are made with default options (i.e. no options).
I knew about that vfs_cache_pressure=0 "drawback", it's not a fix :(
While testing I have never seen any tendency to swap. I have tested with swappiness=100 and different swap sizes and areas and even a swap file now (thanks for the recent fallocate addition, much appreciated :) ).
I'll do a quick run and give you some dmesg
On Mon, Jan 28, 2019 at 11:26:32PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > > --- Comment #2 from Roger (rogan6710@gmail.com) --- > > Hello Dave ! > Thanks for the really fast reply :) > Here is most of the (rather lengthy) system information: > > Single "eight" core processor: > > rogan@trooper:~$ uname -a > Linux trooper.morgoth.org 4.19.18 #2 SMP Sat Jan 26 13:43:16 CST 2019 x86_64 > AMD FX(tm)-9590 Eight-Core Processor AuthenticAMD GNU/Linux > > root@trooper:~# xfs_repair -V > xfs_repair version 4.19.0 > > root@trooper:~# cat /proc/meminfo > MemTotal: 24645396 kB > MemFree: 358452 kB > MemAvailable: 22044292 kB > Buffers: 3152 kB > Cached: 22005216 kB > SwapCached: 0 kB > Active: 1713092 kB > Inactive: 21824100 kB > Active(anon): 1157816 kB > Inactive(anon): 555736 kB > Active(file): 555276 kB > Inactive(file): 21268364 kB .... > Slab: 565012 kB > SReclaimable: 502684 kB Ok, so memory is completely used by the page cache, and there is some inode/dentry cache overhead in the slab caches. Nothing unusual in the rest of the output , either. > xfs_info /dev/sdc1 > xfs_info: /dev/sdc1 contains a mounted filesystem > > fatal error -- couldn't initialize XFS library > > hmm ? $ man xfs_info ... xfs_info [ -t mtab ] mount-point ... [...] The mount-point argument is the pathname of the directory where the filesystem is mounted. [...] $ sudo mount /dev/vdc /mnt/scratch $ sudo xfs_info /dev/vdc xfs_info: /dev/vdc contains a mounted filesystem fatal error -- couldn't initialize XFS library $ sudo xfs_info /mnt/scratch meta-data=/dev/vdc isize=512 agcount=500, agsize=268435455 blks = sectsz=512 attr=2, projid32bit=1 = crc=1 finobt=1, sparse=1, rmapbt=0 = reflink=0 data = bsize=4096 blocks=134217727500, imaxpct=1 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0, ftype=1 log =internal log bsize=4096 blocks=521728, version=2 = sectsz=512 sunit=0 blks, lazy-count=1 realtime =none extsz=4096 blocks=0, rtextents=0 $ > I'll do a quick run and give you some dmesg OK, that'll be interesting :) Cheers, Dave. "If all else fails, read the man page" ;) The complete dmesg output is a litte bit too big for the system here. they only allow 65535 characters Last Output: [ 1831.904739] sysrq: SysRq : Show Blocked State [ 1831.904745] task PC stack pid father [ 1831.904752] kswapd0 D 0 85 2 0x80000000 [ 1831.904753] Call Trace: [ 1831.904758] ? __schedule+0x21d/0x840 [ 1831.904760] schedule+0x28/0x80 [ 1831.904761] schedule_preempt_disabled+0xa/0x10 [ 1831.904762] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.904806] ? xfs_perag_get_tag+0x3d/0xe0 [xfs] [ 1831.904830] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.904854] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.904876] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.904899] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.904901] super_cache_scan+0x155/0x1a0 [ 1831.904903] do_shrink_slab+0x128/0x290 [ 1831.904905] shrink_slab+0x233/0x2b0 [ 1831.904907] shrink_node+0xe6/0x460 [ 1831.904908] kswapd+0x408/0x720 [ 1831.904909] ? mem_cgroup_shrink_node+0x180/0x180 [ 1831.904911] kthread+0x112/0x130 [ 1831.904912] ? kthread_create_worker_on_cpu+0x70/0x70 [ 1831.904913] ret_from_fork+0x22/0x40 [ 1831.904930] xfsaild/sdc1 D 0 1446 2 0x80000000 [ 1831.904931] Call Trace: [ 1831.904932] ? __schedule+0x21d/0x840 [ 1831.904933] schedule+0x28/0x80 [ 1831.904956] xfs_log_force+0x166/0x2e0 [xfs] [ 1831.904957] ? wake_up_q+0x70/0x70 [ 1831.904981] xfsaild+0x1b2/0x830 [xfs] [ 1831.905005] ? xfs_trans_ail_cursor_first+0x80/0x80 [xfs] [ 1831.905006] kthread+0x112/0x130 [ 1831.905007] ? kthread_create_worker_on_cpu+0x70/0x70 [ 1831.905008] ret_from_fork+0x22/0x40 [ 1831.905012] Xorg D 0 1496 1495 0x00000000 [ 1831.905013] Call Trace: [ 1831.905014] ? __schedule+0x21d/0x840 [ 1831.905015] schedule+0x28/0x80 [ 1831.905016] schedule_preempt_disabled+0xa/0x10 [ 1831.905017] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.905039] ? xfs_perag_get_tag+0x3d/0xe0 [xfs] [ 1831.905061] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.905084] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.905106] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.905128] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.905130] super_cache_scan+0x155/0x1a0 [ 1831.905131] do_shrink_slab+0x128/0x290 [ 1831.905132] shrink_slab+0x233/0x2b0 [ 1831.905133] shrink_node+0xe6/0x460 [ 1831.905135] do_try_to_free_pages+0xc6/0x370 [ 1831.905136] try_to_free_pages+0xf5/0x1c0 [ 1831.905137] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.905139] ? enqueue_entity+0x36d/0x7e0 [ 1831.905140] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.905142] kmalloc_order+0x14/0x40 [ 1831.905143] kmalloc_order_trace+0x1e/0xa0 [ 1831.905198] dc_create_state+0x19/0x30 [amdgpu] [ 1831.905234] amdgpu_dm_atomic_check+0xc6/0x3b0 [amdgpu] [ 1831.905248] drm_atomic_check_only+0x460/0x660 [drm] [ 1831.905258] ? drm_atomic_set_fb_for_plane+0x53/0x80 [drm] [ 1831.905267] drm_atomic_nonblocking_commit+0x13/0x50 [drm] [ 1831.905276] drm_atomic_helper_page_flip+0x5b/0x90 [drm_kms_helper] [ 1831.905285] drm_mode_page_flip_ioctl+0x553/0x5b0 [drm] [ 1831.905294] ? drm_mode_cursor2_ioctl+0x10/0x10 [drm] [ 1831.905301] drm_ioctl_kernel+0xa1/0xf0 [drm] [ 1831.905310] drm_ioctl+0x206/0x3a0 [drm] [ 1831.905319] ? drm_mode_cursor2_ioctl+0x10/0x10 [drm] [ 1831.905347] amdgpu_drm_ioctl+0x49/0x80 [amdgpu] [ 1831.905349] do_vfs_ioctl+0xa4/0x630 [ 1831.905351] ? __x64_sys_futex+0x143/0x180 [ 1831.905352] ksys_ioctl+0x60/0x90 [ 1831.905354] __x64_sys_ioctl+0x16/0x20 [ 1831.905355] do_syscall_64+0x55/0x100 [ 1831.905356] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.905358] RIP: 0033:0x7f87fd574d37 [ 1831.905361] Code: Bad RIP value. [ 1831.905362] RSP: 002b:00007fff347ff238 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 [ 1831.905363] RAX: ffffffffffffffda RBX: 0000000000bd9f10 RCX: 00007f87fd574d37 [ 1831.905364] RDX: 00007fff347ff270 RSI: 00000000c01864b0 RDI: 000000000000000e [ 1831.905364] RBP: 00007fff347ff270 R08: 00000000000041ce R09: 0000000000000000 [ 1831.905365] R10: 00000000014cbb60 R11: 0000000000000246 R12: 00000000c01864b0 [ 1831.905366] R13: 000000000000000e R14: 0000000000000000 R15: 0000000000bd58e0 [ 1831.905380] mc D 0 1866 1740 0x00000000 [ 1831.905381] Call Trace: [ 1831.905382] ? __schedule+0x21d/0x840 [ 1831.905383] schedule+0x28/0x80 [ 1831.905384] schedule_preempt_disabled+0xa/0x10 [ 1831.905385] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.905407] ? xfs_perag_get_tag+0x3d/0xe0 [xfs] [ 1831.905429] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.905431] ? inode_lru_list_add+0x20/0x40 [ 1831.905432] ? iput+0x16d/0x200 [ 1831.905455] ? xfs_iunlock+0x61/0x110 [xfs] [ 1831.905477] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.905499] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.905522] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.905523] super_cache_scan+0x155/0x1a0 [ 1831.905524] do_shrink_slab+0x128/0x290 [ 1831.905526] shrink_slab+0x233/0x2b0 [ 1831.905527] shrink_node+0xe6/0x460 [ 1831.905528] do_try_to_free_pages+0xc6/0x370 [ 1831.905529] try_to_free_pages+0xf5/0x1c0 [ 1831.905530] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.905531] ? __switch_to_asm+0x34/0x70 [ 1831.905532] ? __switch_to_asm+0x40/0x70 [ 1831.905533] ? __switch_to_asm+0x34/0x70 [ 1831.905534] ? __switch_to_asm+0x40/0x70 [ 1831.905535] ? __switch_to_asm+0x34/0x70 [ 1831.905536] ? __switch_to_asm+0x40/0x70 [ 1831.905537] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.905538] __do_page_cache_readahead+0xb1/0x1b0 [ 1831.905539] ondemand_readahead+0x1f9/0x2c0 [ 1831.905541] generic_file_read_iter+0x738/0xc10 [ 1831.905542] ? page_cache_tree_insert+0xe0/0xe0 [ 1831.905543] nfs_file_read+0x5d/0x80 [ 1831.905546] __vfs_read+0x133/0x190 [ 1831.905547] vfs_read+0x8a/0x140 [ 1831.905548] ksys_read+0x4f/0xb0 [ 1831.905549] do_syscall_64+0x55/0x100 [ 1831.905551] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.905551] RIP: 0033:0x7fad0ffd9aae [ 1831.905553] Code: Bad RIP value. [ 1831.905553] RSP: 002b:00007ffc380b1bb8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 1831.905554] RAX: ffffffffffffffda RBX: 00000000008ef9e0 RCX: 00007fad0ffd9aae [ 1831.905555] RDX: 0000000000020000 RSI: 00000000008f7ec0 RDI: 000000000000000a [ 1831.905555] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000000 [ 1831.905556] R10: 0000000000000008 R11: 0000000000000246 R12: 00000000008f7ec0 [ 1831.905556] R13: 0000000000000000 R14: 0000000199000000 R15: 00000000008d5b70 [ 1831.905574] kworker/u16:4 D 0 14955 2 0x80000000 [ 1831.905577] Workqueue: writeback wb_workfn (flush-8:32) [ 1831.905578] Call Trace: [ 1831.905579] ? __schedule+0x21d/0x840 [ 1831.905580] schedule+0x28/0x80 [ 1831.905581] schedule_timeout+0x1d8/0x370 [ 1831.905603] ? xfs_buf_read_map+0xc1/0x180 [xfs] [ 1831.905604] ? schedule+0x28/0x80 [ 1831.905606] ? down_trylock+0x25/0x30 [ 1831.905607] __down+0x7f/0xd0 [ 1831.905629] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.905630] down+0x3b/0x50 [ 1831.905652] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.905675] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.905698] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.905720] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.905743] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.905764] xfs_read_agf+0x94/0x120 [xfs] [ 1831.905785] xfs_alloc_read_agf+0x47/0x1b0 [xfs] [ 1831.905805] xfs_alloc_fix_freelist+0x377/0x430 [xfs] [ 1831.905807] ? __update_load_avg_cfs_rq+0x1b5/0x230 [ 1831.905808] ? __alloc_pages_nodemask+0x13a/0x2c0 [ 1831.905809] ? update_curr+0xba/0x1a0 [ 1831.905831] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.905851] xfs_alloc_vextent+0x121/0x580 [xfs] [ 1831.905871] xfs_bmap_btalloc+0x420/0x890 [xfs] [ 1831.905893] xfs_bmapi_write+0x5f5/0xb80 [xfs] [ 1831.905916] xfs_iomap_write_allocate+0x176/0x380 [xfs] [ 1831.905939] xfs_map_blocks+0x186/0x450 [xfs] [ 1831.905962] xfs_do_writepage+0x123/0x440 [xfs] [ 1831.905963] write_cache_pages+0x1dd/0x470 [ 1831.905985] ? xfs_vm_releasepage+0x80/0x80 [xfs] [ 1831.905987] ? genl_register_family+0xfa/0x610 [ 1831.905989] ? __tcp_transmit_skb+0x58d/0xad0 [ 1831.906011] xfs_vm_writepages+0x59/0x90 [xfs] [ 1831.906012] do_writepages+0x41/0xd0 [ 1831.906013] ? __tcp_push_pending_frames+0x2d/0xa0 [ 1831.906014] ? tcp_sendmsg_locked+0x509/0xd80 [ 1831.906015] __writeback_single_inode+0x4a/0x380 [ 1831.906017] writeback_sb_inodes+0x1d0/0x460 [ 1831.906018] __writeback_inodes_wb+0x5d/0xb0 [ 1831.906019] wb_writeback+0x263/0x310 [ 1831.906020] ? get_nr_inodes+0x35/0x50 [ 1831.906021] ? cpumask_next+0x16/0x20 [ 1831.906022] wb_workfn+0x340/0x3f0 [ 1831.906024] ? __switch_to_asm+0x40/0x70 [ 1831.906025] process_one_work+0x1eb/0x420 [ 1831.906026] worker_thread+0x2d/0x3d0 [ 1831.906027] ? pwq_unbound_release_workfn+0xc0/0xc0 [ 1831.906028] kthread+0x112/0x130 [ 1831.906029] ? kthread_create_worker_on_cpu+0x70/0x70 [ 1831.906030] ret_from_fork+0x22/0x40 [ 1831.906033] make D 0 25592 24315 0x00000000 [ 1831.906034] Call Trace: [ 1831.906036] ? __schedule+0x21d/0x840 [ 1831.906037] schedule+0x28/0x80 [ 1831.906037] rwsem_down_read_failed+0xe1/0x140 [ 1831.906039] ? update_curr+0xba/0x1a0 [ 1831.906040] call_rwsem_down_read_failed+0x14/0x30 [ 1831.906041] down_read+0x1c/0x30 [ 1831.906042] lookup_slow+0x27/0x50 [ 1831.906043] walk_component+0x1bf/0x4a0 [ 1831.906045] ? __switch_to_asm+0x40/0x70 [ 1831.906046] ? __switch_to_asm+0x34/0x70 [ 1831.906047] ? __switch_to_asm+0x40/0x70 [ 1831.906048] ? __switch_to_asm+0x34/0x70 [ 1831.906048] path_lookupat.isra.55+0x6d/0x220 [ 1831.906050] ? __switch_to_asm+0x40/0x70 [ 1831.906051] ? __switch_to_asm+0x34/0x70 [ 1831.906051] ? __switch_to_asm+0x40/0x70 [ 1831.906052] ? __switch_to_asm+0x34/0x70 [ 1831.906053] ? __switch_to_asm+0x40/0x70 [ 1831.906054] filename_lookup.part.69+0xa0/0x170 [ 1831.906055] ? __switch_to_asm+0x34/0x70 [ 1831.906056] ? __check_object_size+0x158/0x184 [ 1831.906058] ? strncpy_from_user+0x4a/0x170 [ 1831.906059] vfs_statx+0x73/0xe0 [ 1831.906061] __do_sys_newstat+0x39/0x70 [ 1831.906063] ? recalc_sigpending+0x17/0x50 [ 1831.906064] ? __set_task_blocked+0x6d/0x90 [ 1831.906064] ? __set_current_blocked+0x3d/0x60 [ 1831.906065] ? sigprocmask+0x72/0xa0 [ 1831.906066] ? __x64_sys_rt_sigprocmask+0x76/0xd0 [ 1831.906067] do_syscall_64+0x55/0x100 [ 1831.906068] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.906069] RIP: 0033:0x7efe49566325 [ 1831.906070] Code: Bad RIP value. [ 1831.906071] RSP: 002b:00007ffd677f3518 EFLAGS: 00000246 ORIG_RAX: 0000000000000004 [ 1831.906072] RAX: ffffffffffffffda RBX: 00007ffd677f3660 RCX: 00007efe49566325 [ 1831.906072] RDX: 00007ffd677f3590 RSI: 00007ffd677f3590 RDI: 00007ffd677f3520 [ 1831.906073] RBP: 00007ffd677f3650 R08: 000000000000000a R09: 00007efe495c1950 [ 1831.906073] R10: 7974697275636573 R11: 0000000000000246 R12: 00007ffd677f3870 [ 1831.906074] R13: 00007ffd677f3520 R14: 0000000000000000 R15: 0000000000000009 [ 1831.906076] cc1 D 0 26405 26404 0x00000000 [ 1831.906077] Call Trace: [ 1831.906078] ? __schedule+0x21d/0x840 [ 1831.906101] ? xfs_bwrite+0x25/0x60 [xfs] [ 1831.906101] schedule+0x28/0x80 [ 1831.906102] schedule_timeout+0x1d8/0x370 [ 1831.906104] ? blk_finish_plug+0x21/0x2e [ 1831.906127] ? xfs_bwrite+0x25/0x60 [xfs] [ 1831.906128] wait_for_completion+0xad/0x130 [ 1831.906129] ? wake_up_q+0x70/0x70 [ 1831.906151] ? __xfs_buf_submit+0xd7/0x230 [xfs] [ 1831.906173] xfs_buf_iowait+0x27/0xd0 [xfs] [ 1831.906195] __xfs_buf_submit+0xd7/0x230 [xfs] [ 1831.906218] xfs_bwrite+0x25/0x60 [xfs] [ 1831.906240] xfs_reclaim_inode+0x309/0x330 [xfs] [ 1831.906263] xfs_reclaim_inodes_ag+0x1b1/0x300 [xfs] [ 1831.906285] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.906308] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.906331] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.906332] super_cache_scan+0x155/0x1a0 [ 1831.906333] do_shrink_slab+0x128/0x290 [ 1831.906335] shrink_slab+0x233/0x2b0 [ 1831.906336] shrink_node+0xe6/0x460 [ 1831.906337] do_try_to_free_pages+0xc6/0x370 [ 1831.906338] try_to_free_pages+0xf5/0x1c0 [ 1831.906339] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.906340] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.906342] alloc_pages_vma+0x7c/0x1f0 [ 1831.906343] __handle_mm_fault+0x8b5/0xf80 [ 1831.906345] handle_mm_fault+0x155/0x1d0 [ 1831.906346] __do_page_fault+0x1e6/0x460 [ 1831.906348] ? page_fault+0x8/0x30 [ 1831.906349] page_fault+0x1e/0x30 [ 1831.906350] RIP: 0033:0x7f49d7b4ba38 [ 1831.906351] Code: Bad RIP value. [ 1831.906351] RSP: 002b:00007ffc9d5e4bd8 EFLAGS: 00010206 [ 1831.906352] RAX: 00007f49d67ec000 RBX: 0000000000000170 RCX: 00007f49d67ec040 [ 1831.906353] RDX: 0000000000000170 RSI: 0000000000000000 RDI: 00007f49d67ec000 [ 1831.906353] RBP: 00007f49d783d100 R08: 00000000031ee1f0 R09: 0000000000000000 [ 1831.906354] R10: 0000000000000000 R11: 00000000031ee1f0 R12: 00007f49d67eac00 [ 1831.906354] R13: 00007f49d67eac00 R14: 0000000000000000 R15: 00007f49d78472d0 [ 1831.906355] cc1 D 0 26411 26410 0x00000000 [ 1831.906356] Call Trace: [ 1831.906357] ? __schedule+0x21d/0x840 [ 1831.906358] schedule+0x28/0x80 [ 1831.906359] schedule_preempt_disabled+0xa/0x10 [ 1831.906360] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.906383] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.906384] ? inode_lru_list_add+0x20/0x40 [ 1831.906385] ? iput+0x16d/0x200 [ 1831.906408] ? xfs_iunlock+0x61/0x110 [xfs] [ 1831.906429] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.906452] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.906474] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.906476] super_cache_scan+0x155/0x1a0 [ 1831.906477] do_shrink_slab+0x128/0x290 [ 1831.906478] shrink_slab+0x233/0x2b0 [ 1831.906479] shrink_node+0xe6/0x460 [ 1831.906481] do_try_to_free_pages+0xc6/0x370 [ 1831.906481] try_to_free_pages+0xf5/0x1c0 [ 1831.906483] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.906484] ? __alloc_pages_slowpath+0x173/0xdc0 [ 1831.906485] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.906486] alloc_pages_vma+0x7c/0x1f0 [ 1831.906487] wp_page_copy+0x4f0/0x740 [ 1831.906488] do_wp_page+0x8a/0x5f0 [ 1831.906489] __handle_mm_fault+0xafc/0xf80 [ 1831.906491] handle_mm_fault+0x155/0x1d0 [ 1831.906492] __do_page_fault+0x1e6/0x460 [ 1831.906493] ? page_fault+0x8/0x30 [ 1831.906494] page_fault+0x1e/0x30 [ 1831.906495] RIP: 0033:0x5b126b [ 1831.906496] Code: Bad RIP value. [ 1831.906496] RSP: 002b:00007ffcb1940470 EFLAGS: 00010256 [ 1831.906497] RAX: 0000000000000000 RBX: 00007fdf9a729000 RCX: 0000000000000001 [ 1831.906498] RDX: 0000000010000002 RSI: 0000000000000001 RDI: 0000000000000054 [ 1831.906498] RBP: 00007fdf9a715000 R08: 0000000000000000 R09: 000000008000833a [ 1831.906499] R10: 0000000000000000 R11: 0000000002d22010 R12: 00007fdf9c68ddb0 [ 1831.906499] R13: 00007fdf9a725900 R14: 0000000000000000 R15: 00007fdf9a725900 [ 1831.906500] cc1 D 0 26415 26414 0x00000000 [ 1831.906501] Call Trace: [ 1831.906502] ? __schedule+0x21d/0x840 [ 1831.906503] schedule+0x28/0x80 [ 1831.906504] schedule_preempt_disabled+0xa/0x10 [ 1831.906505] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.906528] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.906551] ? xfs_iunlock+0x61/0x110 [xfs] [ 1831.906573] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.906595] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.906618] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.906619] super_cache_scan+0x155/0x1a0 [ 1831.906620] do_shrink_slab+0x128/0x290 [ 1831.906622] shrink_slab+0x233/0x2b0 [ 1831.906623] shrink_node+0xe6/0x460 [ 1831.906624] do_try_to_free_pages+0xc6/0x370 [ 1831.906625] try_to_free_pages+0xf5/0x1c0 [ 1831.906626] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.906627] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.906628] alloc_pages_vma+0x7c/0x1f0 [ 1831.906629] __handle_mm_fault+0x8b5/0xf80 [ 1831.906631] handle_mm_fault+0x155/0x1d0 [ 1831.906631] __do_page_fault+0x1e6/0x460 [ 1831.906633] ? page_fault+0x8/0x30 [ 1831.906634] page_fault+0x1e/0x30 [ 1831.906634] RIP: 0033:0x7f25af773a38 [ 1831.906636] Code: Bad RIP value. [ 1831.906636] RSP: 002b:00007ffdf763bac8 EFLAGS: 00010202 [ 1831.906637] RAX: 00007f25ad1ee000 RBX: 0000000000000080 RCX: 00007f25ad1ee040 [ 1831.906638] RDX: 0000000000000080 RSI: 0000000000000000 RDI: 00007f25ad1ee000 [ 1831.906638] RBP: 000000007ff9f6ef R08: 00000000039dc8d0 R09: 0000000000000000 [ 1831.906639] R10: 0000000000000000 R11: 00000000039daf80 R12: 0000000000000003 [ 1831.906639] R13: 0000000000000022 R14: 00007f25af47f3d8 R15: 000000007ff9f6ef [ 1831.906641] cc1 D 0 26430 26428 0x00000000 [ 1831.906641] Call Trace: [ 1831.906643] ? __schedule+0x21d/0x840 [ 1831.906643] schedule+0x28/0x80 [ 1831.906644] schedule_preempt_disabled+0xa/0x10 [ 1831.906645] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.906668] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.906669] ? inode_lru_list_add+0x20/0x40 [ 1831.906670] ? iput+0x16d/0x200 [ 1831.906693] ? xfs_iunlock+0x61/0x110 [xfs] [ 1831.906714] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.906737] ? xfs_inode_set_reclaim_tag+0xd2/0x140 [xfs] [ 1831.906759] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.906760] super_cache_scan+0x155/0x1a0 [ 1831.906762] do_shrink_slab+0x128/0x290 [ 1831.906763] shrink_slab+0x233/0x2b0 [ 1831.906764] shrink_node+0xe6/0x460 [ 1831.906765] do_try_to_free_pages+0xc6/0x370 [ 1831.906766] try_to_free_pages+0xf5/0x1c0 [ 1831.906767] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.906768] ? ttwu_do_wakeup+0x19/0x150 [ 1831.906770] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.906771] alloc_pages_vma+0x7c/0x1f0 [ 1831.906772] __handle_mm_fault+0x8b5/0xf80 [ 1831.906773] handle_mm_fault+0x155/0x1d0 [ 1831.906774] __do_page_fault+0x1e6/0x460 [ 1831.906775] ? page_fault+0x8/0x30 [ 1831.906776] page_fault+0x1e/0x30 [ 1831.906777] RIP: 0033:0x7f3c73bba484 [ 1831.906778] Code: Bad RIP value. [ 1831.906779] RSP: 002b:00007ffffaa9d5c8 EFLAGS: 00010202 [ 1831.906780] RAX: 00007f3c71ade000 RBX: 00007f3c72827000 RCX: 0000000000080000 [ 1831.906780] RDX: 00000000000d4f70 RSI: 00007f3c728fbff0 RDI: 00007f3c71bb3070 [ 1831.906781] RBP: 0000000000180000 R08: 00007f3c71bddff0 R09: 00007f3c72927000 [ 1831.906781] R10: 0000000000000007 R11: 00007f3c73c08680 R12: 00007f3c71ade000 [ 1831.906782] R13: 0000000000100000 R14: 00007ffffaa9db20 R15: 00007ffffaa9db20 [ 1831.906783] fixdep D 0 26436 26319 0x00000000 [ 1831.906784] Call Trace: [ 1831.906785] ? __schedule+0x21d/0x840 [ 1831.906786] schedule+0x28/0x80 [ 1831.906787] rwsem_down_read_failed+0xe1/0x140 [ 1831.906788] call_rwsem_down_read_failed+0x14/0x30 [ 1831.906789] down_read+0x1c/0x30 [ 1831.906790] path_openat+0xb9b/0x1650 [ 1831.906792] ? generic_file_read_iter+0x853/0xc10 [ 1831.906812] ? xfs_bmapi_read+0x129/0x340 [xfs] [ 1831.906813] do_filp_open+0x93/0x100 [ 1831.906815] ? __check_object_size+0x158/0x184 [ 1831.906816] do_sys_open+0x186/0x210 [ 1831.906817] do_syscall_64+0x55/0x100 [ 1831.906818] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.906819] RIP: 0033:0x7fc96d8769c0 [ 1831.906820] Code: Bad RIP value. [ 1831.906821] RSP: 002b:00007ffd1be5b150 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.906822] RAX: ffffffffffffffda RBX: 0000000000b9d071 RCX: 00007fc96d8769c0 [ 1831.906822] RDX: 0000000000000000 RSI: 0000000000b9d071 RDI: 00000000ffffff9c [ 1831.906823] RBP: 0000000000b9d071 R08: 0000000000b9d071 R09: 00007fc96d8d1b40 [ 1831.906823] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 1831.906824] R13: 0000000000bab372 R14: 0000000000000021 R15: 000000000000000b [ 1831.906825] cc1 D 0 26450 26449 0x00000000 [ 1831.906826] Call Trace: [ 1831.906827] ? __schedule+0x21d/0x840 [ 1831.906849] ? xfs_buf_read_map+0xc1/0x180 [xfs] [ 1831.906850] schedule+0x28/0x80 [ 1831.906851] schedule_timeout+0x1d8/0x370 [ 1831.906852] ? blk_finish_plug+0x21/0x2e [ 1831.906874] ? xfs_buf_read_map+0xc1/0x180 [xfs] [ 1831.906875] wait_for_completion+0xad/0x130 [ 1831.906876] ? wake_up_q+0x70/0x70 [ 1831.906898] ? __xfs_buf_submit+0xd7/0x230 [xfs] [ 1831.906920] xfs_buf_iowait+0x27/0xd0 [xfs] [ 1831.906942] __xfs_buf_submit+0xd7/0x230 [xfs] [ 1831.906965] xfs_buf_read_map+0xc1/0x180 [xfs] [ 1831.906988] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.907010] xfs_imap_to_bp+0x67/0xd0 [xfs] [ 1831.907031] xfs_iread+0x82/0x1f0 [xfs] [ 1831.907033] ? inode_init_always+0x120/0x1d0 [ 1831.907055] xfs_iget+0x20f/0x990 [xfs] [ 1831.907077] ? xfs_dir_lookup+0x184/0x1d0 [xfs] [ 1831.907099] xfs_lookup+0xa4/0x120 [xfs] [ 1831.907100] ? unlazy_walk+0x3a/0xa0 [ 1831.907123] xfs_vn_lookup+0x70/0xa0 [xfs] [ 1831.907124] path_openat+0xaff/0x1650 [ 1831.907125] do_filp_open+0x93/0x100 [ 1831.907127] ? __handle_mm_fault+0x9dc/0xf80 [ 1831.907128] ? __check_object_size+0x158/0x184 [ 1831.907129] do_sys_open+0x186/0x210 [ 1831.907130] do_syscall_64+0x55/0x100 [ 1831.907131] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.907132] RIP: 0033:0x7f3884a4e9c0 [ 1831.907133] Code: Bad RIP value. [ 1831.907134] RSP: 002b:00007ffcfa97a360 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.907134] RAX: ffffffffffffffda RBX: 0000000002407db0 RCX: 00007f3884a4e9c0 [ 1831.907135] RDX: 0000000000000100 RSI: 00000000023b14f0 RDI: 00000000ffffff9c [ 1831.907135] RBP: 0000000002215ae0 R08: 00000000023b2b20 R09: 0000000099568b0e [ 1831.907136] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000023b14f0 [ 1831.907136] R13: 0000000099568de8 R14: 00000000021cf190 R15: 00000000021b73b0 [ 1831.907138] cc1 D 0 26454 26453 0x00000000 [ 1831.907139] Call Trace: [ 1831.907140] ? __schedule+0x21d/0x840 [ 1831.907141] schedule+0x28/0x80 [ 1831.907142] schedule_timeout+0x1d8/0x370 [ 1831.907143] __down+0x7f/0xd0 [ 1831.907144] ? syscall_return_via_sysret+0x13/0x83 [ 1831.907145] ? __switch_to_asm+0x40/0x70 [ 1831.907146] ? __switch_to_asm+0x40/0x70 [ 1831.907168] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907169] down+0x3b/0x50 [ 1831.907191] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.907213] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907235] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.907258] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.907280] ? xfs_buf_trylock+0x19/0xd0 [xfs] [ 1831.907303] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.907325] xfs_read_agi+0x9e/0x140 [xfs] [ 1831.907347] xfs_ialloc_read_agi+0x34/0xd0 [xfs] [ 1831.907368] xfs_dialloc+0xe7/0x2b0 [xfs] [ 1831.907391] xfs_ialloc+0x6b/0x5a0 [xfs] [ 1831.907414] ? kmem_zone_alloc+0x61/0xe0 [xfs] [ 1831.907437] xfs_dir_ialloc+0x6c/0x220 [xfs] [ 1831.907460] xfs_create+0x224/0x620 [xfs] [ 1831.907483] xfs_generic_create+0x226/0x2c0 [xfs] [ 1831.907484] path_openat+0x1279/0x1650 [ 1831.907486] ? current_time+0x4f/0x90 [ 1831.907487] do_filp_open+0x93/0x100 [ 1831.907488] ? __check_object_size+0x158/0x184 [ 1831.907489] do_sys_open+0x186/0x210 [ 1831.907490] do_syscall_64+0x55/0x100 [ 1831.907491] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.907492] RIP: 0033:0x7f4afda6e9c0 [ 1831.907493] Code: Bad RIP value. [ 1831.907494] RSP: 002b:00007ffef4762170 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.907495] RAX: ffffffffffffffda RBX: 0000000003523800 RCX: 00007f4afda6e9c0 [ 1831.907495] RDX: 0000000000000241 RSI: 00007ffef4763faa RDI: 00000000ffffff9c [ 1831.907496] RBP: 000000000128aafd R08: 0000000000000001 R09: 000000000310e660 [ 1831.907496] R10: 00000000000001b6 R11: 0000000000000246 R12: 0000000000000004 [ 1831.907497] R13: 000000000128aafd R14: 0000000000000000 R15: 0000000000000000 [ 1831.907498] rm D 0 26462 26356 0x00000000 [ 1831.907498] Call Trace: [ 1831.907500] ? __schedule+0x21d/0x840 [ 1831.907501] schedule+0x28/0x80 [ 1831.907501] schedule_timeout+0x1d8/0x370 [ 1831.907503] __down+0x7f/0xd0 [ 1831.907524] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907525] down+0x3b/0x50 [ 1831.907547] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.907570] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907592] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.907614] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.907637] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.907659] xfs_read_agi+0x9e/0x140 [xfs] [ 1831.907682] xfs_iunlink+0x4d/0x140 [xfs] [ 1831.907705] xfs_remove+0x1ec/0x2e0 [xfs] [ 1831.907728] xfs_vn_unlink+0x55/0xa0 [xfs] [ 1831.907729] ? may_delete+0x7f/0x190 [ 1831.907730] vfs_unlink+0x109/0x1a0 [ 1831.907731] do_unlinkat+0x225/0x310 [ 1831.907732] do_syscall_64+0x55/0x100 [ 1831.907733] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.907734] RIP: 0033:0x7f05978905b7 [ 1831.907735] Code: Bad RIP value. [ 1831.907736] RSP: 002b:00007fff97cd1258 EFLAGS: 00000202 ORIG_RAX: 0000000000000107 [ 1831.907737] RAX: ffffffffffffffda RBX: 00000000011d68c0 RCX: 00007f05978905b7 [ 1831.907737] RDX: 0000000000000000 RSI: 00000000011d5690 RDI: 00000000ffffff9c [ 1831.907738] RBP: 00000000011d5600 R08: 0000000000000003 R09: 0000000000000000 [ 1831.907738] R10: 0000000000000003 R11: 0000000000000202 R12: 00007fff97cd1410 [ 1831.907739] R13: 0000000000000000 R14: 0000000000000000 R15: 00000000011d68c0 [ 1831.907739] rm D 0 26472 26300 0x00000000 [ 1831.907740] Call Trace: [ 1831.907742] ? __schedule+0x21d/0x840 [ 1831.907742] schedule+0x28/0x80 [ 1831.907743] schedule_timeout+0x1d8/0x370 [ 1831.907744] __down+0x7f/0xd0 [ 1831.907766] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907767] down+0x3b/0x50 [ 1831.907789] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.907811] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.907834] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.907856] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.907879] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.907901] xfs_read_agi+0x9e/0x140 [xfs] [ 1831.907924] xfs_iunlink+0x4d/0x140 [xfs] [ 1831.907947] xfs_remove+0x1ec/0x2e0 [xfs] [ 1831.907969] xfs_vn_unlink+0x55/0xa0 [xfs] [ 1831.907970] ? may_delete+0x7f/0x190 [ 1831.907971] vfs_unlink+0x109/0x1a0 [ 1831.907972] do_unlinkat+0x225/0x310 [ 1831.907974] do_syscall_64+0x55/0x100 [ 1831.907975] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.907975] RIP: 0033:0x7f26250485b7 [ 1831.907977] Code: Bad RIP value. [ 1831.907977] RSP: 002b:00007fffce6faab8 EFLAGS: 00000206 ORIG_RAX: 0000000000000107 [ 1831.907978] RAX: ffffffffffffffda RBX: 00000000016728c0 RCX: 00007f26250485b7 [ 1831.907979] RDX: 0000000000000000 RSI: 0000000001671690 RDI: 00000000ffffff9c [ 1831.907979] RBP: 0000000001671600 R08: 0000000000000003 R09: 0000000000000000 [ 1831.907980] R10: 0000000000000003 R11: 0000000000000206 R12: 00007fffce6fac70 [ 1831.907980] R13: 0000000000000000 R14: 0000000000000000 R15: 00000000016728c0 [ 1831.907981] gcc D 0 26474 26473 0x00000000 [ 1831.907982] Call Trace: [ 1831.907983] ? __schedule+0x21d/0x840 [ 1831.907984] schedule+0x28/0x80 [ 1831.907985] rwsem_down_read_failed+0xe1/0x140 [ 1831.907987] call_rwsem_down_read_failed+0x14/0x30 [ 1831.907988] down_read+0x1c/0x30 [ 1831.907988] lookup_slow+0x27/0x50 [ 1831.907989] walk_component+0x1bf/0x4a0 [ 1831.907990] path_lookupat.isra.55+0x6d/0x220 [ 1831.907992] filename_lookup.part.69+0xa0/0x170 [ 1831.907993] ? __check_object_size+0x158/0x184 [ 1831.907994] ? strncpy_from_user+0x4a/0x170 [ 1831.907995] ? getname_flags+0x6a/0x1e0 [ 1831.907996] do_faccessat+0xa2/0x240 [ 1831.907997] do_syscall_64+0x55/0x100 [ 1831.907998] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.907999] RIP: 0033:0x7f4af479ed87 [ 1831.908000] Code: Bad RIP value. [ 1831.908000] RSP: 002b:00007fff3f11af58 EFLAGS: 00000246 ORIG_RAX: 0000000000000015 [ 1831.908001] RAX: ffffffffffffffda RBX: 000000000000005c RCX: 00007f4af479ed87 [ 1831.908002] RDX: 0000000000632e65 RSI: 0000000000000000 RDI: 000000000227b460 [ 1831.908002] RBP: 00007fff3f11b000 R08: 0000000000000000 R09: 00007f4af47f9af0 [ 1831.908003] R10: 7974697275636573 R11: 0000000000000246 R12: 0000000000498875 [ 1831.908003] R13: 00007fff3f11dd8d R14: 000000000227b460 R15: 0000000000000000 [ 1831.908004] cc1 D 0 26477 26476 0x00000000 [ 1831.908005] Call Trace: [ 1831.908006] ? __schedule+0x21d/0x840 [ 1831.908007] schedule+0x28/0x80 [ 1831.908008] schedule_preempt_disabled+0xa/0x10 [ 1831.908009] __mutex_lock.isra.6+0x2c3/0x4b0 [ 1831.908032] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] [ 1831.908052] ? xfs_bmapi_read+0x129/0x340 [xfs] [ 1831.908054] ? inode_lru_list_add+0x20/0x40 [ 1831.908054] ? iput+0x16d/0x200 [ 1831.908077] ? xfs_iunlock+0x61/0x110 [xfs] [ 1831.908099] ? xfs_perag_get+0x27/0xb0 [xfs] [ 1831.908121] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] [ 1831.908144] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] [ 1831.908145] super_cache_scan+0x155/0x1a0 [ 1831.908146] do_shrink_slab+0x128/0x290 [ 1831.908148] shrink_slab+0x233/0x2b0 [ 1831.908149] shrink_node+0xe6/0x460 [ 1831.908150] do_try_to_free_pages+0xc6/0x370 [ 1831.908151] try_to_free_pages+0xf5/0x1c0 [ 1831.908152] __alloc_pages_slowpath+0x3aa/0xdc0 [ 1831.908153] __alloc_pages_nodemask+0x297/0x2c0 [ 1831.908154] alloc_pages_vma+0x7c/0x1f0 [ 1831.908155] __handle_mm_fault+0x8b5/0xf80 [ 1831.908157] handle_mm_fault+0x155/0x1d0 [ 1831.908158] __do_page_fault+0x1e6/0x460 [ 1831.908159] ? page_fault+0x8/0x30 [ 1831.908160] page_fault+0x1e/0x30 [ 1831.908161] RIP: 0033:0x7ff3864ab988 [ 1831.908162] Code: Bad RIP value. [ 1831.908162] RSP: 002b:00007ffe12e37508 EFLAGS: 00010283 [ 1831.908163] RAX: 00007ff38634e000 RBX: 00007ff3870bb198 RCX: 0000000000000001 [ 1831.908164] RDX: 0000000000000014 RSI: 0000000000000000 RDI: 00007ff38634e000 [ 1831.908164] RBP: 0000000000000005 R08: 000000000239e9f0 R09: 0000000000000000 [ 1831.908165] R10: 0000000000000000 R11: 000000000239e9f0 R12: 0000000000a2c800 [ 1831.908165] R13: 00007ff3863269c8 R14: 000000007ffff9d8 R15: 00007ff38711c000 [ 1831.908166] fixdep D 0 26479 26425 0x00000000 [ 1831.908167] Call Trace: [ 1831.908168] ? __schedule+0x21d/0x840 [ 1831.908169] schedule+0x28/0x80 [ 1831.908170] io_schedule+0x12/0x40 [ 1831.908171] generic_file_read_iter+0x3a4/0xc10 [ 1831.908172] ? page_cache_tree_insert+0xe0/0xe0 [ 1831.908195] xfs_file_buffered_aio_read+0x4b/0xd0 [xfs] [ 1831.908217] xfs_file_read_iter+0x6e/0xd0 [xfs] [ 1831.908219] __vfs_read+0x133/0x190 [ 1831.908220] vfs_read+0x8a/0x140 [ 1831.908221] ksys_read+0x4f/0xb0 [ 1831.908222] do_syscall_64+0x55/0x100 [ 1831.908224] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.908224] RIP: 0033:0x7fa104b76c21 [ 1831.908225] Code: fe ff ff 48 8d 3d 6f 68 0a 00 48 83 ec 08 e8 56 3d 02 00 66 0f 1f 44 00 00 48 8d 05 d9 fa 0d 00 8b 00 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 41 54 55 49 89 d4 53 [ 1831.908226] RSP: 002b:00007ffea7b75238 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 1831.908227] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fa104b76c21 [ 1831.908227] RDX: 00000000000002a6 RSI: 00000000014f5910 RDI: 0000000000000003 [ 1831.908228] RBP: 00000000014f5910 R08: 00000000014efa55 R09: 00007fa104bd1b40 [ 1831.908228] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000002a6 [ 1831.908229] R13: 00000000014fab76 R14: 0000000000000019 R15: 0000000000000007 [ 1831.908229] rm D 0 26480 26371 0x00000000 [ 1831.908230] Call Trace: [ 1831.908232] ? __schedule+0x21d/0x840 [ 1831.908233] ? __switch_to_asm+0x34/0x70 [ 1831.908233] schedule+0x28/0x80 [ 1831.908234] schedule_timeout+0x1d8/0x370 [ 1831.908235] ? __switch_to_asm+0x40/0x70 [ 1831.908236] ? __switch_to_asm+0x34/0x70 [ 1831.908237] ? __switch_to_asm+0x40/0x70 [ 1831.908239] ? __switch_to+0x159/0x4c0 [ 1831.908240] ? __switch_to_asm+0x34/0x70 [ 1831.908241] ? __switch_to_asm+0x40/0x70 [ 1831.908242] __down+0x7f/0xd0 [ 1831.908264] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.908265] down+0x3b/0x50 [ 1831.908287] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.908309] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.908331] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.908354] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.908377] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.908399] xfs_imap_to_bp+0x67/0xd0 [xfs] [ 1831.908421] xfs_iunlink_remove+0x2b6/0x430 [xfs] [ 1831.908445] xfs_ifree+0x42/0x140 [xfs] [ 1831.908475] xfs_inactive_ifree+0x9e/0x1c0 [xfs] [ 1831.908499] xfs_inactive+0x9e/0x140 [xfs] [ 1831.908522] xfs_fs_destroy_inode+0xb1/0x1c0 [xfs] [ 1831.908523] do_unlinkat+0x256/0x310 [ 1831.908524] do_syscall_64+0x55/0x100 [ 1831.908526] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.908526] RIP: 0033:0x7fce9b3a05b7 [ 1831.908528] Code: Bad RIP value. [ 1831.908528] RSP: 002b:00007ffc5b1d3528 EFLAGS: 00000206 ORIG_RAX: 0000000000000107 [ 1831.908529] RAX: ffffffffffffffda RBX: 00000000020248c0 RCX: 00007fce9b3a05b7 [ 1831.908530] RDX: 0000000000000000 RSI: 0000000002023690 RDI: 00000000ffffff9c [ 1831.908530] RBP: 0000000002023600 R08: 0000000000000003 R09: 0000000000000000 [ 1831.908531] R10: 0000000000000003 R11: 0000000000000206 R12: 00007ffc5b1d36e0 [ 1831.908531] R13: 0000000000000000 R14: 0000000000000000 R15: 00000000020248c0 [ 1831.908532] cc1 D 0 26483 26482 0x00000000 [ 1831.908533] Call Trace: [ 1831.908535] ? __schedule+0x21d/0x840 [ 1831.908535] schedule+0x28/0x80 [ 1831.908536] rwsem_down_read_failed+0xe1/0x140 [ 1831.908538] call_rwsem_down_read_failed+0x14/0x30 [ 1831.908539] down_read+0x1c/0x30 [ 1831.908540] path_openat+0xb9b/0x1650 [ 1831.908541] ? mem_cgroup_commit_charge+0x7f/0x550 [ 1831.908542] do_filp_open+0x93/0x100 [ 1831.908543] ? __handle_mm_fault+0x9dc/0xf80 [ 1831.908544] ? __check_object_size+0x158/0x184 [ 1831.908546] do_sys_open+0x186/0x210 [ 1831.908547] do_syscall_64+0x55/0x100 [ 1831.908548] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.908549] RIP: 0033:0x7f3e426469c0 [ 1831.908550] Code: Bad RIP value. [ 1831.908550] RSP: 002b:00007ffe6e0c7070 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.908551] RAX: ffffffffffffffda RBX: 00000000027634a0 RCX: 00007f3e426469c0 [ 1831.908552] RDX: 0000000000000100 RSI: 0000000002762300 RDI: 00000000ffffff9c [ 1831.908552] RBP: 00000000027adae0 R08: 00000000027b5f40 R09: 00000000f43cde6b [ 1831.908553] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000002762300 [ 1831.908553] R13: 00000000f43cde6b R14: 0000000002760fc0 R15: 0000000002760fc0 [ 1831.908554] as D 0 26484 26482 0x00000000 [ 1831.908555] Call Trace: [ 1831.908556] ? __schedule+0x21d/0x840 [ 1831.908557] schedule+0x28/0x80 [ 1831.908558] schedule_timeout+0x17e/0x370 [ 1831.908559] ? __next_timer_interrupt+0xc0/0xc0 [ 1831.908582] xfs_iget+0x17f/0x990 [xfs] [ 1831.908605] xfs_ialloc+0xf5/0x5a0 [xfs] [ 1831.908628] ? kmem_zone_alloc+0x61/0xe0 [xfs] [ 1831.908650] xfs_dir_ialloc+0x6c/0x220 [xfs] [ 1831.908673] xfs_create+0x224/0x620 [xfs] [ 1831.908696] xfs_generic_create+0x226/0x2c0 [xfs] [ 1831.908697] path_openat+0x1279/0x1650 [ 1831.908699] ? filemap_map_pages+0x139/0x3c0 [ 1831.908700] do_filp_open+0x93/0x100 [ 1831.908701] ? __handle_mm_fault+0xd6a/0xf80 [ 1831.908702] ? __check_object_size+0x158/0x184 [ 1831.908703] do_sys_open+0x186/0x210 [ 1831.908704] do_syscall_64+0x55/0x100 [ 1831.908705] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.908706] RIP: 0033:0x7fb4160ce9c0 [ 1831.908707] Code: Bad RIP value. [ 1831.908708] RSP: 002b:00007ffcbec13710 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.908709] RAX: ffffffffffffffda RBX: 0000000000a05280 RCX: 00007fb4160ce9c0 [ 1831.908709] RDX: 0000000000000242 RSI: 0000000000a29d50 RDI: 00000000ffffff9c [ 1831.908710] RBP: 00007fb4162ac7ca R08: 0000000000000002 R09: 00007fb4162ac7cb [ 1831.908710] R10: 00000000000001b6 R11: 0000000000000246 R12: 0000000000000000 [ 1831.908711] R13: 00007fb4162ac7c9 R14: 00000000ffffffff R15: 00007ffcbec13a20 [ 1831.908712] cc1 D 0 26487 26486 0x00000000 [ 1831.908713] Call Trace: [ 1831.908714] ? __schedule+0x21d/0x840 [ 1831.908715] schedule+0x28/0x80 [ 1831.908716] io_schedule+0x12/0x40 [ 1831.908717] generic_file_read_iter+0x3a4/0xc10 [ 1831.908718] ? page_cache_tree_insert+0xe0/0xe0 [ 1831.908740] xfs_file_buffered_aio_read+0x4b/0xd0 [xfs] [ 1831.908763] xfs_file_read_iter+0x6e/0xd0 [xfs] [ 1831.908764] __vfs_read+0x133/0x190 [ 1831.908766] vfs_read+0x8a/0x140 [ 1831.908767] ksys_read+0x4f/0xb0 [ 1831.908768] do_syscall_64+0x55/0x100 [ 1831.908769] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.908770] RIP: 0033:0x7fd0adf56c21 [ 1831.908771] Code: Bad RIP value. [ 1831.908772] RSP: 002b:00007fff4be63908 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 1831.908772] RAX: ffffffffffffffda RBX: 00000000000002a6 RCX: 00007fd0adf56c21 [ 1831.908773] RDX: 00000000000002a6 RSI: 0000000002e1a8f0 RDI: 0000000000000005 [ 1831.908773] RBP: 0000000002e39ae0 R08: 000000000120d1f6 R09: 000000006feaa6fe [ 1831.908774] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000002e1a8f0 [ 1831.908774] R13: 0000000002ef6800 R14: 0000000000000000 R15: 0000000000000000 [ 1831.908775] as D 0 26488 26486 0x00000000 [ 1831.908776] Call Trace: [ 1831.908777] ? __schedule+0x21d/0x840 [ 1831.908778] schedule+0x28/0x80 [ 1831.908779] schedule_timeout+0x1d8/0x370 [ 1831.908780] __down+0x7f/0xd0 [ 1831.908802] ? xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.908803] down+0x3b/0x50 [ 1831.908825] xfs_buf_lock+0x32/0xf0 [xfs] [ 1831.908847] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] [ 1831.908870] xfs_buf_get_map+0x40/0x2c0 [xfs] [ 1831.908892] xfs_buf_read_map+0x28/0x180 [xfs] [ 1831.908915] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] [ 1831.908937] xfs_read_agi+0x9e/0x140 [xfs] [ 1831.908959] xfs_ialloc_read_agi+0x34/0xd0 [xfs] [ 1831.908980] xfs_dialloc+0xe7/0x2b0 [xfs] [ 1831.909003] xfs_ialloc+0x6b/0x5a0 [xfs] [ 1831.909026] ? kmem_zone_alloc+0x61/0xe0 [xfs] [ 1831.909049] xfs_dir_ialloc+0x6c/0x220 [xfs] [ 1831.909072] xfs_create+0x224/0x620 [xfs] [ 1831.909095] xfs_generic_create+0x226/0x2c0 [xfs] [ 1831.909096] path_openat+0x1279/0x1650 [ 1831.909097] ? filemap_map_pages+0x139/0x3c0 [ 1831.909098] do_filp_open+0x93/0x100 [ 1831.909099] ? __handle_mm_fault+0xd6a/0xf80 [ 1831.909100] ? __check_object_size+0x158/0x184 [ 1831.909102] do_sys_open+0x186/0x210 [ 1831.909103] do_syscall_64+0x55/0x100 [ 1831.909104] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1831.909105] RIP: 0033:0x7f435fabe9c0 [ 1831.909106] Code: Bad RIP value. [ 1831.909106] RSP: 002b:00007ffd8f4c1980 EFLAGS: 00000246 ORIG_RAX: 0000000000000101 [ 1831.909107] RAX: ffffffffffffffda RBX: 0000000001df5280 RCX: 00007f435fabe9c0 [ 1831.909108] RDX: 0000000000000242 RSI: 0000000001e19a00 RDI: 00000000ffffff9c [ 1831.909108] RBP: 00007f435fc9c7ca R08: 0000000000000002 R09: 00007f435fc9c7cb [ 1831.909109] R10: 00000000000001b6 R11: 0000000000000246 R12: 0000000000000000 [ 1831.909109] R13: 00007f435fc9c7c9 R14: 00000000ffffffff R15: 00007ffd8f4c1c90 Should have mentioned that this was done without turning off inode reclaim and after a reboot. On Tue, Jan 29, 2019 at 12:43:39AM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > > --- Comment #4 from Roger (rogan6710@gmail.com) --- > "If all else fails, read the man page" ;) > The complete dmesg output is a litte bit too big for the > system here. they only allow 65535 characters Attach it to the bug rather than pasting in line. Can be much bigger that way. > Last Output: > [ 1831.904739] sysrq: SysRq : Show Blocked State > [ 1831.904745] task PC stack pid father > [ 1831.904752] kswapd0 D 0 85 2 0x80000000 > [ 1831.904753] Call Trace: > [ 1831.904758] ? __schedule+0x21d/0x840 > [ 1831.904760] schedule+0x28/0x80 > [ 1831.904761] schedule_preempt_disabled+0xa/0x10 > [ 1831.904762] __mutex_lock.isra.6+0x2c3/0x4b0 > [ 1831.904806] ? xfs_perag_get_tag+0x3d/0xe0 [xfs] > [ 1831.904830] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] Waiting on something else reclaiming inodes from that AG. > [ 1831.904930] xfsaild/sdc1 D 0 1446 2 0x80000000 > [ 1831.904931] Call Trace: > [ 1831.904932] ? __schedule+0x21d/0x840 > [ 1831.904933] schedule+0x28/0x80 > [ 1831.904956] xfs_log_force+0x166/0x2e0 [xfs] Waiting on a log force. > [ 1831.905012] Xorg D 0 1496 1495 0x00000000 > [ 1831.905013] Call Trace: > [ 1831.905014] ? __schedule+0x21d/0x840 > [ 1831.905015] schedule+0x28/0x80 > [ 1831.905016] schedule_preempt_disabled+0xa/0x10 > [ 1831.905017] __mutex_lock.isra.6+0x2c3/0x4b0 > [ 1831.905039] ? xfs_perag_get_tag+0x3d/0xe0 [xfs] > [ 1831.905061] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] > [ 1831.905084] ? xfs_perag_get+0x27/0xb0 [xfs] > [ 1831.905106] ? xfs_inode_set_reclaim_tag+0x67/0x140 [xfs] > [ 1831.905128] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] > [ 1831.905130] super_cache_scan+0x155/0x1a0 > [ 1831.905131] do_shrink_slab+0x128/0x290 > [ 1831.905132] shrink_slab+0x233/0x2b0 > [ 1831.905133] shrink_node+0xe6/0x460 > [ 1831.905135] do_try_to_free_pages+0xc6/0x370 > [ 1831.905136] try_to_free_pages+0xf5/0x1c0 > [ 1831.905137] __alloc_pages_slowpath+0x3aa/0xdc0 > [ 1831.905139] ? enqueue_entity+0x36d/0x7e0 > [ 1831.905140] __alloc_pages_nodemask+0x297/0x2c0 > [ 1831.905142] kmalloc_order+0x14/0x40 > [ 1831.905143] kmalloc_order_trace+0x1e/0xa0 > [ 1831.905198] dc_create_state+0x19/0x30 [amdgpu] > [ 1831.905234] amdgpu_dm_atomic_check+0xc6/0x3b0 [amdgpu] > [ 1831.905248] drm_atomic_check_only+0x460/0x660 [drm] > [ 1831.905258] ? drm_atomic_set_fb_for_plane+0x53/0x80 [drm] > [ 1831.905267] drm_atomic_nonblocking_commit+0x13/0x50 [drm] > [ 1831.905276] drm_atomic_helper_page_flip+0x5b/0x90 [drm_kms_helper] > [ 1831.905285] drm_mode_page_flip_ioctl+0x553/0x5b0 [drm] > [ 1831.905294] ? drm_mode_cursor2_ioctl+0x10/0x10 [drm] > [ 1831.905301] drm_ioctl_kernel+0xa1/0xf0 [drm] > [ 1831.905310] drm_ioctl+0x206/0x3a0 [drm] Ok, that looks familiar. GPU in a "nonblocking" code path, doing a blocking memory allocation. Yeah, dc_create_state() is doing a GFP_KERNEL allocation, which means the memory allocation is allowed to block waiting for memory reclaim.... > [ 1831.905380] mc D 0 1866 1740 0x00000000 > [ 1831.905381] Call Trace: > [ 1831.905383] schedule+0x28/0x80 > [ 1831.905384] schedule_preempt_disabled+0xa/0x10 > [ 1831.905429] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] > [ 1831.905522] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] > [ 1831.905523] super_cache_scan+0x155/0x1a0 > [ 1831.905524] do_shrink_slab+0x128/0x290 > [ 1831.905526] shrink_slab+0x233/0x2b0 > [ 1831.905527] shrink_node+0xe6/0x460 > [ 1831.905528] do_try_to_free_pages+0xc6/0x370 > [ 1831.905529] try_to_free_pages+0xf5/0x1c0 > [ 1831.905530] __alloc_pages_slowpath+0x3aa/0xdc0 > [ 1831.905537] __alloc_pages_nodemask+0x297/0x2c0 > [ 1831.905538] __do_page_cache_readahead+0xb1/0x1b0 > [ 1831.905539] ondemand_readahead+0x1f9/0x2c0 > [ 1831.905541] generic_file_read_iter+0x738/0xc10 > [ 1831.905542] ? page_cache_tree_insert+0xe0/0xe0 > [ 1831.905543] nfs_file_read+0x5d/0x80 Oh, NFS read. XFS clears GFP_FS from it's mapping mask so page cache demand doesn't end up blocked on filesystem reclaim. > [ 1831.905574] kworker/u16:4 D 0 14955 2 0x80000000 > [ 1831.905577] Workqueue: writeback wb_workfn (flush-8:32) > [ 1831.905578] Call Trace: > [ 1831.905580] schedule+0x28/0x80 > [ 1831.905581] schedule_timeout+0x1d8/0x370 > [ 1831.905607] __down+0x7f/0xd0 > [ 1831.905630] down+0x3b/0x50 > [ 1831.905652] xfs_buf_lock+0x32/0xf0 [xfs] > [ 1831.905675] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] > [ 1831.905698] xfs_buf_get_map+0x40/0x2c0 [xfs] > [ 1831.905720] xfs_buf_read_map+0x28/0x180 [xfs] > [ 1831.905743] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] > [ 1831.905764] xfs_read_agf+0x94/0x120 [xfs] > [ 1831.905785] xfs_alloc_read_agf+0x47/0x1b0 [xfs] > [ 1831.905805] xfs_alloc_fix_freelist+0x377/0x430 [xfs] > [ 1831.905851] xfs_alloc_vextent+0x121/0x580 [xfs] > [ 1831.905871] xfs_bmap_btalloc+0x420/0x890 [xfs] > [ 1831.905893] xfs_bmapi_write+0x5f5/0xb80 [xfs] > [ 1831.905916] xfs_iomap_write_allocate+0x176/0x380 [xfs] > [ 1831.905939] xfs_map_blocks+0x186/0x450 [xfs] > [ 1831.905962] xfs_do_writepage+0x123/0x440 [xfs] > [ 1831.905963] write_cache_pages+0x1dd/0x470 Writeback blocked waiting for the AGF to be unlocked so it can do allocation. > [ 1831.906033] make D 0 25592 24315 0x00000000 > [ 1831.906034] Call Trace: > [ 1831.906037] schedule+0x28/0x80 > [ 1831.906037] rwsem_down_read_failed+0xe1/0x140 > [ 1831.906040] call_rwsem_down_read_failed+0x14/0x30 > [ 1831.906041] down_read+0x1c/0x30 > [ 1831.906042] lookup_slow+0x27/0x50 > [ 1831.906043] walk_component+0x1bf/0x4a0 > [ 1831.906048] path_lookupat.isra.55+0x6d/0x220 > [ 1831.906054] filename_lookup.part.69+0xa0/0x170 > [ 1831.906059] vfs_statx+0x73/0xe0 Blocked in VFS pathname walk. > [ 1831.906076] cc1 D 0 26405 26404 0x00000000 > [ 1831.906077] Call Trace: > [ 1831.906101] schedule+0x28/0x80 > [ 1831.906102] schedule_timeout+0x1d8/0x370 > [ 1831.906128] wait_for_completion+0xad/0x130 > [ 1831.906173] xfs_buf_iowait+0x27/0xd0 [xfs] > [ 1831.906195] __xfs_buf_submit+0xd7/0x230 [xfs] > [ 1831.906218] xfs_bwrite+0x25/0x60 [xfs] > [ 1831.906240] xfs_reclaim_inode+0x309/0x330 [xfs] > [ 1831.906263] xfs_reclaim_inodes_ag+0x1b1/0x300 [xfs] > [ 1831.906331] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] > [ 1831.906332] super_cache_scan+0x155/0x1a0 > [ 1831.906333] do_shrink_slab+0x128/0x290 > [ 1831.906335] shrink_slab+0x233/0x2b0 > [ 1831.906336] shrink_node+0xe6/0x460 > [ 1831.906337] do_try_to_free_pages+0xc6/0x370 > [ 1831.906338] try_to_free_pages+0xf5/0x1c0 > [ 1831.906339] __alloc_pages_slowpath+0x3aa/0xdc0 > [ 1831.906340] __alloc_pages_nodemask+0x297/0x2c0 > [ 1831.906342] alloc_pages_vma+0x7c/0x1f0 > [ 1831.906343] __handle_mm_fault+0x8b5/0xf80 > [ 1831.906345] handle_mm_fault+0x155/0x1d0 > [ 1831.906346] __do_page_fault+0x1e6/0x460 > [ 1831.906349] page_fault+0x1e/0x30 And there's our reclaimer that is doing IO. Page fault on an executable page. > [ 1831.906355] cc1 D 0 26411 26410 0x00000000 > [ 1831.906356] Call Trace: > [ 1831.906358] schedule+0x28/0x80 > [ 1831.906359] schedule_preempt_disabled+0xa/0x10 > [ 1831.906360] __mutex_lock.isra.6+0x2c3/0x4b0 > [ 1831.906383] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] > [ 1831.906474] xfs_reclaim_inodes_nr+0x31/0x40 [xfs] > [ 1831.906476] super_cache_scan+0x155/0x1a0 > [ 1831.906477] do_shrink_slab+0x128/0x290 > [ 1831.906478] shrink_slab+0x233/0x2b0 > [ 1831.906479] shrink_node+0xe6/0x460 > [ 1831.906481] do_try_to_free_pages+0xc6/0x370 > [ 1831.906481] try_to_free_pages+0xf5/0x1c0 > [ 1831.906483] __alloc_pages_slowpath+0x3aa/0xdc0 > [ 1831.906485] __alloc_pages_nodemask+0x297/0x2c0 > [ 1831.906486] alloc_pages_vma+0x7c/0x1f0 > [ 1831.906487] wp_page_copy+0x4f0/0x740 > [ 1831.906488] do_wp_page+0x8a/0x5f0 > [ 1831.906489] __handle_mm_fault+0xafc/0xf80 > [ 1831.906491] handle_mm_fault+0x155/0x1d0 > [ 1831.906492] __do_page_fault+0x1e6/0x460 same thing, but blocked on the per-ag reclaim lock. > [ 1831.906500] cc1 D 0 26415 26414 0x00000000 > [ 1831.906501] Call Trace: > [ 1831.906503] schedule+0x28/0x80 > [ 1831.906504] schedule_preempt_disabled+0xa/0x10 > [ 1831.906505] __mutex_lock.isra.6+0x2c3/0x4b0 > [ 1831.906528] xfs_reclaim_inodes_ag+0x299/0x300 [xfs] same thing. > [ 1831.906641] cc1 D 0 26430 26428 0x00000000 same thing. > [ 1831.906783] fixdep D 0 26436 26319 0x00000000 > [ 1831.906784] Call Trace: > [ 1831.906786] schedule+0x28/0x80 > [ 1831.906787] rwsem_down_read_failed+0xe1/0x140 > [ 1831.906788] call_rwsem_down_read_failed+0x14/0x30 > [ 1831.906789] down_read+0x1c/0x30 > [ 1831.906790] path_openat+0xb9b/0x1650 > [ 1831.906813] do_filp_open+0x93/0x100 > [ 1831.906816] do_sys_open+0x186/0x210 Blocked in pathwalk. > [ 1831.906825] cc1 D 0 26450 26449 0x00000000 > [ 1831.906826] Call Trace: > [ 1831.906850] schedule+0x28/0x80 > [ 1831.906851] schedule_timeout+0x1d8/0x370 > [ 1831.906875] wait_for_completion+0xad/0x130 > [ 1831.906920] xfs_buf_iowait+0x27/0xd0 [xfs] > [ 1831.906942] __xfs_buf_submit+0xd7/0x230 [xfs] > [ 1831.906965] xfs_buf_read_map+0xc1/0x180 [xfs] > [ 1831.906988] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] > [ 1831.907010] xfs_imap_to_bp+0x67/0xd0 [xfs] > [ 1831.907031] xfs_iread+0x82/0x1f0 [xfs] > [ 1831.907055] xfs_iget+0x20f/0x990 [xfs] > [ 1831.907099] xfs_lookup+0xa4/0x120 [xfs] > [ 1831.907123] xfs_vn_lookup+0x70/0xa0 [xfs] > [ 1831.907124] path_openat+0xaff/0x1650 > [ 1831.907125] do_filp_open+0x93/0x100 Blocked in open(), waiting for inode buffer read. > [ 1831.907138] cc1 D 0 26454 26453 0x00000000 > [ 1831.907139] Call Trace: > [ 1831.907141] schedule+0x28/0x80 > [ 1831.907142] schedule_timeout+0x1d8/0x370 > [ 1831.907143] __down+0x7f/0xd0 > [ 1831.907169] down+0x3b/0x50 > [ 1831.907191] xfs_buf_lock+0x32/0xf0 [xfs] > [ 1831.907213] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] > [ 1831.907235] xfs_buf_get_map+0x40/0x2c0 [xfs] > [ 1831.907258] xfs_buf_read_map+0x28/0x180 [xfs] > [ 1831.907303] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] > [ 1831.907325] xfs_read_agi+0x9e/0x140 [xfs] > [ 1831.907347] xfs_ialloc_read_agi+0x34/0xd0 [xfs] > [ 1831.907368] xfs_dialloc+0xe7/0x2b0 [xfs] > [ 1831.907391] xfs_ialloc+0x6b/0x5a0 [xfs] INode allocation in open call, blocked waiting on AGI buffer lock. > [ 1831.907498] rm D 0 26462 26356 0x00000000 > [ 1831.907498] Call Trace: > [ 1831.907501] schedule+0x28/0x80 > [ 1831.907501] schedule_timeout+0x1d8/0x370 > [ 1831.907503] __down+0x7f/0xd0 > [ 1831.907525] down+0x3b/0x50 > [ 1831.907547] xfs_buf_lock+0x32/0xf0 [xfs] > [ 1831.907570] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] > [ 1831.907592] xfs_buf_get_map+0x40/0x2c0 [xfs] > [ 1831.907614] xfs_buf_read_map+0x28/0x180 [xfs] > [ 1831.907637] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] > [ 1831.907659] xfs_read_agi+0x9e/0x140 [xfs] > [ 1831.907682] xfs_iunlink+0x4d/0x140 [xfs] > [ 1831.907705] xfs_remove+0x1ec/0x2e0 [xfs] > [ 1831.907728] xfs_vn_unlink+0x55/0xa0 [xfs] Unlink, blocked on AGI buffer lock. > [ 1831.907739] rm D 0 26472 26300 0x00000000 Ditto. > [ 1831.907981] gcc D 0 26474 26473 0x00000000 > [ 1831.907982] Call Trace: > [ 1831.907984] schedule+0x28/0x80 > [ 1831.907985] rwsem_down_read_failed+0xe1/0x140 > [ 1831.907987] call_rwsem_down_read_failed+0x14/0x30 > [ 1831.907988] down_read+0x1c/0x30 > [ 1831.907988] lookup_slow+0x27/0x50 > [ 1831.907989] walk_component+0x1bf/0x4a0 > [ 1831.907990] path_lookupat.isra.55+0x6d/0x220 > [ 1831.907992] filename_lookup.part.69+0xa0/0x170 > [ 1831.907996] do_faccessat+0xa2/0x240 Blocked in pathname walk. > [ 1831.908004] cc1 D 0 26477 26476 0x00000000 Pagefault -> per ag shrinker lock again. > [ 1831.908166] fixdep D 0 26479 26425 0x00000000 > [ 1831.908167] Call Trace: > [ 1831.908169] schedule+0x28/0x80 > [ 1831.908170] io_schedule+0x12/0x40 > [ 1831.908171] generic_file_read_iter+0x3a4/0xc10 > [ 1831.908195] xfs_file_buffered_aio_read+0x4b/0xd0 [xfs] > [ 1831.908217] xfs_file_read_iter+0x6e/0xd0 [xfs] > [ 1831.908219] __vfs_read+0x133/0x190 > [ 1831.908220] vfs_read+0x8a/0x140 waiting on read IO. Disk is busy. > [ 1831.908229] rm D 0 26480 26371 0x00000000 > [ 1831.908230] Call Trace: > [ 1831.908233] schedule+0x28/0x80 > [ 1831.908234] schedule_timeout+0x1d8/0x370 > [ 1831.908242] __down+0x7f/0xd0 > [ 1831.908265] down+0x3b/0x50 > [ 1831.908287] xfs_buf_lock+0x32/0xf0 [xfs] > [ 1831.908309] xfs_buf_find.isra.30+0x3b4/0x5e0 [xfs] > [ 1831.908331] xfs_buf_get_map+0x40/0x2c0 [xfs] > [ 1831.908354] xfs_buf_read_map+0x28/0x180 [xfs] > [ 1831.908377] xfs_trans_read_buf_map+0xb4/0x2f0 [xfs] > [ 1831.908399] xfs_imap_to_bp+0x67/0xd0 [xfs] > [ 1831.908421] xfs_iunlink_remove+0x2b6/0x430 [xfs] > [ 1831.908445] xfs_ifree+0x42/0x140 [xfs] > [ 1831.908475] xfs_inactive_ifree+0x9e/0x1c0 [xfs] > [ 1831.908499] xfs_inactive+0x9e/0x140 [xfs] > [ 1831.908522] xfs_fs_destroy_inode+0xb1/0x1c0 [xfs] Unlink, holds AGI buffer lock, blocked on inode buffer lock. > [ 1831.908532] cc1 D 0 26483 26482 0x00000000 Blocked in path walk. > [ 1831.908554] as D 0 26484 26482 0x00000000 > [ 1831.908555] Call Trace: > [ 1831.908557] schedule+0x28/0x80 > [ 1831.908558] schedule_timeout+0x17e/0x370 > [ 1831.908582] xfs_iget+0x17f/0x990 [xfs] > [ 1831.908605] xfs_ialloc+0xf5/0x5a0 [xfs] > [ 1831.908650] xfs_dir_ialloc+0x6c/0x220 [xfs] > [ 1831.908673] xfs_create+0x224/0x620 [xfs] > [ 1831.908696] xfs_generic_create+0x226/0x2c0 [xfs] > [ 1831.908697] path_openat+0x1279/0x1650 > [ 1831.908700] do_filp_open+0x93/0x100 Blocked in inode allocation, most likely waiting to for a recently freed inode to be reclaimed fully > [ 1831.908712] cc1 D 0 26487 26486 0x00000000 Waiting on read. > [ 1831.908775] as D 0 26488 26486 0x00000000 waiting on AGI buffer lock for allocation. OK, so your disks are busy and it would appear that the problem is memory reclaim driving the inode cache hard into reclaiming dirty inodes and having to wait for IO to complete before it can make progress. That's currently the only behaviour we have that stands between "systems works" and "system can be driven into OOM kill death by direct reclaim". i.e. it prevents memory reclaim from skipping and making insufficient progress and winding the reclaim priority up until it triggers the OOM killer because it takes a lot of time to write back dirty inodes... It looks like 4.18->4.19 has put a lot more pressure on the inode caches and is driving them to block on dirty inodes much, much more often. It would be instructive to know if this behaviour appeared in 4.19-rc1 or not, because the memory reclaim shrinker algorithms were significantly changed in the 4.19 merge window.... Cheers, Dave. I'll do a test on 4.19-rc1 asap, and use the "Add an attachment" for dmesg from that test. Have to get some sleep first. Created attachment 280837 [details]
meminfo and xfs_info 4.19.0-rc1
Created attachment 280839 [details]
dmesg with sysrq show blocked state for a run on 4.19.0-rc1
I did not experience these problems with 4.19.0-rc1. The compile completed in 3min 38s which is about as good as the best tests on pre 4.19 that I've done on any file system. I had to do the test "nomodeset" in console mode because the vega10 drivers for my vega64 stopped working in this version. Now onto testing rc2... Now I have tested all rc versions as well. None of them have the problem. I'm watching "top" as the compile executes and seeing a _large_ difference in how the problem free kernel versions handles buff/cache versus the others. Beginnig from rc5, might have been earlier also, cache get's released, sometimes almost all of it, and begins to fill up slowly again, while for instance on 4.19.18 it get's almost completely filled (23.5 of 24 G) and is not released unless the copying is manually halted. Considering that rc8 which I believe was released as 4.19.0 did not show any problems on my 24G machine I must have managed to get a false positive on 4.19.0. The machine I tested that on has less ram (8G) but I don't know if that matters.
Anyhow, after a filthy amount of copying and compiling I can say that
something probably went wrong between 4.19.2, which is ok, and 4.19.3
which is not, at least on this 9590.
I downloaded, compiled, and tested all rc versions, 4.19.{2,3,5,9} and verified that 4.19.{3,5,9,18} all have the problems described above on the 9590.
All tests were done in console (nomodeset) directly after boot.
On Tue, Jan 29, 2019 at 05:55:00PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > > --- Comment #12 from Roger (rogan6710@gmail.com) --- > Now I have tested all rc versions as well. None of them have the problem. > I'm watching "top" as the compile executes and seeing a _large_ difference > in how the problem free kernel versions handles buff/cache versus the others. You've been busy! And your results are very interesting. > Beginnig from rc5, might have been earlier also, cache get's released, > sometimes almost all of it, and begins to fill up slowly again, Which I'd consider bad behaviour - trashing the entire working set because memory pressure is occurring is pathological behaviour. Can you confirm which -rcX that behaviour starts in? e.g. between -rc4 and -rc5 there is this commit: 172b06c32b94 mm: slowly shrink slabs with a relatively small number of objects Which does change the way that the inode caches are reclaimed by forcably triggering reclaim for caches that would have previously been ignored. That's one of the "red flag" commits I noticed when first looking at the history between 4.18 and 4.19.... > while for > instance on 4.19.18 it get's almost completely filled (23.5 of 24 G) and is > not > released unless the copying is manually halted. Which is how I'd expect memory reclaim to work - only free enough for the current demand. What seems to be the issue is that it's not freeing enough page cache, and so dumping more reclaim load on the shrinkers and that's driving XFS inode reclaim into IO and blocking... Looking at the sysrq-w info from 4.19-rc1, it's all just waiting on IO as the disk is busy, as I'd expect to see. Given that this doesn't appear to be a problem in the early 4.19-rcX kernels, that means it's either a problem in the released 4.19.0 or it's something backported from a 4.20 kernel into the stable kernels. SO, three questions: - did you test a 4.19.0 kernel? - if not, can you test it? - if 4.19.0 doesn't have the problem, can you sample a couple of 4.19.x stable kernels (say .5, .10 and .15, but definitely not .11 or .12 as they contain memory corrupting bugs from an auto-backport of a buggy, untested 4.20-rc commit) Basically, we're now at the point where this needs to be isolated to the stable kernel series, and then we have a much smaller bunch of commits that might be causing it. Cheers, Dave. On Tue, Jan 29, 2019 at 09:19:52PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > > --- Comment #13 from Roger (rogan6710@gmail.com) --- > Considering that rc8 which I believe was released as 4.19.0 did not show any > problems on my 24G machine I must have managed to get a false positive on > 4.19.0. The machine I tested that on has less ram (8G) but I don't know if > that > matters. > > Anyhow, after a filthy amount of copying and compiling I can say that > something probably went wrong between 4.19.2, which is ok, and 4.19.3 > which is not, at least on this 9590. Thank you! We crossed streams - I was writing the email suggesting this when, in fact, your were way ahead of me. > I downloaded, compiled, and tested all rc versions, 4.19.{2,3,5,9} and > verified > that 4.19.{3,5,9,18} all have the problems described above on the 9590. > All tests were done in console (nomodeset) directly after boot. Ok, I'll have a look at the 4.19.2 -> 4.19.3 history now and see what pops out. Cheers, Dave. On Tue, Jan 29, 2019 at 09:41:21PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > --- Comment #14 from Dave Chinner (david@fromorbit.com) --- > > --- Comment #12 from Roger (rogan6710@gmail.com) --- > > Beginnig from rc5, might have been earlier also, cache get's released, > > sometimes almost all of it, and begins to fill up slowly again, > > Which I'd consider bad behaviour - trashing the entire working set > because memory pressure is occurring is pathological behaviour. > > Can you confirm which -rcX that behaviour starts in? e.g. between > -rc4 and -rc5 there is this commit: > > 172b06c32b94 mm: slowly shrink slabs with a relatively small number of > objects > > Which does change the way that the inode caches are reclaimed by > forcably triggering reclaim for caches that would have previously > been ignored. That's one of the "red flag" commits I noticed when > first looking at the history between 4.18 and 4.19.... And now, added in 4.19.3: $ gl -n 1 5ebac3b957a9 -p commit 5ebac3b957a91c921d2f1a7953caafca18aa6260 Author: Roman Gushchin <guro@fb.com> Date: Fri Nov 16 15:08:18 2018 -0800 mm: don't reclaim inodes with many attached pages commit a76cf1a474d7dbcd9336b5f5afb0162baa142cf0 upstream. Spock reported that commit 172b06c32b94 ("mm: slowly shrink slabs with a relatively small number of objects") leads to a regression on his setup: periodically the majority of the pagecache is evicted without an obvious reason, while before the change the amount of free memory was balancing around the watermark. The reason behind is that the mentioned above change created some minimal background pressure on the inode cache. The problem is that if an inode is considered to be reclaimed, all belonging pagecache page are stripped, no matter how many of them are there. So, if a huge multi-gigabyte file is cached in the memory, and the goal is to reclaim only few slab objects (unused inodes), we still can eventually evict all gigabytes of the pagecache at once. The workload described by Spock has few large non-mapped files in the pagecache, so it's especially noticeable. To solve the problem let's postpone the reclaim of inodes, which have more than 1 attached page. Let's wait until the pagecache pages will be evicted naturally by scanning the corresponding LRU lists, and only then reclaim the inode structure. Link: http://lkml.kernel.org/r/20181023164302.20436-1-guro@fb.com Signed-off-by: Roman Gushchin <guro@fb.com> Reported-by: Spock <dairinin@gmail.com> Tested-by: Spock <dairinin@gmail.com> Reviewed-by: Andrew Morton <akpm@linux-foundation.org> Cc: Michal Hocko <mhocko@kernel.org> Cc: Rik van Riel <riel@surriel.com> Cc: Randy Dunlap <rdunlap@infradead.org> Cc: <stable@vger.kernel.org> [4.19.x] Signed-off-by: Andrew Morton <akpm@linux-foundation.org> Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org> Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org> SO, basically, I was right - the slab shrinking change in 4.18-rc5 caused the page cache to saw tooth like you reported, and there is a "fix" for it in 4.19.3. What does that "fix" do? It stops inode reclaim from inodes with cached pages attached. diff --git a/fs/inode.c b/fs/inode.c index 42f6d25f32a5..65ae154df760 100644 --- a/fs/inode.c +++ b/fs/inode.c @@ -730,8 +730,11 @@ static enum lru_status inode_lru_isolate(struct list_head *item, return LRU_REMOVED; } - /* recently referenced inodes get one more pass */ - if (inode->i_state & I_REFERENCED) { + /* + * Recently referenced inodes and inodes with many attached pages + * get one more pass. + */ + if (inode->i_state & I_REFERENCED || inode->i_data.nrpages > 1) { inode->i_state &= ~I_REFERENCED; spin_unlock(&inode->i_lock); return LRU_ROTATE; Basically, what happened before this patch was that when an inode was aged out of the cache due to the shrinker cycling over it, it's page cache was reclaimed and then the inode reclaimed. Now, the inode does not get reclaimed and the page cache is not reclaimed. When you have lots of large files in your workload, that means the inode cache turning over can no longer reclaim those inodes, and so the inode can only be reclaimed after memory reclaim has reclaimed the entire page cache for an inode. That's a /massive/ change in behaviour, and it means that clean inodes with cached pages attached can no longer be reclaimed by the inode cache shrinker. Which will drive the inode cache shrinker into trying to reclaim dirty inodes..... Can you revert the above patch and see if the problem goes away? Cheers, Dave. I suspected that commit as well... I would love to try that revert. I have never done one so I'm not sure how to go about it. I'll have to read up a little. Do I revert in 4.19.3 or the latest ? (In reply to Roger from comment #17) > I suspected that commit as well... > I would love to try that revert. I have never done one so I'm not sure how > to go about it. I'll have to read up a little. > Do I revert in 4.19.3 or the latest ? Reverting in 4.19.3 and testing that would be ideal, though it would probably revert just fine in the lastest tree. If yuive been building from a git tree, then: $ git revert 5ebac3b957a9 and rebuild is all you need to do (assuming it cleanly reverts). If you've been building from a downloaded tarball, then you'll need to apply the revert yourself. I'll attach a revert patch, which you can apply via: $ patch -p1 < revert.patch and rebuild the kernel (assuming it applies cleanly - use --dry-run to test). Or you can just manually change the code in an editor to set the code back to the original. i.e: /* recently referenced inodes get one more pass */ if (inode->i_state & I_REFERENCED) { -Dave. Created attachment 280859 [details]
revert patch
I used my trusty old emacs and remove the second conditional in the if statement. I'll have to use the console with 4.19.3 so it'll take approximately 16 + 10 min before I'm back... Worked very well :) (compile took 3min 31s) I saw the same behaviour as I first noticed on rc5, sawtoothing buff/cache. On Tue, Jan 29, 2019 at 11:03:21PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=202441 > > --- Comment #21 from Roger (rogan6710@gmail.com) --- > Worked very well :) (compile took 3min 31s) > I saw the same behaviour as I first noticed on rc5, sawtoothing buff/cache. Ok, thanks for confirming. I doubt there's going to be a fast fix for this, though, but we'll see how it goes. Cheers, Dave. Me and my kernel compiling workhorse says thank you very much :) Let me know if any ideas pop up and if I should try them. A few moments ago, a piece of the puzzle fell into place. The problem persists. All this revert did, was to make the issue granularity dependent from what I gather. While redoing the test with all those source trees I used to compile the kernels, the same exact problem came back. The earlier tests were done using mostly multi GB files. After some more testing I found out that rc4 is completely problem free in this regard, but rc5 is definately not, so the real culprit was probably introduced in rc5. After applying our inode.c revert on 4.19.18, it shows the same behaviour as rc5. I can test on intermediate versions as well if necessary, as I still have them all compiled and ready. If I had been less strict in my testing I probably would have discovered that the problem was present earlier than 4.19.3. Mr Gushins commit made it more visible. I'm going back to work after two days off, so I might not be able to respond inside your working hours, but I'll keep checking in on this as I get a chance. I have tried both your suggested reverts on a customized non-modular server oriented 5.0.0-rc3, and subjected the poor machine to a brutal test: 8 "simultaneous" defonfig compiles, a sort of load balancing test I do to evaluate io and cpu, on a xfs formatted hdd, while copying GB sized files to a btrfs formatted hdd ditto and my, by now, significant collection of kernel source trees to yet another ext4 formatted hdd. All this while watching a (very boring) youtube HD video and writing this. All working perfectly with a very responsive ui, while buff/cache is kept at 20-23 Gb, and almost no cpu idle. I have also done the earlier tests with very good results :) 5.5.0-rc3 locked up completely, and I had do do a "Norwegian reboot", when I tried loading it like that, earlier, without the reverts. From my point of view, they entirely solve this particular problem. I'll continue testing the reverts on other versions as well. All kernel compile processes finished with a delta t < 5o seconds, good :) (now try that on jfs ;)) I've done testing on distribution standard 4.19.19 "generic" kernel with the reverts applied, all seems ok again :) [....] When vfs_cache_pressure=0, the kernel will never reclaim dentries and inodes due to memory pressure and this can easily lead to out-of-memory conditions. [....] I wish that was true. I have it set to 0, and I have 32 GiB RAM of which 23 GiB free when doing the test using XFS filesystem: $ du -sh $ sleep 60 # (dentries forgotten, the next du takes a minute to run (SATA rust platter disk)) $ du -sh kernel 5.10.80. No swap. MemTotal: 32759756 kB MemFree: 23807992 kB MemAvailable: 23774316 kB Buffers: 24 kB Cached: 765240 kB SwapCached: 0 kB Active: 290420 kB Inactive: 3859348 kB Active(anon): 168968 kB Inactive(anon): 3720380 kB Active(file): 121452 kB Inactive(file): 138968 kB Unevictable: 18304 kB Mlocked: 18304 kB SwapTotal: 0 kB SwapFree: 0 kB Dirty: 56 kB Writeback: 0 kB AnonPages: 3391352 kB Mapped: 310564 kB Shmem: 496832 kB KReclaimable: 196444 kB Slab: 2197440 kB SReclaimable: 196444 kB SUnreclaim: 2000996 kB KernelStack: 25728 kB PageTables: 67676 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 15855588 kB Committed_AS: 17433636 kB VmallocTotal: 34359738367 kB VmallocUsed: 392660 kB VmallocChunk: 0 kB Percpu: 43264 kB HardwareCorrupted: 0 kB AnonHugePages: 1015808 kB ShmemHugePages: 0 kB ShmemPmdMapped: 0 kB FileHugePages: 0 kB FilePmdMapped: 0 kB HugePages_Total: 512 HugePages_Free: 512 HugePages_Rsvd: 0 HugePages_Surp: 0 Hugepagesize: 2048 kB Hugetlb: 1048576 kB DirectMap4k: 27877496 kB DirectMap2M: 5607424 kB DirectMap1G: 1048576 kB |