Do all loggin in main thread

Before this committ, the solver (via the generic solution-appender
routines in src/solve/solutions.h) and the H48 data generator did some
logging in the worker threads, without using any locks. This was not nice,
but in practice it did not cause any problem, because the log messages
were rare.

However, this turned out to be a problem when building to WASM, because
web workers do not have access to the main JS memory, and therefore
they cannot call functions from the main JS. This includes not only the
callback functions for logging, but also those for polling the status
of the solver (run / pause / stop).

This commit fixes this at the cost or being somewhat inelegant: the
solutions are not logged as they are found, but only every 500ms.

7 files changed, 124 insertions, 92 deletions

diff --git a/src/solvers/coord/solve.h b/src/solvers/coord/solve.h
index 659040c..018aa90 100644
--- a/src/solvers/coord/solve.h
+++ b/src/solvers/coord/solve.h
@@ -123,8 +123,7 @@ solve_coord_dfs(dfsarg_solve_coord_t arg[static 1])
                 if (!coord_solution_admissible(arg))
                         return 0;
                 return appendsolution(arg->solution_moves,
-                    arg->solution_settings, arg->solution_list, true,
-                    arg->coord->name);
+                    arg->solution_settings, arg->solution_list);
         }
 
         if (solve_coord_dfs_stop(arg))
@@ -326,7 +325,7 @@ solve_coord(
 
         if (coord->coord(c, coord_data) == 0) {
                 if (minmoves == 0 && !appendsolution(&solution_moves,
-                    &solution_settings, &solution_list, true, coord->name))
+                    &solution_settings, &solution_list))
                                 goto solve_coord_error_buffer;
                 goto solve_coord_done;
         }
diff --git a/src/solvers/distribution.h b/src/solvers/distribution.h
index 3c006a7..27b72d7 100644
--- a/src/solvers/distribution.h
+++ b/src/solvers/distribution.h
@@ -94,10 +94,13 @@ distribution_equal(
                         LOG("[checkdata] Value for depth %" PRIu8
                             ": expected %" PRIu64 ", found %" PRIu64 "\n",
                             i, expected[i], actual[i]);
-                } else {
+                }
+                /*
+                else {
                         LOG("[checkdata] Value for depth %" PRIu8
                             " is correct (%" PRIu64 ")\n", i, actual[i]);
                 }
+                */
         }
 
         return wrong == 0;
diff --git a/src/solvers/h48/gendata_h48.h b/src/solvers/h48/gendata_h48.h
index d1ab3bd..4e5daee 100644
--- a/src/solvers/h48/gendata_h48.h
+++ b/src/solvers/h48/gendata_h48.h
@@ -105,7 +105,7 @@ gendata_h48(gendata_h48_arg_t arg[static 1])
                 return size; /* Dry-run */
 
         if (arg->buf_size < size) {
-                LOG("[H48 gendata] Error data: buffer is too small "
+                LOG("[H48 gendata] Error: buffer is too small "
                     "(needed %" PRId64 " bytes but received %" PRId64 ")\n",
                     size, arg->buf_size);
                 return NISSY_ERROR_BUFFER_SIZE;
@@ -392,9 +392,11 @@ gendata_h48k2(gendata_h48_arg_t arg[static 1])
         };
 
         uint8_t t;
+        int sleeptime;
         unsigned char *table;
         int64_t j;
-        uint64_t i, ii, inext, count, bufsize;
+        _Atomic uint64_t count;
+        uint64_t i, ii, inext, bufsize, done, nshort, velocity;
         h48map_t shortcubes;
         gendata_h48short_arg_t shortarg;
         h48k2_dfs_arg_t dfsarg[THREADS];
@@ -414,7 +416,8 @@ gendata_h48k2(gendata_h48_arg_t arg[static 1])
                 .map = &shortcubes
         };
         gendata_h48short(&shortarg);
-        LOG("[H48 gendata] Computed %" PRIu64 " positions\n", shortarg.map->n);
+        nshort = shortarg.map->n;
+        LOG("[H48 gendata] Computed %" PRIu64 " positions\n", nshort);
 
         if (arg->base >= 20)
                 arg->base = base[arg->h];
@@ -446,6 +449,31 @@ gendata_h48k2(gendata_h48_arg_t arg[static 1])
                     &thread[i], NULL, gendata_h48k2_runthread, &dfsarg[i]);
         }
 
+        if (NISSY_CANSLEEP) {
+                /* Log the progress periodically */
+                LOG("Processing 'short cubes'. This will take a while.\n");
+
+                /* Estimate velocity by checking how much is done after 1s */
+                msleep(1000);
+                velocity = count;
+
+                /* We plan to log 10 times */
+                sleeptime = (100*(nshort-velocity)) / velocity;
+
+                done = count;
+                while (nshort - done > (velocity * sleeptime) / 1000) {
+                        msleep(sleeptime);
+                        pthread_mutex_lock(&shortcubes_mutex);
+                        done = count;
+                        pthread_mutex_unlock(&shortcubes_mutex);
+                        LOG("Processed %" PRIu64 " / %" PRIu64 " cubes\n",
+                            (done / 1000) * 1000, nshort);
+                }
+        } else {
+                LOG("Status updates won't be available because the sleep() "
+                    "functionality is not available on this platform.\n");
+        }
+
         for (i = 0; i < THREADS; i++)
                 pthread_join(thread[i], NULL);
 
@@ -463,7 +491,7 @@ gendata_h48k2(gendata_h48_arg_t arg[static 1])
 STATIC void *
 gendata_h48k2_runthread(void *arg)
 {
-        uint64_t count, coord, mutex;
+        uint64_t coord, mutex;
         kvpair_t kv;
         h48k2_dfs_arg_t *dfsarg;
 
@@ -477,13 +505,9 @@ gendata_h48k2_runthread(void *arg)
                         pthread_mutex_unlock(dfsarg->shortcubes_mutex);
                         break;
                 }
-                count = ++(*dfsarg->count);
+                (*dfsarg->count)++;
                 pthread_mutex_unlock(dfsarg->shortcubes_mutex);
 
-                if (count % UINT64_C(1000000) == 0)
-                        LOG("[H48 gendata] Processing %" PRIu64
-                            "th short cube\n", count);
-
                 if (kv.val < dfsarg->shortdepth) {
                         coord = kv.key >> (int64_t)(11 - dfsarg->h);
                         mutex = H48_INDEX(coord, dfsarg->k) % CHUNKS;
diff --git a/src/solvers/h48/gendata_types_macros.h b/src/solvers/h48/gendata_types_macros.h
index b0592c2..21f0134 100644
--- a/src/solvers/h48/gendata_types_macros.h
+++ b/src/solvers/h48/gendata_types_macros.h
@@ -107,7 +107,7 @@ typedef struct {
         pthread_mutex_t *shortcubes_mutex;
         pthread_mutex_t *table_mutex[CHUNKS];
         uint64_t *next;
-        uint64_t *count;
+        _Atomic uint64_t *count;
 } h48k2_dfs_arg_t;
 
 typedef struct {
diff --git a/src/solvers/h48/solve.h b/src/solvers/h48/solve.h
index 2818c09..4d3c451 100644
--- a/src/solvers/h48/solve.h
+++ b/src/solvers/h48/solve.h
@@ -35,10 +35,8 @@ typedef struct {
         solve_h48_task_t *tasks;
         int thread_id;
         pthread_mutex_t *solutions_mutex;
-        int (*poll_status)(void *);
-        void *poll_status_data;
-        _Atomic bool cancelled;
-        _Atomic bool cantsleep;
+        _Atomic int *status;
+        _Atomic bool thread_done;
 } dfsarg_solve_h48_t;
 
 typedef struct {
@@ -58,9 +56,9 @@ STATIC_INLINE bool solve_h48_stop(dfsarg_solve_h48_t [static 1]);
 STATIC int64_t solve_h48_maketasks(
     dfsarg_solve_h48_t [static 1], dfsarg_solve_h48_maketasks_t [static 1],
     solve_h48_task_t [static STARTING_CUBES], int [static 1]);
-STATIC bool solve_h48_runthread_continue(dfsarg_solve_h48_t *);
 STATIC void *solve_h48_runthread(void *);
 STATIC int64_t solve_h48_dfs(dfsarg_solve_h48_t [static 1]);
+STATIC void solve_h48_log_solutions(solution_list_t [static 1], size_t);
 STATIC int64_t solve_h48(oriented_cube_t, uint8_t, uint8_t, uint8_t, uint8_t,
     uint8_t, uint64_t, const unsigned char *, size_t n, char [n],
     long long [static NISSY_SIZE_SOLVE_STATS], int (*)(void *), void *);
@@ -201,7 +199,7 @@ solve_h48_dfs(dfsarg_solve_h48_t arg[static 1])
                         return 0;
                 pthread_mutex_lock(arg->solutions_mutex);
                 ret = appendsolution(arg->solution_moves,
-                    arg->solution_settings, arg->solution_list, true, "H48");
+                    arg->solution_settings, arg->solution_list);
                 pthread_mutex_unlock(arg->solutions_mutex);
                 return ret;
         }
@@ -271,41 +269,20 @@ solve_h48_dfs(dfsarg_solve_h48_t arg[static 1])
         return ret;
 }
 
-STATIC bool
-solve_h48_runthread_continue(dfsarg_solve_h48_t *arg)
-{
-        int status;
-
-        for (status = NISSY_STATUS_PAUSE; status == NISSY_STATUS_PAUSE; ) {
-                status = arg->poll_status == NULL ? NISSY_STATUS_RUN :
-                    arg->poll_status(arg->poll_status_data);
-                msleep(500);
-        }
-
-        return status == NISSY_STATUS_RUN;
-}
-
 STATIC void *
 solve_h48_runthread(void *arg)
 {
-        int i, j, status;
+        int i, j;
         solve_h48_task_t task;
         dfsarg_solve_h48_t *dfsarg;
 
         dfsarg = (dfsarg_solve_h48_t *)arg;
 
         for (i = dfsarg->thread_id; i < dfsarg->ntasks; i += dfsarg->threads) {
-                status = dfsarg->poll_status == NULL ? NISSY_STATUS_RUN :
-                    dfsarg->poll_status(dfsarg->poll_status_data);
-                switch (status) {
-                case NISSY_STATUS_STOP:
-                        goto solve_h48_runthread_cancel;
-                case NISSY_STATUS_PAUSE:
-                        if (!NISSY_CANSLEEP)
-                                goto solve_h48_runthread_cantsleep;
-                        if (!solve_h48_runthread_continue(dfsarg))
-                                goto solve_h48_runthread_cancel;
-                }
+                if (*dfsarg->status == NISSY_STATUS_STOP)
+                        goto solve_h48_runthread_end;
+                while (*dfsarg->status == NISSY_STATUS_PAUSE)
+                        msleep(BASE_SLEEP_TIME);
 
                 task = dfsarg->tasks[i];
 
@@ -329,12 +306,8 @@ solve_h48_runthread(void *arg)
                 solve_h48_dfs(dfsarg);
         }
 
-        return NULL;
-
-solve_h48_runthread_cantsleep:
-        dfsarg->cantsleep = true;
-solve_h48_runthread_cancel:
-        dfsarg->cancelled = true;
+solve_h48_runthread_end:
+        dfsarg->thread_done = true;
         return NULL;
 }
 
@@ -366,7 +339,7 @@ solve_h48_maketasks(
                     maketasks_arg->moves, maketasks_arg->nmoves);
 
                 appret = appendsolution(&moves, solve_arg->solution_settings,
-                    solve_arg->solution_list, true, "H48");
+                    solve_arg->solution_list);
                 return appret < 0 ? appret : NISSY_OK;
         }
 
@@ -410,6 +383,22 @@ solve_h48_maketasks(
         return NISSY_OK;
 }
 
+STATIC void
+solve_h48_log_solutions(solution_list_t s[static 1], size_t e)
+{
+        size_t i;
+        char b;
+        while (e != s->used) {
+                LOG("[h48 solve] Found solution: ");
+                for (i = e; s->buf[i] != '\n' && s->buf[i] != '\0'; i++) ;
+                b = s->buf[i];
+                s->buf[i] = '\0';
+                LOG("%s\n", s->buf + e);
+                s->buf[i] = b;
+                e = i + 1;
+        }
+}
+
 STATIC int64_t
 solve_h48(
         oriented_cube_t oc,
@@ -427,8 +416,10 @@ solve_h48(
         void *poll_status_data
 )
 {
-        bool anycancelled, anycantsleep;
         int i, ntasks, eoesep_table_index;
+        bool td, fp;
+        _Atomic int status;
+        size_t lastused;
         int8_t d;
         dfsarg_solve_h48_t arg[THREADS];
         solve_h48_task_t tasks[STARTING_CUBES];
@@ -508,10 +499,7 @@ solve_h48(
                         .threads = threads,
                         .thread_id = i,
                         .solutions_mutex = &solutions_mutex,
-                        .poll_status = poll_status,
-                        .poll_status_data = poll_status_data,
-                        .cancelled = false,
-                        .cantsleep = false,
+                        .status = &status,
                 };
 
         }
@@ -538,35 +526,69 @@ solve_h48(
 
         LOG("[H48 solve] Prepared %d tasks\n", ntasks);
 
-        anycancelled = anycantsleep = false;
+        solve_h48_log_solutions(&sollist, 0);
+        lastused = sollist.used;
+        status = poll_status == NULL ? NISSY_STATUS_RUN :
+            poll_status(poll_status_data);
+        if (!NISSY_CANSLEEP) {
+                LOG("[solve h48] Pause / Stop / Resume functionality won't "
+                    "be available on this system (can't sleep()).\n");
+        }
         for (
             d = MAX(minmoves, STARTING_MOVES + 1);
-            !(solutions_done(&sollist, &settings, d) || anycancelled);
+            !(solutions_done(&sollist, &settings, d)) &&
+                status != NISSY_STATUS_STOP;
             d++
         ) {
-                if (d >= 15)
+                if (d >= 15) {
                         LOG("[H48 solve] Found %" PRId64 " solutions, "
                             "searching at depth %" PRId8 "\n",
                             sollist.nsols, d);
+                }
+
                 for (i = 0; i < threads; i++) {
                         arg[i].target_depth = d;
+                        arg[i].thread_done = false;
                         pthread_create(
                             &thread[i], NULL, solve_h48_runthread, &arg[i]);
                 }
-                for (i = 0; i < threads; i++) {
-                        pthread_join(thread[i], NULL);
-                        anycancelled = anycancelled || arg[i].cancelled;
-                        anycantsleep = anycantsleep || arg[i].cantsleep;
+
+                /* Log solutions and handle pause / stop / resume */
+                if (d >= 15 && NISSY_CANSLEEP) {
+                        td = false;
+                        fp = true;
+                        while (!td && status != NISSY_STATUS_STOP) {
+                                msleep(BASE_SLEEP_TIME);
+
+                                pthread_mutex_lock(&solutions_mutex);
+                                solve_h48_log_solutions(&sollist, lastused);
+                                lastused = sollist.used;
+                                pthread_mutex_unlock(&solutions_mutex);
+
+                                if (poll_status == NULL)
+                                        continue;
+
+                                status = poll_status(poll_status_data);
+                                if (status == NISSY_STATUS_PAUSE && fp) {
+                                        LOG("[H48 solve] Paused\n");
+                                        fp = false;
+                                }
+                                if (status == NISSY_STATUS_RUN)
+                                        fp = true;
+
+                                for (td = true, i = 0; i < threads; i++)
+                                        td = td && arg[i].thread_done;
+                        }
                 }
-        }
 
-        if (anycantsleep) {
-                LOG("[H48 solve] Received pause request, but this feature is "
-                    "not available on this system. "
-                    "Taking it as a stop request.\n");
+                for (i = 0; i < threads; i++)
+                        pthread_join(thread[i], NULL);
+
+                solve_h48_log_solutions(&sollist, lastused);
+                lastused = sollist.used;
         }
 
-        if (anycancelled) {
+        if (status == NISSY_STATUS_STOP) {
                 LOG("[H48 solve] Received stop request, ending solution "
                     "search early.\n");
         }
diff --git a/src/solvers/solutions.h b/src/solvers/solutions.h
index 75d0804..182ae18 100644
--- a/src/solvers/solutions.h
+++ b/src/solvers/solutions.h
@@ -12,8 +12,7 @@ STATIC bool appendnormal(
 STATIC bool appendinverse(
     const solution_moves_t [static 1], solution_list_t [static 1]);
 STATIC int64_t appendsolution(const solution_moves_t [static 1],
-    const solution_settings_t [static 1], solution_list_t [static 1], bool,
-    const char *);
+    const solution_settings_t [static 1], solution_list_t [static 1]);
 STATIC bool solutions_done(const solution_list_t [static 1],
     const solution_settings_t [static 1], int8_t depth);
 
@@ -53,10 +52,8 @@ solution_moves_reorient(solution_moves_t moves[static 1], uint8_t or)
 STATIC bool
 solution_list_init(solution_list_t sols[static 1], size_t n, char buf[n])
 {
-        if (n == 0) {
-                LOG("Error: cannot use solution buffer with size 0\n");
+        if (n == 0)
                 return false;
-        }
 
         sols->nsols = 0;
         sols->shortest_sol = MAXLEN + 1;
@@ -158,16 +155,13 @@ STATIC int64_t
 appendsolution(
         const solution_moves_t moves[static 1],
         const solution_settings_t settings[static 1],
-        solution_list_t list[static 1],
-        bool log,
-        const char *solver_name
+        solution_list_t list[static 1]
 )
 {
         int64_t r;
         int i;
         uint8_t t;
         solution_moves_t tsol[NTRANS];
-        char *last_start;
 
         if (moves->nmoves + moves->npremoves > MAXLEN)
                 goto appendsolution_error_solution_length;
@@ -210,8 +204,6 @@ appendsolution(
                 if (solution_moves_is_duplicate(r, tsol))
                         continue;
 
-                last_start = list->buf + list->used;
-
                 /* Append first the moves on the side that has more */
                 /* E.g. write (U L F) B instead of B (U L F) */
                 if (tsol[r].nmoves >= tsol[r].npremoves) {
@@ -244,26 +236,16 @@ appendsolution(
                     list->shortest_sol, tsol[r].nmoves + tsol[r].npremoves);
                 r++;
 
-                if (log) {
-                        list->buf[list->used-1] = '\0';
-                        LOG("[%s solve] Found solution #%" PRIu64 ": %s\n",
-                            solver_name, list->nsols, last_start);
-                        list->buf[list->used-1] = '\n';
-                }
         }
 
         list->buf[list->used] = '\0';
         return r;
 
 appendsolution_error_buffer:
-        LOG("[%s solve] Error: buffer too small\n", solver_name);
         list->buf[0] = '\0';
         return NISSY_ERROR_BUFFER_SIZE;
 
 appendsolution_error_solution_length:
-        LOG("[%s solve] Error: solution is too long (%" PRIu8 ").\n"
-            "This is a bug, please report it.\n",
-            solver_name, moves->nmoves + moves->npremoves);
         list->buf[0] = '\0';
         return NISSY_ERROR_UNKNOWN;
 }
diff --git a/src/utils/sleep.h b/src/utils/sleep.h
index d618e9b..7cdd081 100644
--- a/src/utils/sleep.h
+++ b/src/utils/sleep.h
@@ -1,3 +1,5 @@
+#define BASE_SLEEP_TIME 500
+
 STATIC void msleep(int);
 
 #if defined(WIN32)