************************ crashinfo ************************* /exports/testreports/47198/testresults/sanityn-zfs-centos7_x86_64-centos7_x86_64/oleg419-server-timeout-core (3.10.0-7.9-debug) +==========================+ | *** Crashinfo v1.3.7 *** | +==========================+ +++WARNING+++ PARTIAL DUMP with size(vmcore) < 25% size(RAM) KERNEL: /tmp/crash-anaysis.aMVKW/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47198/testresults/sanityn-zfs-centos7_x86_64-centos7_x86_64/oleg419-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Sat Nov 16 05:42:15 EST 2024 UPTIME: 01:07:20 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 354 NODENAME: oleg419-server.virtnet RELEASE: 3.10.0-7.9-debug VERSION: #1 SMP Sat Mar 26 23:28:42 EDT 2022 MACHINE: x86_64 (2399 Mhz) MEMORY: 4 GB PANIC: "" +--------------------------+ >------------------------| Per-cpu Stacks ('bt -a') |------------------------< +--------------------------+ -- CPU#0 -- PID=0 CPU=0 CMD=swapper/0 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 rest_init+0x8e #7 start_kernel+0x456 #8 x86_64_start_reservations+0x2a #9 x86_64_start_kernel+0x152 #10 start_cpu+0x5 -- CPU#1 -- PID=0 CPU=1 CMD=swapper/1 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 -- CPU#2 -- PID=0 CPU=2 CMD=swapper/2 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 -- CPU#3 -- PID=0 CPU=3 CMD=swapper/3 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 +--------------------------------+ >---------------------| How This Dump Has Been Created |---------------------< +--------------------------------+ Cannot identify the specific condition that triggered vmcore +---------------+ >------------------------------| Tasks Summary |------------------------------< +---------------+ Number of Threads That Ran Recently ----------------------------------- last second 32 last 5s 64 last 60s 79 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 350 TASK_RUNNING 1 +++WARNING+++ There are 3 threads running in their own namespaces Use 'taskinfo --ns' to get more details +-----------------------+ >--------------------------| 5 Most Recent Threads |--------------------------< +-----------------------+ PID CMD Age ARGS ----- -------------- ------ ---------------------------- 3493 l2arc_feed 0 ms (no user stack) 8067 z_null_iss 0 ms (no user stack) 8068 z_null_int 0 ms (no user stack) 6735 z_null_iss 28 ms (no user stack) 8123 mmp 42 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 710476 2.7 GB 74% of TOTAL MEM USED 244591 955.4 MB 25% of TOTAL MEM SHARED 10370 40.5 MB 1% of TOTAL MEM BUFFERS 5126 20 MB 0% of TOTAL MEM CACHED 70518 275.5 MB 7% of TOTAL MEM SLAB 19495 76.2 MB 2% of TOTAL MEM TOTAL HUGE 0 0 ---- HUGE FREE 0 0 0% of TOTAL HUGE TOTAL SWAP 262143 1024 MB ---- SWAP USED 0 0 0% of TOTAL SWAP SWAP FREE 262143 1024 MB 100% of TOTAL SWAP COMMIT LIMIT 739676 2.8 GB ---- COMMITTED 59002 230.5 MB 7% of TOTAL LIMIT +-------------------------------+ >----------------------| Scheduler Runqueues (per CPU) |----------------------< +-------------------------------+ ---+ CPU=0 ---- | CURRENT TASK , CMD=swapper/0 ---+ CPU=1 ---- | CURRENT TASK , CMD=swapper/1 ---+ CPU=2 ---- | CURRENT TASK , CMD=swapper/2 ---+ CPU=3 ---- | CURRENT TASK , CMD=swapper/3 +------------------------+ >-------------------------| Network Status Summary |-------------------------< +------------------------+ TCP Connection Info ------------------- ESTABLISHED 9 LISTEN 3 NAGLE disabled (TCP_NODELAY): 7 user_data set (NFS etc.): 8 UDP Connection Info ------------------- 2 UDP sockets, 0 in ESTABLISHED Unix Connection Info ------------------------ ESTABLISHED 26 CLOSE 17 LISTEN 8 Raw sockets info -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 4038.1 eth0 n/a 3.0 RSS_TOTAL=49568 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137668380 ffff880137678800 sysfs sysfs /sys ffff880137668540 ffff880139944000 proc proc /proc ffff880137668700 ffff880137678000 devtmpfs devtmpfs /dev ffff8801376688c0 ffff8800b5227800 securityfs securityfs /sys/kernel/security ffff880137668a80 ffff880137679000 tmpfs tmpfs /dev/shm ffff880137668c40 ffff880137316800 devpts devpts /dev/pts ffff880137668e00 ffff880137679800 tmpfs tmpfs /run ffff880137668fc0 ffff88013767a000 tmpfs tmpfs /sys/fs/cgroup ffff880137669180 ffff88013767a800 cgroup cgroup /sys/fs/cgroup/systemd ffff880137669340 ffff88013767b000 pstore pstore /sys/fs/pstore ffff880137669500 ffff88013767d000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff8801376696c0 ffff88013767c800 cgroup cgroup /sys/fs/cgroup/freezer ffff880137669880 ffff88013767c000 cgroup cgroup /sys/fs/cgroup/memory ffff880137669a40 ffff88013767b800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880137669c00 ffff88013767d800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880137669dc0 ffff88013767e000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a378000 ffff88013767e800 cgroup cgroup /sys/fs/cgroup/pids ffff88012a3781c0 ffff88013767f000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a378380 ffff88013767f800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a378540 ffff88012a388000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012b28ac40 ffff88012a31e000 configfs configfs /sys/kernel/config ffff88012a378a80 ffff88012a388800 ext4 /dev/nbd0 / ffff88012a378c40 ffff88012b3be000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012b28b500 ffff8800b4006000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012b28b6c0 ffff88012b2d0000 mqueue mqueue /dev/mqueue ffff8800b41d61c0 ffff880129deb800 hugetlbfs hugetlbfs /dev/hugepages ffff88012a378e00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b5270000 ffff8800b4a8b000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b52701c0 ffff8800b4a8e000 ramfs none /mnt ffff88012a379180 ffff8800b4a40800 tmpfs none /var/lib/stateless/writable ffff8800b41d6380 ffff880129dee800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a379340 ffff8800b4a40800 tmpfs none /var/cache/man ffff88012a379500 ffff8800b4a40800 tmpfs none /var/log ffff88012b28b880 ffff8800b4a40800 tmpfs none /var/lib/dbus ffff88012b28ba40 ffff8800b4a40800 tmpfs none /tmp ffff88012a3796c0 ffff8800b4a40800 tmpfs none /var/lib/dhclient ffff8800b5270380 ffff8800b4a40800 tmpfs none /var/tmp ffff88012b28bc00 ffff8800b4a40800 tmpfs none /var/lib/NetworkManager ffff8800b41d6700 ffff8800b4a40800 tmpfs none /var/lib/systemd/random-seed ffff88012a379880 ffff8800b4a40800 tmpfs none /var/spool ffff88012a379a40 ffff8800b4a40800 tmpfs none /var/lib/nfs ffff8800b41d68c0 ffff8800b4a40800 tmpfs none /var/lib/gssproxy ffff8800b5270540 ffff8800b4a40800 tmpfs none /var/lib/logrotate ffff8800b5270700 ffff8800b4a40800 tmpfs none /etc ffff8800b52708c0 ffff8800b4a40800 tmpfs none /var/lib/rsyslog ffff88012b28bdc0 ffff8800b4a40800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012b28b340 ffff8800b437c000 nfs4 192.168.200.253:/exports/state/oleg419-server.virtnet /var/lib/stateless/state ffff8800b5270a80 ffff8800b437c000 nfs4 192.168.200.253:/exports/state/oleg419-server.virtnet /boot ffff88012b28afc0 ffff8800b437c000 nfs4 192.168.200.253:/exports/state/oleg419-server.virtnet /etc/etc/kdump.conf ffff88012a379c00 ffff88012b3be000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b1f02e00 ffff880129dee800 squashfs /dev/vda /usr/sbin/mount.lustre ffff88012b8dcfc0 ffff8800a5d0b800 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b5270fc0 ffff8800a62a0800 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b5271dc0 ffff88012f104000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 107.096331] Lustre: DEBUG MARKER: == sanityn test 2f: check attr/owner updates on DNE with 2 mtpt's ========================================================== 04:36:41 (1731749801) [ 107.469503] Lustre: DEBUG MARKER: SKIP: sanityn test_2f needs >= 2 MDTs [ 107.890549] Lustre: DEBUG MARKER: == sanityn test 2g: check blocks update on sync write ==== 04:36:41 (1731749801) [ 109.499028] Lustre: DEBUG MARKER: == sanityn test 3: symlink on one mtpt, readlink on another ===================================================================== 04:36:43 (1731749803) [ 111.091030] Lustre: DEBUG MARKER: == sanityn test 4: fstat validation on multiple mount points ==================================================================== 04:36:44 (1731749804) [ 113.484337] Lustre: DEBUG MARKER: == sanityn test 5: create a file on one mount, truncate it on the other ========================================================== 04:36:47 (1731749807) [ 115.030039] Lustre: DEBUG MARKER: == sanityn test 6: remove of open file on other node ============================================================================ 04:36:48 (1731749808) [ 116.613233] Lustre: DEBUG MARKER: == sanityn test 7: remove of open directory on other node ======================================================================= 04:36:50 (1731749810) [ 118.125077] Lustre: DEBUG MARKER: == sanityn test 8: remove of open special file on other node ==================================================================== 04:36:52 (1731749812) [ 119.643433] Lustre: DEBUG MARKER: == sanityn test 9a: append of file with sub-page size on multiple mounts ========================================================== 04:36:53 (1731749813) [ 121.427317] Lustre: DEBUG MARKER: == sanityn test 9b: append to striped sparse file ======== 04:36:55 (1731749815) [ 123.136756] Lustre: DEBUG MARKER: == sanityn test 10a: write of file with sub-page size on multiple mounts ========================================================== 04:36:57 (1731749817) [ 125.023848] Lustre: DEBUG MARKER: == sanityn test 10b: write of file with sub-page size on multiple mounts ========================================================== 04:36:58 (1731749818) [ 126.679347] Lustre: DEBUG MARKER: == sanityn test 11: execution of file opened for write should return error ============================================================== 04:37:00 (1731749820) [ 128.461459] Lustre: DEBUG MARKER: == sanityn test 12: test lock ordering (link, stat, unlink) ========================================================== 04:37:02 (1731749822) [ 277.659891] Lustre: DEBUG MARKER: == sanityn test 13: test directory page revocation ======= 04:39:31 (1731749971) [ 280.439694] Lustre: DEBUG MARKER: == sanityn test 14aa: execution of file open for write returns -ETXTBSY ========================================================== 04:39:34 (1731749974) [ 282.495021] Lustre: DEBUG MARKER: == sanityn test 14ab: open(RDWR) of executing file returns -ETXTBSY ========================================================== 04:39:36 (1731749976) [ 284.460518] Lustre: DEBUG MARKER: == sanityn test 14b: truncate of executing file returns -ETXTBSY ================================================================ 04:39:38 (1731749978) [ 286.586804] Lustre: DEBUG MARKER: == sanityn test 14c: open(O_TRUNC) of executing file return -ETXTBSY ============================================================ 04:39:40 (1731749980) [ 288.553792] Lustre: DEBUG MARKER: == sanityn test 14d: chmod of executing file is still possible ================================================================== 04:39:42 (1731749982) [ 289.015588] Lustre: DEBUG MARKER: chmod [ 290.876832] Lustre: DEBUG MARKER: == sanityn test 15: test out-of-space with multiple writers ===================================================================== 04:39:44 (1731749984) [ 296.352419] Lustre: DEBUG MARKER: SKIP: oos2 test_15 oos2.sh: 7521280kB free gt MAXFREE 800000kB, increase 800000 (or reduce test fs size) to proceed [ 303.911849] Lustre: DEBUG MARKER: == sanityn test 16a: 500 iterations of dual-mount fsx ==== 04:39:57 (1731749997) [ 321.194163] Lustre: DEBUG MARKER: == sanityn test 16b: 500 iterations of dual-mount fsx at small size ========================================================== 04:40:15 (1731750015) [ 332.025834] Lustre: DEBUG MARKER: == sanityn test 16c: verify data consistency on ldiskfs with cache disabled (b=17397) ========================================================== 04:40:25 (1731750025) [ 332.726808] Lustre: DEBUG MARKER: SKIP: sanityn test_16c dio on ldiskfs only [ 333.198234] Lustre: DEBUG MARKER: == sanityn test 16d: Verify DIO and buffer IO with two clients ========================================================== 04:40:27 (1731750027) [ 344.649760] Lustre: DEBUG MARKER: == sanityn test 16e: Verify size consistency for O_DIRECT write ========================================================== 04:40:38 (1731750038) [ 346.371067] Lustre: DEBUG MARKER: == sanityn test 16f: rw sequential consistency vs drop_caches ========================================================== 04:40:40 (1731750040) [ 367.959631] Lustre: DEBUG MARKER: == sanityn test 16g: mmap rw sequential consistency vs drop_caches ========================================================== 04:41:01 (1731750061) [ 389.717964] Lustre: DEBUG MARKER: == sanityn test 16h: mmap read after truncate file ======= 04:41:23 (1731750083) [ 391.466575] Lustre: DEBUG MARKER: == sanityn test 16i: read after truncate file ============ 04:41:25 (1731750085) [ 393.164424] Lustre: DEBUG MARKER: == sanityn test 16j: race dio with buffered i/o ========== 04:41:27 (1731750087) [ 404.248195] Lustre: DEBUG MARKER: == sanityn test 16k: Parallel FSX and drop caches should not panic ========================================================== 04:41:38 (1731750098) [ 430.510651] Lustre: DEBUG MARKER: == sanityn test 17: resource creation/LVB creation race ========================================================================= 04:42:04 (1731750124) [ 430.901131] LustreError: 20438:0:(ldlm_resource.c:1578:ldlm_resource_get()) cfs_fail_timeout id 30a sleeping for 2000ms [ 432.906570] LustreError: 20438:0:(ldlm_resource.c:1578:ldlm_resource_get()) cfs_fail_timeout id 30a awake [ 434.475438] Lustre: DEBUG MARKER: == sanityn test 18: mmap sanity check =========================================================================================== 04:42:08 (1731750128) ****************************************************************************** ************************ A Summary Of Problems Found ************************* ****************************************************************************** -------------------- A list of all +++WARNING+++ messages -------------------- PARTIAL DUMP with size(vmcore) < 25% size(RAM) There are 3 threads running in their own namespaces Use 'taskinfo --ns' to get more details ------------------------------------------------------------------------------ ** Execution took 11.50s (real) 6.56s (CPU), Child processes: 4.90s