************************ crashinfo ************************* /exports/testreports/47154/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg138-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.zyajD/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg138-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 12:24:11 EST 2024 UPTIME: 00:16:58 LOAD AVERAGE: 0.00, 0.20, 0.43 TASKS: 369 NODENAME: oleg138-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 25 last 5s 66 last 60s 78 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 365 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 ----- -------------- ------ ---------------------------- 49 kworker/2:1 0 ms (no user stack) 3285 socknal_reaper 0 ms (no user stack) 484 kworker/1:2 0 ms (no user stack) 46 kworker/0:1 0 ms (no user stack) 8071 z_null_iss 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 727192 2.8 GB 76% of TOTAL MEM USED 227875 890.1 MB 23% of TOTAL MEM SHARED 9992 39 MB 1% of TOTAL MEM BUFFERS 5123 20 MB 0% of TOTAL MEM CACHED 69492 271.5 MB 7% of TOTAL MEM SLAB 20720 80.9 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 57955 226.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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 1016.5 eth0 n/a 1.1 RSS_TOTAL=52272 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137668380 ffff880137679000 sysfs sysfs /sys ffff880137668540 ffff880139944000 proc proc /proc ffff880137668700 ffff880137678000 devtmpfs devtmpfs /dev ffff8801376688c0 ffff88012ae06000 securityfs securityfs /sys/kernel/security ffff880137668a80 ffff880137679800 tmpfs tmpfs /dev/shm ffff880137668c40 ffff88013730e000 devpts devpts /dev/pts ffff880137668e00 ffff88013767a000 tmpfs tmpfs /run ffff880137668fc0 ffff88013767a800 tmpfs tmpfs /sys/fs/cgroup ffff880137669180 ffff88013767b000 cgroup cgroup /sys/fs/cgroup/systemd ffff880137669340 ffff88013767b800 pstore pstore /sys/fs/pstore ffff880137669500 ffff88013767d800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff8801376696c0 ffff88013767d000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880137669880 ffff88013767c800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137669a40 ffff88013767c000 cgroup cgroup /sys/fs/cgroup/perf_event ffff880137669c00 ffff88013767e000 cgroup cgroup /sys/fs/cgroup/freezer ffff880137669dc0 ffff88013767e800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2f2000 ffff88013767f000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a2f21c0 ffff88013767f800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a2f2380 ffff88012a340000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a2f2540 ffff88012a340800 cgroup cgroup /sys/fs/cgroup/pids ffff880138ccb180 ffff880129ca5000 configfs configfs /sys/kernel/config ffff88012b24ce00 ffff8800b48e1000 ext4 /dev/nbd0 / ffff8800b53fc380 ffff8800b5258800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b53fc8c0 ffff8800b4a61800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff8800b53fca80 ffff8800b4a63000 hugetlbfs hugetlbfs /dev/hugepages ffff88012b24cfc0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b53fcc40 ffff88013730f800 mqueue mqueue /dev/mqueue ffff88012b24d180 ffff8800b40f3000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012a2f28c0 ffff8800b42d1000 ramfs none /mnt ffff880129ee2380 ffff880129f55800 tmpfs none /var/lib/stateless/writable ffff880129ee2700 ffff880129f54000 squashfs /dev/vda /home/green/git/lustre-release ffff8800b53fce00 ffff880129f55800 tmpfs none /var/cache/man ffff88012a2f2a80 ffff880129f55800 tmpfs none /var/log ffff88012a2f2c40 ffff880129f55800 tmpfs none /var/lib/dbus ffff88012a2f2e00 ffff880129f55800 tmpfs none /tmp ffff88012a2f2fc0 ffff880129f55800 tmpfs none /var/lib/dhclient ffff8800b53fcfc0 ffff880129f55800 tmpfs none /var/tmp ffff88012a2f3180 ffff880129f55800 tmpfs none /var/lib/NetworkManager ffff88012a2f3340 ffff880129f55800 tmpfs none /var/lib/systemd/random-seed ffff88012a2f3500 ffff880129f55800 tmpfs none /var/spool ffff88012a2f36c0 ffff880129f55800 tmpfs none /var/lib/nfs ffff8800b53fd180 ffff880129f55800 tmpfs none /var/lib/gssproxy ffff88012a2f3880 ffff880129f55800 tmpfs none /var/lib/logrotate ffff8800b53fd340 ffff880129f55800 tmpfs none /etc ffff88012a2f3a40 ffff880129f55800 tmpfs none /var/lib/rsyslog ffff88012a2f3c00 ffff880129f55800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a2f3dc0 ffff8800b4a63800 nfs4 192.168.200.253:/exports/state/oleg138-server.virtnet /var/lib/stateless/state ffff8800b53fd880 ffff8800b4a63800 nfs4 192.168.200.253:/exports/state/oleg138-server.virtnet /boot ffff88012b24d340 ffff8800b4a63800 nfs4 192.168.200.253:/exports/state/oleg138-server.virtnet /etc/etc/kdump.conf ffff880129ee28c0 ffff8800b5258800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff88012e1c7500 ffff880129f54000 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b1ad1180 ffff8800b42d1800 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff880136bda700 ffff8801306c7800 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b1ad0380 ffff880097819000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 130.968283] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 130.970447] [<0>] 0xfffffffffffffffe [ 132.080535] Lustre: ll_ost00_007: service thread pid 15386 was inactive for 40.028 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 132.089748] Lustre: Skipped 1 previous similar message [ 132.091377] Pid: 15386, comm: ll_ost00_007 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 132.094435] Call Trace: [ 132.095531] [<0>] ldlm_completion_ast+0x913/0xd50 [ptlrpc] [ 132.098383] [<0>] ldlm_cli_enqueue_local+0x259/0x890 [ptlrpc] [ 132.102224] [<0>] ofd_destroy_by_fid+0x19c/0x610 [ofd] [ 132.105562] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 132.108237] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 132.111371] [<0>] ptlrpc_server_handle_request+0x281/0xce0 [ptlrpc] [ 132.116172] [<0>] ptlrpc_main+0xc7e/0x1690 [ptlrpc] [ 132.118464] [<0>] kthread+0xe4/0xf0 [ 132.120708] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 132.122746] [<0>] 0xfffffffffffffffe [ 177.134568] LustreError: 21213:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000401:0x26b9:0x0] ACL: rc = -2 [ 190.576602] LustreError: 7079:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.38@tcp ns: filter-lustre-OST0000_UUID lock: ffff880092f2b180/0x1368107cbe1fa8a lrc: 3/0,0 mode: PW/PW res: [0x240000400:0xe:0x0].0x0 rrc: 4 type: EXT [65536->18446744073709551615] (req 2097152->2162687) gid 0 flags: 0x60000400020020 nid: 192.168.201.38@tcp remote: 0x7550eaa69c0beaf9 expref: 10 pid: 8420 timeout: 189 lvb_type: 0 [ 191.578526] LustreError: 7079:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.38@tcp ns: filter-lustre-OST0001_UUID lock: ffff8800911033c0/0x1368107cbe23ccb lrc: 3/0,0 mode: PR/PR res: [0x280000400:0xd:0x0].0x0 rrc: 5 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400000020 nid: 192.168.201.38@tcp remote: 0x7550eaa69c0bfd44 expref: 26 pid: 15386 timeout: 190 lvb_type: 1 [ 191.587644] LustreError: 7077:0:(client.c:1300:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff88008f866a00 x1815627869909760/t0(0) o105->lustre-OST0001@192.168.201.38@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 [ 191.588252] Lustre: ll_ost00_001: service thread pid 8421 completed after 100.685s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 191.588455] Lustre: ll_ost00_004: service thread pid 14818 completed after 100.684s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 191.594538] Lustre: ll_ost00_007: service thread pid 15386 completed after 99.542s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 192.101242] Lustre: 14764:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff880131e36d80 x1815627908549120/t4295035010(0) o101->44c4e2df-51d1-4218-aa7c-a9cfbdab909b@192.168.201.38@tcp:79/0 lens 376/816 e 0 to 0 dl 1731517834 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 221.364704] LustreError: 14760:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000402:0x2e1f:0x0] ACL: rc = -2 [ 221.664672] Lustre: lustre-OST0000: haven't heard from client ad03e6e7-5fce-4169-b3ca-4a9109478e11 (at 192.168.201.38@tcp) in 31 seconds. I think it's dead, and I am evicting it. exp ffff88009129a000, cur 1731517853 expire 1731517823 last 1731517822 [ 223.657994] Lustre: lustre-OST0000: haven't heard from client 44c4e2df-51d1-4218-aa7c-a9cfbdab909b (at 192.168.201.38@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff88009318f800, cur 1731517855 expire 1731517825 last 1731517823 [ 231.429275] LustreError: 14763:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000402:0x3364:0x0] ACL: rc = -2 [ 246.540239] LustreError: 14757:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000401:0x433e:0x0] ACL: rc = -2 [ 298.739356] LustreError: 8460:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000401:0x56c3:0x0] ACL: rc = -2 [ 317.536536] LustreError: 28580:0:(mdt_handler.c:776:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000402:0x59f8:0x0] ACL: rc = -2 [ 317.543577] LustreError: 28580:0:(mdt_handler.c:776:mdt_pack_acl2body()) Skipped 1 previous similar message [ 411.888626] Lustre: mdt00_018: service thread pid 32510 was inactive for 40.119 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 411.895955] Lustre: Skipped 1 previous similar message [ 472.176604] LustreError: 7079:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.38@tcp ns: mdt-lustre-MDT0000_UUID lock: ffff880090a27cc0/0x1368107cc6ad3df lrc: 3/0,0 mode: PR/PR res: [0x200000401:0x70ae:0x0].0x0 bits 0x13/0x0 rrc: 7 type: IBT gid 0 flags: 0x60200400000020 nid: 192.168.201.38@tcp remote: 0x7550eaa69c34801f expref: 1095 pid: 7089 timeout: 471 lvb_type: 0 [ 472.192996] LustreError: 7079:0:(ldlm_lockd.c:241:expired_lock_main()) Skipped 2 previous similar messages [ 472.217202] Lustre: mdt00_001: service thread pid 7088 completed after 100.416s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 472.217267] Lustre: mdt00_008: service thread pid 14758 completed after 100.397s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 472.218247] Lustre: mdt00_018: service thread pid 32510 completed after 100.448s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 472.222062] LustreError: 14962:0:(ldlm_lockd.c:2575:ldlm_cancel_handler()) ldlm_cancel from 192.168.201.38@tcp arrived at 1731518103 with bad export cookie 87399113265618315 ****************************************************************************** ************************ 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.57s (real) 6.99s (CPU), Child processes: 5.54s