search

nefelim4ag / systemd-swap

Script for creating hybrid swap space from zram swaps, swap files and swap partitions.
GNU General Public License v3.0
543 stars 81 forks source link

subprocess.CalledProcessError: Command '['systemctl', 'start', 'var-lib-systemd\x2dswap-swapfc-x.swap']' returned non-zero exit status 1. #194

Open Termuellinator opened 3 years ago

Termuellinator commented 3 years ago

Hi, i recently switched to btrfs and now have issues getting systemd-swap to work properly. It starts up fine but once i open a more memory intensive program, i don't see any swap being used in the ressource monitor and the service failed:

~ >>> systemctl status systemd-swap.service                                                                                                                                                                                                           
● systemd-swap.service - Manage swap spaces on zram, files and partitions.
     Loaded: loaded (/usr/lib/systemd/system/systemd-swap.service; enabled; vendor preset: disabled)
     Active: failed (Result: exit-code) since Sun 2020-12-20 13:55:39 CET; 2min 13s ago
    Process: 73379 ExecStart=/usr/bin/systemd-swap start (code=exited, status=1/FAILURE)
   Main PID: 73379 (code=exited, status=1/FAILURE)
     Status: "Allocating swap file..."

Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:     self.create_swapfile(
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:   File "/usr/bin/systemd-swap", line 311, in create_swapfile
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:     swapfile = self.prepare_swapfile(
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:   File "/usr/bin/systemd-swap", line 361, in prepare_swapfile
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:     subprocess.run(["chattr", "+C", path], check=True)
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:   File "/usr/lib/python3.9/subprocess.py", line 524, in run
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]:     raise CalledProcessError(retcode, process.args,
Dez 20 13:55:39 Zaubertrank systemd-swap[73379]: subprocess.CalledProcessError: Command '['chattr', '+C', '/swap/swapfc/1']' returned non-zero exit status 1.
Dez 20 13:55:39 Zaubertrank systemd[1]: systemd-swap.service: Main process exited, code=exited, status=1/FAILURE
Dez 20 13:55:39 Zaubertrank systemd[1]: systemd-swap.service: Failed with result 'exit-code'.

My config:

~ >>> cat /etc/systemd/swap.conf                                                                                                                                                                                                                 [130]
################################################################################
# Defaults are optimized for general usage
################################################################################

################################################################################
# You can override any settings by files in:
# /etc/systemd/swap.conf.d/*.conf
################################################################################

################################################################################
# Zswap
#
# Kernel >= 3.11
# Zswap create compress cache between swap and memory for reduce IO
# https://www.kernel.org/doc/Documentation/vm/zswap.txt

zswap_enabled=1
zswap_compressor=lz4      # lzo lz4
zswap_max_pool_percent=25 # 1-99
zswap_zpool=z3fold          # zbud z3fold

################################################################################
# ZRam
#
# Kernel >= 3.15
# Zram compression streams count for additional information see:
# https://www.kernel.org/doc/Documentation/blockdev/zram.txt

zram_enabled=0
zram_size=$(($RAM_SIZE/5))      # This is 1/4 of ram size by default.
zram_streams=$(($NCPU/2))
zram_alg=lz4                    # lzo lz4 deflate lz4hc 842 - for Linux 4.8.4
zram_prio=32767                 # 1 - 32767

################################################################################
# Swap File Chunked
# Allocate swap files dynamically
# For btrfs fallback to swapfile + loop will be used
# ex. Min swap size 512M, Max 8*512M
swapfc_enabled=1
swapfc_force_use_loop=1     # Force usage of swapfile + loop
swapfc_frequency=1         # How often check free swap space
swapfc_chunk_size=1024M      # Allocate size of swap chunk
swapfc_max_count=10          # 0 - unlimited, note: 32 is a kernel maximum
swapfc_free_swap_perc=15    # Add new chunk if free < 15%
                            # Remove chunk if free > 15+40% & chunk count > 2
swapfc_path=/swap/swapfc
# Only for swapfile + loop
swapfc_nocow=1              # Disable CoW on swapfile
swapfc_directio=1           # Use directio for loop dev
swapfc_force_preallocated=1 # Will preallocate created files

################################################################################
# Swap devices
# Find and auto swapon all available swap devices
swapd_auto_swapon=1
swapd_prio=1024

i've created an @swap subvolume that is mounted at /swap , in there i created a folder swapfc and did sudo btrfs property set /swap/swapfc compression none and sudo chattr +C /swap/swapfc

When the systemd-swap.service is started everything looks fine, the folder /swap/swapfc is empty. When i notice the stopped service there is a file named "1" in that folder that is deleted when i systemctl stop systemd-swap.service.

I'm not sure what i'm doing wrong - it seems the program is trying to un-set CoW for the file and fails? Could it be that me setting chattr +C for the folder is wrong because the file already inherits the flag on creation?

vilgotf commented 3 years ago

I'd recommend keeping the default swapfc_path and not set anything by yourself (the program is meant to automate everything)

Termuellinator commented 3 years ago

ok, i used the config from https://github.com/Nefelim4ag/systemd-swap/blob/master/include/swap-default.conf and only set swapfc_enabled=1 But it seems i get another error this way once more memory is consumed:

~ >>> systemctl status systemd-swap.service                                                                                                                                                                                                           
● systemd-swap.service - Manage swap spaces on zram, files and partitions.
     Loaded: loaded (/usr/lib/systemd/system/systemd-swap.service; enabled; vendor preset: disabled)
     Active: failed (Result: exit-code) since Sun 2020-12-20 16:17:51 CET; 52s ago
    Process: 1380 ExecStart=/usr/bin/systemd-swap start (code=exited, status=1/FAILURE)
   Main PID: 1380 (code=exited, status=1/FAILURE)
     Status: "Allocating swap file..."

Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:     swap_fc.run()
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:   File "/usr/bin/systemd-swap", line 227, in run
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:     self.create_swapfile(
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:   File "/usr/bin/systemd-swap", line 329, in create_swapfile
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:     subprocess.run(["systemctl", "start", unit_name], check=True)
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:   File "/usr/lib/python3.9/subprocess.py", line 524, in run
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]:     raise CalledProcessError(retcode, process.args,
Dez 20 16:17:51 Zaubertrank systemd-swap[1380]: subprocess.CalledProcessError: Command '['systemctl', 'start', 'var-lib-systemd\\x2dswap-swapfc-1.swap']' returned non-zero exit status 1.
Dez 20 16:17:51 Zaubertrank systemd[1]: systemd-swap.service: Main process exited, code=exited, status=1/FAILURE
Dez 20 16:17:51 Zaubertrank systemd[1]: systemd-swap.service: Failed with result 'exit-code'.
Termuellinator commented 3 years ago

ok, now it seems to be working correclty - i didn't change anything, so it has to be something in manjaros testing-update from the 22nd: https://lists.manjaro.org/pipermail/manjaro-packages/Week-of-Mon-20201221/034718.html

Termuellinator commented 3 years ago

apparently it's still present, just much later:

~ >>> systemctl status systemd-swap.service
● systemd-swap.service - Manage swap spaces on zram, files and partitions. Loaded: loaded (/usr/lib/systemd/system/systemd-swap.service; enabled; vendor preset: disabled) Active: failed (Result: exit-code) since Sun 2020-12-27 01:36:53 CET; 31min ago Process: 1370 ExecStart=/usr/bin/systemd-swap start (code=exited, status=1/FAILURE) Main PID: 1370 (code=exited, status=1/FAILURE) Status: "Allocating swap file..."

Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: swap_fc.run() Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: File "/usr/bin/systemd-swap", line 237, in run Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: self.create_swapfile( Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: File "/usr/bin/systemd-swap", line 329, in create_swapfile Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: subprocess.run(["systemctl", "start", unit_name], check=True) Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: File "/usr/lib/python3.9/subprocess.py", line 524, in run Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: raise CalledProcessError(retcode, process.args, Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: subprocess.CalledProcessError: Command '['systemctl', 'start', 'var-lib-systemd\x2dswap-swapfc-28.swap']' returned non-zero exit status 1. Dez 27 01:36:53 Zaubertrank systemd[1]: systemd-swap.service: Main process exited, code=exited, status=1/FAILURE Dez 27 01:36:53 Zaubertrank systemd[1]: systemd-swap.service: Failed with result 'exit-code'.

vilgotf commented 3 years ago

Please provide the the error message (journalctl -u var-lib-systemd-systemd\x2dswap-swapfc-28.swap).

Termuellinator commented 3 years ago 
~ >>> journalctl -u var-lib-systemd-systemd\x2dswap-swapfc-28.swap                                                                                                                                                                                 [3]
-- Journal begins at Sun 2020-12-13 14:39:38 CET, ends at Sun 2020-12-27 02:29:01 CET. --
-- No entries --

not very much... i've also tried some other numbers (swapfc-1.swap, swapfc-8.swap and so on), no entries for any of them

journalctl -b | grep swap gives me:

Dez 27 01:30:52 Zaubertrank systemd-swap[1370]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  27
Dez 27 01:30:53 Zaubertrank systemd[1]: Activating swap Swap File...
Dez 27 01:30:53 Zaubertrank systemd[1]: Activated swap Swap File.
Dez 27 01:30:53 Zaubertrank kernel: Adding 262140k swap on /var/lib/systemd-swap/swapfc/27.  Priority:24 extents:1 across:262140k DscFS
Dez 27 01:36:53 Zaubertrank systemd-swap[1370]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  28
Dez 27 01:36:53 Zaubertrank systemd[1]: Activating swap Swap File...
Dez 27 01:36:53 Zaubertrank swapon[265560]: swapon: /var/lib/systemd-swap/swapfc/28: swapon fehlgeschlagen: Die Operation ist nicht erlaubt
Dez 27 01:36:53 Zaubertrank systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Swap process exited, code=exited, status=255/EXCEPTION
Dez 27 01:36:53 Zaubertrank systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Failed with result 'exit-code'.
Dez 27 01:36:53 Zaubertrank systemd[1]: Failed to activate swap Swap File.

Dez 27 01:36:53 Zaubertrank swapon[265560]: swapon: /var/lib/systemd-swap/swapfc/28: swapon fehlgeschlagen: Die Operation ist nicht erlaubt translates to "swapon failed: the operation is not permitted"

Termuellinator commented 3 years ago

i've observed it the last couple days and the error still appears on swapfc-1.swap most of the times :/

vilgotf commented 3 years ago

You could manually use the bash branch (4.3.x) for now (you should probably just be able to just replace /usr/bin/systemd-swap with the bash version), development has stalled on the python branch since I've stopped using it. I do plan on ramping up development come summer

Termuellinator commented 3 years ago

oh, i wasn't aware of the rewrite - i've downgraded to 4.3.3 and will keep you posted!

May i ask how you setup your swap now if you stopped using you script here? For me, it seems like the most elegant way i've found yet :)

vilgotf commented 3 years ago

I only use zram so this is enough https://github.com/systemd/zram-generator

ben-foxmoore commented 3 years ago

Same issue observed here, with exactly the same swap chunk number. Log from both systemd units:

[ben@thoth arm-linux-gnueabihf-binutils]$ sudo journalctl -f -u systemd-swap
[sudo] password for ben: 
-- Journal begins at Fri 2020-08-14 09:28:36 CEST. --
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: Zswap: backup current configuration: complete
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: Zswap: set new parameters: start
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: Zswap: Enable: 1, Comp: zstd, Max pool %: 25, Zpool: z3fold
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: Zswap: set new parameters: complete
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: Writing destroy info...
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: swapD: pick up devices from systemd-gpt-auto-generator
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: swapD: searching swap devices
Feb 09 11:03:30 thoth systemd-swap[461]: INFO: swapFC: on-demand swap activation at >10329 MiB memory usage
Feb 09 11:03:30 thoth systemd[1]: Started Manage swap spaces on zram, files and partitions..
Feb 09 11:26:16 thoth systemd-swap[461]: INFO: swapFC: free ram: 34 < 35 - allocate chunk:  1
Feb 09 11:29:11 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  2
Feb 09 11:29:39 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  3
Feb 09 11:29:58 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  4
Feb 09 11:30:04 thoth systemd-swap[461]: INFO: swapFC: free swap: 8 < 15 - allocate chunk:  5
Feb 09 11:30:06 thoth systemd-swap[461]: INFO: swapFC: free swap: 11 < 15 - allocate chunk:  6
Feb 09 11:30:22 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  7
Feb 09 11:30:25 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  8
Feb 09 11:30:48 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  9
Feb 09 11:31:06 thoth systemd-swap[461]: INFO: swapFC: free swap: 9 < 15 - allocate chunk:  10
Feb 09 11:31:08 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  11
Feb 09 11:31:23 thoth systemd-swap[461]: INFO: swapFC: free swap: 11 < 15 - allocate chunk:  12
Feb 09 11:31:25 thoth systemd-swap[461]: INFO: swapFC: free swap: 11 < 15 - allocate chunk:  13
Feb 09 11:31:28 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  14
Feb 09 11:31:48 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  15
Feb 09 11:31:50 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  16
Feb 09 11:32:03 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  17
Feb 09 11:32:06 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  18
Feb 09 11:32:28 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  19
Feb 09 11:32:34 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  20
Feb 09 11:32:37 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  21
Feb 09 11:32:40 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  22
Feb 09 11:33:35 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  23
Feb 09 11:33:39 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  24
Feb 09 11:33:52 thoth systemd-swap[461]: INFO: swapFC: free swap: 13 < 15 - allocate chunk:  25
Feb 09 11:34:08 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  26
Feb 09 11:34:25 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  27
Feb 09 11:35:00 thoth systemd-swap[461]: INFO: swapFC: free swap: 14 < 15 - allocate chunk:  28
Feb 09 11:35:02 thoth systemd-swap[260592]: Job failed. See "journalctl -xe" for details.
Feb 09 11:35:02 thoth systemd-swap[461]: Traceback (most recent call last):
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/bin/systemd-swap", line 904, in <module>
Feb 09 11:35:02 thoth systemd-swap[461]:     main()
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/bin/systemd-swap", line 892, in main
Feb 09 11:35:02 thoth systemd-swap[461]:     start()
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/bin/systemd-swap", line 734, in start
Feb 09 11:35:02 thoth systemd-swap[461]:     swap_fc.run()
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/bin/systemd-swap", line 237, in run
Feb 09 11:35:02 thoth systemd-swap[461]:     self.create_swapfile(
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/bin/systemd-swap", line 329, in create_swapfile
Feb 09 11:35:02 thoth systemd-swap[461]:     subprocess.run(["systemctl", "start", unit_name], check=True)
Feb 09 11:35:02 thoth systemd-swap[461]:   File "/usr/lib/python3.9/subprocess.py", line 524, in run
Feb 09 11:35:02 thoth systemd-swap[461]:     raise CalledProcessError(retcode, process.args,
Feb 09 11:35:02 thoth systemd-swap[461]: subprocess.CalledProcessError: Command '['systemctl', 'start', 'var-lib-systemd\\x2dswap-swapfc-28.swap']' returned non-zero exit status 1.
Feb 09 11:35:02 thoth systemd[1]: systemd-swap.service: Main process exited, code=exited, status=1/FAILURE
Feb 09 11:35:02 thoth systemd[1]: systemd-swap.service: Failed with result 'exit-code'.
^C
[ben@thoth arm-linux-gnueabihf-binutils]$ sudo journalctl -u var-lib-systemd\\x2dswap-swapfc-28.swap
[sudo] password for ben: 
-- Journal begins at Fri 2020-08-14 09:28:36 CEST, ends at Tue 2021-02-09 11:37:16 CET. --
Feb 08 17:04:47 thoth systemd[1]: Activating swap Swap File...
Feb 08 17:04:47 thoth swapon[1776984]: swapon: /var/lib/systemd-swap/swapfc/28: swapon failed: Operation not permitted
Feb 08 17:04:47 thoth systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Swap process exited, code=exited, status=255/EXCEPTION
Feb 08 17:04:47 thoth systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Failed with result 'exit-code'.
Feb 08 17:04:47 thoth systemd[1]: Failed to activate swap Swap File.
-- Boot d9d41bc175cb4199a5918b6445f2f9e1 --
Feb 09 11:35:02 thoth systemd[1]: Activating swap Swap File...
Feb 09 11:35:02 thoth swapon[260593]: swapon: /var/lib/systemd-swap/swapfc/28: swapon failed: Operation not permitted
Feb 09 11:35:02 thoth systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Swap process exited, code=exited, status=255/EXCEPTION
Feb 09 11:35:02 thoth systemd[1]: var-lib-systemd\x2dswap-swapfc-28.swap: Failed with result 'exit-code'.
Feb 09 11:35:02 thoth systemd[1]: Failed to activate swap Swap File.

In the log, it looks like the same swap chunk failed on a previous boot as well.

oold commented 2 years ago

There is a kernel limit for the amount of active swap files. Should be 32 and it seems like additional limitations imposed by some kernel configuration options can bring that down to 27 (https://unix.stackexchange.com/a/638358). That would explain why the exact number of swap files when it fails is 28. We should probably update the default settings accordingly.