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 791085 - tracker constantly crawling NFS share(s)
tracker constantly crawling NFS share(s)
Status: RESOLVED OBSOLETE
Product: tracker
Classification: Core
Component: General
1.12.x
Other Linux
: Normal critical
: ---
Assigned To: tracker-general
tracker-general
Depends on:
Blocks:
 
 
Reported: 2017-12-01 13:30 UTC by Brian J. Murrell
Modified: 2021-05-26 22:25 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description Brian J. Murrell 2017-12-01 13:30:46 UTC
Tracker seems to be stuck in a loop of constantly recrawling an NFS filesytem:

01 Dec 2017, 06:52:23:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 06:58:38:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:04:56:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:11:27:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:18:39:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:24:55:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:31:28:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:37:31:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:45:14:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:52:45:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 07:58:57:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 08:05:13:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 08:12:56:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 
01 Dec 2017, 08:20:01:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures' 

As you can see below, tracker-miner-fs has racked up a lot of CPU time since it was started 18 days ago.

$ ps axf | grep tracker
 3260 tty2     SNl+ 12033:31              \_ /usr/libexec/tracker-miner-fs
 3311 tty2     SNl+   0:00              \_ /usr/libexec/tracker-miner-user-guides
 3346 tty2     SNl+   0:00              \_ /usr/libexec/tracker-miner-apps
 3383 ?        Ssl  134:54  \_ /usr/libexec/tracker-store
  496 ?        SNsl 100:57  \_ /usr/libexec/tracker-extract

The journal does report streams of:

Dec 01 04:55:08 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby
Dec 01 04:55:08 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby
Dec 01 04:55:09 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby
Dec 01 04:55:09 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby
Dec 01 04:55:09 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby
Dec 01 04:55:09 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS delete statement: table fts5 has no column named nco:hobby

But they don't really align with the number of repetitive crawls.  The above one at 4:55:09 was the last in the log and many crawls have happened since that.
Comment 1 Brian J. Murrell 2017-12-07 13:23:56 UTC
Is there any interest in gathering information from this failing tracker instance while it's still in this state (and has been since I filed the ticket) or can I just stop using it so that it's not constantly kicking the crap out of my system?
Comment 2 Carlos Garnacho 2017-12-07 15:34:15 UTC
There is indeed interest.

(In reply to Brian J. Murrell from comment #0)
> Tracker seems to be stuck in a loop of constantly recrawling an NFS
> filesytem:
> 
> 01 Dec 2017, 06:52:23:    1%  File System             - Crawling recursively
> directory 'file:///home/brian/Pictures' 
<snip>

That "1%" is actually a fake state set by tracker-miner-fs, to get "tracker status" and other clients interested in progress going until it knows how many files are left to (re)index and it can produce more accurate timings:

https://git.gnome.org//browse/tracker/tree/src/libtracker-miner/tracker-miner-fs.c#n2225

This means that tracker-miner-fs is apparently left stuck at comparing filesystem and database directory/file mtimes. This is done per-directory from the root to the deepmost folders, and symlinks aren't followed, so it *should* be finite.

> 
> As you can see below, tracker-miner-fs has racked up a lot of CPU time since
> it was started 18 days ago.
> 
> $ ps axf | grep tracker
>  3260 tty2     SNl+ 12033:31              \_ /usr/libexec/tracker-miner-fs
>  3311 tty2     SNl+   0:00              \_
> /usr/libexec/tracker-miner-user-guides
>  3346 tty2     SNl+   0:00              \_ /usr/libexec/tracker-miner-apps
>  3383 ?        Ssl  134:54  \_ /usr/libexec/tracker-store
>   496 ?        SNsl 100:57  \_ /usr/libexec/tracker-extract

I see, that's not normal at all.

> 
> The journal does report streams of:
> 
> Dec 01 04:55:08 pc.interlinx.bc.ca tracker-store[3383]: Could not create FTS
> delete statement: table fts5 has no column named nco:hobby
<snip>

This is bug #764783 , basically a bad result of an old database migration, which is kind of hard to automatically repair... A "tracker reset --hard" would result in the database correctly created from scratch, or I think doing "rm ~/.cache/tracker/ontologies.gvdb" should also work without deleting the database altogether (Backup ~/.cache/tracker first if you appreciate the data).

Anyhow, that might result in glitches when doing full-text search (eg. from nautilus), but I don't think that's directly related to this infinite crawling (This warning happens when performing updates in the DB, but crawling only does "select" queries).

> 
> But they don't really align with the number of repetitive crawls.  The above
> one at 4:55:09 was the last in the log and many crawls have happened since
> that.

I really would expect to see other associated warnings from tracker-miner-fs... A few things to tick off:

- Maybe you are affected by bug #790284 ? The symptoms seem different (It would need to reindex stuff from scratch on every startup, but that would be finite), but worth checking anyway since that's the only recent issue that hasn't been backported to 1.12.x.
- Do you see tracker-miner-fs memory usage and ~/.cache/tracker/meta.db growing over time?
- Do the files indexed in ~/Music make sense? You can dump their paths with:
  tracker sparql -q "select ?url { ?u nie:url ?url . FILTER (STRSTARTS(?url, 'file:///.../Music'))}" (Use the appropriate uri)
  If the answer to the previous question is "yes", I'd maybe look for suspiciously deep paths.
- If you see nothing suspicious here, it's probably time to check more verbose logs, you can do:

  killall -15 tracker-miner-fs ; /usr/libexec/tracker-miner-fs -v 3 2>&1 | tee /tmp/tracker-log

  (It's important that the file specified to tee is not in a indexed path, to avoid feedback loops). In the (overly verbose) logs, you can perhaps figure out what it is exactly doing when it hits ~/Music.

I will leave sharing of those logs to your discretion as they'll contain somewhat detailed information of your files (same you could get from ls, really), please consider anonymizing it first and/or sending it to me directly via email. We'll try to work something out if neither are an option.
Comment 3 Brian J. Murrell 2017-12-07 18:09:33 UTC
(In reply to Carlos Garnacho from comment #2)
> 
> That "1%" is actually a fake state set by tracker-miner-fs,

Yeah.  I knew that.  :-)
 
> This means that tracker-miner-fs is apparently left stuck at comparing
> filesystem and database directory/file mtimes. This is done per-directory
> from the root to the deepmost folders, and symlinks aren't followed, so it
> *should* be finite.

Yeah.  I never goes beyond that 1% before finishing a pass with:

07 Dec 2017, 12:59:29:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures/1997/01/26' 
07 Dec 2017, 12:59:29:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures/2004/12/26' 
07 Dec 2017, 12:59:29:    1%  File System             - Crawling recursively directory 'file:///home/brian/Pictures/2007/01/01' 
07 Dec 2017, 12:59:29:  ✓     File System             - Idle 
07 Dec 2017, 12:59:35:  ✓     File System             - Processing… 
07 Dec 2017, 12:59:35:  ✓     File System             - Idle 
07 Dec 2017, 12:59:36:    0%  Extractor               - Extracting metadata 
07 Dec 2017, 12:59:36:  ✓     Extractor               - Idle 
07 Dec 2017, 12:59:36:  ✓     File System             - Processing… 
07 Dec 2017, 12:59:36:  ✓     File System             - Idle 
07 Dec 2017, 12:59:45:  ✓     File System             - Processing… 
07 Dec 2017, 12:59:45:  ✓     File System             - Idle 
07 Dec 2017, 13:00:09:  ✓     File System             - Processing… 
07 Dec 2017, 13:00:09:  ✓     File System             - Idle 
07 Dec 2017, 13:00:11:    0%  Extractor               - Extracting metadata 
07 Dec 2017, 13:00:11:  ✓     Extractor               - Idle 
 
> This is bug #764783 , basically a bad result of an old database migration,
> which is kind of hard to automatically repair... A "tracker reset --hard"
> would result in the database correctly created from scratch, or I think
> doing "rm ~/.cache/tracker/ontologies.gvdb" should also work without
> deleting the database altogether (Backup ~/.cache/tracker first if you
> appreciate the data).

Yeah, somewhat reluctant to start over again fresh.

> - Do you see tracker-miner-fs memory usage

Seems reasonable:

VmPeak:	 1588164 kB
VmSize:	 1539520 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	  431032 kB
VmRSS:	  392008 kB
RssAnon:	  384928 kB
RssFile:	    7080 kB
RssShmem:	       0 kB
VmData:	  610724 kB
VmStk:	     132 kB
VmExe:	     120 kB
VmLib:	   52512 kB
VmPTE:	    1484 kB
VmPMD:	      16 kB
VmSwap:	  159080 kB

since Nov. 12, so almost a month.

> and ~/.cache/tracker/meta.db
> growing over time?

I don't back up ~/.cache so I have no history to compare to, but it's currently 3.3GB.

> - Do the files indexed in ~/Music

Assuming you mean ~/Pictures...

> make sense? You can dump their paths with:
>   tracker sparql -q "select ?url { ?u nie:url ?url . FILTER (STRSTARTS(?url,
> 'file:///.../Music'))}" (Use the appropriate uri)

Yeah, they seem pretty sane,

>   If the answer to the previous question is "yes", I'd maybe look for
> suspiciously deep paths.

Nothing deeper than 7 or so directories.

> - If you see nothing suspicious here, it's probably time to check more
> verbose logs, you can do:
> 
>   killall -15 tracker-miner-fs ; /usr/libexec/tracker-miner-fs -v 3 2>&1 |
> tee /tmp/tracker-log

This didn't run for very long:

$ killall -15 tracker-miner-fs ; /usr/libexec/tracker-miner-fs -v 3 2>&1 | tee /var/tmp/tracker-log
Tracker-Message: Path '/home/brian' being removed from recursive directories list, as it also exists in single directories list
Tracker-Message: Starting tracker-miner-fs 1.12.4
Tracker-Message: General options:
Tracker-Message:   Verbosity  ............................  3
Tracker-Message:   Sched Idle  ...........................  1
Tracker-Message:   Initial Sleep  ........................  15
Tracker-Message: Indexer options:
Tracker-Message:   Throttle level  .......................  0
Tracker-Message:   Indexing while on battery  ............  no (first time only = yes)
Tracker-Message:   Low disk space limit  .................  Disabled
Tracker-Message: Setting priority nice level to 19
Tracker-Message: Checking if we're running as a daemon:
Tracker-Message:   Yes 
Tracker-Message: Initializing Storage...
Tracker-Message: Mount monitors set up for to watch for added, removed and pre-unmounts...
Tracker-Message: Initializing UPower...
Tracker-Message: Current and DB locales match: 'en_CA.utf8'
Tracker-Message: Setting database locations
Tracker-Message: Checking database files exist
Tracker-Message: Opened sqlite3 database:'/home/brian/.cache/tracker/meta.db'
Tracker-Message:   Setting page size to 8192
Tracker-Message:   Setting cache size to 250
Tracker-Message: Closed sqlite3 database:'/home/brian/.cache/tracker/meta.db'
Tracker-Message: Opened sqlite3 database:'/home/brian/.cache/tracker/meta.db'
Tracker-Message:   Setting page size to 8192
Tracker-Message:   Setting cache size to 250
Tracker-Message: Trying to use introspection XML:
<node>  <interface name='org.freedesktop.Tracker1.Miner'>    <method name='Start'>    </method>    <method name='GetStatus'>      <arg type='s' name='status' direction='out' />    </method>    <method name='GetProgress'>      <arg type='d' name='progress' direction='out' />    </method>    <method name='GetRemainingTime'>      <arg type='i' name='remaining_time' direction='out' />    </method>    <method name='GetPauseDetails'>      <arg type='as' name='pause_applications' direction='out' />      <arg type='as' name='pause_reasons' direction='out' />    </method>    <method name='Pause'>      <arg type='s' name='application' direction='in' />      <arg type='s' name='reason' direction='in' />      <arg type='i' name='cookie' direction='out' />    </method>    <method name='PauseForProcess'>      <arg type='s' name='application' direction='in' />      <arg type='s' name='reason' direction='in' />      <arg type='i' name='cookie' direction='out' />    </method>    <method name='Resume'>      <arg type='i' name='cookie' direction='in' />    </method>    <method name='IgnoreNextUpdate'>      <arg type='as' name='urls' direction='in' />    </method>    <signal name='Started' />    <signal name='Stopped' />    <signal name='Paused' />    <signal name='Resumed' />    <signal name='Progress'>      <arg type='s' name='status' />      <arg type='d' name='progress' />      <arg type='i' name='remaining_time' />    </signal>    <!-- Additional introspection data given by other miners -->      </interface></node>

Tracker-Message: Registering D-Bus object...
Tracker-Message:   Path:'/org/freedesktop/Tracker1/Miner/Files'
Tracker-Message:   Object Type:'TrackerMinerFiles'
Tracker-Message: Closed sqlite3 database:'/home/brian/.cache/tracker/meta.db'

(tracker-miner-fs:11673): Tracker-CRITICAL **: Couldn't create new Files miner: 'D-Bus service name:'org.freedesktop.Tracker1.Miner.Files' is already taken, perhaps the application is already running?'
Tracker-Message: Stopping tracker-miner-fs 1.12.4
(tracker-miner-fs:11673): Tracker-DEBUG: Ignoring mount 'brian on owncloud.interlinx.bc.ca', URI 'davs://brian@owncloud.interlinx.bc.ca/remote.php/webdav' is not native
(tracker-miner-fs:11673): Tracker-DEBUG: tracker-backend.vala:37: Waiting for service to become available...
(tracker-miner-fs:11673): Tracker-DEBUG: tracker-backend.vala:45: Service is ready
(tracker-miner-fs:11673): Tracker-DEBUG: tracker-backend.vala:47: Constructing connection
(tracker-miner-fs:11673): Tracker-DEBUG: tracker-backend.vala:203: Using backend = 'AUTO'
(tracker-miner-fs:11673): Tracker-DEBUG: Locale 'TRACKER_LOCALE_LANGUAGE' was set to 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Locale 'TRACKER_LOCALE_TIME' was set to 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Locale 'TRACKER_LOCALE_COLLATE' was set to 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Locale 'TRACKER_LOCALE_NUMERIC' was set to 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Locale 'TRACKER_LOCALE_MONETARY' was set to 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Resetting collator in db interface 0x5641031208d0
(tracker-miner-fs:11673): Tracker-DEBUG: [ICU collation] Initializing collator for locale 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA synchronous = OFF;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA encoding = "UTF-8"'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA auto_vacuum = 0;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA temp_store = MEMORY;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA journal_mode = WAL;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA wal_autocheckpoint = 0'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA journal_size_limit = 10240000'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA page_size = 8192'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA cache_size = 250'
(tracker-miner-fs:11673): Tracker-DEBUG: Resetting collator in db interface 0x564103120990
(tracker-miner-fs:11673): Tracker-DEBUG: [ICU collation] Initializing collator for locale 'en_CA.utf8'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA synchronous = OFF;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA encoding = "UTF-8"'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA auto_vacuum = 0;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA temp_store = MEMORY;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA journal_mode = WAL;'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA wal_autocheckpoint = 0'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA journal_size_limit = 10240000'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA page_size = 8192'
(tracker-miner-fs:11673): Tracker-DEBUG: Preparing query: 'PRAGMA cache_size = 250'
(tracker-miner-fs:11673): Tracker-DEBUG: tracker-backend.vala:49: Backend is ready
[brian@pc gw-Reboot]$ ps -ef | grep tracker-miner
brian     3311  2492  0 Nov12 tty2     00:00:00 /usr/libexec/tracker-miner-user-guides
brian     3346  2492  0 Nov12 tty2     00:00:01 /usr/libexec/tracker-miner-apps
Comment 4 Carlos Garnacho 2017-12-07 19:04:33 UTC
(In reply to Brian J. Murrell from comment #3)
>  
> > This is bug #764783 , basically a bad result of an old database migration,
> > which is kind of hard to automatically repair... A "tracker reset --hard"
> > would result in the database correctly created from scratch, or I think
> > doing "rm ~/.cache/tracker/ontologies.gvdb" should also work without
> > deleting the database altogether (Backup ~/.cache/tracker first if you
> > appreciate the data).
> 
> Yeah, somewhat reluctant to start over again fresh.

Sure... I think it really shouldn't take that long, unless those NFS mounts have far too many files/dirs. I guess that's a question worth making :), how many files/dirs are there?

> 
> > - Do you see tracker-miner-fs memory usage
> 
> Seems reasonable:
> 
> VmPeak:	 1588164 kB
> VmSize:	 1539520 kB
> VmLck:	       0 kB
> VmPin:	       0 kB
> VmHWM:	  431032 kB
> VmRSS:	  392008 kB
> RssAnon:	  384928 kB
> RssFile:	    7080 kB
> RssShmem:	       0 kB
> VmData:	  610724 kB
> VmStk:	     132 kB
> VmExe:	     120 kB
> VmLib:	   52512 kB
> VmPTE:	    1484 kB
> VmPMD:	      16 kB
> VmSwap:	  159080 kB
> 
> since Nov. 12, so almost a month.
> 
> > and ~/.cache/tracker/meta.db
> > growing over time?
> 
> I don't back up ~/.cache so I have no history to compare to, but it's
> currently 3.3GB.

Ok... that's a bit on the high end, but it's certainly possible if there's many text documents.

> 
> > - Do the files indexed in ~/Music
> 
> Assuming you mean ~/Pictures...

Oops, yes :).

> 
> > make sense? You can dump their paths with:
> >   tracker sparql -q "select ?url { ?u nie:url ?url . FILTER (STRSTARTS(?url,
> > 'file:///.../Music'))}" (Use the appropriate uri)
> 
> Yeah, they seem pretty sane,
> 
> >   If the answer to the previous question is "yes", I'd maybe look for
> > suspiciously deep paths.
> 
> Nothing deeper than 7 or so directories.

Ok, that seems to discard tracker-miner-fs doing any faulty recursion somewhere in the filesystem.

> 
> > - If you see nothing suspicious here, it's probably time to check more
> > verbose logs, you can do:
> > 
> >   killall -15 tracker-miner-fs ; /usr/libexec/tracker-miner-fs -v 3 2>&1 |
> > tee /tmp/tracker-log
> 
> This didn't run for very long:
> 
<snip>

Hmm, it bailed out early because the previous instance didn't quit on SIGTERM. This might be an indication of something.

Please try the "killall -SIGTERM tracker-miner-fs" step separately. If tracker-miner-fs doesn't terminate means it's busy looping without ever returning to the main loop. I think gdb would be the next thing to try.

If it terminates after all (might be just late to handle the signal), you can do the "/usr/libexec/tracker-miner-fs -v3 2>&1 | tee /tmp/tracker-log" step then, it should run successfully after the previous process is terminated.
Comment 5 Brian J. Murrell 2017-12-07 19:41:23 UTC
At the start of one of these scan loops, the verbose log above reports:

(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2011/01/22'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:3 (G_FILE_MONITOR_EVENT_CREATED) for directory:'file:///home/brian/Pictures'
(tracker-miner-fs:24555): Tracker-DEBUG: Waiting for event pairs
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:1 (G_FILE_MONITOR_EVENT_CHANGES_DONE_HINT) for directory:'file:///home/brian/Pictures'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2002'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:3 (G_FILE_MONITOR_EVENT_CREATED) for directory:'file:///home/brian/Pictures/2002'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:1 (G_FILE_MONITOR_EVENT_CHANGES_DONE_HINT) for directory:'file:///home/brian/Pictures/2002'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2008'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:3 (G_FILE_MONITOR_EVENT_CREATED) for directory:'file:///home/brian/Pictures/2008'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:1 (G_FILE_MONITOR_EVENT_CHANGES_DONE_HINT) for directory:'file:///home/brian/Pictures/2008'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2017'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/1997'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2001'
(tracker-miner-fs:24555): Tracker-DEBUG: Received monitor event:6 (G_FILE_MONITOR_EVENT_UNMOUNTED) for directory:'file:///home/brian/Pictures/2015
Comment 6 Ray Strode [halfline] 2017-12-07 20:22:10 UTC
are you using autofs? if so, can you post /etc/auto.master ?
Comment 7 Brian J. Murrell 2017-12-07 21:37:04 UTC
Yes, I am using autofs and yes, file:///home/brian/Pictures is (a symlink to) an autofs mounted directory.
Comment 8 Carlos Garnacho 2017-12-11 15:43:15 UTC
I guess the essential question about auto.master is: is there any timeout specified there for the NFS mounts?

Just to further confirm this is a file monitoring mishap (looks like it is since unmounted+created+changes_done_hint sounds kind of broken). Can you try disabling file monitors?:

gsettings set org.freedesktop.Tracker.Miner.Files enable-monitors false

If after this (should work immediately, or at next restart/login at worst) you see that tracker-miner-fs proceeds without a hitch, then we know where to focus.
With monitors disabled you'll get tracker-miner-fs only updating DB state after each startup.

(Anyway, I have growing reservations about the feasibility of monitoring remote NFS folders)
Comment 9 Brian J. Murrell 2017-12-30 15:12:01 UTC
(In reply to Carlos Garnacho from comment #8)
> I guess the essential question about auto.master is: is there any timeout
> specified there for the NFS mounts?

There is definitely going to be a timeout.  Using automount is pointless if one is not going to time out mounts.  One may as well just hard mount them in /etc/fstab.


> Just to further confirm this is a file monitoring mishap (looks like it is
> since unmounted+created+changes_done_hint sounds kind of broken). Can you
> try disabling file monitors?:
> 
> gsettings set org.freedesktop.Tracker.Miner.Files enable-monitors false
> 
> If after this (should work immediately,

What if there is a tracker-miner-fs already running?  Should that stop immediately or will it run to completion, but another should not start after it's done?

> you see that tracker-miner-fs proceeds without a hitch,

What does that mean, "without a hitch"?  It's not really having a hitch right now except that it's just being rerun too frequently, without any changes happening.

> (Anyway, I have growing reservations about the feasibility of monitoring
> remote NFS folders)

Without a remote file monitoring protocol, I have a hard time disagreeing.  But the bottom line is that file-sharing is here to stay.  It's not really feasible to give each person a local copy of a file that should be shared.

There are remote file monitoring protocols available but it seems information on them is scarce.  Given that they are so important to Tracker it would be useful if some time was spent documenting/explaining what peoples options are given that it seems to be buried in the layers of abstraction that Tracker is built upon.  A dedicated "how to index NFS shares" page on the Tracker main page would be useful.

Have you investigated having an inotify-like protocol added to NFS to make it transparent to users?  Granted it's not just going to be added overnight given that NFS is a standards-driven protocol.  But it seems like it would be directly useful to the Tracker project.
Comment 10 Brian J. Murrell 2017-12-30 15:28:30 UTC
Hrm.  I guess not.  I have a tracker-miner-fs that has been running since Dec. 19 so I guess they are long-lived processes.

So are you saying once I disable file monitors, it should it stop indexing?
Comment 11 Brian J. Murrell 2017-12-30 15:29:19 UTC
s/indexing/crawling/

Once I disable file monitors, it should stop crawling.
Comment 12 Brian J. Murrell 2017-12-31 14:47:11 UTC
So, it didn't stop crawling.  It was still starting new crawls this morning so I killed it and restarted it with:

$ /usr/libexec/tracker-miner-fs

Looks like it did a crawl and is Idle right now.  I will see if it does any more crawls.  It shouldn't, correct?
Comment 13 Carlos Garnacho 2017-12-31 15:59:59 UTC
(In reply to Brian J. Murrell from comment #9)
> (In reply to Carlos Garnacho from comment #8)
> > I guess the essential question about auto.master is: is there any timeout
> > specified there for the NFS mounts?
> 
> There is definitely going to be a timeout.  Using automount is pointless if
> one is not going to time out mounts.  One may as well just hard mount them
> in /etc/fstab.

"It's pointless" != "It's not possible". Good that you confirm though, that may be the source for the "unmounted" events. Although the "created" event after that still looks as broken.

> 
> 
> > Just to further confirm this is a file monitoring mishap (looks like it is
> > since unmounted+created+changes_done_hint sounds kind of broken). Can you
> > try disabling file monitors?:
> > 
> > gsettings set org.freedesktop.Tracker.Miner.Files enable-monitors false
> > 
> > If after this (should work immediately,
> 
> What if there is a tracker-miner-fs already running?  Should that stop
> immediately or will it run to completion, but another should not start after
> it's done?

tracker-miner-fs is a session daemon and by default stays on the background, ready to attend file notification or mount events. The running tracker-miner-fs does react to configuration changes, so it should get rid of all file monitors at runtime.

> 
> > you see that tracker-miner-fs proceeds without a hitch,
> 
> What does that mean, "without a hitch"?  It's not really having a hitch
> right now except that it's just being rerun too frequently, without any
> changes happening.

It means that tracker-miner-fs should check all content is up-to-date once, maybe index missing content that it never got to index before, and stay idle after that.

> 
> > (Anyway, I have growing reservations about the feasibility of monitoring
> > remote NFS folders)
> 
> Without a remote file monitoring protocol, I have a hard time disagreeing.

FAM should be it, except the amount of testing and real life use it gets nowadays compared to inotify is minuscule.
 
> But the bottom line is that file-sharing is here to stay.  It's not really
> feasible to give each person a local copy of a file that should be shared.
> 
> There are remote file monitoring protocols available but it seems
> information on them is scarce.  Given that they are so important to Tracker
> it would be useful if some time was spent documenting/explaining what
> peoples options are given that it seems to be buried in the layers of
> abstraction that Tracker is built upon.  A dedicated "how to index NFS
> shares" page on the Tracker main page would be useful.

Whatever we do (supporting monitoring or not), it should just work. But FWIW, this is the first bug related to NFS I've seen in years. I don't mean to dismiss the usecase, but from where I stand it doesn't seem as commonplace :)

> 
> Have you investigated having an inotify-like protocol added to NFS to make
> it transparent to users?  Granted it's not just going to be added overnight
> given that NFS is a standards-driven protocol.  But it seems like it would
> be directly useful to the Tracker project.

NFS and FAM should get along well enough, known shortcomings in both protocols aside. Something like that would be nice to have for other remote mounts than NFS though.

Anyhow, even though Tracker would directly benefit from such thing, it's outside the scope of Tracker. Given enough time and resources it might be a nice goal, but there are other things that need tackling first in our own yard.
Comment 14 Carlos Garnacho 2017-12-31 16:04:59 UTC
(In reply to Brian J. Murrell from comment #12)
> So, it didn't stop crawling.  It was still starting new crawls this morning
> so I killed it and restarted it with:

Given I don't really know yet where it's "looping" (all new files found and file monitor events should be handled in the main loop), it sounds plausible that you needed to terminate tracker-miner-fs after all...

> 
> $ /usr/libexec/tracker-miner-fs
> 
> Looks like it did a crawl and is Idle right now.  I will see if it does any
> more crawls.  It shouldn't, correct?

Correct, on restart it may still check mtimes to check no new content was added since the last time it crawled, but that boils down to the minimum possible set of stat()/readdir() syscalls.
Comment 15 Carlos Garnacho 2017-12-31 16:06:40 UTC
Most notably, that won't involve reading files, neither entirely nor partially. I forgot to add.
Comment 16 Brian J. Murrell 2019-10-28 18:19:19 UTC
I don't think we really ever got to the bottom of this.  Right now, tracker-store and tracker-miner-fs are by far the highest resource consumers of my system in terms of CPU time and disk I/O.

Interestingly since the last time I looked at this and in particular the advise do disable monitors in https://bugzilla.gnome.org/show_bug.cgi?id=791085#c8, it seems it's enabled again:

$ gsettings get org.freedesktop.Tracker.Miner.Files enable-monitors
true

And I have no recollection of having enabled that myself.  I wouldn't know to.
Comment 17 Brian J. Murrell 2019-10-29 09:37:46 UTC
So, disabling file monitors does stop the constant NFS/autofs recrawling.

Obviously given that disabling file monitors was just a debugging step and it's not practical to leave them disabled, what are the next steps?
Comment 18 Brian J. Murrell 2019-11-01 19:09:59 UTC
Any further thoughts on this?
Comment 19 Brian J. Murrell 2019-11-12 16:54:11 UTC
No more thoughts on this?
Comment 20 Sam Thursfield 2021-05-26 22:25:16 UTC
GNOME is going to shut down bugzilla.gnome.org in favor of gitlab.gnome.org.
As part of that, we are mass-closing older open tickets in bugzilla.gnome.org
which have not seen updates for a longer time (resources are unfortunately
quite limited so not every ticket can get handled).

If you can still reproduce the situation described in this ticket in a recent
and supported software version, then please follow
  https://wiki.gnome.org/GettingInTouch/BugReportingGuidelines
and create a new enhancement request ticket at
  https://gitlab.gnome.org/GNOME/tracker/-/issues/

Thank you for your understanding and your help.