************************ crashinfo ************************* /exports/testreports/51244/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg301-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.gpjWS/vmlinux [TAINTED] DUMPFILE: /exports/testreports/51244/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg301-client-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Thu May 1 04:11:53 EDT 2025 UPTIME: 04:26:59 LOAD AVERAGE: 0.55, 0.58, 0.59 TASKS: 175 NODENAME: oleg301-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 31 last 5s 42 last 60s 91 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 170 TASK_RUNNING 1 TASK_UNINTERRUPTIBLE 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 ----- -------------- ------ ---------------------------- 11 rcuos/0 0 ms (no user stack) 34 rcuos/3 0 ms (no user stack) 9 rcu_sched 0 ms (no user stack) 19017 ssh 4 ms ssh -oConnectTimeout=10 -2 -a -x oleg301-server (PATH=$PATH:/home/green/git/lustre-release/lustre/utils:/home/green/git/lustre-release/lustre/tests:/sbin:/usr/sbin; cd /root; LUSTRE="/home/green/git/lustre-release/lustre" mds1_FSTYPE=ldiskfs ost1_FSTYPE=ldiskfs VERBOSE=false FSTYPE=ldiskfs NETTYPE=tcp bash -c "/home/green/git/lustre-release/lustre/utils/lctl get_param -n osp.*.destroys_in_flight") 15 migration/1 18 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955079 3.6 GB ---- FREE 858619 3.3 GB 89% of TOTAL MEM USED 96460 376.8 MB 10% of TOTAL MEM SHARED 12269 47.9 MB 1% of TOTAL MEM BUFFERS 3021 11.8 MB 0% of TOTAL MEM CACHED 39620 154.8 MB 4% of TOTAL MEM SLAB 11716 45.8 MB 1% of TOTAL MEM TOTAL HUGE 0 0 ---- HUGE FREE 0 0 0% of TOTAL HUGE TOTAL SWAP 262143 1024 MB ---- SWAP USED 194 776 KB 0% of TOTAL SWAP SWAP FREE 261949 1023.2 MB 99% of TOTAL SWAP COMMIT LIMIT 739682 2.8 GB ---- COMMITTED 81647 318.9 MB 11% 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 7 TIME_WAIT 110 LISTEN 13 NAGLE disabled (TCP_NODELAY): 5 user_data set (NFS etc.): 8 UDP Connection Info ------------------- 15 UDP sockets, 0 in ESTABLISHED user_data set (NFS etc.): 4 Unix Connection Info ------------------------ ESTABLISHED 33 CLOSE 20 LISTEN 8 Raw sockets info -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 16016.8 eth0 n/a 0.0 RSS_TOTAL=124540 pages, %mem= 2.0 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff880137668700 ffff8800b6ce3000 sysfs sysfs /sys ffff8801376688c0 ffff880139944000 proc proc /proc ffff880137668a80 ffff880137678000 devtmpfs devtmpfs /dev ffff880137668c40 ffff88012b34f800 securityfs securityfs /sys/kernel/security ffff880137668e00 ffff8800b6ce3800 tmpfs tmpfs /dev/shm ffff880137668fc0 ffff88013771f000 devpts devpts /dev/pts ffff880137669180 ffff8800b6ce4000 tmpfs tmpfs /run ffff880137669340 ffff8800b6ce4800 tmpfs tmpfs /sys/fs/cgroup ffff880137669500 ffff8800b6ce5000 cgroup cgroup /sys/fs/cgroup/systemd ffff8801376696c0 ffff8800b6ce5800 pstore pstore /sys/fs/pstore ffff880137669880 ffff8800b6ce7800 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff880137669a40 ffff8800b6ce7000 cgroup cgroup /sys/fs/cgroup/freezer ffff880137669c00 ffff8800b6ce6800 cgroup cgroup /sys/fs/cgroup/devices ffff880137669dc0 ffff8800b6ce6000 cgroup cgroup /sys/fs/cgroup/memory ffff88012aa96000 ffff88012aae8000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012aa961c0 ffff88012aae8800 cgroup cgroup /sys/fs/cgroup/pids ffff88012aa96380 ffff88012aae9000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012aa96540 ffff88012aae9800 cgroup cgroup /sys/fs/cgroup/blkio ffff88012aa96700 ffff88012aaea000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012aa968c0 ffff88012aaea800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff880138ccb180 ffff8800b6ca5800 configfs configfs /sys/kernel/config ffff88012a51a1c0 ffff880137304800 ext4 /dev/nbd0 / ffff88012a51a380 ffff88012aaed800 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8801377f2700 ffff8800b6ca7800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff8800b63261c0 ffff880137678800 mqueue mqueue /dev/mqueue ffff88012a51a540 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff8800b6326380 ffff88012a5c8800 hugetlbfs hugetlbfs /dev/hugepages ffff8801377f28c0 ffff8800b6ca7000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8801377f2a80 ffff88012a5cb800 ramfs none /mnt ffff8800b6326540 ffff8800b5862000 tmpfs none /var/lib/stateless/writable ffff8800b6326700 ffff88012a5ca800 squashfs /dev/vda /home/green/git/lustre-release ffff88012a51a700 ffff8800b5862000 tmpfs none /var/cache/man ffff8800b6326a80 ffff8800b5862000 tmpfs none /var/log ffff8800b6326c40 ffff8800b5862000 tmpfs none /var/lib/dbus ffff8800b6326e00 ffff8800b5862000 tmpfs none /tmp ffff8800b6326fc0 ffff8800b5862000 tmpfs none /var/lib/dhclient ffff88012a51a8c0 ffff8800b5862000 tmpfs none /var/tmp ffff8800b6327180 ffff8800b5862000 tmpfs none /var/lib/NetworkManager ffff8800b6327340 ffff8800b5862000 tmpfs none /var/lib/systemd/random-seed ffff8800b6327500 ffff8800b5862000 tmpfs none /var/spool ffff88012a51aa80 ffff8800b5862000 tmpfs none /var/lib/nfs ffff8800b63276c0 ffff8800b5862000 tmpfs none /var/lib/gssproxy ffff8800b6327880 ffff8800b5862000 tmpfs none /var/lib/logrotate ffff88012a51ac40 ffff8800b5862000 tmpfs none /etc ffff8800b6327a40 ffff8800b5862000 tmpfs none /var/lib/rsyslog ffff8800b6327c00 ffff8800b5862000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8801377f2c40 ffff8800b5a5e800 nfs4 192.168.200.253:/exports/state/oleg301-client.virtnet /var/lib/stateless/state ffff88012a51b180 ffff8800b5a5e800 nfs4 192.168.200.253:/exports/state/oleg301-client.virtnet /boot ffff8800b6327dc0 ffff8800b5a5e800 nfs4 192.168.200.253:/exports/state/oleg301-client.virtnet /etc/etc/kdump.conf ffff88012a51b340 ffff88012aaed800 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b39f5dc0 ffff8800b5867800 nfs4 192.168.200.253://exports/testreports/51244/testresults/sanity2-ldiskfs-DNE-centos7_x86_64-centos7_x86_64 /tmp/tmp/testlogs ffff88012a5ac380 ffff8800b5863000 tmpfs tmpfs /run/user/0 ffff88012a5acfc0 ffff8800814c3800 nfsd nfsd /proc/fs/nfsd ffff8800b5ab4c40 ffff88012a5ca800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800b5ab4a80 ffff88012e5c7000 lustre 192.168.203.101@tcp:/lustre /mnt/lustre +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [15825.061843] Lustre: DEBUG MARKER: == sanity test 853: Verify that random fadvise works as expected ========================================================== 04:08:37 (1746086917) [15830.583096] Lustre: DEBUG MARKER: == sanity test 900: umount should not race with any mgc requeue thread ========================================================== 04:08:43 (1746086923) [15846.599908] LustreError: MGC192.168.203.101@tcp: Connection to MGS (at 192.168.203.101@tcp) was lost; in progress operations using this service will fail [15846.606958] Lustre: Evicted from MGS (at 192.168.203.101@tcp) after server handle changed from 0x2b3059ed71667fc9 to 0x2b3059ed7167bc20 [15846.616159] LustreError: 26684:0:(client.c:3262:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff88007e4bad80 x1830895874952320/t60129545171(60129545171) o101->lustre-MDT0000-mdc-ffff88012e5c7800@192.168.203.101@tcp:12/10 lens 520/664 e 0 to 0 dl 1746086994 ref 2 fl Interpret:RPQU/204/0 rc 301/301 job:'lfs.0' uid:0 gid:0 [15846.622432] LustreError: 26684:0:(client.c:3262:ptlrpc_replay_interpret()) Skipped 4 previous similar messages [15847.920865] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 sleeping for 20000ms [15851.249901] Lustre: DEBUG MARKER: oleg301-client.virtnet: executing wait_import_state_mount (FULL|IDLE) mdc.lustre-MDT0000-mdc-*.mds_server_uuid [15852.100899] Lustre: DEBUG MARKER: mdc.lustre-MDT0000-mdc-*.mds_server_uuid in FULL state after 0 sec [15867.922907] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 awake [15867.929564] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 sleeping for 20000ms [15887.930963] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 awake [15887.940099] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 sleeping for 20000ms [15887.941255] LustreError: 12927:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [15887.941257] LustreError: 12927:0:(obd_class.h:479:obd_check_dev()) Skipped 9 previous similar messages [15887.960911] Lustre: Unmounted lustre-client [15907.945943] LustreError: 4521:0:(mgc_request.c:1762:mgc_process_log()) cfs_fail_timeout id 903 awake [15907.950150] LustreError: 4521:0:(mgc_request.c:616:do_requeue()) failed processing log: -5 [15907.955252] LustreError: 12927:0:(obd_class.h:479:obd_check_dev()) Device 0 not setup [15907.956883] LustreError: 12927:0:(obd_class.h:479:obd_check_dev()) Skipped 7 previous similar messages [15944.826231] Key type lgssc unregistered [15944.917156] LNet: 13640:0:(lib-ptl.c:966:lnet_clear_lazy_portal()) Active lazy portal 0 on exit [15945.922259] LNet: Removed LNI 192.168.203.1@tcp [15949.220693] libcfs: HW NUMA nodes: 1, HW CPU cores: 4, npartitions: 2 [15949.224741] alg: No test for adler32 (adler32-zlib) [15950.132892] Lustre: Lustre: Build Version: 2.16.54_58_ga30b9d5 [15950.305140] LNet: Added LNI 192.168.203.1@tcp [8/256/0/180] [15950.307429] LNet: Accept secure, port 988 [15951.862951] Key type lgssc registered [15952.244741] Lustre: Echo OBD driver; http://www.lustre.org/ [15982.751081] Lustre: Mounted lustre-client [15984.821396] Lustre: DEBUG MARKER: Using TIMEOUT=20 [15992.579363] Lustre: DEBUG MARKER: == sanity test 901: don't leak a mgc lock on client umount ========================================================== 04:11:25 (1746087085) [15993.764176] LustreError: 17006:0:(obd_class.h:479:obd_check_dev()) Device 6 not setup [15993.783223] Lustre: Unmounted lustre-client [15993.883299] Lustre: Mounted lustre-client [15995.634630] Lustre: DEBUG MARKER: == sanity test 902: test short write doesn't hang lustre ========================================================== 04:11:28 (1746087088) [15995.712120] Lustre: *** cfs_fail_loc=2001415, val=0*** [15997.499556] Lustre: DEBUG MARKER: == sanity test 903: Test long page discard does not cause evictions ========================================================== 04:11:30 (1746087090) [16002.650261] LustreError: 17029:0:(osc_cache.c:3321:osc_page_gang_lookup()) cfs_fail_timeout id 417 sleeping for 20000ms ****************************************************************************** ************************ 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.47s (real) 5.89s (CPU), Child processes: 5.55s