systemd vnc service does not startup properly during VM startup when user home is mounted with NFS root squash

[sroth80021]

Describe the bug
systemd vnc service does not start properly during VM startup when user home is mounted with NFS root squash.

To Reproduce

1. install systemd vnc service on Oracle Linux 9
2. systemctl disable firewalld
3. create user with NFS home directory, and ensure NFS root squash is enabled.
4. add user to /etc/tigervnc/vncserver.users with :2 display
5. sudo to user and run vncpasswd to set password
6. systemctl enable vncserver@:2.service
7. systemctl start vncserver@:2.service
8. verify vnc session from client works properly
9. reboot system
10. systemctl status vncserver@:2.service (should be active)
11. netstat -nltlp | grep 5902 (should be open)

Actual behavior for step 10 is:
[sroth@sroth-ol9 ~]$ systemctl status vncserver@:2.service
○ vncserver@:2.service - Remote desktop service (VNC)
Loaded: loaded (/etc/systemd/system/vncserver@:2.service; enabled; preset: disabled)
Active: inactive (dead) since Fri 2025-01-10 11:21:46 EST; 4min 8s ago
Duration: 4ms
Process: 2361 ExecStartPre=/usr/libexec/vncsession-restore :2 (code=exited, status=0/SUCCESS)
Process: 2370 ExecStart=/usr/libexec/vncsession-start :2 (code=exited, status=0/SUCCESS)
Main PID: 2377 (code=exited, status=0/SUCCESS)
CPU: 24ms

Expected behavior
vncserver@:2.service should be Active and port 5902 should be open.

Server (please complete the following information):

• OS: Oracle Linux 9.5
• VNC server: TigerVNC
• VNC server version: 1.14.1-1
• Server downloaded from: ol9_appstream yum repository
• Server was started using: systemctl enable vncserver@:2.service

Additional context
With a local user, the vncserver service starts up properly during VM startup.

It appears that vncservice (as root) is trying to write to the user's home directory at path ~/.local/state/tigervnc. I see the following logged in journalctl:

[root@sroth-ol9 ~]# journalctl -fe|grep vnc
Jan 10 15:12:51 sroth-ol9.... vncsession[2406]: pam_unix(tigervnc:session): session opened for user sroth(uid=....) by sroth(uid=0)
Jan 10 15:12:51 sroth-ol9.... vncsession[3057]: Failure creating "/home/sroth/.local/state/tigervnc": Permission denied
Jan 10 15:12:51 sroth-ol9..... vncsession[2406]: vncsession: vncserver exited with status=71

It also seems to work properly for a user with a NFS root squash home directory if I change the systemd service file to delay startup until the end of the VM startup process, by changing

After=syslog.target network.target systemd-user-sessions.service
to
After=multi-user.target

I'm not sure why/how that changes the behavior, but it provided a workaround in my case.

[sroth80021]

Also as an FYI, the syslog.target referenced in the systemd unit file does not appear to exist on Oracle Linux 9.5:

[root@sroth-ol9 ~]# systemctl status syslog.target
Unit syslog.target could not be found.

This does not appear to be the cause of this issue, and does not appear to cause issues during startup, just FYI.

[CendioOssman]

root squash was actually considered during the design, so it should not be the problem. The fact that a delay resolves is supports that theory.

Perhaps the issue is that the service starts before the home directory is mounted?

Please restore the service file to original and reboot. Then check the output of the command systemd-analyze critical-chain vncserver@:2.service.

[sroth80021]

This is the output from systemd-analyze critical-chain vncserver@:2.service:

The time when unit became active or started is printed after the "@" character.
The time the unit took to start is printed after the "+" character.

vncserver@:2.service +397ms
└─systemd-user-sessions.service @4.085s +4ms
  └─cloud-config.service @3.831s +251ms
    └─oci-yum-repo-mapper.service @3.829s
      └─network-online.target @3.822s
        └─cloud-init.service @3.529s +291ms
          └─NetworkManager-wait-online.service @3.509s +18ms
            └─NetworkManager.service @2.955s +552ms
              └─network-pre.target @2.954s
                └─cloud-init-local.service @2.342s +611ms
                  └─dbus.socket @2.339s
                    └─sysinit.target @2.336s
                      └─systemd-update-utmp.service @2.328s +7ms
                        └─auditd.service @2.279s +47ms
                          └─systemd-tmpfiles-setup.service @2.121s +156ms
                            └─local-fs.target @2.117s
                              └─run-user-1002-doc.mount @7.678s
                                └─run-user-1002.mount @4.283s
                                  └─local-fs-pre.target @1.598s
                                    └─systemd-tmpfiles-setup-dev.service @556ms +46ms
                                      └─kmod-static-nodes.service @497ms +32ms
                                        └─systemd-journald.socket
                                          └─system.slice
                                            └─-.slice

I also tried changing the service dependencies to explicitly add dependencies on the autofs mount:

[Unit]
...
After=syslog.target network.target systemd-user-sessions.service home-sroth.mount remote-fs.target
Requires=home-sroth.mount remote-fs.target
RequiresMountsFor=/home/sroth/Documents

...

Unfortunately, this also did not resolve the issue.

In journalctl logs, this is potentially interesting -- in this case I have sroth (autofs home directory with root squash) on :2 and srothlocal (local home directory): on :3.

Notice the 'failure creating' permission denied message. This directory /home/sroth/.local/state/tigervnc already exists, and for ~sroth/.local and below, all directories have sroth owner and 777 permissions. So I would expect only root would get this Permission Denied message, because root-squash is enabled. All other users should be able to write to that directory.

Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd[1]: Started Session 1 of User stevelocal.
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd[1]: Started Session 2 of User sroth.
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com vncsession[2475]: pam_unix(tigervnc:session): session opened for user stevelocal(uid=1002) by stevelocal(uid=0)
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd[1]: Started Remote desktop service (VNC).
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com NetworkManager[1816]: <info>  [1738273593.4761] audit: op="reload" arg="0" pid=2950 uid=0 result="success"
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com NetworkManager[1816]: <info>  [1738273593.4764] config: signal: SIGHUP (no changes from disk)
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com vncsession[2476]: pam_unix(tigervnc:session): session opened for user sroth(uid=504932) by sroth(uid=0)
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd[1]: Started Remote desktop service (VNC).
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com vncsession[2985]: Failure creating "/home/sroth/.local/state/tigervnc": Permission denied
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com vncsession[2476]: vncsession: vncserver exited with status=71
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com vncsession[2476]: pam_unix(tigervnc:session): session closed for user sroth
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd[1]: vncserver@:2.service: Deactivated successfully.
Jan 30 16:46:33 sroth-ol9.common.linuxandvirtiad.oraclevcn.com systemd-logind[1856]: Session 2 logged out. Waiting for processes to exit.

[sroth80021]

Even with the mods above, I tried verifying the home directory was available during the ExecStart phase and indeed found it is not.
/usr/bin/ls: cannot access '/home/sroth': No such file or directory

So clearly this is still an issue with my systemd config and my home directory not being available. I'll continue investigating on this side.

[CendioOssman]

This is the output from systemd-analyze critical-chain vncserver@:2.service:

Thanks. Unfortunately, I would expect to see remote-fs.target before systemd-user-sessions.service. That could explain the problems you are seeing.

Since this seems to be a general issue, and not a TigerVNC specific one, I'll close this issue for now. Feel free to update us if you find something new that indicates that it is a problem with our service.