After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 766433 - FUSE mounts do not appear at all
FUSE mounts do not appear at all
Status: RESOLVED NOTGNOME
Product: gdm
Classification: Core
Component: general
3.20.x
Other Linux
: Normal normal
: ---
Assigned To: gvfs-maint
gvfs-maint
Depends on:
Blocks:
 
 
Reported: 2016-05-14 11:26 UTC by Martin Szulecki
Modified: 2016-05-20 18:49 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Log of gdm starting up on vt8 breaking gvfsd-fuse mounting (17.60 KB, text/plain)
2016-05-20 11:54 UTC, Martin Szulecki
Details

Description Martin Szulecki 2016-05-14 11:26:25 UTC
As already reported as perhaps related to bug #753561, on openSUSE Tumbleweed the "/run/user/1000/gvfs" directory just stays empty despite mounts are added/removed using Nautilus (GTK-bookmarks). This breaks a lot of apps that do not directly use the GVFS API but the fuse filesystem way to access remote files.

Currently running: Kernel 4.5.4, gvfs 1.28.2, fuse 2.9.5, dbus 1.10.8 and sytsemd 228.

If I restart "gvfsd-fuse" manually, directories for mounts work as expected.
Mounting was tested either trough Nautilus and using "gvfs-mount". Neither works.

I recompiled with "DEBUG_ENABLED", added some more debugging and got a "vfs.debug" file which lists a bunch of vfs.* operations as you navigate to the gvfs fuse mount directory.

However, despite "subthread_main" is running, the "mount_tracker_mounted_cb" and "mount_tracker_unmounted_cb" callbacks are never called.

If "gvfsd-fuse" is manually restarted, the callbacks are again called correctly again thus the mount point directories appear as expected.

I somehow suspect there is a problem with the proxy volume monitor but I have limited knowledge of the GVFS DBUS pingpong to debug it appropriately... please give a hint.
Comment 1 Ondrej Holy 2016-05-16 11:39:19 UTC
Thanks for the bug report. It seems to me that the proxy volume monitor is not involved for daemon mounts. Deamon mounts are handled by GDeamonVolumeMonitor, which is registered itself as GIO extension. I suppose there is some problem with GDeamonVolumeMonitor. The reason why Nautilus see the mounts is because GDeamonVolumeMonitor is not singleton. So I suppose there is some race and the monitor is probably constructed too early and something is broken there...

I can't see this with Fedora 24, but it seems it can be reproduced using openSUSE Tumbleweed live CD...
Comment 2 Martin Szulecki 2016-05-17 12:34:18 UTC
Doesn't that mean that the DBUS session bus that GDaemonVolumeMonitor (and the mount tracker) uses somehow does not work correctly as the signals are not received? Nautilus and "gvfs-mount" are started later and both get the signals.

Usually systemd will wait for the dbus name to be acquired but I think the codepath does a "lazy" start here, right?

From the gdm startup debug log I noticed that "vfs.debug" is updated a few seconds before gdm-x-session outputs "Running session message bus".

Perhaps I'll try to see what happens if it's already running upfront.
Any other hint how I could debug this?
Comment 3 Ondrej Holy 2016-05-18 07:51:36 UTC
(In reply to Ondrej Holy from comment #1)
> I can't see this with Fedora 24, but it seems it can be reproduced using
> openSUSE Tumbleweed live CD...

It seems it happens only after boot, but I don't see any relevant error messages. So I installed openSUSE to make additional tests, however it fails to boot due to some kernel failure :-(

(In reply to Martin Szulecki from comment #2)
> Doesn't that mean that the DBUS session bus that GDaemonVolumeMonitor (and
> the mount tracker) uses somehow does not work correctly as the signals are
> not received? Nautilus and "gvfs-mount" are started later and both get the
> signals.

Yep, that's more or less what I thought...

I can see "Mounted" signal from mount tracer using dbus-monitor, so there is something wrong with the instance of GDaemonVolumeMonitor. I suppose it fails in this point:
https://git.gnome.org/browse/gvfs/tree/client/gdaemonvolumemonitor.c#n206

We can't see any errors probably because the fuse daemon is spawned with G_SPAWN_STDERR_TO_DEV_NULL, see:
https://git.gnome.org/browse/gvfs/tree/daemon/main.c#n103

I was able to reproduce it even on F24 following way yesterday, however it doesn't work today :-(:
export $(dbus-launch); gvfs-mount localtest:///

> Usually systemd will wait for the dbus name to be acquired but I think the
> codepath does a "lazy" start here, right?
> 
> From the gdm startup debug log I noticed that "vfs.debug" is updated a few
> seconds before gdm-x-session outputs "Running session message bus".

Good catch, this might be the problem, but I wonder, how it can happen, because mount tracer is registered in bus_acquired_handler and fuse daemon is spawned in name_acquired_handler. See:
https://git.gnome.org/browse/gvfs/tree/daemon/main.c#n67

Hmm, perhaps it might be somehow related to systemd user units...

> Perhaps I'll try to see what happens if it's already running upfront.
> Any other hint how I could debug this?

Probably best what we can do is to add some prints in gdaemonvolumemonitor.c,  and prove the ideas...
Comment 4 Martin Szulecki 2016-05-18 09:46:15 UTC
I have noticed that two "gvfsd" processes are spawned and I am not sure if that is the expected behavior. The first one is apparently triggered by gnome-session as far as I could investigate, the latter starts up when the desktop comes up.

Both processes use different values for "DBUS_SESSION_BUS_ADDRESS" according to "/proc/<PID>/environ".

One is used by "gvfsd-fuse" while the other address is the one that Nautilus and all other backend daemons share after login. Effectively this means that the first bus doesn't get the mount messages appearing on the second bus. That also would explain why starting "gvfsd-fuse" manually afterwards fixes the situation as it will start to use the correct session bus.

For me this indicates that the D-BUS session is not correctly propagated during boot/login for some reason.

I'll also try to involve downstream since gdm is pretty "patched" on openSUSE.
Comment 5 Ondrej Holy 2016-05-18 09:59:16 UTC
This is probably because of the following bug 752278 in gdm.

But you should also see two gvfsd-fuse daemons, however each with different mountpoint ("/run/user/$(id -u)/gvfs" vs "/run/user/$(id -u gdm)/gvfs"), so this should not be problem, you can check it using "ps ax | grep gvfs".
Comment 6 Martin Szulecki 2016-05-18 10:33:58 UTC
(In reply to Ondrej Holy from comment #3)
> (In reply to Ondrej Holy from comment #1)
> > I can't see this with Fedora 24, but it seems it can be reproduced using
> > openSUSE Tumbleweed live CD...
> 
> It seems it happens only after boot, but I don't see any relevant error
> messages. So I installed openSUSE to make additional tests, however it fails
> to boot due to some kernel failure :-(

You probably need to add "rootfstype=ramfs" to the kernel cmdline to boot correctly. I verified the issue is indeed visible with the oS TW live cd.

It is enough to relogin to re-establish a state with the issue, a full reboot is not required.
Comment 7 Martin Szulecki 2016-05-18 12:57:22 UTC
There is no "/run/user/$(id -u gdm)/gvfs" mount created ever in the chain as far as I checked.

$ ps ax | grep gvfsd
19182 tty8     Sl+    0:00 /usr/lib/gvfs/gvfsd -d
19194 tty8     Sl+    0:00 /usr/lib/gvfs/gvfsd-fuse /run/user/1000/gvfs -f -o big_writes
19234 ?        Sl     0:00 /usr/lib/gvfs/gvfsd -d
19323 ?        Sl     0:00 /usr/lib/gvfs/gvfsd-metadata
28282 ?        Sl     0:00 /usr/lib/gvfs/gvfsd-trash --debug --spawner :1.1 /org/gtk/gvfs/exec_spaw/0

I see that there are systems where this is not reproducible and things work.
It appears that on these systems only a single "gvfsd" process is running after login and it is using the correct DBUS session bus.

Reported it downstream here:
https://bugzilla.opensuse.org/show_bug.cgi?id=980521
Comment 8 Ondrej Holy 2016-05-18 14:59:25 UTC
Ah, that's the problem, good catch again! The both gvfsd processes belongs to same user:
linux@nohostname:~> ps aux | grep gvfsd$
linux     2234  0.0  0.2  37864  6088 tty7     Sl+  14:28   0:00 /usr/lib/gvfs/gvfsd
linux     2239  0.0  0.2  50684  5020 tty7     Sl+  14:28   0:00 /usr/lib/gvfs/gvfsd

And yes, there are running two sesion buses for one user, which is obviously wrong:
linux@nohostname:~> ps aux | grep dbus-daemon | grep session
linux     2083  0.0  0.1   6008  4112 tty7     S+   14:28   0:00 dbus-daemon --print-address 4 --session
linux     2482  0.0  0.1   6516  3596 ?        Ss   14:28   0:00 /bin/dbus-daemon --fork --print-pid 5 --print-address 7 --session

In such case the second fuse daemon fails because mount point is already used...

It seems that the first one is spawned by gdm, so it might be related with the bug I mentioned earlier:
linux@nohostname:~> pstree -s 2083
systemd───gdm───gdm-session-wor───gdm-x-session───dbus-daemon
linux@nohostname:~> pstree -s 2482
systemd───dbus-daemon

However under Fedora the first session bus is running under user gdm, so this may be caused by the downstream patches as you told...
Comment 9 Martin Szulecki 2016-05-18 16:30:17 UTC
Another thing I found...
I started the failing system with nouveau instead of NVIDIA's binary driver.
Guess what... single "gvfsd" and the fuse mounts appear.
Installed the blob again and it fails.
Not sure yet if the drivers have influence but it smells like a nasty thing somewhere in "gdm" during the login/xsession process.
Comment 10 Ondrej Holy 2016-05-20 08:18:42 UTC
The OpenSUSE should apply GDM patches related to bug 752278. If the additional dbus sessions are needed, it should have GIO_USE_VFS=local (and maybe GVFS_DISABLE_FUSE=1 for sure). Closing as NOTGNOME.
Comment 11 Martin Szulecki 2016-05-20 11:54:42 UTC
Created attachment 328252 [details]
Log of gdm starting up on vt8 breaking gvfsd-fuse mounting

The patches you mention were already applied. GDM (on vt7) does start a session bus but all is fine with it since it uses a separate address and the environment variables and thus not blocking the fuse mountpoint.

The issue is for the regular user, who must be able to start GVFS.

I enabled full tracing on the system and it doesn't point at a distro specific problem for me (yet). Next to two "gvfsd" processes running I also spotted two "dconf-service" daemons that itself causes other problems...

In the attached log, "gdm-x-session" spawns a dbus user session bus that gets used by the first "gvfsd" which mounts the fuse point with "gvfsd-fuse" correctly (dbus address /tmp/dbus-Z5CBrn32qu). Then, for some reason and most likely related to the cause of the bug, systemd spawns another dbus user session bus (dbus address /tmp/dbus-WEsBUBGVbE).

The latter one gets picked up by another "org.gtk.vfs.Daemon" / "gvfsd" daemon (not sure where that one is launched from?) which fails to start "gvfsd-fuse" as obviously the mountpoint is already in use by the previous instance.

As far as I read up, systemd is responsible for creating dbus user sessions since version 226. Perhaps that conflicts with the idea of "gdm-x-session" creating one?

I also noticed the second "ok" session bus processes have "_=/bin/dbus-update-activation-environment" in their environment.

How to determine what starts the second "gvfsd"? I don't see any systemd dbus activation notice for it in the logs...

It that the expected gdm login/startup procedure or does anything look suspicious?
Comment 12 Martin Szulecki 2016-05-20 12:05:56 UTC
Maybe this is more systemd/gdm related and easier for the guys so reassigning.

To add up on the questions above. Does the following pstree of gdm look correct?

systemd,1,root --switched-root --system --deserialize 24
  └─gdm,1367,root
      ├─gdm-session-wor,1389,root [pam/gdm-launch-environment]
      │   ├─gdm-x-session,1453,gdm gnome-session --autostart /usr/share/gdm/greeter/autostart --debug
      │   │   ├─Xorg,1455 vt7 -displayfd 3 -auth /run/user/109/gdm/Xauthority -background none -noreset -keeptty -verbose 7 -core
      │   │   ├─dbus-daemon,1904 --print-address 4 --session
      │   │   ├─gnome-session-b,1906 --autostart /usr/share/gdm/greeter/autostart --debug
...
      ├─gdm-session-wor,2152,root [pam/gdm-password]
      │   ├─gdm-x-session,2163,linux --run-script gnome
      │   │   ├─Xorg,2165 vt8 -displayfd 3 -auth /run/user/1000/gdm/Xauthority -background none -noreset -keeptty -verbose 7 -core
      │   │   ├─dbus-daemon,2168 --print-address 4 --session
      │   │   ├─gnome-session-b,2170 --debug
...
Comment 13 Martin Szulecki 2016-05-20 18:49:17 UTC
Nevermind, found the cause. The openSUSE xdm configuration script "/etc/X11/xdm/sys.xsession" from the "xdm" package did mess with "DBUS_SESSION_BUS_ADDRESS" and apparently caused the problem.

Disabling it leads to a well working GNOME session and a single working gvfs setup.
Thanks for the help, the issue was very annoying.