************************ crashinfo ************************* /exports/testreports/51653/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg246-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.Y4E3W/vmlinux [TAINTED] DUMPFILE: /exports/testreports/51653/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg246-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 14 08:17:13 EDT 2025 UPTIME: 04:08:32 LOAD AVERAGE: 0.17, 0.13, 0.14 TASKS: 268 NODENAME: oleg246-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 67 last 5s 80 last 60s 89 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 264 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 ----- -------------- ------ ---------------------------- 1980 kworker/0:2 0 ms (no user stack) 26101 kworker/1:0 0 ms (no user stack) 415 kworker/3:1 0 ms (no user stack) 28746 kworker/2:0 0 ms (no user stack) 8329 lnet_discovery 34 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 164686 643.3 MB 17% of TOTAL MEM USED 790381 3 GB 82% of TOTAL MEM SHARED 12165 47.5 MB 1% of TOTAL MEM BUFFERS 8141 31.8 MB 0% of TOTAL MEM CACHED 613814 2.3 GB 64% of TOTAL MEM SLAB 37648 147.1 MB 3% 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 65554 256.1 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 Unusual Situations: Doing Retransmission: 1 (run xportshow --retrans for details) 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 14909.2 eth0 n/a 0.1 RSS_TOTAL=50180 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137012c40 ffff8800b7e61800 sysfs sysfs /sys ffff880137012e00 ffff880139944000 proc proc /proc ffff880137012fc0 ffff880137678000 devtmpfs devtmpfs /dev ffff880137013180 ffff8800b51ee000 securityfs securityfs /sys/kernel/security ffff880137013340 ffff8800b7e62000 tmpfs tmpfs /dev/shm ffff880137013500 ffff88013702d800 devpts devpts /dev/pts ffff8801370136c0 ffff8800b7e62800 tmpfs tmpfs /run ffff880137013880 ffff8800b7e63000 tmpfs tmpfs /sys/fs/cgroup ffff880137013a40 ffff8800b7e63800 cgroup cgroup /sys/fs/cgroup/systemd ffff880137013c00 ffff8800b7e64000 pstore pstore /sys/fs/pstore ffff880137013dc0 ffff8800b7e66000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a24e000 ffff8800b7e65800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a24e1c0 ffff8800b7e65000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a24e380 ffff8800b7e64800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a24e540 ffff8800b7e66800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a24e700 ffff8800b7e67000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a24e8c0 ffff8800b7e67800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a24ea80 ffff88012a318000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a24ec40 ffff88012a318800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a24ee00 ffff88012a319000 cgroup cgroup /sys/fs/cgroup/pids ffff8800b4e02000 ffff8800b4c3e800 configfs configfs /sys/kernel/config ffff880138ccae00 ffff8800b4d7f800 ext4 /dev/nbd0 / ffff880138ccafc0 ffff88012a31c800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012a24f340 ffff8800b4193800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880138ccb180 ffff88013702f000 mqueue mqueue /dev/mqueue ffff88012a24f500 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b4e03880 ffff880129e82000 hugetlbfs hugetlbfs /dev/hugepages ffff88012a24f6c0 ffff8800b421c800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b4e036c0 ffff880129e84000 ramfs none /mnt ffff880137668700 ffff8800b43d5800 tmpfs none /var/lib/stateless/writable ffff8801376688c0 ffff8800b43d0800 squashfs /dev/vda /home/green/git/lustre-release ffff8800b4e03a40 ffff8800b43d5800 tmpfs none /var/cache/man ffff88012a24fa40 ffff8800b43d5800 tmpfs none /var/log ffff88012a24fc00 ffff8800b43d5800 tmpfs none /var/lib/dbus ffff88012a24fdc0 ffff8800b43d5800 tmpfs none /tmp ffff880138ccb340 ffff8800b43d5800 tmpfs none /var/lib/dhclient ffff88012a24efc0 ffff8800b43d5800 tmpfs none /var/tmp ffff880137668a80 ffff8800b43d5800 tmpfs none /var/lib/NetworkManager ffff880137668c40 ffff8800b43d5800 tmpfs none /var/lib/systemd/random-seed ffff880137668e00 ffff8800b43d5800 tmpfs none /var/spool ffff880138ccb500 ffff8800b43d5800 tmpfs none /var/lib/nfs ffff880138ccb6c0 ffff8800b43d5800 tmpfs none /var/lib/gssproxy ffff880138ccb880 ffff8800b43d5800 tmpfs none /var/lib/logrotate ffff880137668fc0 ffff8800b43d5800 tmpfs none /etc ffff880137669180 ffff8800b43d5800 tmpfs none /var/lib/rsyslog ffff880137669340 ffff8800b43d5800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b3bf4000 ffff88012c543800 nfs4 192.168.200.253:/exports/state/oleg246-server.virtnet /var/lib/stateless/state ffff8800b3bf4380 ffff88012c543800 nfs4 192.168.200.253:/exports/state/oleg246-server.virtnet /boot ffff8800b3bf4540 ffff88012c543800 nfs4 192.168.200.253:/exports/state/oleg246-server.virtnet /etc/etc/kdump.conf ffff880137669500 ffff88012a31c800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b3bf5c00 ffff8800b43d0800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b403dc00 ffff880135e67000 lustre /dev/mapper/mds2_flakey /mnt/lustre-mds2 ffff880136b23880 ffff88012ff18000 lustre /dev/mapper/mds1_flakey /mnt/lustre-mds1 ffff8800b403d6c0 ffff88009a31f000 lustre /dev/mapper/ost1_flakey /mnt/lustre-ost1 ffff8800b403d180 ffff880098588000 lustre /dev/mapper/ost2_flakey /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [11156.132555] Lustre: *** cfs_fail_loc=248, val=0*** [11158.828395] Lustre: DEBUG MARKER: == sanity test 819b: too big niobuf in write ============= 07:14:38 (1747221278) [11159.228623] Lustre: *** cfs_fail_loc=248, val=0*** [11159.234990] LustreError: 16453:0:(sec.c:2692:sptlrpc_svc_unwrap_bulk()) @@@ truncated bulk GET 1048576(1052672) req@ffff8801368f4000 x1832088233447680/t0(0) o4->41506f39-a01a-4bea-a0be-89e81b52ad31@192.168.202.46@tcp:290/0 lens 488/448 e 0 to 0 dl 1747221290 ref 1 fl Interpret:/600/0 rc 0/0 job:'dd.0' uid:0 gid:0 projid:0 [11159.242170] Lustre: lustre-OST0001: Bulk IO write error with 41506f39-a01a-4bea-a0be-89e81b52ad31 (at 192.168.202.46@tcp), client will retry: rc = -110 [11175.708900] Lustre: lustre-OST0001: Client 41506f39-a01a-4bea-a0be-89e81b52ad31 (at 192.168.202.46@tcp) reconnecting [11179.422383] Lustre: DEBUG MARKER: == sanity test 820: update max EA from open intent ======= 07:14:59 (1747221299) [11180.448204] Lustre: Failing over lustre-OST0000 [11180.607620] Lustre: server umount lustre-OST0000 complete [11181.438472] LustreError: lustre-OST0000-osc-MDT0001: operation ost_statfs to node 0@lo failed: rc = -107 [11181.988105] Lustre: Failing over lustre-OST0001 [11182.264664] Lustre: server umount lustre-OST0001 complete [11190.781836] LDISKFS-fs (dm-2): file extents enabled, maximum tree depth=5 [11190.787390] LDISKFS-fs (dm-2): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11190.881268] Lustre: 19964:0:(mgc_request_server.c:550:mgc_llog_local_copy()) MGC192.168.202.146@tcp: no remote llog for lustre-sptlrpc, check MGS config [11192.789680] Lustre: DEBUG MARKER: oleg246-server.virtnet: executing set_default_debug all all [11193.174799] Lustre: lustre-OST0000: Denying connection for new client cd4a0111-bec3-465d-a56d-0f79d06f0040 (at 192.168.202.46@tcp), waiting for 2 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:59 [11195.895712] LDISKFS-fs (dm-3): file extents enabled, maximum tree depth=5 [11195.901547] LDISKFS-fs (dm-3): mounted filesystem with ordered data mode. Opts: user_xattr,acl,no_mbcache,nodelalloc [11197.854547] Lustre: DEBUG MARKER: oleg246-server.virtnet: executing set_default_debug all all [11198.180984] Lustre: lustre-OST0000: Denying connection for new client cd4a0111-bec3-465d-a56d-0f79d06f0040 (at 192.168.202.46@tcp), waiting for 2 known clients (0 recovered, 0 in progress, and 0 evicted) to recover in 0:54 [11199.927415] Lustre: DEBUG MARKER: == sanity test 823: Setting create_count > OST_MAX_PRECREATE is lowered to maximum ========================================================== 07:15:19 (1747221319) [11202.102267] Lustre: DEBUG MARKER: setting create_count to 100200: [11202.493815] Lustre: DEBUG MARKER: -result- count: 9984 with max: 20000, expecting: 9984 [11202.700667] Lustre: 8332:0:(client.c:2451:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1747221307/real 1747221307] req@ffff880099845c00 x1832088055133824/t0(0) o400->lustre-OST0001-osc-MDT0000@0@lo:28/4 lens 224/224 e 0 to 1 dl 1747221323 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [11202.708064] Lustre: 8332:0:(client.c:2451:ptlrpc_expire_one_request()) Skipped 1 previous similar message [11205.585234] Lustre: DEBUG MARKER: == sanity test 831: throttling unlink/setattr queuing on OSP ========================================================== 07:15:25 (1747221325) [11213.122917] Lustre: 2354:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11214.128219] Lustre: 21775:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11216.149817] Lustre: 21775:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11219.160738] Lustre: 21775:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11223.424839] Lustre: 2704:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11223.431145] Lustre: 2704:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 2 previous similar messages [11231.695108] Lustre: 15405:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11231.701527] Lustre: 15405:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 3 previous similar messages [11248.494064] Lustre: 23661:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [11248.500873] Lustre: 23661:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 8 previous similar messages [11268.738737] Lustre: DEBUG MARKER: == sanity test 832: lfs rm_entry ========================= 07:16:28 (1747221388) [11271.419428] Lustre: DEBUG MARKER: == sanity test 833: Mixed buffered/direct read and write should not return -EIO ========================================================== 07:16:31 (1747221391) [11306.684293] Lustre: DEBUG MARKER: == sanity test 835: Setting read_ahead_kb explictly will be revised automatically ========================================================== 07:17:06 (1747221426) ****************************************************************************** ************************ 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.35s (real) 6.49s (CPU), Child processes: 5.80s