************************ crashinfo ************************* /exports/testreports/47154/testresults/sanity-quota-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg144-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.5SqLB/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/sanity-quota-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg144-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 13:09:34 EST 2024 UPTIME: 01:02:21 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 253 NODENAME: oleg144-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 62 last 60s 75 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 249 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 ----- -------------- ------ ---------------------------- 7197 ldlm_bl_02 0 ms (no user stack) 46 kworker/0:1 0 ms (no user stack) 3758 monitor_thread 0 ms (no user stack) 22122 mdt_out00_003 0 ms (no user stack) 3753 socknal_reaper 9 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 738709 2.8 GB 77% of TOTAL MEM USED 216358 845.1 MB 22% of TOTAL MEM SHARED 11208 43.8 MB 1% of TOTAL MEM BUFFERS 8831 34.5 MB 0% of TOTAL MEM CACHED 71323 278.6 MB 7% of TOTAL MEM SLAB 15329 59.9 MB 1% 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 59047 230.7 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 3739.1 eth0 n/a 1.4 RSS_TOTAL=51564 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a2d2000 ffff88012a2a8000 sysfs sysfs /sys ffff88012a2d21c0 ffff880139944000 proc proc /proc ffff88012a2d2380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a2d2540 ffff8800b51e8800 securityfs securityfs /sys/kernel/security ffff88012a2d2700 ffff88012a2a8800 tmpfs tmpfs /dev/shm ffff88012a2d28c0 ffff88013710a800 devpts devpts /dev/pts ffff88012a2d2a80 ffff88012a2a9000 tmpfs tmpfs /run ffff88012a2d2c40 ffff88012a2a9800 tmpfs tmpfs /sys/fs/cgroup ffff88012a2d2e00 ffff88012a2aa000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a2d2fc0 ffff88012a2aa800 pstore pstore /sys/fs/pstore ffff88012a2d3180 ffff88012a2ac800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2d3340 ffff88012a2ac000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a2d3500 ffff88012a2ab800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a2d36c0 ffff88012a2ab000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a2d3880 ffff88012a2ad000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a2d3a40 ffff88012a2ad800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a2d3c00 ffff88012a2ae000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a2d3dc0 ffff88012a2ae800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a270000 ffff88012a2af000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a2701c0 ffff88012a2af800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880138ccbc00 ffff8800b51ee800 configfs configfs /sys/kernel/config ffff880129e861c0 ffff880129dd0800 ext4 /dev/nbd0 / ffff880138ccbdc0 ffff8800b524a000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff880137669a40 ffff880129da2000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880129e86380 ffff88013710c000 mqueue mqueue /dev/mqueue ffff880129e86540 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137669c00 ffff880129da6800 hugetlbfs hugetlbfs /dev/hugepages ffff880137669dc0 ffff880129da7000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012a2708c0 ffff8800b524f800 ramfs none /mnt ffff8801376696c0 ffff88012a32f000 tmpfs none /var/lib/stateless/writable ffff880138ccb880 ffff8800b4182000 squashfs /dev/vda /home/green/git/lustre-release ffff880137669500 ffff88012a32f000 tmpfs none /var/cache/man ffff88012a270a80 ffff88012a32f000 tmpfs none /var/log ffff880137668380 ffff88012a32f000 tmpfs none /var/lib/dbus ffff88012a270c40 ffff88012a32f000 tmpfs none /tmp ffff8800b2a10000 ffff88012a32f000 tmpfs none /var/lib/dhclient ffff8800b42fc000 ffff88012a32f000 tmpfs none /var/tmp ffff8800b2a101c0 ffff88012a32f000 tmpfs none /var/lib/NetworkManager ffff88012a270e00 ffff88012a32f000 tmpfs none /var/lib/systemd/random-seed ffff8800b2a10380 ffff88012a32f000 tmpfs none /var/spool ffff8800b2a10540 ffff88012a32f000 tmpfs none /var/lib/nfs ffff8800b42fc1c0 ffff88012a32f000 tmpfs none /var/lib/gssproxy ffff8800b2a10700 ffff88012a32f000 tmpfs none /var/lib/logrotate ffff8800b42fc380 ffff88012a32f000 tmpfs none /etc ffff88012a270fc0 ffff88012a32f000 tmpfs none /var/lib/rsyslog ffff8800b2a108c0 ffff88012a32f000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b2a10a80 ffff8800b524d000 nfs4 192.168.200.253:/exports/state/oleg144-server.virtnet /var/lib/stateless/state ffff88012a271500 ffff8800b524d000 nfs4 192.168.200.253:/exports/state/oleg144-server.virtnet /boot ffff8800b2a10c40 ffff8800b524d000 nfs4 192.168.200.253:/exports/state/oleg144-server.virtnet /etc/etc/kdump.conf ffff8800b42fc540 ffff8800b524a000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff88012a292e00 ffff8800b4182000 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b42fcfc0 ffff88013682e000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800b42fcc40 ffff8800b1f4e800 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff8800b42fd880 ffff880099239800 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff8800b42fca80 ffff88009d61d000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 73.664481] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 73.671455] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 74.216397] Lustre: DEBUG MARKER: oleg144-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 79.038977] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 82.189317] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 88.318893] Lustre: DEBUG MARKER: oleg144-server.virtnet: executing check_logdir /tmp/testlogs/ [ 89.159781] Lustre: DEBUG MARKER: oleg144-server.virtnet: executing yml_node [ 90.115989] Lustre: DEBUG MARKER: Client: 2.16.0.1 [ 90.749643] Lustre: DEBUG MARKER: MDS: 2.16.0.1 [ 91.388180] Lustre: DEBUG MARKER: OSS: 2.16.0.1 [ 91.788426] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-quota ============----- Wed Nov 13 12:08:44 EST 2024 [ 95.913879] Lustre: DEBUG MARKER: excepting tests: 2 4a 63 65 [ 96.293709] Lustre: DEBUG MARKER: skipping tests SLOW=no: 61 [ 97.071433] Lustre: DEBUG MARKER: === sanity-quota: start setup 12:08:49 (1731517729) === [ 97.966138] Lustre: DEBUG MARKER: oleg144-client.virtnet: executing check_config_client /mnt/lustre [ 103.017172] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 103.900883] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 104.580820] Lustre: DEBUG MARKER: oleg144-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 105.737014] Lustre: DEBUG MARKER: === sanity-quota: finish setup 12:08:58 (1731517738) === [ 116.090390] Lustre: DEBUG MARKER: == sanity-quota test 0: Test basic quota performance ===== 12:09:09 (1731517749) [ 132.405237] Lustre: DEBUG MARKER: == sanity-quota test 1a: Block hard limit (normal use and out of quota) ========================================================== 12:09:25 (1731517765) [ 135.004664] Lustre: DEBUG MARKER: User quota (block hardlimit:10 MB) [ 136.292189] Lustre: DEBUG MARKER: Write... [ 136.802345] Lustre: DEBUG MARKER: Write out of block quota ... [ 184.416458] Lustre: ll_ost00_001: service thread pid 9550 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: [ 184.421656] Pid: 9550, comm: ll_ost00_001 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 184.424062] Call Trace: [ 184.424851] [<0>] ldlm_completion_ast+0x913/0xd50 [ptlrpc] [ 184.426603] [<0>] ldlm_cli_enqueue_local+0x259/0x890 [ptlrpc] [ 184.428185] [<0>] ofd_destroy_by_fid+0x19c/0x610 [ofd] [ 184.429718] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 184.431259] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 184.432868] [<0>] ptlrpc_server_handle_request+0x281/0xce0 [ptlrpc] [ 184.434732] [<0>] ptlrpc_main+0xc7e/0x1690 [ptlrpc] [ 184.436188] [<0>] kthread+0xe4/0xf0 [ 184.437255] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 184.438675] [<0>] 0xfffffffffffffffe [ 244.576481] LustreError: 7198:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.44@tcp ns: filter-lustre-OST0000_UUID lock: ffff8800839ca400/0xf74df36aec815857 lrc: 3/0,0 mode: PW/PW res: [0x280000401:0x3:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400010020 nid: 192.168.201.44@tcp remote: 0xb536110c09effded expref: 6 pid: 9550 timeout: 243 lvb_type: 0 [ 244.593071] Lustre: ll_ost00_001: service thread pid 9550 completed after 100.239s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 278.992868] Lustre: lustre-OST0000: haven't heard from client 2ffc521c-4beb-49ff-8390-5828f7e5a2d6 (at 192.168.201.44@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff8800724ee000, cur 1731517911 expire 1731517881 last 1731517879 ****************************************************************************** ************************ 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.19s (real) 6.45s (CPU), Child processes: 5.69s