************************ crashinfo ************************* /exports/testreports/46455/testresults/sanity-hsm-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg204-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.zytz2/vmlinux [TAINTED] DUMPFILE: /exports/testreports/46455/testresults/sanity-hsm-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg204-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Oct 16 12:10:14 EDT 2024 UPTIME: 01:47:18 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 255 NODENAME: oleg204-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 19 last 5s 63 last 60s 79 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 251 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 ----- -------------- ------ ---------------------------- 7233 ldlm_bl_02 0 ms (no user stack) 4543 l2arc_feed 0 ms (no user stack) 17 kworker/1:0 0 ms (no user stack) 3775 lnet_discovery 39 ms (no user stack) 22603 hsm_cdtr 88 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 716808 2.7 GB 75% of TOTAL MEM USED 238259 930.7 MB 24% of TOTAL MEM SHARED 11892 46.5 MB 1% of TOTAL MEM BUFFERS 9432 36.8 MB 0% of TOTAL MEM CACHED 91302 356.6 MB 9% of TOTAL MEM SLAB 16602 64.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 67946 265.4 MB 9% 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 6432.2 eth0 n/a 0.0 RSS_TOTAL=54152 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880138ccac40 ffff88012a2c0800 sysfs sysfs /sys ffff880138ccae00 ffff880139944000 proc proc /proc ffff880138ccafc0 ffff880137678000 devtmpfs devtmpfs /dev ffff880138ccb180 ffff88012a2c0000 securityfs securityfs /sys/kernel/security ffff880138ccb340 ffff88012a2c1000 tmpfs tmpfs /dev/shm ffff880138ccb500 ffff88013700c000 devpts devpts /dev/pts ffff880138ccb6c0 ffff88012a2c1800 tmpfs tmpfs /run ffff880138ccb880 ffff88012a2c2000 tmpfs tmpfs /sys/fs/cgroup ffff880138ccba40 ffff88012a2c2800 cgroup cgroup /sys/fs/cgroup/systemd ffff880138ccbc00 ffff88012a2c3000 pstore pstore /sys/fs/pstore ffff880138ccbdc0 ffff88012a2c5000 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a382000 ffff88012a2c4800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a3821c0 ffff88012a2c4000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a382380 ffff88012a2c3800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a382540 ffff88012a2c5800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a382700 ffff88012a2c6000 cgroup cgroup /sys/fs/cgroup/devices ffff88012a3828c0 ffff88012a2c6800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a382a80 ffff88012a2c7000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a382c40 ffff88012a2c7800 cgroup cgroup /sys/fs/cgroup/blkio ffff880137668380 ffff8800b635c000 cgroup cgroup /sys/fs/cgroup/memory ffff880137668540 ffff8800b635f800 configfs configfs /sys/kernel/config ffff8801370d6fc0 ffff88012b346000 ext4 /dev/nbd0 / ffff880137669880 ffff88012a3ac800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8801377fe700 ffff8800b4e6c000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880137669c00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8801377fe8c0 ffff88013700d800 mqueue mqueue /dev/mqueue ffff8801370d7180 ffff880129cbc800 hugetlbfs hugetlbfs /dev/hugepages ffff8801377fea80 ffff8800b4f8d000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b4cd6000 ffff880129f0e000 ramfs none /mnt ffff8801377fec40 ffff8800b4f8e800 squashfs /dev/vda /home/green/git/lustre-release ffff8801377fee00 ffff8800b4f8a000 tmpfs none /var/lib/stateless/writable ffff8801370d7340 ffff8800b4f8a000 tmpfs none /var/cache/man ffff8801370d7500 ffff8800b4f8a000 tmpfs none /var/log ffff8800b4cd6380 ffff8800b4f8a000 tmpfs none /var/lib/dbus ffff8801370d76c0 ffff8800b4f8a000 tmpfs none /tmp ffff8801370d7880 ffff8800b4f8a000 tmpfs none /var/lib/dhclient ffff8801370d7a40 ffff8800b4f8a000 tmpfs none /var/tmp ffff8801377fefc0 ffff8800b4f8a000 tmpfs none /var/lib/NetworkManager ffff8801377ff180 ffff8800b4f8a000 tmpfs none /var/lib/systemd/random-seed ffff8801377ff340 ffff8800b4f8a000 tmpfs none /var/spool ffff8801377ff500 ffff8800b4f8a000 tmpfs none /var/lib/nfs ffff8801370d7c00 ffff8800b4f8a000 tmpfs none /var/lib/gssproxy ffff8801370d7dc0 ffff8800b4f8a000 tmpfs none /var/lib/logrotate ffff8801370d6c40 ffff8800b4f8a000 tmpfs none /etc ffff88012a3e0000 ffff8800b4f8a000 tmpfs none /var/lib/rsyslog ffff88012a3e01c0 ffff8800b4f8a000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a383180 ffff8800b4d83800 nfs4 192.168.200.253:/exports/state/oleg204-server.virtnet /var/lib/stateless/state ffff8801377ffa40 ffff8800b4d83800 nfs4 192.168.200.253:/exports/state/oleg204-server.virtnet /boot ffff88012a3e0380 ffff8800b4d83800 nfs4 192.168.200.253:/exports/state/oleg204-server.virtnet /etc/etc/kdump.conf ffff8800b4cd6540 ffff88012a3ac800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff88012a383c00 ffff8800b4f8e800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b2545dc0 ffff880129e89800 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800b25448c0 ffff8800a78b7000 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff8800b2545500 ffff880077a17800 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff8800b25441c0 ffff8800b523a800 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 276.360828] Lustre: DEBUG MARKER: SKIP: sanity-hsm test_12h Need 2 or more clients, have 1 [ 276.893750] Lustre: DEBUG MARKER: == sanity-hsm test 12m: Archive/release/implicit restore ========================================================== 10:27:33 (1729088853) [ 280.749558] Lustre: DEBUG MARKER: == sanity-hsm test 12n: Import/implicit restore/release == 10:27:36 (1729088856) [ 283.801999] Lustre: DEBUG MARKER: == sanity-hsm test 12o: Layout-swap failure during Restore leaves file released ========================================================== 10:27:39 (1729088859) [ 286.055643] Lustre: *** cfs_fail_loc=152, val=0*** [ 302.820856] Lustre: DEBUG MARKER: == sanity-hsm test 12p: implicit restore of a file on copytool mount point ========================================================== 10:27:58 (1729088878) [ 307.140636] Lustre: DEBUG MARKER: == sanity-hsm test 12q: file attributes are refreshed after restore ========================================================== 10:28:03 (1729088883) [ 316.494704] Lustre: DEBUG MARKER: == sanity-hsm test 12r: lseek restores released file ===== 10:28:12 (1729088892) [ 320.585168] Lustre: DEBUG MARKER: == sanity-hsm test 12s: race between restore requests ==== 10:28:16 (1729088896) [ 322.557516] LustreError: 7244:0:(mdt_hsm_cdt_client.c:369:mdt_hsm_register_hal()) cfs_race id 18b sleeping [ 327.559736] LustreError: 7244:0:(mdt_hsm_cdt_client.c:369:mdt_hsm_register_hal()) cfs_fail_race id 18b awake: rc=0 [ 330.607431] Lustre: DEBUG MARKER: == sanity-hsm test 12t: Multiple parallel reads for a HSM imported file ========================================================== 10:28:26 (1729088906) [ 334.905268] Lustre: DEBUG MARKER: == sanity-hsm test 12u: Multiple reads on multiple HSM imported files in parallel ========================================================== 10:28:31 (1729088911) [ 343.558146] Lustre: DEBUG MARKER: == sanity-hsm test 13: Recursively import and restore a directory ========================================================== 10:28:39 (1729088919) [ 351.491596] Lustre: DEBUG MARKER: == sanity-hsm test 14: Rebind archived file to a new fid ========================================================== 10:28:47 (1729088927) [ 355.721709] Lustre: DEBUG MARKER: == sanity-hsm test 15: Rebind a list of files ============ 10:28:51 (1729088931) [ 365.080488] Lustre: DEBUG MARKER: == sanity-hsm test 16: Test CT bandwith control option === 10:29:01 (1729088941) [ 388.970615] Lustre: DEBUG MARKER: == sanity-hsm test 20: Release is not permitted ========== 10:29:25 (1729088965) [ 390.754230] Lustre: DEBUG MARKER: == sanity-hsm test 21: Simple release tests ============== 10:29:26 (1729088966) [ 395.813683] Lustre: DEBUG MARKER: == sanity-hsm test 22: Could not swap a release file ===== 10:29:31 (1729088971) [ 399.442183] Lustre: DEBUG MARKER: == sanity-hsm test 23: Release does not change a/mtime (utime) ========================================================== 10:29:35 (1729088975) [ 402.878113] Lustre: DEBUG MARKER: == sanity-hsm test 24a: Archive, release, and restore does not change a/mtime (i/o) ========================================================== 10:29:39 (1729088979) [ 409.433524] Lustre: DEBUG MARKER: == sanity-hsm test 24b: root can archive, release, and restore user files ========================================================== 10:29:45 (1729088985) [ 415.791371] Lustre: DEBUG MARKER: == sanity-hsm test 24c: check that user,group,other request masks work ========================================================== 10:29:51 (1729088991) [ 422.726008] Lustre: DEBUG MARKER: == sanity-hsm test 24d: check that read-only mounts are respected ========================================================== 10:29:58 (1729088998) [ 428.824409] Lustre: DEBUG MARKER: == sanity-hsm test 24e: tar succeeds on HSM released files ========================================================== 10:30:04 (1729089004) [ 432.271757] Lustre: DEBUG MARKER: == sanity-hsm test 24f: root can archive, release, and restore tar files ========================================================== 10:30:08 (1729089008) [ 436.092022] Lustre: DEBUG MARKER: == sanity-hsm test 24g: write by non-owner still sets dirty ========================================================== 10:30:12 (1729089012) [ 438.212836] Lustre: DEBUG MARKER: == sanity-hsm test 25a: Restore lost file (HS_LOST flag) from import ========================================================== 10:30:14 (1729089014) [ 440.188289] Lustre: DEBUG MARKER: == sanity-hsm test 25b: Restore lost file (HS_LOST flag) after release ========================================================== 10:30:16 (1729089016) [ 442.316516] Lustre: DEBUG MARKER: == sanity-hsm test 26A: Remove the archive of a valid file ========================================================== 10:30:18 (1729089018) [ 446.149943] Lustre: DEBUG MARKER: == sanity-hsm test 26a: Remove Archive On Last Unlink (RAoLU) policy ========================================================== 10:30:22 (1729089022) [ 654.914269] Lustre: DEBUG MARKER: sanity-hsm test_26a: @@@@@@ FAIL: request on 0x200000403:0xa0:0x0 is not SUCCEED on mds1 [ 657.957470] Lustre: DEBUG MARKER: == sanity-hsm test 26b: RAoLU policy when CDT off ======== 10:33:54 (1729089234) [ 864.635151] Lustre: DEBUG MARKER: sanity-hsm test_26b: @@@@@@ FAIL: request on 0x200000403:0xa2:0x0 is not SUCCEED on mds1 [ 866.587377] Lustre: DEBUG MARKER: == sanity-hsm test 26c: RAoLU effective when file closed ========================================================== 10:37:22 (1729089442) [ 1072.616803] Lustre: DEBUG MARKER: sanity-hsm test_26c: @@@@@@ FAIL: request on 0x200000403:0xa4:0x0 is not SUCCEED on mds1 [ 4471.026576] Lustre: DEBUG MARKER: == sanity-hsm test 26d: RAoLU when Client eviction ======= 11:37:27 (1729093047) [ 4475.654364] Lustre: 17540:0:(genops.c:1672:obd_export_evict_by_uuid()) lustre-MDT0000: evicting 002a0e0f-ac06-4bb8-a04b-6e8b6f97b425 at adminstrative request [ 4677.541431] Lustre: DEBUG MARKER: sanity-hsm test_26d: @@@@@@ FAIL: request on 0x200000403:0xa6:0x0 is not SUCCEED on mds1 ****************************************************************************** ************************ 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 10.74s (real) 5.80s (CPU), Child processes: 4.91s