#962870 tracker-miner-fs: Repeated SIGABRT crashes due to file_tree_lookup assertion failed

Package:
tracker-miner-fs
Source:
tracker-miners
Description:
metadata database, indexer and search tool - filesystem indexer
Submitter:
Tomáš Szaniszlo
Date:
2022-01-04 15:18:03 UTC
Severity:
normal
#962870#5
Date:
2020-06-15 11:23:53 UTC
From:
To:
Hello, in my user journal I noticed that the tracker-miner-fs binary frequently
crashes, a few times every minute. I did not install it explicitly, nor am I
aware of specifically configuring it.

User journal excerpt:

Jun 15 13:15:03 ... systemd[693688]: Starting Tracker file system data miner...
Jun 15 13:15:03 ... tracker-miner-f[713320]: Set scheduler policy to SCHED_IDLE
Jun 15 13:15:03 ... tracker-miner-f[713320]: Setting priority nice level to 19
Jun 15 13:15:03 ... systemd[693688]: Started Tracker file system data miner.
Jun 15 13:15:19 ... tracker-miner-fs[713320]: **
Jun 15 13:15:19 ... tracker-miner-fs[713320]: Tracker:ERROR:../src/libtracker-miner/tracker-file-system.c:259:file_tree_lookup: assertion failed: (ptr[0] == '/')
Jun 15 13:15:19 ... tracker-miner-fs[713320]: Bail out! Tracker:ERROR:../src/libtracker-miner/tracker-file-system.c:259:file_tree_lookup: assertion failed: (ptr[0] == '/')
Jun 15 13:15:19 ... systemd[693688]: tracker-miner-fs.service: Main process exited, code=killed, status=6/ABRT
Jun 15 13:15:19 ... systemd[693688]: tracker-miner-fs.service: Failed with result 'signal'.
Jun 15 13:15:19 ... systemd[693688]: tracker-miner-fs.service: Scheduled restart job, restart counter is at 752.
Jun 15 13:15:19 ... systemd[693688]: Stopped Tracker file system data miner.

GDB backtrace on SIGABRT:

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f2cf636355b in __GI_abort () at abort.c:79
#2  0x00007f2cf66b0de3 in g_assertion_message (domain=<optimized out>, file=<optimized out>, line=<optimized out>, func=0x7f2cf6a51ae0 <__func__.29125> "file_tree_lookup", message=<optimized out>)
    at ../../../glib/gtestutils.c:2914
#3  0x00007f2cf670c77b in g_assertion_message_expr (domain=domain@entry=0x7f2cf6a4e329 "Tracker", file=file@entry=0x7f2cf6a51718 "../src/libtracker-miner/tracker-file-system.c", line=line@entry=259,
    func=func@entry=0x7f2cf6a51ae0 <__func__.29125> "file_tree_lookup", expr=expr@entry=0x7f2cf6a51683 "ptr[0] == '/'") at ../../../glib/gtestutils.c:2940
#4  0x00007f2cf6a420d2 in file_tree_lookup (tree=0x7f2ce41bb360, file=file@entry=0x55ee5fcff0a0, parent_node=parent_node@entry=0x7ffee5638a68, uri_remainder=uri_remainder@entry=0x7ffee5638a70)
    at ../src/libtracker-miner/tracker-file-system.c:259
#5  0x00007f2cf6a42769 in tracker_file_system_get_file (file_system=0x55ee5f97f440, file=file@entry=0x55ee5fcff0a0, file_type=file_type@entry=G_FILE_TYPE_UNKNOWN, parent=parent@entry=0x7f2ce0016380)
    at ../src/libtracker-miner/tracker-file-system.c:569
#6  0x00007f2cf6a3ea97 in _insert_store_info (notifier=notifier@entry=0x55ee5f70ac10, file=file@entry=0x55ee5fcff0a0, file_type=file_type@entry=G_FILE_TYPE_UNKNOWN, parent=parent@entry=0x7f2ce0016380,
    iri=iri@entry=0x7f2ce0010a58 "urn:uuid:7bc15158-5bb0-9480-d158-ccea0dd4f312", _time=<optimized out>) at ../src/libtracker-miner/tracker-file-notifier.c:506
#7  0x00007f2cf6a4059d in sparql_files_query_populate (check_root=1, cursor=0x7f2cd4026b20, notifier=0x55ee5f70ac10) at ../src/libtracker-miner/tracker-file-notifier.c:566
#8  sparql_files_query_cb (object=<optimized out>, result=<optimized out>, user_data=user_data@entry=0x55ee5f70ac10) at ../src/libtracker-miner/tracker-file-notifier.c:855
#9  0x00007f2cf68c8cd9 in g_task_return_now (task=0x55ee5f6b6cb0) at ../../../gio/gtask.c:1214
#10 0x00007f2cf68c981d in g_task_return (task=0x55ee5f6b6cb0, type=<optimized out>) at ../../../gio/gtask.c:1283
#11 0x00007f2cf68c9e3c in g_task_return (type=G_TASK_RETURN_SUCCESS, task=<optimized out>) at ../../../gio/gtask.c:1686
#12 g_task_return_pointer (task=<optimized out>, result=<optimized out>, result_destroy=<optimized out>) at ../../../gio/gtask.c:1691
#13 0x000055ee5fc696d0 in ?? ()
#14 0x00007f2cf68c8cd9 in g_task_return_now (task=0x7f2cf69ff730 <tracker_sparql_backend_query_async_ready>) at ../../../gio/gtask.c:1214
#15 0x00007f2cf68c8d19 in complete_in_idle_cb (task=0x55ee5fc696d0) at ../../../gio/gtask.c:1228
#16 0x00007f2cf66e44de in g_main_dispatch (context=0x55ee5f6aabd0) at ../../../glib/gmain.c:3309
#17 g_main_context_dispatch (context=context@entry=0x55ee5f6aabd0) at ../../../glib/gmain.c:3974
#18 0x00007f2cf66e4890 in g_main_context_iterate (context=0x55ee5f6aabd0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4047
#19 0x00007f2cf66e4b63 in g_main_loop_run (loop=0x55ee5f6d2be0) at ../../../glib/gmain.c:4241
#20 0x000055ee5ef46a47 in main (argc=<optimized out>, argv=<optimized out>) at ../src/miners/fs/tracker-main.c:973

#962870#10
Date:
2022-01-04 15:08:47 UTC
From:
To:
After upgrading from Debian 10 to Debian 11, I found Evolution crashing whenever I tried to delete a few messages. Looking at coredumpctl, I noticed tracker-miner-fs crashing every few minutes, as you mention. I let myself be distracted by that for a bit, so I dug in with gdb, and found:

#4  0x00007f3955ceca82 in file_tree_lookup (tree=0x7f394400d320, file=file@entry=0x5644bfbfe2c0,
    parent_node=parent_node@entry=0x7fff51069238, uri_remainder=uri_remainder@entry=0x7fff51069240)
    at ../src/libtracker-miner/tracker-file-system.c:259
259	../src/libtracker-miner/tracker-file-system.c: No such file or directory.
(gdb) print ptr
$15 = (gchar *) 0x5644bfb3c74f "-expenses"


So I looked around my homedir for that string, and I found ~/Documents/ox-expenses/

Thinking it might be treating the ox- prefix as special (wouldn't know why), I renamed the dir to oxexpenses. Then tracker-store crashed!

Jan 04 15:36:12 plato tracker-store[873997]: SQLite error: database disk image is malformed (errno: Success)
Jan 04 15:36:12 plato tracker-store[873997]: SQLite experienced an error with file:'/home/peter/.cache/tracker/meta.db'. It is either NOT a SQLite database or it is corrupt or there was an IO error accessing the data. This file has now been removed and will be recreated on the next start. Shutting down now.
Jan 04 15:36:13 plato systemd-coredump[874163]: Process 873997 (tracker-store) of user 1000 dumped core.

                                                Stack trace of thread 874001:
                                                #0  0x00007f2214af9ca7 g_log_structured_array (libglib-2.0.so.0 + 0x58ca7)
                                                #1  0x00007f2214afa0b5 g_log_default_handler (libglib-2.0.so.0 + 0x590b5)
                                                #2  0x00007f2214afa309 g_logv (libglib-2.0.so.0 + 0x59309)
                                                #3  0x00007f2214afa59f g_log (libglib-2.0.so.0 + 0x5959f)
                                                #4  0x00007f2214c08e83 n/a (libtracker-data.so + 0x38e83)
                                                #5  0x00007f2214bfe03c n/a (libtracker-data.so + 0x2e03c)
                                                #6  0x00007f2214c016dc n/a (libtracker-data.so + 0x316dc)

After that (30 minutes ago now), nothing has crashed - not tracker-miner-fs, not tracker-store, and, to my surprise, not Evolution either.

I don't have an explanation for what happened here, but perhaps you can try removing your meta.db (plus meta.db-* in the same dir) to see if it helps?

#962870#15
Date:
2022-01-04 15:16:05 UTC
From:
To:
I am sad to report that Evolution's unexplained recovery was temporary. So ignore what I said about Evolution - it still crashes which then likely is unrelated.