************************ crashinfo ************************* /exports/testreports/47154/testresults/sanity-benchmark-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg132-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.4fFaU/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/sanity-benchmark-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg132-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 13:11:38 EST 2024 UPTIME: 01:04:27 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 319 NODENAME: oleg132-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 17 last 5s 60 last 60s 85 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 315 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 ----- -------------- ------ ---------------------------- 7196 ldlm_bl_02 0 ms (no user stack) 50 kworker/3:1 0 ms (no user stack) 580 kworker/2:2 0 ms (no user stack) 11 rcuos/0 0 ms (no user stack) 46 kworker/0:1 34 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 794088 3 GB 83% of TOTAL MEM USED 160979 628.8 MB 16% of TOTAL MEM SHARED 1671 6.5 MB 0% of TOTAL MEM BUFFERS 910 3.6 MB 0% of TOTAL MEM CACHED 13069 51.1 MB 1% of TOTAL MEM SLAB 18250 71.3 MB 1% of TOTAL MEM TOTAL HUGE 0 0 ---- HUGE FREE 0 0 0% of TOTAL HUGE TOTAL SWAP 262143 1024 MB ---- SWAP USED 1922 7.5 MB 0% of TOTAL SWAP SWAP FREE 260221 1016.5 MB 99% of TOTAL SWAP COMMIT LIMIT 739676 2.8 GB ---- COMMITTED 58985 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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 3865.0 eth0 n/a 0.3 RSS_TOTAL=24852 pages, %mem= 0.2 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012b3da000 ffff88012a2f8000 sysfs sysfs /sys ffff88012b3da1c0 ffff880139944000 proc proc /proc ffff88012b3da380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012b3da540 ffff8800b51d4800 securityfs securityfs /sys/kernel/security ffff88012b3da700 ffff88012a2f8800 tmpfs tmpfs /dev/shm ffff88012b3da8c0 ffff8801370f2800 devpts devpts /dev/pts ffff88012b3daa80 ffff88012a2f9000 tmpfs tmpfs /run ffff88012b3dac40 ffff88012a2f9800 tmpfs tmpfs /sys/fs/cgroup ffff88012b3dae00 ffff88012a2fa000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012b3dafc0 ffff88012a2fa800 pstore pstore /sys/fs/pstore ffff88012b3db180 ffff88012a2fc800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012b3db340 ffff88012a2fc000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012b3db500 ffff88012a2fb800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012b3db6c0 ffff88012a2fb000 cgroup cgroup /sys/fs/cgroup/freezer ffff88012b3db880 ffff88012a2fd000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012b3dba40 ffff88012a2fd800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012b3dbc00 ffff88012a2fe000 cgroup cgroup /sys/fs/cgroup/devices ffff88012b3dbdc0 ffff88012a2fe800 cgroup cgroup /sys/fs/cgroup/pids ffff88012a2c4000 ffff88012a2ff000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a2c41c0 ffff88012a2ff800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2c4540 ffff88012a36b000 configfs configfs /sys/kernel/config ffff880138ccbdc0 ffff8800b4f93800 ext4 /dev/nbd0 / ffff880129d68000 ffff8800b4c53800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b53cc700 ffff88012a36d000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a2c5880 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880129d681c0 ffff8800b4eb1000 hugetlbfs hugetlbfs /dev/hugepages ffff8800b53cc8c0 ffff8801370f4000 mqueue mqueue /dev/mqueue ffff8800b53cca80 ffff8800b4e8f800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880137668380 ffff880129e7d000 ramfs none /mnt ffff8800b53ccc40 ffff88012a36b800 squashfs /dev/vda /home/green/git/lustre-release ffff880129d68380 ffff8800b4e8c000 tmpfs none /var/lib/stateless/writable ffff88012a2c5dc0 ffff8800b4e8c000 tmpfs none /var/cache/man ffff8800b1d82000 ffff8800b4e8c000 tmpfs none /var/log ffff8800b53cce00 ffff8800b4e8c000 tmpfs none /var/lib/dbus ffff8800b1d821c0 ffff8800b4e8c000 tmpfs none /tmp ffff8800b1d82380 ffff8800b4e8c000 tmpfs none /var/lib/dhclient ffff8800b53ccfc0 ffff8800b4e8c000 tmpfs none /var/tmp ffff8800b1d82540 ffff8800b4e8c000 tmpfs none /var/lib/NetworkManager ffff880137668540 ffff8800b4e8c000 tmpfs none /var/lib/systemd/random-seed ffff880137668700 ffff8800b4e8c000 tmpfs none /var/spool ffff8801376688c0 ffff8800b4e8c000 tmpfs none /var/lib/nfs ffff8800b1d82700 ffff8800b4e8c000 tmpfs none /var/lib/gssproxy ffff880129d68540 ffff8800b4e8c000 tmpfs none /var/lib/logrotate ffff8800b1d828c0 ffff8800b4e8c000 tmpfs none /etc ffff880137668a80 ffff8800b4e8c000 tmpfs none /var/lib/rsyslog ffff8800b53cd180 ffff8800b4e8c000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff880137668c40 ffff880129f85000 nfs4 192.168.200.253:/exports/state/oleg132-server.virtnet /var/lib/stateless/state ffff8800b1d82e00 ffff880129f85000 nfs4 192.168.200.253:/exports/state/oleg132-server.virtnet /boot ffff880137668fc0 ffff880129f85000 nfs4 192.168.200.253:/exports/state/oleg132-server.virtnet /etc/etc/kdump.conf ffff8800b1d82fc0 ffff8800b4c53800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b1f8ba40 ffff88012a36b800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b4d62a80 ffff8801370f4800 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800b4d63340 ffff8800a979c800 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff8800b4d63dc0 ffff880097fbf800 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff8800b4d62380 ffff88009c015800 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 75.171101] Lustre: Skipped 1 previous similar message [ 75.181841] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 75.184363] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 75.813730] Lustre: DEBUG MARKER: oleg132-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 80.698442] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 81.019080] random: crng init done [ 87.982556] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 94.255854] Lustre: DEBUG MARKER: oleg132-server.virtnet: executing check_logdir /tmp/testlogs/ [ 95.185494] Lustre: DEBUG MARKER: oleg132-server.virtnet: executing yml_node [ 96.277404] Lustre: DEBUG MARKER: Client: 2.16.0.1 [ 96.918460] Lustre: DEBUG MARKER: MDS: 2.16.0.1 [ 97.564628] Lustre: DEBUG MARKER: OSS: 2.16.0.1 [ 97.974886] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-benchmark ============----- Wed Nov 13 12:08:47 EST 2024 [ 102.104776] Lustre: DEBUG MARKER: excepting tests: [ 102.489584] Lustre: DEBUG MARKER: skipping tests SLOW=no: iozone [ 102.887557] Lustre: DEBUG MARKER: === sanity-benchmark: start setup 12:08:51 (1731517731) === [ 103.778758] Lustre: DEBUG MARKER: oleg132-client.virtnet: executing check_config_client /mnt/lustre [ 108.846404] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 109.737504] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 110.436780] Lustre: DEBUG MARKER: oleg132-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 111.683015] Lustre: DEBUG MARKER: === sanity-benchmark: finish setup 12:09:00 (1731517740) === [ 112.052151] Lustre: DEBUG MARKER: == sanity-benchmark test dbench: dbench ================== 12:09:01 (1731517741) [ 259.419472] Lustre: DEBUG MARKER: == sanity-benchmark test bonnie: bonnie++ ================ 12:11:28 (1731517888) [ 259.773537] Lustre: DEBUG MARKER: min OST has 3335440kB available, using 5003160kB file size [ 387.547351] Lustre: ll_ost00_029: service thread pid 15958 was inactive for 40.078 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 387.552248] Pid: 15958, comm: ll_ost00_029 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 387.554304] Call Trace: [ 387.555181] [<0>] ldlm_completion_ast+0x913/0xd50 [ptlrpc] [ 387.557030] [<0>] ldlm_cli_enqueue_local+0x259/0x890 [ptlrpc] [ 387.558860] [<0>] ofd_destroy_by_fid+0x19c/0x610 [ofd] [ 387.560391] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 387.562013] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 387.564087] [<0>] ptlrpc_server_handle_request+0x281/0xce0 [ptlrpc] [ 387.566446] [<0>] ptlrpc_main+0xc7e/0x1690 [ptlrpc] [ 387.568664] [<0>] kthread+0xe4/0xf0 [ 387.569765] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 387.571319] [<0>] 0xfffffffffffffffe [ 447.707414] LustreError: 7197:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.32@tcp ns: filter-lustre-OST0001_UUID lock: ffff880095094d80/0xc5985431353b33d4 lrc: 3/0,0 mode: PW/PW res: [0x2c0000401:0x26a0:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->8191) gid 0 flags: 0x60000400010020 nid: 192.168.201.32@tcp remote: 0xfc42739e6b86add2 expref: 6 pid: 15963 timeout: 446 lvb_type: 0 [ 447.716580] Lustre: ll_ost00_029: service thread pid 15958 completed after 100.247s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 480.827673] Lustre: lustre-OST0001: haven't heard from client f4d90953-00a2-432e-a4d6-6eeef81696a5 (at 192.168.201.32@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff880056204800, cur 1731518111 expire 1731518081 last 1731518079 ****************************************************************************** ************************ 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.43s (real) 6.64s (CPU), Child processes: 5.74s