************************ crashinfo ************************* /exports/testreports/47154/testresults/ost-pools-zfs-centos7_x86_64-centos7_x86_64/oleg426-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.I8oos/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/ost-pools-zfs-centos7_x86_64-centos7_x86_64/oleg426-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 13:14:09 EST 2024 UPTIME: 01:06:58 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 352 NODENAME: oleg426-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 27 last 5s 62 last 60s 76 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 348 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 ----- -------------- ------ ---------------------------- 3296 monitor_thread 0 ms (no user stack) 20 rcuos/1 0 ms (no user stack) 915 in:imjournal 0 ms /usr/sbin/rsyslogd -n 6723 z_null_iss 0 ms (no user stack) 830 gmain 34 ms /usr/sbin/NetworkManager --no-daemon +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 724515 2.8 GB 75% of TOTAL MEM USED 230552 900.6 MB 24% of TOTAL MEM SHARED 10171 39.7 MB 1% of TOTAL MEM BUFFERS 5123 20 MB 0% of TOTAL MEM CACHED 71554 279.5 MB 7% of TOTAL MEM SLAB 20676 80.8 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 60013 234.4 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 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 4015.6 eth0 n/a 2.9 RSS_TOTAL=53312 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880138ccafc0 ffff8800b54dd000 sysfs sysfs /sys ffff880138ccb180 ffff880139944000 proc proc /proc ffff880138ccb340 ffff880137678000 devtmpfs devtmpfs /dev ffff880138ccb500 ffff8800b7c3d800 securityfs securityfs /sys/kernel/security ffff880138ccb6c0 ffff8800b54dd800 tmpfs tmpfs /dev/shm ffff880138ccb880 ffff8801372e6000 devpts devpts /dev/pts ffff880138ccba40 ffff8800b54de000 tmpfs tmpfs /run ffff880138ccbc00 ffff8800b54de800 tmpfs tmpfs /sys/fs/cgroup ffff880138ccbdc0 ffff8800b54df000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a2ee000 ffff8800b54df800 pstore pstore /sys/fs/pstore ffff88012a2ee1c0 ffff88012a309800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2ee380 ffff88012a309000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a2ee540 ffff88012a308800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a2ee700 ffff88012a308000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a2ee8c0 ffff88012a30a000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a2eea80 ffff88012a30a800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a2eec40 ffff88012a30b000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a2eee00 ffff88012a30b800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a2eefc0 ffff88012a30c000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a2ef180 ffff88012a30c800 cgroup cgroup /sys/fs/cgroup/freezer ffff880137668380 ffff88013767b000 configfs configfs /sys/kernel/config ffff880129cfafc0 ffff8800b5252800 ext4 /dev/nbd0 / ffff88012a2efa40 ffff88012a30d800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012b257180 ffff8800b4f6f000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880129cfb180 ffff88012a3e0800 hugetlbfs hugetlbfs /dev/hugepages ffff88012b257340 ffff8801372e7800 mqueue mqueue /dev/mqueue ffff88012a2efc00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137668540 ffff88012a30f800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012b2576c0 ffff8800b4f6e800 ramfs none /mnt ffff880137668700 ffff8800b4328000 squashfs /dev/vda /home/green/git/lustre-release ffff8801376688c0 ffff8800b432e000 tmpfs none /var/lib/stateless/writable ffff880129cfb500 ffff8800b432e000 tmpfs none /var/cache/man ffff880129cfb6c0 ffff8800b432e000 tmpfs none /var/log ffff880137668a80 ffff8800b432e000 tmpfs none /var/lib/dbus ffff880137668c40 ffff8800b432e000 tmpfs none /tmp ffff880137668e00 ffff8800b432e000 tmpfs none /var/lib/dhclient ffff880129cfb880 ffff8800b432e000 tmpfs none /var/tmp ffff880129cfba40 ffff8800b432e000 tmpfs none /var/lib/NetworkManager ffff880129cfbc00 ffff8800b432e000 tmpfs none /var/lib/systemd/random-seed ffff880137668fc0 ffff8800b432e000 tmpfs none /var/spool ffff880129cfbdc0 ffff8800b432e000 tmpfs none /var/lib/nfs ffff8800b219a000 ffff8800b432e000 tmpfs none /var/lib/gssproxy ffff8800b219a1c0 ffff8800b432e000 tmpfs none /var/lib/logrotate ffff88012b257880 ffff8800b432e000 tmpfs none /etc ffff880137669180 ffff8800b432e000 tmpfs none /var/lib/rsyslog ffff8800b219a380 ffff8800b432e000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff880137669340 ffff8800b4256000 nfs4 192.168.200.253:/exports/state/oleg426-server.virtnet /var/lib/stateless/state ffff880137669500 ffff8800b4256000 nfs4 192.168.200.253:/exports/state/oleg426-server.virtnet /boot ffff88012b257a40 ffff8800b4256000 nfs4 192.168.200.253:/exports/state/oleg426-server.virtnet /etc/etc/kdump.conf ffff8800b219a700 ffff88012a30d800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff880137669880 ffff8800b4328000 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b43cf340 ffff8800b5256000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b20dca80 ffff88012c0e5000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b53bd180 ffff8800943f0800 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 465.413477] Lustre: DEBUG MARKER: SKIP: ost-pools test_13 needs >= 3 OSTs [ 465.780488] Lustre: DEBUG MARKER: == ost-pools test 14: Round robin and QOS striping within a pool ========================================================== 12:14:55 (1731518095) [ 466.097994] Lustre: DEBUG MARKER: SKIP: ost-pools test_14 needs >= 3 OSTs [ 466.458842] Lustre: DEBUG MARKER: == ost-pools test 15: One directory per OST/pool ========= 12:14:56 (1731518096) [ 488.377895] Lustre: DEBUG MARKER: == ost-pools test 16: Inheritance of pool properties ===== 12:15:18 (1731518118) [ 505.173728] Lustre: DEBUG MARKER: == ost-pools test 17: Referencing an empty pool ========== 12:15:35 (1731518135) [ 522.276749] Lustre: DEBUG MARKER: == ost-pools test 18: File create in a directory which references a deleted pool ========================================================== 12:15:52 (1731518152) [ 904.682488] Lustre: DEBUG MARKER: == ost-pools test 19: Pools should not come into play when not specified ========================================================== 12:22:14 (1731518534) [ 923.014317] Lustre: DEBUG MARKER: == ost-pools test 20: Different pools in a directory hierarchy. ========================================================== 12:22:33 (1731518553) [ 947.230398] Lustre: DEBUG MARKER: == ost-pools test 21: OST pool with fewer OSTs than stripe count ========================================================== 12:22:57 (1731518577) [ 960.870603] Lustre: DEBUG MARKER: == ost-pools test 22: Simultaneous manipulation of a pool ========================================================== 12:23:10 (1731518590) [ 969.965757] LustreError: 499:0:(mgs_handler.c:844:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.testpool [ 969.974661] LustreError: 499:0:(mgs_handler.c:844:mgs_iocontrol_pool()) Skipped 2 previous similar messages [ 970.603607] LustreError: 759:0:(qmt_pool.c:1513:qmt_pool_add_rem()) lustre-QMT0000: can't remove lustre-OST0001_UUID pool 'testpool': rc = -22 [ 972.147467] LustreError: 1446:0:(mgs_handler.c:844:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.testpool2 [ 972.152983] LustreError: 1446:0:(mgs_handler.c:844:mgs_iocontrol_pool()) Skipped 9 previous similar messages [ 972.190513] LustreError: 1480:0:(qmt_pool.c:1513:qmt_pool_add_rem()) lustre-QMT0000: can't remove lustre-OST0001_UUID pool 'testpool': rc = -22 [ 973.796481] LustreError: 1932:0:(qmt_pool.c:1513:qmt_pool_add_rem()) lustre-QMT0000: can't remove lustre-OST0001_UUID pool 'testpool': rc = -22 [ 973.803788] LustreError: 1932:0:(qmt_pool.c:1513:qmt_pool_add_rem()) Skipped 2 previous similar messages [ 976.318774] LustreError: 2071:0:(mgs_handler.c:844:mgs_iocontrol_pool()) OBD_IOC_POOL err -17, cmd CE021 for pool lustre.testpool [ 976.320888] LustreError: 2071:0:(mgs_handler.c:844:mgs_iocontrol_pool()) Skipped 5 previous similar messages [ 976.757782] LustreError: 2219:0:(qmt_pool.c:1513:qmt_pool_add_rem()) lustre-QMT0000: can't remove lustre-OST0001_UUID pool 'testpool': rc = -22 [ 976.765421] LustreError: 2219:0:(qmt_pool.c:1513:qmt_pool_add_rem()) Skipped 1 previous similar message [ 990.960063] Lustre: DEBUG MARKER: == ost-pools test 23a: OST pools and quota =============== 12:23:40 (1731518620) [ 1049.339787] Lustre: ll_ost00_010: service thread pid 12856 was inactive for 40.091 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 1049.347657] Pid: 12856, comm: ll_ost00_010 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 1049.351151] Call Trace: [ 1049.352451] [<0>] ldlm_completion_ast+0x913/0xd50 [ptlrpc] [ 1049.355758] [<0>] ldlm_cli_enqueue_local+0x259/0x890 [ptlrpc] [ 1049.359057] [<0>] ofd_destroy_by_fid+0x19c/0x610 [ofd] [ 1049.362444] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 1049.365218] [<0>] tgt_request_handle+0x74e/0x1a60 [ptlrpc] [ 1049.368137] [<0>] ptlrpc_server_handle_request+0x281/0xce0 [ptlrpc] [ 1049.371526] [<0>] ptlrpc_main+0xc7e/0x1690 [ptlrpc] [ 1049.373946] [<0>] kthread+0xe4/0xf0 [ 1049.375901] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 1049.379134] [<0>] 0xfffffffffffffffe [ 1109.627826] LustreError: 7035:0:(ldlm_lockd.c:241:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.204.26@tcp ns: filter-lustre-OST0000_UUID lock: ffff880092790d80/0xf223797b5b58e4a6 lrc: 3/0,0 mode: PW/PW res: [0x240000400:0xabfd:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400010020 nid: 192.168.204.26@tcp remote: 0xd2e30859fa3c1024 expref: 6 pid: 12856 timeout: 1108 lvb_type: 0 [ 1109.647681] Lustre: ll_ost00_010: service thread pid 12856 completed after 100.399s. This likely indicates the system was overloaded (too many service threads, or not enough hardware resources). [ 1146.443986] Lustre: lustre-OST0000: haven't heard from client b3597084-d9ef-4237-ada6-b9a00b8eb24c (at 192.168.204.26@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff880090934800, cur 1731518776 expire 1731518746 last 1731518744 ****************************************************************************** ************************ 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 14.02s (real) 7.07s (CPU), Child processes: 6.88s