************************ crashinfo ************************* /exports/testreports/42551/testresults/sanity-sec-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg348-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.AsyXR/vmlinux [TAINTED] DUMPFILE: /exports/testreports/42551/testresults/sanity-sec-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg348-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 8 19:57:52 EDT 2024 UPTIME: 01:57:01 LOAD AVERAGE: 0.00, 0.01, 0.05 TASKS: 246 NODENAME: oleg348-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 18 last 5s 63 last 60s 73 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 242 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 ----- -------------- ------ ---------------------------- 8652 osp-pre-1-0 0 ms (no user stack) 3683 ptlrpcd_00_00 0 ms (no user stack) 30283 mdt_out00_003 0 ms (no user stack) 8267 mdt_out00_002 0 ms (no user stack) 3684 ptlrpcd_00_01 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 732357 2.8 GB 76% of TOTAL MEM USED 222710 870 MB 23% of TOTAL MEM SHARED 13547 52.9 MB 1% of TOTAL MEM BUFFERS 11912 46.5 MB 1% of TOTAL MEM CACHED 73373 286.6 MB 7% of TOTAL MEM SLAB 16230 63.4 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 65446 255.6 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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 7019.0 eth0 n/a 1.3 RSS_TOTAL=50976 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a33e000 ffff880137181000 sysfs sysfs /sys ffff88012a33e1c0 ffff880139944000 proc proc /proc ffff88012a33e380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a33e540 ffff8800b5185000 securityfs securityfs /sys/kernel/security ffff88012a33e700 ffff880137181800 tmpfs tmpfs /dev/shm ffff88012a33e8c0 ffff88013771f000 devpts devpts /dev/pts ffff88012a33ea80 ffff880137182000 tmpfs tmpfs /run ffff88012a33ec40 ffff880137182800 tmpfs tmpfs /sys/fs/cgroup ffff88012a33ee00 ffff880137183000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a33efc0 ffff880137183800 pstore pstore /sys/fs/pstore ffff88012a33f180 ffff880137185800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a33f340 ffff880137185000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a33f500 ffff880137184800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a33f6c0 ffff880137184000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a33f880 ffff880137186000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a33fa40 ffff880137186800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a33fc00 ffff880137187000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a33fdc0 ffff880137187800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a342000 ffff88012a378000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a3421c0 ffff88012a378800 cgroup cgroup /sys/fs/cgroup/freezer ffff880137012540 ffff8800b51be800 configfs configfs /sys/kernel/config ffff880138ccba40 ffff8800b4b3a000 ext4 /dev/nbd0 / ffff88012a3436c0 ffff8800b5187000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff880137012c40 ffff88012a37d800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a343880 ffff8800b4b4b800 hugetlbfs hugetlbfs /dev/hugepages ffff880137012e00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137012fc0 ffff88012b2b8800 mqueue mqueue /dev/mqueue ffff88012a343a40 ffff8800b4b3e800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880137013180 ffff88012a379000 ramfs none /mnt ffff88012a343dc0 ffff88012e554000 tmpfs none /var/lib/stateless/writable ffff880137013340 ffff880129cb1800 squashfs /dev/vda /home/green/git/lustre-release ffff880137668540 ffff88012e554000 tmpfs none /var/cache/man ffff880137668700 ffff88012e554000 tmpfs none /var/log ffff8801376688c0 ffff88012e554000 tmpfs none /var/lib/dbus ffff8800b276c000 ffff88012e554000 tmpfs none /tmp ffff8800b276c1c0 ffff88012e554000 tmpfs none /var/lib/dhclient ffff880137668a80 ffff88012e554000 tmpfs none /var/tmp ffff880137668c40 ffff88012e554000 tmpfs none /var/lib/NetworkManager ffff880137668e00 ffff88012e554000 tmpfs none /var/lib/systemd/random-seed ffff880137668fc0 ffff88012e554000 tmpfs none /var/spool ffff880138ccb880 ffff88012e554000 tmpfs none /var/lib/nfs ffff880137669180 ffff88012e554000 tmpfs none /var/lib/gssproxy ffff880138ccbc00 ffff88012e554000 tmpfs none /var/lib/logrotate ffff8800b276c380 ffff88012e554000 tmpfs none /etc ffff8800b276c540 ffff88012e554000 tmpfs none /var/lib/rsyslog ffff880137669340 ffff88012e554000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff880137669500 ffff88012e551800 nfs4 192.168.200.253:/exports/state/oleg348-server.virtnet /var/lib/stateless/state ffff8800b276c700 ffff88012e551800 nfs4 192.168.200.253:/exports/state/oleg348-server.virtnet /boot ffff880137669880 ffff88012e551800 nfs4 192.168.200.253:/exports/state/oleg348-server.virtnet /etc/etc/kdump.conf ffff8800b276c8c0 ffff8800b5187000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800ad445c00 ffff880129cb1800 squashfs /dev/vda /usr/sbin/mount.lustre ffff88012e5cc1c0 ffff8800b1ed1000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff88012e5cddc0 ffff8800a0587800 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff88012e5cc380 ffff88009e036000 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff88012e5cd180 ffff88009c8ea000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 4362.276717] Lustre: DEBUG MARKER: SKIP: sanity-sec test_60 client encryption not supported [ 4365.074637] Lustre: DEBUG MARKER: == sanity-sec test 61: Nodemap enforces read-only mount == 19:13:34 (1715210014) [ 4366.191075] Lustre: DEBUG MARKER: oleg348-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0000.recovery_status 1475 [ 4366.982115] Lustre: DEBUG MARKER: oleg348-server.virtnet: executing _wait_recovery_complete *.lustre-MDT0001.recovery_status 1475 [ 4489.646488] Lustre: DEBUG MARKER: == sanity-sec test 62: e2fsck with encrypted files ======= 19:15:38 (1715210138) [ 4490.211871] Lustre: DEBUG MARKER: SKIP: sanity-sec test_62 client encryption not supported [ 4492.869857] Lustre: DEBUG MARKER: == sanity-sec test 63: fid2path with encrypted files ===== 19:15:41 (1715210141) [ 4493.398805] Lustre: DEBUG MARKER: SKIP: sanity-sec test_63 client encryption not supported [ 4496.222576] Lustre: DEBUG MARKER: == sanity-sec test 64a: Nodemap enforces file_perms RBAC roles ========================================================== 19:15:45 (1715210145) [ 4627.522467] Lustre: DEBUG MARKER: == sanity-sec test 64b: Nodemap enforces dne_ops RBAC roles ========================================================== 19:17:56 (1715210276) [ 4758.863712] Lustre: DEBUG MARKER: == sanity-sec test 64c: Nodemap enforces quota_ops RBAC roles ========================================================== 19:20:07 (1715210407) [ 4889.220068] Lustre: DEBUG MARKER: == sanity-sec test 64d: Nodemap enforces byfid_ops RBAC roles ========================================================== 19:22:18 (1715210538) [ 5014.222506] Lustre: ll_ost00_003: service thread pid 9948 was inactive for 40.014 seconds. The thread might be hung, or it might only be slow and will resume later. Dumping the stack trace for debugging purposes: [ 5014.231083] Pid: 9948, comm: ll_ost00_003 3.10.0-7.9-debug #1 SMP Sat Mar 26 23:28:42 EDT 2022 [ 5014.234908] Call Trace: [ 5014.236397] [<0>] ldlm_completion_ast+0x963/0xd00 [ptlrpc] [ 5014.238931] [<0>] ldlm_cli_enqueue_local+0x259/0x880 [ptlrpc] [ 5014.241403] [<0>] ofd_destroy_by_fid+0x1d1/0x520 [ofd] [ 5014.243757] [<0>] ofd_destroy_hdl+0x20c/0xae0 [ofd] [ 5014.246120] [<0>] tgt_request_handle+0x74e/0x1a50 [ptlrpc] [ 5014.248642] [<0>] ptlrpc_server_handle_request+0x26c/0xcb0 [ptlrpc] [ 5014.251564] [<0>] ptlrpc_main+0xc76/0x1690 [ptlrpc] [ 5014.253951] [<0>] kthread+0xe4/0xf0 [ 5014.255696] [<0>] ret_from_fork_nospec_begin+0x7/0x21 [ 5014.258014] [<0>] 0xfffffffffffffffe [ 5019.421654] Lustre: DEBUG MARKER: == sanity-sec test 64e: Nodemap enforces chlg_ops RBAC roles ========================================================== 19:24:28 (1715210668) [ 5074.382596] LustreError: 7113:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.203.48@tcp ns: filter-lustre-OST0000_UUID lock: ffff880095b6cb40/0xb43a46c7f9825e2 lrc: 3/0,0 mode: PR/PR res: [0x280000400:0x17:0x0].0x0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) gid 0 flags: 0x60000400010020 nid: 192.168.203.48@tcp remote: 0x7d289af49b3057ea expref: 8 pid: 9951 timeout: 5073 lvb_type: 1 [ 5089.165171] Lustre: lustre-MDD0000: changelog on [ 5090.130706] Lustre: lustre-MDD0001: changelog on [ 5109.854704] Lustre: lustre-OST0000: haven't heard from client 1b36f519-86e9-4128-a298-f090ce9725ff (at 192.168.203.48@tcp) in 32 seconds. I think it's dead, and I am evicting it. exp ffff88013085e800, cur 1715210760 expire 1715210730 last 1715210728 [ 5114.307901] Lustre: DEBUG MARKER: sanity-sec test_64e: @@@@@@ FAIL: failed to touch /mnt/lustre/d64e.sanity-sec/f64e.sanity-sec [ 5116.364170] Lustre: DEBUG MARKER: sanity-sec test_64e: @@@@@@ FAIL: lustre-MDT0001: changelog_clear cl2 0 fail: 0 [ 5117.762212] Lustre: lustre-MDD0001: changelog off [ 5118.922848] Lustre: DEBUG MARKER: sanity-sec test_64e: @@@@@@ FAIL: lustre-MDT0000: changelog_clear cl2 0 fail: 0 [ 5120.285099] Lustre: lustre-MDD0000: changelog off [ 5157.757658] Lustre: DEBUG MARKER: == sanity-sec test 64f: Nodemap enforces fscrypt_admin RBAC roles ========================================================== 19:26:46 (1715210806) [ 5158.307769] Lustre: DEBUG MARKER: SKIP: sanity-sec test_64f Need enc support, skip fscrypt_admin role [ 5161.129302] Lustre: DEBUG MARKER: == sanity-sec test 65: lfs find -printf %La and --attrs support ========================================================== 19:26:50 (1715210810) [ 5161.674554] Lustre: DEBUG MARKER: SKIP: sanity-sec test_65 client encryption not supported [ 5164.375631] Lustre: DEBUG MARKER: == sanity-sec test 68: all config logs are processed ===== 19:26:53 (1715210813) ****************************************************************************** ************************ 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.02s (CPU), Child processes: 5.24s