diff --git a/components/utilities/Kconfig b/components/utilities/Kconfig index 01fd1ea3ca29d3d40447c16c40ac2a391ba578c5..e6b84c888472138418af20c3304f68b23265b31a 100644 --- a/components/utilities/Kconfig +++ b/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 diff --git a/components/utilities/ulog/SConscript b/components/utilities/ulog/SConscript index 03ea1b5528561a7d704c0a9b069bc7f657fb1dbc..467ec4007d33e350940d3ff9b329c962e7eea897 100644 --- a/components/utilities/ulog/SConscript +++ b/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') diff --git a/components/utilities/ulog/backend/file_be.c b/components/utilities/ulog/backend/file_be.c new file mode 100644 index 0000000000000000000000000000000000000000..693d9abaebe7d463c4a1f3da39d1319ad6e08116 --- /dev/null +++ b/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 +#include +#include + +#include +#include + +#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 */ diff --git a/components/utilities/ulog/backend/ulog_be.h b/components/utilities/ulog/backend/ulog_be.h new file mode 100644 index 0000000000000000000000000000000000000000..e975765566c9ade95fcd19dc2c1174bc4a452832 --- /dev/null +++ b/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 + +#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_ */ diff --git a/components/utilities/ulog/syslog/syslog.c b/components/utilities/ulog/syslog/syslog.c index f9d71a1224bf7ed2804aca1713a9199699c73a05..d5f31b0c18ac5ce6bc25eca2658d7c563b19efe3 100644 --- a/components/utilities/ulog/syslog/syslog.c +++ b/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; } diff --git a/components/utilities/ulog/ulog.c b/components/utilities/ulog/ulog.c index f8f11aaf7858e2232ca61db6dcd170a33927abd0..4b0dbac9e6264113bfbeefb63d2534c2fe9b4aea 100644 --- a/components/utilities/ulog/ulog.c +++ b/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 */ diff --git a/components/utilities/ulog/ulog.h b/components/utilities/ulog/ulog.h index 8340d4c417fe3a069dea1b6d00ab9c5ac26b907b..598e3076cdb99b1e6cc2db1a4e1bce6779cfe84e 100644 --- a/components/utilities/ulog/ulog.h +++ b/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 /*