************************ crashinfo ************************* /exports/testreports/47845/testresults/sanity-benchmark-special4-zfs-centos7_x86_64-centos7_x86_64/oleg107-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.epRzd/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47845/testresults/sanity-benchmark-special4-zfs-centos7_x86_64-centos7_x86_64/oleg107-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Thu Dec 12 10:09:09 EST 2024 UPTIME: 00:06:55 LOAD AVERAGE: 6.99, 4.77, 2.20 TASKS: 382 NODENAME: oleg107-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=8444 CPU=0 CMD=ll_ost_io00_002 #-1 pvclock_clocksource_read+0x1f, 449 bytes of data #0 kvm_clock_read+0x33 #1 kvm_clock_get_cycles+0x9 #2 ktime_get+0x4c #3 clockevents_program_event+0x39 #4 tick_program_event+0x23 #5 hrtimer_interrupt+0xf5 #6 local_apic_timer_interrupt+0x35 #7 smp_apic_timer_interrupt+0x3d #8 apic_timer_interrupt+0x16a, 19 bytes of data #9 apic_timer_interrupt+0x16a #-1 la_from_obdo+0x53, 477 bytes of data #10 ofd_preprw+0x40a #11 tgt_brw_write+0xa06 #12 tgt_request_handle+0x74e #13 ptlrpc_server_handle_request+0x281 #14 ptlrpc_main+0xc7e #15 kthread+0xe4 #16 ret_from_fork_nospec_begin+0x7 -- CPU#1 -- PID=0 CPU=1 CMD=swapper/1 #-1 poll_idle+0x92, 449 bytes of data #0 cpuidle_enter_state+0x40 #1 cpuidle_idle_call+0xd8 #2 arch_cpu_idle+0xe #3 cpu_startup_entry+0x14a #4 start_secondary+0x1eb #5 start_cpu+0x5 -- CPU#2 -- PID=9410 CPU=2 CMD=dp_sync_taskq #-1 dbuf_sync_leaf+0x117, 449 bytes of data #0 dbuf_sync_list+0x95 #1 dbuf_sync_indirect+0xed #2 dbuf_sync_list+0x76 #3 dbuf_sync_indirect+0xed #4 dbuf_sync_list+0x76 #5 dnode_sync+0x3f6 #6 sync_dnodes_task+0x7d #7 taskq_thread+0x2c9 #8 kthread+0xe4 #9 ret_from_fork_nospec_begin+0x7 -- CPU#3 -- PID=9389 CPU=3 CMD=z_wr_iss #-1 ktime_get_update_offsets_now+0xd5, 449 bytes of data #0 hrtimer_interrupt+0x85 #1 local_apic_timer_interrupt+0x35 #2 smp_apic_timer_interrupt+0x3d #3 apic_timer_interrupt+0x16a, 19 bytes of data #4 apic_timer_interrupt+0x16a #-1 memcpy+0x6, 477 bytes of data #5 abd_copy_from_buf_off_cb+0x1d #6 abd_iterate_func+0xe1 #7 abd_copy_from_buf_off+0x3e #8 arc_write_ready+0x2fa #9 zio_ready+0x60 #10 zio_execute+0x99 #11 taskq_thread+0x2c9 #12 kthread+0xe4 #13 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 69 last 5s 123 last 60s 147 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 356 TASK_RUNNING 17 TASK_UNINTERRUPTIBLE 6 +++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 ----- -------------- ------ ---------------------------- 9410 dp_sync_taskq 0 ms (no user stack) 14926 ll_ost_io00_003 0 ms (no user stack) 15087 ll_ost_io00_014 0 ms (no user stack) 3297 socknal_sd00_01 0 ms (no user stack) 34 rcuos/3 0 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 242259 946.3 MB 25% of TOTAL MEM USED 712808 2.7 GB 74% of TOTAL MEM SHARED 10661 41.6 MB 1% of TOTAL MEM BUFFERS 5120 20 MB 0% of TOTAL MEM CACHED 69491 271.4 MB 7% of TOTAL MEM SLAB 20392 79.7 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 57957 226.4 MB 7% of TOTAL LIMIT +-------------------------------+ >----------------------| Scheduler Runqueues (per CPU) |----------------------< +-------------------------------+ ---+ CPU=0 ---- | CURRENT TASK , CMD=ll_ost_io00_002 14941 ll_ost_io00_009 1.67231 8072 z_rd_int 0.60025 8443 ll_ost_io00_001 1.55731 8442 ll_ost_io00_000 0.90630 27633 ll_ost_io00_019 0.55917 15088 ll_ost_io00_015 0.88937 14939 ll_ost_io00_007 1.47875 14927 ll_ost_io00_004 0.66063 14945 ll_ost_io00_011 0.85895 3296 socknal_sd00_00 18.73539 14940 ll_ost_io00_008 1.42386 ---+ CPU=1 ---- | CURRENT TASK , CMD=swapper/1 3298 socknal_sd00_02 18.75452 ---+ CPU=2 ---- | CURRENT TASK , CMD=dp_sync_taskq ---+ CPU=3 ---- | CURRENT TASK , CMD=z_wr_iss 3490 spl_dynamic_tas 5.71164 +------------------------+ >-------------------------| 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.5 eth0 n/a 0.0 RSS_TOTAL=52608 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff8801370001c0 ffff8800b7e9e800 sysfs sysfs /sys ffff880137000380 ffff880139944000 proc proc /proc ffff880137000540 ffff880137678000 devtmpfs devtmpfs /dev ffff880137000700 ffff8800b5555800 securityfs securityfs /sys/kernel/security ffff8801370008c0 ffff8800b7e9f000 tmpfs tmpfs /dev/shm ffff880137000a80 ffff880137111800 devpts devpts /dev/pts ffff880137000c40 ffff8800b7e9f800 tmpfs tmpfs /run ffff880137000e00 ffff88012a300000 tmpfs tmpfs /sys/fs/cgroup ffff880137000fc0 ffff88012a300800 cgroup cgroup /sys/fs/cgroup/systemd ffff880137001180 ffff88012a301000 pstore pstore /sys/fs/pstore ffff880137001340 ffff88012a303000 cgroup cgroup /sys/fs/cgroup/memory ffff880137001500 ffff88012a302800 cgroup cgroup /sys/fs/cgroup/devices ffff8801370016c0 ffff88012a302000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff880137001880 ffff88012a301800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880137001a40 ffff88012a303800 cgroup cgroup /sys/fs/cgroup/pids ffff880137001c00 ffff88012a304000 cgroup cgroup /sys/fs/cgroup/freezer ffff880137001dc0 ffff88012a304800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a312000 ffff88012a305000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a3121c0 ffff88012a305800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a312380 ffff88012a306000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a312540 ffff8800b53a2000 configfs configfs /sys/kernel/config ffff8800b5269340 ffff8800b525c800 ext4 /dev/nbd0 / ffff88012a312700 ffff8800b525e000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8800b5269500 ffff880129de0000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff880137668fc0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012a312e00 ffff8800b4b24800 hugetlbfs hugetlbfs /dev/hugepages ffff88012a312fc0 ffff880137113000 mqueue mqueue /dev/mqueue ffff88012a313180 ffff8800b4b20000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8800b52696c0 ffff8800b60f7800 ramfs none /mnt ffff8800b5269880 ffff8800b4840000 tmpfs none /var/lib/stateless/writable ffff8800b5269a40 ffff8800b4845800 squashfs /dev/vda /home/green/git/lustre-release ffff8800b5269c00 ffff8800b4840000 tmpfs none /var/cache/man ffff88012a313340 ffff8800b4840000 tmpfs none /var/log ffff880137669340 ffff8800b4840000 tmpfs none /var/lib/dbus ffff88012a313500 ffff8800b4840000 tmpfs none /tmp ffff88012a3136c0 ffff8800b4840000 tmpfs none /var/lib/dhclient ffff88012a313880 ffff8800b4840000 tmpfs none /var/tmp ffff88012a313a40 ffff8800b4840000 tmpfs none /var/lib/NetworkManager ffff8800b5269dc0 ffff8800b4840000 tmpfs none /var/lib/systemd/random-seed ffff8800b21e4000 ffff8800b4840000 tmpfs none /var/spool ffff880138ccb340 ffff8800b4840000 tmpfs none /var/lib/nfs ffff880137669500 ffff8800b4840000 tmpfs none /var/lib/gssproxy ffff8801376696c0 ffff8800b4840000 tmpfs none /var/lib/logrotate ffff88012a313c00 ffff8800b4840000 tmpfs none /etc ffff8800b21e41c0 ffff8800b4840000 tmpfs none /var/lib/rsyslog ffff8800b21e4380 ffff8800b4840000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b21e4540 ffff8800b489c000 nfs4 192.168.200.253:/exports/state/oleg107-server.virtnet /var/lib/stateless/state ffff880137669880 ffff8800b489c000 nfs4 192.168.200.253:/exports/state/oleg107-server.virtnet /boot ffff88012a312a80 ffff8800b489c000 nfs4 192.168.200.253:/exports/state/oleg107-server.virtnet /etc/etc/kdump.conf ffff880137669a40 ffff8800b525e000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff880129e0ce00 ffff8800b4845800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b5268540 ffff8800a4837800 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b5268a80 ffff8800a83ed000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff880129e0cfc0 ffff88009a26a000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 78.928312] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000200000400-0x0000000240000400]:0:mdt [ 79.037133] mount.lustre (6991) used greatest stack depth: 10144 bytes left [ 80.241775] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 82.628208] Lustre: Modifying parameter general.debug_raw_pointers in log params [ 84.399755] random: crng init done [ 84.597140] Lustre: lustre-OST0000: new disk, initializing [ 84.599283] Lustre: srv-lustre-OST0000: No data found on store. Initialize space. [ 84.601264] Lustre: Skipped 1 previous similar message [ 84.635696] Lustre: lustre-OST0000: Imperative Recovery not enabled, recovery window 60-180 [ 85.776200] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000240000400-0x0000000280000400]:0:ost [ 85.780217] Lustre: cli-lustre-OST0000-super: Allocated super-sequence [0x0000000240000400-0x0000000280000400]:0:ost] [ 85.842536] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x100000000 to 0x240000400 [ 86.411360] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 89.787872] Lustre: lustre-OST0001: new disk, initializing [ 89.790581] Lustre: srv-lustre-OST0001: No data found on store. Initialize space. [ 89.806471] Lustre: lustre-OST0001: Imperative Recovery not enabled, recovery window 60-180 [ 91.260023] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 92.815053] Lustre: ctl-lustre-MDT0000: super-sequence allocation rc = 0 [0x0000000280000400-0x00000002c0000400]:1:ost [ 92.819028] Lustre: cli-lustre-OST0001-super: Allocated super-sequence [0x0000000280000400-0x00000002c0000400]:1:ost] [ 92.855700] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x100010000 to 0x280000400 [ 96.372488] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 99.813687] Lustre: Setting parameter general.lod.*.mdt_hash in log params [ 106.057646] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing check_logdir /tmp/testlogs/ [ 106.901219] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing yml_node [ 107.832032] Lustre: DEBUG MARKER: Client: 2.16.0.RC5 [ 108.424763] Lustre: DEBUG MARKER: MDS: 2.16.0.RC5 [ 109.059371] Lustre: DEBUG MARKER: OSS: 2.16.0.RC5 [ 109.451259] Lustre: DEBUG MARKER: -----============= acceptance-small: sanity-benchmark ============----- Thu Dec 12 10:04:02 EST 2024 [ 113.262647] Lustre: DEBUG MARKER: excepting tests: [ 113.644854] Lustre: DEBUG MARKER: skipping tests SLOW=no: iozone [ 114.043557] Lustre: DEBUG MARKER: === sanity-benchmark: start setup 10:04:07 (1734015847) === [ 115.094865] Lustre: DEBUG MARKER: oleg107-client.virtnet: executing check_config_client /mnt/lustre [ 121.030746] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 122.151625] Lustre: Modifying parameter general.lod.*.mdt_hash in log params [ 123.093707] Lustre: DEBUG MARKER: oleg107-server.virtnet: executing set_default_debug vfstrace rpctrace dlmtrace neterror ha config ioctl super lfsck all [ 124.351663] Lustre: DEBUG MARKER: === sanity-benchmark: finish setup 10:04:17 (1734015857) === [ 125.056382] Lustre: DEBUG MARKER: == sanity-benchmark test dbench: dbench ================== 10:04:17 (1734015857) [ 164.934258] hrtimer: interrupt took 5080001 ns [ 289.027863] Lustre: DEBUG MARKER: == sanity-benchmark test bonnie: bonnie++ ================ 10:07:01 (1734016021) [ 290.496632] Lustre: DEBUG MARKER: min OST has 3469312kB available, using 5203968kB 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 13.14s (real) 7.55s (CPU), Child processes: 5.56s