GNOME.org
 

[tracker-miners/sam/index-file-sync: 316/316] WIP

commit 59249000309d2418598c84e2e6ba7dc84912c6ee
Author: Sam Thursfield <sam afuera me uk>
Date:   Wed Apr 29 01:27:29 2020 +0200

    WIP

 HACKING.md                                   | 10 ++++++++
 docs/manpages/tracker-miner-fs.1.txt         |  1 +
 src/libtracker-miner/tracker-miner-fs.c      |  5 ++--
 src/libtracker-miners-common/tracker-debug.c |  1 +
 src/libtracker-miners-common/tracker-debug.h |  1 +
 src/miners/fs/tracker-main.c                 |  3 ++-
 src/tracker/tracker-indexing-status.c        |  2 ++
 src/tracker/tracker-miner-manager.c          |  2 ++
 tests/functional-tests/cli.py                |  8 +++++--
 tests/functional-tests/fixtures.py           | 27 +++++++++++++--------
 tests/functional-tests/helpers.py            | 32 +++++++++++++++++++++++++
 tests/functional-tests/miner-on-demand.py    | 36 ++++++++++++++++++++++++++++
 12 files changed, 113 insertions(+), 15 deletions(-)
---
diff --git a/HACKING.md b/HACKING.md
index 6f7edbe7e..628f5ef96 100644
--- a/HACKING.md
+++ b/HACKING.md
@@ -1,2 +1,12 @@
 Please see the file HACKING.md in Tracker core:
 https://gitlab.gnome.org/GNOME/tracker/blob/master/HACKING.md
+
+The ENVIRONMENT sections of `docs/man/tracker-miners-fs.1.txt` and
+`docs/man/tracker-extract.1.txt` document available debugging tools
+for these daemons.
+
+Set `TRACKER_TESTS_MINER_FS_COMMAND` when running the functional-tests
+to help debugging tracker-miner-fs issues. For example, you can debug
+the miner-fs process during the 'miner-basic' functional tests like this:
+
+    env TRACKER_TESTS_MINER_FS_COMMAND="/usr/bin/gdb ./src/miners/fs/tracker-miner-fs-3" meson test 
miner-basic -t 100000 --verbose
diff --git a/docs/manpages/tracker-miner-fs.1.txt b/docs/manpages/tracker-miner-fs.1.txt
index e98c0c7ad..c06c26de6 100644
--- a/docs/manpages/tracker-miner-fs.1.txt
+++ b/docs/manpages/tracker-miner-fs.1.txt
@@ -50,6 +50,7 @@ than one instance of this at the same time.
   list of one or more keywords:
     config::: miner configuration
     miner-fs-events::: internal processing of tracker-miner-fs
+    miner-fs-sparql::: all SPARQL queries processing of tracker-miner-fs
     monitors::: change events from filesystem monitors
     statistics::: show statistics about how many files were processed
     status:: log the status messages that are published over D-Bus
diff --git a/src/libtracker-miner/tracker-miner-fs.c b/src/libtracker-miner/tracker-miner-fs.c
index fdedda9c9..cad9a652b 100644
--- a/src/libtracker-miner/tracker-miner-fs.c
+++ b/src/libtracker-miner/tracker-miner-fs.c
@@ -1387,7 +1387,8 @@ item_remove (TrackerMinerFS *fs,
        uri = g_file_get_uri (file);
 
        TRACKER_NOTE (MINER_FS_EVENTS,
-                     g_message ("Removing item: '%s' (Deleted from filesystem or no longer monitored)", 
uri));
+                     g_message ("Removing item%s: '%s' (Deleted from filesystem or no longer monitored)",
+                                only_children? " and children" : "", uri));
 
        g_object_set_qdata (G_OBJECT (file),
                            fs->priv->quark_recursive_removal,
@@ -2550,5 +2551,5 @@ tracker_miner_fs_cancel_all_tasks (TrackerMinerFS *fs)
                                   NULL);
 
        tracker_priority_queue_clear (priv->items,
-                                     (GFunc) queue_event_free);
+                                     (GDestroyNotify) queue_event_free);
 }
diff --git a/src/libtracker-miners-common/tracker-debug.c b/src/libtracker-miners-common/tracker-debug.c
index 061b99373..64f7f0b44 100644
--- a/src/libtracker-miners-common/tracker-debug.c
+++ b/src/libtracker-miners-common/tracker-debug.c
@@ -25,6 +25,7 @@
 static const GDebugKey tracker_miners_debug_keys[] = {
   { "config", TRACKER_DEBUG_CONFIG },
   { "miner-fs-events", TRACKER_DEBUG_MINER_FS_EVENTS },
+  { "miner-fs-sparql", TRACKER_DEBUG_MINER_FS_SPARQL },
   { "monitors", TRACKER_DEBUG_MONITORS },
   { "statistics", TRACKER_DEBUG_STATISTICS },
   { "status", TRACKER_DEBUG_STATUS },
diff --git a/src/libtracker-miners-common/tracker-debug.h b/src/libtracker-miners-common/tracker-debug.h
index 2377aa48a..b265b5839 100644
--- a/src/libtracker-miners-common/tracker-debug.h
+++ b/src/libtracker-miners-common/tracker-debug.h
@@ -31,6 +31,7 @@ G_BEGIN_DECLS
 typedef enum {
   TRACKER_DEBUG_CONFIG              = 1 <<  1,
   TRACKER_DEBUG_MINER_FS_EVENTS     = 1 <<  2,
+  TRACKER_DEBUG_MINER_FS_SPARQL     = 1 <<  3,
   TRACKER_DEBUG_MONITORS            = 1 <<  3,
   TRACKER_DEBUG_STATISTICS          = 1 <<  4,
   TRACKER_DEBUG_STATUS              = 1 <<  5,
diff --git a/src/miners/fs/tracker-main.c b/src/miners/fs/tracker-main.c
index 99ade457e..d15f60c0b 100644
--- a/src/miners/fs/tracker-main.c
+++ b/src/miners/fs/tracker-main.c
@@ -1057,6 +1057,7 @@ main (gint argc, gchar *argv[])
                g_debug ("Waiting for miner-fs to process removals.");
                g_signal_connect (miner_files, "finished", G_CALLBACK (quit_on_miner_finished_cb), 
shutdown_loop);
                g_main_loop_run (shutdown_loop);
+               g_debug ("Finished processing removals.");
        } else {
                g_debug ("No removals to process.");
        }
@@ -1079,7 +1080,7 @@ main (gint argc, gchar *argv[])
        tracker_sparql_connection_close (sparql_conn);
        g_object_unref (sparql_conn);
 
-       g_print ("\nOK\n\n");
+       g_debug ("tracker-miner-fs shutdown complete");
 
        return EXIT_SUCCESS;
 }
diff --git a/src/tracker/tracker-indexing-status.c b/src/tracker/tracker-indexing-status.c
index 1abd4766b..12b95c7f5 100644
--- a/src/tracker/tracker-indexing-status.c
+++ b/src/tracker/tracker-indexing-status.c
@@ -361,6 +361,8 @@ file_processed_cb (TrackerMinerManager   *miner_manager,
        GFile *file;
        TrackerIndexingStatusPrivate *priv;
 
+       g_message ("file-processed: %s, %s, %i, %s", miner, uri, success, message);
+
        priv = tracker_indexing_status_get_instance_private (status);
 
        file = g_file_new_for_uri (uri);
diff --git a/src/tracker/tracker-miner-manager.c b/src/tracker/tracker-miner-manager.c
index b2b69a16a..12eaa79d8 100644
--- a/src/tracker/tracker-miner-manager.c
+++ b/src/tracker/tracker-miner-manager.c
@@ -443,6 +443,7 @@ miner_files_processed (GDBusConnection *connection,
        g_variant_iter_init (&iter, files);
        while ((file_info = g_variant_iter_next_value (&iter))) {
                g_variant_get (file_info, "(&sbs)", &url, &status, &message);
+               g_message ("!! %s, %i, %s, .. %p", url, status, message, data->manager);
 
                if (data->manager) {
                        g_signal_emit (data->manager, signals[MINER_FILE_PROCESSED], 0, data->dbus_name, url, 
status, message);
@@ -558,6 +559,7 @@ miner_manager_initable_init (GInitable     *initable,
                                                                           data,
                                                                           NULL);
 
+               g_message ("Subscribed to %s.FilesProcessed signal for %s", TRACKER_MINER_DBUS_INTERFACE, 
data->dbus_name);
                data->files_processed_signal = g_dbus_connection_signal_subscribe (priv->connection,
                                                                                   data->dbus_name,
                                                                                   
TRACKER_MINER_DBUS_INTERFACE,
diff --git a/tests/functional-tests/cli.py b/tests/functional-tests/cli.py
index 536b50e3e..ae6fa31fe 100644
--- a/tests/functional-tests/cli.py
+++ b/tests/functional-tests/cli.py
@@ -51,8 +51,12 @@ class TestCli(fixtures.TrackerCommandLineTestCase):
         # This will generate an invalid .mp3 file.
         testfile = self.create_test_file('test-data/content.mp3')
 
-        with self.assertRaises(fixtures.CliError) as e:
-            self.run_cli(['index', str(testfile)])
+        try:
+            with self.assertRaises(fixtures.CliError) as e:
+                output = self.run_cli(['index', str(testfile)])
+        except AssertionError as e: 
+            print(f"CLI output:\n{output}")
+            raise
         #print(e.exception)
         #assert 'foo' in e.exception.args[0]
 
diff --git a/tests/functional-tests/fixtures.py b/tests/functional-tests/fixtures.py
index d58de85c2..9f64316d4 100644
--- a/tests/functional-tests/fixtures.py
+++ b/tests/functional-tests/fixtures.py
@@ -65,8 +65,11 @@ def tracker_test_main():
         handler_stderr.addFilter(logging.Filter('trackertestutils.dbusdaemon.stderr'))
         handler_stdout = logging.StreamHandler(stream=sys.stderr)
         handler_stdout.addFilter(logging.Filter('trackertestutils.dbusdaemon.stdout'))
+        handler_test_fixtures = logging.StreamHandler(stream=sys.stdout)
+        handler_test_fixtures.addFilter(logging.Filter('fixtures'))
         logging.basicConfig(level=logging.INFO,
-                            handlers=[handler_stderr, handler_stdout],
+                            handlers=[handler_stderr, handler_stdout,
+                                      handler_test_fixtures],
                             format='%(message)s')
 
     # Avoid the test process sending itself SIGTERM via the GDBusConnection
@@ -135,7 +138,8 @@ class TrackerMinerTest(ut.TestCase):
 
     def tearDown(self):
         self.sandbox.stop()
-        cfg.remove_monitored_test_dir(self.workdir)
+        #cfg.remove_monitored_test_dir(self.workdir)
+        log.info("DIR AT %s", self.workdir)
 
     def path(self, filename):
         return os.path.join(self.workdir, filename)
@@ -505,22 +509,25 @@ class TrackerCommandLineTestCase(TrackerMinerTest):
     def setUp(self):
         super(TrackerCommandLineTestCase, self).setUp()
 
-        self.env = os.environ.copy()
-        self.env.update(cfg.test_environment(self.workdir))
+        self.extra_env = cfg.test_environment(self.workdir)
 
-        path = self.env.get('PATH', []).split(':')
-        self.env['PATH'] = ':'.join([cfg.cli_dir()] + path)
+        path = os.environ.get('PATH', []).split(':')
+        self.extra_env['PATH'] = ':'.join([cfg.cli_dir()] + path)
 
-        self.env['DBUS_SESSION_BUS_ADDRESS'] = self.sandbox.daemon.address
+        self.extra_env['DBUS_SESSION_BUS_ADDRESS'] = self.sandbox.daemon.address
 
-        self.tracker_cli = shutil.which('tracker3', path=self.env['PATH'])
+        self.tracker_cli = shutil.which('tracker3', path=self.extra_env['PATH'])
 
     def run_cli(self, command):
         command = [self.tracker_cli] + [str(c) for c in command]
 
-        log.info("Running: %s", ' '.join(command))
+        log.info("env %s %s",
+                 ' '.join('%s=%s' % (k,v) for k,v in self.extra_env.items()),
+                 ' '.join(command))
+
+        env = os.environ.copy().update(self.extra_env)
         result = subprocess.run(command, stdout=subprocess.PIPE,
-                                stderr=subprocess.PIPE, env=self.env)
+                                stderr=subprocess.PIPE, env=env)
 
         if len(result.stdout) > 0:
             log.debug("stdout: %s", result.stdout.decode('utf-8'))
diff --git a/tests/functional-tests/helpers.py b/tests/functional-tests/helpers.py
index 62a6068c3..9c18ebcd4 100644
--- a/tests/functional-tests/helpers.py
+++ b/tests/functional-tests/helpers.py
@@ -25,7 +25,9 @@ from gi.repository import Tracker
 
 import dataclasses
 import logging
+import os
 import pathlib
+import subprocess
 
 import trackertestutils.mainloop
 
@@ -127,6 +129,22 @@ class await_files_processed():
         return True
 
 
+def await_bus_name(connection, name):
+    loop = trackertestutils.mainloop.MainLoop()
+
+    def appeared_cb(connection, name, name_owner):
+        log.debug("%s appeared (owner: %s)", name, name_owner)
+        loop.quit()
+
+    def vanished_cb(connection, name):
+        log.debug("%s vanished", name)
+
+    Gio.bus_watch_name_on_connection(
+        connection, name, Gio.BusNameWatcherFlags.NONE, appeared_cb,
+        vanished_cb);
+    loop.run_checked()
+
+
 class MinerFsHelper ():
 
     MINERFS_BUSNAME = "org.freedesktop.Tracker3.Miner.Files"
@@ -151,6 +169,20 @@ class MinerFsHelper ():
             self.MINERFS_BUSNAME, self.MINERFS_INDEX_OBJ_PATH, self.MINER_INDEX_IFACE)
 
     def start(self):
+        if 'TRACKER_TESTS_MINER_FS_COMMAND' in os.environ:
+            # This can be used to manually run the miner-fs instead of using
+            # D-Bus autoactivation. Useful if you want to use a debugging tool.
+            # The process should exit when sandbox D-Bus daemon exits.
+            command = os.environ['TRACKER_TESTS_MINER_FS_COMMAND']
+            logging.info("Manually starting tracker-miner-fs using TRACKER_TESTS_MINER_FS_COMMAND %s", 
command)
+            p = subprocess.Popen(command, shell=True)
+            if p.poll():
+                raise RuntimeError("Error manually starting miner-fs")
+            # Wait for the process to connect to D-Bus. Autoactivation has a
+            # hard timeout of 25 seconds, which can be too short if running
+            # under Valgrind.
+            await_bus_name(self.bus, self.MINERFS_BUSNAME)
+
         self.miner_iface.Start()
 
     def stop(self):
diff --git a/tests/functional-tests/miner-on-demand.py b/tests/functional-tests/miner-on-demand.py
index 13281b1bc..c0ae6a97a 100755
--- a/tests/functional-tests/miner-on-demand.py
+++ b/tests/functional-tests/miner-on-demand.py
@@ -46,6 +46,15 @@ class MinerOnDemandTest(fixtures.TrackerMinerTest):
         testfile.write_text("Hello, I'm a test file.")
         return testfile
 
+    def create_test_directory_tree(self):
+        testdir = pathlib.Path(self.workdir).joinpath('test-not-monitored')
+        for dirname in ['a', 'b', 'c', 'd', 'e', 'f', 'g', 'h', 'i', 'j']:
+            subdir = testdir.joinpath(dirname)
+            subdir.mkdir(parents=True)
+            subdir_file = subdir.joinpath('content.txt')
+            subdir_file.write_text("Hello, I'm a test file in a subdirectory")
+        return testdir
+
     def test_index_file_basic(self):
         """
         Test on-demand indexing of a file.
@@ -116,6 +125,33 @@ class MinerOnDemandTest(fixtures.TrackerMinerTest):
         with self.miner_fs.await_files_processed(expected):
             self.miner_fs.index_file(testdir.as_uri())
 
+    def test_index_for_process_miner_shutdown(self):
+        """
+        Test on-demand indexing linked to a D-Bus connection.
+
+        Similar to test_index_for_process, only this tests what happens in the
+        unusual case that the tracker-miner-fs process terminates before the
+        process that triggered indexing. Data should be removed from the
+        store in the same way.
+        """
+
+        testdir = self.create_test_directory_tree()
+
+        process_conn = self.sandbox.daemon.create_connection()
+        process_miner_fs = helpers.MinerFsHelper(process_conn)
+
+        with self.await_document_inserted(testdir.joinpath('g/content.txt')) as resource:
+            process_miner_fs.index_file_for_process(testdir.as_uri())
+
+        self.assertFileIndexed(testdir.joinpath('g/content.txt'))
+
+        self.sandbox.stop_miner_fs()
+
+        # This query should cause the miner-fs to restart, and the content
+        # should now be gone.
+        log.info("Checking that removal was processed.")
+        self.assertFileNotIndexed(testdir.joinpath('g/content.txt'))
+
 
 if __name__ == "__main__":
     fixtures.tracker_test_main()
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]