supervisor: a worker's ready line is found wherever it sits in its log, not in the first page only (#105)

.github/workflows/ci.yml

@@ -78,8 +78,9 @@ jobs:
           test "$(printf '%s\n%s\n' "$floor" "$have" | sort -V | head -n 1)" = "$floor" || { echo "mod-host $have is below the floor $floor"; exit 1; }
 
       # The daemon with the installed workers over jack, in a PipeWire of its own: omx-clap-host for CLAP and mod-host
-      # for LV2, driving the fixture bundle of this repository (a stereo gain, tests/lv2_fixture.c) from a world of its
-      # own, so that the worker's bundle set is one directory. It needs a private user namespace with its own /proc; a
+      # for LV2, driving the fixture bundle of this repository (a stereo gain, tests/lv2_fixture.c) with the whole tests/
+      # directory as the world: a few dozen files that are no bundle, which lilv warns about one by one before mod-host
+      # says ready, and a pool worker must still start under that (#105). It needs a private user namespace with its own /proc; a
       # runner that refuses one cannot run it, and the step says so. The LV2 steps are required to have run: a run that
       # skipped them fails here.
       - name: Test the daemon with real workers over jack, CLAP and LV2, then break every guard on purpose
@@ -89,9 +90,7 @@ jobs:
           export JACK_METER_SOURCE=/usr/libexec/omx-clap-host/tests/jack_meter_source
           export FAKE_CLAP=/usr/libexec/omx-clap-host/tests/fake.clap
           make tests/plugin-hostd-fixture.lv2/plugin-hostd-fixture.so
-          mkdir -p "$PWD/lv2-world"
-          cp -r tests/plugin-hostd-fixture.lv2 "$PWD/lv2-world/"
-          export MOD_HOST=/usr/bin/mod-host LV2_DIR=$PWD/lv2-world LV2_URI=urn:plugin-hostd:test:stereo
+          export MOD_HOST=/usr/bin/mod-host LV2_DIR=$PWD/tests LV2_URI=urn:plugin-hostd:test:stereo
           export LV2_BUNDLE=plugin-hostd-fixture.lv2 LV2_PARAM=gain
           if unshare --user --map-root-user --net --pid --fork --mount-proc true; then
             make test-jack OMX_CLAP_HOST=/usr/bin/omx-clap-host 2>&1 | tee test-jack.log

BUILDING.md

@@ -71,9 +71,10 @@ worker is killed.
 
 Given `MOD_HOST` and a bundle, it also runs mod-host's scenario corpus against the daemon with an LV2 worker, and kills
 an LV2 worker to read the graph and a parameter back. The CI job does this with the mod-host package of the FreeMixer
-channel and this repository's fixture bundle: build `tests/plugin-hostd-fixture.lv2/plugin-hostd-fixture.so`, copy the
-bundle into a directory of its own, and give `MOD_HOST=/usr/bin/mod-host LV2_DIR=<that directory>
-LV2_URI=urn:plugin-hostd:test:stereo LV2_BUNDLE=plugin-hostd-fixture.lv2 LV2_PARAM=gain`.
+channel and this repository's fixture bundle: build `tests/plugin-hostd-fixture.lv2/plugin-hostd-fixture.so` and give
+`MOD_HOST=/usr/bin/mod-host LV2_DIR=$PWD/tests LV2_URI=urn:plugin-hostd:test:stereo LV2_BUNDLE=plugin-hostd-fixture.lv2
+LV2_PARAM=gain`. The world is the whole `tests/` directory on purpose: lilv warns about every entry that is no bundle
+before mod-host says ready, and a worker must start behind that (#105).
 
     make test-jack2 OMX_CLAP_HOST=<omx-clap-host> [...]
 

src/proc.c

@@ -205,20 +205,36 @@ int proc_spawn(const conf_t *conf, const char *bin, const char *world_env, const
     return 0;
 }
 
+/* whether the worker's log carries the ready marker yet: the whole log, a page at a time, the tail of each page kept in
+ * front of the next so that a marker split across two reads is still found. A worker says ready after it has set up
+ * its world, and what it says about the world comes first: mod-host's lilv writes a warning line for every entry of
+ * LV2_PATH that is no bundle, so a world of a few dozen stray files puts the marker past the first page (#105) */
 static int log_has_ready(const char *logfile)
 {
     char buffer[4096];
+    size_t keep = strlen(PHD_WORKER_READY_MARKER) - 1, held = 0;
     ssize_t n;
-    int fd = open(logfile, O_RDONLY);
+    int fd = open(logfile, O_RDONLY), found = 0;
 
     if (fd < 0)
         return 0;
-    n = read(fd, buffer, sizeof(buffer) - 1);
+    while (!found && (n = read(fd, buffer + held, sizeof(buffer) - 1 - held)) > 0)
+    {
+        held += n;
+        buffer[held] = '\0';
+        /* a NUL inside the page would stop strstr short of the rest of it */
+        for (size_t i = 0; i < held; i++)
+            if (buffer[i] == '\0')
+                buffer[i] = ' ';
+        found = strstr(buffer, PHD_WORKER_READY_MARKER) != NULL;
+        if (held > keep)
+        {
+            memmove(buffer, buffer + held - keep, keep);
+            held = keep;
+        }
+    }
     close(fd);
-    if (n <= 0)
-        return 0;
-    buffer[n] = '\0';
-    return strstr(buffer, PHD_WORKER_READY_MARKER) != NULL;
+    return found;
 }
 
 static int connect_loopback(int port)

tests/daemon_test.py

@@ -160,6 +160,21 @@ def a_worker_that_never_listens_is_refused_after_a_bounded_number_of_starts():
         d.close()
 
 
+@test
+def a_worker_that_warns_more_than_a_page_before_ready_still_starts():
+    """lilv writes a warning line for every entry of the world that is no bundle, before mod-host says ready: a world
+    of a few dozen stray files puts the marker past the first 4 KB of the log (plugin-hostd#105, resp -503)"""
+    d = daemon(env={"FAKE_WARN_BEFORE_READY": "64"})
+    try:
+        t0 = time.time()
+        d.expect("add fake:a 0", "resp 0")
+        check(time.time() - t0 < 3, "the start saw the ready line, it did not wait out the ready timeout (%.1fs)" % (time.time() - t0))
+        log = open(os.path.join(d.tmp, "plugin-hostd", str(d.proc.pid), "%s.log" % d.holder(0)[0])).read()
+        check(log.index("ready!") > 4096, "positive control: the ready line sits past the first page of the log (%d)" % log.index("ready!"))
+    finally:
+        d.close()
+
+
 @test
 def own_crash_respawns_only_that_instance_and_replays_it():
     d = daemon()

tests/fake_host.c

@@ -68,6 +68,8 @@
  *
  * Its layout is one CLAP parameter whose default is FAKE_LAYOUT_DEFAULT (0.5 without it); "fake-host -L" prints its
  * layout pin. With FAKE_LOG set, every command received is appended to that file as "<pid> <command>".
+ * FAKE_WARN_BEFORE_READY=<n> writes n warning lines to stderr before "ready!", as lilv writes one for every entry of
+ * a world that is no bundle (plugin-hostd#105: a world of a few dozen stray files buries the marker under 5 KB).
  */
 
 #include <dirent.h>
@@ -625,6 +627,14 @@ int main(int argc, char **argv)
     sig.sa_handler = term_signal;
     sigemptyset(&sig.sa_mask);
     sigaction(SIGTERM, &sig, NULL);
+    if (getenv("FAKE_WARN_BEFORE_READY"))
+    {
+        int n = atoi(getenv("FAKE_WARN_BEFORE_READY")), i;
+
+        for (i = 0; i < n; i++)
+            fprintf(stderr, "load_dir_entry(): warning: Skipping non-directory `/a/world/of/stray/files/entry-%d.c' within path entry\n", i);
+        fflush(stderr);
+    }
     printf("fake-host ready!\n");
     fflush(stdout);
     while (running)

tests/sabotage.py

@@ -15,6 +15,10 @@
 # tests/readme_build.py, with no daemon to build; "probeschema" breaks protocol/probe-output.schema.json and runs
 # tests/probe_schema.py; "relay" breaks src/relay.c and runs tests/relay_test.c; "alloc" breaks src/relay.c or src/lv2.c and runs make test-alloc; "contract" breaks the probe runner or the generator and runs tests/contract_derived.py; "consumer" breaks the header and compiles tests/consumer.c against it; "probe" breaks src/probe.c and runs tests/probe_test.py; "nopins" breaks the packaging or a workflow and runs tests/no_pins.py
 SABOTAGE = [
+    ("the ready marker is looked for in the first page of the worker's log only", "src/proc.c",
+     "while (!found && (n = read(fd, buffer + held, sizeof(buffer) - 1 - held)) > 0)",
+     "while (!found && held == 0 && (n = read(fd, buffer + held, sizeof(buffer) - 1 - held)) > 0)",
+     "a_worker_that_warns_more_than_a_page_before_ready_still_starts"),
     ("the verb tail is not replayed", "src/supervisor.c",
      "if (replay_line(w, i->tail[m].line) != RPC_OK)", "if (0 && replay_line(w, i->tail[m].line) != RPC_OK)",
      "own_crash_respawns_only_that_instance_and_replays_it"),