Freeze during heavy file transferral

Ask Fedora
, , , ,
1

So, twice today my f37 machine has frozen up, pretty much as described in this post, by @childishgiant.

Only, I have been moving files from a Windows laptop over to a fedora 37 machine, using PSFTP of the PuTTY set. A couple of hours into the transfer of a 100+GB file I have found fedora completely unresponsive, with PuTTY on the Win machine having spat out the following:

FATAL ERROR: Network error: Software caused connection abort

I will need to become more familiar with logging in fedora, but I managed to bring forth the following error messages through journalctl:

Mar 09 12:45:51 fedora kernel: x86/cpu: VMX (outside TXT) disabled by BIOS
Mar 09 12:45:51 fedora kernel: x86/cpu: SGX disabled by BIOS.
Mar 09 12:45:51 fedora kernel: tpm_crb MSFT0101:00: [Firmware Bug]: ACPI region does not cover the entire command/response buffer. [mem 0xfed40000-0xfed4087f flags 0x200] vs fed40080 f80
Mar 09 12:45:51 fedora kernel: tpm_crb MSFT0101:00: [Firmware Bug]: ACPI region does not cover the entire command/response buffer. [mem 0xfed40000-0xfed4087f flags 0x200] vs fed40080 f80
Mar 09 12:46:14 fedora systemd-gpt-auto-generator[821]: Failed to dissect: Permission denied
Mar 09 12:46:14 fedora (sd-executor)[806]: /usr/lib/systemd/system-generators/systemd-gpt-auto-generator failed with exit status 1.

That is around the time the freeze must have occurred as well.

Here’s some sysinfo, and I have the dump saved in case there’s something transient in there I might include here later.

2

I think the above psftp message just indicates a dropped connection, not necessarily a crash. Dropped wifi connections can be due to external factors outside your control, but Realtek wifi adapters do have a reputation for dropping connections. Ethernet is more robust. For large file transfers your best solution might be a cheap ethernet cable.

The error messages you posted appear to be from a normal boot. Firmware bugs should be investigated, but many are not problems that would cause a crash.

2 Likes
3

In particular, this bug has to do with the TPM module, which is unlikely to be related to anything here. (If you want to get rid of it, it’s possible that updating your motherboard firmware will help.)

The other two bios warnings are features features you may be able to turn on or off in the bios — and again, unrelated here.

1 Like
4

Thank you both for replying.

I had trouble looking through the journals previously, but I think one of two bad cables is the most probable cause of these crashes, of which I had a third one this morning.

These are the last ones before the crash:

Mar 10 09:44:11 fedora kernel: usb 1-6: device not accepting address 37, error -71
Mar 10 09:44:11 fedora kernel: usb 1-6: new full-speed USB device number 38 using xhci_hcd
Mar 10 09:44:11 fedora kernel: usb 1-6: Device not responding to setup address.
Mar 10 09:44:11 fedora kernel: usb 1-6: Device not responding to setup address.
Mar 10 09:44:11 fedora kernel: usb 1-6: device not accepting address 38, error -71
Mar 10 09:44:11 fedora kernel: usb usb1-port6: unable to enumerate USB device
Mar 10 09:49:56 fedora kernel: e1000e 0000:00:1f.6 enp0s31f6: NIC Link is Down

But I also found these:

Mar 10 09:17:12 fedora kernel: usb usb1-port6: Cannot enable. Maybe the USB cable is bad?
Mar 10 09:17:13 fedora kernel: usb usb1-port6: Cannot enable. Maybe the USB cable is bad?

The aforepasted ones had been going on a lot all morning, excluding the very last ‘enp0s31f6’ message.

5
1 Like
6

Oh, I just realized, I’ve had auto-suspend off through all of this because of a separate issue I’ve been having with it. The refusal of the machine to reawaken out of the suspended state that I’ve seen pop up on here recently too.

My fedora machine has also refused to turn off completely rather often, which I’ve thought about bringing up on here as well.

Also, I’ve been messing about with hardware and cables all this morning in particular. I definitely have two bad ones, or one bad cable and one bad female connector.

1 Like
7

At this point I’m mainly trying this same procedure over again to have it be a learning experience.

I tried the transfer again this morning and experienced another crash within an hour so. I was not using the bad wires and stuff.

During each transferal attempt I have been checking for progress every so often, up until I’ve noticed the crash. Every time I have checked, progress has been made.

The following are the ends of the logs where I had a crash . I don’t know why the pre-formatted text comes out all pink on my end.

First Crash

Mar 09 12:26:57 fedora systemd[1]: Started systemd-hostnamed.service - Hostname Service.
Mar 09 12:26:57 fedora audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm=
Mar 09 12:27:01 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.freedesktop.Tracker3.Miner.Files' requested by ':1.10' (uid=
Mar 09 12:27:01 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.Daemon' requested by ':1.11' (uid=0 pid=23733 comm="
Mar 09 12:27:01 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.Daemon'
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &DOCUMENTS. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &MUSIC. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &PICTURES. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &VIDEOS. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &DOWNLOAD. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &DOCUMENTS. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &MUSIC. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &PICTURES. Ignoring this location.
Mar 09 12:27:01 fedora tracker-miner-f[23733]: Unable to get XDG user directory path for special directory &VIDEOS. Ignoring this location.
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.UDisks2VolumeMonitor' requested by ':1.11' (uid=0 pi
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.MTPVolumeMonitor' requested by ':1.11' (uid=0 pid=23
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.GPhoto2VolumeMonitor' requested by ':1.11' (uid=0 pi
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.AfcVolumeMonitor' requested by ':1.11' (uid=0 pid=23
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gtk.vfs.GoaVolumeMonitor' requested by ':1.11' (uid=0 pid=23
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gnome.OnlineAccounts' requested by ':1.18' (uid=0 pid=23775 
Mar 09 12:27:02 fedora goa-daemon[23779]: goa-daemon version 3.46.0 starting
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='org.gnome.Identity' requested by ':1.19' (uid=0 pid=23779 comm="
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gnome.OnlineAccounts'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Mar 09 12:27:02 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.gnome.Identity'
Mar 09 12:27:02 fedora goa-identity-se[23788]: GoaKerberosIdentityManager: Using polling for change notification for credential cache type 'KCM'
Mar 09 12:27:03 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'org.freedesktop.Tracker3.Miner.Files'
Mar 09 12:27:07 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Activating service name='ca.desrt.dconf' requested by ':1.10' (uid=0 pid=23661 comm="emac
Mar 09 12:27:07 fedora dbus-daemon[4684]: [session uid=0 pid=4682] Successfully activated service 'ca.desrt.dconf'
Mar 09 12:27:27 fedora systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Mar 09 12:27:27 fedora audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="
Mar 09 12:27:27 fedora audit: BPF prog-id=126 op=UNLOAD
Mar 09 12:27:27 fedora audit: BPF prog-id=125 op=UNLOAD
Mar 09 12:27:27 fedora audit: BPF prog-id=124 op=UNLOAD

Don’t know what to make of the fedora tracker-miner-f[23733]: and the goa-identity-se[23788]: one.

Second Crash

Mar 09 19:35:10 fedora cupsd[1314]: REQUEST localhost - - "POST / HTTP/1.1" 200 189 Renew-Subscription successful-ok
Mar 09 19:38:23 fedora audit[8083]: CRYPTO_SESSION pid=8083 uid=0 auid=1000 ses=5 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from-
Mar 09 19:38:23 fedora audit[8083]: CRYPTO_SESSION pid=8083 uid=0 auid=1000 ses=5 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from-
Mar 09 19:38:23 fedora audit[8083]: CRYPTO_KEY_USER pid=8083 uid=0 auid=1000 ses=5 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=session
Mar 09 19:38:23 fedora audit[8083]: CRYPTO_KEY_USER pid=8083 uid=0 auid=1000 ses=5 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=session
Mar 09 19:38:25 fedora systemd[2041]: Starting tracker-extract-3.service - Tracker metadata extractor...
Mar 09 19:38:26 fedora systemd[2041]: Started tracker-extract-3.service - Tracker metadata extractor.

There’s a lot of systemd[2041]: Starting tracker-extract-3.service going on some ten minutes before, and earlier. And also this `Mar 09 19:23:00 fedora NetworkManager[1307]: [1678386180.3544] dhcp4 (wlp3s0): state changed new lease, address=192.168.35.21

Third Crash

Mar 10 09:49:50 fedora NetworkManager[2043]: <info>  [1678438190.8092] device (enp0s31f6): state change: prepare  config (reason 'none', sys-iface-state: 
Mar 10 09:49:50 fedora audit[2023]: NETFILTER_CFG table=firewalld:206 family=1 entries=6 op=nft_register_rule pid=2023 subj=system_u:system_r:firewalld_t:s0
Mar 10 09:49:50 fedora NetworkManager[2043]:   [1678438190.8177] device (enp0s31f6): state change: config -> ip-config (reason 'none', sys-iface-state
Mar 10 09:49:50 fedora NetworkManager[2043]:   [1678438190.8184] dhcp4 (enp0s31f6): activation: beginning transaction (timeout in 45 seconds)
Mar 10 09:49:50 fedora avahi-daemon[1924]: Joining mDNS multicast group on interface enp0s31f6.IPv6 with address fe80::50b1:91c6:c217:224.
Mar 10 09:49:50 fedora avahi-daemon[1924]: New relevant interface enp0s31f6.IPv6 for mDNS.
Mar 10 09:49:50 fedora avahi-daemon[1924]: Registering new address record for fe80::50b1:91c6:c217:224 on enp0s31f6.*.
Mar 10 09:49:56 fedora kernel: e1000e 0000:00:1f.6 enp0s31f6: NIC Link is Down
Mar 10 09:49:58 fedora Tor[8713]: Failed to find node for hop #1 of our path. Discarding this circuit.
Mar 10 09:50:02 fedora NetworkManager[2043]: <info>  [1678438202.6904] device (enp0s31f6): state change: ip-config - unavailable (reason 'carrier-changed',
Mar 10 09:50:02 fedora NetworkManager[2043]: <info>  [1678438202.6964] dhcp4 (enp0s31f6): canceled DHCP transaction
Mar 10 09:50:02 fedora NetworkManager[2043]: <info>  [1678438202.6964] dhcp4 (enp0s31f6): state changed no lease
Mar 10 09:50:02 fedora avahi-daemon[1924]: Withdrawing address record for fe80::50b1:91c6:c217:224 on enp0s31f6.
Mar 10 09:50:02 fedora avahi-daemon[1924]: Leaving mDNS multicast group on interface enp0s31f6.IPv6 with address fe80::50b1:91c6:c217:224.
Mar 10 09:50:02 fedora avahi-daemon[1924]: Interface enp0s31f6.IPv6 no longer relevant for mDNS.
Mar 10 09:50:02 fedora audit[2023]: NETFILTER_CFG table=firewalld:207 family=1 entries=6 op=nft_unregister_rule pid=2023 subj=system_u:system_r:firewalld_t:
Mar 10 09:50:02 fedora NetworkManager[2043]: <info>  [1678438202.6974] manager: NetworkManager state is now DISCONNECTED
Mar 10 09:50:10 fedora NetworkManager[2043]: <info>  [1678438210.1874] device (wlp3s0): set-hw-addr: set MAC address to F2:BD:B9:8F:EA:08 (scanning)
Mar 10 09:50:10 fedora NetworkManager[2043]: <info>  [1678438210.5568] device (wlp3s0): supplicant interface state: inactive -> interface_disabled
Mar 10 09:50:10 fedora NetworkManager[2043]: <info>  [1678438210.5568] device (p2p-dev-wlp3s0): supplicant management interface state: inactive -> interface
Mar 10 09:50:10 fedora NetworkManager[2043]: <info>  [1678438210.5629] device (wlp3s0): supplicant interface state: interface_disabled -> inactive
Mar 10 09:50:10 fedora NetworkManager[2043]: <info>  [1678438210.5629] device (p2p-dev-wlp3s0): supplicant management interface state: interface_disabled 
Mar 10 09:50:57 fedora Tor[8713]: Failed to find node for hop #1 of our path. Discarding this circuit.

So, simply network card giving out? That of course seemed likely earlier, though I myself can’t be super sure about much of any of this. This one has all the usb: warnings shortly before.

Fourth Crash

Mar 11 12:03:15 fedora systemd[2032]: Started tracker-extract-3.service - Tracker metadata extractor.
Mar 11 12:07:26 fedora audit[6067]: CRYPTO_SESSION pid=6067 uid=0 auid=1000 ses=4 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from
Mar 11 12:07:26 fedora audit[6067]: CRYPTO_SESSION pid=6067 uid=0 auid=1000 ses=4 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start direction=from
Mar 11 12:07:26 fedora audit[6067]: CRYPTO_KEY_USER pid=6067 uid=0 auid=1000 ses=4 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=session
Mar 11 12:07:26 fedora audit[6067]: CRYPTO_KEY_USER pid=6067 uid=0 auid=1000 ses=4 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=session
Mar 11 12:07:52 fedora NetworkManager[1298]: <info>  [1678532872.7332] dhcp4 (wlp3s0): state changed new lease, address=192.168.48.21

No kernel messages at the end of that one, but there were a bunch more CRYPTO_SESSION stuff along with many bunches of systemd[2032]: Started tracker-extract-3.service starting hours back.

I’ll be looking more into the details, but there it is, in case anyone’s got something they’d like to point out or ask about in the meantime.

Hopefully you won’t need to see all the cut-off messages.