Repository: rclone/rclone (language: go)

Issue:
rclone rcd unmount triggers sd-notify STOPPING notification
<!--

We understand you are having a problem with rclone; we want to help you with that!

**STOP and READ**
**YOUR POST WILL BE REMOVED IF IT IS LOW QUALITY**:
Please show the effort you've put into solving the problem and please be specific.
People are volunteering their time to help! Low effort posts are not likely to get good answers!

If you think you might have found a bug, try to replicate it with the latest beta (or stable).
The update instructions are available at https://rclone.org/commands/rclone_selfupdate/

If you can still replicate it or just got a question then please use the rclone forum:

    https://forum.rclone.org/

for a quick response instead of filing an issue on this repo.

If nothing else helps, then please fill in the info below which helps us help you.

**DO NOT REDACT** any information except passwords/keys/personal info.

You should use 3 backticks to begin and end your paste to make it readable.

Make sure to include a log obtained with '-vv'.

You can also use '-vv --log-file bug.log' and a service such as https://pastebin.com or https://gist.github.com/

Thank you

The Rclone Developers

-->

#### The associated forum post URL from `https://forum.rclone.org`
n/a


#### What is the problem you are having with rclone?
rclone rcd creates sd-notify notifications for each mount / unmount operation.  
In case rclone rcd is started as a systemd service this behavior puts the systemd service into the ' deactivating' state and subsequently triggers a SIGABRT by systemd after the stop timeout because the service is not actually stopping.

The culprit is most probably: https://github.com/rclone/rclone/blob/bb679a9def96019f05c2b9ca473b27c2de2190e2/cmd/mountlib/mount.go#L308

mountlib should not propagate systemd notifications, but only commands should propagate them.

#### What is your rclone version (output from `rclone version`)
```
rclone 1.64.2
- os/version: fedora 39 (64 bit)
- os/kernel: 6.6.8-200.fc39.x86_64 (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.1
- go/linking: dynamic
- go/tags: none
```

#### Which OS you are using and how many bits (e.g. Windows 7, 64 bit)
Fedora 39, 64bit


#### Which cloud storage system are you using? (e.g. Google Drive)
Google Drive, OneDrive


#### The command you were trying to run (e.g. `rclone copy /tmp remote:tmp`)
sd-notify mock:
```shell
socat unix-recv:/tmp/rclone-notify.sock -
```

rclone rcd:
```shell
NOTIFY_SOCKET="/tmp/rclone-notify.sock" rclone rcd --rc-addr "localhost:5573" --rc-no-auth -vv
```

rclone rc mount:
```shell
rclone rc --rc-addr "localhost:5573" mount/mount "fs=onedrive:" "mountPoint=/run/user/1000/rclone/onedrive"
```

rclone rc unmount:
```shell
rclone rc --rc-addr "localhost:5573" mount/unmount "mountPoint=/run/user/1000/rclone/onedrive"
```

1. Start sd-notify mock
2. Start rclone rcd
  a) sd-notify mock output: `READY=1`
3. Start rclone rc mount
  a) sd-notify mock output: `READY=1` (Note: This notification should not have been generated but is harmless)
4. Start rclone rc unmount
  a) sd-notify mock output: `STOPPING=1` (Note: This notification would mark the systemd service as "deactivating" and is most probably the problem)
5. Stop rclone rcd
  a) sd-notify mock output: `STOPPING=1`

#### A log from the command with the `-vv` flag (e.g. output from `rclone -vv copy /tmp remote:tmp`)
```
2024/01/03 12:50:45 DEBUG : rclone: Version "1.64.2" starting with parameters ["rclone" "rcd" "--rc-addr" "localhost:5573" "--rc-no-auth" "-vv"]
2024/01/03 12:50:45 NOTICE: Serving remote control on http://127.0.0.1:5573/
2024/01/03 12:50:58 DEBUG : rc: "mount/mount": with parameters map[fs:onedrive: mountPoint:/run/user/1000/rclone/onedrive]
2024/01/03 12:50:58 DEBUG : Creating backend with remote "onedrive:"
2024/01/03 12:50:58 DEBUG : Using config file from "/home/xxxxx/.config/rclone/rclone.conf"
2024/01/03 12:50:59 DEBUG : OneDrive root '': Next delta token is: [...]
2024/01/03 12:50:59 NOTICE: OneDrive root '': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2024/01/03 12:50:59 DEBUG : OneDrive root '': Mounting on "/run/user/1000/rclone/onedrive"
2024/01/03 12:50:59 DEBUG : Mount for OneDrive root '' created at /run/user/1000/rclone/onedrive using mount
2024/01/03 12:50:59 DEBUG : rc: "mount/mount": reply map[]: <nil>
2024/01/03 12:50:59 DEBUG : : Root: 
2024/01/03 12:50:59 DEBUG : : >Root: node=/, err=<nil>
2024/01/03 12:50:59 DEBUG : /: Lookup: name=".Trash"
2024/01/03 12:50:59 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2024/01/03 12:50:59 DEBUG : /: Lookup: name=".Trash-1000"
2024/01/03 12:50:59 DEBUG : /: >Lookup: node=.Trash-1000/, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/: Attr: 
2024/01/03 12:50:59 DEBUG : .Trash-1000/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/: Lookup: name="files"
2024/01/03 12:50:59 DEBUG : .Trash-1000/: >Lookup: node=.Trash-1000/files/, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/files/: Attr: 
2024/01/03 12:50:59 DEBUG : .Trash-1000/files/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/files/: ReadDirAll: 
2024/01/03 12:50:59 DEBUG : .Trash-1000/files/: >ReadDirAll: item=4, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/: Lookup: name="info"
2024/01/03 12:50:59 DEBUG : .Trash-1000/: >Lookup: node=.Trash-1000/info/, err=<nil>
2024/01/03 12:50:59 DEBUG : .Trash-1000/info/: Attr: 
2024/01/03 12:50:59 DEBUG : .Trash-1000/info/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
[...]
2024/01/03 12:51:05 DEBUG : rc: "mount/unmount": with parameters map[mountPoint:/run/user/1000/rclone/onedrive]
2024/01/03 12:51:05 DEBUG : /run/user/1000/rclone/onedrive: Unmounted externally. Just exit now.
2024/01/03 12:51:05 DEBUG : rc: "mount/unmount": reply map[]: <nil>
^C2024/01/03 12:51:15 INFO  : Signal received: interrupt
2024/01/03 12:51:15 DEBUG : rclone: Version "1.64.2" finishing with parameters ["rclone" "rcd" "--rc-addr" "localhost:5573" "--rc-no-auth" "-vv"]
2024/01/03 12:51:15 INFO  : Exiting...
```


<!--- Please keep the note below for others who read your bug report. -->

#### How to use GitHub

* Please use the 👍 [reaction](https://blog.github.com/2016-03-10-add-reactions-to-pull-requests-issues-and-comments/) to show that you are affected by the same issue.
* Please don't comment if you have no relevant information to add. It's just extra noise for everyone subscribed to this issue.
* Subscribe to receive notifications on status change and new comments.



Discussion / hints:
This is because the rcd calls `daemon.SdNotify(false, daemon.SdNotifyReady)` and so does the mount. The calls don't nest apparently!

I think we probably need to reference count the SdNotify calls. So increment a counter and call 
`daemon.SdNotify(false, daemon.SdNotifyReady)` when the counter goes from 0->1 and 
`daemon.SdNotify(false, daemon.SdNotifyStopping)` when the counter goes from 1->0 and otherwise do nothing.

@darthShadow you were the last to touch this code - what do you think?
Ideally, we shouldn't be calling the SDNotify API at all if it's not the main process. I think this would have worked fine if the mount was started in the daemon mode. @Syquel Can you please confirm if you see the same issue with the daemon option specified for the mount?

If that works, perhaps we should make that the default (or even the only option) for mounts started via rc or is there a use-case for non-daemon mounts via rc?
It seems that rcd does not support the daemon option.
https://github.com/rclone/rclone/blob/eb5fd07131f0e8b84941d1f01efbdebf4f3d7785/cmd/mountlib/rc.go#L100-L102

Fix patch:
diff --git a/cmd/mountlib/mount.go b/cmd/mountlib/mount.go
index 4a539e0f7dc21..0e54193983973 100644
--- a/cmd/mountlib/mount.go
+++ b/cmd/mountlib/mount.go
@@ -18,11 +18,11 @@ import (
 	"github.com/rclone/rclone/fs/config/flags"
 	"github.com/rclone/rclone/lib/atexit"
 	"github.com/rclone/rclone/lib/daemonize"
+	"github.com/rclone/rclone/lib/systemd"
 	"github.com/rclone/rclone/vfs"
 	"github.com/rclone/rclone/vfs/vfscommon"
 	"github.com/rclone/rclone/vfs/vfsflags"
 
-	"github.com/coreos/go-systemd/v22/daemon"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 )
@@ -307,6 +307,7 @@ func NewMountCommand(commandName string, hidden bool, mount MountFn) *cobra.Comm
 			// Wait for foreground mount, if any...
 			if mountDaemon == nil {
 				if err == nil {
+					defer systemd.Notify()()
 					err = mnt.Wait()
 				}
 				if err != nil {
@@ -385,7 +386,6 @@ func (m *MountPoint) Wait() error {
 	var finaliseOnce sync.Once
 	finalise := func() {
 		finaliseOnce.Do(func() {
-			_, _ = daemon.SdNotify(false, daemon.SdNotifyStopping)
 			// Unmount only if directory was mounted by rclone, e.g. don't unmount autofs hooks.
 			if err := CheckMountReady(m.MountPoint); err != nil {
 				fs.Debugf(m.MountPoint, "Unmounted externally. Just exit now.")
@@ -401,11 +401,6 @@ func (m *MountPoint) Wait() error {
 	fnHandle := atexit.Register(finalise)
 	defer atexit.Unregister(fnHandle)
 
-	// Notify systemd
-	if _, err := daemon.SdNotify(false, daemon.SdNotifyReady); err != nil {
-		return fmt.Errorf("failed to notify systemd: %w", err)
-	}
-
 	// Reload VFS cache on SIGHUP
 	sigHup := make(chan os.Signal, 1)
 	NotifyOnSigHup(sigHup)
diff --git a/lib/systemd/notify.go b/lib/systemd/notify.go
index 8dccafb4f0975..2373431470930 100644
--- a/lib/systemd/notify.go
+++ b/lib/systemd/notify.go
@@ -9,10 +9,13 @@ import (
 	"github.com/rclone/rclone/lib/atexit"
 )
 
-// Notify systemd that the service is starting. This returns a
+// Notify systemd that the service is ready. This returns a
 // function which should be called to notify that the service is
 // stopping. This function will be called on exit if the service exits
 // on a signal.
+// NOTE: this function should only be called once, and so it
+// should generally only be used directly in a command's Run handler.
+// It should not be called as a result of rc commands. See #7540.
 func Notify() func() {
 	if _, err := daemon.SdNotify(false, daemon.SdNotifyReady); err != nil {
 		log.Printf("failed to notify ready to systemd: %v", err)


Test patch: