You are not logged in.

#1 2021-08-18 23:44:25

aleksF
Member
Registered: 2019-03-09
Posts: 19

Random freezes. What does journalctl tells me here?

Hello,

I have Arch on my DELL XPS 13 2 in 1 9310.

CPU: 11th Gen Intel® Core™ i7-1165G7 @ 2.80GHz × 8
Graphics: Mesa Intel® Xe Graphics (TGL GT2)
Current Kernel: Arch stock kernel 5.13.10

The system totally freezes at random moments, when on battery power.Maybe once a day.
I used xorg/i3, recently switched to gnome wayland to test if it would improve things. Seems a bit more stable.

Sometimes I got a blinking caps lock (hence I suppose it is a kernel panic), sometimes I don't.

Last crash I had on wayland/gnome 40, and I could move the pointer.
Could not switch TTY.

Before last crash happened, I got this in journalctl (output truncated, below). I had left my laptop unplugged, lid closed for two hours, then at 6:24 pm I had opened the lid (as you can see in the first line of the log) and after a minute it froze.


Aug 18 18:24:52 arcticfox systemd-logind[812]: Lid opened.
Aug 18 18:24:52 arcticfox systemd-sleep[11184]: System returned from sleep state.
Aug 18 18:24:52 arcticfox kernel: PM: suspend exit
Aug 18 18:24:53 arcticfox systemd[1]: systemd-suspend.service: Deactivated successfully.
Aug 18 18:24:53 arcticfox systemd[1]: Finished System Suspend.
Aug 18 18:24:53 arcticfox audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/s>
Aug 18 18:24:53 arcticfox audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/sy>
Aug 18 18:24:53 arcticfox systemd[1]: Stopped target Sleep.
Aug 18 18:24:53 arcticfox systemd[1]: Reached target Suspend.
Aug 18 18:24:53 arcticfox systemd[1]: Stopped target Suspend.
Aug 18 18:24:53 arcticfox systemd-logind[812]: Operation 'sleep' finished.
Aug 18 18:24:53 arcticfox kernel: audit: type=1130 audit(1629325493.020:204): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="syst>
Aug 18 18:24:53 arcticfox kernel: audit: type=1131 audit(1629325493.020:205): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="syst>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0263] manager: sleep: wake requested (sleeping: yes  enabled: yes)
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0264] device (wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', sys-if>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0276] device (p2p-dev-wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed'>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0282] manager: NetworkManager state is now DISCONNECTED
Aug 18 18:24:53 arcticfox wpa_supplicant[934]: nl80211: kernel reports: Attribute failed policy validation
Aug 18 18:24:53 arcticfox wpa_supplicant[934]: Failed to create interface p2p-dev-wlp0s20f3: -22 (Invalid argument)
Aug 18 18:24:53 arcticfox wpa_supplicant[934]: nl80211: Failed to create a P2P Device interface p2p-dev-wlp0s20f3
Aug 18 18:24:53 arcticfox wpa_supplicant[934]: P2P: Failed to enable P2P Device interface
Aug 18 18:24:53 arcticfox wpa_supplicant[934]: dbus: fill_dict_with_properties dbus_interface=fi.w1.wpa_supplicant1.Interface.P2PDevice dbus_property=P2PDevi>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0769] device (wlp0s20f3): supplicant interface state: internal-starting -> disconnected
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0769] device (p2p-dev-wlp0s20f3): state change: unavailable -> unmanaged (reason 'removed'>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0775] Wi-Fi P2P device controlled by interface wlp0s20f3 created
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0780] manager: (p2p-dev-wlp0s20f3): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkM>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0783] device (p2p-dev-wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed'>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0792] device (wlp0s20f3): state change: unavailable -> disconnected (reason 'supplicant-av>
Aug 18 18:24:53 arcticfox NetworkManager[805]: <info>  [1629325493.0802] device (p2p-dev-wlp0s20f3): state change: unavailable -> disconnected (reason 'none'>
Aug 18 18:24:53 arcticfox kernel: mmc0: cannot verify signal voltage switch
Aug 18 18:24:53 arcticfox gsd-media-keys[4150]: [4150:10436:0818/182453.978506:ERROR:get_updates_processor.cc(257)] PostClientToServerMessage() failed during>
Aug 18 18:24:55 arcticfox systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Aug 18 18:24:55 arcticfox audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/>
Aug 18 18:24:55 arcticfox kernel: audit: type=1131 audit(1629325495.913:206): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher >
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=US
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.3991] policy: auto-activating connection 'JazzThang' (6e9685e5-22f3-47b4-86a7-2d8fa798dc7f)
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.3996] device (wlp0s20f3): Activation: starting connection 'JazzThang' (6e9685e5-22f3-47b4->
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.3998] device (wlp0s20f3): state change: disconnected -> prepare (reason 'none', sys-iface->
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4002] manager: NetworkManager state is now CONNECTING
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4006] device (wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state:>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4009] device (wlp0s20f3): Activation: (wifi) access point 'JazzThang' has security, but se>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4009] device (wlp0s20f3): state change: config -> need-auth (reason 'none', sys-iface-stat>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4011] sup-iface[5b4dc2f0b66e8ffd,3,wlp0s20f3]: wps: type pbc start...
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4027] device (wlp0s20f3): state change: need-auth -> prepare (reason 'none', sys-iface-sta>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4029] device (wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state:>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4030] device (wlp0s20f3): Activation: (wifi) connection 'JazzThang' has security, and secr>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'ssid' value 'JazzThang'
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'scan_ssid' value '1'
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'bgscan' value 'simple:30:-70:86400'
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK'
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'auth_alg' value 'OPEN'
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4031] Config: added 'psk' value '<hidden>'
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: SME: Trying to authenticate with d4:5d:64:a3:c0:20 (SSID='JazzThang' freq=2447 MHz)
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: authenticate with d4:5d:64:a3:c0:20
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: send auth to d4:5d:64:a3:c0:20 (try 1/3)
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4156] device (wlp0s20f3): supplicant interface state: disconnected -> authenticating
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4157] device (p2p-dev-wlp0s20f3): supplicant management interface state: disconnected -> a>
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: Trying to associate with d4:5d:64:a3:c0:20 (SSID='JazzThang' freq=2447 MHz)
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4408] device (wlp0s20f3): supplicant interface state: authenticating -> associating
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4409] device (p2p-dev-wlp0s20f3): supplicant management interface state: authenticating ->>
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: authenticated
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: associate with d4:5d:64:a3:c0:20 (try 1/3)
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: RX AssocResp from d4:5d:64:a3:c0:20 (capab=0x1411 status=0 aid=38)
Aug 18 18:24:56 arcticfox kernel: iwlwifi 0000:00:14.3: Got NSS = 4 - trimming to 2
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: Associated with d4:5d:64:a3:c0:20
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: associated
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4674] device (wlp0s20f3): supplicant interface state: associating -> 4way_handshake
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.4674] device (p2p-dev-wlp0s20f3): supplicant management interface state: associating -> 4w>
Aug 18 18:24:56 arcticfox kernel: wlp0s20f3: Limiting TX power to 30 (30 - 0) dBm as advertised by d4:5d:64:a3:c0:20
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: WPA: Key negotiation completed with d4:5d:64:a3:c0:20 [PTK=CCMP GTK=CCMP]
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: CTRL-EVENT-CONNECTED - Connection to d4:5d:64:a3:c0:20 completed [id=0 id_str=]
Aug 18 18:24:56 arcticfox kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f3: link becomes ready
Aug 18 18:24:56 arcticfox wpa_supplicant[934]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-30 noise=9999 txrate=58500
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6085] device (wlp0s20f3): supplicant interface state: 4way_handshake -> completed
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6086] device (wlp0s20f3): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. C>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6086] device (p2p-dev-wlp0s20f3): supplicant management interface state: 4way_handshake ->>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6088] device (wlp0s20f3): state change: config -> ip-config (reason 'none', sys-iface-stat>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6094] dhcp4 (wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6338] dhcp4 (wlp0s20f3): state changed unknown -> bound, address=192.168.50.247
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6360] device (wlp0s20f3): state change: ip-config -> ip-check (reason 'none', sys-iface-st>
Aug 18 18:24:56 arcticfox dbus-daemon[802]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispa>
Aug 18 18:24:56 arcticfox systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 18 18:24:56 arcticfox dbus-daemon[802]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 18 18:24:56 arcticfox systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 18 18:24:56 arcticfox audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib>
Aug 18 18:24:56 arcticfox kernel: audit: type=1130 audit(1629325496.647:207): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher >
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6530] device (wlp0s20f3): state change: ip-check -> secondaries (reason 'none', sys-iface->
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6533] device (wlp0s20f3): state change: secondaries -> activated (reason 'none', sys-iface>
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6539] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6551] manager: NetworkManager state is now CONNECTED_SITE
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6552] policy: set 'JazzThang' (wlp0s20f3) as default for IPv4 routing and DNS
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.6599] device (wlp0s20f3): Activation: successful, device activated.
Aug 18 18:24:56 arcticfox NetworkManager[805]: <info>  [1629325496.8656] manager: NetworkManager state is now CONNECTED_GLOBAL
Aug 18 18:24:57 arcticfox wpa_supplicant[934]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-28 noise=9999 txrate=58500
Aug 18 18:24:58 arcticfox ntpd[855]: Listen normally on 11 wlp0s20f3 192.168.50.247:123
Aug 18 18:24:58 arcticfox ntpd[855]: bind(24) AF_INET6 fe80::1385:24e5:192c:19cb%2#123 flags 0x11 failed: Cannot assign requested address
Aug 18 18:24:58 arcticfox ntpd[855]: unable to create socket on wlp0s20f3 (12) for fe80::1385:24e5:192c:19cb%2#123
Aug 18 18:24:58 arcticfox ntpd[855]: failed to init interface for address fe80::1385:24e5:192c:19cb%2
Aug 18 18:24:58 arcticfox ntpd[855]: new interface(s) found: waking up resolver
Aug 18 18:25:00 arcticfox ntpd[855]: Listen normally on 13 wlp0s20f3 [fe80::1385:24e5:192c:19cb%2]:123
Aug 18 18:25:00 arcticfox ntpd[855]: new interface(s) found: waking up resolver
Aug 18 18:25:06 arcticfox systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Aug 18 18:25:06 arcticfox audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/>
Aug 18 18:25:06 arcticfox kernel: audit: type=1131 audit(1629325506.911:208): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher >
Aug 18 18:25:17 arcticfox systemd-logind[812]: Power key pressed.

I also tried to set up kdump, and although kdump is loaded (checked with cat /sys/kernel/kexec_crash_loaded), the capture kernel does not reboot once I cause a kp on purpose. That's another topic because I spend 3 days trying to make kdump work.

Any help would be appreciated. Is there something obvious from the journalctl log that I am missing?

In partcular, I do not understand why networkManager seems to do weird things and fail, and I am also confused by this line:

Aug 18 18:24:53 arcticfox kernel: mmc0: cannot verify signal voltage switch

Which relates to the memory card, which is automounted in fstab and constantly synced in background with syncthing. Is that a cause of freeze?

Thanks a lot!!

Last edited by aleksF (2021-08-19 14:36:11)

Offline

Board footer

Powered by FluxBB