clock_gettime() can, theoretically, fail, although it probably won't until
2038 on old 32-bit systems. Still, it's possible someone could run with
a wildly out of sync clock, or new errors could be added, or it could fail
due to a bug in libc or the kernel.
We don't handle this well. In the debug_print case in vlogmsg we'll just
ignore the failure, and print a timestamp based on uninitialised garbage.
In logfile_write() we exit early and won't log anything at all, which seems
like a good way to make an already weird situation undebuggable.
Add some helpers to instead handle this by using "<error>" in place of a
timestamp if something goes wrong with clock_gettime().
Signed-off-by: David Gibson <david(a)gibson.dropbear.id.au>
---
log.c | 47 ++++++++++++++++++++++++++++++++---------------
1 file changed, 32 insertions(+), 15 deletions(-)
diff --git a/log.c b/log.c
index e60852f7..9f4cb7fc 100644
--- a/log.c
+++ b/log.c
@@ -49,20 +49,37 @@ bool log_runtime; /* Daemonised, or ready in foreground */
#define LL_STRLEN (sizeof("-9223372036854775808"))
#define LOGTIME_STRLEN (LL_STRLEN + 5)
+/**
+ * logtime() - Get the current time for logging purposes
+ * @ts: Buffer into which to store the timestamp
+ *
+ * Return: pointer to @now, or NULL if there was an error retrieving the time
+ */
+const struct timespec *logtime(struct timespec *ts)
+{
+ if (clock_gettime(CLOCK_MONOTONIC, ts))
+ return NULL;
+ return ts;
+}
+
/**
* logtime_fmt() - Format timestamp into a string for the log
* @buf: Buffer into which to format the time
* @size: Size of @buf
- * @ts: Time to format
+ * @ts: Time to format (or NULL on error)
*
* Return: number of characters written to @buf (excluding \0)
*/
int logtime_fmt(char *buf, size_t size, const struct timespec *ts)
{
- int64_t delta = timespec_diff_us(ts, &log_start);
+ if (ts) {
+ int64_t delta = timespec_diff_us(ts, &log_start);
+
+ return snprintf(buf, size, "%lli.%04lli", delta / 1000000LL,
+ (delta / 100LL) % 10000);
+ }
- return snprintf(buf, size, "%lli.%04lli", delta / 1000000LL,
- (delta / 100LL) % 10000);
+ return snprintf(buf, size, "<error>");
}
/* Prefixes for log file messages, indexed by priority */
@@ -213,14 +230,14 @@ static int logfile_rotate(int fd, const struct timespec *now)
*/
static void logfile_write(bool newline, int pri, const char *format, va_list ap)
{
- struct timespec now;
+ const struct timespec *now;
+ struct timespec ts;
char buf[BUFSIZ];
int n;
- if (clock_gettime(CLOCK_MONOTONIC, &now))
- return;
+ now = logtime(&ts);
- n = logtime_fmt(buf, BUFSIZ, &now);
+ n = logtime_fmt(buf, BUFSIZ, now);
n += snprintf(buf + n, BUFSIZ - n, ": %s", logfile_prefix[pri]);
n += vsnprintf(buf + n, BUFSIZ - n, format, ap);
@@ -228,7 +245,7 @@ static void logfile_write(bool newline, int pri, const char *format,
va_list ap)
if (newline && format[strlen(format)] != '\n')
n += snprintf(buf + n, BUFSIZ - n, "\n");
- if ((log_written + n >= log_size) && logfile_rotate(log_file, &now))
+ if ((log_written + n >= log_size) && logfile_rotate(log_file, now))
return;
if ((n = write(log_file, buf, n)) >= 0)
@@ -245,15 +262,15 @@ static void logfile_write(bool newline, int pri, const char *format,
va_list ap)
void vlogmsg(bool newline, int pri, const char *format, va_list ap)
{
bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
- struct timespec tp;
if (debug_print) {
- char logtime[LOGTIME_STRLEN];
-
- clock_gettime(CLOCK_MONOTONIC, &tp);
+ char timestr[LOGTIME_STRLEN];
+ const struct timespec *now;
+ struct timespec ts;
- logtime_fmt(logtime, sizeof(logtime), &tp);
- fprintf(stderr, "%s: ", logtime);
+ now = logtime(&ts);
+ logtime_fmt(timestr, sizeof(timestr), now);
+ fprintf(stderr, "%s: ", timestr);
}
if ((log_mask & LOG_MASK(LOG_PRI(pri))) || !log_conf_parsed) {
--
2.45.2