Tracker flooding syslog until suid root /usr/bin/gpg

[jrj]

I thuoght I’d write this down for others to look at. maybe it’s a bug.

I look at /var/log/syslog sometimes, and I saw a recurring set of messages from tracker:

2024-01-20T09:36:21.315269-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:36:21.315618-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:36:24.306495-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:36:24.325729-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:36:24.406192-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:36:24.406556-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:36:24.511544-06:00 x360 tracker-extract-3[2947949]: Warning: using insecure memory!
2024-01-20T09:36:59.285512-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.567s CPU time.
2024-01-20T09:37:08.937105-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:37:08.974087-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:37:09.022307-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:37:09.022529-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:37:09.082466-06:00 x360 tracker-extract-3[2956529]: Warning: using insecure memory!
2024-01-20T09:37:19.312676-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.271s CPU time.
2024-01-20T09:37:22.478067-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:37:22.494118-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:37:28.215914-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:37:28.237990-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:37:28.287581-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:37:28.287852-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:37:28.377646-06:00 x360 tracker-extract-3[2960192]: Warning: using insecure memory!
2024-01-20T09:37:44.330108-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.349s CPU time.
2024-01-20T09:37:48.819734-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:37:48.849881-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:37:48.917414-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:37:48.917629-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:37:48.996874-06:00 x360 tracker-extract-3[2964125]: Warning: using insecure memory!
2024-01-20T09:38:04.336111-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.484s CPU time.
2024-01-20T09:38:09.650166-06:00 x360 systemd[1]: Starting lmt-poll.service - Laptop Mode Tools - Battery Polling Service...
2024-01-20T09:38:09.650810-06:00 x360 sh[2968112]: laptop-mode: Battery polling disabled
2024-01-20T09:38:09.660268-06:00 x360 systemd[1]: lmt-poll.service: Deactivated successfully.
2024-01-20T09:38:09.660324-06:00 x360 systemd[1]: Finished lmt-poll.service - Laptop Mode Tools - Battery Polling Service.
2024-01-20T09:38:10.304571-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:38:10.325971-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:38:10.387690-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:38:10.388067-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:38:10.454033-06:00 x360 tracker-extract-3[2968133]: Warning: using insecure memory!
2024-01-20T09:38:15.826027-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:38:15.826403-06:00 x360 rtkit-daemon[5098]: Supervising 0 threads of 0 processes of 0 users.
2024-01-20T09:38:35.313153-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.340s CPU time.
2024-01-20T09:38:36.520497-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Activating via systemd: service name='org.freedesktop.Tracker3.Miner.Extract' unit='tracker-extract-3.service' requested by ':1.13' (uid=1000 pid=6193 comm="/usr/libexec/tracker-miner-fs-3")
2024-01-20T09:38:36.549803-06:00 x360 systemd[6047]: Starting tracker-extract-3.service - Tracker metadata extractor...
2024-01-20T09:38:36.594763-06:00 x360 dbus-daemon[6087]: [session uid=1000 pid=6087] Successfully activated service 'org.freedesktop.Tracker3.Miner.Extract'
2024-01-20T09:38:36.595042-06:00 x360 systemd[6047]: Started tracker-extract-3.service - Tracker metadata extractor.
2024-01-20T09:38:36.662632-06:00 x360 tracker-extract-3[2973172]: Warning: using insecure memory!
2024-01-20T09:38:56.312976-06:00 x360 systemd[6047]: tracker-extract-3.service: Consumed 1.454s CPU time.

The insecure memory thing got my attention and I googled it. I couldn’t find anything about tracker, but gpg kept coming up and I saw this:
https://lists.gnupg.org/pipermail/gnupg-users/1999-August/004024.html

I can’t think of much going wrong if gpg is suid root so I did that. And the syslog errors stopped.

I can’t imagine why it matters to tracker but maybe tracker uses gpg from the command line to do part of its work. Maybe gpg fails if gpg can’t do it securely. (that wouldn’t surprise me), and maybe tracker tetries every 15 seconds like a jack russel terrier if it didn’t complete…

[sthursfield (Sam Thursfield)]

At first glance this is a rather strange and wonderful bug. There is no reference at all to ‘gpg’ in the tracker-miners.git source code. So its a bit of a surprise to see a GPG related bug.

My first guess is that it might be related to encrypted or signed PDFs? I can see a few results for ‘gpg’ in the poppler.git repo. Tracker Extract uses Poppler to extract text from PDFs. So perhaps that is involved.

I am not sure why it is started by systemd every 15 seconds either. There is no clue in the log. What version of tracker-miners is this?

[jrj]

Your guess sounds plausible. I’m sure I do have some encrypted pdfs under my homedir. not too many but probably > 1

rygel-tracker/stable,now 0.42.1-1 amd64 [installed]
tracker-extract/stable,now 3.4.3-1 amd64 [installed,automatic]
tracker-miner-fs/stable,now 3.4.3-1 amd64 [installed,automatic]
tracker/stable,now 3.4.2-1 amd64 [installed]

Debian 12/bookworm