************************ crashinfo ************************* /exports/testreports/47154/testresults/sanity2-zfs-centos7_x86_64-centos7_x86_64/oleg429-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.lLE0x/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/sanity2-zfs-centos7_x86_64-centos7_x86_64/oleg429-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 13:09:51 EST 2024 UPTIME: 01:02:38 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 345 NODENAME: oleg429-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 29 last 5s 67 last 60s 78 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 341 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 ----- -------------- ------ ---------------------------- 9332 z_null_int 0 ms (no user stack) 3488 dbuf_evict 0 ms (no user stack) 6719 z_null_iss 0 ms (no user stack) 9331 z_null_iss 0 ms (no user stack) 9391 mmp 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 739800 2.8 GB 77% of TOTAL MEM USED 215267 840.9 MB 22% of TOTAL MEM SHARED 9792 38.2 MB 1% of TOTAL MEM BUFFERS 5123 20 MB 0% of TOTAL MEM CACHED 70545 275.6 MB 7% of TOTAL MEM SLAB 18890 73.8 MB 1% 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 58988 230.4 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 -------------------- CLOSE 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 3756.0 eth0 n/a 1.2 RSS_TOTAL=51052 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a340000 ffff88012a348000 sysfs sysfs /sys ffff88012a3401c0 ffff880139944000 proc proc /proc ffff88012a340380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a340540 ffff8800b522c000 securityfs securityfs /sys/kernel/security ffff88012a340700 ffff88012a348800 tmpfs tmpfs /dev/shm ffff88012a3408c0 ffff8801372ee000 devpts devpts /dev/pts ffff88012a340a80 ffff88012a349000 tmpfs tmpfs /run ffff88012a340c40 ffff88012a349800 tmpfs tmpfs /sys/fs/cgroup ffff88012a340e00 ffff88012a34a000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a340fc0 ffff88012a34a800 pstore pstore /sys/fs/pstore ffff88012a341180 ffff88012a34c800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a341340 ffff88012a34c000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a341500 ffff88012a34b800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a3416c0 ffff88012a34b000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a341880 ffff88012a34d000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a341a40 ffff88012a34d800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a341c00 ffff88012a34e000 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a341dc0 ffff88012a34e800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a2a4000 ffff88012a34f000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a2a41c0 ffff88012a34f800 cgroup cgroup /sys/fs/cgroup/pids ffff88012a2a4540 ffff88012a3e7800 configfs configfs /sys/kernel/config ffff88012a2a4700 ffff88012a3e4800 ext4 /dev/nbd0 / ffff88012a2a48c0 ffff88012a3e5800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012b284a80 ffff8801373f3800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a2a4fc0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880129e48540 ffff8801373e0800 hugetlbfs hugetlbfs /dev/hugepages ffff880129e48700 ffff8801372ef800 mqueue mqueue /dev/mqueue ffff880129e488c0 ffff8801373e4800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880129e48a80 ffff8800b4137800 ramfs none /mnt ffff8801376688c0 ffff8800b53ec800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a2a5180 ffff880129d0d000 tmpfs none /var/lib/stateless/writable ffff880129e48c40 ffff880129d0d000 tmpfs none /var/cache/man ffff88012b284c40 ffff880129d0d000 tmpfs none /var/log ffff88012a2a5340 ffff880129d0d000 tmpfs none /var/lib/dbus ffff880137668a80 ffff880129d0d000 tmpfs none /tmp ffff88012a2a5500 ffff880129d0d000 tmpfs none /var/lib/dhclient ffff88012a2a56c0 ffff880129d0d000 tmpfs none /var/tmp ffff88012a2a5880 ffff880129d0d000 tmpfs none /var/lib/NetworkManager ffff880129e48e00 ffff880129d0d000 tmpfs none /var/lib/systemd/random-seed ffff880137668c40 ffff880129d0d000 tmpfs none /var/spool ffff880137668e00 ffff880129d0d000 tmpfs none /var/lib/nfs ffff880137668fc0 ffff880129d0d000 tmpfs none /var/lib/gssproxy ffff880137669180 ffff880129d0d000 tmpfs none /var/lib/logrotate ffff880137669340 ffff880129d0d000 tmpfs none /etc ffff880137669500 ffff880129d0d000 tmpfs none /var/lib/rsyslog ffff88012a2a5a40 ffff880129d0d000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a2a5c00 ffff88013700e000 nfs4 192.168.200.253:/exports/state/oleg429-server.virtnet /var/lib/stateless/state ffff88012a2a4a80 ffff88013700e000 nfs4 192.168.200.253:/exports/state/oleg429-server.virtnet /boot ffff8801376696c0 ffff88013700e000 nfs4 192.168.200.253:/exports/state/oleg429-server.virtnet /etc/etc/kdump.conf ffff880137669880 ffff88012a3e5800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b1b5b880 ffff8800b53ec800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b19ea1c0 ffff8800b4de0000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b19e9dc0 ffff8800a5152000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b19eb340 ffff8800a5151000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 78.907925] Lustre: DEBUG MARKER: OSS: 2.16.0.1 [ 79.273594] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity ============----- Wed Nov 13 12:08:31 EST 2024 [ 83.108885] Lustre: DEBUG MARKER: excepting tests: 225 255 256 400a 42a 42c 42b 118c 118d 407 119i 411b 130b 130c 130d 130e 130f 130g 312 [ 83.449259] Lustre: DEBUG MARKER: skipping tests SLOW=no: 27m 60i 64b 68 71 135 136 230d 300o 842 51b [ 83.802619] Lustre: DEBUG MARKER: === sanity: start setup 12:08:36 (1731517716) === [ 84.606754] Lustre: DEBUG MARKER: oleg429-client.virtnet: executing check_config_client /mnt/lustre [ 88.933405] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 89.761548] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 90.418681] Lustre: DEBUG MARKER: oleg429-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 91.190577] Lustre: DEBUG MARKER: === sanity: finish setup 12:08:43 (1731517723) === [ 92.833661] Lustre: DEBUG MARKER: == sanity test 60a: llog_test run from kernel module and test llog_reader ========================================================== 12:08:45 (1731517725) [ 93.763190] Lustre: DEBUG MARKER: SKIP: sanity test_60a missing subtest run-llog.sh [ 94.203549] Lustre: DEBUG MARKER: == sanity test 60b: limit repeated messages from CERROR/CWARN ========================================================== 12:08:46 (1731517726) [ 95.956775] Lustre: DEBUG MARKER: == sanity test 60c: unlink file when mds full ============ 12:08:48 (1731517728) [ 121.879230] Lustre: DEBUG MARKER: == sanity test 60d: test printk console message masking == 12:09:14 (1731517754) [ 123.433524] Lustre: DEBUG MARKER: == sanity test 60e: no space while new llog is being created ========================================================== 12:09:16 (1731517756) [ 123.751968] Lustre: *** cfs_fail_loc=15b, val=0*** [ 123.753995] Lustre: *** cfs_fail_loc=15b, val=0*** [ 125.261730] Lustre: DEBUG MARKER: == sanity test 60f: change debug_path works ============== 12:09:17 (1731517757) [ 126.964290] Lustre: DEBUG MARKER: == sanity test 60g: transaction abort won't cause MDT hung ========================================================== 12:09:19 (1731517759) [ 127.231644] Lustre: *** cfs_fail_loc=19a, val=0*** [ 127.964671] Lustre: *** cfs_fail_loc=19a, val=0*** [ 127.966864] Lustre: Skipped 2 previous similar messages [ 129.197330] Lustre: *** cfs_fail_loc=19a, val=0*** [ 129.198510] Lustre: Skipped 4 previous similar messages [ 131.454411] Lustre: *** cfs_fail_loc=19a, val=0*** [ 131.456509] Lustre: Skipped 8 previous similar messages [ 135.687118] Lustre: *** cfs_fail_loc=19a, val=0*** [ 135.689059] Lustre: Skipped 17 previous similar messages [ 143.712631] Lustre: *** cfs_fail_loc=19a, val=0*** [ 143.713824] Lustre: Skipped 32 previous similar messages [ 154.492686] Lustre: DEBUG MARKER: == sanity test 60h: striped directory with missing stripes can be accessed ========================================================== 12:09:47 (1731517787) [ 154.848656] Lustre: DEBUG MARKER: SKIP: sanity test_60h Need at least 2 MDTs [ 155.247559] Lustre: DEBUG MARKER: SKIP: sanity test_60i skipping SLOW test 60i [ 155.661955] Lustre: DEBUG MARKER: == sanity test 60j: llog_reader reports corruptions ====== 12:09:48 (1731517788) [ 156.072537] Lustre: DEBUG MARKER: SKIP: sanity test_60j ldiskfs only test [ 156.470620] Lustre: DEBUG MARKER: == sanity test 61a: mmap() writes don't make sync hang ========================================================================== 12:09:49 (1731517789) [ 256.559333] LustreError: 7045:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.204.29@tcp ns: filter-lustre-OST0001_UUID lock: ffff8800a4956ac0/0xde577b03d0f49d04 lrc: 3/0,0 mode: PR/PR res: [0x280000400:0x9c8:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400000020 nid: 192.168.204.29@tcp remote: 0x1ee53ef653f59d92 expref: 7 pid: 16040 timeout: 255 lvb_type: 1 [ 256.582842] LustreError: 7043:0:(client.c:1300:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff88009399ce00 x1815627865728000/t0(0) o105->lustre-OST0001@192.168.204.29@tcp:15/16 lens 392/224 e 0 to 0 dl 0 ref 1 fl Rpc:QU/0/ffffffff rc 0/-1 job:'' uid:4294967295 gid:4294967295 [ 292.095519] Lustre: lustre-OST0001: haven't heard from client 1c87dfb0-7c16-4750-b895-774f99e96e15 (at 192.168.204.29@tcp) in 35 seconds. I think it's dead, and I am evicting it. exp ffff88009bcf6800, cur 1731517924 expire 1731517894 last 1731517889 ****************************************************************************** ************************ 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 12.41s (real) 6.87s (CPU), Child processes: 5.51s