[components][ulog] Add file backend

components/utilities/Kconfig

@@ -178,6 +178,13 @@ config RT_USING_ULOG
             help
                 The low level output using rt_kprintf().
 
+        config ULOG_BACKEND_USING_FILE
+            bool "Enable file backend."
+            select RT_USING_DFS
+            default n
+            help
+                The file backend of ulog.
+
         config ULOG_USING_FILTER
             bool "Enable runtime log filter."
             default n

components/utilities/ulog/SConscript

@@ -6,7 +6,11 @@ path = [cwd]
 
 if GetDepend('ULOG_BACKEND_USING_CONSOLE'):
     src += ['backend/console_be.c']
-    
+
+if GetDepend('ULOG_BACKEND_USING_FILE'):
+    path +=  [cwd + '/backend']
+    src += ['backend/file_be.c']
+
 if GetDepend('ULOG_USING_SYSLOG'):
     path +=  [cwd + '/syslog']
     src  += Glob('syslog/*.c')

components/utilities/ulog/backend/file_be.c

@@ -0,0 +1,227 @@
+/*
+ * Copyright (c) 2006-2021, RT-Thread Development Team
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ *
+ * Change Logs:
+ * Date           Author       Notes
+ * 2021-01-07     ChenYong     first version
+ * 2021-12-20     armink       add multi-instance version
+ */
+
+#include <rtthread.h>
+#include <dfs_file.h>
+#include <unistd.h>
+
+#include <ulog.h>
+#include <ulog_be.h>
+
+#ifdef ULOG_BACKEND_USING_FILE
+
+#if defined(ULOG_ASYNC_OUTPUT_THREAD_STACK) && (ULOG_ASYNC_OUTPUT_THREAD_STACK < 2048)
+#error "The value of ULOG_ASYNC_OUTPUT_THREAD_STACK must be greater than 2048."
+#endif
+
+/* rotate the log file xxx_n-1.log => xxx_n.log, and xxx.log => xxx_0.log */
+static rt_bool_t ulog_file_rotate(struct ulog_file_be *be)
+{
+#define SUFFIX_LEN          10
+    /* mv xxx_n-1.log => xxx_n.log, and xxx.log => xxx_0.log */
+    static char old_path[ULOG_FILE_PATH_LEN], new_path[ULOG_FILE_PATH_LEN];
+    int index = 0, err = 0, file_fd = 0;
+    rt_bool_t result = RT_FALSE;
+    size_t base_len = 0;
+
+    rt_snprintf(old_path, ULOG_FILE_PATH_LEN, "%s/%s", be->cur_log_dir_path, be->parent.name);
+    rt_snprintf(new_path, ULOG_FILE_PATH_LEN, "%s/%s", be->cur_log_dir_path, be->parent.name);
+    base_len = rt_strlen(be->cur_log_dir_path) + rt_strlen(be->parent.name) + 1;
+
+    if (be->cur_log_file_fd >= 0)
+    {
+        close(be->cur_log_file_fd);
+    }
+
+    for (index = be->file_max_num - 2; index >= 0; --index)
+    {
+        rt_snprintf(old_path + base_len, SUFFIX_LEN, index ? "_%d.log" : ".log", index - 1);
+        rt_snprintf(new_path + base_len, SUFFIX_LEN, "_%d.log", index);
+        /* remove the old file */
+        if ((file_fd = open(new_path, O_RDONLY)) >= 0)
+        {
+            close(file_fd);
+            unlink(new_path);
+        }
+        /* change the new log file to old file name */
+        if ((file_fd = open(old_path , O_RDONLY)) >= 0)
+        {
+            close(file_fd);
+            err = dfs_file_rename(old_path, new_path);
+        }
+
+        if (err < 0)
+        {
+            result = RT_FALSE;
+            goto __exit;
+        }
+
+        result = RT_TRUE;
+    }
+
+__exit:
+    /* reopen the file */
+    be->cur_log_file_fd = open(be->cur_log_file_path, O_CREAT | O_RDWR | O_APPEND);
+
+    return result;
+}
+
+static void ulog_file_backend_flush_with_buf(struct ulog_backend *backend)
+{
+    struct ulog_file_be *be = (struct ulog_file_be *) backend;
+    rt_size_t file_size = 0, write_size = 0;
+
+    if (be->enable == RT_FALSE)
+    {
+        return;
+    }
+
+    if (be->cur_log_file_fd < 0)
+    {
+        /* check log file directory  */
+        if (access(be->cur_log_dir_path, 0) < 0)
+        {
+            mkdir(be->cur_log_dir_path, 0);
+        }
+        /* open file */
+        rt_snprintf(be->cur_log_file_path, ULOG_FILE_PATH_LEN, "%s/%s.log", be->cur_log_dir_path, be->parent.name);
+        be->cur_log_file_fd = open(be->cur_log_file_path, O_CREAT | O_RDWR | O_APPEND);
+        if (be->cur_log_file_fd < 0)
+        {
+            rt_kprintf("ulog file(%s) open failed.", be->cur_log_file_path);
+            return;
+        }
+    }
+
+    file_size = lseek(be->cur_log_file_fd, 0, SEEK_END);
+    if (file_size >= (be->file_max_size - be->buf_size * 2))
+    {
+        if (!ulog_file_rotate(be))
+        {
+            return;
+        }
+    }
+
+    write_size = (rt_size_t)(be->buf_ptr_now - be->file_buf);
+    /* write to the file */
+    if (write(be->cur_log_file_fd, be->file_buf, write_size) != write_size)
+    {
+        return;
+    }
+    /* flush file cache */
+    fsync(be->cur_log_file_fd);
+
+    /* point be->buf_ptr_now at the head of be->file_buf[be->buf_size] */
+    be->buf_ptr_now = be->file_buf;
+}
+
+static void ulog_file_backend_output_with_buf(struct ulog_backend *backend, rt_uint32_t level,
+            const char *tag, rt_bool_t is_raw, const char *log, rt_size_t len)
+{
+    struct ulog_file_be *be = (struct ulog_file_be *)backend;
+    rt_size_t copy_len = 0, free_len = 0;
+    const unsigned char *buf_ptr_end = be->file_buf + be->buf_size;
+
+    while (len)
+    {
+        /* free space length */
+        free_len = buf_ptr_end - be->buf_ptr_now;
+        /* copy the log to the mem buffer */
+        if (len > free_len)
+        {
+            copy_len = free_len;
+        }
+        else
+        {
+            copy_len = len;
+        }
+        rt_memcpy(be->buf_ptr_now, log, copy_len);
+        /* update data pos */
+        be->buf_ptr_now += copy_len;
+        len -= copy_len;
+        log += copy_len;
+
+        RT_ASSERT(be->buf_ptr_now <= buf_ptr_end);
+        /* check the log buffer remain size */
+        if (buf_ptr_end == be->buf_ptr_now)
+        {
+            ulog_file_backend_flush_with_buf(backend);
+            if (buf_ptr_end == be->buf_ptr_now)
+            {
+                /* There is no space, indicating that the data cannot be refreshed
+                   to the back end of the file Discard data and exit directly */
+                break;
+            }
+        }
+    }
+}
+
+/* initialize the ulog file backend */
+int ulog_file_backend_init(struct ulog_file_be *be, const char *name, const char *dir_path, rt_size_t max_num,
+        rt_size_t max_size, rt_size_t buf_size)
+{
+    be->file_buf = rt_calloc(1, buf_size);
+    if (!be->file_buf)
+    {
+        rt_kprintf("Warning: NO MEMORY for %s file backend\n", name);
+        return -RT_ENOMEM;
+    }
+    /* temporarily store the start address of the ulog file buffer */
+    be->buf_ptr_now = be->file_buf;
+    be->cur_log_file_fd = -1;
+    be->file_max_num = max_num;
+    be->file_max_size = max_size;
+    be->buf_size = buf_size;
+    be->enable = RT_FALSE;
+    rt_strncpy(be->cur_log_dir_path, dir_path, ULOG_FILE_PATH_LEN);
+    /* the buffer length MUST less than file size */
+    RT_ASSERT(be->buf_size < be->file_max_size);
+
+    be->parent.output = ulog_file_backend_output_with_buf;
+    be->parent.flush = ulog_file_backend_flush_with_buf;
+    ulog_backend_register((ulog_backend_t) be, name, RT_FALSE);
+
+    return 0;
+}
+
+/* uninitialize the ulog file backend */
+int ulog_file_backend_deinit(struct ulog_file_be *be)
+{
+    if (be->cur_log_file_fd >= 0)
+    {
+        /* flush log to file */
+        ulog_file_backend_flush_with_buf((ulog_backend_t)be);
+        /* close */
+        close(be->cur_log_file_fd);
+        be->cur_log_file_fd = -1;
+    }
+
+    if (!be->file_buf)
+    {
+        rt_free(be->file_buf);
+        be->file_buf = RT_NULL;
+    }
+
+    ulog_backend_unregister((ulog_backend_t)be);
+    return 0;
+}
+
+void ulog_file_backend_enable(struct ulog_file_be *be)
+{
+    be->enable = RT_TRUE;
+}
+
+void ulog_file_backend_disable(struct ulog_file_be *be)
+{
+    be->enable = RT_FALSE;
+}
+
+#endif /* ULOG_BACKEND_USING_FILE */

components/utilities/ulog/backend/ulog_be.h

@@ -0,0 +1,44 @@
+/*
+ * Copyright (c) 2006-2021, RT-Thread Development Team
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ *
+ * Change Logs:
+ * Date           Author       Notes
+ * 2021-01-07     ChenYong     first version
+ * 2021-12-20     armink       add multi-instance version
+ */
+
+#ifndef _ULOG_BE_H_
+#define _ULOG_BE_H_
+
+#include <ulog.h>
+
+#ifndef ULOG_FILE_PATH_LEN
+#define ULOG_FILE_PATH_LEN   128
+#endif
+
+struct ulog_file_be
+{
+    struct ulog_backend parent;
+    int cur_log_file_fd;
+    rt_size_t file_max_num;
+    rt_size_t file_max_size;
+    rt_size_t buf_size;
+    rt_bool_t enable;
+
+    rt_uint8_t *file_buf;
+    rt_uint8_t *buf_ptr_now;
+
+    char cur_log_file_path[ULOG_FILE_PATH_LEN];
+    char cur_log_dir_path[ULOG_FILE_PATH_LEN];
+};
+
+/* ulog file backend api */
+int ulog_file_backend_init(struct ulog_file_be *be, const char *name, const char *dir_path, rt_size_t max_num,
+        rt_size_t max_size, rt_size_t buf_size);
+int ulog_file_backend_deinit(struct ulog_file_be *be);
+void ulog_file_backend_enable(struct ulog_file_be *be);
+void ulog_file_backend_disable(struct ulog_file_be *be);
+
+#endif /* _ULOG_BE_H_ */

components/utilities/ulog/syslog/syslog.c

@@ -236,13 +236,15 @@ RT_WEAK rt_size_t syslog_formater(char *log_buf, int level, const char *tag, rt_
         log_len = ULOG_LINE_BUF_SIZE;
     }
 
-    /* overflow check and reserve some space for newline sign */
-    if (log_len + newline_len > ULOG_LINE_BUF_SIZE)
+    /* overflow check and reserve some space for newline sign and string end sign */
+    if (log_len + newline_len + sizeof('\0') > ULOG_LINE_BUF_SIZE)
     {
         /* using max length */
         log_len = ULOG_LINE_BUF_SIZE;
         /* reserve some space for newline sign */
         log_len -= newline_len;
+        /* reserve some space for string end sign */
+        log_len -= sizeof('\0');
     }
 
     /* package newline sign */
@@ -251,6 +253,9 @@ RT_WEAK rt_size_t syslog_formater(char *log_buf, int level, const char *tag, rt_
         log_len += ulog_strcpy(log_len, log_buf + log_len, ULOG_NEWLINE_SIGN);
     }
 
+    /* add string end sign */
+    log_buf[log_len] = '\0';
+
     return log_len;
 }
 

components/utilities/ulog/ulog.c

@@ -279,32 +279,33 @@ RT_WEAK rt_size_t ulog_formater(char *log_buf, rt_uint32_t level, const char *ta
         static struct timeval now;
         static struct tm *tm, tm_tmp;
         static rt_bool_t check_usec_support = RT_FALSE, usec_is_support = RT_FALSE;
+        time_t t = (time_t)0;
 
         if (gettimeofday(&now, RT_NULL) >= 0)
         {
-            time_t t = now.tv_sec;
-            tm = localtime_r(&t, &tm_tmp);
-            /* show the time format MM-DD HH:MM:SS */
-            rt_snprintf(log_buf + log_len, ULOG_LINE_BUF_SIZE - log_len, "%02d-%02d %02d:%02d:%02d", tm->tm_mon + 1,
-                    tm->tm_mday, tm->tm_hour, tm->tm_min, tm->tm_sec);
-            /* check the microseconds support when kernel is startup */
-            if (!check_usec_support && rt_thread_self() != RT_NULL)
-            {
-                long old_usec = now.tv_usec;
-                /* delay some time for wait microseconds changed */
-                rt_thread_mdelay(10);
-                gettimeofday(&now, RT_NULL);
-                check_usec_support = RT_TRUE;
-                /* the microseconds is not equal between two gettimeofday calls */
-                if (now.tv_usec != old_usec)
-                    usec_is_support = RT_TRUE;
-            }
-            if (usec_is_support)
-            {
-                /* show the millisecond */
-                log_len += rt_strlen(log_buf + log_len);
-                rt_snprintf(log_buf + log_len, ULOG_LINE_BUF_SIZE - log_len, ".%03d", now.tv_usec / 1000);
-            }
+            t = now.tv_sec;
+        }
+        tm = localtime_r(&t, &tm_tmp);
+        /* show the time format MM-DD HH:MM:SS */
+        rt_snprintf(log_buf + log_len, ULOG_LINE_BUF_SIZE - log_len, "%02d-%02d %02d:%02d:%02d", tm->tm_mon + 1,
+                tm->tm_mday, tm->tm_hour, tm->tm_min, tm->tm_sec);
+        /* check the microseconds support when kernel is startup */
+        if (t > 0 && !check_usec_support && rt_thread_self() != RT_NULL)
+        {
+            long old_usec = now.tv_usec;
+            /* delay some time for wait microseconds changed */
+            rt_thread_mdelay(10);
+            gettimeofday(&now, RT_NULL);
+            check_usec_support = RT_TRUE;
+            /* the microseconds is not equal between two gettimeofday calls */
+            if (now.tv_usec != old_usec)
+                usec_is_support = RT_TRUE;
+        }
+        if (usec_is_support)
+        {
+            /* show the millisecond */
+            log_len += rt_strlen(log_buf + log_len);
+            rt_snprintf(log_buf + log_len, ULOG_LINE_BUF_SIZE - log_len, ".%03d", now.tv_usec / 1000);
         }
 
 #else
@@ -382,22 +383,24 @@ RT_WEAK rt_size_t ulog_formater(char *log_buf, rt_uint32_t level, const char *ta
         log_len = ULOG_LINE_BUF_SIZE;
     }
 
-    /* overflow check and reserve some space for CSI end sign and newline sign */
+    /* overflow check and reserve some space for CSI end sign, newline sign and string end sign */
 #ifdef ULOG_USING_COLOR
-    if (log_len + (sizeof(CSI_END) - 1) + newline_len > ULOG_LINE_BUF_SIZE)
+    if (log_len + (sizeof(CSI_END) - 1) + newline_len + sizeof((char)'\0') > ULOG_LINE_BUF_SIZE)
     {
         /* using max length */
         log_len = ULOG_LINE_BUF_SIZE;
         /* reserve some space for CSI end sign */
         log_len -= (sizeof(CSI_END) - 1);
 #else
-    if (log_len + newline_len > ULOG_LINE_BUF_SIZE)
+    if (log_len + newline_len + sizeof((char)'\0') > ULOG_LINE_BUF_SIZE)
     {
         /* using max length */
         log_len = ULOG_LINE_BUF_SIZE;
 #endif /* ULOG_USING_COLOR */
         /* reserve some space for newline sign */
         log_len -= newline_len;
+        /* reserve some space for string end sign */
+        log_len -= sizeof((char)'\0');
     }
 
     /* package newline sign */
@@ -414,10 +417,13 @@ RT_WEAK rt_size_t ulog_formater(char *log_buf, rt_uint32_t level, const char *ta
     }
 #endif /* ULOG_USING_COLOR */
 
+    /* add string end sign */
+    log_buf[log_len] = '\0';
+
     return log_len;
 }
 
-void ulog_output_to_all_backend(rt_uint32_t level, const char *tag, rt_bool_t is_raw, const char *log, rt_size_t size)
+static void ulog_output_to_all_backend(rt_uint32_t level, const char *tag, rt_bool_t is_raw, const char *log, rt_size_t len)
 {
     rt_slist_t *node;
     ulog_backend_t backend;
@@ -441,21 +447,21 @@ void ulog_output_to_all_backend(rt_uint32_t level, const char *tag, rt_bool_t is
             continue;
         }
 #if !defined(ULOG_USING_COLOR) || defined(ULOG_USING_SYSLOG)
-        backend->output(backend, level, tag, is_raw, log, size);
+        backend->output(backend, level, tag, is_raw, log, len);
 #else
-        if (backend->filter && backend->filter(backend, level, tag, is_raw, log, size) == RT_FALSE)
+        if (backend->filter && backend->filter(backend, level, tag, is_raw, log, len) == RT_FALSE)
         {
             /* backend's filter is not match, so skip output */
             continue;
         }
         if (backend->support_color || is_raw)
         {
-            backend->output(backend, level, tag, is_raw, log, size);
+            backend->output(backend, level, tag, is_raw, log, len);
         }
         else
         {
             /* recalculate the log start address and log size when backend not supported color */
-            rt_size_t color_info_len = 0, output_size = size;
+            rt_size_t color_info_len = 0, output_len = len;
             const char *output_log = log;
 
             if (color_output_info[level] != RT_NULL)
@@ -466,9 +472,9 @@ void ulog_output_to_all_backend(rt_uint32_t level, const char *tag, rt_bool_t is
                 rt_size_t color_hdr_len = rt_strlen(CSI_START) + color_info_len;
 
                 output_log += color_hdr_len;
-                output_size -= (color_hdr_len + (sizeof(CSI_END) - 1));
+                output_len -= (color_hdr_len + (sizeof(CSI_END) - 1));
             }
-            backend->output(backend, level, tag, is_raw, output_log, output_size);
+            backend->output(backend, level, tag, is_raw, output_log, output_len);
         }
 #endif /* !defined(ULOG_USING_COLOR) || defined(ULOG_USING_SYSLOG) */
     }
@@ -477,6 +483,7 @@ void ulog_output_to_all_backend(rt_uint32_t level, const char *tag, rt_bool_t is
 static void do_output(rt_uint32_t level, const char *tag, rt_bool_t is_raw, const char *log_buf, rt_size_t log_len)
 {
 #ifdef ULOG_USING_ASYNC_OUTPUT
+    rt_size_t log_buf_size = log_len + sizeof((char)'\0');
 
     if (is_raw == RT_FALSE)
     {
@@ -484,7 +491,7 @@ static void do_output(rt_uint32_t level, const char *tag, rt_bool_t is_raw, cons
         ulog_frame_t log_frame;
 
         /* allocate log frame */
-        log_blk = rt_rbb_blk_alloc(ulog.async_rbb, RT_ALIGN(sizeof(struct ulog_frame) + log_len, RT_ALIGN_SIZE));
+        log_blk = rt_rbb_blk_alloc(ulog.async_rbb, RT_ALIGN(sizeof(struct ulog_frame) + log_buf_size, RT_ALIGN_SIZE));
         if (log_blk)
         {
             /* package the log frame */
@@ -496,7 +503,7 @@ static void do_output(rt_uint32_t level, const char *tag, rt_bool_t is_raw, cons
             log_frame->tag = tag;
             log_frame->log = (const char *)log_blk->buf + sizeof(struct ulog_frame);
             /* copy log data */
-            rt_memcpy(log_blk->buf + sizeof(struct ulog_frame), log_buf, log_len);
+            rt_strncpy((char *)(log_blk->buf + sizeof(struct ulog_frame)), log_buf, log_buf_size);
             /* put the block */
             rt_rbb_blk_put(log_blk);
             /* send a notice */
@@ -515,7 +522,7 @@ static void do_output(rt_uint32_t level, const char *tag, rt_bool_t is_raw, cons
     }
     else if (ulog.async_rb)
     {
-        rt_ringbuffer_put(ulog.async_rb, (const rt_uint8_t *)log_buf, log_len);
+        rt_ringbuffer_put(ulog.async_rb, (const rt_uint8_t *)log_buf, log_buf_size);
         /* send a notice */
         rt_sem_release(&ulog.async_notice);
     }
@@ -584,6 +591,7 @@ void ulog_voutput(rt_uint32_t level, const char *tag, rt_bool_t newline, const c
 #endif /* ULOG_USING_SYSLOG */
     else if (!rt_strstr(tag, ulog.filter.tag))
     {
+        /* tag filter */
         return;
     }
 #endif /* ULOG_USING_FILTER */
@@ -705,7 +713,7 @@ void ulog_raw(const char *format, ...)
     }
 
     /* do log output */
-    do_output(LOG_LVL_DBG, RT_NULL, RT_TRUE, log_buf, log_len);
+    do_output(LOG_LVL_DBG, "", RT_TRUE, log_buf, log_len);
 
     /* unlock output */
     output_unlock();
@@ -1394,11 +1402,12 @@ void ulog_async_output(void)
     if (ulog.async_rb)
     {
         rt_size_t log_len = rt_ringbuffer_data_len(ulog.async_rb);
-        char *log = rt_malloc(log_len);
+        char *log = rt_malloc(log_len + 1);
         if (log)
         {
             rt_size_t len = rt_ringbuffer_get(ulog.async_rb, (rt_uint8_t *)log, log_len);
-            ulog_output_to_all_backend(LOG_LVL_DBG, RT_NULL, RT_TRUE, log, len);
+            log[log_len] = '\0';
+            ulog_output_to_all_backend(LOG_LVL_DBG, "", RT_TRUE, log, len);
             rt_free(log);
         }
     }
@@ -1419,11 +1428,13 @@ void ulog_async_output_enabled(rt_bool_t enabled)
  * waiting for get asynchronous output log
  *
  * @param time the waiting time
+ *
+ * @return the operation status, RT_EOK on successful
  */
-void ulog_async_waiting_log(rt_int32_t time)
+rt_err_t ulog_async_waiting_log(rt_int32_t time)
 {
     rt_sem_control(&ulog.async_notice, RT_IPC_CMD_RESET, RT_NULL);
-    rt_sem_take(&ulog.async_notice, time);
+    return rt_sem_take(&ulog.async_notice, time);
 }
 
 static void async_output_thread_entry(void *param)
@@ -1433,7 +1444,22 @@ static void async_output_thread_entry(void *param)
     while (1)
     {
         ulog_async_waiting_log(RT_WAITING_FOREVER);
-        ulog_async_output();
+        while (1)
+        {
+            ulog_async_output();
+            /* If there is no log output for a certain period of time,
+             * refresh the log buffer
+             */
+            if (ulog_async_waiting_log(RT_TICK_PER_SECOND * 2) == RT_EOK)
+            {
+                continue;
+            }
+            else
+            {
+                ulog_flush();
+                break;
+            }
+        }
     }
 }
 #endif /* ULOG_USING_ASYNC_OUTPUT */

components/utilities/ulog/ulog.h

@@ -81,7 +81,7 @@ void ulog_flush(void);
  */
 void ulog_async_output(void);
 void ulog_async_output_enabled(rt_bool_t enabled);
-void ulog_async_waiting_log(rt_int32_t time);
+rt_err_t ulog_async_waiting_log(rt_int32_t time);
 #endif
 
 /*