Bug 561904 - gvfsd-metadata producing large amounts of traffic to nfs server
Summary: gvfsd-metadata producing large amounts of traffic to nfs server
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: gvfs
Version: 18
Hardware: x86_64
OS: Linux
low
medium
Target Milestone: ---
Assignee: Ondrej Holy
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 962229 (view as bug list)
Depends On:
Blocks: 902448
TreeView+ depends on / blocked
 
Reported: 2010-02-04 16:48 UTC by John Kissane
Modified: 2014-09-13 18:57 UTC (History)
18 users (show)

Fixed In Version: gvfs-1.14.2-4.fc18
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 902448 (view as bug list)
Environment:
Last Closed: 2013-05-30 02:59:40 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
Trace of gvfsd-metadata daemon while issue was occurring (6.86 MB, text/plain)
2010-02-04 16:48 UTC, John Kissane
no flags Details
Further trace of gvfsd-metadata daemon while issue was occurring (10.25 MB, text/plain)
2010-02-17 10:42 UTC, John Kissane
no flags Details
Strace of approximately 7 seconds of gvfs-metadata operation (223.83 KB, text/plain)
2013-02-11 11:33 UTC, Myroslav Opyr
no flags Details

Description John Kissane 2010-02-04 16:48:20 UTC
Created attachment 388839 [details]
Trace of gvfsd-metadata daemon while issue was occurring

Description of problem:
Periodically the gvfsd-metadata daemon on Fedora 12 hosts appears to get into some strange state where it is sending large amount of traffic to an NFS server which is holding the user's home directory.

The traffic according to 'ntop' running on the NFS server is between 4 & 5Gb/hour.

It's not clear what causes this as it has happened to different users on different hosts all of which are running Fedora 12. We also have a large install base of Fedora 10 hosts which don't exhibit this problem. 

Version-Release number of selected component (if applicable):
gvfs-1.4.3-3.fc12.x86_64

How reproducible:
Unsure how to reproduce

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Attached is a log file from a host while the issue was happening using the following command: "strace -fp PID -o /tmp/gvfsd-metadata.log".

Comment 1 John Kissane 2010-02-04 17:34:16 UTC
On further investigation there were 25K+ files of the format:

home-xxxxxxxx.log

in the directory .local/share/gvfs-metadata for the user on the host.

These look to be a binary format.

Comment 2 Tomáš Bžatek 2010-02-16 13:46:32 UTC
This is rather interesting bug. Can you please post output of `mount`? Is your home directory mounted directly to /home or /home/ggreene? Looking at the metadata daemon source, we are doing special steps when storing the database:

link("/mnt/scratch/tbzatek/nfstest/.local/share/gvfs-metadata/home", "/mnt/scratch/tbzatek/nfstest/.local/share/gvfs-metadata/.openV7V07U") = 0
open("/mnt/scratch/tbzatek/nfstest/.local/share/gvfs-metadata/.openV7V07U", O_RDONLY) = 6
unlink("/mnt/scratch/tbzatek/nfstest/.local/share/gvfs-metadata/.openV7V07U") = 0

I don't see traces of ".openXXXXXX" files in your strace, probably because the nfs storage is not properly detected.

It works fine here when homedir is located on nfs mount directly. I can see constant number of files in ~/.local/share/gvfs-metadata - i.e. for each database (two files) there are four more ".nfsXXXXXXXXXXXXX" stale files (unlinked opened files). Each time the daemon rotates a database, no more files appear.

Perhaps you can try removing all the data in ~/.local/share/gvfs-metadata and start from scratch - there were bugs in previous gvfs versions leading to data corruption, however by using current gvfs versions, corrupted databases are being overwritten by consistent ones and corrupted data are lost. I doubt it will make the bug go away though.

Comment 3 John Kissane 2010-02-17 09:31:51 UTC
Thanks for the feedback, output of mount is below:

/dev/sda1 on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
tmpfs on /dev/shm type tmpfs (rw)
/dev/sda5 on /local type ext3 (rw)
/dev/sda3 on /windows type ext3 (rw)
none on /proc/sys/fs/binfmt_misc type binfmt_misc (rw)
sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw)
none on /proc/fs/vmblock/mountPoint type vmblock (rw)
storage-nfs:/gpfs/local/linux-x86_64-opt on /opt type nfs (rw,noatime,udp,bg,hard,rsize=32768,wsize=32768,addr=x.x.x.x)
storage-nfs:/gpfs/unixhome/users on /home type nfs (rw,nosuid,noatime,udp,bg,hard,rsize=32768,wsize=32768,addr=x.x.x.x)

I've deleted everything in the ~/.local/share/gvfs-metadata folder so will wait to see if it happens again.

Comment 4 John Kissane 2010-02-17 10:40:23 UTC
Emptying the ~/.local/share/gvfs-metadata directory didn't help unfortunately, same thing occurred again today. However this time it hadn't created large numbers of files. Directory content is:

(45) ls -l
total 136
-rw------- 1 marks man  1244 2010-02-17 10:36 home
-rw-r--r-- 1 marks man 32768 2010-02-17 10:36 home-428afacc.log
-rw-r--r-- 1 marks man 32768 2010-02-17 10:36 home-7b3d4f37.log.JEDF8U
-rw------- 1 marks man  1244 2010-02-17 10:36 home.HU8E8U

I took another trace which I'll attach as well.

Comment 5 John Kissane 2010-02-17 10:42:49 UTC
Created attachment 394706 [details]
Further trace of gvfsd-metadata daemon while issue was occurring

Comment 6 John Kissane 2010-02-17 11:53:47 UTC
gvfs was updated last week to gvfs-1.4.3-4.fc12.x86_64 i.e. prior to this happening again.

Comment 7 John Kissane 2010-02-24 12:48:44 UTC
Updated to gvfs-1.4.3-5.fc12.x86_64 to see if it makes any difference.

Comment 8 John Kissane 2010-02-25 11:43:57 UTC
No change by installing gvfs-1.4.3-5.fc12.x86_64 as issue is still occurring.

Comment 9 Benjamin Riggs 2010-06-17 20:34:58 UTC
I am encountering this same problem after upgrading out department machines from Fedora 11 to 13.  After noticing one particular host started hammering our file server at about 9:25 one morning, I discovered the following syslogs on the machine (the user had been logged in since about 8:00):

Jun 15 09:16:58 asimov kernel: type=1400 audit(1276611418.484:78158): avc:  denied  { read } for  pid=14592 comm="gvfsd-trash" name="" dev=0:3c ino=13796884 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:30 asimov kernel: type=1400 audit(1276611870.547:78159): avc:  denied  { read } for  pid=14592 comm="gvfsd-trash" name="joe" dev=0:3c ino=13798490 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=lnk_file
Jun 15 09:24:44 asimov kernel: type=1400 audit(1276611884.261:78160): avc:  denied  { append } for  pid=14234 comm="gconfd-2" name="saved_state" dev=0:3d ino=108544018 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.672:78161): avc:  denied  { write } for  pid=14592 comm="gvfsd-trash" name="Trash" dev=0:3d ino=168084264 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.672:78162): avc:  denied  { add_name } for  pid=14592 comm="gvfsd-trash" name="expunged" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.672:78163): avc:  denied  { create } for  pid=14592 comm="gvfsd-trash" name="expunged" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.690:78164): avc:  denied  { remove_name } for  pid=14592 comm="gvfsd-trash" name=53637265656E73686F742D4E545320536572766963652047617465776179202D204D6F7A696C6C612046697265666F782E706E67 dev=0:3d ino=173096962 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.690:78165): avc:  denied  { rename } for  pid=14592 comm="gvfsd-trash" name=53637265656E73686F742D4E545320536572766963652047617465776179202D204D6F7A696C6C612046697265666F782E706E67 dev=0:3d ino=173096962 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.692:78166): avc:  denied  { link } for  pid=14592 comm="gvfsd-trash" name="home" dev=0:3d ino=169836595 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.693:78167): avc:  denied  { unlink } for  pid=14592 comm="gvfsd-trash" name=".openM5BKEV" dev=0:3d ino=169836595 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:24:53 asimov kernel: type=1400 audit(1276611893.723:78168): avc:  denied  { setattr } for  pid=15886 comm="gvfsd-trash" name="expunged" dev=0:3d ino=168084265 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:54 asimov kernel: type=1400 audit(1276611894.066:78169): avc:  denied  { rename } for  pid=14592 comm="gvfsd-trash" name="MonteCarloSimulator" dev=0:3d ino=170771244 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:24:54 asimov kernel: type=1400 audit(1276611894.066:78170): avc:  denied  { reparent } for  pid=14592 comm="gvfsd-trash" name="MonteCarloSimulator" dev=0:3d ino=170771244 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:25:44 asimov kernel: audit_printk_skb: 6 callbacks suppressed
Jun 15 09:25:44 asimov kernel: type=1400 audit(1276611944.904:78174): avc:  denied  { setattr } for  pid=14234 comm="gconfd-2" name="%gconf.xml.new" dev=0:3d ino=103448606 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:30:10 asimov kernel: type=1400 audit(1276612210.107:78175): avc:  denied  { module_request } for  pid=15990 comm="sshd" kmod="net-pf-10" scontext=system_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=system_u:system_r:kernel_t:s0 tclass=system
Jun 15 09:35:40 asimov kernel: type=1400 audit(1276612540.707:78176): avc:  denied  { read } for  pid=14619 comm="gvfsd-metadata" name="joe" dev=0:3c ino=13798490 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=lnk_file
Jun 15 09:35:40 asimov kernel: type=1400 audit(1276612540.707:78177): avc:  denied  { write } for  pid=14619 comm="gvfsd-metadata" name="gvfs-metadata" dev=0:3d ino=169836868 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:35:40 asimov kernel: type=1400 audit(1276612540.707:78178): avc:  denied  { remove_name } for  pid=14619 comm="gvfsd-metadata" name="home-743066b6.log.YOQ3DV" dev=0:3d ino=169837307 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:35:40 asimov kernel: type=1400 audit(1276612540.707:78179): avc:  denied  { rename } for  pid=14619 comm="gvfsd-metadata" name="home-743066b6.log.YOQ3DV" dev=0:3d ino=169837307 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:35:40 asimov kernel: type=1400 audit(1276612540.708:78180): avc:  denied  { add_name } for  pid=14619 comm="gvfsd-metadata" name="home-743066b6.log" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:35:41 asimov kernel: type=1400 audit(1276612541.675:78181): avc:  denied  { write } for  pid=14619 comm="gvfsd-metadata" name="home" dev=0:3d ino=169836589 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:35:41 asimov kernel: type=1400 audit(1276612541.675:78182): avc:  denied  { unlink } for  pid=14619 comm="gvfsd-metadata" name="home" dev=0:3d ino=169836589 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:35:41 asimov kernel: type=1400 audit(1276612541.678:78183): avc:  denied  { read } for  pid=14619 comm="gvfsd-metadata" name="gvfs-metadata" dev=0:3d ino=169836868 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 09:35:41 asimov kernel: type=1400 audit(1276612541.684:78184): avc:  denied  { create } for  pid=14619 comm="gvfsd-metadata" name="home.WPFMEV" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:41:53 asimov kernel: type=1400 audit(1276612913.044:78185): avc:  denied  { append } for  pid=14234 comm="gconfd-2" name="saved_state" dev=0:3d ino=168084573 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 09:45:09 asimov kernel: type=1400 audit(1276613109.417:78186): avc:  denied  { module_request } for  pid=16102 comm="sshd" kmod="net-pf-10" scontext=system_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=system_u:system_r:kernel_t:s0 tclass=system
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.888:78187): avc:  denied  { create } for  pid=14619 comm="gvfsd-metadata" name="home.SWZIEV" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.890:78188): avc:  denied  { write } for  pid=14619 comm="gvfsd-metadata" name="home.SWZIEV" dev=0:3d ino=169837306 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.914:78189): avc:  denied  { write } for  pid=14619 comm="gvfsd-metadata" name="gvfs-metadata" dev=0:3d ino=169836868 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.914:78190): avc:  denied  { remove_name } for  pid=14619 comm="gvfsd-metadata" name="home-086d928d.log.WU6IEV" dev=0:3d ino=169837307 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.914:78191): avc:  denied  { rename } for  pid=14619 comm="gvfsd-metadata" name="home-086d928d.log.WU6IEV" dev=0:3d ino=169837307 scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
Jun 15 10:00:09 asimov kernel: type=1400 audit(1276614009.914:78192): avc:  denied  { add_name } for  pid=14619 comm="gvfsd-metadata" name="home-086d928d.log" scontext=system_u:system_r:xdm_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir

Followed by many, many more messages about gvfsd-metadata, even after the user logged out, until I killed the process.

Comment 10 John Kissane 2010-06-18 08:05:03 UTC
Just to confirm this still happens on Fedora 12 as well with latest gvfs packages installed.

gvfs-1.4.3-7.fc12.x86_64
gvfs-archive-1.4.3-7.fc12.x86_64
gvfs-obexftp-1.4.3-7.fc12.x86_64
gvfs-gphoto2-1.4.3-7.fc12.x86_64
gvfs-fuse-1.4.3-7.fc12.x86_64
gvfs-smb-1.4.3-7.fc12.x86_64

Comment 11 John Kissane 2010-10-12 08:31:38 UTC
This is continuing to happen in Fedora 13 as well. When I see a high load on our NFS server I use ntop to track down the hosts where the gvfsd-metadata daemon has gone nuts, killing it gets rid of the issue for a while on that particular host.

Comment 12 Sean Crosby 2010-10-25 06:58:59 UTC
This happens on my fleet of Ubuntu Lucid machines as well (v 1.6.1). High NFS traffic from the clients to the server. Killing the gvfs-metadata process stops the NFS traffic immediately. But the process does come back eventually, increasing the load on the NFS server considerably.

My setup:

home directories are located on an NFS share, mounted to /imports/server/home

/home is a symlink to /imports/server/home

Comment 13 John Kissane 2010-10-27 08:19:06 UTC
One interesting thing I noticed is that even if the user on the PC logs out, the gvfs-metadata daemon (owned by them) continues to run consuming one core of the CPU & generating NFS traffic.

Comment 14 Bug Zapper 2010-11-03 23:03:12 UTC
This message is a reminder that Fedora 12 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 12.  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 '12'.

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 12'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 12 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 15 John Kissane 2010-11-04 12:23:30 UTC
This issue also happens in Fedora 13, should I create a new bug or change the version of this one to avoid it being closed? Issue does not occur in Fedora 10 & it will be early 2011 before we will be rolling out Fedora 14.

Comment 16 Benjamin Riggs 2010-11-08 20:24:49 UTC
"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."

Please, by all means change this bug to Fedora 13.

Also, Sean mentioned that he uses a symlink from /home to the actual NFS mount on the client.  We also use symlinks in a similar fashion, e.g. /home/staff pointing to /staff.  John, does your setup also use symlinks?  If so, I think we've discovered a huge clue.

Comment 17 John Kissane 2010-11-09 09:06:50 UTC
I've changed the version to to Fedora 13.

We don't use symbolic links so the NFS file system is directly mounted on /home. This is the entry from the fstab for which /home is the mountpoint:

storage-nfs:/gpfs/unixhome/users /home nfs udp,nosuid,noatime,bg,hard,rsize=3276
8,wsize=32768 0 0

Comment 18 Need Real Name 2011-05-20 07:11:19 UTC
This still exists on F14, and with NFSv4. SIGHUP was enough to shut it up.

Comment 19 John Kissane 2011-05-20 07:56:49 UTC
I can confirm this as I see the same issue on F12, F13 & F14. It's not present in F10 and can't say for F11 as it's not in use on our site.

Comment 20 John Kissane 2011-05-23 10:06:37 UTC
(In reply to comment #18)
> This still exists on F14, and with NFSv4. SIGHUP was enough to shut it up.

This worked for me as well, prior to this I had been killing the process on the affected machines so this 'gentler' way is fix it is good to know.

Comment 21 Bug Zapper 2011-06-02 16:40:52 UTC
This message is a reminder that Fedora 13 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 13.  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 '13'.

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 13'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 13 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 22 John Kissane 2011-06-24 16:08:38 UTC
I've just seen the same behaviour with Fedora 15 so seems the issue is still present in the latest release.

Comment 23 Aleksandr Brezhnev 2011-08-18 23:55:23 UTC
I have got the same issue with F15 and the home directory on a local disk.
gvfsd-meta creates and deletes files in ~/.local/share/gvfsd-meta
The files are "home", "home.??????" and "home-????????.log" where "?" are changing every moment.

The process writes to disk about 2MB/s.

Comment 24 Andrew McNabb 2011-08-25 21:02:00 UTC
I am experiencing this problem in Fedora 15, where gvfsd-metadata is using 10 to 20 Mb/sec on the network.  Killing gvfsd-metadata made a huge difference.

Comment 25 John Kissane 2011-08-26 08:14:42 UTC
(In reply to comment #24)
> I am experiencing this problem in Fedora 15, where gvfsd-metadata is using 10
> to 20 Mb/sec on the network.  Killing gvfsd-metadata made a huge difference.

I used to just kill it as well but found that a kill -HUP works as well, eg.

pkill -HUP gvfsd-metadata

I've now got a cronjob running that does this every 15 mins on our machines to stop the extra load on our nfs server. This issue appeared for the first time in Fedora 12 and has hung around every release since.

Comment 26 Andrew McNabb 2011-08-26 16:09:15 UTC
John, has anyone looked into it or asked you any questions about how to reproduce it?  This seems like a really serious problem to have been sitting around for so long.

Comment 27 John Kissane 2011-08-26 16:24:27 UTC
(In reply to comment #26)
> John, has anyone looked into it or asked you any questions about how to
> reproduce it?  This seems like a really serious problem to have been sitting
> around for so long.

Not since 2010, see Comment #2.

Comment 28 John Kissane 2011-09-08 08:42:07 UTC
This is the bandaid I use for this problem:

[root@xxxx]crontab -l
0,15,30,45 * * * * pkill -HUP gvfsd-metadata > /dev/null

Haven't seen any problems with this approach as yet.

Comment 29 Jimmy Dorff 2011-11-29 18:02:12 UTC
I see this problem on RHEL 6.1 as well as Fedora. I've seen this with NFSv3 and NFSv4 mounted home dirs.

Comment 30 Michael Karcher 2011-12-14 23:53:43 UTC
I tried to track down the problem and if I understand the code correctly, I'm afraid it seems to be a fundamental design problem in gvfsd-metadata, as it expects there is only one instance working on the redo log at the same time.

As long as there are multiple instances running on one host, all instances share the same mmap() view of the redo log, so their entries are properly merged as long as no two writes happen at the same time. The time window for race condition problems is quite small, although the problem is probably provocable when stressing gvfsd-metadata in concurrent instances. The rwlock in the code won't help between different processes, although it seems to do the job for a single process, even if it runs in multiple threads.

On the other hand, there is no magic that synchronizes mmap()ed views of file between different NFS clients. So gvfsd-metadata will never know that on a different NFS client the redo log has been amended, and keep working with its stale mmap()ed copy of that file. NFS is designed that way, that as soon as two hosts operate at the same time on the same time, no consistency is specified, so this is not a bug in NFS.

This problem enters an endless loop hammering on the NFS server amongst other in the following scenario:

client A loads the r/o db + the current redo log
client B loads the r/o db + the current redo log
client B performs writes, until the redo log overflows
client B rotates the r/o db and creates a new redo log, marking the old one as "rotated".
client A does not get any hint about the redo log filling up and getting rotated, it keeps working on its own local mmap()ed copy(!) of it.
client A performs db writes, until the redo log overflows.
client A decides to rotate the redo log as it is full.
loop:
client A creates a new r/o db (from the r/o db opened in the first step and the redo log as seen by client A, thus killing all changes made by client B)
client A checks the db currently on disc for the redo log ID, and over-renames the current db on disk with the db just generated.
client A marks the redo log for the log ID it obtained from the db on disk as rotated. This will be the new redo log created by client B, *not* the old redo log that client B already rotated away.
client A *still* has the stale cache of its redo log not indicating that client B rotated it away.
client A retries the insert after the log rotation process
client A determines that the log is full, and a log rotation is needed
goto loop

Other breakage might be possible, too. We observed different patterns of run-away gvfsd-metadata processes, this is just explaining what I saw in the one I investigated.

Comment 31 Fedora End Of Life 2012-08-07 19:42:06 UTC
This message is a notice that Fedora 15 is now at end of life. Fedora
has stopped maintaining and issuing updates for Fedora 15. It is
Fedora's policy to close all bug reports from releases that are no
longer maintained. At this time, all open bugs with a Fedora 'version'
of '15' have been closed as WONTFIX.

(Please note: Our normal process is to give advanced warning of this
occurring, but we forgot to do that. A thousand apologies.)

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, feel free to reopen
this bug and simply change the 'version' to a later Fedora version.

Bug Reporter: Thank you for reporting this issue and we are sorry that
we were unable to fix it before Fedora 15 reached 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, you are encouraged to click on
"Clone This Bug" (top right of this page) and open it against that
version of Fedora.

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 32 John Paul Adrian Glaubitz 2013-01-13 19:20:40 UTC
Could you please re-open this issue?

Closing it due to end-of-life won't magically fix a fundamental design problem which still exists in future versions.

This bug has been marked as serious in Debian:

> http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=624507

In Ubuntu:

> https://bugs.launchpad.net/ubuntu/+source/gvfs/+bug/720927

Adrian

Comment 33 John Paul Adrian Glaubitz 2013-01-13 19:56:23 UTC
GNOME upstream bug report:

> https://bugzilla.gnome.org/show_bug.cgi?id=637095

Comment 34 Andrew McNabb 2013-01-14 16:13:00 UTC
John, what's the latest version of Fedora that you can confirm this in? Have you observed it in Fedora 18 yet?

Comment 35 Myroslav Opyr 2013-02-07 10:40:05 UTC
I've experienced local harddrive issue with /usr/libexec/gvfsd-metadata from gvfs-1.12.3-1.fc17.i686. My home partition is on reiserfs (survived many Fedora reinstall already) and when I got heavy disk activity and localized it to gvfsd-metadata I found this bug. Killing the gvfsd-metadata solved the issue, but I'll be tracking if it reappear on my local harddrive.

I hadn't upgraded to Fedora 18 yet.

Comment 36 Tomáš Bžatek 2013-02-07 11:04:47 UTC
(In reply to comment #35)
> I've experienced local harddrive issue with /usr/libexec/gvfsd-metadata from
> gvfs-1.12.3-1.fc17.i686. My home partition is on reiserfs (survived many
> Fedora reinstall already) and when I got heavy disk activity and localized
> it to gvfsd-metadata I found this bug. Killing the gvfsd-metadata solved the
> issue, but I'll be tracking if it reappear on my local harddrive.

Interesting, I usually have reiserfs everywhere and my current system is running reiserfs on root and home partitions. Never seen any issue though.

If you manage to reproduce it reliably, please post it here. Preferably having clean metadata database, i.e. empty ~/.local/share/gvfs-metadata

Comment 37 John Paul Adrian Glaubitz 2013-02-07 11:06:25 UTC
(In reply to comment #35)
> I've experienced local harddrive issue with /usr/libexec/gvfsd-metadata from
> gvfs-1.12.3-1.fc17.i686. My home partition is on reiserfs (survived many
> Fedora reinstall already) and when I got heavy disk activity and localized
> it to gvfsd-metadata I found this bug. Killing the gvfsd-metadata solved the
> issue, but I'll be tracking if it reappear on my local harddrive.

It can actually happen on local filesystems as well under certain circumstances, see:

> http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=624507#58

Adrian

Comment 38 Myroslav Opyr 2013-02-07 11:23:52 UTC
(In reply to comment #37)
> It can actually happen on local filesystems as well under certain
> circumstances, see:
> 
> > http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=624507#58
> 
> Adrian

I have local filesystem (not exported) and I did no restore from backup. Thus it is either my drive or reiserfs who corrupted the database or something scenario that has not been mentioned yet.

Comment 39 Myroslav Opyr 2013-02-07 14:22:22 UTC
(In reply to comment #36)
> Interesting, I usually have reiserfs everywhere and my current system is
> running reiserfs on root and home partitions. Never seen any issue though.
> 
> If you manage to reproduce it reliably, please post it here. Preferably
> having clean metadata database, i.e. empty ~/.local/share/gvfs-metadata

Today was the first time in many years when the issue appeared that I have Fedora on my PC (including F12, F15, F16 and F17). I.e. it look like on local filesystem the probability is much smaller.

The only thing that I can correlate is me closing of Firebug in Firefox, i.e. moment, when it started. But I am skeptical about the fact that Firefox/Firebug increased the probability.

P.S. I've emailed this comment as reply to bugzilla notification e-mail but it never landed in this bug, thus I'm re-posting manually.

Comment 40 Myroslav Opyr 2013-02-11 11:33:42 UTC
Created attachment 696036 [details]
Strace of approximately 7 seconds of gvfs-metadata operation

Today disk thrashing happened again on my RaiserFS partition. I managed to grab the strace before RaiserFS locked up (after ~1h30m of disk activity) making me to reset the PC. 

FYI, I've been getting these ReiserFS lockups even before but I didn't connect them with elevated dis activity. There is a chance that I'm getting these ReiserFS lockups just because of gvfs-metadata.

Comment 41 Myroslav Opyr 2013-03-07 08:01:42 UTC
The issue reoccurred again today and killing /usr/libexec/gvfsd-metadata helped.

If I can provide more information (diagnosis, etc.) let me know what is required and I'll try to collect necessary information next time.

Comment 42 Myroslav Opyr 2013-03-28 11:48:16 UTC
The issue reoccurred again today and killing /usr/libexec/gvfsd-metadata helped.

It look like the issue is occurring after I "Save as..." in Firefox. Not yet sure if after each save, but it did today.

Comment 43 Mikhail Strizhov 2013-04-18 20:15:46 UTC
+1, same issue, had to kill it manually.

Comment 44 Myroslav Opyr 2013-04-19 11:02:30 UTC
In my case the issue returns more often when saving screenshot from "Awesome Screenshot" (https://addons.mozilla.org/en-US/firefox/addon/awesome-screenshot-capture-/) Firefox extension to disk.

Comment 45 Tomáš Bžatek 2013-05-13 10:03:09 UTC
*** Bug 962229 has been marked as a duplicate of this bug. ***

Comment 46 Elliott Forney 2013-05-13 19:11:20 UTC
This is still happening to us on a daily basis with F18 and NFS mounted home directories.  I think the Fedora version should be updated on this bug report.

We have several hundred desktop machines running Fedora and see two or three gvfsd-metadata processes hung writing to disk per day.  This has been happening since F15.  We wrote a script to just go out and kill them when they are hung.

Comment 47 Tomáš Bžatek 2013-05-14 15:55:21 UTC
(In reply to comment #46)
> This is still happening to us on a daily basis with F18 and NFS mounted home
> directories.  I think the Fedora version should be updated on this bug
> report.

Right, now that the patches have been pushed to master, it's time to build F18 update as well.

Comment 48 Fedora Update System 2013-05-14 16:07:37 UTC
gvfs-1.14.2-4.fc18 has been submitted as an update for Fedora 18.
https://admin.fedoraproject.org/updates/gvfs-1.14.2-4.fc18

Comment 49 Myroslav Opyr 2013-05-14 16:11:03 UTC
Will there be Fedora 17 update?

Comment 50 John Kissane 2013-05-14 16:12:42 UTC
(In reply to comment #49)
> Will there be Fedora 17 update?

I'd be interested in this as well!

Comment 51 Fedora Update System 2013-05-15 03:34:22 UTC
Package gvfs-1.14.2-4.fc18:
* should fix your issue,
* was pushed to the Fedora 18 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing gvfs-1.14.2-4.fc18'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-8229/gvfs-1.14.2-4.fc18
then log in and leave karma (feedback).

Comment 52 Fedora Admin XMLRPC Client 2013-05-23 14:35:40 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 53 Fedora Admin XMLRPC Client 2013-05-23 14:38:41 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 54 Fedora Admin XMLRPC Client 2013-05-23 14:41:37 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 55 Fedora Admin XMLRPC Client 2013-05-23 14:44:20 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 56 Fedora Update System 2013-05-30 02:59:40 UTC
gvfs-1.14.2-4.fc18 has been pushed to the Fedora 18 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 57 Phil V 2013-06-26 18:19:17 UTC
Andrew and Tomáš : 

Could the fix be pushed to Fedora 17 as well?



I note there have been other bugs applicable to F17 and F18 where it seems the need to push to F17 is not even considered.

Isn't Fedora 17 still supported until a month after the release of the upcoming Fedora 19?

https://fedoraproject.org/wiki/Fedora_Release_Life_Cycle?rd=LifeCycle#Maintenance_Schedule


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