[SOLVED] Proxmox random crash since update from 6.x to 7.x : Inserted module 'iscsi_tcp'

Post-it · Dec 8, 2021

Hello all,
All was working well with my cluster with the update 6.3-2
I have recently upgraded to 7.1-5 and since the upgrade, nodes are randomly crashing.
Everytime the node is crashing and reboots.

Each time of crash, the sequence of logs are beginning with :

Code:

"pve1 systemd-modules-load[1913]: Inserted module 'iscsi_tcp'"

Every time i see this line in my logs, my node crash and reboots.

What is "'iscsi_tcp'" ?
What is the program that runs and load this module ?

I attach to my question all crash and the first line of sequence crash.

I can post more details of my config if you need it.

Thanks to you in advance
Regards

My config :

Code:

pveversion -v
pveversion -v
proxmox-ve: 7.1-1 (running kernel: 5.13.19-1-pve)
pve-manager: 7.1-5 (running version: 7.1-5/6fe299a0)
pve-kernel-5.13: 7.1-4
pve-kernel-helper: 7.1-4
pve-kernel-5.11: 7.0-10
pve-kernel-5.4: 6.4-6
pve-kernel-5.13.19-1-pve: 5.13.19-2
pve-kernel-5.11.22-7-pve: 5.11.22-12
pve-kernel-5.11.22-4-pve: 5.11.22-9
pve-kernel-5.4.140-1-pve: 5.4.140-1
pve-kernel-5.4.128-1-pve: 5.4.128-2
pve-kernel-5.4.106-1-pve: 5.4.106-1
ceph-fuse: 14.2.21-1
corosync: 3.1.5-pve2
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown: 0.8.36+pve1
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-1
libknet1: 1.22-pve2
libproxmox-acme-perl: 1.4.0
libproxmox-backup-qemu0: 1.2.0-1
libpve-access-control: 7.1-2
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.0-14
libpve-guest-common-perl: 4.0-3
libpve-http-server-perl: 4.0-3
libpve-storage-perl: 7.0-15
libqb0: 1.0.5-1
libspice-server1: 0.14.3-2.1
lvm2: 2.03.11-2.1
lxc-pve: 4.0.9-4
lxcfs: 4.0.8-pve2
novnc-pve: 1.2.0-3
proxmox-backup-client: 2.0.14-1
proxmox-backup-file-restore: 2.0.14-1
proxmox-mini-journalreader: 1.2-1
proxmox-widget-toolkit: 3.4-2
pve-cluster: 7.1-2
pve-container: 4.1-2
pve-docs: 7.1-2
pve-edk2-firmware: 3.20210831-2
pve-firewall: 4.2-5
pve-firmware: 3.3-3
pve-ha-manager: 3.3-1
pve-i18n: 2.6-1
pve-qemu-kvm: 6.1.0-2
pve-xtermjs: 4.12.0-1
qemu-server: 7.1-3
smartmontools: 7.2-pve2
spiceterm: 3.2-2
swtpm: 0.7.0~rc1+2
vncterm: 1.7-1
zfsutils-linux: 2.1.1-pve3

oguz · Dec 20, 2021

hi,

do you find a kernel trace in the logs after the crash (check dmesg)?
errors in journalctl?
please post those as well. (hint: you can use [code][/code] tags)

Post-it said:
What is "'iscsi_tcp'" ?
What is the program that runs and load this module ?

it's the kernel module needed to support ISCSI [0], but the problem maybe something else, hard to tell without seeing the logs

[0]: https://pve.proxmox.com/wiki/Storage:_iSCSI

Post-it · Jan 3, 2022

Hi Oguz,

Thanks for your reply and i wish you to have a happy new year !
Yes sorry for no posting all logs, because when it happens, logs was very big.
Finally, i have found and fixed the problem. The problem was comming from the loading of the module iscsi_tcp.
To fix it i have disabled the loading of this module
I have edited the file :

Code:

/lib/modules-load.d/open-iscsi.conf

And commented the two lines (to be sure to fix the problem) :

Code:

#iscsi_tcp
#ib_iser

And then restarted the service with :

Code:

systemctl restart systemd-modules-load.service

And checked that the service is running with :

Code:

systemctl status systemd-modules-load.service

Since this correction, all is running well with replication of nodes since 3 weeks

oguz · Jan 3, 2022

thanks for sharing your workaround and happy new year to you as well... unloading the module fixes the problem but not the underlying issue.

if everything is working fine then i guess you don't need this module (you'd need it if you used an iSCSI storage).

it would be still interesting to see some logs to get to the bottom of the issue

Post-it · Jan 6, 2022

Yes i have actually no iSCSI Storage, here is a typical log that i have caught. Sometimes the crash happens directly after "Inserted module 'iscsi_tcp'" and sometimes it works a few microseconds later and crash (like in this case) :

Code:

Dec  6 11:56:09 pve0 pvescheduler[1887656]: send/receive failed, cleaning up snapshot(s)..
    Dec  6 11:56:09 pve0 pvescheduler[1887656]: 118-0: got unexpected replication job error - command 'set -o pipefail && pvesm export local-zfs:vm-118-disk-0 zfs - -with-snapshots 1 -snapshot __replicate_118-0_1638788166__ | /usr/bin/ssh -e none -o 'BatchMode=yes' -o 'HostKeyAlias=pve1' root@192.168.100.253 -- pvesm import local-zfs:vm-118-disk-0 zfs - -with-snapshots 1 -snapshot __replicate_118-0_1638788166__ -allow-rename 0' failed: exit code 255
    Dec  6 11:59:03 pve0 systemd[1]: Started Session 3300 of user root.
    Dec  6 11:59:04 pve0 systemd[1]: session-3300.scope: Succeeded.
    Dec  6 11:59:04 pve0 systemd[1]: Started Session 3301 of user root.
    Dec  6 11:59:04 pve0 systemd[1]: session-3301.scope: Succeeded.
    Dec  6 11:59:05 pve0 systemd[1]: Started Session 3302 of user root.
    Dec  6 11:59:06 pve0 systemd[1]: session-3302.scope: Succeeded.
    Dec  6 11:59:06 pve0 systemd[1]: Started Session 3303 of user root.
    Dec  6 11:59:07 pve0 systemd[1]: session-3303.scope: Succeeded.
    Dec  6 12:03:18 pve0 pmxcfs[4068]: [status] notice: received log
    Dec  6 12:03:31 pve0 pmxcfs[4068]: [dcdb] notice: data verification successful
    Dec  6 12:04:58 pve0 systemd-modules-load[2046]: Inserted module 'iscsi_tcp'
    Dec  6 12:04:58 pve0 systemd-modules-load[2046]: Inserted module 'ib_iser'
    Dec  6 12:04:58 pve0 systemd-modules-load[2046]: Inserted module 'vhost_net'
    Dec  6 12:04:58 pve0 systemd[1]: Starting Flush Journal to Persistent Storage...
    Dec  6 12:04:58 pve0 systemd[1]: Finished Coldplug All udev Devices.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Helper to synchronize boot up for ifupdown...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Wait for udev To Complete Device Initialization...
    Dec  6 12:04:58 pve0 systemd-udevd[2155]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2130]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2141]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2141]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd-udevd[2130]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd-udevd[2155]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd-udevd[2129]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2134]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2129]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd-udevd[2134]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Flush Journal to Persistent Storage.
    Dec  6 12:04:58 pve0 systemd-udevd[2131]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 udevadm[2170]: systemd-udev-settle.service is deprecated. Please fix zfs-import-cache.service not to pull it in.
    Dec  6 12:04:58 pve0 systemd[1]: Created slice system-lvm2\x2dpvscan.slice.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target Sound Card.
    Dec  6 12:04:58 pve0 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
    Dec  6 12:04:58 pve0 systemd[1]: Starting LVM event activation on device 230:162...
    Dec  6 12:04:58 pve0 lvm[2647]:   pvscan[2647] /dev/zd160p2 excluded by filters: device is rejected by filter config.
    Dec  6 12:04:58 pve0 systemd[1]: Finished LVM event activation on device 230:162.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Helper to synchronize boot up for ifupdown.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Wait for udev To Complete Device Initialization.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Import ZFS pools by cache file...
    Dec  6 12:04:58 pve0 systemd[1]: Finished Import ZFS pools by cache file.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target ZFS pool import target.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Mount ZFS filesystems...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Wait for ZFS Volume (zvol) links in /dev...
    Dec  6 12:04:58 pve0 zvol_wait[3424]: Testing 18 zvol links
    Dec  6 12:04:58 pve0 zvol_wait[3424]: All zvol links are now present.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Wait for ZFS Volume (zvol) links in /dev.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target ZFS volumes are ready.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Mount ZFS filesystems.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target Local File Systems.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Load AppArmor profiles...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Set console font and keymap...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Preprocess NFS configuration...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Proxmox VE Login Banner...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Proxmox VE firewall logger...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Commit Proxmox VE network changes...
    Dec  6 12:04:58 pve0 systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
    Dec  6 12:04:58 pve0 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Create Volatile Files and Directories...
    Dec  6 12:04:58 pve0 systemd[1]: nfs-config.service: Succeeded.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Preprocess NFS configuration.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Set console font and keymap.
    Dec  6 12:04:58 pve0 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
    Dec  6 12:04:58 pve0 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target NFS client services.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Commit Proxmox VE network changes.
    Dec  6 12:04:58 pve0 apparmor.systemd[3656]: Restarting AppArmor
    Dec  6 12:04:58 pve0 apparmor.systemd[3656]: Reloading AppArmor profiles
    Dec  6 12:04:58 pve0 systemd[1]: Finished Create Volatile Files and Directories.
    Dec  6 12:04:58 pve0 systemd[1]: Starting RPC bind portmap service...
    Dec  6 12:04:58 pve0 pvefw-logger[3689]: starting pvefw logger
    Dec  6 12:04:58 pve0 systemd[1]: Starting Network Time Synchronization...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Update UTMP about System Boot/Shutdown...
    Dec  6 12:04:58 pve0 systemd[1]: Started Proxmox VE firewall logger.
    Dec  6 12:04:58 pve0 systemd[1]: Started RPC bind portmap service.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target RPC Port Mapper.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Update UTMP about System Boot/Shutdown.
    Dec  6 12:04:58 pve0 systemd[1]: Finished Load AppArmor profiles.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Raise network interfaces...
    Dec  6 12:04:58 pve0 systemd-udevd[2158]: Using default interface naming scheme 'v247'.
    Dec  6 12:04:58 pve0 systemd-udevd[2158]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
    Dec  6 12:04:58 pve0 systemd[1]: Started Network Time Synchronization.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target System Initialization.
    Dec  6 12:04:58 pve0 systemd[1]: Started Daily Cleanup of Temporary Directories.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target System Time Set.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target System Time Synchronized.
    Dec  6 12:04:58 pve0 systemd[1]: Started Daily apt download activities.
    Dec  6 12:04:58 pve0 systemd[1]: Started Daily apt upgrade and clean activities.
    Dec  6 12:04:58 pve0 systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.
    Dec  6 12:04:58 pve0 systemd[1]: Started Daily rotation of log files.
    Dec  6 12:04:58 pve0 systemd[1]: Started Daily man-db regeneration.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target Timers.
    Dec  6 12:04:58 pve0 systemd[1]: Listening on D-Bus System Message Bus Socket.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target Sockets.
    Dec  6 12:04:58 pve0 systemd[1]: Reached target Basic System.
    Dec  6 12:04:58 pve0 systemd[1]: Started D-Bus System Message Bus.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Remove Stale Online ext4 Metadata Check Snapshots...
    Dec  6 12:04:58 pve0 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Kernel Samepage Merging (KSM) Tuning Daemon...
    Dec  6 12:04:58 pve0 systemd[1]: Started Enclosure LED Utilities.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Initialize hardware monitoring sensors...
    Dec  6 12:04:58 pve0 systemd[1]: Started FUSE filesystem for LXC.
    Dec  6 12:04:58 pve0 systemd[1]: Starting Proxmox VE LXC Syscall Daemon...
    Dec  6 12:04:58 pve0 systemd[1]: Starting PVE Qemu Event Daemon...
    Dec  6 12:04:58 pve0 systemd[1]: Starting System Logging Service...
    Dec  6 12:04:58 pve0 systemd[1]: Starting Self Monitoring and Reporting Technology (SMART) Daemon...
    Dec  6 12:04:58 pve0 systemd[1]: Starting User Login Management...
    Dec  6 12:04:58 pve0 systemd[1]: Started Proxmox VE watchdog multiplexer.
    Dec  6 12:04:58 pve0 lxcfs[3744]: Running constructor lxcfs_init to reload liblxcfs
    Dec  6 12:04:58 pve0 systemd[1]: Starting ZFS file system shares...
    Dec  6 12:04:58 pve0 systemd[1]: Started ZFS Event Daemon (zed).
    Dec  6 12:04:58 pve0 lxcfs[3744]: mount namespace: 5
    Dec  6 12:04:58 pve0 lxcfs[3744]: hierarchies:
    Dec  6 12:04:58 pve0 lxcfs[3744]:   0: fd:   6: cpuset,cpu,io,memory,hugetlb,pids,rdma,misc
    Dec  6 12:04:58 pve0 lxcfs[3744]: Kernel supports pidfds
    Dec  6 12:04:58 pve0 lxcfs[3744]: api_extensions:
    Dec  6 12:04:58 pve0 lxcfs[3744]: - cgroups
    Dec  6 12:04:58 pve0 lxcfs[3744]: - sys_cpu_online
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_cpuinfo
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_diskstats
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_loadavg
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_meminfo
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_stat
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_swaps
    Dec  6 12:04:58 pve0 lxcfs[3744]: - proc_uptime
    Dec  6 12:04:58 pve0 lxcfs[3744]: - shared_pidns
    Dec  6 12:04:58 pve0 lxcfs[3744]: - cpuview_daemon
    Dec  6 12:04:58 pve0 lxcfs[3744]: - loadavg_daemon
    Dec  6 12:04:58 pve0 lxcfs[3744]: - pidfds
    Dec  6 12:04:58 pve0 systemd[1]: Started Proxmox VE LXC Syscall Daemon.
    Dec  6 12:04:58 pve0 systemd[1]: Started PVE Qemu Event Daemon.
    Dec  6 12:04:58 pve0 watchdog-mux[3760]: Watchdog driver 'Software Watchdog', version 0
    Dec  6 12:04:58 pve0 sensors[3777]: radeon-pci-0100
    Dec  6 12:04:58 pve0 sensors[3777]: Adapter: PCI adapter
    Dec  6 12:04:58 pve0 sensors[3777]: temp1:        +53.0°C  (crit = +120.0°C, hyst = +90.0°C)
    Dec  6 12:04:58 pve0 sensors[3777]: k10temp-pci-00c3
    Dec  6 12:04:58 pve0 sensors[3777]: Adapter: PCI adapter
    Dec  6 12:04:58 pve0 sensors[3777]: temp1:        +53.5°C  (high = +70.0°C)
    Dec  6 12:04:58 pve0 sensors[3777]:                        (crit = +80.0°C, hyst = +77.0°C)
    Dec  6 12:04:58 pve0 sensors[3777]: fam15h_power-pci-00c4
    Dec  6 12:04:58 pve0 sensors[3777]: Adapter: PCI adapter
    Dec  6 12:04:58 pve0 sensors[3777]: power1:      124.74 W  (crit = 125.19 W)
    Dec  6 12:04:58 pve0 systemd[1]: Finished Initialize hardware monitoring sensors.
    Dec  6 12:04:58 pve0 systemd[1]: Started Kernel Samepage Merging (KSM) Tuning Daemon.
    Dec  6 12:04:58 pve0 zed[3765]: ZFS Event Daemon 2.1.1-pve3 (PID 3765)
    Dec  6 12:04:58 pve0 zed[3765]: Processing events since eid=0
    Dec  6 12:04:58 pve0 dbus-daemon[3739]: [system] AppArmor D-Bus mediation is enabled
    Dec  6 12:04:58 pve0 systemd[1]: Started System Logging Service.
    Dec  6 12:04:58 pve0 rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.2102.0]
    Dec  6 12:04:58 pve0 rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="3750" x-info="https://www.rsyslog.com"] start
Dec  6 12:04:58 pve0 kernel: [    0.000000] Linux version -------------------------> CRASH LINE NODE REBOOT

jan_ysp · Mar 19, 2022

We also see this problem while we do not use any iscsi, it's always triggered when a vm config is changed or created:

Code:

Mar 18 19:15:20 pve1 systemd-modules-load[32221]: Inserted module 'iscsi_tcp'
Mar 18 19:15:20 pve1 kernel: [    0.000000] Linux version 5.0.21-2-pve (build@pve) (gcc version 8.3.0 (Debian 8.3.0-6)) #1 SMP PVE 5.0.21-3 (Thu, 05 Sep 2019 13:56:01 +0200) ()

Asimov6 · Oct 11, 2022

I also have had crashes with the same message in syslog. Happens every three weeks or so. I now also commented the lines in open-iscsi.conf.

Search

Search

[SOLVED] Proxmox random crash since update from 6.x to 7.x : Inserted module 'iscsi_tcp'

Post-it

New Member

Attachments

oguz

Proxmox Retired Staff

Post-it

New Member

oguz

Proxmox Retired Staff

Post-it

New Member

jan_ysp

New Member

Asimov6

New Member