************************ crashinfo ************************* /exports/testreports/52418/testresults/racer-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg125-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.U6SJa/vmlinux [TAINTED] DUMPFILE: /exports/testreports/52418/testresults/racer-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg125-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Tue Jun 10 03:48:17 EDT 2025 UPTIME: 00:17:01 LOAD AVERAGE: 0.13, 3.95, 3.56 TASKS: 511 NODENAME: oleg125-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 68 last 60s 94 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 507 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 ----- -------------- ------ ---------------------------- 10904 ldlm_bl_04 0 ms (no user stack) 580 kworker/2:2 0 ms (no user stack) 17236 kworker/0:1 0 ms (no user stack) 17101 kworker/3:0 0 ms (no user stack) 3763 ptlrpcd_00_00 5 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 524524 2 GB 54% of TOTAL MEM USED 430543 1.6 GB 45% of TOTAL MEM SHARED 89723 350.5 MB 9% of TOTAL MEM BUFFERS 87342 341.2 MB 9% of TOTAL MEM CACHED 89631 350.1 MB 9% of TOTAL MEM SLAB 97637 381.4 MB 10% 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 62918 245.8 MB 8% 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 Unusual Situations: Doing Retransmission: 1 (run xportshow --retrans for details) 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 1019.0 eth0 n/a 0.0 RSS_TOTAL=50596 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a33e000 ffff88012a340000 sysfs sysfs /sys ffff88012a33e1c0 ffff880139944000 proc proc /proc ffff88012a33e380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a33e540 ffff8800b51b4800 securityfs securityfs /sys/kernel/security ffff88012a33e700 ffff88012a340800 tmpfs tmpfs /dev/shm ffff88012a33e8c0 ffff88013710a800 devpts devpts /dev/pts ffff88012a33ea80 ffff88012a341000 tmpfs tmpfs /run ffff88012a33ec40 ffff88012a341800 tmpfs tmpfs /sys/fs/cgroup ffff88012a33ee00 ffff88012a342000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a33efc0 ffff88012a342800 pstore pstore /sys/fs/pstore ffff88012a33f180 ffff88012a344800 cgroup cgroup /sys/fs/cgroup/pids ffff88012a33f340 ffff88012a344000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a33f500 ffff88012a343800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a33f6c0 ffff88012a343000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a33f880 ffff88012a345000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a33fa40 ffff88012a345800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a33fc00 ffff88012a346000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a33fdc0 ffff88012a346800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a310000 ffff88012a347000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a3101c0 ffff88012a347800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a310380 ffff8800b524a000 configfs configfs /sys/kernel/config ffff880137668540 ffff8800b5202000 ext4 /dev/nbd0 / ffff88012a310540 ffff8800b5205800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b4050380 ffff88012a35b000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a310c40 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137668700 ffff88013710c000 mqueue mqueue /dev/mqueue ffff88012a310e00 ffff8800b53cf000 hugetlbfs hugetlbfs /dev/hugepages ffff8800b4050540 ffff8800b4da2800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b4050700 ffff8800b4da7000 ramfs none /mnt ffff8800b40508c0 ffff8800b524e800 tmpfs none /var/lib/stateless/writable ffff88012a311180 ffff8800b40e6800 squashfs /dev/vda /home/green/git/lustre-release ffff8801376688c0 ffff8800b524e800 tmpfs none /var/cache/man ffff88012a311340 ffff8800b524e800 tmpfs none /var/log ffff88012a311500 ffff8800b524e800 tmpfs none /var/lib/dbus ffff880137668a80 ffff8800b524e800 tmpfs none /tmp ffff88012a3116c0 ffff8800b524e800 tmpfs none /var/lib/dhclient ffff88012a311880 ffff8800b524e800 tmpfs none /var/tmp ffff88012a311a40 ffff8800b524e800 tmpfs none /var/lib/NetworkManager ffff88012a311c00 ffff8800b524e800 tmpfs none /var/lib/systemd/random-seed ffff880137668c40 ffff8800b524e800 tmpfs none /var/spool ffff88012a311dc0 ffff8800b524e800 tmpfs none /var/lib/nfs ffff88012a310a80 ffff8800b524e800 tmpfs none /var/lib/gssproxy ffff8800b4050a80 ffff8800b524e800 tmpfs none /var/lib/logrotate ffff88012a3108c0 ffff8800b524e800 tmpfs none /etc ffff8800b4050c40 ffff8800b524e800 tmpfs none /var/lib/rsyslog ffff88012a310700 ffff8800b524e800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b2218000 ffff8800b40e2800 nfs4 192.168.200.253:/exports/state/oleg125-server.virtnet /var/lib/stateless/state ffff8800b2218700 ffff8800b40e2800 nfs4 192.168.200.253:/exports/state/oleg125-server.virtnet /boot ffff8800b22188c0 ffff8800b40e2800 nfs4 192.168.200.253:/exports/state/oleg125-server.virtnet /etc/etc/kdump.conf ffff8800b2218a80 ffff8800b5205800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff880129c841c0 ffff8800b40e6800 squashfs /dev/vda /usr/sbin/mount.lustre ffff880129ec2540 ffff88012a35d000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff880129ec3500 ffff8800b1b27000 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff880129ec3a40 ffff8800888ef000 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff880129ec2e00 ffff88009f000000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 717.064153] [] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 717.067010] [] ptlrpc_server_handle_request+0x23d/0xd10 [ptlrpc] [ 717.071379] [] ptlrpc_main+0xc61/0x1640 [ptlrpc] [ 717.074482] [] ? put_prev_entity+0x31/0x400 [ 717.077881] [] ? ptlrpc_wait_event+0x630/0x630 [ptlrpc] [ 717.081421] [] kthread+0xe4/0xf0 [ 717.083349] [] ? kthread_create_on_node+0x140/0x140 [ 717.087179] [] ret_from_fork_nospec_begin+0x7/0x21 [ 717.090271] [] ? kthread_create_on_node+0x140/0x140 [ 725.805498] Lustre: 8563:0:(mdt_recovery.c:102:mdt_req_from_lrd()) @@@ restoring transno req@ffff880073f83100 x1834526929332864/t4295177234(0) o101->8b74ea1d-167a-499f-929c-41a9dbf64867@192.168.201.25@tcp:429/0 lens 376/48208 e 0 to 0 dl 1749541544 ref 1 fl Interpret:H/602/0 rc 0/0 job:'dd.0' uid:0 gid:0 projid:0 [ 725.822935] Lustre: 8563:0:(mdt_recovery.c:102:mdt_req_from_lrd()) Skipped 30 previous similar messages [ 734.671587] Lustre: lustre-MDT0001-osp-MDT0000: Connection to lustre-MDT0001 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 734.675367] LustreError: 7227:0:(ldlm_request.c:123:ldlm_expired_completion_wait()) ### lock timed out (enqueued at 1749541110, 300s ago), entering recovery for lustre-MDT0001_UUID@192.168.201.125@tcp ns: lustre-MDT0001-osp-MDT0000 lock: ffff8800723c4c00/0x4b7067e29462c492 lrc: 4/0,1 mode: --/PW res: [0x240000402:0x1:0x0].0x31 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x1000000000000 nid: local remote: 0x4b7067e29462c499 expref: -99 pid: 7227 timeout: 0 lvb_type: 0 [ 734.675760] Lustre: lustre-MDT0001: Received new MDS connection from 0@lo, keep former export from same NID [ 734.676690] Lustre: lustre-MDT0001-osp-MDT0000: Connection restored to 192.168.201.125@tcp (at 0@lo) [ 734.684550] LustreError: 16311:0:(ldlm_request.c:104:ldlm_expired_completion_wait()) ### lock timed out (enqueued at 1749541110, 300s ago); not entering recovery in server code, just going back to sleep ns: mdt-lustre-MDT0000_UUID lock: ffff88008e446a00/0x4b7067e29462c675 lrc: 3/0,1 mode: --/EX res: [0x200000403:0x4d65:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT flags: 0x40210000000000 pid: 16311 initiator: MDT0 [ 734.763895] LustreError: dumping log to /tmp/lustre-log.1749541410.16311 [ 955.983619] Lustre: mdt00_001: service thread pid 7214 was inactive for 222.637 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 955.983626] Lustre: mdt00_003: service thread pid 8563 was inactive for 222.645 seconds. Watchdog stack traces are limited to 3 per 300 seconds, skipping this one. [ 955.983628] Lustre: Skipped 2 previous similar messages [ 955.999211] Lustre: Skipped 1 previous similar message [ 956.001315] Pid: 7214, comm: mdt00_001 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 956.004852] Call Trace: [ 956.006070] [<0>] ldlm_completion_ast+0x943/0xd80 [ptlrpc] [ 956.008354] [<0>] ldlm_cli_enqueue_local+0x2ea/0x810 [ptlrpc] [ 956.010829] [<0>] mdt_object_lock_internal+0x1b3/0x470 [mdt] [ 956.013217] [<0>] mdt_object_lock+0x88/0x1c0 [mdt] [ 956.015276] [<0>] mdt_getattr_name_lock+0xc4a/0x2cc0 [mdt] [ 956.017631] [<0>] mdt_intent_getattr+0x2cc/0x4e0 [mdt] [ 956.019856] [<0>] mdt_intent_opc.constprop.74+0x211/0xc60 [mdt] [ 956.022348] [<0>] mdt_intent_policy+0x10f/0x460 [mdt] [ 956.024579] [<0>] ldlm_lock_enqueue+0x397/0x980 [ptlrpc] [ 956.026887] [<0>] ldlm_handle_enqueue+0x547/0x1900 [ptlrpc] [ 956.029213] [<0>] tgt_enqueue+0x68/0x240 [ptlrpc] [ 956.031288] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 956.033662] [<0>] ptlrpc_server_handle_request+0x23d/0xd10 [ptlrpc] [ 956.036312] [<0>] ptlrpc_main+0xc61/0x1640 [ptlrpc] [ 956.038404] [<0>] kthread+0xe4/0xf0 [ 956.039930] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 956.041806] [<0>] 0xfffffffffffffffe ****************************************************************************** ************************ 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 13.33s (real) 7.53s (CPU), Child processes: 5.75s