************************ crashinfo ************************* /exports/testreports/48091/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg122-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.ACUMX/vmlinux [TAINTED] DUMPFILE: /exports/testreports/48091/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg122-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Fri Dec 20 05:45:08 EST 2024 UPTIME: 04:27:05 LOAD AVERAGE: 2.16, 0.79, 0.62 TASKS: 257 NODENAME: oleg122-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 22 last 5s 88 last 60s 137 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 253 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 ----- -------------- ------ ---------------------------- 22052 kworker/3:2 0 ms (no user stack) 13353 kworker/1:1 0 ms (no user stack) 28540 kworker/0:2 0 ms (no user stack) 3449 kworker/2:0 0 ms (no user stack) 21008 socknal_reaper 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 762514 2.9 GB 79% of TOTAL MEM USED 192553 752.2 MB 20% of TOTAL MEM SHARED 16677 65.1 MB 1% of TOTAL MEM BUFFERS 13088 51.1 MB 1% of TOTAL MEM CACHED 34533 134.9 MB 3% of TOTAL MEM SLAB 22452 87.7 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 64543 252.1 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 16022.6 eth0 n/a 0.1 RSS_TOTAL=54208 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 ffff8800b5264000 securityfs securityfs /sys/kernel/security ffff880137668a80 ffff880137679000 tmpfs tmpfs /dev/shm ffff880137668c40 ffff880137191800 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 ffff880138ccae00 ffff88012a300000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff880138ccafc0 ffff88012a300800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880138ccb180 ffff88012a301000 cgroup cgroup /sys/fs/cgroup/blkio ffff880138ccb340 ffff88012a301800 cgroup cgroup /sys/fs/cgroup/perf_event ffff880138ccb500 ffff88012a302000 cgroup cgroup /sys/fs/cgroup/devices ffff880138ccb6c0 ffff88012a302800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880138ccb880 ffff88012a303000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880138ccba40 ffff88012a303800 cgroup cgroup /sys/fs/cgroup/freezer ffff880138ccbc00 ffff88012a304000 cgroup cgroup /sys/fs/cgroup/pids ffff880138ccbdc0 ffff88012a304800 cgroup cgroup /sys/fs/cgroup/memory ffff880137020e00 ffff880129cc4800 configfs configfs /sys/kernel/config ffff88012a2e41c0 ffff8800b4ec1000 ext4 /dev/nbd0 / ffff88012a2e4380 ffff88013767c800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff880137020fc0 ffff8800b4dfa800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a2e4540 ffff8800b41bb000 hugetlbfs hugetlbfs /dev/hugepages ffff8801376696c0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b4f2da40 ffff88013771e000 mqueue mqueue /dev/mqueue ffff880137669880 ffff8800b7c1f800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b4f2ddc0 ffff88013767d800 ramfs none /mnt ffff880137669a40 ffff8800b412b000 tmpfs none /var/lib/stateless/writable ffff88012a2e4700 ffff8800b41be800 squashfs /dev/vda /home/green/git/lustre-release ffff8800b4f2d500 ffff8800b412b000 tmpfs none /var/cache/man ffff880137669c00 ffff8800b412b000 tmpfs none /var/log ffff88012a2e48c0 ffff8800b412b000 tmpfs none /var/lib/dbus ffff880137669dc0 ffff8800b412b000 tmpfs none /tmp ffff8800b4f2d340 ffff8800b412b000 tmpfs none /var/lib/dhclient ffff88012a2e4a80 ffff8800b412b000 tmpfs none /var/tmp ffff88012a2e4c40 ffff8800b412b000 tmpfs none /var/lib/NetworkManager ffff88012a2e4e00 ffff8800b412b000 tmpfs none /var/lib/systemd/random-seed ffff880137669500 ffff8800b412b000 tmpfs none /var/spool ffff8800b2a24000 ffff8800b412b000 tmpfs none /var/lib/nfs ffff88012a2e4fc0 ffff8800b412b000 tmpfs none /var/lib/gssproxy ffff8800b1904000 ffff8800b412b000 tmpfs none /var/lib/logrotate ffff8800b19041c0 ffff8800b412b000 tmpfs none /etc ffff8800b1904380 ffff8800b412b000 tmpfs none /var/lib/rsyslog ffff880137021180 ffff8800b412b000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff880137021340 ffff8800b4f1b800 nfs4 192.168.200.253:/exports/state/oleg122-server.virtnet /var/lib/stateless/state ffff88012a2e5180 ffff8800b4f1b800 nfs4 192.168.200.253:/exports/state/oleg122-server.virtnet /boot ffff8800b1904540 ffff8800b4f1b800 nfs4 192.168.200.253:/exports/state/oleg122-server.virtnet /etc/etc/kdump.conf ffff880137021a40 ffff88013767c800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b2b63340 ffff8800b41be800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800acda4540 ffff880088b95000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800acda4a80 ffff8800627e9800 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff8800acda4380 ffff880085bcf000 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff8800acda41c0 ffff880063d2e000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [15831.956125] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [15832.956788] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x2c0000403:47429 to 0x2c0000403:47489) [15832.958051] Lustre: lustre-OST0000: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x280000400:38596 to 0x280000400:48609) [15832.996346] Lustre: lustre-OST0001: new connection from lustre-MDT0001-mdtlov (cleaning up unused objects from 0x2c0000400:37348 to 0x2c0000400:47361) [15833.339720] Lustre: DEBUG MARKER: oleg122-server.virtnet: executing set_default_debug all all [15837.347553] Lustre: DEBUG MARKER: Using TIMEOUT=20 [15838.369871] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [15845.405878] Lustre: DEBUG MARKER: == sanity test 901: don't leak a mgc lock on client umount ========================================================== 05:42:06 (1734691326) [15848.691615] Lustre: DEBUG MARKER: == sanity test 902: test short write doesn't hang lustre ========================================================== 05:42:10 (1734691330) [15850.749449] Lustre: DEBUG MARKER: == sanity test 903: Test long page discard does not cause evictions ========================================================== 05:42:12 (1734691332) [15896.344308] Lustre: ll_ost00_001: service thread pid 25001 was inactive for 40.062 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [15896.349943] Pid: 25001, comm: ll_ost00_001 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [15896.353746] Call Trace: [15896.355056] [<0>] ldlm_completion_ast+0x913/0xd50 [ptlrpc] [15896.357772] [<0>] ldlm_cli_enqueue_local+0x2ea/0x800 [ptlrpc] [15896.359764] [<0>] ofd_destroy_by_fid+0x19c/0x610 [ofd] [15896.362158] [<0>] ofd_destroy_hdl+0x20c/0xaf0 [ofd] [15896.364523] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [15896.366552] [<0>] ptlrpc_server_handle_request+0x281/0xce0 [ptlrpc] [15896.369591] [<0>] ptlrpc_main+0xc61/0x1640 [ptlrpc] [15896.371289] [<0>] kthread+0xe4/0xf0 [15896.372960] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [15896.375264] [<0>] 0xfffffffffffffffe [15976.408547] Lustre: ll_ost00_001: service thread pid 25001 completed after 120.127s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [15986.119405] Lustre: DEBUG MARKER: == sanity test 904: virtual project ID xattr ============= 05:44:27 (1734691467) [15989.496938] Lustre: DEBUG MARKER: == sanity test 905: bad or new opcode should not stuck client ========================================================== 05:44:31 (1734691471) [15989.812306] Lustre: *** cfs_fail_loc=253, val=21*** [15991.424872] Lustre: DEBUG MARKER: == sanity test 906: Simple test for io_uring I/O engine via fio ========================================================== 05:44:32 (1734691472) [15991.908156] Lustre: DEBUG MARKER: SKIP: sanity test_906 Client OS does not support io_uring I/O engine [15992.378994] Lustre: DEBUG MARKER: == sanity test 907: write rpc error during unlink ======== 05:44:33 (1734691473) [15992.789998] LustreError: 25006:0:(tgt_handler.c:2666:tgt_brw_write()) cfs_fail_timeout id 216 sleeping for 1000ms [15993.792255] LustreError: 25006:0:(tgt_handler.c:2666:tgt_brw_write()) cfs_fail_timeout id 216 awake [15995.432718] Lustre: DEBUG MARKER: == sanity test 908a: llog created with valid ctime ======= 05:44:36 (1734691476) [15997.232326] Lustre: DEBUG MARKER: == sanity test 908b: changelog stores valid mtime ======== 05:44:38 (1734691478) [15997.899060] Lustre: lustre-MDD0000: changelog on [15998.617222] Lustre: lustre-MDD0001: changelog on [16006.701546] Lustre: lustre-MDD0000: changelog off [16007.206548] Lustre: lustre-MDD0001: changelog off [16010.573744] Lustre: DEBUG MARKER: == sanity test complete, duration 15861 sec ============== 05:44:51 (1734691491) [16011.198953] Lustre: DEBUG MARKER: === sanity: start cleanup 05:44:52 (1734691492) === ****************************************************************************** ************************ 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.30s (real) 6.03s (CPU), Child processes: 5.23s