add information when an entry is printed out of order

Sometimes an entry is delivered to dlog with a delay longer
than sorting window and needs to be printed out of order.
Add information when it happens to minimize the risk of
confusion

Change-Id: I1b0913ad4755899b9000e2707193f07c3cdc9931
Signed-off-by: Maciej Slodczyk <m.slodczyk2@partner.samsung.com>

diff --git a/include/log_file.h b/include/log_file.h
index ce15cb4..6bbd313 100644 (file)
--- a/include/log_file.h
+++ b/include/log_file.h
@@ -37,6 +37,8 @@ struct log_file {
        size_t rotate_size_kbytes;
        size_t max_rotated;
        log_format *format;
+       int32_t prev_sec;  /* previously written entry's timestamp, seconds */
+       int32_t prev_nsec; /* previously written timestamp, nanoseconds */
 };
 
 #ifdef __cplusplus

diff --git a/src/shared/log_file.c b/src/shared/log_file.c
index 5813175..e379e59 100644 (file)
--- a/src/shared/log_file.c
+++ b/src/shared/log_file.c
@@ -43,6 +43,8 @@ int logfile_init(struct log_file *l_file)
        l_file->rotate_size_kbytes = DEFAULT_ROTATE_SIZE_KB;
        l_file->max_rotated = DEFAULT_ROTATE_NUM_FILES;
        l_file->format = log_format_new();
+       l_file->prev_sec = INT_MIN;
+       l_file->prev_nsec = INT_MIN;
 
        return l_file->format != NULL ? 0 : -1;
 }
@@ -203,6 +205,12 @@ void logfile_do_rotate(struct log_file *file)
        logfile_open_internal(file);
 }
 
+static void logfile_add_timestamp(struct log_file *file, const struct logger_entry *p)
+{
+       file->prev_sec = p->sec;
+       file->prev_nsec = p->nsec;
+}
+
 /**
  * @brief Write with rotation
  * @details Writes the entry to given file, automatically handling file rotation
@@ -214,11 +222,26 @@ int logfile_write_with_rotation(const struct logger_entry *e, struct log_file *f
 {
        if (!log_should_print_line(file->format, e))
                return 1;
-       int written_bytes = log_print_log_line(file->format, file->fd, e);
+       int written_bytes = 0;
+
+       if (e->sec < file->prev_sec || (e->sec == file->prev_sec && e->nsec < file->prev_nsec)) {
+               char buffer[512];
+               int r = snprintf(buffer, sizeof buffer, "INFO: Following log entry could not be sorted and is out of order.\n");
+               written_bytes = write(file->fd, buffer, r);
+
+               if (written_bytes < 0) {
+                       ERR("unable to write out-of-order message %m");
+                       written_bytes = 0;
+               }
+       }
+
+       written_bytes += log_print_log_line(file->format, file->fd, e);
        if (written_bytes <= 0)
                return 1;
        file->size += written_bytes;
 
+       logfile_add_timestamp(file, e);
+
        if (logfile_rotate_needed(file))
                logfile_do_rotate(file);
        return 0;