Automount option in fstab prevents automatically mounting a partition in due time on Bookworm

huidbui25 · 26 July 2023 09:26

Required Information

DietPi version | cat /boot/dietpi/.version
G_DIETPI_VERSION_CORE=8
G_DIETPI_VERSION_SUB=19
G_DIETPI_VERSION_RC=1
G_GITBRANCH=‘master’
G_GITOWNER=‘MichaIng’
G_LIVE_PATCH_STATUS[0]=‘applied’
G_LIVE_PATCH_STATUS[1]=‘applied’
G_LIVE_PATCH_STATUS[2]=‘not applicable’
Distro version | echo $G_DISTRO_NAME $G_RASPBIAN
bookworm 0
Kernel version | uname -a
Linux DietPi 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr 3 17:24:16 BST 2023 aarch64 GNU/Linux
Architecture | dpkg --print-architecture
arm64
SBC model | echo $G_HW_MODEL_NAME or (EG: RPi3)
RPi 3 Model B (aarch64)
SD card used | (EG: SanDisk ultra)
64 GB card, not all of that space needed though.
Plus dietpi_userdata moved to an USB-connected SSD that is automatically mounted through fstab.

Additional Information (if applicable)

Software title
Vaultwarden (installed using dietpi-software)
Was the software title installed freshly or updated/migrated?
Freshly installed on a fresh Dietpi Bookworm image (no update at all).
However, of course, re-using my previous Vaultwarden config and database on the new system (i.e. Vaultwarden’s dietpi_userdata subfolder)
Can this issue be replicated on a fresh installation of DietPi?
Yes, see question above. But it only appears on DietPi Bookworm. It worked flawlessly before on BullsEye (v11).

Steps to reproduce

The raspberry is freshly started, e.g. after a manual boot or after a poweroff
Trying to connect to vaultwarden, but impossible since its service failed to start.

Expected behaviour

Vaultwarden service should be automatically started at boot

Actual behaviour

Vaultwarden service fails to automatically start at boot

Extra details

I was on BullyEye (v11) before and everything worked fone. I did a fresh Bookworm install (i.e. no update to Bookworm, but started from scratch with a new image) and installed Vaultwarden on it using dietpi-software. But whenever I boot the system, vaultwarden fails to start automatically.
Manually starting the service fails, too, in the first instance.
It complains it cannot find the environment/config files and hence fails to start.
However, after a few minutes of waiting I can manually start Vaultwarden all of a sudden as if nothing had been wrong before. Thus, to me it appears as there is some timing issue.
I also checked if the vaultwarden files are accessible. Everything looks fine here. Right after boot I can SSH into DietPi and access the dietpi_userdata-folder where Vaultwarden’s environment file is located. And note: Eventhough the files are accessible, a manual start of the Vaultwarden service doesn’t work for a few minutes after boot. No clue why.
Failed service right after boot:

root@DietPi:~# systemctl status vaultwarden
× vaultwarden.service - vaultwarden (DietPi)
     Loaded: loaded (/lib/systemd/system/vaultwarden.service; enabled; preset: enabled)
     Active: failed (Result: resources) since Wed 2023-07-26 02:25:35 CEST; 8h ago
       Docs: https://github.com/dani-garcia/vaultwarden
        CPU: 0

Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 5.
Jul 26 02:25:35 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Start request repeated too quickly.
Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:35 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).

Trying to manually start vaultwarden fails, too:

root@DietPi:~# systemctl start vaultwarden
Job for vaultwarden.service failed because of unavailable resources or another system error.
See "systemctl status vaultwarden.service" and "journalctl -xeu vaultwarden.service" for details.

This is what the syslog says:

root@DietPi:~# journalctl -u vaultwarden
Jul 26 02:25:09 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 26 02:25:09 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 26 02:25:09 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:09 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:14 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 1.
Jul 26 02:25:14 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:14 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 26 02:25:14 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 26 02:25:14 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:14 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:20 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 2.
Jul 26 02:25:20 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:20 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 26 02:25:20 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 26 02:25:20 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:20 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:25 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 3.
Jul 26 02:25:25 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:25 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 26 02:25:25 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 26 02:25:25 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:25 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:30 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 4.
Jul 26 02:25:30 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:30 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 26 02:25:30 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 26 02:25:30 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:30 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 5.
Jul 26 02:25:35 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Start request repeated too quickly.
Jul 26 02:25:35 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 02:25:35 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).
Jul 26 10:41:35 DietPi systemd[1]: vaultwarden.service: Start request repeated too quickly.
Jul 26 10:41:35 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 26 10:41:35 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).

And after a few minutes of waiting, the service can be started all of a sudden and works flawlessly until the next system boot:

root@DietPi:~# systemctl status vaultwarden
● vaultwarden.service - vaultwarden (DietPi)
     Loaded: loaded (/lib/systemd/system/vaultwarden.service; enabled; preset: enabled)
     Active: active (running) since Wed 2023-07-26 10:46:36 CEST; 12s ago
       Docs: https://github.com/dani-garcia/vaultwarden
   Main PID: 1250 (vaultwarden)
      Tasks: 13 (limit: 1069)
        CPU: 418ms
     CGroup: /system.slice/vaultwarden.service
             └─1250 /opt/vaultwarden/vaultwarden

Jul 26 10:46:37 DietPi vaultwarden[1250]: | Report suspected bugs/issues in the software itself at:            |
Jul 26 10:46:37 DietPi vaultwarden[1250]: |   https://github.com/dani-garcia/vaultwarden/issues/new            |
Jul 26 10:46:37 DietPi vaultwarden[1250]: \--------------------------------------------------------------------/
Jul 26 10:46:37 DietPi vaultwarden[1250]: [INFO] Using environment file `.env` for configuration.
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.958][rocket::shield::shield::_][WARN] Detected TLS-enabled liftoff without enabling HSTS.
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.958][rocket::shield::shield::_][WARN] Detected TLS-enabled liftoff without enabling HSTS.
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.962][rocket::shield::shield::_][WARN] Shield has enabled a default HSTS policy.
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.962][rocket::shield::shield::_][WARN] Shield has enabled a default HSTS policy.
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.963][start][INFO] Rocket has launched from https://0.0.0.0:8001
Jul 26 10:46:37 DietPi vaultwarden[1250]: [2023-07-26 10:46:37.963][start][INFO] Rocket has launched from https://0.0.0.0:8001

A boot time analysis doesn’t show problems to me:

root@DietPi:~# systemd-analyze blame
2.930s php8.2-fpm.service
2.829s ifupdown-pre.service
1.933s unbound.service
1.457s boot.mount
1.381s dev-mmcblk0p2.device
1.258s phpsessionclean.service
1.144s ssh.service
1.004s lighttpd.service
 636ms systemd-udev-trigger.service
 607ms keyboard-setup.service
 366ms systemd-fsck@dev-disk-by\x2dpartuuid-780ce4e2\x2d01.service
 324ms networking.service
 304ms systemd-fsck-root.service
 297ms systemd-timesyncd.service
 290ms ifup@eth0.service
 276ms systemd-journald.service
 238ms dietpi-preboot.service
 217ms systemd-udevd.service
 193ms dietpi-ramlog.service
 167ms pihole-FTL.service
 167ms systemd-remount-fs.service
 155ms sys-kernel-debug.mount
 153ms dev-mqueue.mount
 151ms sys-kernel-tracing.mount
 142ms fake-hwclock.service
 133ms kmod-static-nodes.service
 132ms modprobe@configfs.service
 130ms systemd-modules-load.service
 129ms modprobe@dm_mod.service
 126ms modprobe@efi_pstore.service
 123ms systemd-sysctl.service
 122ms modprobe@fuse.service
 119ms modprobe@loop.service
  94ms systemd-journal-flush.service
  92ms systemd-sysusers.service
  89ms systemd-tmpfiles-setup.service
  86ms systemd-random-seed.service
  78ms systemd-tmpfiles-setup-dev.service
  58ms systemd-user-sessions.service
  57ms mnt-mymediassd.mount
  52ms systemd-update-utmp.service
  50ms var-swap.swap
  47ms systemd-update-utmp-runlevel.service
  30ms tmp.mount
  28ms console-setup.service
  26ms var-log.mount
  24ms sys-fs-fuse-connections.mount
  19ms sys-kernel-config.mount

Joulinar · 26 July 2023 12:50

hmm I did a test on my Orange Pi5. Installed Vaultwarden on Bullseye and performed the upgrade to Bookworm. After reboot Vaultwarden is starting fine still.

Do you use an external drive where dietpi user data is located on? Can you share the whole output of journalctl 5 minutes after reboot? It will be a long output and you could attach it as log file or use pastebin

mantas · 27 July 2023 19:25

Today I faced a few issues regarding Vaultwarden, including the one that OP described. Some info from my side:

I noticed that I can’t access my Vaultwarden Web Vault. I found out that on May, 2022 Vaultwarden started to bind ROCKET_ADDRESS to 127.0.0.1 instead of 0.0.0.0, which is weird because I always could access my Web Vault and only started running into issues today and I was always up-to-date with DietPi and Vaultwarden.
I changed my ROCKET_ADDRESS to 0.0.0.0 in dietpi_userdata/vaultwarden/vaultwarden.env and that’s when I started having problems like OP. The only difference was that even after a few minutes I wasn’t able to start Vaultwarden service.
I changed my ROCKET_ADDRESS to my RPi local IP and now it works fine.

I’m running latest Vaultwarden and DietPi on RPi 3B+ bullseye.
Hope this helps for anyone who will try to figure and solve this issue.

Joulinar · 27 July 2023 19:47

Your issue seems to be different as vaultwarden was starting but bound to a different port.

This change has been introduced last year by vaultwarden developer and is available on our implementation for long time already.

What was the setting before?

huidbui25 · 27 July 2023 20:03

Hi!

Thank you … and sorry for the delay. Wasn’t at home.

How can I delete/flush the log (journal) to only have new entries since the boot? Currentl it seems to contain old entries before the boot.

Joulinar · 27 July 2023 20:15

Did you enabled permanent logs? Default setting would be to clear logs on reboot.

huidbui25 · 27 July 2023 20:20

Naa, sorry … please forget my previous post. I was confused.

I have just rebooted the rPi and the log only shows the entries since the reboot.

Now waiting a bit until I can manually start vaultwarden service. Currently it fails and doesn’t let me start it … yet. As described above. Will post the complete log as soon as I could start vaultwarden service.

huidbui25 · 27 July 2023 20:36

Hi Joulinar!

So, here’s the complete logfile since boot. (If you like me to post it differently, please let me know. I didn’t manage to find a way to leave the colours of the log output intact.)

As described: The Vaultwarden service cannot be started automatically. If I try so manually, it refuses to start for a few minutes after boot. And all of a sudden the manuel start works.

Yes, the Vaultwarden files (i.e. database and environment file) are stored in dietpi_userdata folder. This is located on an external Verbatim SSD connected by USB and automatically mounted on boot. I don’t assume there is a problem with that because the same setup (SSD, folder, mounting) works flawlessly on Bullseye. And I can access the vaultwarden folder on the SSD through SSH right after boot. The problem only came up with Bookworm now.

The SSD mounting point is called “/mnt/mymediassd”.

journalctl _output.txt (58.1 KB)

Joulinar · 28 July 2023 05:41

Your disk is not mounted directly during boot. It just mounts on your user request, which is ok and expected. You see your login process and I guess you checked the drive/folder?

Jul 27 22:16:05 DietPi sshd[1071]: Accepted password for root from 192.168.66.13 port 49931 ssh2
Jul 27 22:16:05 DietPi sshd[1071]: pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0)
Jul 27 22:16:05 DietPi sshd[1071]: pam_env(sshd:session): deprecated reading of user environment enabled
Jul 27 22:16:05 DietPi systemd[1]: mnt-mymediassd.automount: Got automount request for /mnt/mymediassd, triggered by 1077 (bash)
Jul 27 22:16:05 DietPi systemd[1]: Mounting mnt-mymediassd.mount - /mnt/mymediassd...
Jul 27 22:16:05 DietPi kernel: BTRFS info (device sda1): using crc32c (crc32c-generic) checksum algorithm
Jul 27 22:16:05 DietPi kernel: BTRFS info (device sda1): enabling ssd optimizations
Jul 27 22:16:05 DietPi kernel: BTRFS info (device sda1): disk space caching is enabled
Jul 27 22:16:05 DietPi systemd[1]: Mounted mnt-mymediassd.mount - /mnt/mymediassd.

But Vaultwarden is started way before this

Jul 27 22:12:37 DietPi systemd[1]: vaultwarden.service: Failed to load environment files: No such file or directory
Jul 27 22:12:37 DietPi systemd[1]: vaultwarden.service: Failed to run 'start' task: No such file or directory
Jul 27 22:12:37 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.

After 5 tries, Vaultwarden service is giving up and is blocked for some minutes as it is restarting too quickly.

Jul 27 22:13:03 DietPi systemd[1]: vaultwarden.service: Scheduled restart job, restart counter is at 5.
Jul 27 22:13:03 DietPi systemd[1]: Stopped vaultwarden.service - vaultwarden (DietPi).
Jul 27 22:13:03 DietPi systemd[1]: vaultwarden.service: Start request repeated too quickly.
Jul 27 22:13:03 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 27 22:13:03 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).

You see, you are not able to start as it is blocked still.

Jul 27 22:21:05 DietPi systemd[1]: vaultwarden.service: Start request repeated too quickly.
Jul 27 22:21:05 DietPi systemd[1]: vaultwarden.service: Failed with result 'resources'.
Jul 27 22:21:05 DietPi systemd[1]: Failed to start vaultwarden.service - vaultwarden (DietPi).

Soooo, usually the automatic mount should be triggered by Vaultwarden as well, but somehow this did not happen. Can you share following:

cat /etc/fstab

mantas · 28 July 2023 06:56

By default my ROCKET_ADDRESS is commented out. And if I leave it commented out it binds to 127.0.0.1. Looks like DietPi implementation of this fix doesn’t get applied for me, for some reason. Even though I did dietpi-software reinstall 183

Joulinar · 28 July 2023 07:44

on DietPi, we use an own Debian package file hosted on our server https://dietpi.com/downloads/binaries/

I just had a look and the configuration is correct inside the package.

## Rocket specific settings
## See https://rocket.rs/v0.4/guide/configuration/ for more details.
ROCKET_ADDRESS=0.0.0.0
ROCKET_PORT=8001
# ROCKET_WORKERS=10
ROCKET_TLS={certs="./cert.pem",key="./privkey.pem"}

But I guess the configuration file will not be overwritten by the debian packge to avoid loosing own config changed done by end user.

mantas · 28 July 2023 08:22

Should I delete my .env file in order for DietPi one to be applied?
But it’s still weird that if I set it as ROCKET_ADDRESS=0.0.0.0 I get retries errors

Joulinar · 28 July 2023 08:34

I thought it was working for you now?

Some more logs are needed after fresh reboot

journalctl -u vaultwarden

huidbui25 · 28 July 2023 10:31

Hi Joulinar!

Oh yes, thank you very much. I guess I didn’t see that because I could access the files through WinSCP but only Vaultwarden could not - so I assumed the mounting itself should be okay.

You say that Vaultwarden is blocking further starts. Well, that would make sense then.

Here the fstab:

# You can use "dietpi-drive_manager" to setup mounts.
# NB: It overwrites and re-creates physical drive mount entries on use.
#----------------------------------------------------------------
# NETWORK
#----------------------------------------------------------------


#----------------------------------------------------------------
# TMPFS
#----------------------------------------------------------------
tmpfs /tmp tmpfs size=1024M,noatime,lazytime,nodev,nosuid,mode=1777
tmpfs /var/log tmpfs size=60M,noatime,lazytime,nodev,nosuid

#----------------------------------------------------------------
# MISC: ecryptfs, vboxsf, glusterfs, mergerfs, bind, Btrfs subvolume
#----------------------------------------------------------------


#----------------------------------------------------------------
# SWAP SPACE
#----------------------------------------------------------------
/var/swap none swap sw

#----------------------------------------------------------------
# PHYSICAL DRIVES
#----------------------------------------------------------------
PARTUUID=780ce4e2-02 / ext4 noatime,lazytime,rw 0 1
PARTUUID=780ce4e2-01 /boot vfat noatime,lazytime,rw 0 2
UUID=d5149685-f80a-4b1a-9b69-e61f089e3b88 /mnt/mymediassd btrfs ssd,noatime,lazytime,rw,nofail,auto,x-systemd.automount

These are the same arguments (ssd, lazytime, etc.) in the UUID-line as before on Bullyeye. So I didn’t really expect problems here.

mantas · 28 July 2023 11:42

It’s working when I set ROCKET_ADDRESS to my local RPi IP address, it doesn’t when I set it to 0.0.0.0

Joulinar · 28 July 2023 11:56

Do you use special firewall rules? Normally 0.0.0.0 means to LISTEN on all interfaces and IP ranges, not only on a specific interface. On your system there seems to be something special because 0.0.0.0 is used by default by almost all applications.

mantas · 28 July 2023 12:10

I don’t. And I can reach every other application, except Vaultwarden (if ROCKET_ADDRESS is set to 0.0.0.0). And this only started happening yesterday for some reason

Joulinar · 28 July 2023 12:15

We did not changed or updated anything from our side. And you did not install anything or performed any other task?

Joulinar · 28 July 2023 12:31

looks like an issue with x-systemd.automount option on Debian Bookworm. Something changed upstream. Not sure if this is a bug inside the global Debian config or if simply the option changed. Something to check. As workaround, can you can remove the option from /etc/fstab and try again to reboot. BUT: don’t use drive manager at the moment as this will add x-systemd.automount again

mantas · 28 July 2023 13:25

No, same thing on my side - didn’t do anything