Skip to content

Commit

Permalink
syslog: migrate structured logging
Browse files Browse the repository at this point in the history
  • Loading branch information
moodyhunter committed Aug 1, 2024
1 parent d415d9f commit 8cdaa07
Show file tree
Hide file tree
Showing 9 changed files with 179 additions and 105 deletions.
3 changes: 3 additions & 0 deletions kernel/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -101,4 +101,7 @@ add_kernel_source(kmain.c ksyscall_entry.c ksyscall.c)
generate_nanopb_proto(FILESYSTEM_PROTO_SRCS FILESYSTEM_PROTO_HEADERS ${CMAKE_SOURCE_DIR}/proto/mos_rpc.proto ${CMAKE_SOURCE_DIR}/proto/filesystem.proto)
add_kernel_source(${FILESYSTEM_PROTO_SRCS} ${FILESYSTEM_PROTO_HEADERS})

generate_nanopb_proto(SYSLOG_PROTO_SRCS SYSLOG_PROTO_HEADERS ${CMAKE_SOURCE_DIR}/proto/syslog.proto)
add_kernel_source(${SYSLOG_PROTO_SRCS} ${SYSLOG_PROTO_HEADERS})

add_subdirectory(tests)
14 changes: 11 additions & 3 deletions kernel/include/private/mos/syslog/debug.h
Original file line number Diff line number Diff line change
Expand Up @@ -50,15 +50,23 @@
// clang-format on

#if MOS_CONFIG(MOS_DYNAMIC_DEBUG)

typedef struct _debug_info_entry
{
u32 id;
const char *name;
bool enabled;
} debug_info_entry;

extern struct _mos_debug_info
{
#define _expand_field(name) bool name;
#define _expand_field(name) debug_info_entry name;
MOS_ALL_DEBUG_MODULES(_expand_field)
#undef _expand_field
} mos_debug_info;

#define mos_debug_enabled(name) (mos_debug_info.name)
#define mos_debug_enabled_ptr(name) (&mos_debug_info.name)
#define mos_debug_enabled(name) (mos_debug_info.name.enabled)
#define mos_debug_enabled_ptr(name) (&mos_debug_info.name.enabled)
#else
#define mos_debug_enabled(name) MOS_DEBUG_FEATURE(name)
#define mos_debug_enabled_ptr(name) NULL
Expand Down
32 changes: 12 additions & 20 deletions kernel/include/private/mos/syslog/printk.h
Original file line number Diff line number Diff line change
Expand Up @@ -3,31 +3,23 @@
#pragma once

#include "mos/syslog/debug.h"
#include "mos/syslog/printk_prefix.h"
#include "mos/syslog/syslog.h"

#include <mos/mos_global.h>
#include <mos/types.h>

typedef enum
{
MOS_LOG_FATAL = 6,
MOS_LOG_EMERG = 5,
MOS_LOG_WARN = 4,
MOS_LOG_EMPH = 3,
MOS_LOG_INFO = 2,
MOS_LOG_INFO2 = 1,
MOS_LOG_UNSET = 0,
} loglevel_t;

#ifndef pr_fmt
#define pr_fmt(fmt) fmt // default format string
#endif

#define emit_syslog(level, feat, fmt, ...) do_syslog(level, current_thread, __FILE_NAME__, __func__, __LINE__, &mos_debug_info.feat, fmt, ##__VA_ARGS__)
#define emit_syslog_nofeat(level, fmt, ...) do_syslog(level, current_thread, __FILE_NAME__, __func__, __LINE__, NULL, fmt, ##__VA_ARGS__)

#define lprintk_debug_wrapper(feat, level, fmt, ...) \
do \
{ \
if (mos_debug_enabled(feat)) \
lprintk_wrapper(level, "%-10s | " fmt, #feat, ##__VA_ARGS__); \
emit_syslog(level, feat, fmt, ##__VA_ARGS__); \
} while (0)

// clang-format off
Expand All @@ -39,13 +31,13 @@ typedef enum
#define pr_dfatal(feat, fmt, ...) lprintk_debug_wrapper(feat, MOS_LOG_FATAL, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_dcont(feat, fmt, ...) do { if (mos_debug_enabled(feat)) pr_cont(fmt, ##__VA_ARGS__); } while (0)

#define pr_info(fmt, ...) lprintk_wrapper(MOS_LOG_INFO, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_info2(fmt, ...) lprintk_wrapper(MOS_LOG_INFO2, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_emph(fmt, ...) lprintk_wrapper(MOS_LOG_EMPH, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warn(fmt, ...) lprintk_wrapper(MOS_LOG_WARN, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_emerg(fmt, ...) lprintk_wrapper(MOS_LOG_EMERG, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_fatal(fmt, ...) lprintk_wrapper(MOS_LOG_FATAL, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_cont(fmt, ...) lprintk(MOS_LOG_UNSET, "" fmt, ##__VA_ARGS__)
#define pr_info(fmt, ...) emit_syslog_nofeat(MOS_LOG_INFO, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_info2(fmt, ...) emit_syslog_nofeat(MOS_LOG_INFO2, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_emph(fmt, ...) emit_syslog_nofeat(MOS_LOG_EMPH, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warn(fmt, ...) emit_syslog_nofeat(MOS_LOG_WARN, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_emerg(fmt, ...) emit_syslog_nofeat(MOS_LOG_EMERG, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_fatal(fmt, ...) emit_syslog_nofeat(MOS_LOG_FATAL, pr_fmt(fmt), ##__VA_ARGS__)
#define pr_cont(fmt, ...) emit_syslog_nofeat(MOS_LOG_UNSET, "" fmt, ##__VA_ARGS__)
// clang-format off

__BEGIN_DECLS
Expand Down
73 changes: 0 additions & 73 deletions kernel/include/private/mos/syslog/printk_prefix.h

This file was deleted.

19 changes: 19 additions & 0 deletions kernel/include/private/mos/syslog/syslog.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
// SPDX-License-Identifier: GPL-3.0-or-later

#pragma once

#include "mos/platform/platform.h"
#include "mos/syslog/debug.h"

typedef enum
{
MOS_LOG_FATAL = 6,
MOS_LOG_EMERG = 5,
MOS_LOG_WARN = 4,
MOS_LOG_EMPH = 3,
MOS_LOG_INFO = 2,
MOS_LOG_INFO2 = 1,
MOS_LOG_UNSET = 0,
} loglevel_t;

long do_syslog(loglevel_t level, thread_t *thread, const char *file, const char *func, int line, debug_info_entry *feat, const char *fmt, ...);
2 changes: 1 addition & 1 deletion kernel/misc/kutils.c
Original file line number Diff line number Diff line change
Expand Up @@ -38,5 +38,5 @@ void hexdump(const char *data, const size_t len)
}
}

pr_info();
pr_info("");
}
15 changes: 7 additions & 8 deletions kernel/syslog/debug.c
Original file line number Diff line number Diff line change
Expand Up @@ -19,8 +19,8 @@ MOS_ALL_DEBUG_MODULES(_check_debug_macro_defined_)
#if MOS_CONFIG(MOS_DYNAMIC_DEBUG)

// populate default debug settings
typeof(mos_debug_info) mos_debug_info = {
#define X(name) .name = MOS_DEBUG_FEATURE(name),
struct _mos_debug_info mos_debug_info = {
#define X(_name) ._name = { .id = __COUNTER__ + 1, .name = #_name, .enabled = MOS_DEBUG_FEATURE(_name) },
MOS_ALL_DEBUG_MODULES(X)
#undef X
};
Expand All @@ -35,7 +35,7 @@ void debug_print_action(const char *name, bool newstate)
#define debug_show_function(name) \
bool debug_show_##name(sysfs_file_t *file) \
{ \
sysfs_printf(file, "%d\n", mos_debug_info.name); \
sysfs_printf(file, "%d\n", mos_debug_info.name.enabled); \
return true; \
}

Expand All @@ -47,14 +47,13 @@ void debug_print_action(const char *name, bool newstate)
if (count < 1) \
return -EINVAL; \
const bool on = buf[0] == '1'; \
mos_debug_info.name = on; \
mos_debug_info.name.enabled = on; \
debug_print_action(#name, on); \
return count; \
}

#define X(name) debug_show_function(name) debug_store_function(name)
MOS_ALL_DEBUG_MODULES(X)
#undef X
MOS_ALL_DEBUG_MODULES(debug_show_function)
MOS_ALL_DEBUG_MODULES(debug_store_function)

static sysfs_item_t sys_debug_items[] = {
#define X(name) SYSFS_RW_ITEM(#name, debug_show_##name, debug_store_##name),
Expand All @@ -67,7 +66,7 @@ SYSFS_AUTOREGISTER(debug, sys_debug_items);
#define SETUP_DEBUG_MODULE(name) \
static bool setup_debug_##name(const char *value) \
{ \
mos_debug_info.name = cmdline_string_truthiness(value, true); \
mos_debug_info.name.enabled = cmdline_string_truthiness(value, true); \
return true; \
} \
MOS_SETUP("debug." #name, setup_debug_##name);
Expand Down
71 changes: 71 additions & 0 deletions kernel/syslog/syslog.c
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
// SPDX-License-Identifier: GPL-3.0-or-later

#include "mos/syslog/syslog.h"

#include "mos/platform/platform.h"
#include "mos/tasks/task_types.h"
#include "proto/syslog.pb.h"

#include <mos/compiler.h>
#include <mos/mos_global.h>
#include <mos_stdio.h>
#include <pb_encode.h>

static spinlock_t global_syslog_lock = SPINLOCK_INIT;

long do_syslog(loglevel_t level, thread_t *thread, const char *file, const char *func, int line, debug_info_entry *feat, const char *fmt, ...)
{
pb_syslog_message msg = {
.timestamp = platform_get_timestamp(),
.cpu_id = platform_current_cpu_id(),
};

msg.info.level = (syslog_level) level;
msg.info.featid = feat ? feat->id : 0;
msg.info.source_location.line = line;
strncpy(msg.info.source_location.filename, file, sizeof(msg.info.source_location.filename));
strncpy(msg.info.source_location.function, func, sizeof(msg.info.source_location.function));

if (thread)
{
msg.thread.tid = thread->tid;
msg.process.pid = thread->owner->pid;
strncpy(msg.thread.name, thread->name, sizeof(msg.thread.name));
strncpy(msg.process.name, thread->owner->name, sizeof(msg.process.name));
}

va_list args;
va_start(args, fmt);
vsnprintf(msg.message, sizeof(msg.message), fmt, args);
va_end(args);

spinlock_acquire(&global_syslog_lock);

lprintk(level, "\r\n");

#if MOS_CONFIG(MOS_PRINTK_WITH_TIMESTAMP)
lprintk(MOS_LOG_UNSET, "%-16llu | ", platform_get_timestamp());
#endif

#if MOS_CONFIG(MOS_PRINTK_WITH_DATETIME)
lprintk(MOS_LOG_UNSET, "%s | ", (const char *) platform_get_datetime_str());
#endif

#if MOS_CONFIG(MOS_PRINTK_WITH_CPU_ID)
lprintk(MOS_LOG_UNSET, "cpu %2d | ", msg.cpu_id);
#endif

#if MOS_CONFIG(MOS_PRINTK_WITH_FILENAME)
lprintk(MOS_LOG_UNSET, "%-15s | ", msg.info.source_location.filename);
#endif

#if MOS_CONFIG(MOS_PRINTK_WITH_THREAD_ID)
lprintk(MOS_LOG_UNSET, "%pt\t| ", ((void *) thread));
#endif

lprintk(MOS_LOG_UNSET, "%s", msg.message);

spinlock_release(&global_syslog_lock);

return 0;
}
55 changes: 55 additions & 0 deletions proto/syslog.proto
Original file line number Diff line number Diff line change
@@ -0,0 +1,55 @@
// SPDX-License-Identifier: GPL-3.0-or-later
syntax = "proto3";
import "nanopb.proto";

option (nanopb_fileopt).fallback_type = FT_STATIC;
option (nanopb_fileopt).proto3_singular_msgs = true;

enum syslog_level
{
UNSET = 0;
INFO2 = 1;
INFO = 2;
EMPH = 3;
WARN = 4;
EMERG = 5;
FATAL = 6;
}

message pb_thread
{
uint32 tid = 1;
string name = 2 [ (nanopb).max_size = 32 ];
}

message pb_process
{
uint32 pid = 1;
string name = 2 [ (nanopb).max_size = 32 ];
}

message pb_source_location
{
string filename = 1 [ (nanopb).max_size = 32 ];
uint32 line = 2;
string function = 3 [ (nanopb).max_size = 32 ];
}

message pb_syslog_source_info
{
syslog_level level = 1;
uint32 featid = 2;
pb_source_location source_location = 3;
}

message pb_syslog_message
{
uint64 timestamp = 1;
pb_syslog_source_info info = 2;
string message = 3 [ (nanopb).max_size = 512 ];

pb_thread thread = 4;
pb_process process = 5;

uint32 cpu_id = 6;
}

0 comments on commit 8cdaa07

Please sign in to comment.