************************ crashinfo ************************* /exports/testreports/47845/testresults/sanity-benchmark-special9-zfs-DNE-centos7_x86_64-centos7_x86_64/oleg113-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.LktxA/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47845/testresults/sanity-benchmark-special9-zfs-DNE-centos7_x86_64-centos7_x86_64/oleg113-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Thu Dec 12 10:09:09 EST 2024 UPTIME: 00:06:56 LOAD AVERAGE: 5.73, 4.28, 1.98 TASKS: 452 NODENAME: oleg113-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_write_msr_safe+0xa, 449 bytes of data #0 __x2apic_send_IPI_mask+0xb2 #1 x2apic_send_IPI_mask+0x13 #2 native_smp_send_reschedule+0x4c #3 resched_curr+0xd8 #4 check_preempt_curr+0x80 #5 ttwu_do_wakeup+0x19 #6 ttwu_do_activate+0x6f #7 try_to_wake_up+0x152 #8 default_wake_function+0x12 #9 autoremove_wake_function+0x18 #10 __wake_up_common+0x70 #11 __wake_up_common_lock+0x83 #12 __wake_up+0x13 #13 ksocknal_read_callback+0x67 #14 ksocknal_data_ready+0x44 #15 tcp_rcv_established+0x444 #16 tcp_v4_do_rcv+0x10a #17 tcp_v4_rcv+0x7ff #18 ip_local_deliver_finish+0xc8 #19 ip_local_deliver+0x60 #20 ip_rcv_finish+0x8a #21 ip_rcv+0x2bd #22 __netif_receive_skb_core+0x714 #23 __netif_receive_skb+0x18 #24 netif_receive_skb_internal+0x50 #25 napi_gro_receive+0xf8 #26 virtnet_poll+0x265 #27 net_rx_action+0x28b #28 __do_softirq+0xf7 #29 call_softirq+0x1c #30 do_softirq+0x65 #31 irq_exit+0x105 #32 do_IRQ+0x56, 19 bytes of data #33 ret_from_intr+0x0 #-1 native_safe_halt+0xb, 477 bytes of data #34 default_idle+0x1e #35 default_enter_idle+0x45 #36 cpuidle_enter_state+0x40 #37 cpuidle_idle_call+0xd8 #38 arch_cpu_idle+0xe #39 cpu_startup_entry+0x14a #40 rest_init+0x8e #41 start_kernel+0x456 #42 x86_64_start_reservations+0x2a #43 x86_64_start_kernel+0x152 #44 start_cpu+0x5 -- CPU#1 -- PID=0 CPU=1 CMD=swapper/1 #-1 __pv_queued_spin_lock_slowpath+0x102, 449 bytes of data #0 do_raw_spin_lock+0x6d #1 _raw_spin_lock_irq+0x25 #2 __schedule+0xae #3 schedule_preempt_disabled+0x39 #4 cpu_startup_entry+0x18a #5 start_secondary+0x1eb #6 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=3511 CPU=3 CMD=socknal_sd00_02 #-1 __pv_queued_spin_lock_slowpath+0x102, 449 bytes of data #0 do_raw_spin_lock+0x6d #1 _raw_spin_lock_irqsave+0x30 #2 prepare_to_wait_exclusive+0x27 #3 ksocknal_scheduler+0x9a0 #4 kthread+0xe4 #5 ret_from_fork_nospec_begin+0x7 +--------------------------------+ >---------------------| How This Dump Has Been Created |---------------------< +--------------------------------+ Cannot identify the specific condition that triggered vmcore +---------------+ >------------------------------| Tasks Summary |------------------------------< +---------------+ Number of Threads That Ran Recently ----------------------------------- last second 63 last 5s 144 last 60s 157 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 442 TASK_RUNNING 3 TASK_UNINTERRUPTIBLE 3 TASK_WAKEKILL 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 ----- -------------- ------ ---------------------------- 3511 socknal_sd00_02 0 ms (no user stack) 3510 socknal_sd00_01 0 ms (no user stack) 17494 ll_ost_io00_005 0 ms (no user stack) 3509 socknal_sd00_00 1 ms (no user stack) 9 rcu_sched 3 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 212191 828.9 MB 22% of TOTAL MEM USED 742876 2.8 GB 77% of TOTAL MEM SHARED 10804 42.2 MB 1% of TOTAL MEM BUFFERS 5120 20 MB 0% of TOTAL MEM CACHED 69493 271.5 MB 7% of TOTAL MEM SLAB 23629 92.3 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 57950 226.4 MB 7% of TOTAL LIMIT +-------------------------------+ >----------------------| Scheduler Runqueues (per CPU) |----------------------< +-------------------------------+ ---+ CPU=0 ---- | CURRENT TASK , CMD=swapper/0 17947 ll_ost_io00_011 1.20192 ---+ CPU=1 ---- | CURRENT TASK , CMD=swapper/1 3509 socknal_sd00_00 16.11400 ---+ CPU=2 ---- | CURRENT TASK , CMD=swapper/2 ---+ CPU=3 ---- | CURRENT TASK , CMD=socknal_sd00_02 +------------------------+ >-------------------------| 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 -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 410.7 eth0 n/a 0.0 RSS_TOTAL=53240 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff8801376688c0 ffff8800b51f0000 sysfs sysfs /sys ffff880137668a80 ffff880139944000 proc proc /proc ffff880137668c40 ffff880137678000 devtmpfs devtmpfs /dev ffff880137668e00 ffff88012abfe000 securityfs securityfs /sys/kernel/security ffff880137668fc0 ffff8800b51f0800 tmpfs tmpfs /dev/shm ffff880137669180 ffff880137679000 devpts devpts /dev/pts ffff880137669340 ffff8800b51f1000 tmpfs tmpfs /run ffff880137669500 ffff8800b51f1800 tmpfs tmpfs /sys/fs/cgroup ffff8801376696c0 ffff8800b51f2000 cgroup cgroup /sys/fs/cgroup/systemd ffff880137669880 ffff8800b51f2800 pstore pstore /sys/fs/pstore ffff880138ccae00 ffff88012abfe800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880138ccafc0 ffff88012abff000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880138ccb180 ffff88012abff800 cgroup cgroup /sys/fs/cgroup/perf_event ffff880138ccb340 ffff88012a358000 cgroup cgroup /sys/fs/cgroup/memory ffff880138ccb500 ffff88012a358800 cgroup cgroup /sys/fs/cgroup/devices ffff880137669a40 ffff8800b51f4800 cgroup cgroup /sys/fs/cgroup/pids ffff880137669c00 ffff8800b51f4000 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137669dc0 ffff8800b51f3800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a322000 ffff8800b51f3000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a3221c0 ffff8800b51f5000 cgroup cgroup /sys/fs/cgroup/blkio ffff8801370b68c0 ffff8800b524d800 configfs configfs /sys/kernel/config ffff880138ccb6c0 ffff880129fcf000 ext4 /dev/nbd0 / ffff8801370b6e00 ffff88012a38c000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8801370b7500 ffff8801373f5800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff8801370b76c0 ffff8801377a7800 mqueue mqueue /dev/mqueue ffff88012a323500 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012a3236c0 ffff8800b4241800 hugetlbfs hugetlbfs /dev/hugepages ffff88012a323880 ffff8800b4240800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8801370b7880 ffff8801373f0800 ramfs none /mnt ffff8801370b7a40 ffff88012a359800 tmpfs none /var/lib/stateless/writable ffff8801370b7c00 ffff88012a35a800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a323c00 ffff88012a359800 tmpfs none /var/cache/man ffff880138ccb880 ffff88012a359800 tmpfs none /var/log ffff8801370b7dc0 ffff88012a359800 tmpfs none /var/lib/dbus ffff880138ccba40 ffff88012a359800 tmpfs none /tmp ffff8801370b7340 ffff88012a359800 tmpfs none /var/lib/dhclient ffff88012a323dc0 ffff88012a359800 tmpfs none /var/tmp ffff88012b80e000 ffff88012a359800 tmpfs none /var/lib/NetworkManager ffff88012b80e1c0 ffff88012a359800 tmpfs none /var/lib/systemd/random-seed ffff880138ccbc00 ffff88012a359800 tmpfs none /var/spool ffff880138ccbdc0 ffff88012a359800 tmpfs none /var/lib/nfs ffff88012b80e380 ffff88012a359800 tmpfs none /var/lib/gssproxy ffff88012b80e540 ffff88012a359800 tmpfs none /var/lib/logrotate ffff88012b80e700 ffff88012a359800 tmpfs none /etc ffff8801370b6540 ffff88012a359800 tmpfs none /var/lib/rsyslog ffff88012b80e8c0 ffff88012a359800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b54be000 ffff8800b4d04000 nfs4 192.168.200.253:/exports/state/oleg113-server.virtnet /var/lib/stateless/state ffff8801370b6fc0 ffff8800b4d04000 nfs4 192.168.200.253:/exports/state/oleg113-server.virtnet /boot ffff88013701c380 ffff8800b4d04000 nfs4 192.168.200.253:/exports/state/oleg113-server.virtnet /etc/etc/kdump.conf ffff88013701c540 ffff88012a38c000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b18b7880 ffff88012a35a800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b54bea80 ffff8800b1a82000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b54bf180 ffff88009a148800 lustre lustre-mdt2/mdt2 /mnt/lustre-mds2 ffff8800b218bc00 ffff88009a33f800 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff8800b218b180 ffff880135ff0000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 90.033279] Lustre: Modifying parameter lustre-MDT0001.mdt.identity_upcall in log lustre-MDT0001 [ 90.059459] Lustre: srv-lustre-MDT0001: No data found on store. Initialize space. [ 90.062168] Lustre: Skipped 1 previous similar message [ 90.099543] Lustre: lustre-MDT0001: new disk, initializing [ 90.197331] Lustre: lustre-MDT0001: Imperative Recovery not enabled, recovery window 60-180 [ 90.219563] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:1:mdt [ 90.224558] Lustre: cli-ctl-lustre-MDT0001: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:1:mdt] [ 91.123531] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 93.200112] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 94.698586] Lustre: lustre-OST0000: new disk, initializing [ 94.700843] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 94.728410] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 96.263173] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 99.825077] Lustre: lustre-OST0001: new disk, initializing [ 99.827151] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 99.858561] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 101.240111] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 102.925163] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:0:ost [ 102.933009] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:0:ost] [ 102.988416] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x280000401 [ 102.998860] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x2c0000401 [ 106.115871] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 109.227531] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 115.505501] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing check_logdir /tmp/testlogs/ [ 116.507174] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing yml_node [ 118.200459] Lustre: DEBUG MARKER: Client: 2.16.0.RC5 [ 119.181969] Lustre: DEBUG MARKER: MDS: 2.16.0.RC5 [ 120.027236] Lustre: DEBUG MARKER: OSS: 2.16.0.RC5 [ 120.562781] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-benchmark ============----- Thu Dec 12 10:04:10 EST 2024 [ 126.126845] Lustre: DEBUG MARKER: excepting tests: [ 126.770073] Lustre: DEBUG MARKER: skipping tests SLOW=no: iozone [ 127.385601] Lustre: DEBUG MARKER: === sanity-benchmark: start setup 10:04:17 (1734015857) === [ 129.109955] Lustre: DEBUG MARKER: oleg113-client.virtnet: executing check_config_client /mnt/lustre [ 139.447796] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 141.434896] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 142.916640] Lustre: DEBUG MARKER: oleg113-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 144.958815] Lustre: DEBUG MARKER: === sanity-benchmark: finish setup 10:04:34 (1734015874) === [ 145.996537] Lustre: DEBUG MARKER: == sanity-benchmark test dbench: dbench ================== 10:04:35 (1734015875) [ 307.234602] Lustre: DEBUG MARKER: == sanity-benchmark test bonnie: bonnie++ ================ 10:07:16 (1734016036) [ 308.522408] Lustre: DEBUG MARKER: min OST has 3723264kB available, using 5584896kB file size ****************************************************************************** ************************ 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.58s (real) 7.17s (CPU), Child processes: 5.37s