Swapspace issue

I have 24GB of ram.
When I installed manjaro in august I found that the recommended swapspace with hibernate enabled would be 25GB. So I have 25GB of swap partition. This has been working until last night.
Last night hibernate failed. Looking at the journal I see that system rsn out of space while hibernating.

Running
journalctl -b-0 | grep pages
gives this:

...
feb. 07 11:08:42 pl140 kernel: PM: hibernation: Allocated 2586289 pages for snapshot
feb. 07 11:08:42 pl140 kernel: PM: hibernation: Need to copy 2568782 pages
feb. 07 11:08:42 pl140 kernel: PM: hibernation: Normal pages needed: 2568782 + 1024, available pages: 3652191
feb. 07 11:08:42 pl140 kernel: PM: hibernation: free pages cleared after restore
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x0009f000-0x000fffff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x56559000-0x56e58fff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x5ca1d000-0x5cad3fff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6d06f000-0x6fc4efff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6fc50000-0xffffffff]
feb. 07 20:51:47 pl140 kernel: PM: hibernation: Image allocation is 874612 pages short
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x0009f000-0x000fffff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x56559000-0x56e58fff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x5ca1d000-0x5cad3fff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6d06f000-0x6fc4efff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6fc50000-0xffffffff]
feb. 07 20:52:54 pl140 kernel: PM: hibernation: Image allocation is 595785 pages short

At 11:08 i did a successful hibernate. At 20:51 and 20:52 I tried hibernate twice before realizing what was going on.

Looking at the used ram and swap raises some questions

# free -h
              total        used        free      shared  buff/cache   available
Mem:           23Gi        16Gi       6,1Gi       185Mi       666Mi       6,1Gi
Swap:          25Gi       7,1Gi        18Gi

Why is 7GB of swap used when there is 6GB of free ram?
Shouldn’t 18GB of free swap be enough to store 16GB of ram?

The easy fix here would be to increase the swap partition. How large should it be?
Should I do something to make the system make less use of swap? I’m not sure if thats good or bad. As I usually hibernate twice a day (hibernate when I know I’ll be away from the pc for more than 4 hours, without charger connected), swapping the parts of ram that are not used between each hibernate would actually cause less disk writes and faster suspend/resume.

Well, it’s hard to say why those 7GB are there. What value do you have for swappiness?

sysctl vm.swappiness

With the amount of RAM you have, you don’t need a high swappiness. Th higher the value, the sooner the system will start to swap.

On the other hand, when you resume from hibernate, it’s natural that not all swap gets cleared. Only the needed pages will be transferred to RAM and others will remain in swap until needed or discarded.

It can happen that your RAM usage fills up available RAM and a part of swap, in such a way you can’t hibernate for lack of space. That already happened to me more than once. However, sometimes the system can’t hibernate due to a specific application or service.

1 Like

Thanks for your reply.
vm.swappiness = 60

I don’t know what that means. Does it mean it will start to swap when less than 60% of the ram is free?

It’s not that linear, but close to it. With 24GB of RAM I’d go for a value of 5 (10 at the most).

Create the file /etc/sysctl.d/99-swappiness.conf and write the following:

vm.swappiness = 5

Save it. Then apply the setting on the fly:

sudo sysctl -w vm.swappiness=5

If you feel swap starts too late change it to 10.

(source)

With dual PCIe x4 SSDs, I doubt I will notice any slowdown caused by swap.

I don’t think changing swappiness solves the problem of running out of space during hibernate. It will change WHEN the problem occurs, but it doesn’t make it go away.

I wonder about that advice of having combined hibernatespace and swapspace slightly over the total ram size. In the world of windows swap+hiber will consume 2-2,5 times the ram.

Is there any command that can be issued to dump as nearly all ram content into swap? For an experiment I’d like to run that command (if it exists) just before hibernate. I’d expect the hibernate to fail, but I’d like to see the log for how much space it would like to have. Based on that I could resize the partitions.

I don’t know. But it would be a failed experiment. When you hibernate the RAM pages aren’t stored in swap the same way. inodes and other data not necessary are discarded and the data is compressed. It isn’t just a dump.

You’re probably right. The solution is then to increase swap or use less RAM.

Well, first of all those are two different things in Windows. Second, Windows swaps a lot more, but it can be adjusted. In the days I used Windows, I always adjusted swap area to a value a lot lower than the default. It made my system faster.

After hibernate, is there a way to see how much space the hibernate consumed? Like booting on a usb and look at free space in the swap partition?

I want to figure out how much space is actually needed for hibernate when lots of programs are loaded.

Well, you should really look for errors: journalctl -p3 -b

If there is a problem hibernating it should be written to the journal.

Looking at this, I don’t see why you would have lack of space to hibernate. You’re using 16GB of RAM and have 18GB of free swap. Maybe we’re looking in the wrong direction.

I don’t know. You can always try it.

How do you find the available space in a swap partition of a not running system? It’s not like it can be mounted in a live usb environment and run df.

A swap space doesn’t even contain a filesystem.
It’s still possible to, for example,
analyze the usage by creating a fresh swap space with dd
which is filled with zeroes all the way during creation

then you can analyze the amount of that space which is not zeroed anymore after it has been in use

It’s probably easier to estimate the degree to which it will be used
by looking of the contents and amount of space your RAM is filled to - which is what has to be written to swap in the case of a hibernation to swap.

and then there is this, of course:

1 Like

Yes. And that compression ratio is? If it compresses 1% and maybe have a 1GB overhead, that explains why 16GB (which may be 16,49GB) cannot be stored in a swap partition with 18GB (which may be 17,5GB) free.
Could there be an option to put a filesystem on the swap partition just to see the size of files created? Will a swap file and hiber file grow and shrink to the actual size needed? Is it even possible to hibernate to file on linux?

All I want is a way to figure out the size needed for swap + hiber.

I don’t know - but that is rather easy to find out.
It certainly is better than 1% - it is very likely that gzip or another standard algorithm is used and perhaps even configurable.

… if you use a swap file :wink:
(which is a file within the filesystem, which, just like a swap partition, also has no filesystem on it)

Trial and error is the only way I know - and keeping with the recommendation that you should have as much swap than you have RAM - so a worst case 2:1 compression will still fit into swap

When you do what I suggested then you’ll at least know how much of the swap space actually was used for a given amount of used RAM
and can estimate the ratio from there.
or find out the compression algorithm that is used - then you’ll also know pretty accurately

1 Like

Maybe try a partitioning program?

Again, I think you’re looking in the wrong direction. You should provide the output of journalctl -p3 -b after a failed attempt. The system will log why it wasn’t possible to hibernate. It can be a completely unrelated problem.

1 Like

Using swapiness=5 it still uses swap before 50% of the ram is used!

free -h
              total        used        free      shared  buff/cache   available
Mem:           23Gi        10Gi        10Gi       422Mi       2,1Gi        11Gi
Swap:          30Gi        73Mi        30Gi


free -h
              total        used        free      shared  buff/cache   available
Mem:           23Gi       9,5Gi        12Gi       273Mi       831Mi        12Gi
Swap:          30Gi       1,5Gi        28Gi

Between those two printouts is a couple of hours of firefox browsing

(I’ve increased to swap partition by 5GB)

WIth that I tried to hibernate, which failed. And for what I can see it looks like an out of space issue.

journalctl -p3 -b --since "2021-02-16 12:58:00"
-- Journal begins at Wed 2020-09-30 20:51:46 CEST, ends at Tue 2021-02-16 14:59:16 CET. --
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Image allocation is 409500 pages short
feb. 16 13:00:10 pl140 systemd-sleep[489091]: Failed to suspend system. System resumed again: Cannot allocate memory
feb. 16 13:00:10 pl140 systemd[1]: Failed to start Hibernate.
feb. 16 14:55:14 pl140 lightdm[489509]: gkr-pam: unable to locate daemon control file

Full journal for the selected time intervall

-- Journal begins at Wed 2020-09-30 20:51:46 CEST, ends at Tue 2021-02-16 15:04:07 CET. --
feb. 16 12:59:32 pl140 gvfsd[488310]: PTP: reading event an error 0x05 occurred
feb. 16 12:59:32 pl140 kernel: usb 1-1: USB disconnect, device number 13
feb. 16 12:59:33 pl140 gvfsd[488310]: Device 0 (VID=2717 and PID=ff40) is a Xiaomi Mi-2s (id2) (MTP).
feb. 16 12:59:33 pl140 gvfsd[488310]: Android device detected, assigning default bug flags
feb. 16 13:00:04 pl140 ModemManager[1250]: <info>  [sleep-monitor] system is about to suspend
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5228] manager: sleep: sleep requested (sleeping: no  enabled: yes)
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5231] device (p2p-dev-wlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5245] manager: NetworkManager state is now ASLEEP
feb. 16 13:00:04 pl140 dbus-daemon[1201]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=1284 comm="/usr/bin/NetworkManager --no-daemon ")
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5250] device (wlan0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:04 pl140 systemd[1]: Starting Network Manager Script Dispatcher Service...
feb. 16 13:00:04 pl140 dbus-daemon[1201]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
feb. 16 13:00:04 pl140 systemd[1]: Started Network Manager Script Dispatcher Service.
feb. 16 13:00:04 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:04 pl140 kernel: audit: type=1130 audit(1613476804.555:1796): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:04 pl140 kernel: wlan0: deauthenticating from de:47:32:28:70:37 by local choice (Reason: 3=DEAUTH_LEAVING)
feb. 16 13:00:04 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-DISCONNECTED bssid=de:47:32:28:70:37 reason=3 locally_generated=1
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5755] device (wlan0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5763] dhcp4 (wlan0): canceled DHCP transaction
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5763] dhcp4 (wlan0): state changed extended -> done
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Withdrawing address record for fe80::6ed7:551:91f7:8cee on wlan0.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::6ed7:551:91f7:8cee.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Interface wlan0.IPv6 no longer relevant for mDNS.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Interface wlan0.IPv4 no longer relevant for mDNS.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Withdrawing address record for 192.168.68.118 on wlan0.
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.5881] device (wlan0): set-hw-addr: set MAC address to BE:24:0D:28:50:07 (scanning)
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: New relevant interface wlan0.IPv4 for mDNS.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Registering new address record for 192.168.68.118 on wlan0.IPv4.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Withdrawing address record for 192.168.68.118 on wlan0.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:04 pl140 avahi-daemon[1199]: Interface wlan0.IPv4 no longer relevant for mDNS.
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.6048] device (wlan0): supplicant interface state: completed -> disconnected
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.6126] device (wlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:04 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-100
feb. 16 13:00:04 pl140 NetworkManager[1284]: <info>  [1613476804.6175] device (wlan0): set-hw-addr: reset MAC address to 34:7D:F6:19:8B:06 (unmanage)
feb. 16 13:00:04 pl140 systemd[1]: Reached target Sleep.
feb. 16 13:00:04 pl140 systemd[1]: Starting Hibernate...
feb. 16 13:00:04 pl140 wpa_supplicant[1480]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
feb. 16 13:00:05 pl140 systemd-sleep[489091]: Suspending system...
feb. 16 13:00:05 pl140 kernel: PM: hibernation: hibernation entry
feb. 16 13:00:10 pl140 kernel: Filesystems sync: 0.003 seconds
feb. 16 13:00:10 pl140 kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
feb. 16 13:00:10 pl140 kernel: OOM killer disabled.
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x0009f000-0x000fffff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x56559000-0x56e58fff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x5ca1d000-0x5cad3fff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6d06f000-0x6fc4efff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6fc50000-0xffffffff]
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Basic memory bitmaps created
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Preallocating image memory
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Image allocation is 409500 pages short
feb. 16 13:00:10 pl140 kernel: acpi LNXPOWER:05: Turning OFF
feb. 16 13:00:10 pl140 kernel: acpi LNXPOWER:00: Turning OFF
feb. 16 13:00:10 pl140 kernel: PM: hibernation: Basic memory bitmaps freed
feb. 16 13:00:10 pl140 kernel: OOM killer enabled.
feb. 16 13:00:10 pl140 kernel: Restarting tasks ... done.
feb. 16 13:00:10 pl140 kernel: PM: hibernation: hibernation exit
feb. 16 13:00:10 pl140 systemd-sleep[489091]: Failed to suspend system. System resumed again: Cannot allocate memory
feb. 16 13:00:10 pl140 rtkit-daemon[1735]: The canary thread is apparently starving. Taking action.
feb. 16 13:00:10 pl140 rtkit-daemon[1735]: Demoting known real-time threads.
feb. 16 13:00:10 pl140 rtkit-daemon[1735]: Successfully demoted thread 479625 of process 479391.
feb. 16 13:00:10 pl140 rtkit-daemon[1735]: Successfully demoted thread 479302 of process 479156.
feb. 16 13:00:10 pl140 rtkit-daemon[1735]: Demoted 2 threads.
feb. 16 13:00:10 pl140 systemd[1]: systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
feb. 16 13:00:10 pl140 kernel: kauditd_printk_skb: 6 callbacks suppressed
feb. 16 13:00:10 pl140 kernel: audit: type=1130 audit(1613476810.745:1812): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=systemd-hibernate comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
feb. 16 13:00:10 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=systemd-hibernate comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
feb. 16 13:00:10 pl140 ModemManager[1250]: <info>  [sleep-monitor] system is resuming
feb. 16 13:00:10 pl140 systemd[1]: systemd-hibernate.service: Failed with result 'exit-code'.
feb. 16 13:00:10 pl140 systemd[1]: Failed to start Hibernate.
feb. 16 13:00:10 pl140 systemd[1]: Dependency failed for Hibernate.
feb. 16 13:00:10 pl140 systemd[1]: hibernate.target: Job hibernate.target/start failed with result 'dependency'.
feb. 16 13:00:10 pl140 systemd[1]: Stopped target Sleep.
feb. 16 13:00:10 pl140 systemd-logind[1209]: Operation 'sleep' finished.
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.7543] manager: sleep: wake requested (sleeping: yes  enabled: yes)
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.7563] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'managed')
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.7602] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'managed')
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.7610] manager: NetworkManager state is now CONNECTED_LOCAL
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8240] device (wlan0): supplicant interface state: internal-starting -> disconnected
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8241] device (p2p-dev-wlan0): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8247] Wi-Fi P2P device controlled by interface wlan0 created
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8249] manager: (p2p-dev-wlan0): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkManager/Devices/51)
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8252] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
feb. 16 13:00:10 pl140 NetworkManager[1284]: <warn>  [1613476810.8259] sup-iface[c1304c6beaeb7b21,23,wlan0]: call-p2p-cancel: failed with P2P cancel failed
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8259] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
feb. 16 13:00:10 pl140 NetworkManager[1284]: <info>  [1613476810.8266] device (p2p-dev-wlan0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.3990] policy: auto-activating connection 'Ormeletveien1 1' (cbcf382a-4ceb-45b8-85d3-3878cc0263ac)
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.3997] device (wlan0): Activation: starting connection 'Ormeletveien1 1' (cbcf382a-4ceb-45b8-85d3-3878cc0263ac)
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.3999] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4002] manager: NetworkManager state is now CONNECTING
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4004] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4008] device (wlan0): Activation: (wifi) access point 'Ormeletveien1 1' has security, but secrets are required.
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4008] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4050] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4055] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] device (wlan0): Activation: (wifi) connection 'Ormeletveien1 1' has security, and secrets exist.  No new secrets needed.
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] Config: added 'ssid' value 'Ormeletveien1'
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] Config: added 'scan_ssid' value '1'
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] Config: added 'bgscan' value 'simple:30:-65:300'
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK'
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4058] Config: added 'psk' value '<hidden>'
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: SME: Trying to authenticate with de:47:32:28:70:37 (SSID='Ormeletveien1' freq=5180 MHz)
feb. 16 13:00:12 pl140 kernel: wlan0: authenticate with de:47:32:28:70:37
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4172] device (wlan0): supplicant interface state: disconnected -> authenticating
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4172] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> authenticating
feb. 16 13:00:12 pl140 kernel: wlan0: send auth to de:47:32:28:70:37 (try 1/3)
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: Trying to associate with de:47:32:28:70:37 (SSID='Ormeletveien1' freq=5180 MHz)
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4426] device (wlan0): supplicant interface state: authenticating -> associating
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4426] device (p2p-dev-wlan0): supplicant management interface state: authenticating -> associating
feb. 16 13:00:12 pl140 kernel: wlan0: authenticated
feb. 16 13:00:12 pl140 kernel: wlan0: associate with de:47:32:28:70:37 (try 1/3)
feb. 16 13:00:12 pl140 kernel: wlan0: RX AssocResp from de:47:32:28:70:37 (capab=0x1511 status=0 aid=1)
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: Associated with de:47:32:28:70:37
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
feb. 16 13:00:12 pl140 kernel: wlan0: associated
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4587] device (wlan0): supplicant interface state: associating -> associated
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4588] device (p2p-dev-wlan0): supplicant management interface state: associating -> associated
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4643] device (wlan0): supplicant interface state: associated -> 4way_handshake
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4643] device (p2p-dev-wlan0): supplicant management interface state: associated -> 4way_handshake
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: WPA: Key negotiation completed with de:47:32:28:70:37 [PTK=CCMP GTK=TKIP]
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-CONNECTED - Connection to de:47:32:28:70:37 completed [id=0 id_str=]
feb. 16 13:00:12 pl140 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-66 noise=9999 txrate=26000
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4780] device (wlan0): supplicant interface state: 4way_handshake -> completed
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4781] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Ormeletveien1"
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4781] device (p2p-dev-wlan0): supplicant management interface state: 4way_handshake -> completed
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4783] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:12 pl140 NetworkManager[1284]: <info>  [1613476812.4789] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
feb. 16 13:00:12 pl140 avahi-daemon[1199]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::6ed7:551:91f7:8cee.
feb. 16 13:00:12 pl140 avahi-daemon[1199]: New relevant interface wlan0.IPv6 for mDNS.
feb. 16 13:00:12 pl140 avahi-daemon[1199]: Registering new address record for fe80::6ed7:551:91f7:8cee on wlan0.*.
feb. 16 13:00:12 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-66 noise=9999 txrate=26000
feb. 16 13:00:12 pl140 kernel: wlan0: Limiting TX power to 23 (23 - 0) dBm as advertised by de:47:32:28:70:37
feb. 16 13:00:12 pl140 audit[489463]: CRED_ACQ pid=489463 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:setcred grantors=pam_env,pam_permit acct="lightdm" exe="/usr/bin/lightdm" hostname=? addr=? terminal=:1 res=success'
feb. 16 13:00:12 pl140 lightdm[489463]: pam_unix(lightdm-greeter:session): session opened for user lightdm(uid=969) by (uid=0)
feb. 16 13:00:12 pl140 kernel: audit: type=1103 audit(1613476812.608:1813): pid=489463 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:setcred grantors=pam_env,pam_permit acct="lightdm" exe="/usr/bin/lightdm" hostname=? addr=? terminal=:1 res=success'
feb. 16 13:00:12 pl140 systemd[1]: Created slice User Slice of UID 969.
feb. 16 13:00:12 pl140 systemd[1]: Starting User Runtime Directory /run/user/969...
feb. 16 13:00:12 pl140 systemd-logind[1209]: New session c37 of user lightdm.
feb. 16 13:00:12 pl140 systemd[1]: Finished User Runtime Directory /run/user/969.
feb. 16 13:00:12 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=user-runtime-dir@969 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 systemd[1]: Starting User Manager for UID 969...
feb. 16 13:00:12 pl140 kernel: audit: type=1130 audit(1613476812.628:1814): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=user-runtime-dir@969 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 dbus-daemon[1201]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.894' (uid=0 pid=489467 comm="(systemd) ")
feb. 16 13:00:12 pl140 audit[489467]: USER_ACCT pid=489467 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 audit[489467]: CRED_ACQ pid=489467 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:setcred grantors=? acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
feb. 16 13:00:12 pl140 dbus-daemon[1201]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
feb. 16 13:00:12 pl140 systemd[489467]: pam_systemd_home(systemd-user:account): systemd-homed is not available: Unit dbus-org.freedesktop.home1.service not found.
feb. 16 13:00:12 pl140 kernel: audit: type=1101 audit(1613476812.638:1815): pid=489467 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 kernel: audit: type=1103 audit(1613476812.638:1816): pid=489467 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:setcred grantors=? acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
feb. 16 13:00:12 pl140 kernel: audit: type=1006 audit(1613476812.638:1817): pid=489467 uid=0 subj==unconfined old-auid=4294967295 auid=969 tty=(none) old-ses=4294967295 ses=39 res=1
feb. 16 13:00:12 pl140 systemd[489467]: pam_warn(systemd-user:setcred): function=[pam_sm_setcred] flags=0x8002 service=[systemd-user] terminal=[] user=[lightdm] ruser=[<unknown>] rhost=[<unknown>]
feb. 16 13:00:12 pl140 audit[489467]: USER_START pid=489467 uid=0 auid=969 ses=39 subj==unconfined msg='op=PAM:session_open grantors=pam_loginuid,pam_loginuid,pam_keyinit,pam_limits,pam_unix,pam_permit,pam_mail,pam_systemd,pam_env acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 systemd[489467]: pam_unix(systemd-user:session): session opened for user lightdm(uid=969) by (uid=0)
feb. 16 13:00:12 pl140 systemd[489467]: pam_env(systemd-user:session): deprecated reading of user environment enabled
feb. 16 13:00:12 pl140 kernel: audit: type=1105 audit(1613476812.642:1818): pid=489467 uid=0 auid=969 ses=39 subj==unconfined msg='op=PAM:session_open grantors=pam_loginuid,pam_loginuid,pam_keyinit,pam_limits,pam_unix,pam_permit,pam_mail,pam_systemd,pam_env acct="lightdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 audit: BPF prog-id=67 op=LOAD
feb. 16 13:00:12 pl140 audit: BPF prog-id=67 op=UNLOAD
feb. 16 13:00:12 pl140 kernel: audit: type=1334 audit(1613476812.648:1819): prog-id=67 op=LOAD
feb. 16 13:00:12 pl140 kernel: audit: type=1334 audit(1613476812.648:1820): prog-id=67 op=UNLOAD
feb. 16 13:00:12 pl140 systemd-xdg-autostart-generator[489473]: Configuration file /etc/xdg/autostart/msm_notifier.desktop is marked executable. Please remove executable permission bits. Proceeding anyway.
feb. 16 13:00:12 pl140 systemd[489467]: Queued start job for default target Main User Target.
feb. 16 13:00:12 pl140 systemd[489467]: -.slice: Failed to migrate controller cgroups from /user.slice/user-969.slice/user@969.service, ignoring: Permission denied
feb. 16 13:00:12 pl140 systemd[489467]: Created slice User Application Slice.
feb. 16 13:00:12 pl140 systemd[489467]: Reached target Paths.
feb. 16 13:00:12 pl140 systemd[489467]: Reached target Timers.
feb. 16 13:00:12 pl140 systemd[489467]: Starting D-Bus User Message Bus Socket.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on GnuPG network certificate management daemon.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
feb. 16 13:00:12 pl140 systemd[489467]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
feb. 16 13:00:12 pl140 systemd[489467]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
feb. 16 13:00:12 pl140 systemd[489467]: Listening on GnuPG cryptographic agent and passphrase cache.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on p11-kit server.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on Multimedia System.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on Sound System.
feb. 16 13:00:12 pl140 systemd[489467]: Listening on D-Bus User Message Bus Socket.
feb. 16 13:00:12 pl140 systemd[489467]: Reached target Sockets.
feb. 16 13:00:12 pl140 systemd[489467]: Reached target Basic System.
feb. 16 13:00:12 pl140 systemd[1]: Started User Manager for UID 969.
feb. 16 13:00:12 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=user@969 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 systemd[1]: Started Session c37 of user lightdm.
feb. 16 13:00:12 pl140 systemd[489467]: Starting Update XDG user dir configuration...
feb. 16 13:00:12 pl140 kernel: audit: type=1130 audit(1613476812.838:1821): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=user@969 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:12 pl140 systemd[489467]: xdg-user-dirs-update.service: Succeeded.
feb. 16 13:00:12 pl140 systemd[489467]: Finished Update XDG user dir configuration.
feb. 16 13:00:12 pl140 systemd[489467]: Reached target Main User Target.
feb. 16 13:00:12 pl140 systemd[489467]: Startup finished in 193ms.
feb. 16 13:00:12 pl140 audit[489463]: USER_START pid=489463 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='op=PAM:session_open grantors=pam_unix,pam_systemd acct="lightdm" exe="/usr/bin/lightdm" hostname=? addr=? terminal=:1 res=success'
feb. 16 13:00:13 pl140 systemd[489467]: Started D-Bus User Message Bus.
feb. 16 13:00:13 pl140 dbus-daemon[489483]: [session uid=969 pid=489483] Activating via systemd: service name='org.a11y.Bus' unit='at-spi-dbus-bus.service' requested by ':1.1' (uid=969 pid=489477 comm="/usr/bin/lightdm-gtk-greeter ")
feb. 16 13:00:13 pl140 systemd[489467]: Starting Accessibility services bus...
feb. 16 13:00:13 pl140 dbus-daemon[489483]: [session uid=969 pid=489483] Successfully activated service 'org.a11y.Bus'
feb. 16 13:00:13 pl140 systemd[489467]: Started Accessibility services bus.
feb. 16 13:00:13 pl140 dbus-daemon[489483]: [session uid=969 pid=489483] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=969 pid=489477 comm="/usr/bin/lightdm-gtk-greeter ")
feb. 16 13:00:13 pl140 systemd[489467]: Starting Virtual filesystem service...
feb. 16 13:00:13 pl140 dbus-daemon[489483]: [session uid=969 pid=489483] Successfully activated service 'org.gtk.vfs.Daemon'
feb. 16 13:00:13 pl140 systemd[489467]: Started Virtual filesystem service.
feb. 16 13:00:13 pl140 ModemManager[1250]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.3': not supported by any plugin
feb. 16 13:00:13 pl140 polkitd[1204]: <no filename>:3: action=[Action id='org.freedesktop.DisplayManager.AccountsService.ReadAny']
feb. 16 13:00:13 pl140 polkitd[1204]: <no filename>:4: subject=[Subject pid=489477 user='lightdm' groups=lightdm seat='seat0' session='c37' local=true active=true]
feb. 16 13:00:13 pl140 polkitd[1204]: <no filename>:3: action=[Action id='org.freedesktop.DisplayManager.AccountsService.ReadAny']
feb. 16 13:00:13 pl140 polkitd[1204]: <no filename>:4: subject=[Subject pid=489477 user='lightdm' groups=lightdm seat='seat0' session='c37' local=true active=true]
feb. 16 13:00:13 pl140 at-spi-bus-launcher[489490]: dbus-daemon[489490]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=969 pid=489477 comm="/usr/bin/lightdm-gtk-greeter ")
feb. 16 13:00:13 pl140 at-spi-bus-launcher[489490]: dbus-daemon[489490]: Successfully activated service 'org.a11y.atspi.Registry'
feb. 16 13:00:13 pl140 at-spi-bus-launcher[489512]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5038] dhcp4 (wlan0): option dhcp_lease_time      => '7200'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option domain_name_servers  => '80.202.2.2 217.13.0.2 192.168.68.1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option expiry               => '1613484014'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option ip_address           => '192.168.68.118'
feb. 16 13:00:14 pl140 avahi-daemon[1199]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_broadcast_address => '1'
feb. 16 13:00:14 pl140 avahi-daemon[1199]: New relevant interface wlan0.IPv4 for mDNS.
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_domain_name => '1'
feb. 16 13:00:14 pl140 avahi-daemon[1199]: Registering new address record for 192.168.68.118 on wlan0.IPv4.
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_domain_name_servers => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_domain_search => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_host_name  => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_interface_mtu => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5039] dhcp4 (wlan0): option requested_ms_classless_static_routes => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_nis_domain => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_nis_servers => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_ntp_servers => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_rfc3442_classless_static_routes => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_root_path  => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_routers    => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_static_routes => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_subnet_mask => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_time_offset => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5040] dhcp4 (wlan0): option requested_wpad       => '1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5041] dhcp4 (wlan0): option routers              => '192.168.68.1'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5041] dhcp4 (wlan0): option subnet_mask          => '255.255.255.0'
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5041] dhcp4 (wlan0): state changed unknown -> bound
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5060] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5108] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5112] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5119] manager: NetworkManager state is now CONNECTED_LOCAL
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5151] manager: NetworkManager state is now CONNECTED_SITE
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5154] policy: set 'Ormeletveien1 1' (wlan0) as default for IPv4 routing and DNS
feb. 16 13:00:14 pl140 NetworkManager[1284]: <info>  [1613476814.5180] device (wlan0): Activation: successful, device activated.
feb. 16 13:00:14 pl140 systemd[1]: NetworkManager-dispatcher.service: Succeeded.
feb. 16 13:00:14 pl140 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:16 pl140 systemd-logind[1209]: Lid closed.
feb. 16 13:00:19 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-68 noise=9999 txrate=26000
feb. 16 13:00:22 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-74 noise=9999 txrate=26000
feb. 16 13:00:22 pl140 NetworkManager[1284]: <info>  [1613476822.8737] manager: NetworkManager state is now CONNECTED_GLOBAL
feb. 16 13:00:22 pl140 dbus-daemon[1201]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=1284 comm="/usr/bin/NetworkManager --no-daemon ")
feb. 16 13:00:22 pl140 systemd[1]: Starting Network Manager Script Dispatcher Service...
feb. 16 13:00:22 pl140 dbus-daemon[1201]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
feb. 16 13:00:22 pl140 systemd[1]: Started Network Manager Script Dispatcher Service.
feb. 16 13:00:22 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:22 pl140 kernel: kauditd_printk_skb: 2 callbacks suppressed
feb. 16 13:00:22 pl140 kernel: audit: type=1130 audit(1613476822.888:1824): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:32 pl140 systemd[1]: NetworkManager-dispatcher.service: Succeeded.
feb. 16 13:00:32 pl140 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:32 pl140 kernel: audit: type=1131 audit(1613476832.687:1825): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:34 pl140 systemd-logind[1209]: Suspending...
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8527] manager: sleep: sleep requested (sleeping: no  enabled: yes)
feb. 16 13:00:34 pl140 ModemManager[1250]: <info>  [sleep-monitor] system is about to suspend
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8528] device (p2p-dev-wlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8533] manager: NetworkManager state is now ASLEEP
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8535] device (wlan0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:34 pl140 dbus-daemon[1201]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.6' (uid=0 pid=1284 comm="/usr/bin/NetworkManager --no-daemon ")
feb. 16 13:00:34 pl140 systemd[1]: Starting Network Manager Script Dispatcher Service...
feb. 16 13:00:34 pl140 dbus-daemon[1201]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
feb. 16 13:00:34 pl140 systemd[1]: Started Network Manager Script Dispatcher Service.
feb. 16 13:00:34 pl140 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:34 pl140 kernel: audit: type=1130 audit(1613476834.864:1826): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
feb. 16 13:00:34 pl140 kernel: wlan0: deauthenticating from de:47:32:28:70:37 by local choice (Reason: 3=DEAUTH_LEAVING)
feb. 16 13:00:34 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-DISCONNECTED bssid=de:47:32:28:70:37 reason=3 locally_generated=1
feb. 16 13:00:34 pl140 wpa_supplicant[1480]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=0 noise=9999 txrate=0
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8799] device (wlan0): supplicant interface state: completed -> disconnected
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8801] device (wlan0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Withdrawing address record for fe80::6ed7:551:91f7:8cee on wlan0.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::6ed7:551:91f7:8cee.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Interface wlan0.IPv6 no longer relevant for mDNS.
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8986] dhcp4 (wlan0): canceled DHCP transaction
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.8986] dhcp4 (wlan0): state changed bound -> done
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Interface wlan0.IPv4 no longer relevant for mDNS.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Withdrawing address record for 192.168.68.118 on wlan0.
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.9023] device (wlan0): set-hw-addr: set MAC address to 86:1E:A4:4D:F5:3B (scanning)
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: New relevant interface wlan0.IPv4 for mDNS.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Registering new address record for 192.168.68.118 on wlan0.IPv4.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Withdrawing address record for 192.168.68.118 on wlan0.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.118.
feb. 16 13:00:34 pl140 avahi-daemon[1199]: Interface wlan0.IPv4 no longer relevant for mDNS.
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.9148] device (wlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
feb. 16 13:00:34 pl140 NetworkManager[1284]: <info>  [1613476834.9169] device (wlan0): set-hw-addr: reset MAC address to 34:7D:F6:19:8B:06 (unmanage)
feb. 16 13:00:34 pl140 systemd[1]: Reached target Sleep.
feb. 16 13:00:34 pl140 systemd[1]: Starting Suspend...
feb. 16 13:00:35 pl140 wpa_supplicant[1480]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
feb. 16 13:00:35 pl140 systemd-sleep[489538]: Suspending system...
feb. 16 13:00:35 pl140 kernel: PM: suspend entry (s2idle)

Memory usage after resume:

free -h
              total        used        free      shared  buff/cache   available
Mem:           23Gi        13Gi       9,4Gi       282Mi       817Mi       9,4Gi
Swap:          30Gi       2,2Gi        28Gi

It isn’t linear.

I’m still not convinced this is a lack of space issue, though I can’t quite figure out the problem. What kernel are you using? Have you considered trying another one?

The only thing logged that say what went wrong is:
Failed to suspend system. System resumed again: Cannot allocate memory

Last time it failed it said
PM: hibernation: Image allocation is 595785 pages short

I guess the image allocation message indicates swap running out of space, while the cannot allocate memory indicates some other issue.

Current kernel 5.10.15-1. It was automatically installed through system update on Feb 12th. I don’t know how to figure which kernel was running before this update. I’m sure it was 5.10.something.

Can you try 5.4 to see if the problem persists?

Here we go again. Seems like out of swap space

feb. 17 01:37:16 pl140 systemd-sleep[641639]: Suspending system...
feb. 17 01:37:16 pl140 kernel: PM: hibernation: hibernation entry
feb. 17 01:37:23 pl140 kernel: Filesystems sync: 0.008 seconds
feb. 17 01:37:23 pl140 kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
feb. 17 01:37:23 pl140 kernel: OOM killer disabled.
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x0009f000-0x000fffff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x56559000-0x56e58fff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x5ca1d000-0x5cad3fff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6d06f000-0x6fc4efff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Marking nosave pages: [mem 0x6fc50000-0xffffffff]
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Basic memory bitmaps created
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Preallocating image memory
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Image allocation is 313523 pages short
feb. 17 01:37:23 pl140 kernel: acpi LNXPOWER:05: Turning OFF
feb. 17 01:37:23 pl140 kernel: acpi LNXPOWER:00: Turning OFF
feb. 17 01:37:23 pl140 kernel: PM: hibernation: Basic memory bitmaps freed
feb. 17 01:37:23 pl140 kernel: OOM killer enabled.
feb. 17 01:37:23 pl140 kernel: Restarting tasks ... done.
free -h
              total        used        free      shared  buff/cache   available
Mem:           23Gi        12Gi        10Gi       139Mi       460Mi        10Gi
Swap:          30Gi       2,0Gi        28Gi

Should be plenty of space on swap partition.

Will downgrading kernel make trouble with zfs? There were some major filesystem issues with zfs that got fixed some months ago. I’m afraid going too far back with kernel will cause data loss.

In principle, there won’t be a problem as long as you install the required modules.

In this case you should check if those fixes were backported before installing an older kernel. In doubt, don’t risk it.

It is obvious it doesn’t matter how big swap space is. The problem lies elsewhere. Check proper partition alignment and fstab, for example.

As free reflects the size of the swap partition, and also reflected the change when I made the partition larger, I doubt fstab is the problem.

Searching through pacman.log I figured my kernel versions has jumped:
on January 23rd from 5.10.2-2 to 5.10.7-3
on February 9th from 5.10.7-3 to 5.10.13-2
on February 12th from 5.10.13-2 to 5.10.15-1

This problem first occurred on February 7th. At that point I was running 5.10.7-3. In terms of downgrading kernel, I’d like to revert to 5.10.2-2. Just have to figure out how. Manjaro settings manager give me the choice to go back to 5.9.16-1.