************************ crashinfo ************************* /exports/testreports/51653/testresults/sanity2-zfs-centos7_x86_64-centos7_x86_64/oleg224-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.aotrS/vmlinux [TAINTED] DUMPFILE: /exports/testreports/51653/testresults/sanity2-zfs-centos7_x86_64-centos7_x86_64/oleg224-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed May 14 07:52:25 EDT 2025 UPTIME: 03:43:43 LOAD AVERAGE: 0.10, 0.14, 0.14 TASKS: 367 NODENAME: oleg224-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 48 last 5s 70 last 60s 82 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 363 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 ----- -------------- ------ ---------------------------- 11 rcuos/0 0 ms (no user stack) 9 rcu_sched 0 ms (no user stack) 17311 monitor_thread 0 ms (no user stack) 20547 txg_quiesce 0 ms (no user stack) 8092 kworker/1:0 2 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 639328 2.4 GB 66% of TOTAL MEM USED 315739 1.2 GB 33% of TOTAL MEM SHARED 9771 38.2 MB 1% of TOTAL MEM BUFFERS 5434 21.2 MB 0% of TOTAL MEM CACHED 77695 303.5 MB 8% of TOTAL MEM SLAB 31576 123.3 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 64530 252.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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 13420.8 eth0 n/a 0.2 RSS_TOTAL=51932 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a2fa000 ffff8800b520b800 sysfs sysfs /sys ffff88012a2fa1c0 ffff880139944000 proc proc /proc ffff88012a2fa380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a2fa540 ffff8800b51b9000 securityfs securityfs /sys/kernel/security ffff88012a2fa700 ffff8800b520c000 tmpfs tmpfs /dev/shm ffff88012a2fa8c0 ffff880137322800 devpts devpts /dev/pts ffff88012a2faa80 ffff8800b520c800 tmpfs tmpfs /run ffff88012a2fac40 ffff8800b520d000 tmpfs tmpfs /sys/fs/cgroup ffff88012a2fae00 ffff8800b520d800 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a2fafc0 ffff8800b520e000 pstore pstore /sys/fs/pstore ffff88012a2fb180 ffff88012a338000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2fb340 ffff88012a338800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a2fb500 ffff88012a339000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a2fb6c0 ffff88012a339800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a2fb880 ffff88012a33a000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a2fba40 ffff88012a33a800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a2fbc00 ffff88012a33b000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a2fbdc0 ffff88012a33b800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a336000 ffff88012a33c000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a3361c0 ffff88012a33c800 cgroup cgroup /sys/fs/cgroup/devices ffff880137013180 ffff880137326800 configfs configfs /sys/kernel/config ffff88012a337500 ffff88012a33d000 ext4 /dev/nbd0 / ffff880137013340 ffff880137327000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff880137668a80 ffff8800b4a8b800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880137668c40 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff880137012e00 ffff880137324000 mqueue mqueue /dev/mqueue ffff880137013500 ffff8800b417b800 hugetlbfs hugetlbfs /dev/hugepages ffff88012a3376c0 ffff8800b4b49000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880137668e00 ffff8800b4a88800 ramfs none /mnt ffff88012a337a40 ffff880129cb9800 squashfs /dev/vda /home/green/git/lustre-release ffff8801370136c0 ffff8800b4a9c800 tmpfs none /var/lib/stateless/writable ffff88012a337dc0 ffff8800b4a9c800 tmpfs none /var/cache/man ffff880137013880 ffff8800b4a9c800 tmpfs none /var/log ffff880137668fc0 ffff8800b4a9c800 tmpfs none /var/lib/dbus ffff8800b2410000 ffff8800b4a9c800 tmpfs none /tmp ffff880137669180 ffff8800b4a9c800 tmpfs none /var/lib/dhclient ffff880137669340 ffff8800b4a9c800 tmpfs none /var/tmp ffff880137013a40 ffff8800b4a9c800 tmpfs none /var/lib/NetworkManager ffff8800b24101c0 ffff8800b4a9c800 tmpfs none /var/lib/systemd/random-seed ffff880137013c00 ffff8800b4a9c800 tmpfs none /var/spool ffff880137013dc0 ffff8800b4a9c800 tmpfs none /var/lib/nfs ffff8800b2410380 ffff8800b4a9c800 tmpfs none /var/lib/gssproxy ffff8800b2410540 ffff8800b4a9c800 tmpfs none /var/lib/logrotate ffff880137012fc0 ffff8800b4a9c800 tmpfs none /etc ffff880137669500 ffff8800b4a9c800 tmpfs none /var/lib/rsyslog ffff8801376696c0 ffff8800b4a9c800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a376000 ffff8800b4b4f800 nfs4 192.168.200.253:/exports/state/oleg224-server.virtnet /var/lib/stateless/state ffff88012a3761c0 ffff8800b4b4f800 nfs4 192.168.200.253:/exports/state/oleg224-server.virtnet /boot ffff880138ccafc0 ffff8800b4b4f800 nfs4 192.168.200.253:/exports/state/oleg224-server.virtnet /etc/etc/kdump.conf ffff8800b2410700 ffff880137327000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b19b9340 ffff880129cb9800 squashfs /dev/vda /usr/sbin/mount.lustre ffff88012f3a7880 ffff88011893f000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 ffff88012f3a6e00 ffff8800b4179000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b5385500 ffff88009a119800 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 9683.667486] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug all all [ 9684.415579] LustreError: 20208:0:(osp_sync.c:346:osp_sync_declare_add()) logging isn't available, run LFSCK [ 9687.344892] Lustre: Failing over lustre-MDT0000 [ 9687.427381] LustreError: 20256:0:(osp_sync.c:1358:osp_sync_thread()) can't get appropriate context [ 9687.499836] Lustre: server umount lustre-MDT0000 complete [ 9696.344929] Lustre: 17314:0:(client.c:2451:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1747219801/real 1747219801] req@ffff88008f101880 x1832087991207936/t0(0) o400->lustre-MDT0000-lwp-OST0000@0@lo:12/10 lens 224/224 e 0 to 1 dl 1747219817 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 projid:4294967295 [ 9696.360217] Lustre: 17314:0:(client.c:2451:ptlrpc_expire_one_request()) Skipped 1 previous similar message [ 9699.614721] LustreError: MGC192.168.202.124@tcp: Connection to MGS (at 0@lo) was lost; in progress operations using this service will fail [ 9699.897988] Lustre: lustre-MDT0000: Imperative Recovery not enabled, recovery window 60-180 [ 9701.051663] Lustre: DEBUG MARKER: oleg224-server.virtnet: executing set_default_debug all all [ 9703.050980] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000402:59791 to 0x240000402:59841) [ 9703.052103] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000402:58614 to 0x280000402:58689) [ 9704.128721] Lustre: DEBUG MARKER: oleg224-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 9704.512286] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 9706.238443] Lustre: DEBUG MARKER: == sanity test 819a: too big niobuf in read ============== 06:50:26 (1747219826) [ 9706.639082] Lustre: *** cfs_fail_loc=248, val=0*** [ 9708.503049] Lustre: DEBUG MARKER: == sanity test 819b: too big niobuf in write ============= 06:50:28 (1747219828) [ 9708.803399] Lustre: *** cfs_fail_loc=248, val=0*** [ 9712.895986] Lustre: lustre-MDT0000-lwp-OST0001: Connection restored to (at 0@lo) [ 9712.897522] Lustre: Skipped 1 previous similar message [ 9713.062168] Lustre: DEBUG MARKER: == sanity test 820: update max EA from open intent ======= 06:50:33 (1747219833) [ 9713.481130] Lustre: DEBUG MARKER: SKIP: sanity test_820 needs >= 2 MDTs [ 9714.036289] Lustre: DEBUG MARKER: == sanity test 823: Setting create_count > OST_MAX_PRECREATE is lowered to maximum ========================================================== 06:50:34 (1747219834) [ 9715.850359] Lustre: DEBUG MARKER: setting create_count to 100200: [ 9716.257793] Lustre: DEBUG MARKER: -result- count: 9984 with max: 20000, expecting: 9984 [ 9719.112040] Lustre: DEBUG MARKER: == sanity test 831: throttling unlink/setattr queuing on OSP ========================================================== 06:50:39 (1747219839) [ 9732.108786] Lustre: 21929:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9733.114261] Lustre: 21929:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9735.138870] Lustre: 21929:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9738.368705] Lustre: 14717:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9742.612674] Lustre: 14717:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9742.615333] Lustre: 14717:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 2 previous similar messages [ 9750.807335] Lustre: 21931:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9750.812595] Lustre: 21931:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 3 previous similar messages [ 9767.275580] Lustre: 21930:0:(osp_sync.c:323:osp_sync_declare_add()) lustre-OST0000-osc-MDT0000: queued changes counter exceeds limit 101 > 100 [ 9767.278121] Lustre: 21930:0:(osp_sync.c:323:osp_sync_declare_add()) Skipped 8 previous similar messages [ 9782.189964] Lustre: DEBUG MARKER: == sanity test 832: lfs rm_entry ========================= 06:51:42 (1747219902) [ 9782.575761] Lustre: DEBUG MARKER: SKIP: sanity test_832 needs >= 2 MDTs [ 9783.043495] Lustre: DEBUG MARKER: == sanity test 833: Mixed buffered/direct read and write should not return -EIO ========================================================== 06:51:43 (1747219903) [ 9819.424894] Lustre: DEBUG MARKER: == sanity test 835: Setting read_ahead_kb explictly will be revised automatically ========================================================== 06:52:19 (1747219939) ****************************************************************************** ************************ 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.76s (real) 7.07s (CPU), Child processes: 5.66s