************************ crashinfo ************************* /exports/testreports/47154/testresults/replay-dual-zfs-centos7_x86_64-centos7_x86_64/oleg236-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.fT3Ah/vmlinux [TAINTED] DUMPFILE: /exports/testreports/47154/testresults/replay-dual-zfs-centos7_x86_64-centos7_x86_64/oleg236-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Wed Nov 13 12:50:15 EST 2024 UPTIME: 00:43:03 LOAD AVERAGE: 0.00, 0.17, 0.42 TASKS: 365 NODENAME: oleg236-server.virtnet RELEASE: 3.10.0-7.9-debug VERSION: #1 SMP Sat Mar 26 23:28:42 EDT 2022 MACHINE: x86_64 (2400 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 32 last 5s 67 last 60s 76 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 361 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 ----- -------------- ------ ---------------------------- 7027 ll_evictor 0 ms (no user stack) 3485 arc_reap 0 ms (no user stack) 3489 l2arc_feed 0 ms (no user stack) 22363 kworker/0:2 0 ms (no user stack) 8380 ldlm_bl_03 25 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 713553 2.7 GB 74% of TOTAL MEM USED 241514 943.4 MB 25% of TOTAL MEM SHARED 9469 37 MB 0% of TOTAL MEM BUFFERS 5123 20 MB 0% of TOTAL MEM CACHED 76584 299.2 MB 8% of TOTAL MEM SLAB 19621 76.6 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 65014 254 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 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 2581.1 eth0 n/a 0.8 RSS_TOTAL=53040 pages, %mem= 0.9 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137668380 ffff8800b522a000 sysfs sysfs /sys ffff880137668540 ffff880139944000 proc proc /proc ffff880137668700 ffff880137678000 devtmpfs devtmpfs /dev ffff8801376688c0 ffff88012a300000 securityfs securityfs /sys/kernel/security ffff880137668a80 ffff8800b522a800 tmpfs tmpfs /dev/shm ffff880137668c40 ffff880137316000 devpts devpts /dev/pts ffff880137668e00 ffff8800b522b000 tmpfs tmpfs /run ffff880137668fc0 ffff8800b522b800 tmpfs tmpfs /sys/fs/cgroup ffff880137669180 ffff8800b522c000 cgroup cgroup /sys/fs/cgroup/systemd ffff880137669340 ffff8800b522c800 pstore pstore /sys/fs/pstore ffff880137669500 ffff8800b522e800 cgroup cgroup /sys/fs/cgroup/freezer ffff8801376696c0 ffff8800b522e000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880137669880 ffff8800b522d800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880137669a40 ffff8800b522d000 cgroup cgroup /sys/fs/cgroup/cpuset ffff880137669c00 ffff8800b522f000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff880137669dc0 ffff8800b522f800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a326000 ffff88012a328000 cgroup cgroup /sys/fs/cgroup/memory ffff88012a3261c0 ffff88012a328800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a326380 ffff88012a329000 cgroup cgroup /sys/fs/cgroup/pids ffff88012a326540 ffff88012a329800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a3268c0 ffff88012a32f000 configfs configfs /sys/kernel/config ffff88012a2aa380 ffff88012a307000 ext4 /dev/nbd0 / ffff88012b256a80 ffff88012a306000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012a2aa540 ffff88012a304800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012a327340 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012a2aa700 ffff880137317800 mqueue mqueue /dev/mqueue ffff88012a2aa8c0 ffff88012a305000 hugetlbfs hugetlbfs /dev/hugepages ffff88012b2568c0 ffff8800b4ff2000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012b256c40 ffff8800b4ff2800 ramfs none /mnt ffff88012a2aaa80 ffff8800b4085800 tmpfs none /var/lib/stateless/writable ffff88012b256e00 ffff8800b417f000 squashfs /dev/vda /home/green/git/lustre-release ffff88012a327500 ffff8800b4085800 tmpfs none /var/cache/man ffff8800b4cba380 ffff8800b4085800 tmpfs none /var/log ffff88012a3276c0 ffff8800b4085800 tmpfs none /var/lib/dbus ffff88012a2aac40 ffff8800b4085800 tmpfs none /tmp ffff88012a2aae00 ffff8800b4085800 tmpfs none /var/lib/dhclient ffff88012a2aafc0 ffff8800b4085800 tmpfs none /var/tmp ffff88012a2ab180 ffff8800b4085800 tmpfs none /var/lib/NetworkManager ffff88012a2ab340 ffff8800b4085800 tmpfs none /var/lib/systemd/random-seed ffff88012b256fc0 ffff8800b4085800 tmpfs none /var/spool ffff88012a2ab500 ffff8800b4085800 tmpfs none /var/lib/nfs ffff88012a2ab6c0 ffff8800b4085800 tmpfs none /var/lib/gssproxy ffff88012a2ab880 ffff8800b4085800 tmpfs none /var/lib/logrotate ffff88012a327880 ffff8800b4085800 tmpfs none /etc ffff88012a327a40 ffff8800b4085800 tmpfs none /var/lib/rsyslog ffff88012a327c00 ffff8800b4085800 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012a2aba40 ffff8800b2598000 nfs4 192.168.200.253:/exports/state/oleg236-server.virtnet /var/lib/stateless/state ffff88012a2abc00 ffff8800b2598000 nfs4 192.168.200.253:/exports/state/oleg236-server.virtnet /boot ffff88012a327dc0 ffff8800b2598000 nfs4 192.168.200.253:/exports/state/oleg236-server.virtnet /etc/etc/kdump.conf ffff88012a2abdc0 ffff88012a306000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b1e23880 ffff8800b417f000 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b1e6e8c0 ffff8800b4ff5800 lustre lustre-ost2/ost2 /mnt/lustre-ost2 ffff8800b1e6f880 ffff88008a907000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b1ebdc00 ffff880087daa000 lustre lustre-ost1/ost1 /mnt/lustre-ost1 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 2056.807124] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2843 to 0x280000400:2881) [ 2057.615045] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2057.979205] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2089.362521] Lustre: DEBUG MARKER: == replay-dual test 28: lock replay should be ordered: waiting after granted ========================================================== 12:41:59 (1731519719) [ 2111.396316] Lustre: Failing over lustre-OST0000 [ 2111.418112] Lustre: server umount lustre-OST0000 complete [ 2111.935497] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2111.938230] LustreError: lustre-OST0000: not available for connect from 0@lo (no target). If you are running an HA pair check that the target is mounted on the other server. [ 2124.157404] Lustre: DEBUG MARKER: oleg236-server.virtnet: executing set_default_debug -1 all [ 2124.734995] Lustre: *** cfs_fail_loc=32a, val=0*** [ 2124.970035] Lustre: 3295:0:(client.c:2363:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1731519671/real 1731519671] req@ffff88008a95dc00 x1815627865233024/t0(0) o400->lustre-MDT0000-lwp-OST0001@0@lo:12/10 lens 224/224 e 0 to 1 dl 1731519756 ref 1 fl Rpc:XNQr/200/ffffffff rc 0/-1 job:'kworker.0' uid:0 gid:0 [ 2124.980231] Lustre: 3295:0:(client.c:2363:ptlrpc_expire_one_request()) Skipped 40 previous similar messages [ 2126.656646] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2127.046443] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL state after 0 sec [ 2131.708272] Lustre: DEBUG MARKER: == replay-dual test 29: replay vs update with the same xid ========================================================== 12:42:41 (1731519761) [ 2132.045902] Lustre: DEBUG MARKER: SKIP: replay-dual test_29 needs >= 2 MDTs [ 2132.419091] Lustre: DEBUG MARKER: == replay-dual test 30: layout lock replay is not blocked on IO ========================================================== 12:42:42 (1731519762) [ 2133.988502] Lustre: Failing over lustre-MDT0000 [ 2134.096457] Lustre: server umount lustre-MDT0000 complete [ 2146.696502] Lustre: DEBUG MARKER: oleg236-server.virtnet: executing set_default_debug -1 all [ 2154.734300] Lustre: lustre-OST0000: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x240000400:2965 to 0x240000400:3009) [ 2154.734535] Lustre: lustre-OST0001: new connection from lustre-MDT0000-mdtlov (cleaning up unused objects from 0x280000400:2964 to 0x280000400:3009) [ 2155.517809] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 2155.920009] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [ 2158.608463] Lustre: DEBUG MARKER: == replay-dual test 31: deadlock on file_remove_privs and occupied mod rpc slots ========================================================== 12:43:08 (1731519788) [ 2159.508153] Lustre: Failing over lustre-OST0000 [ 2159.536271] Lustre: server umount lustre-OST0000 complete [ 2159.791503] LustreError: lustre-OST0000-osc-MDT0000: operation ost_statfs to node 0@lo failed: rc = -107 [ 2171.176057] mount.lustre (31257) used greatest stack depth: 9584 bytes left [ 2172.459026] Lustre: DEBUG MARKER: oleg236-server.virtnet: executing set_default_debug -1 all [ 2172.690075] Lustre: lustre-OST0000: Recovery over after 0:01, of 2 clients 2 recovered and 0 were evicted. [ 2172.694133] Lustre: Skipped 11 previous similar messages [ 2175.051027] Lustre: DEBUG MARKER: oleg236-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 2175.432199] Lustre: DEBUG MARKER: osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid in FULL [ 2178.471299] Lustre: DEBUG MARKER: == replay-dual test 32: gap in update llog shouldn't break recovery ========================================================== 12:43:28 (1731519808) [ 2178.823491] Lustre: DEBUG MARKER: SKIP: replay-dual test_32 needs >= 2 MDTs [ 2179.214004] Lustre: DEBUG MARKER: == replay-dual test 33: Check for OBD_INCOMPAT_MULTI_RPCS in last_rcvd after abort_recovery ========================================================== 12:43:29 (1731519809) [ 2179.568070] Lustre: DEBUG MARKER: SKIP: replay-dual test_33 ldiskfs only test [ 2179.962970] Lustre: DEBUG MARKER: == replay-dual test complete, duration 2100 sec ========== 12:43:29 (1731519809) [ 2180.346007] Lustre: DEBUG MARKER: === replay-dual: start cleanup 12:43:30 (1731519810) === ****************************************************************************** ************************ 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.03s (CPU), Child processes: 5.48s