commit f07471f34fe496d7a9044d4fc2f0eb32dfff02b9
parent 58e27ae7696a8bd029d37497977b155ee3758d3e
Author: Vincent Forest <vincent.forest@meso-star.com>
Date: Wed, 1 Mar 2023 12:01:50 +0100
Start supporting plain text messages and fix a MPI log issue
Until now, log messages were assumed to be read through a VT100-like
terminal and could therefore consist of escape sequences used to
control text color, cursor positioning, etc. This assumption makes it
more difficult to use plain text log files: output messages must be
post-processed by the caller to remove escape sequences.
In this commit, we add the device attribute 'no_escape_sequence' which,
when set, prevents the use of escape sequences in log messages. Among
the most notable changes, colors are disabled and progress messages are
displayed line by line rather than being updated. To contain the number
of printed lines, progress messages are displayed every 10 percent, not
every percentage.
Currently, only the 'sdis_solve_probe' function fully takes into account
the 'no_escape_sequence' option, both in normal or MPI execution.
By the way, this commit resolves an issue when logging the MPI progress
message. Once completed, non-master processes send their completion
status twice to the master process. This could result in corrupted
progress messages for the next calculation if these statuses were not
flushed by the master process at the end of the calculation, due to
random scheduling of processes.
Diffstat:
8 files changed, 91 insertions(+), 28 deletions(-)
diff --git a/src/sdis.c b/src/sdis.c
@@ -99,7 +99,12 @@ static void
rewind_progress_printing(struct sdis_device* dev)
{
size_t i;
- if(!dev->use_mpi || dev->mpi_nprocs == 1) return;
+
+ if(!dev->use_mpi
+ || dev->no_escape_sequence
+ || dev->mpi_nprocs == 1)
+ return;
+
FOR_EACH(i, 0, dev->mpi_nprocs-1) {
log_info(dev, "\033[1A\r"); /* Move up */
}
@@ -816,17 +821,19 @@ print_progress
{
ASSERT(dev && label);
#ifndef SDIS_ENABLE_MPI
- log_info(dev, "%s%3d%%\r", label, progress[0]);
+ log_info(dev, "%s%3d%%%c", label, progress[0],
+ dev->no_escape_sequence ? '\n' : '\r');
#else
if(!dev->use_mpi) {
- log_info(dev, "%s%3d%%\r", label, progress[0]);
+ log_info(dev, "%s%3d%%%c", label, progress[0],
+ dev->no_escape_sequence ? '\n' : '\r');
} else {
int i;
if(dev->mpi_rank != 0) return;
mpi_fetch_progress(dev, progress);
FOR_EACH(i, 0, dev->mpi_nprocs) {
- log_info(dev, "Process %d -- %s%3d%%%c",
- i, label, progress[i], i == dev->mpi_nprocs - 1 ? '\r' : '\n');
+ log_info(dev, "Process %d -- %s%3d%%%c", i, label, progress[i],
+ i == dev->mpi_nprocs - 1 && !dev->no_escape_sequence ? '\r' : '\n');
}
}
#endif
@@ -857,6 +864,35 @@ print_progress_update
}
void
+print_progress_completion
+ (struct sdis_device* dev,
+ int32_t progress[],
+ const char* label)
+{
+ ASSERT(dev);
+ (void)dev, (void)progress, (void)label;
+
+ /* Only print at 100% completion when MPI is enabled, because when last
+ * printed non-master processes might still be running. When MPI is disabled,
+ * 100% completion is printed during calculation */
+#ifdef SDIS_ENABLE_MPI
+ if(dev->use_mpi && dev->mpi_rank == 0 && dev->mpi_nprocs > 1) {
+ mpi_fetch_progress(dev, progress);
+ rewind_progress_printing(dev);
+ print_progress(dev, progress, label);
+
+ /* When escape sequences are allowed, the last newline character of the
+ * progress message is replaced with a carriage return. After the
+ * calculation is complete, we therefore print an additional newline
+ * character after this carriage return. */
+ if(!dev->no_escape_sequence) {
+ log_info(dev, "\n");
+ }
+ }
+#endif
+}
+
+void
process_barrier(struct sdis_device* dev)
{
#ifndef SDIS_ENABLE_MPI
diff --git a/src/sdis.h b/src/sdis.h
@@ -137,6 +137,7 @@ struct sdis_device_create_args {
struct mem_allocator* allocator; /* NULL <=> default allocator */
unsigned nthreads_hint; /* Hint on the number of threads to use */
int verbosity; /* Verbosity level */
+ int no_escape_sequence; /* Rm escape sequences from log messages */
/* Use the Message Passing Interface to distribute work between processes.
* This option is taken into account only if Stardis-Solver is compiled with
@@ -144,7 +145,7 @@ struct sdis_device_create_args {
int use_mpi;
};
#define SDIS_DEVICE_CREATE_ARGS_DEFAULT__ { \
- NULL, NULL, SDIS_NTHREADS_DEFAULT, 1, 0 \
+ NULL, NULL, SDIS_NTHREADS_DEFAULT, 1, 0, 0 \
}
static const struct sdis_device_create_args SDIS_DEVICE_CREATE_ARGS_DEFAULT =
SDIS_DEVICE_CREATE_ARGS_DEFAULT__;
diff --git a/src/sdis_c.h b/src/sdis_c.h
@@ -149,6 +149,13 @@ print_progress_update
int32_t progress[],
const char* label); /* Text preceding the progress status */
+/* Print progress completion, i.e. rewind the printing and print 100% */
+extern LOCAL_SYM void
+print_progress_completion
+ (struct sdis_device* dev,
+ int32_t progress[],
+ const char* label); /* Text preceding the progress status */
+
/* Waiting for all processes. Without MPI this function does nothing. With MPI
* it waits for MPI process synchronisation */
extern LOCAL_SYM void
diff --git a/src/sdis_device.c b/src/sdis_device.c
@@ -326,6 +326,7 @@ sdis_device_create
}
nthreads_max = (unsigned)MMAX(omp_get_max_threads(), omp_get_num_procs());
dev->allocator = allocator;
+ dev->no_escape_sequence = args->no_escape_sequence;
dev->verbose = args->verbosity;
dev->nthreads = MMIN(args->nthreads_hint, nthreads_max);
ref_init(&dev->ref);
diff --git a/src/sdis_device_c.h b/src/sdis_device_c.h
@@ -46,6 +46,7 @@ struct sdis_device {
struct logger logger__; /* Default logger */
struct mem_allocator* allocator;
unsigned nthreads;
+ int no_escape_sequence;
int verbose;
#ifdef SDIS_ENABLE_MPI
diff --git a/src/sdis_log.c b/src/sdis_log.c
@@ -41,22 +41,35 @@ log_msg
static void
print_info(const char* msg, void* ctx)
{
- (void)ctx;
- fprintf(stderr, MSG_INFO_PREFIX"%s", msg);
+ struct sdis_device* dev = ctx;
+
+ if(dev->no_escape_sequence) {
+ fprintf(stderr, MSG_INFO_PREFIX_PLAIN_TEXT"%s", msg);
+ } else {
+ fprintf(stderr, MSG_INFO_PREFIX"%s", msg);
+ }
}
static void
print_err(const char* msg, void* ctx)
{
- (void)ctx;
- fprintf(stderr, MSG_ERROR_PREFIX"%s", msg);
+ struct sdis_device* dev = ctx;
+ if(dev->no_escape_sequence) {
+ fprintf(stderr, MSG_ERROR_PREFIX_PLAIN_TEXT"%s", msg);
+ } else {
+ fprintf(stderr, MSG_ERROR_PREFIX"%s", msg);
+ }
}
static void
print_warn(const char* msg, void* ctx)
{
- (void)ctx;
- fprintf(stderr, MSG_WARNING_PREFIX"%s", msg);
+ struct sdis_device* dev = ctx;
+ if(dev->no_escape_sequence) {
+ fprintf(stderr, MSG_WARNING_PREFIX_PLAIN_TEXT"%s", msg);
+ } else {
+ fprintf(stderr, MSG_WARNING_PREFIX"%s", msg);
+ }
}
/*******************************************************************************
@@ -73,9 +86,9 @@ setup_log_default(struct sdis_device* dev)
if(dev->verbose) print_err("Could not setup the logger.\n", NULL);
goto error;
}
- logger_set_stream(&dev->logger__, LOG_OUTPUT, print_info, NULL);
- logger_set_stream(&dev->logger__, LOG_ERROR, print_err, NULL);
- logger_set_stream(&dev->logger__, LOG_WARNING, print_warn, NULL);
+ logger_set_stream(&dev->logger__, LOG_OUTPUT, print_info, dev);
+ logger_set_stream(&dev->logger__, LOG_ERROR, print_err, dev);
+ logger_set_stream(&dev->logger__, LOG_WARNING, print_warn, dev);
dev->logger = &dev->logger__;
exit:
diff --git a/src/sdis_log.h b/src/sdis_log.h
@@ -18,16 +18,15 @@
#include <rsys/rsys.h>
-#ifdef OS_UNIX
- /* On UNIX assume a VT100-like terminal emulator */
- #define MSG_INFO_PREFIX "stardis-solver (\x1b[1m\x1b[32minfo\x1b[0m): "
- #define MSG_ERROR_PREFIX "stardis-solver (\x1b[1m\x1b[31merror\x1b[0m): "
- #define MSG_WARNING_PREFIX "stardis-solver (\x1b[1m\x1b[33mwarning\x1b[0m): "
-#else
- #define MSG_INFO_PREFIX "stardis-solver (info): "
- #define MSG_ERROR_PREFIX "stardis-solver (error): "
- #define MSG_WARNING_PREFIX "stardis-solver (warning): "
-#endif
+/* By default assume messages are printed in a VT100-like terminal emulator */
+#define MSG_INFO_PREFIX "stardis-solver (\x1b[1m\x1b[32minfo\x1b[0m): "
+#define MSG_ERROR_PREFIX "stardis-solver (\x1b[1m\x1b[31merror\x1b[0m): "
+#define MSG_WARNING_PREFIX "stardis-solver (\x1b[1m\x1b[33mwarning\x1b[0m): "
+
+/* Plain text message prefixes */
+#define MSG_INFO_PREFIX_PLAIN_TEXT "stardis-solver (info): "
+#define MSG_ERROR_PREFIX_PLAIN_TEXT "stardis-solver (error): "
+#define MSG_WARNING_PREFIX_PLAIN_TEXT "stardis-solver (warning): "
extern LOCAL_SYM res_T
setup_log_default
diff --git a/src/sdis_solve_probe_Xd.h b/src/sdis_solve_probe_Xd.h
@@ -102,6 +102,7 @@ XD(solve_probe)
size_t nrealisations = 0;
int64_t irealisation = 0;
int32_t* progress = NULL; /* Per process progress bar */
+ int pcent_progress = 1; /* Percentage requiring progress update */
int register_paths = SDIS_HEAT_PATH_NONE;
int is_master_process = 1;
ATOMIC nsolved_realisations = 0;
@@ -130,6 +131,11 @@ XD(solve_probe)
nthreads = scn->dev->nthreads;
allocator = scn->dev->allocator;
+ /* Update the progress bar every percent if escape sequences are allowed in
+ * log messages or only every 10 percent when only plain text is allowed.
+ * This reduces the number of lines of plain text printed */
+ pcent_progress = scn->dev->no_escape_sequence ? 10 : 1;
+
/* Create the per thread RNGs */
res = create_per_thread_rng
(scn->dev, args->rng_state, args->rng_type, &rng_proxy, &per_thread_rng);
@@ -265,7 +271,7 @@ XD(solve_probe)
pcent = (int)((double)n * 100.0 / (double)nrealisations + 0.5/*round*/);
#pragma omp critical
- if(pcent > progress[0]) {
+ if(pcent/pcent_progress > progress[0]/pcent_progress) {
progress[0] = pcent;
print_progress_update(scn->dev, progress, PROGRESS_MSG);
}
@@ -283,8 +289,7 @@ XD(solve_probe)
res = gather_res_T(scn->dev, (res_T)res);
if(res != RES_OK) goto error;
- print_progress_update(scn->dev, progress, PROGRESS_MSG);
- log_info(scn->dev, "\n");
+ print_progress_completion(scn->dev, progress, PROGRESS_MSG);
#undef PROGRESS_MSG
/* Report computation time */
