************************ crashinfo ************************* /exports/testreports/49584/testresults/sanity-hsm-zfs-centos7_x86_64-centos7_x86_64/oleg455-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.O19wq/vmlinux [TAINTED] DUMPFILE: /exports/testreports/49584/testresults/sanity-hsm-zfs-centos7_x86_64-centos7_x86_64/oleg455-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Tue Feb 25 08:22:18 EST 2025 UPTIME: 01:23:38 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 357 NODENAME: oleg455-server.virtnet RELEASE: 3.10.0-7.9-debug VERSION: #1 SMP Sat Mar 26 23:28:42 EDT 2022 MACHINE: x86_64 (2400 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 53 last 5s 66 last 60s 80 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 353 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 ----- -------------- ------ ---------------------------- 20 rcuos/1 0 ms (no user stack) 9 rcu_sched 0 ms (no user stack) 1 systemd 0 ms /usr/lib/systemd/systemd --switched-root --system --deserialize 21 902 in:imjournal 14 ms /usr/sbin/rsyslogd -n 3480 arc_reap 212 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 636057 2.4 GB 66% of TOTAL MEM USED 319010 1.2 GB 33% of TOTAL MEM SHARED 10382 40.6 MB 1% of TOTAL MEM BUFFERS 5161 20.2 MB 0% of TOTAL MEM CACHED 72747 284.2 MB 7% of TOTAL MEM SLAB 22019 86 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 61004 238.3 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 5015.5 eth0 n/a 0.6 RSS_TOTAL=49052 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a306000 ffff88012a2e0000 sysfs sysfs /sys ffff88012a3061c0 ffff880139944000 proc proc /proc ffff88012a306380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a306540 ffff8800b5237000 securityfs securityfs /sys/kernel/security ffff88012a306700 ffff88012a2e0800 tmpfs tmpfs /dev/shm ffff88012a3068c0 ffff880137161800 devpts devpts /dev/pts ffff88012a306a80 ffff88012a2e1000 tmpfs tmpfs /run ffff88012a306c40 ffff88012a2e1800 tmpfs tmpfs /sys/fs/cgroup ffff88012a306e00 ffff88012a2e2000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a306fc0 ffff88012a2e2800 pstore pstore /sys/fs/pstore ffff88012a307180 ffff88012a2e4800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a307340 ffff88012a2e4000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a307500 ffff88012a2e3800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a3076c0 ffff88012a2e3000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a307880 ffff88012a2e5000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a307a40 ffff88012a2e5800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a307c00 ffff88012a2e6000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a307dc0 ffff88012a2e6800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a338000 ffff88012a2e7000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a3381c0 ffff88012a2e7800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137668540 ffff88012a292800 configfs configfs /sys/kernel/config ffff8800b4018000 ffff8800b7e7c000 ext4 /dev/nbd0 / ffff8800b4888c40 ffff8800b51f3800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b4018700 ffff8800b4152000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880137668700 ffff880137163000 mqueue mqueue /dev/mqueue ffff88012a3388c0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b40188c0 ffff8800b4157000 hugetlbfs hugetlbfs /dev/hugepages ffff8800b4018a80 ffff8800b4151000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b4018e00 ffff88012a386800 ramfs none /mnt ffff8800b4018fc0 ffff8800b419a000 tmpfs none /var/lib/stateless/writable ffff8800b4019180 ffff8800b419b800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a338a80 ffff8800b419a000 tmpfs none /var/cache/man ffff8800b4019340 ffff8800b419a000 tmpfs none /var/log ffff88012a338c40 ffff8800b419a000 tmpfs none /var/lib/dbus ffff8800b4019500 ffff8800b419a000 tmpfs none /tmp ffff8801376688c0 ffff8800b419a000 tmpfs none /var/lib/dhclient ffff88012a338e00 ffff8800b419a000 tmpfs none /var/tmp ffff88012a338fc0 ffff8800b419a000 tmpfs none /var/lib/NetworkManager ffff880137668a80 ffff8800b419a000 tmpfs none /var/lib/systemd/random-seed ffff880137668c40 ffff8800b419a000 tmpfs none /var/spool ffff880137668e00 ffff8800b419a000 tmpfs none /var/lib/nfs ffff880137668fc0 ffff8800b419a000 tmpfs none /var/lib/gssproxy ffff88012a339180 ffff8800b419a000 tmpfs none /var/lib/logrotate ffff8800b4888fc0 ffff8800b419a000 tmpfs none /etc ffff880137669180 ffff8800b419a000 tmpfs none /var/lib/rsyslog ffff880137669340 ffff8800b419a000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a339340 ffff8800b1d48800 nfs4 192.168.200.253:/exports/state/oleg455-server.virtnet /var/lib/stateless/state ffff88012a339a40 ffff8800b1d48800 nfs4 192.168.200.253:/exports/state/oleg455-server.virtnet /boot ffff8800b40196c0 ffff8800b1d48800 nfs4 192.168.200.253:/exports/state/oleg455-server.virtnet /etc/etc/kdump.conf ffff88012a339c00 ffff8800b51f3800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b49eaa80 ffff8800b419b800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b49ea8c0 ffff88012d565000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b49ebdc0 ffff8801313d1800 lustre lustre-ost2/ost2 /mnt/lustre-ost2 ffff88012c495c00 ffff88009986d000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 1551.351634] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1551.372447] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1552.334833] Lustre: DEBUG MARKER: oleg455-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1557.357456] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.204.155@tcp (at 0@lo) [ 1557.362790] Lustre: Skipped 1 previous similar message [ 1557.460444] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1557.507272] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1557.536709] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:707 to 0x240000400:737) [ 1557.536727] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:707 to 0x280000400:737) [ 1558.684562] Lustre: DEBUG MARKER: oleg455-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1559.250157] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1567.191597] Lustre: DEBUG MARKER: == sanity-hsm test 408: Verify fiemap on release file ==== 07:24:45 (1740486285) [ 1567.911557] Lustre: DEBUG MARKER: SKIP: sanity-hsm test_408 ORI-366/LU-1941: FIEMAP unimplemented on ZFS [ 1568.597814] Lustre: DEBUG MARKER: == sanity-hsm test 409a: Coordinator should not stop when in use ========================================================== 07:24:46 (1740486286) [ 1570.829136] LustreError: 9958:0:(mdt_hsm_cdt_client.c:366:mdt_hsm_register_hal()) cfs_fail_timeout id 164 sleeping for 5000ms [ 1575.833875] LustreError: 9958:0:(mdt_hsm_cdt_client.c:366:mdt_hsm_register_hal()) cfs_fail_timeout id 164 awake [ 1581.722193] Lustre: DEBUG MARKER: == sanity-hsm test 409b: getattr released file with CDT stopped after remount ========================================================== 07:25:00 (1740486300) [ 1583.985075] Lustre: Modifying parameter lustre.mdt.lustre-MDT0000.hsm_control in log params [ 1604.974932] Lustre: Failing over lustre-MDT0000 [ 1605.121408] Lustre: server umount lustre-MDT0000 complete [ 1617.593043] LustreError: MGC192.168.204.155@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 1617.786219] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 1617.817191] Lustre: lustre-MDT0000: in recovery but waiting for the first client to connect [ 1618.928409] Lustre: DEBUG MARKER: oleg455-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 1620.830541] Lustre: lustre-MDT0000: Will be in recovery for at least 1:00, or until 2 clients reconnect [ 1622.580885] Lustre: lustre-MDT0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 1622.595056] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:740 to 0x280000400:769) [ 1622.598594] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:741 to 0x240000400:769) [ 1622.771015] Lustre: lustre-MDT0000-lwp-OST0001: Connection to lustre-MDT0000 (at 0@lo) was lost; in progress operations using this service will wait for recovery to complete [ 1622.771930] Lustre: lustre-MDT0000-lwp-OST0000: Connection restored to 192.168.204.155@tcp (at 0@lo) [ 1622.771931] Lustre: Skipped 1 previous similar message [ 1622.780047] Lustre: Skipped 1 previous similar message [ 1623.338406] Lustre: DEBUG MARKER: oleg455-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 1623.770912] Lustre: 3289:0:(client.c:2350:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1740486326/real 1740486326] req@ffff88009158e300 x1825030536363648/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1740486342 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 1623.785536] Lustre: 3289:0:(client.c:2350:ptlrpc_expire_one_request()) Skipped 11 previous similar messages [ 1623.929919] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 1648.489875] Lustre: DEBUG MARKER: == sanity-hsm test 410: lfs data_version -s allows release of force-archived file ========================================================== 07:26:06 (1740486366) [ 1651.102255] Lustre: DEBUG MARKER: == sanity-hsm test 411: hsm_ops rbac role ================ 07:26:09 (1740486369) [ 1705.529422] Lustre: DEBUG MARKER: == sanity-hsm test 500: various LLAPI HSM tests ========== 07:27:03 (1740486423) [ 1721.145420] Lustre: HSM agent d9118b17-dde8-4c0c-a15c-8cc5ed263dfe already registered ****************************************************************************** ************************ 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.28s (real) 6.22s (CPU), Child processes: 5.01s