************************ crashinfo ************************* /exports/testreports/42551/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg409-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.XY4iP/vmlinux [TAINTED] DUMPFILE: /exports/testreports/42551/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg409-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 8 18:27:45 EDT 2024 UPTIME: 00:26:54 LOAD AVERAGE: 0.00, 0.02, 0.13 TASKS: 437 NODENAME: oleg409-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 66 last 60s 79 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 433 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 ----- -------------- ------ ---------------------------- 50 kworker/2:1 0 ms (no user stack) 6659 txg_quiesce 0 ms (no user stack) 6660 txg_sync 0 ms (no user stack) 34 rcuos/3 0 ms (no user stack) 8013 z_null_iss 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 706841 2.7 GB 74% of TOTAL MEM USED 248226 969.6 MB 25% of TOTAL MEM SHARED 8801 34.4 MB 0% of TOTAL MEM BUFFERS 5096 19.9 MB 0% of TOTAL MEM CACHED 65021 254 MB 6% of TOTAL MEM SLAB 22133 86.5 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 57937 226.3 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 1611.3 eth0 n/a 2.4 RSS_TOTAL=52148 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88013701c1c0 ffff8801377cf800 sysfs sysfs /sys ffff88013701c380 ffff880139944000 proc proc /proc ffff88013701c540 ffff880137678000 devtmpfs devtmpfs /dev ffff88013701c700 ffff8800b5227000 securityfs securityfs /sys/kernel/security ffff88013701c8c0 ffff8801377c7800 tmpfs tmpfs /dev/shm ffff88013701ca80 ffff88013732a000 devpts devpts /dev/pts ffff88013701cc40 ffff88012a360000 tmpfs tmpfs /run ffff88013701ce00 ffff88012a360800 tmpfs tmpfs /sys/fs/cgroup ffff88013701cfc0 ffff88012a361000 cgroup cgroup /sys/fs/cgroup/systemd ffff88013701d180 ffff88012a361800 pstore pstore /sys/fs/pstore ffff88013701d340 ffff88012a363800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88013701d500 ffff88012a363000 cgroup cgroup /sys/fs/cgroup/pids ffff88013701d6c0 ffff88012a362800 cgroup cgroup /sys/fs/cgroup/blkio ffff88013701d880 ffff88012a362000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88013701da40 ffff88012a364000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88013701dc00 ffff88012a364800 cgroup cgroup /sys/fs/cgroup/freezer ffff88013701ddc0 ffff88012a365000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a388000 ffff88012a365800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a3881c0 ffff88012a366000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a388380 ffff88012a366800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a388700 ffff8800b539a000 configfs configfs /sys/kernel/config ffff880138ccb6c0 ffff8800b4e67000 ext4 /dev/nbd0 / ffff88012a388a80 ffff8800b539a800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012a388c40 ffff8800b4e66000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a388e00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137669a40 ffff8800b4fe0000 hugetlbfs hugetlbfs /dev/hugepages ffff880137669c00 ffff88013732b800 mqueue mqueue /dev/mqueue ffff88012a388fc0 ffff8800b4e61800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012a389340 ffff8800b51c7000 ramfs none /mnt ffff880129d58700 ffff88012a32b800 squashfs /dev/vda /home/green/git/lustre-release ffff880129d588c0 ffff88012a32e800 tmpfs none /var/lib/stateless/writable ffff880129d58a80 ffff88012a32e800 tmpfs none /var/cache/man ffff88012a389500 ffff88012a32e800 tmpfs none /var/log ffff880129d58c40 ffff88012a32e800 tmpfs none /var/lib/dbus ffff88012a3896c0 ffff88012a32e800 tmpfs none /tmp ffff880129d58e00 ffff88012a32e800 tmpfs none /var/lib/dhclient ffff880129d58fc0 ffff88012a32e800 tmpfs none /var/tmp ffff88012a389880 ffff88012a32e800 tmpfs none /var/lib/NetworkManager ffff88012a389a40 ffff88012a32e800 tmpfs none /var/lib/systemd/random-seed ffff88012a389c00 ffff88012a32e800 tmpfs none /var/spool ffff88012a389dc0 ffff88012a32e800 tmpfs none /var/lib/nfs ffff88012a388540 ffff88012a32e800 tmpfs none /var/lib/gssproxy ffff88012dc66000 ffff88012a32e800 tmpfs none /var/lib/logrotate ffff880129d59180 ffff88012a32e800 tmpfs none /etc ffff880136a80000 ffff88012a32e800 tmpfs none /var/lib/rsyslog ffff880136a801c0 ffff88012a32e800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff880136a80380 ffff8800b1dfd800 nfs4 192.168.200.253:/exports/state/oleg409-server.virtnet /var/lib/stateless/state ffff880136a80700 ffff8800b1dfd800 nfs4 192.168.200.253:/exports/state/oleg409-server.virtnet /boot ffff880136a808c0 ffff8800b1dfd800 nfs4 192.168.200.253:/exports/state/oleg409-server.virtnet /etc/etc/kdump.conf ffff880136a80a80 ffff8800b539a800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b2b87880 ffff88012a32b800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b2b86e00 ffff8800b4e65800 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b2b87dc0 ffff88009cc0e000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b2b87500 ffff880092a54800 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 134.985435] Pid: 8400, comm: ll_ost00_002 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 134.989171] Call Trace: [ 134.990073] [<0>] ldlm_completion_ast+0x963/0xd00 [ptlrpc] [ 134.993192] [<0>] ldlm_cli_enqueue_local+0x259/0x880 [ptlrpc] [ 134.994807] [<0>] ofd_destroy_by_fid+0x1d1/0x520 [ofd] [ 134.996391] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 134.998477] [<0>] tgt_request_handle+0x74e/0x1a50 [ptlrpc] [ 135.001204] [<0>] ptlrpc_server_handle_request+0x26c/0xcb0 [ptlrpc] [ 135.003266] [<0>] ptlrpc_main+0xc76/0x1690 [ptlrpc] [ 135.005508] [<0>] kthread+0xe4/0xf0 [ 135.006693] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 135.009142] [<0>] 0xfffffffffffffffe [ 135.010759] Pid: 10799, comm: ll_ost00_003 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 135.015144] Call Trace: [ 135.016631] [<0>] ldlm_completion_ast+0x963/0xd00 [ptlrpc] [ 135.019775] [<0>] ldlm_cli_enqueue_local+0x259/0x880 [ptlrpc] [ 135.022120] [<0>] ofd_destroy_by_fid+0x1d1/0x520 [ofd] [ 135.024528] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 135.025673] [<0>] tgt_request_handle+0x74e/0x1a50 [ptlrpc] [ 135.027936] [<0>] ptlrpc_server_handle_request+0x26c/0xcb0 [ptlrpc] [ 135.030418] [<0>] ptlrpc_main+0xc76/0x1690 [ptlrpc] [ 135.032449] [<0>] kthread+0xe4/0xf0 [ 135.033887] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 135.036035] [<0>] 0xfffffffffffffffe [ 135.462490] Lustre: ll_ost00_000: service thread pid 8398 was inactive for 40.137 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 136.358499] Lustre: ll_ost00_010: service thread pid 16638 was inactive for 40.124 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 136.363983] Lustre: Skipped 1 previous similar message [ 137.766632] Lustre: ll_ost00_007: service thread pid 15471 was inactive for 40.000 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 137.773675] Lustre: Skipped 3 previous similar messages [ 139.814509] Lustre: ll_ost00_014: service thread pid 18742 was inactive for 40.018 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 139.819076] Lustre: Skipped 5 previous similar messages [ 194.598509] LustreError: 6910:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.204.9@tcp ns: filter-lustre-OST0000_UUID lock: ffff88008e2fe880/0x9c3d52057664c10c lrc: 3/0,0 mode: PW/PW res: [0x240000400:0x7:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->36863) gid 0 flags: 0x60000400010020 nid: 192.168.204.9@tcp remote: 0x12ec1d28bc976a32 expref: 29 pid: 8400 timeout: 194 lvb_type: 0 [ 194.613103] LustreError: 6908:0:(client.c:1281:ptlrpc_import_delay_req()) @@@ IMP_CLOSED req@ffff880136aea680 x1798523519012224/t0(0) o105->lustre-OST0001@192.168.204.9@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 [ 194.613841] Lustre: 9979:0:(client.c:2343:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1715205845/real 1715205845] req@ffff880136ae8000 x1798523519012160/t0(0) o105->lustre-OST0000@192.168.204.9@tcp:15/16 lens 392/224 e 0 to 1 dl 1715205861 ref 1 fl Rpc:EeXQU/0/ffffffff rc -5/-1 job:'' uid:4294967295 gid:4294967295 [ 194.629902] LustreError: 6908:0:(client.c:1281:ptlrpc_import_delay_req()) Skipped 11 previous similar messages [ 225.142640] Lustre: lustre-OST0000: haven't heard from client 3ada91b2-be41-4612-9da5-6a9e46ce8c64 (at 192.168.204.9@tcp) in 31 seconds. I think it's dead, and I am evicting it. exp ffff88009427d800, cur 1715205876 expire 1715205846 last 1715205845 [ 226.114613] Lustre: lustre-OST0001: haven't heard from client 4507db73-81e7-466b-b798-04c79c62d76c (at 192.168.204.9@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff880094278800, cur 1715205877 expire 1715205847 last 1715205845 [ 226.123869] Lustre: Skipped 1 previous similar message [ 258.050034] LustreError: 15031:0:(mdt_handler.c:777:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000402:0x362e:0x0] ACL: rc = -2 [ 322.049628] LustreError: 15023:0:(mdt_handler.c:777:mdt_pack_acl2body()) lustre-MDT0000: unable to read [0x200000402:0x4bc2:0x0] ACL: rc = -2 ****************************************************************************** ************************ 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.74s (real) 7.23s (CPU), Child processes: 5.50s