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 784396 - tracker-miner-fs: sparql buffer errors and CPU usage spikes after login to GNOME
tracker-miner-fs: sparql buffer errors and CPU usage spikes after login to GNOME
Status: RESOLVED OBSOLETE
Product: tracker
Classification: Core
Component: Miners
1.10.x
Other Linux
: Normal normal
: ---
Assigned To: tracker-general
tracker-general
Depends on:
Blocks:
 
 
Reported: 2017-06-30 18:08 UTC by Alexander P
Modified: 2018-05-24 11:00 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description Alexander P 2017-06-30 18:08:32 UTC
This was reported originally downstream in RHBZ against Fedora 21 and tracker 1.2.5, more than two years ago. The bug was recently closed with a request to report it here.

The original bug report:
https://bugzilla.redhat.com/show_bug.cgi?id=1192224

In my case the log entries have evolved a bit over time. I am currently on Fedora 25 with tracker-1.10.5-1.fc25.x86_64 and whenever I log in, tracker-miner-fs takes up ~20% of CPU time on my 6-core system for about 10 minutes. At the same time, my system log shows this kind of errors:

Jun 30 19:00:04 tracker-miner-f[2354]: Could not execute sparql: UNIQUE constraint failed: nie:DataObject.nie:url (strerror of errno (not necessarily related): Resource temporarily unavailable)
Jun 30 19:00:04 tracker-miner-f[2354]:   (Sparql buffer) Error in task 12 (file:///home/user/Pictures/scanner/File0001.png) of the array-update: UNIQUE constraint failed: nie:DataObject.nie:url (strerror of errno (not necessarily related): Resource temporarily unavailable)

This happens with any possible file type (source code, images, audio, compressed files, documents, etc.) and path (with and without spaces or weird characters).

I do not have any other tracker-related errors any more, at least not for the last couple of months.

In this heat wave, I could really do without that extra CPU usage…
Comment 1 Carlos Garnacho 2017-07-01 08:16:30 UTC
Thanks for the bug report, this issue was fixed some time ago, but unfortunately the database has been left in an inconsistent state, and tracker-miner-fs can't detect this without performing rather expensive checks which it doesn't do by default.

As per https://git.gnome.org/browse/tracker/commit/?h=6e42c641b8ed48a39a4e3dec9b4a138b8173ea94 , I added the TRACKER_MINER_FORCE_CHECK_UPDATED envvar so it can be told to do those checks and fix the database inconsistencies.

So you can do:

killall -15 tracker-miner-fs; TRACKER_MINER_FORCE_CHECK_UPDATED=1 /usr/libexec/tracker-miner-fs

Alternatively, a partial/total delete of the database should also work, depending on how you value the additional Tracker data (eg. tags, play counts in songs, virtual playlists,...):

tracker reset -f ~/
tracker reset --hard

I'm closing as obsolete since this was fixed around the 1.8 days. Please reopen if you still find those errors after following these steps.
Comment 2 Alexander P 2017-07-01 10:39:24 UTC
Were there database incompatibilities between tracker versions? I have been updating this system since Fedora 17 or 19, so it has seen many changes. Are those on rolling-release distros expected to fiddle with the db every now and then?

I tried the non-destructive approach first, which led to lots and lots of complaints about the structure of the db, e.g.:

tracker-store[2322]: Could not create FTS delete statement: table fts5 has no column named nco:hobby

I ended up deleting the db and tracker seems to be doing better now save for a little hiccup:
Before the deletion I would get the "unable to create file '/run/user/1000/dconf/user': Permission denied" (bug #779342) message 1-10 times per hour. Now it appears ~1500-4000 times shortly after login. I'll wait and see if it goes away when I upgrade to Fedora 26.
Comment 3 Carlos Garnacho 2017-07-01 12:06:27 UTC
(In reply to Alexander P from comment #2)
> Were there database incompatibilities between tracker versions? I have been
> updating this system since Fedora 17 or 19, so it has seen many changes. Are
> those on rolling-release distros expected to fiddle with the db every now
> and then?

No, it was a plain bug hitting in odd situations that made tracker-miner-fs fail to entirely delete its data about a folder being deleted recursively. If at a later point the folder was added with (partially) the same structure, tracker-miner-fs stumbled over previous zombie instances of the older files.

The "solution" I've pointed you to makes tracker-miner-fs to treat every folder as "changed" (which usually only does if its mtime changed, and files were added/deleted), which goes through more expensive checks about the folder content (as seen by Tracker) being correct. I took the envvar approach because doing this automatically would have made Tracker "suck less" (i.e. fix the bug) for the few that hit it at the expense of making Tracker "suck more" (i.e. more expensive operations on every startup) for everybody.

Tracker has the utmost respect for the stored data, and a requisite for every database format change that has ever been performed since around the 0.16 days is that it must seamlessly migrate from older formats. Sometimes bad things happen in the worst moment, bugs or non observed situations may slip in, and the database breaks in result. Software is not perfect, surely you've had to rebuild the rpm database at some point :).

> 
> I tried the non-destructive approach first, which led to lots and lots of
> complaints about the structure of the db, e.g.:
> 
> tracker-store[2322]: Could not create FTS delete statement: table fts5 has
> no column named nco:hobby
> 
> I ended up deleting the db and tracker seems to be doing better now save for
> a little hiccup:
> Before the deletion I would get the "unable to create file
> '/run/user/1000/dconf/user': Permission denied" (bug #779342) message 1-10
> times per hour. Now it appears ~1500-4000 times shortly after login. I'll
> wait and see if it goes away when I upgrade to Fedora 26.

That's https://git.gnome.org//browse/tracker/commit?id=e9e7cda6e5b5e83ac9d3b86127e6877b3f9db980 , from 1.12 onwards, effectively.
Comment 4 Alexander P 2017-07-01 13:05:34 UTC
(In reply to Carlos Garnacho from comment #3)
> (In reply to Alexander P from comment #2)
> > Were there database incompatibilities between tracker versions? I have been
> > updating this system since Fedora 17 or 19, so it has seen many changes. Are
> > those on rolling-release distros expected to fiddle with the db every now
> > and then?
> 
> No, it was a plain bug hitting in odd situations that made tracker-miner-fs
> fail to entirely delete its data about a folder being deleted recursively.
> If at a later point the folder was added with (partially) the same
> structure, tracker-miner-fs stumbled over previous zombie instances of the
> older files.

Odd situations are just my thing! 
 
> Tracker has the utmost respect for the stored data, and a requisite for
> every database format change that has ever been performed since around the
> 0.16 days is that it must seamlessly migrate from older formats. Sometimes
> bad things happen in the worst moment, bugs or non observed situations may
> slip in, and the database breaks in result. Software is not perfect, surely
> you've had to rebuild the rpm database at some point :).

Subtle ;). I am also using Gentoo and my Fedora packages come from the testing repos, so I'm no stranger to rebuilding, rolling back or building from scratch. I was just asking in case there was a miscommunication somewhere down the stream and I should have taken action after an update.

Thanks for all the information!
Comment 5 Carlos Garnacho 2017-07-01 13:42:40 UTC
(In reply to Alexander P from comment #4)
> (In reply to Carlos Garnacho from comment #3)
> > (In reply to Alexander P from comment #2)
> > > Were there database incompatibilities between tracker versions? I have been
> > > updating this system since Fedora 17 or 19, so it has seen many changes. Are
> > > those on rolling-release distros expected to fiddle with the db every now
> > > and then?
> > 
> > No, it was a plain bug hitting in odd situations that made tracker-miner-fs
> > fail to entirely delete its data about a folder being deleted recursively.
> > If at a later point the folder was added with (partially) the same
> > structure, tracker-miner-fs stumbled over previous zombie instances of the
> > older files.
> 
> Odd situations are just my thing! 
>  
> > Tracker has the utmost respect for the stored data, and a requisite for
> > every database format change that has ever been performed since around the
> > 0.16 days is that it must seamlessly migrate from older formats. Sometimes
> > bad things happen in the worst moment, bugs or non observed situations may
> > slip in, and the database breaks in result. Software is not perfect, surely
> > you've had to rebuild the rpm database at some point :).
> 
> Subtle ;).

Hey don't get me wrong :), I'm a happy Fedora camper. But been there, done that myself.

> I am also using Gentoo and my Fedora packages come from the
> testing repos, so I'm no stranger to rebuilding, rolling back or building
> from scratch. I was just asking in case there was a miscommunication
> somewhere down the stream and I should have taken action after an update.
> 
> Thanks for all the information!

You're welcome! I remember I wrote something about it in the 1.8 release notes, maybe could have written a blog post or reached out harder to downstreams, but still the extent is limited...
Comment 6 Jane Foot 2018-05-23 09:53:16 UTC
My syslog has these error messages too:

May 23 10:20:01 tracker-miner-f[2370]:   (Sparql buffer) Error in task 0 (file:///home/user/Documents/Ubuntu%2018.04/App%20stuff/text%20file.txt) of the array-update: UNIQUE constraint failed: nie:DataObject.nie:url
May 23 10:20:01 tracker-miner-f[2370]: Could not execute sparql: UNIQUE constraint failed: nie:DataObject.nie:url

I don't seem to have any CPU spikes.

But I think the tracker apps might be hogging memory (these are from after I reset the database):

tracker-extract 657.2MiB
tracker-miner-fs 442.3MiB
tracker-miner-apps 131.9MiB
tracker-store 96.8MiB


I deleted/reset the database as in the first comment but the error still persist:

$ tracker reset --hard

CAUTION: This process may irreversibly delete data.
Although most content indexed by Tracker can be safely reindexed, it can’t be assured that this is the case for all data. Be aware that you may be incurring a data loss situation. Proceed at your own risk.

Are you sure you want to proceed? [y|N]: y
Found 4 PIDs…
  Killed process 2201 — “tracker-extract”
  Killed process 2202 — “tracker-miner-apps”
  Killed process 2207 — “tracker-miner-fs”
  Killed process 2212 — “tracker-store”
Setting database locations
Checking database directories exist
Checking database version
Checking whether database files exist
Removing all database/storage files
  Removing database:'/home/user/.cache/tracker/meta.db'
  Removing db-locale file:'/home/user/.cache/tracker/db-locale.txt'
  Removing journal:'/home/user/.local/share/tracker/data/tracker-store.journal'
  Removing db-version file:'/home/user/.cache/tracker/db-version.txt'


Then I rebooted.

But I still get those error messages (and memory use maybe high)


Ubuntu 18.04

'tracker-store --verison' produces no result for me:

$ tracker-store --version
tracker-store: command not found
Comment 7 Jane Foot 2018-05-23 15:45:28 UTC
$ tracker --version
Tracker 2.0.3
Comment 8 Jane Foot 2018-05-24 11:00:58 UTC
Started new bug 796383