gcsfuse hangs when called from systemd startup

[AssortedParrot]

Automatically mounting via /etc/fstab fails, so I set up a systemd mount unit that looks like this:

[Unit]
Description=GCS bucket automount
Requires=network-online.target
After=network-online.target

[Mount]
What=my-gcs-bucket
Where=/var/gcs
Type=gcsfuse-wrapper
Options=rw,user

[Install]
WantedBy=multi-user.target

gcsfuse-wrapper is a wrapper script that strips away the -n option that /sbin/mount.gcsfuse does not understand. For debugging, it also waits 15 seconds before actually calling /sbin/mount.gcsfuse to ensure that the network is actually up.

When systemd tries to mount the unit during startup, it hangs.

root@instance:~# systemctl status var-gcs.mount -l
● var-gcs.mount - GCS bucket automount
   Loaded: loaded (/etc/systemd/system/var-gcs.mount; disabled)
   Active: activating (mounting) since Thu 2016-09-08 17:37:05 UTC; 32s ago
    Where: /var/gcs
     What: my-gcs-bucket
  Control: 673 (mount)
   CGroup: /system.slice/var-gcs.mount
           ├─673 /bin/mount -n my-gcs-bucket /var-gcs -t gcsfuse-wrapper -o rw,user
           ├─674 /sbin/mount.gcsfuse-wrapper my-gcs-bucket /var/gcs -n -o rw,noexec,nosuid,nodev,user
           ├─738 sh -c '/sbin/mount.gcsfuse' '-o' 'rw' '-o' 'noexec' '-o' 'nosuid' '-o' 'nodev' '-o' 'user' 'my-gcs-bucket' '/var/gcs'
           ├─739 /sbin/mount.gcsfuse -o rw -o noexec -o nosuid -o nodev -o user my-gcs-bucket /var/gcs
           ├─742 gcsfuse -o noexec -o nosuid -o nodev -o rw my-gcs-bucket /var/gcs
           └─749 /usr/bin/gcsfuse --foreground -o noexec -o nosuid -o nodev -o rw my-gcs-bucket /var/gcs

Sep 08 17:37:05 instance systemd[1]: Mounting GCS bucket automount...
Sep 08 17:37:05 instance mount[673]: [wrapper] Sleeping for 15 seconds to wait for the network to come up...
Sep 08 17:37:21 instance mount[673]: [wrapper] Invoking gcsfuse with: '/sbin/mount.gcsfuse' '-o' 'rw' '-o' 'noexec' '-o' 'nosuid' '-o' 'nodev' '-o' 'user' 'my-gcs-bucket' '/var/gcs'
Sep 08 17:37:21 instance mount[673]: Calling gcsfuse with arguments: -o noexec -o nosuid -o nodev -o rw my-gcs-bucket /var/gcs
Sep 08 17:37:21 instance mount[673]: Using mount point: /var/gcs
Sep 08 17:37:21 instance mount[673]: Opening GCS connection...
Sep 08 17:37:21 instance mount[673]: Opening bucket...
Sep 08 17:37:21 instance mount[673]: Mounting file system...

After a while, systemd will timeout and terminate the process. If I issue a systemctl restart var-gcs.mount, it will work just fine and properly mount the bucket.

Unfortunately, I was unable to make /sbin/mount.gcsfuse accept the --debug_* options, so I cannot provide more detailed information.

What could be causing this, and how can I work around it? Or is there a better way to automatically mount the bucket on boot?

[jacobsa]

Sorry, I'm far from an expert on systemd so I fear I'm a bit ill-equipped here. Are you able to do anything like send SIGQUIT to the process and seeing what shows up on stderr, or use strace to see what it's doing?

You may also try adding printf debugging to the code for mount.gcsfuse.

[AssortedParrot]

I modified mount.gcsfuse so it accepts -o debug, making it pass --foreground --debug_fuse --debug_gcs --debug_invariants to gcsfuse. However, that still doesn't help much.

root@instance:~# systemctl status var-gcs.mount -l
● var-gcs.mount - /var/gcs automount
   Loaded: loaded (/etc/systemd/system/var-gcs.mount; disabled)
   Active: active (mounting-done) since Fri 2016-09-09 11:09:03 UTC; 5s ago
    Where: /var/gcs
     What: my-gcs-bucket
  Control: 675 (mount)
   CGroup: /system.slice/var-gcs.mount
           ├─675 /bin/mount -n my-gcs-bucket /var/gcs -t gcsfuse-wrapper -o rw,user,debug
           ├─676 /sbin/mount.gcsfuse-wrapper my-gcs-bucket /var/gcs -n -o rw,noexec,nosuid,nodev,debug,user
           ├─797 sh -c '/sbin/mount.gcsfuse' '-o' 'rw' '-o' 'noexec' '-o' 'nosuid' '-o' 'nodev' '-o' 'debug' '-o' 'user' 'my-gcs-bucket' '/var/gcs'
           ├─798 /sbin/mount.gcsfuse -o rw -o noexec -o nosuid -o nodev -o debug -o user my-gcs-bucket /var/gcs
           └─801 gcsfuse -o rw -o noexec -o nosuid -o nodev --debug_fuse --debug_gcs --debug_invariants --foreground my-gcs-bucket /var/gcs

Sep 09 11:09:02 instance mount[675]: root. If this is not what you intended, invoke gcsfuse as the user that will
Sep 09 11:09:02 instance mount[675]: be interacting with the file system.
Sep 09 11:09:02 instance mount[675]: Opening bucket...
Sep 09 11:09:02 instance mount[675]: gcs: Req              0x0: <- ListObjects()
Sep 09 11:09:03 instance mount[675]: gcs: Req              0x0: -> ListObjects() (168.103999ms): OK
Sep 09 11:09:03 instance mount[675]: Mounting file system...
Sep 09 11:09:03 instance systemd[1]: Mounted /var/gcs automount.
Sep 09 11:09:03 instance mount[675]: fuse_debug: Op 0x00000001        connection.go:395] <- init
Sep 09 11:09:03 instance mount[675]: fuse_debug: Op 0x00000001        connection.go:474] -> OK ()
Sep 09 11:09:03 instance mount[675]: File system has been successfully mounted.
root@instance:~# ls -l /var/gcs
^C
root@instance:~# systemctl restart var-gcs.mount
root@instance:~# systemctl status var-gcs.mount -l
● var-gcs.mount - /var/gcs automount
   Loaded: loaded (/etc/systemd/system/var-gcs.mount; disabled)
   Active: active (mounting-done) since Fri 2016-09-09 11:10:07 UTC; 2s ago
    Where: /var/gcs
     What: my-gcs-bucket
  Process: 821 ExecUnmount=/bin/umount -n /var/gcs (code=exited, status=0/SUCCESS)
  Control: 823 (mount)
   CGroup: /system.slice/var-gcs.mount
           ├─823 /bin/mount -n my-gcs-bucket /var/gcs -t gcsfuse-wrapper -o rw,user,debug
           ├─824 /usr/bin/php /sbin/mount.gcsfuse-wrapper my-gcs-bucket /var/gcs -n -o rw,noexec,nosuid,nodev,debug,user
           ├─830 sh -c '/sbin/mount.gcsfuse' '-o' 'rw' '-o' 'noexec' '-o' 'nosuid' '-o' 'nodev' '-o' 'debug' '-o' 'user' 'my-gcs-bucket' '/var/gcs'
           ├─831 /sbin/mount.gcsfuse -o rw -o noexec -o nosuid -o nodev -o debug -o user my-gcs-bucket /var/gcs
           └─834 gcsfuse -o rw -o noexec -o nosuid -o nodev --debug_fuse --debug_gcs --debug_invariants --foreground my-gcs-bucket /var/gcs

Sep 09 11:10:07 instance mount[823]: WARNING: gcsfuse invoked as root. This will cause all files to be owned by
Sep 09 11:10:07 instance mount[823]: root. If this is not what you intended, invoke gcsfuse as the user that will
Sep 09 11:10:07 instance mount[823]: be interacting with the file system.
Sep 09 11:10:07 instance mount[823]: Opening bucket...
Sep 09 11:10:07 instance mount[823]: gcs: Req              0x0: <- ListObjects()
Sep 09 11:10:07 instance mount[823]: gcs: Req              0x0: -> ListObjects() (107.861916ms): OK
Sep 09 11:10:07 instance mount[823]: Mounting file system...
Sep 09 11:10:07 instance systemd[1]: Mounted /var/gcs automount.
Sep 09 11:10:07 instance mount[823]: fuse_debug: Op 0x00000001        connection.go:395] <- init
Sep 09 11:10:07 instance mount[823]: fuse_debug: Op 0x00000001        connection.go:474] -> OK ()
Sep 09 11:10:07 instance mount[823]: File system has been successfully mounted.
root@instance:~# ls -l /var/gcs
total 0
drw-r--r-- 1 root root 0 Sep  9 11:10 test.txt

As you can see, the ls -l /var/gcs still hangs. The output of gcsfuse doesn't really differ between the two invocations. The first one never works, but the second (and all subsequent ones) work.

Sending a SIGQUIT to gcsfuse produces this output (extracted from the syslog because it's running from systemd).

straceing the wrapper script + all child processes produces a huge load of output.

Any other thing I could try to help debug the issue?

[jacobsa]

I notice this is automount. See this discussion, where @ashamza identified a deadlock. Are you able to try the code workaround we discussed there?

[AssortedParrot]

I'm not exactly sure which workaround to try or how. I added printfs before and after the call os os.Stat, and the output suggests that the call does not block.

Sep 12 13:32:19 instance mount[676]: Opening bucket...
Sep 12 13:32:19 instance mount[676]: gcs: Req              0x0: <- ListObjects()
Sep 12 13:32:19 instance mount[676]: gcs: Req              0x0: -> ListObjects() (144.519067ms): OK
Sep 12 13:32:19 instance mount[676]: Mounting file system...
Sep 12 13:32:19 instance mount[676]: fuse: 2016/09/12 13:32:19.265617 before stat() on /var/gcs
Sep 12 13:32:19 instance mount[676]: fuse: 2016/09/12 13:32:19.266104 after stat() on /var/gcs
Sep 12 13:32:19 instance systemd[1]: Mounted /var/gcs automount.
Sep 12 13:32:19 instance mount[676]: fuse_debug: Op 0x00000001        connection.go:395] <- init
Sep 12 13:32:19 instance mount[676]: fuse_debug: Op 0x00000001        connection.go:474] -> OK ()
Sep 12 13:32:19 instance mount[676]: File system has been successfully mounted.
root@instance:~# ls -l /var/gcs
^C

In fact, even if I remove the call entirely, ls -l /var/gcs still hangs.

(Also, just for the record, I'm trying to automatically mount the FS on boot. systemd also supports "on-demand" automounting, where it will defer the mount until the first time the directory is accessed, but this is not what I'm trying to do.)

[jacobsa]

Ah interesting. The workaround I meant was removing the call entirely (on Linux). So apparently that's not the issue.

To clarify, because it's hard to tell for sure from your output: is the gcsfuse process still running? It's not in a stopped state or something like that? Does /proc/<pid>/stack for the various thread IDs agree that it's waiting on a read from /dev/fuse?

[AssortedParrot]

Yes, it's still running. (I'm still running it with --debug_* and --foreground; hopefully that's not a problem)

This gist contains the contents of /proc/<pid>/stack when gcsfuse is running 1) when started automatically on boot, where it doesn't work, and 2) after it's restarted, where it starts working.

[jacobsa]

Thanks for the nice gist. A few things:

• Unfortunately, the gcsfuse process is going to have several threads. Are you
  able to capture the stack for all of them?
• Dumb question: have you done whatever dance is necessary with systemd to make
  sure /dev/fuse is initialized correctly before the mount begins?
• Another dumb question: are you sure the permissions are right here? What UID
  is the gcsfuse process running as? And ls (looks like root)?
• What does /proc show for the kernel stack for the hanging ls process?

[AssortedParrot]

Unfortunately, the gcsfuse process is going to have several threads. Are you able to capture the stack for all of them?

Sorry, I did not realize that. Here's a new gist that should contain the stack of all threads when gcsfuse is started after boot (stack-after-boot.log) and when it's restarted (stack-after-restart.log). It also contains the stack of ls -l /var/gcs while it blocks.

Dumb question: have you done whatever dance is necessary with systemd to make
sure /dev/fuse is initialized correctly before the mount begins?

I don't know about /dev/fuse, but systemctl list-units | grep fuse suggests that systemd manages /sys/modules/fuse and /sys/fs/fuse/connections. Adding explicit After= and Requires= to my unit file doesn't seem to fix the issue.

Another dumb question: are you sure the permissions are right here? What UID
is the gcsfuse process running as? And ls (looks like root)?

Both gcsfuse and ls are running as root right now, for simplicity. I thought I'd try to get it up and running first, then change the user everything is running as.

[jacobsa]

Thanks, that's really helpful. I wonder if the problem here is root though -- I know that fuse treats it specially (see for example the allow_root mount option). Could you try running both gcsfuse and ls as another, unprivileged users? (The same user for both.)

[AssortedParrot]

Okay, now I'm confused.

I added the User= option to my .mount file, which produced errors while mounting because systemd passes --no-mtab to mount, which it will reject if it's not called by root.

To work around this, I converted the .mount unit to a .service unit that just calls gcsfuse directly. And this worked... both as root, and as a normal user. Unfortunately this isn't a good solution because this way, /var/gcs isn't actually recognized as a mount point, i.e. you can't use the normal mount/umount commands on it.

I didn't find a simple way to make systemd not pass --no-mtab to mount, so I couldn't really test it as a .mount unit as a normal user. Not really sure how to proceed from here...

[jacobsa]

Sorry for the slow response. Unfortunately knowing nothing about systemd, I'm also not sure. :-/

[ashamza]

Systemd is different than what I am doing but I tried to do a systemd configuration and looks like systemd is working so I am wondering why it isn't working with @AssortedParrot.

I have two questions to @AssortedParrot:

• Does /var/gcs already exist? If yes who is the owner and what are the permissions it has. If no did you try to create it manually?
• Have you tried to run gcsfuse directly instead of mount.gcsfuse using nohup and --foreground?

I have a workaround that makes automount works which is using a wrapper to call gcsfuse with --foreground using nohup. For some reason this is working but all my other tries didn't fully succeed.

When I first tried automounting it used to hang in gcsfuse binary that run with --foreground. I first tried to remove the os.Stat then I found that the fusermount binary was called and now fusermount is the one that hangs. I also tried to move daemonize.SignalOutcome(nil) call before the mount start to mock what I am doing with nohup but also this didn't work (I didn't investigate why doesn't this solution work yet).

[jacobsa]

@AssortedParrot: what's your current understanding of this issue? Do you think it is a gcsfuse bug?

[jbaublitz]

@AssortedParrot I'm about to test a patch that was just merged. I found the same problem that mount.gcsfuse was getting -n and didn't know what to do with it. I will post my results here but if you get around to testing it as a mount file first, please let me know. The one thing that you should be aware of is I tried to patch this for the gcsfuse executable as well but because of the package that is used for CLI parsing in the case of the executable itself, if -n is passed to gcsfuse at the end of the command line (which is unfortunately what systemd does), gcsfuse thinks it is an argument and errors out with too many arguments. Therefore, you are probably better off testing this using a .mount file with Type=gcsfuse as originally planned because I had no luck with .service files due to systemd and this Go CLI package not playing well together.

[jbaublitz]

@AssortedParrot I think I now see what your problem is. I just tested the systemd service file I created to integrate with the patch I submitted. Now I am getting an error around the --no-mtab flag as well because I am not root.

@jacobsa I see a few issues with the gcsfuse invocation requirements that will make it very hard to integrate with systemd.

1. Only the CLI invocation will allow you to specify the credentials to use when mounting the bucket both from the command line and from an environment variable. Given that .mount files require helpers in my experience to resolve the Type parameter in .mount files, the helper would need to accept at least one of these methods. Otherwise, we must always depend on the application default credentials being registered for the user which one could argue defeats the purpose of systemd integration. For now, I'm going to try to write a second service as a work around to register these credentials using gcloud called from systemd and will report back on this.
2. gcsfuse requires the command to be run as the user mounting the bucket. This will remove the possibility of using gcsfuse to mount buckets as a regular user as mount is currently complaining that --no-mtab is being passed to it. This is a problem because it means that we will only be able to access bucket files as root.

Do you have any thoughts around these changes? I'm happy to try to help implement some of them.

[jacobsa]

(Please bear with my dumb questions. I don't know the first thing about systemd, and only a little about mount helpers.)

1. Is the existing support for a key_file option not sufficient here?
2. How are root vs. regular user and --no-mtab related? For context, the original reason that I made gcsfuse require you to be the mounting user is because of a heap of security implications documented in the kernel fuse documentation. I haven't thought hard about whether they are relevant here.

[jbaublitz]

1. I looked at the source code for gcsfuse vs. mount.gcsfuse and see that the --key-file parameter passes a key_file option to the mount helper. I had seen this before but was looking a little while ago so it slipped my mind. Now that I remember, we can disregard this as it should not be an issue.
2. If there are security implications, I understand that prioritizing those is very important. However the mount executable has a number of parameters that are only allowed as root. This means that because --no-mtab for instance (which only root can specify) is automatically added by .mount files, unless gcsfuse can handle running itself as another user when invoked as root, there is no way to give the file system permissions other than root from a .mount file. This in my opinion is more of an issue with systemd not allowing adequate ability to configure how mount is invoked from the .mount files but I feel that working around systemd might make more sense in this case.

[jacobsa]

Again I'm confused—why is --no-mtab relevant to the question of which user invokes gcsfuse?

It seems like it would be possible and pragmatic to write a wrapper which, when run as root, changes to the correct user and then runs gcsfuse, right?

[jbaublitz]

.mount files do not really have this option unfortunately. While .service files allow you to specify a script to run, .mount files really just are data about the filesystem to be mounted. It will just call the mount helper directly based on the Type parameter.

[jacobsa]

Sure. But you could have a Type specified as gcsfuse_systemd with a mount.gcsfuse_systemd binary, right?

It's feeling to me like this issue belongs in the systemd bug tracker, with a workaround for systemd distributed separately until the bug is fixed.

[jbaublitz]

To be fair, I also believe this belongs in the systemd bug tracker. However I decided to try to work around this on this end because the systemd developers are notoriously disagreeable according to many of the people who have worked with them. I think the work around you propose sounds reasonable and I am willing to reach out to the systemd people to see if they are willing to change this but my expectation is that this work around will be the only way of integrating with systemd moving forward.

[jacobsa]

Right, that's sad. :-(

What I'd like to happen here; please tell me if you agree:

1. Move the existing -n workaround into a new mount.gcsfuse_systemd binary. Perhaps this should live in another repo, owned by you, since I don't know anything at all about systemd. (I'm not 100% set on this.)
2. Add any other workarounds necessary to that binary.
3. File a systemd bug for each workaround that was necessary, including the -n one.
4. Add references to those bugs to the code for the workarounds.

[jbaublitz]

@jacobsa That sounds like a good idea to me. It might take me a bit to get around to this but if you would like to assign this issue to me on Github just so I have a reminder on my account that I need to do this, that would be great. Thanks!

[jacobsa]

I must admit to being a GitHub simpleton. When I click on the gear next to assignees I see a list of people including myself and AssortedParrot, but not you. If I type "jbaublitz" and hit enter, nothing at all happens. Am I missing something?

[jbaublitz]

Hmmmm... I have never done this before so I might need to have access to the repo. If that is the case, I will just do it the "old fashioned" way and make a note for myself. :) Once I create the repo, I will put a link to it here for bookkeeping purposes. Thanks!

[jbaublitz]

Here is the link where I will be developing this for anyone who is interested.

[jacobsa]

Thanks. To be clear, I'm not recommending you fork the existing project. I think this just needs to be a simple tool that calls into gcsfuse or mount.gcsfuse, right?

[jbaublitz]

Whoops. I was going to do that in the existing project for integration purposes but I can create a separate project that just contains that code if that is preferable. I'll fix that.

[craigafinch]

I have a created a systemd service to mount a Google Cloud Storage volume via gcsfuse on boot. The trick to avoiding the "lock on boot" problem is to ensure that it runs after sys-fs-fuse-connections.mount.

It has worked for me on two Google VM instances so far. Use it at your own risk; I recommend setting a root password on the VM and enabling the serial console before rebooting, in case this service locks up your instance on boot.

[jbaublitz]

@jacobsa I realized I never followed up on this. Sorry to have dropped the ball. Currently I am using a .service file in systemd with the --foreground flag passed to the gcsfuse executable and Type=simple in the [Service] definition. I can dig back into this if more detail is helpful, but as I remember, none of the other types of services in systemd would really work with the gcsfuse executable. The foreground and simple service seems to be the magic combo that keeps gcsfuse running in a daemonized state. Even forking seemed to cause issues without --foreground where the gcsfuse executable would mount until the systemd finished starting the service and then the filesystem would disappear as soon as the initialization was done. Still not sure why that is. I can paste the entire service file if that's of interest. I still have not had time to work on implementing the caller for systemd because this implementation seems to work. Is this something that's still of interest or is this a good enough workaround? If compatibility with mounting through .service files is sufficient, I will paste the exact contents of the file here. Otherwise I will keep you updated on my progress with the caller wrapper.

@craigafinch I am curious how you're getting forking working. That never seemed to work for me. See above for the exact behavior. In any case I will try that again just to verify.

[craigafinch]

@jbaublitz I provided my systemd service file as a link to a gist in a previous comment. Do you have any other specific questions?

[jbaublitz]

@craigafinch Thank you for your contribution. I took a moment to verify and it does indeed work in the current version of systemd and gcsfuse.

@jacobsa I can no longer reproduce the behavior that I saw with forking and am at a loss for exactly why this was happening but it could be something unrelated on my end. Unless you are still interested in a mount helper, this solution is perfectly acceptable in my use case.

[jacobsa]

Great, thanks for the update. I'll close this then; let me know if anything comes up.