[CRIU] [PATCH v2 1/3] Printout early log messages
Adrian Reber
adrian at lisas.de
Wed Dec 12 08:18:24 MSK 2018
From: Adrian Reber <areber at redhat.com>
Up until now any pr_* logging command (except pr_msg) was lost if
logging has not been set up (log_init()).
To make sure not logging messages are lost, vprint_on_level() now writes
all messages (except LOG_MSG) to a temporary buffer which is written
to the logging FD once that is set up.
Related: https://github.com/checkpoint-restore/criu/issues/578
Signed-off-by: Adrian Reber <areber at redhat.com>
---
criu/log.c | 84 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++-
1 file changed, 83 insertions(+), 1 deletion(-)
diff --git a/criu/log.c b/criu/log.c
index a268ab8..bb2b14b 100644
--- a/criu/log.c
+++ b/criu/log.c
@@ -31,11 +31,21 @@
/* Enable timestamps if verbosity is increased from default */
#define LOG_TIMESTAMP (DEFAULT_LOGLEVEL + 1)
#define LOG_BUF_LEN (8*1024)
+#define EARLY_LOG_BUF_LEN 1024
static unsigned int current_loglevel = DEFAULT_LOGLEVEL;
static char buffer[LOG_BUF_LEN];
static char buf_off = 0;
+/*
+ * The early_log_buffer is used to store log messages before
+ * logging is set up to make sure no logs are lost.
+ */
+static char early_log_buffer[EARLY_LOG_BUF_LEN];
+static unsigned int early_log_buf_off = 0;
+
+/* If this is 0 the logging has not been set up yet. */
+static int init_done = 0;
static struct timeval start;
/*
@@ -186,6 +196,8 @@ int log_init(const char *output)
if (fd < 0)
goto err;
+ init_done = 1;
+
print_versions();
return 0;
@@ -262,18 +274,87 @@ void vprint_on_level(unsigned int loglevel, const char *format, va_list params)
{
int fd, size, ret, off = 0;
int __errno = errno;
+ int tmp_log_level;
+ unsigned int log_size;
+ unsigned int pos;
if (unlikely(loglevel == LOG_MSG)) {
fd = STDOUT_FILENO;
off = buf_off; /* skip dangling timestamp */
} else {
- if (loglevel > current_loglevel)
+ /*
+ * If logging has not yet been initialized (init_done == 0)
+ * make sure all messages are written to the early_log_buffer.
+ */
+ if ((loglevel > current_loglevel) && init_done)
return;
fd = log_get_fd();
if (current_loglevel >= LOG_TIMESTAMP)
print_ts();
}
+ if (!init_done && !(loglevel == LOG_MSG)) {
+ if (early_log_buf_off >= EARLY_LOG_BUF_LEN)
+ return;
+ log_size = 0;
+ /* Save loglevel */
+ early_log_buffer[early_log_buf_off++] = loglevel;
+ /* Skip the log entry size */
+ early_log_buf_off += sizeof(unsigned int);
+ if (loglevel >= LOG_TIMESTAMP) {
+ /*
+ * If logging is not yet setup we just write zeros
+ * instead of a real timestamp. This way we can
+ * keep the same format as the other messages on
+ * log levels with timestamps (>=LOG_TIMESTAMP).
+ */
+ log_size = snprintf(early_log_buffer + early_log_buf_off, sizeof early_log_buffer - early_log_buf_off, "(00.000000) ");
+ }
+
+ log_size += vsnprintf(early_log_buffer + early_log_buf_off + log_size, sizeof early_log_buffer - early_log_buf_off - log_size, format, params);
+ /* Save log entry size */
+ memcpy(early_log_buffer + (early_log_buf_off - sizeof(unsigned int)), &log_size, sizeof(unsigned int));
+ early_log_buf_off += log_size;
+
+ return;
+ }
+
+ /*
+ * Once logging is setup this write out all early log messages.
+ * Only those messages which have to correct log level are printed.
+ */
+ if (early_log_buf_off && init_done) {
+ pos = 0;
+ while (pos < early_log_buf_off) {
+ /*
+ * The early_log_buffer contains all messages written
+ * before logging was set up. We only want to print
+ * out messages which correspond to the requested
+ * log_level. Therefore the early_log_buffer also contains
+ * the log_level and the size. This writes one messages,
+ * depending on the log_level, to the logging fd. Start
+ * with reading the log_level.
+ */
+ tmp_log_level = early_log_buffer[pos++];
+ /* Read out log message size */
+ memcpy(&log_size, early_log_buffer + pos, sizeof(unsigned int));
+ pos += sizeof(unsigned int);
+ size = 0;
+ if (tmp_log_level <= current_loglevel) {
+ while (size < log_size) {
+ ret = write(fd, early_log_buffer + pos + size, log_size - size);
+ if (ret <= 0)
+ break;
+ size += ret;
+ }
+ } else {
+ size += log_size;
+ }
+ pos += size;
+ }
+ early_log_buf_off = 0;
+ }
+
size = vsnprintf(buffer + buf_off, sizeof buffer - buf_off, format, params);
size += buf_off;
@@ -284,6 +365,7 @@ void vprint_on_level(unsigned int loglevel, const char *format, va_list params)
off += ret;
}
+ /* This is missing for messages in the early_log_buffer. */
if (loglevel == LOG_ERROR)
log_note_err(buffer + buf_off);
--
1.8.3.1
More information about the CRIU
mailing list