************************ crashinfo ************************* /exports/testreports/44423/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg437-client-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.Zw3Fq/vmlinux [TAINTED] DUMPFILE: /exports/testreports/44423/testresults/racer-zfs-centos7_x86_64-centos7_x86_64/oleg437-client-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Thu Jul 25 00:11:09 EDT 2024 UPTIME: 00:17:13 LOAD AVERAGE: 2.01, 13.26, 20.97 TASKS: 158 NODENAME: oleg437-client.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 16 last 5s 29 last 60s 39 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 152 TASK_RUNNING 1 TASK_UNINTERRUPTIBLE 2 +++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 ----- -------------- ------ ---------------------------- 913 in:imjournal 0 ms /usr/sbin/rsyslogd -n 1 systemd 0 ms /usr/lib/systemd/systemd --switched-root --system --deserialize 22 9570 ldlm_bl_04 0 ms (no user stack) 46 kworker/0:1 0 ms (no user stack) 15708 ll_sa_15627 33 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955079 3.6 GB ---- FREE 849191 3.2 GB 88% of TOTAL MEM USED 105888 413.6 MB 11% of TOTAL MEM SHARED 14908 58.2 MB 1% of TOTAL MEM BUFFERS 5170 20.2 MB 0% of TOTAL MEM CACHED 51283 200.3 MB 5% of TOTAL MEM SLAB 15680 61.2 MB 1% 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 739682 2.8 GB ---- COMMITTED 61860 241.6 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 6 LISTEN 3 NAGLE disabled (TCP_NODELAY): 5 user_data set (NFS etc.): 4 UDP Connection Info ------------------- 2 UDP sockets, 0 in ESTABLISHED Unix Connection Info ------------------------ ESTABLISHED 26 CLOSE 18 LISTEN 8 Raw sockets info -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 1031.6 eth0 n/a 0.1 RSS_TOTAL=75484 pages, %mem= 1.2 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012aa38000 ffff88012aac8000 sysfs sysfs /sys ffff88012aa381c0 ffff880139944000 proc proc /proc ffff88012aa38380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012aa38540 ffff8800b6cf0800 securityfs securityfs /sys/kernel/security ffff88012aa38700 ffff88012aac8800 tmpfs tmpfs /dev/shm ffff88012aa388c0 ffff8801372fe000 devpts devpts /dev/pts ffff88012aa38a80 ffff88012aac9000 tmpfs tmpfs /run ffff88012aa38c40 ffff88012aac9800 tmpfs tmpfs /sys/fs/cgroup ffff88012aa38e00 ffff88012aaca000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012aa38fc0 ffff88012aaca800 pstore pstore /sys/fs/pstore ffff88012aa39180 ffff88012aacc800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012aa39340 ffff88012aacc000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012aa39500 ffff88012aacb800 cgroup cgroup /sys/fs/cgroup/pids ffff88012aa396c0 ffff88012aacb000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012aa39880 ffff88012aacd000 cgroup cgroup /sys/fs/cgroup/freezer ffff88012aa39a40 ffff88012aacd800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012aa39c00 ffff88012aace000 cgroup cgroup /sys/fs/cgroup/memory ffff88012aa39dc0 ffff88012aace800 cgroup cgroup /sys/fs/cgroup/devices ffff88012aadc000 ffff88012aacf000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012aadc1c0 ffff88012aacf800 cgroup cgroup /sys/fs/cgroup/cpuset ffff880138ccb180 ffff8800b606b000 configfs configfs /sys/kernel/config ffff88012aadd500 ffff88012ab8f800 ext4 /dev/nbd0 / ffff88012aadd6c0 ffff88012ab8d000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012aadd880 ffff88012a43c000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012b23c8c0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012aadda40 ffff8801372ff800 mqueue mqueue /dev/mqueue ffff880137668e00 ffff8800b5d3f000 hugetlbfs hugetlbfs /dev/hugepages ffff88012aaddc00 ffff88012a43f800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff88012aadddc0 ffff88012a43d800 ramfs none /mnt ffff880137668fc0 ffff8800b6082000 tmpfs none /var/lib/stateless/writable ffff8800b6f44000 ffff88012a438800 squashfs /dev/vda /home/green/git/lustre-release ffff88012b23cc40 ffff8800b6082000 tmpfs none /var/cache/man ffff880137669180 ffff8800b6082000 tmpfs none /var/log ffff8800b6f44380 ffff8800b6082000 tmpfs none /var/lib/dbus ffff88012b23ce00 ffff8800b6082000 tmpfs none /tmp ffff880137669340 ffff8800b6082000 tmpfs none /var/lib/dhclient ffff88012b23cfc0 ffff8800b6082000 tmpfs none /var/tmp ffff880137669500 ffff8800b6082000 tmpfs none /var/lib/NetworkManager ffff8800b6f44540 ffff8800b6082000 tmpfs none /var/lib/systemd/random-seed ffff8801376696c0 ffff8800b6082000 tmpfs none /var/spool ffff8800b6f44700 ffff8800b6082000 tmpfs none /var/lib/nfs ffff8800b6f448c0 ffff8800b6082000 tmpfs none /var/lib/gssproxy ffff880137669880 ffff8800b6082000 tmpfs none /var/lib/logrotate ffff88012b23d180 ffff8800b6082000 tmpfs none /etc ffff8800b6f44a80 ffff8800b6082000 tmpfs none /var/lib/rsyslog ffff88012b23d340 ffff8800b6082000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b6f44c40 ffff8800b6086000 nfs4 192.168.200.253:/exports/state/oleg437-client.virtnet /var/lib/stateless/state ffff8800b6f45340 ffff8800b6086000 nfs4 192.168.200.253:/exports/state/oleg437-client.virtnet /boot ffff8800b6f45500 ffff8800b6086000 nfs4 192.168.200.253:/exports/state/oleg437-client.virtnet /etc/etc/kdump.conf ffff8800b6f456c0 ffff88012ab8d000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b5df6fc0 ffff8800b5d51000 nfs4 192.168.200.253://exports/testreports/44423/testresults/racer-zfs-centos7_x86_64-centos7_x86_64 /tmp/tmp/testlogs ffff8800b5df7340 ffff8800b0b2f800 tmpfs tmpfs /run/user/0 ffff8800b5df6a80 ffff88012a438800 squashfs /dev/vda /usr/sbin/mount.lustre +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 106.496635] Lustre: DEBUG MARKER: oleg437-client.virtnet: executing check_config_client /mnt/lustre [ 110.276669] Lustre: DEBUG MARKER: Using TIMEOUT=20 [ 110.958101] Lustre: lustre-OST0000-osc-ffff8800b3d83800: disconnect after 23s idle [ 112.205647] Lustre: DEBUG MARKER: == racer test 1: racer on clients: oleg437-client.virtnet DURATION=300 ========================================================== 23:55:46 (1721879746) [ 113.147176] 10[9530]: segfault at 0 ip (null) sp 00007ffe9aa42d48 error 14 in 10[400000+6000] [ 113.782609] random: crng init done [ 222.970902] LustreError: lustre-MDT0000-mdc-ffff8800b3d83800: operation ldlm_enqueue to node 192.168.204.137@tcp failed: rc = -107 [ 222.976996] Lustre: lustre-MDT0000-mdc-ffff8800b3d83800: Connection to lustre-MDT0000 (at 192.168.204.137@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 222.984347] LustreError: lustre-MDT0000-mdc-ffff8800b3d83800: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 222.991381] LustreError: 15454:0:(file.c:5678:ll_inode_revalidate_fini()) lustre: revalidate FID [0x200000401:0x257:0x0] error: rc = -5 [ 222.991462] LustreError: 15461:0:(llite_lib.c:2025:ll_md_setattr()) md_setattr fails: rc = -5 [ 222.992417] LustreError: 15684:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800b3d83800: inode [0x200000401:0xd:0x0] mdc close failed: rc = -108 [ 223.002501] LustreError: 15454:0:(file.c:5678:ll_inode_revalidate_fini()) Skipped 1 previous similar message [ 223.037618] Lustre: lustre-MDT0000-mdc-ffff8800b3d83800: Connection restored to (at 192.168.204.137@tcp) [ 228.447018] 9[19582]: segfault at 8 ip 00007f8ec44b37e8 sp 00007ffcc36d9790 error 4 in ld-2.17.so[7f8ec44a8000+22000] [ 238.132692] 17[25460]: segfault at 8 ip 00007fe7009887e8 sp 00007fff608f7010 error 4 in ld-2.17.so[7fe70097d000+22000] [ 238.154259] LustreError: 25460:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800ab35e000: inode [0x200000402:0x62a:0x0] mdc close failed: rc = -13 [ 238.161014] LustreError: 25460:0:(file.c:262:ll_close_inode_openhandle()) Skipped 17 previous similar messages [ 261.541365] 5[5973]: segfault at 8 ip 00007f19cd9f47e8 sp 00007ffcaf5984a0 error 4 in ld-2.17.so[7f19cd9e9000+22000] [ 262.754037] 7[7039]: segfault at 0 ip (null) sp 00007fff004149f8 error 14 in 7[400000+6000] [ 262.763268] LustreError: 7039:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800b3d83800: inode [0x200000402:0xbdd:0x0] mdc close failed: rc = -13 [ 266.379172] LustreError: 9710:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800ab35e000: inode [0x200000402:0xcdf:0x0] mdc close failed: rc = -13 [ 302.881694] 18[4162]: segfault at 8 ip 00007fa6356732fc sp 00007ffd894a4130 error 4 in ld-2.17.so[7fa635666000+22000] [ 302.897768] LustreError: 4162:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800ab35e000: inode [0x200000403:0x14e6:0x0] mdc close failed: rc = -13 [ 329.922685] 3[21413]: segfault at 8 ip 00007febead987e8 sp 00007ffd50255020 error 4 in ld-2.17.so[7febead8d000+22000] [ 352.261489] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 128ms for inuse entry [0x200000401:0x257:0x0] to be finished [ 434.930622] Lustre: lustre-MDT0000-mdc-ffff8800ab35e000: Connection to lustre-MDT0000 (at 192.168.204.137@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 434.938833] LustreError: lustre-MDT0000-mdc-ffff8800ab35e000: This client was evicted by lustre-MDT0000; in progress operations using this service will fail. [ 434.943744] LustreError: 24237:0:(file.c:262:ll_close_inode_openhandle()) lustre-clilmv-ffff8800ab35e000: inode [0x200000403:0x1daf:0x0] mdc close failed: rc = -5 [ 434.948549] LustreError: 24237:0:(file.c:262:ll_close_inode_openhandle()) Skipped 1 previous similar message [ 434.965439] Lustre: lustre-MDT0000-mdc-ffff8800ab35e000: Connection restored to (at 192.168.204.137@tcp) [ 450.335538] Lustre: DEBUG MARKER: == racer test 2: racer rename: oleg437-client.virtnet DURATION=300 ========================================================== 00:01:24 (1721880084) [ 450.747203] Lustre: DEBUG MARKER: SKIP: racer test_2 need at least 2 MDTs [ 451.197308] Lustre: DEBUG MARKER: == racer test complete, duration 349 sec ================= 00:01:25 (1721880085) [ 451.525483] Lustre: Unmounted lustre-client [ 481.326027] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 256ms for inuse entry [0x200000401:0x257:0x0] to be finished [ 610.377077] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 384ms for inuse entry [0x200000401:0x257:0x0] to be finished [ 739.413026] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 512ms for inuse entry [0x200000401:0x257:0x0] to be finished [ 868.441028] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 640ms for inuse entry [0x200000401:0x257:0x0] to be finished [ 997.469040] Lustre: 15708:0:(statahead.c:1628:ll_statahead_thread()) lustre: statahead thread waited 768ms for inuse entry [0x200000401:0x257:0x0] to be finished ****************************************************************************** ************************ 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 11.07s (real) 5.66s (CPU), Child processes: 5.37s