************************ crashinfo ************************* /exports/testreports/48366/testresults/racer-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg359-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.zMjtU/vmlinux [TAINTED] DUMPFILE: /exports/testreports/48366/testresults/racer-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg359-client-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Tue Jan 7 10:46:05 EST 2025 UPTIME: 00:25:54 LOAD AVERAGE: 0.00, 5.35, 26.75 TASKS: 157 NODENAME: oleg359-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 22 last 5s 40 last 60s 44 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 153 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 ----- -------------- ------ ---------------------------- 50 kworker/3:1 0 ms (no user stack) 1898 monitor_thread 0 ms (no user stack) 34 rcuos/3 0 ms (no user stack) 595 kworker/1:2 8 ms (no user stack) 1 systemd 8 ms /usr/lib/systemd/systemd --switched-root --system --deserialize 24 +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955079 3.6 GB ---- FREE 855928 3.3 GB 89% of TOTAL MEM USED 99151 387.3 MB 10% of TOTAL MEM SHARED 9912 38.7 MB 1% of TOTAL MEM BUFFERS 5232 20.4 MB 0% of TOTAL MEM CACHED 46477 181.6 MB 4% of TOTAL MEM SLAB 15728 61.4 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 61670 240.9 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 1551.9 eth0 n/a 0.4 RSS_TOTAL=75348 pages, %mem= 1.2 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012ab00000 ffff88012b3bd000 sysfs sysfs /sys ffff88012ab001c0 ffff880139944000 proc proc /proc ffff88012ab00380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012ab00540 ffff8800b6c9b800 securityfs securityfs /sys/kernel/security ffff88012ab00700 ffff88012b3bd800 tmpfs tmpfs /dev/shm ffff88012ab008c0 ffff8801372f6000 devpts devpts /dev/pts ffff88012ab00a80 ffff88012b3be000 tmpfs tmpfs /run ffff88012ab00c40 ffff88012b3be800 tmpfs tmpfs /sys/fs/cgroup ffff88012ab00e00 ffff88012b3bf000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012ab00fc0 ffff88012b3bf800 pstore pstore /sys/fs/pstore ffff88012ab01180 ffff88012ab19800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012ab01340 ffff88012ab19000 cgroup cgroup /sys/fs/cgroup/devices ffff88012ab01500 ffff88012ab18800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012ab016c0 ffff88012ab18000 cgroup cgroup /sys/fs/cgroup/pids ffff88012ab01880 ffff88012ab1a000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012ab01a40 ffff88012ab1a800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012ab01c00 ffff88012ab1b000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012ab01dc0 ffff88012ab1b800 cgroup cgroup /sys/fs/cgroup/memory ffff88012ab2c000 ffff88012ab1c000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012ab2c1c0 ffff88012ab1c800 cgroup cgroup /sys/fs/cgroup/blkio ffff880138ccb340 ffff8800b6188000 configfs configfs /sys/kernel/config ffff88012ab2c540 ffff88012a590000 ext4 /dev/nbd0 / ffff88012b26fa40 ffff88012ab1e000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012b26fdc0 ffff8800b6399000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff8801376688c0 ffff8801372f7800 mqueue mqueue /dev/mqueue ffff880137668a80 ffff8800b63cf800 hugetlbfs hugetlbfs /dev/hugepages ffff88012b26e8c0 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012ab2c700 ffff8800b5836800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880138ccb880 ffff8800b58ad800 ramfs none /mnt ffff8800b5ae2000 ffff8800b639b000 tmpfs none /var/lib/stateless/writable ffff880137668e00 ffff8800b63c8000 squashfs /dev/vda /home/green/git/lustre-release ffff8800b5ae2380 ffff8800b639b000 tmpfs none /var/cache/man ffff88012ab2c8c0 ffff8800b639b000 tmpfs none /var/log ffff88012ab2ca80 ffff8800b639b000 tmpfs none /var/lib/dbus ffff880138ccba40 ffff8800b639b000 tmpfs none /tmp ffff88012ab2cc40 ffff8800b639b000 tmpfs none /var/lib/dhclient ffff88012ab2ce00 ffff8800b639b000 tmpfs none /var/tmp ffff88012ab2cfc0 ffff8800b639b000 tmpfs none /var/lib/NetworkManager ffff8800b5ae2540 ffff8800b639b000 tmpfs none /var/lib/systemd/random-seed ffff88012ab2d180 ffff8800b639b000 tmpfs none /var/spool ffff880137668fc0 ffff8800b639b000 tmpfs none /var/lib/nfs ffff88012ab2d340 ffff8800b639b000 tmpfs none /var/lib/gssproxy ffff88012ab2d500 ffff8800b639b000 tmpfs none /var/lib/logrotate ffff8800b5ae2700 ffff8800b639b000 tmpfs none /etc ffff8800b5ae28c0 ffff8800b639b000 tmpfs none /var/lib/rsyslog ffff88012ab2d6c0 ffff8800b639b000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff88012ab2d880 ffff8800b6c9d800 nfs4 192.168.200.253:/exports/state/oleg359-client.virtnet /var/lib/stateless/state ffff8800b5ae2e00 ffff8800b6c9d800 nfs4 192.168.200.253:/exports/state/oleg359-client.virtnet /boot ffff8800b5ae2fc0 ffff8800b6c9d800 nfs4 192.168.200.253:/exports/state/oleg359-client.virtnet /etc/etc/kdump.conf ffff880137669180 ffff88012ab1e000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff88012e199c00 ffff8800b3a1e800 nfs4 192.168.200.253://exports/testreports/48366/testresults/racer-ldiskfs-DNE-centos7_x86_64-centos7_x86_64 /tmp/tmp/testlogs ffff88012d7ec540 ffff8800b639c800 tmpfs tmpfs /run/user/0 ffff880137669dc0 ffff8800b63c8000 squashfs /dev/vda /usr/sbin/mount.lustre ffff88012d7ecc40 ffff88012b4e9800 lustre 192.168.203.159@tcp:/lustre /mnt/lustre +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 478.353610] Lustre: lustre-OST0000-osc-ffff8800a996d800: Connection restored to (at 192.168.203.159@tcp) [ 480.677239] INFO: task mv:8214 blocked for more than 120 seconds. [ 480.679223] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 480.681728] mv D ffff8800a370ca40 12072 8214 1 0x00000004 [ 480.683724] Call Trace: [ 480.684580] [] schedule_preempt_disabled+0x39/0x90 [ 480.686230] [] __mutex_lock_slowpath+0x13a/0x340 [ 480.687803] [] mutex_lock+0x2d/0x40 [ 480.689346] [] lock_rename+0x31/0xe0 [ 480.690841] [] SYSC_renameat2+0x22f/0x570 [ 480.692739] [] ? handle_mm_fault+0xc2/0x150 [ 480.694779] [] ? trace_do_page_fault+0x56/0x170 [ 480.696349] [] SyS_renameat2+0xe/0x10 [ 480.697934] [] system_call_fastpath+0x1f/0x24 [ 480.699603] INFO: task mv:8430 blocked for more than 120 seconds. [ 480.701650] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 480.704689] mv D ffff88012b8606c0 12072 8430 1 0x00000004 [ 480.706448] Call Trace: [ 480.706919] [] schedule_preempt_disabled+0x39/0x90 [ 480.708676] [] __mutex_lock_slowpath+0x13a/0x340 [ 480.710865] [] mutex_lock+0x2d/0x40 [ 480.712637] [] lock_rename+0x31/0xe0 [ 480.714523] [] SYSC_renameat2+0x22f/0x570 [ 480.715957] [] ? handle_mm_fault+0xc2/0x150 [ 480.717264] [] ? trace_do_page_fault+0x56/0x170 [ 480.719471] [] SyS_renameat2+0xe/0x10 [ 480.721014] [] system_call_fastpath+0x1f/0x24 [ 491.323023] LustreError: 15190:0:(file.c:5195:ll_inode_revalidate_fini()) lustre: revalidate FID [0x240000404:0x118a:0x0] error: rc = -5 [ 491.328765] LustreError: 15190:0:(file.c:5195:ll_inode_revalidate_fini()) Skipped 38 previous similar messages [ 491.334186] LustreError: 30446:0:(llite_lib.c:1937:ll_md_setattr()) md_setattr fails: rc = -108 [ 508.391954] LustreError: 11-0: lustre-MDT0001-mdc-ffff8800a996d800: operation mds_getattr to node 192.168.203.159@tcp failed: rc = -107 [ 508.392015] Lustre: lustre-MDT0001-mdc-ffff8800a996d800: Connection to lustre-MDT0001 (at 192.168.203.159@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 508.392016] Lustre: Skipped 1 previous similar message [ 508.393642] LustreError: 167-0: lustre-MDT0001-mdc-ffff8800a996d800: This client was evicted by lustre-MDT0001; in progress operations using this service will fail. [ 508.393643] LustreError: Skipped 1 previous similar message [ 508.411668] LustreError: Skipped 3 previous similar messages [ 508.419930] Lustre: lustre-MDT0001-mdc-ffff8800a996d800: Connection restored to (at 192.168.203.159@tcp) [ 508.423201] Lustre: Skipped 1 previous similar message [ 526.839695] Lustre: DEBUG MARKER: == racer test complete, duration 395 sec ================= 10:28:57 (1736263737) [ 527.091873] Lustre: Unmounted lustre-client ****************************************************************************** ************************ 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 10.40s (real) 5.35s (CPU), Child processes: 5.00s