************************ crashinfo ************************* /exports/testreports/42551/testresults/sanity1-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg331-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.3ar1x/vmlinux [TAINTED] DUMPFILE: /exports/testreports/42551/testresults/sanity1-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg331-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 8 19:22:21 EDT 2024 UPTIME: 01:21:32 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 274 NODENAME: oleg331-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 23 last 5s 57 last 60s 82 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 270 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 ----- -------------- ------ ---------------------------- 9 rcu_sched 0 ms (no user stack) 3686 ptlrpcd_00_02 0 ms (no user stack) 4439 dbuf_evict 0 ms (no user stack) 4437 zthr_procedure 0 ms (no user stack) 1 systemd 4 ms /usr/lib/systemd/systemd --switched-root --system --deserialize 22 +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 699937 2.7 GB 73% of TOTAL MEM USED 255130 996.6 MB 26% of TOTAL MEM SHARED 41226 161 MB 4% of TOTAL MEM BUFFERS 37985 148.4 MB 3% of TOTAL MEM CACHED 74785 292.1 MB 7% of TOTAL MEM SLAB 18558 72.5 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 64490 251.9 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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 4890.1 eth0 n/a 1.8 RSS_TOTAL=55564 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a280000 ffff880137300800 sysfs sysfs /sys ffff88012a2801c0 ffff880139944000 proc proc /proc ffff88012a280380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a280540 ffff8800b520a800 securityfs securityfs /sys/kernel/security ffff88012a280700 ffff880137301000 tmpfs tmpfs /dev/shm ffff88012a2808c0 ffff88013771f000 devpts devpts /dev/pts ffff88012a280a80 ffff880137301800 tmpfs tmpfs /run ffff88012a280c40 ffff880137302000 tmpfs tmpfs /sys/fs/cgroup ffff88012a280e00 ffff880137302800 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a280fc0 ffff880137303000 pstore pstore /sys/fs/pstore ffff880137000540 ffff88012a309000 cgroup cgroup /sys/fs/cgroup/pids ffff880137000700 ffff88012a308800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff8801370008c0 ffff88012a308000 cgroup cgroup /sys/fs/cgroup/devices ffff880137000a80 ffff88012a309800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880137000c40 ffff88012a30a000 cgroup cgroup /sys/fs/cgroup/freezer ffff880137000e00 ffff88012a30a800 cgroup cgroup /sys/fs/cgroup/perf_event ffff880137000fc0 ffff88012a30b000 cgroup cgroup /sys/fs/cgroup/blkio ffff880137001180 ffff88012a30b800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137001340 ffff88012a30c000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880137001500 ffff88012a30c800 cgroup cgroup /sys/fs/cgroup/memory ffff880137668700 ffff88013767c000 configfs configfs /sys/kernel/config ffff8801376688c0 ffff88013767d000 ext4 /dev/nbd0 / ffff88012a281340 ffff880137304000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012a281500 ffff8800b400b800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880137668540 ffff880137678800 mqueue mqueue /dev/mqueue ffff880129c4e8c0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880129c4ea80 ffff88012a30d000 hugetlbfs hugetlbfs /dev/hugepages ffff880137001c00 ffff88013767e000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880129c4ec40 ffff8800b400d000 ramfs none /mnt ffff880137668c40 ffff880129de1800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a2816c0 ffff880129eb8000 tmpfs none /var/lib/stateless/writable ffff880137668e00 ffff880129eb8000 tmpfs none /var/cache/man ffff880129c4efc0 ffff880129eb8000 tmpfs none /var/log ffff880137668fc0 ffff880129eb8000 tmpfs none /var/lib/dbus ffff880129c4f180 ffff880129eb8000 tmpfs none /tmp ffff880129c4f340 ffff880129eb8000 tmpfs none /var/lib/dhclient ffff880137669180 ffff880129eb8000 tmpfs none /var/tmp ffff880137669340 ffff880129eb8000 tmpfs none /var/lib/NetworkManager ffff880129c4f500 ffff880129eb8000 tmpfs none /var/lib/systemd/random-seed ffff880137001dc0 ffff880129eb8000 tmpfs none /var/spool ffff880137001a40 ffff880129eb8000 tmpfs none /var/lib/nfs ffff880137001880 ffff880129eb8000 tmpfs none /var/lib/gssproxy ffff88012a281880 ffff880129eb8000 tmpfs none /var/lib/logrotate ffff8801370016c0 ffff880129eb8000 tmpfs none /etc ffff8800b28e0000 ffff880129eb8000 tmpfs none /var/lib/rsyslog ffff88012a281a40 ffff880129eb8000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a281c00 ffff8800b4201000 nfs4 192.168.200.253:/exports/state/oleg331-server.virtnet /var/lib/stateless/state ffff88012e18a000 ffff8800b4201000 nfs4 192.168.200.253:/exports/state/oleg331-server.virtnet /boot ffff8800b28e01c0 ffff8800b4201000 nfs4 192.168.200.253:/exports/state/oleg331-server.virtnet /etc/etc/kdump.conf ffff88012e18a1c0 ffff880137304000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800aece68c0 ffff880129de1800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b53e0380 ffff88012d255000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 ffff8800b28e0540 ffff88012d324800 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff8800b4ced880 ffff88011e58e000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800b28e0380 ffff8800984b9800 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 1085.315357] Lustre: DEBUG MARKER: == sanity test 27o: create file with all full OSTs (should error) ========================================================== 18:18:53 (1715206733) [ 1089.120977] Lustre: *** cfs_fail_loc=215, val=4294967295*** [ 1091.638649] Lustre: *** cfs_fail_loc=215, val=1*** [ 1096.646712] Lustre: *** cfs_fail_loc=215, val=1*** [ 1096.648891] Lustre: Skipped 3 previous similar messages [ 1101.655028] Lustre: *** cfs_fail_loc=215, val=1*** [ 1101.657292] Lustre: Skipped 3 previous similar messages [ 1112.437687] Lustre: DEBUG MARKER: == sanity test 27oo: don't let few threads to reserve too many objects ========================================================== 18:19:20 (1715206760) [ 1135.582655] Lustre: Failing over lustre-OST0000 [ 1135.629524] Lustre: server umount lustre-OST0000 complete [ 1136.789884] LustreError: 137-5: lustre-OST0000: not available for connect from 192.168.203.31@tcp (no target). If you are running an HA pair check that the target is mounted on the other server. [ 1136.793907] LustreError: Skipped 12 previous similar messages [ 1136.902396] LustreError: 11-0: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [ 1136.905252] Lustre: lustre-OST0000-osc-MDT0001: Connection to lustre-OST0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1136.908810] Lustre: Skipped 1 previous similar message [ 1139.463010] LDISKFS-fs (dm-2): file extents enabled, maximum tree depth=5 [ 1139.466653] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [ 1139.523326] Lustre: lustre-OST0000: Imperative Recovery enabled, recovery window shrunk from 60-180 down to 60-180 [ 1139.528527] Lustre: lustre-OST0000: in recovery but waiting for the first client to connect [ 1140.690385] Lustre: DEBUG MARKER: oleg331-server.virtnet: executing set_default_debug all all [ 1140.907736] Lustre: lustre-OST0000: Will be in recovery for at least 1:00, or until 3 clients reconnect [ 1144.259707] Lustre: DEBUG MARKER: == sanity test 27p: append to a truncated file with some full OSTs ========================================================== 18:19:52 (1715206792) [ 1210.533995] Lustre: lustre-OST0000: recovery is timed out, evict stale exports [ 1210.537467] Lustre: 12449:0:(genops.c:1528:class_disconnect_stale_exports()) lustre-OST0000: disconnect stale client 53c5340c-7106-4a92-bbcc-6bfa25d3d352@192.168.203.31@tcp [ 1210.544097] Lustre: lustre-OST0000: disconnecting 1 stale clients [ 1210.551163] Lustre: lustre-OST0000-osc-MDT0000: Connection restored to 192.168.203.131@tcp (at 0@lo) [ 1210.551648] Lustre: 12449:0:(ldlm_lib.c:2874:target_recovery_thread()) too long recovery - read logs [ 1210.552929] LustreError: dumping log to /tmp/lustre-log.1715206858.12449 [ 1210.640849] Lustre: lustre-OST0000: Recovery over after 1:10, of 3 clients 2 recovered and 1 was evicted. [ 1215.558525] Lustre: *** cfs_fail_loc=215, val=0*** [ 1215.560194] Lustre: Skipped 2 previous similar messages [ 1232.761426] Lustre: DEBUG MARKER: == sanity test 27q: append to truncated file with all OSTs full (should error) ========================================================== 18:21:20 (1715206880) [ 1236.886634] Lustre: *** cfs_fail_loc=215, val=1*** [ 1236.889537] Lustre: Skipped 2 previous similar messages [ 1243.489676] Lustre: *** cfs_fail_loc=215, val=4294967295*** [ 1260.546912] Lustre: DEBUG MARKER: == sanity test 27r: stripe file with some full OSTs (shouldn't LBUG) =========================================================== 18:21:48 (1715206908) [ 1265.639013] Lustre: *** cfs_fail_loc=215, val=0*** [ 1265.640604] Lustre: Skipped 11 previous similar messages [ 1281.837983] Lustre: DEBUG MARKER: == sanity test 27s: lsm_xfersize overflow (should error) (bug 10725) ========================================================== 18:22:09 (1715206929) [ 1286.589727] Lustre: DEBUG MARKER: == sanity test 27t: check that utils parse path correctly ========================================================== 18:22:14 (1715206934) ****************************************************************************** ************************ 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.05s (real) 6.42s (CPU), Child processes: 5.61s