************************ crashinfo ************************* /exports/testreports/42551/testresults/sanity-sec-zfs-centos7_x86_64-centos7_x86_64/oleg359-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.owgRd/vmlinux [TAINTED] DUMPFILE: /exports/testreports/42551/testresults/sanity-sec-zfs-centos7_x86_64-centos7_x86_64/oleg359-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 8 19:57:48 EDT 2024 UPTIME: 01:56:57 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 399 NODENAME: oleg359-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 28 last 5s 64 last 60s 77 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 395 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 ----- -------------- ------ ---------------------------- 8107 z_null_iss 0 ms (no user stack) 9732 txg_quiesce 0 ms (no user stack) 3210 lnet_discovery 0 ms (no user stack) 8108 z_null_int 0 ms (no user stack) 10108 ldlm_bl_03 78 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 695951 2.7 GB 72% of TOTAL MEM USED 259116 1012.2 MB 27% of TOTAL MEM SHARED 8401 32.8 MB 0% of TOTAL MEM BUFFERS 5873 22.9 MB 0% of TOTAL MEM CACHED 71507 279.3 MB 7% of TOTAL MEM SLAB 26893 105.1 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 64344 251.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): 8 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 7014.9 eth0 n/a 2.9 RSS_TOTAL=51592 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137668380 ffff8800b523a000 sysfs sysfs /sys ffff880137668540 ffff880139944000 proc proc /proc ffff880137668700 ffff880137678000 devtmpfs devtmpfs /dev ffff8801376688c0 ffff88012b32f000 securityfs securityfs /sys/kernel/security ffff880137668a80 ffff8800b523a800 tmpfs tmpfs /dev/shm ffff880137668c40 ffff880137169800 devpts devpts /dev/pts ffff880137668e00 ffff8800b523b000 tmpfs tmpfs /run ffff880137668fc0 ffff8800b523b800 tmpfs tmpfs /sys/fs/cgroup ffff880137669180 ffff8800b523c000 cgroup cgroup /sys/fs/cgroup/systemd ffff880137669340 ffff8800b523c800 pstore pstore /sys/fs/pstore ffff880137669500 ffff8800b523e800 cgroup cgroup /sys/fs/cgroup/blkio ffff8801376696c0 ffff8800b523e000 cgroup cgroup /sys/fs/cgroup/freezer ffff880137669880 ffff8800b523d800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880137669a40 ffff8800b523d000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff880137669c00 ffff8800b523f000 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137669dc0 ffff8800b523f800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a338000 ffff88012a348000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a3381c0 ffff88012a348800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a338380 ffff88012a349000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a338540 ffff88012a349800 cgroup cgroup /sys/fs/cgroup/devices ffff8800b537e1c0 ffff8800b4d40000 configfs configfs /sys/kernel/config ffff8800b537f340 ffff8800b4d43000 ext4 /dev/nbd0 / ffff880138ccbc00 ffff8800b6c8e000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b537f500 ffff8800b4d77800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880138ccbdc0 ffff88013684b000 hugetlbfs hugetlbfs /dev/hugepages ffff88012a338e00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012a308380 ffff88013716b000 mqueue mqueue /dev/mqueue ffff88012a338fc0 ffff8800b4208800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8801372de000 ffff8800b4fa0000 ramfs none /mnt ffff8801372de1c0 ffff8800b4fa5000 squashfs /dev/vda /home/green/git/lustre-release ffff8800b537f6c0 ffff8800b4d76800 tmpfs none /var/lib/stateless/writable ffff88012a308540 ffff8800b4d76800 tmpfs none /var/cache/man ffff8800b537fa40 ffff8800b4d76800 tmpfs none /var/log ffff88012a308700 ffff8800b4d76800 tmpfs none /var/lib/dbus ffff8800b537fc00 ffff8800b4d76800 tmpfs none /tmp ffff88012a3088c0 ffff8800b4d76800 tmpfs none /var/lib/dhclient ffff88012a339180 ffff8800b4d76800 tmpfs none /var/tmp ffff88012a339340 ffff8800b4d76800 tmpfs none /var/lib/NetworkManager ffff88012a339500 ffff8800b4d76800 tmpfs none /var/lib/systemd/random-seed ffff88012a3396c0 ffff8800b4d76800 tmpfs none /var/spool ffff88012a308a80 ffff8800b4d76800 tmpfs none /var/lib/nfs ffff88012a339880 ffff8800b4d76800 tmpfs none /var/lib/gssproxy ffff88012a308c40 ffff8800b4d76800 tmpfs none /var/lib/logrotate ffff88012a308e00 ffff8800b4d76800 tmpfs none /etc ffff88012a339a40 ffff8800b4d76800 tmpfs none /var/lib/rsyslog ffff8800b537fdc0 ffff8800b4d76800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b537e000 ffff8800b4090800 nfs4 192.168.200.253:/exports/state/oleg359-server.virtnet /var/lib/stateless/state ffff88012a339c00 ffff8800b4090800 nfs4 192.168.200.253:/exports/state/oleg359-server.virtnet /boot ffff88012a339dc0 ffff8800b4090800 nfs4 192.168.200.253:/exports/state/oleg359-server.virtnet /etc/etc/kdump.conf ffff8800b26381c0 ffff8800b6c8e000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b2638700 ffff8800b4fa5000 squashfs /dev/vda /usr/sbin/mount.lustre ffff8801372dec40 ffff88012a311000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b2639340 ffff88009a199800 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff88012e18e000 ffff880091860000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 4656.512751] Lustre: DEBUG MARKER: SKIP: sanity-sec test_59b client encryption not supported [ 4659.323275] Lustre: DEBUG MARKER: == sanity-sec test 59c: MDT migrate of encrypted files without key ========================================================== 19:18:29 (1715210309) [ 4659.875783] Lustre: DEBUG MARKER: SKIP: sanity-sec test_59c client encryption not supported [ 4662.720815] Lustre: DEBUG MARKER: == sanity-sec test 60: Subdirmount of encrypted dir ====== 19:18:32 (1715210312) [ 4663.280253] Lustre: DEBUG MARKER: SKIP: sanity-sec test_60 client encryption not supported [ 4666.091377] Lustre: DEBUG MARKER: == sanity-sec test 61: Nodemap enforces read-only mount == 19:18:36 (1715210316) [ 4667.185241] Lustre: DEBUG MARKER: oleg359-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4789.520146] Lustre: DEBUG MARKER: == sanity-sec test 62: e2fsck with encrypted files ======= 19:20:39 (1715210439) [ 4790.042814] Lustre: DEBUG MARKER: SKIP: sanity-sec test_62 skip ZFS backend [ 4792.860497] Lustre: DEBUG MARKER: == sanity-sec test 63: fid2path with encrypted files ===== 19:20:43 (1715210443) [ 4793.320593] Lustre: DEBUG MARKER: SKIP: sanity-sec test_63 client encryption not supported [ 4796.109672] Lustre: DEBUG MARKER: == sanity-sec test 64a: Nodemap enforces file_perms RBAC roles ========================================================== 19:20:46 (1715210446) [ 4928.235299] Lustre: DEBUG MARKER: == sanity-sec test 64b: Nodemap enforces dne_ops RBAC roles ========================================================== 19:22:58 (1715210578) [ 4928.747794] Lustre: DEBUG MARKER: SKIP: sanity-sec test_64b mdt count 1, skipping dne_ops role [ 4931.529387] Lustre: DEBUG MARKER: == sanity-sec test 64c: Nodemap enforces quota_ops RBAC roles ========================================================== 19:23:01 (1715210581) [ 5063.074973] Lustre: DEBUG MARKER: == sanity-sec test 64d: Nodemap enforces byfid_ops RBAC roles ========================================================== 19:25:13 (1715210713) [ 5187.545346] Lustre: ll_ost00_000: service thread pid 8529 was inactive for 40.106 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 5187.553513] Pid: 8529, comm: ll_ost00_000 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 5187.557116] Call Trace: [ 5187.558714] [<0>] ldlm_completion_ast+0x963/0xd00 [ptlrpc] [ 5187.561292] [<0>] ldlm_cli_enqueue_local+0x259/0x880 [ptlrpc] [ 5187.563891] [<0>] ofd_destroy_by_fid+0x1d1/0x520 [ofd] [ 5187.566212] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 5187.568541] [<0>] tgt_request_handle+0x74e/0x1a50 [ptlrpc] [ 5187.571054] [<0>] ptlrpc_server_handle_request+0x26c/0xcb0 [ptlrpc] [ 5187.573903] [<0>] ptlrpc_main+0xc76/0x1690 [ptlrpc] [ 5187.576144] [<0>] kthread+0xe4/0xf0 [ 5187.577778] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 5187.580066] [<0>] 0xfffffffffffffffe [ 5194.163635] Lustre: DEBUG MARKER: == sanity-sec test 64e: Nodemap enforces chlg_ops RBAC roles ========================================================== 19:27:24 (1715210844) [ 5247.577344] LustreError: 6982:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.203.59@tcp ns: filter-lustre-OST0000_UUID lock: ffff8800a74b9440/0xeed672c1a43f272c lrc: 3/0,0 mode: PR/PR res: [0x240000400:0x2e:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400010020 nid: 192.168.203.59@tcp remote: 0x1560ca3903e66615 expref: 6 pid: 16858 timeout: 5246 lvb_type: 1 [ 5263.862913] Lustre: lustre-MDD0000: changelog on [ 5265.197681] Lustre: DEBUG MARKER: sanity-sec test_64e: @@@@@@ FAIL: failed to touch /mnt/lustre/d64e.sanity-sec/f64e.sanity-sec [ 5267.143423] Lustre: lustre-MDD0000: changelog off [ 5285.673756] Lustre: lustre-OST0000: haven't heard from client b06b3508-fbac-473a-a5a6-fe7c655cd882 (at 192.168.203.59@tcp) in 33 seconds. I think it's dead, and I am evicting it. exp ffff880133097000, cur 1715210935 expire 1715210905 last 1715210902 [ 5306.966410] Lustre: DEBUG MARKER: == sanity-sec test 64f: Nodemap enforces fscrypt_admin RBAC roles ========================================================== 19:29:17 (1715210957) [ 5307.491571] Lustre: DEBUG MARKER: SKIP: sanity-sec test_64f Need enc support, skip fscrypt_admin role [ 5310.318733] Lustre: DEBUG MARKER: == sanity-sec test 65: lfs find -printf %La and --attrs support ========================================================== 19:29:20 (1715210960) [ 5310.837558] Lustre: DEBUG MARKER: SKIP: sanity-sec test_65 client encryption not supported [ 5313.644129] Lustre: DEBUG MARKER: == sanity-sec test 68: all config logs are processed ===== 19:29:23 (1715210963) ****************************************************************************** ************************ 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.30s (real) 7.01s (CPU), Child processes: 5.27s