Bug 445060 - autofs attempts to mount /net/.Trash (while nobody asked)
Summary: autofs attempts to mount /net/.Trash (while nobody asked)
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: autofs
Version: 9
Hardware: All
OS: Linux
low
low
Target Milestone: ---
Assignee: Ian Kent
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-05-03 01:53 UTC by Michal Jaegermann
Modified: 2010-09-24 14:51 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-06-10 12:48:37 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Michal Jaegermann 2008-05-03 01:53:33 UTC
Description of problem:

Starting a desktop session with autofs running (here
'automount -v' is really used) results in the following in logs:


automount[20685]: Starting automounter version 5.0.3-11, master map auto.master
automount[20685]: using kernel protocol version 5.00
automount[20685]: mounted indirect mount on /net with timeout 60, freq 15 seconds
automount[20685]: attempting to mount entry /net/.Trash
automount[20685]: create_udp_client:99: hostname lookup failed: No such process
automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
automount[20685]: lookup_mount: exports lookup failed for .Trash
automount[20685]: failed to mount /net/.Trash
automount[20685]: attempting to mount entry /net/.Trash-400
automount[20685]: create_udp_client:99: hostname lookup failed: No such process
automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
automount[20685]: lookup_mount: exports lookup failed for .Trash-400
automount[20685]: failed to mount /net/.Trash-400
automount[20685]: attempting to mount entry /net/.Trash
automount[20685]: create_udp_client:99: hostname lookup failed: No such process
automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
automount[20685]: lookup_mount: exports lookup failed for .Trash
automount[20685]: failed to mount /net/.Trash
automount[20685]: attempting to mount entry /net/.Trash-400
automount[20685]: create_udp_client:99: hostname lookup failed: No such process
automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
automount[20685]: lookup_mount: exports lookup failed for .Trash-400
automount[20685]: failed to mount /net/.Trash-400

???? 

"400" happens to a numerical id of an account used in this test.
That does not happen if only a text console is used.

Here the only thing active in /etc/auto.master is
/net -hosts --timeout=60

Version-Release number of selected component (if applicable):
autofs-5.0.3-11

How reproducible:
always

Comment 1 Ian Kent 2008-05-05 08:17:01 UTC
(In reply to comment #0)
> Description of problem:
> 
> Starting a desktop session with autofs running (here
> 'automount -v' is really used) results in the following in logs:
> 
> 
> automount[20685]: Starting automounter version 5.0.3-11, master map auto.master
> automount[20685]: using kernel protocol version 5.00
> automount[20685]: mounted indirect mount on /net with timeout 60, freq 15 seconds
> automount[20685]: attempting to mount entry /net/.Trash
> automount[20685]: create_udp_client:99: hostname lookup failed: No such process
> automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
> automount[20685]: lookup_mount: exports lookup failed for .Trash
> automount[20685]: failed to mount /net/.Trash
> automount[20685]: attempting to mount entry /net/.Trash-400
> automount[20685]: create_udp_client:99: hostname lookup failed: No such process
> automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
> automount[20685]: lookup_mount: exports lookup failed for .Trash-400
> automount[20685]: failed to mount /net/.Trash-400
> automount[20685]: attempting to mount entry /net/.Trash
> automount[20685]: create_udp_client:99: hostname lookup failed: No such process
> automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
> automount[20685]: lookup_mount: exports lookup failed for .Trash
> automount[20685]: failed to mount /net/.Trash
> automount[20685]: attempting to mount entry /net/.Trash-400
> automount[20685]: create_udp_client:99: hostname lookup failed: No such process
> automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
> automount[20685]: lookup_mount: exports lookup failed for .Trash-400
> automount[20685]: failed to mount /net/.Trash-400
> 
> ????
> 
> "400" happens to a numerical id of an account used in this test.

The more appropriate question would be why is Gnome trying to
create .Trash in /net?

Do you have a Nautilus bookmark which points to /net, if you
do then Nautilus is going to try and open it and create a
.Trash directory in it, but /net is an autofs file system
and so the this will always result in autofs attempting to
mount a file system on .Trash.


Comment 2 Michal Jaegermann 2008-05-05 15:47:19 UTC
> The more appropriate question would be why is Gnome trying to
> create .Trash in /net?

No idea.  I do not use Nautilus beyond what is by default necessary.
Besides /net is owned by root and has 755 permissions so directs
attempts to create /net/.Trash should fail right away.

I would consider log messages a mere annoyance if not a visible
difference in a desktop startup times depending if autofs is active
or not.

> Do you have a Nautilus bookmark which points to /net

Nothing like that created knowingly.  If I try to "Edit Bookmarks"
from any "Places" menu in various Nautilus windows then I am getting
"No bookmarks defined".

I am seeing the same effect on various accounts from my test system.


Comment 3 Jeff Moyer 2008-05-05 19:01:50 UTC
(In reply to comment #0)
> Description of problem:
> 
> Starting a desktop session with autofs running (here
> 'automount -v' is really used) results in the following in logs:
> 
> 
> automount[20685]: Starting automounter version 5.0.3-11, master map auto.master
> automount[20685]: using kernel protocol version 5.00
> automount[20685]: mounted indirect mount on /net with timeout 60, freq 15 seconds
> automount[20685]: attempting to mount entry /net/.Trash
> automount[20685]: create_udp_client:99: hostname lookup failed: No such process
> automount[20685]: create_tcp_client:308: hostname lookup failed: No such process
> automount[20685]: lookup_mount: exports lookup failed for .Trash

The long delay may be due to the time it takes to do the lookup.  How long does
it take at the command line to run 'host .Trash'?

Comment 4 Michal Jaegermann 2008-05-05 20:20:13 UTC
> How long does it take at the command line to run 'host .Trash'?

$ time host .Trash
host: '.Trash' is not a legal name (unexpected end of input)

real    0m0.005s
user    0m0.001s
sys     0m0.005s

I am not sure what waits.  In log files series of quoted messages
have the same time stamp (but that may mean that they were written
to a syslog at that time).  The preceding one ('Resolved address
"xml:readwrite ..." ....') is usually six seconds earlier.

A not very precise estimate of a time difference from login to an active
desktop with and without autofs active is of an order ten to twelve seconds.
That is why I started to search in logs for possible causes but I cannot
tell for sure that all this time should be charged to autofs. Gnome
apparently is getting more weird with every update.

Comment 5 Ian Kent 2008-05-06 03:58:38 UTC
Before we go further with this can you give autofs-5.0.3-13
at try please.

If you can't find it anywhere else you can get it from
http://userweb.kernel.org/~raven.

Comment 6 Michal Jaegermann 2008-05-06 06:03:33 UTC
I installed autofs-5.0.3-13 from Koji.  Nothing really changed.
Something in a desktop makes automount to repeteadly try to
mount /net/.Trash which quickly fills logs with "create_udp_client:99:"
and similar or related and mount points never expire.
A debug log from that can be found as
https://bugzilla.redhat.com/attachment.cgi?id=304599
attached to bug 445056 (which now really seems to be related).

Why log lines like
automount[5726]: attempting to mount entry /net/.Trash
are even possible?


Comment 7 Ian Kent 2008-05-06 08:49:19 UTC
(In reply to comment #6)
> I installed autofs-5.0.3-13 from Koji.  Nothing really changed.
> Something in a desktop makes automount to repeteadly try to
> mount /net/.Trash which quickly fills logs with "create_udp_client:99:"
> and similar or related and mount points never expire.
> A debug log from that can be found as
> https://bugzilla.redhat.com/attachment.cgi?id=304599
> attached to bug 445056 (which now really seems to be related).
> 
> Why log lines like
> automount[5726]: attempting to mount entry /net/.Trash
> are even possible?
> 

I thought this was Nautilus but the scanning for mount/umount
activity is likely another Gnome process.

If a process tries to access (or create) a directory within an
autofs managed mount point autofs has no option but to try to
fulfill the request, valid or not.

Ian

Comment 8 Ian Kent 2008-05-06 08:51:37 UTC
(In reply to comment #7)
> (In reply to comment #6)
> > I installed autofs-5.0.3-13 from Koji.  Nothing really changed.
> > Something in a desktop makes automount to repeteadly try to
> > mount /net/.Trash which quickly fills logs with "create_udp_client:99:"
> > and similar or related and mount points never expire.
> > A debug log from that can be found as
> > https://bugzilla.redhat.com/attachment.cgi?id=304599
> > attached to bug 445056 (which now really seems to be related).
> > 
> > Why log lines like
> > automount[5726]: attempting to mount entry /net/.Trash
> > are even possible?
> > 
> 
> I thought this was Nautilus but the scanning for mount/umount
> activity is likely another Gnome process.
> 
> If a process tries to access (or create) a directory within an
> autofs managed mount point autofs has no option but to try to
> fulfill the request, valid or not.

And the other gotcha is that the scanning can prevent mounts from
timing out.

Comment 9 Michal Jaegermann 2008-05-06 17:00:50 UTC
> ... he scanning can prevent mounts from timing out.

"Can" seems to be a bit weak.  Paired with NetworkManager
shenanigans that makes automounter positively dangerous.

Comment 10 Jeff Moyer 2008-05-06 17:34:00 UTC
(In reply to comment #6)
> I installed autofs-5.0.3-13 from Koji.  Nothing really changed.
> Something in a desktop makes automount to repeteadly try to
> mount /net/.Trash which quickly fills logs with "create_udp_client:99:"
> and similar or related and mount points never expire.
> A debug log from that can be found as
> https://bugzilla.redhat.com/attachment.cgi?id=304599
> attached to bug 445056 (which now really seems to be related).

In the debug logs, you'll see lines like this:

May  5 22:56:39 dyna0 automount[5726]: handle_packet_missing_indirect: token
119, name .Trash, request pid 5978

Note the "request pid XXXX".  That tells which process is requesting the lookup.
 If you could run with debugging enabled and figure out which process name is
associated with the pid, that would be a great help.

> Why log lines like
> automount[5726]: attempting to mount entry /net/.Trash
> are even possible?

If that's logged without debug logging enabled, then we should fix it, I think.

If you need help with your network manager shenanigans, you'll have to provide a
bit more detail, but it's probably best to leave that to a separate bugzilla.

Cheers,

Jeff

Comment 11 Michal Jaegermann 2008-05-06 18:48:15 UTC
> handle_packet_missing_indirect: token
> 119, name .Trash, request pid 5978

Indeed I am collecting quickly a lot of these.  The problem is that
something is spawning all these short lived processes and by the time
one is trying to find them in a process table they are long gone.

If I would have to guess than 'gvfsd', or something related, would
be a likely candidate.  Maybe that?

3089 /usr/libexec/gvfsd-trash --spawner :1.5 /org/gtk/gvfs/exec_spaw/0

As habitual in this area all these things are really not documented
so it is hard to tell.

Well, I was right about that guess.  After 'pkill -f gvfsd' automount
eventually expires all its mount points.  Actually even
'pkill -f gvfsd-trash' looks to be enough to get everything eventually
expired although attempts 'umount -a -t nfs' still fail.

What starts that thingy I really cannot tell.  In "Session" preferences
I do not see anything which would look to me as something related to
that and "Current Session" listing also does not mention it.

> If you need help with your network manager shenanigans ...

I was refering in particular to this "nice" behaviour that with
NetworkManager after a logout your network is gone.  If you are stuck
with unexpirable NFS mounts, which cannot be really unmounted, then
you have some problems.


Comment 12 Ian Kent 2008-05-07 00:57:07 UTC
(In reply to comment #11)
> Well, I was right about that guess.  After 'pkill -f gvfsd' automount
> eventually expires all its mount points.  Actually even
> 'pkill -f gvfsd-trash' looks to be enough to get everything eventually
> expired although attempts 'umount -a -t nfs' still fail.

At least we know where to look.

You shouldn't be doing a "umount -t nfs" on an autofs managed
mount tree. There are autofs mount dependencies with nested
mounts, such as this, that must also be dealt with. If you do
then you will likely end up with mounts that won't expire and
will probably see invalid file descriptor messages. autofs
might recover, it tries anyway.

Ian

Comment 13 Ian Kent 2008-05-07 01:01:03 UTC
(In reply to comment #11)
> > If you need help with your network manager shenanigans ...
> 
> I was refering in particular to this "nice" behaviour that with
> NetworkManager after a logout your network is gone.  If you are stuck
> with unexpirable NFS mounts, which cannot be really unmounted, then
> you have some problems.

This is more a problem with umount, or more precisely an unavoidable
problem with RPC. This isn't likely to change, but NetworkManager
should be fixed to not blow away the network to early in the shutdown.


Comment 14 Bug Zapper 2008-05-14 10:34:21 UTC
Changing version to '9' as part of upcoming Fedora 9 GA.
More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 15 Bug Zapper 2009-06-10 00:35:40 UTC
This message is a reminder that Fedora 9 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 9.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '9'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 9's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 9 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 16 Jeff Moyer 2009-06-10 12:46:37 UTC
Does this bug still exist?  If it does, it sounds like we should move the component to gvfsd.

Comment 17 Jeff Moyer 2009-06-10 12:48:37 UTC
OK, I did file bug 445409 against gvfs, and that was fixed.  I'm closing this bug.


Note You need to log in before you can comment on or make changes to this bug.