Change logging mechanism to syslog

README-zh.md

@@ -112,9 +112,18 @@ nohup ./hvisor virtio start virtio_cfg.json &
 ./hvisor zone start <vm_config.json>
 ```
 
-其中`nohup ... &`说明该命令会创建一个守护进程，且该进程的日志输出保存在当前文件夹下的nohup.out文件中。
+其中 `&` 说明该命令会在后台运行。由于 Virtio 守护进程使用 `syslog` 记录日志，使用以下命令查看 `hvisor-tool` 的日志：
 
-`virtio_cfg.json`则是一个描述Virtio设备的JSON文件，例如[virtio_cfg.json](./examples/nxp-aarch64/virtio_cfg.json)。该示例文件会依次执行：
+*   **对于使用 `systemd` 的系统：**
+    ```bash
+    journalctl -t hvisor-tool -f
+    ```
+*   **对于没有 `systemd` 的系统（日志由 `rsyslog` 处理）：**
+    ```bash
+    tail -f /var/log/syslog | grep hvisor-tool
+    ```
+
+`virtio_cfg.json` 则是一个描述Virtio设备的JSON file，例如[virtio_cfg.json](./examples/nxp-aarch64/virtio_cfg.json)。该示例文件会依次执行：
 
 1. 地址空间映射
 
@@ -126,7 +135,7 @@ nohup ./hvisor virtio start virtio_cfg.json &
 
 3. 创建Virtio-console设备
 
-创建一个Virtio-console设备，用于`zone1`主串口的输出。root linux需要执行`screen /dev/pts/x`命令进入该虚拟控制台，其中`x`可通过nohup.out日志文件查看。
+创建一个Virtio-console设备，用于`zone1`主串口的输出。root linux需要执行`screen /dev/pts/x`命令进入该虚拟控制台，其中`x`可通过syslog日志查看。
 
 如要退回到主控制台，按下快捷键`ctrl+a+d`。如果在qemu中，则需要按下`ctrl+a ctrl+a+d`。如要再次进入虚拟控制台，执行`screen -r [SID]`，其中SID为该screen会话的进程ID。
 

README.md

@@ -112,7 +112,16 @@ nohup ./hvisor virtio start virtio_cfg.json &
 ./hvisor zone start <vm_config.json>
 ```
 
-The `nohup ... &` part indicates that this command will create a daemon, and its log output will be saved in the `nohup.out` file in the current directory.
+The `&` part indicates that this command will run in the background. Since the Virtio daemon uses `syslog` for logging, use the following commands to view the `hvisor-tool` logs:
+
+*   **For systems with `systemd`:**
+    ```bash
+    journalctl -t hvisor-tool -f
+    ```
+*   **For systems without `systemd` (logs are handled by `rsyslog`):**
+    ```bash
+    tail -f /var/log/syslog | grep hvisor-tool
+    ```
 
 `virtio_cfg.json` is a JSON file that describes the Virtio devices, such as [virtio_cfg.json](./examples/nxp-aarch64/virtio_cfg.json). The example file will perform the following actions:
 
@@ -126,7 +135,7 @@ A Virtio-blk device is created, and `zone1` will communicate with this device vi
 
 3. **Create Virtio-console Device**
 
-A Virtio-console device is created for the main serial port of `zone1`. Root Linux should execute the command `screen /dev/pts/x` to enter this virtual console, where `x` can be found in the `nohup.out` log file.
+A Virtio-console device is created for the main serial port of `zone1`. Root Linux should execute the command `screen /dev/pts/x` to enter this virtual console, where `x` can be found in the system log.
 
 To return to the main console, press the shortcut `ctrl+a+d`. In QEMU, press `ctrl+a ctrl+a+d`. To re-enter the virtual console, execute `screen -r [SID]`, where SID is the process ID of the `screen` session.
 

tools/include/log.h

@@ -20,44 +20,23 @@
 
 #include <stdarg.h>
 #include <stdbool.h>
-#include <stdio.h>
-#include <time.h>
 
 #define LOG_VERSION "0.1.0"
 
-typedef struct {
-    va_list ap;
-    const char *fmt;
-    const char *file;
-    struct tm *time;
-    void *udata;
-    int line;
-    int level;
-} log_Event;
-
-typedef void (*log_LogFn)(log_Event *ev);
-typedef void (*log_LockFn)(bool lock, void *udata);
-
 enum { LOG_TRACE, LOG_DEBUG, LOG_INFO, LOG_WARN, LOG_ERROR, LOG_FATAL };
 
-#define log_trace(...) log_log(1, LOG_TRACE, __FILE__, __LINE__, __VA_ARGS__)
-#define log_debug(...) log_log(1, LOG_DEBUG, __FILE__, __LINE__, __VA_ARGS__)
-#define log_info(...) log_log(1, LOG_INFO, __FILE__, __LINE__, __VA_ARGS__)
-#define log_warn(...) log_log(1, LOG_WARN, __FILE__, __LINE__, __VA_ARGS__)
-#define log_error(...) log_log(1, LOG_ERROR, __FILE__, __LINE__, __VA_ARGS__)
-#define log_fatal(...) log_log(1, LOG_FATAL, __FILE__, __LINE__, __VA_ARGS__)
-// log_printf can be used like printf
-#define log_printf(...) log_log(0, LOG_DEBUG, __FILE__, __LINE__, __VA_ARGS__)
+#define log_trace(...) log_log(LOG_TRACE, __FILE__, __LINE__, __VA_ARGS__)
+#define log_debug(...) log_log(LOG_DEBUG, __FILE__, __LINE__, __VA_ARGS__)
+#define log_info(...) log_log(LOG_INFO, __FILE__, __LINE__, __VA_ARGS__)
+#define log_warn(...) log_log(LOG_WARN, __FILE__, __LINE__, __VA_ARGS__)
+#define log_error(...) log_log(LOG_ERROR, __FILE__, __LINE__, __VA_ARGS__)
+#define log_fatal(...) log_log(LOG_FATAL, __FILE__, __LINE__, __VA_ARGS__)
 
 const char *log_level_string(int level);
-void log_set_lock(log_LockFn fn, void *udata);
 void log_set_level(int level);
 void log_set_quiet(bool enable);
-int log_add_callback(log_LogFn fn, void *udata, int level);
-int log_add_fp(FILE *fp, int level);
 
-void log_log(int with_enter, int level, const char *file, int line,
-             const char *fmt, ...);
+void log_log(int level, const char *file, int line, const char *fmt, ...);
 void multithread_log_init();
-void mutithread_log_exit();
+void multithread_log_exit();
 #endif

tools/log.c

@@ -32,157 +32,43 @@
 
 #include "log.h"
 #include <pthread.h>
-
-#define MAX_CALLBACKS 32
-
-typedef struct {
-    log_LogFn fn;
-    void *udata;
-    int level;
-} Callback;
+#include <stdarg.h>
+#include <stdio.h>
+#include <syslog.h>
 
 static struct {
-    void *udata;
-    log_LockFn lock;
     int level;
     bool quiet;
-    Callback callbacks[MAX_CALLBACKS];
 } L;
 
 static const char *level_strings[] = {"TRACE", "DEBUG", "INFO",
                                       "WARN",  "ERROR", "FATAL"};
 
-#ifdef LOG_USE_COLOR
-static const char *level_colors[] = {"\x1b[94m", "\x1b[36m", "\x1b[32m",
-                                     "\x1b[33m", "\x1b[31m", "\x1b[35m"};
-#endif
-
-static void stdout_callback(log_Event *ev, int with_enter) {
-    char buf[16];
-    // put ev->time as a string into buf
-    buf[strftime(buf, sizeof(buf), "%H:%M:%S", ev->time)] = '\0';
-
-    if (with_enter) {
-#ifdef LOG_USE_COLOR
-        fprintf(ev->udata, "%s %s%-5s\x1b[0m \x1b[90m%s:%d:\x1b[0m ", buf,
-                level_colors[ev->level], level_strings[ev->level], ev->file,
-                ev->line);
-#else
-        fprintf(ev->udata, "%s %-5s %s:%d: ", buf, level_strings[ev->level],
-                ev->file, ev->line);
-#endif
-    }
-
-    vfprintf(ev->udata, ev->fmt, ev->ap);
-    if (with_enter)
-        fprintf(ev->udata, "\n");
-    fflush(ev->udata);
-}
-
-static void file_callback(log_Event *ev) {
-    char buf[64];
-    buf[strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", ev->time)] = '\0';
-    fprintf(ev->udata, "%s %-5s %s:%d: ", buf, level_strings[ev->level],
-            ev->file, ev->line);
-    vfprintf(ev->udata, ev->fmt, ev->ap);
-    fprintf(ev->udata, "\n");
-    fflush(ev->udata);
-}
-
-static void lock(void) {
-    if (L.lock) {
-        L.lock(true, L.udata);
-    }
-}
-
-static void unlock(void) {
-    if (L.lock) {
-        L.lock(false, L.udata);
-    }
-}
+static const int syslog_levels[] = {LOG_DEBUG,   LOG_DEBUG, LOG_INFO,
+                                    LOG_WARNING, LOG_ERR,   LOG_CRIT};
 
 const char *log_level_string(int level) { return level_strings[level]; }
 
-void log_set_lock(log_LockFn fn, void *udata) {
-    L.lock = fn;
-    L.udata = udata;
-}
-
 void log_set_level(int level) { L.level = level; }
 
 void log_set_quiet(bool enable) { L.quiet = enable; }
 
-int log_add_callback(log_LogFn fn, void *udata, int level) {
-    for (int i = 0; i < MAX_CALLBACKS; i++) {
-        if (!L.callbacks[i].fn) {
-            L.callbacks[i] = (Callback){fn, udata, level};
-            return 0;
-        }
-    }
-    return -1;
-}
-
-int log_add_fp(FILE *fp, int level) {
-    return log_add_callback(file_callback, fp, level);
-}
-
-static void init_event(log_Event *ev, void *udata) {
-    if (!ev->time) {
-        time_t t = time(NULL);
-        ev->time = localtime(&t);
-    }
-    ev->udata = udata;
-}
-
-void log_log(int with_enter, int level, const char *file, int line,
-             const char *fmt, ...) {
+void log_log(int level, const char *file, int line, const char *fmt, ...) {
     if (L.quiet || level < L.level) {
         return;
     }
 
-    log_Event ev = {
-        .fmt = fmt,
-        .file = file,
-        .line = line,
-        .level = level,
-    };
-
-    lock();
-
-    if (!L.quiet && level >= L.level) {
-        init_event(&ev, stderr);
-        va_start(ev.ap, fmt);
-        stdout_callback(&ev, with_enter);
-        va_end(ev.ap);
-    }
-
-    for (int i = 0; i < MAX_CALLBACKS && L.callbacks[i].fn; i++) {
-        Callback *cb = &L.callbacks[i];
-        if (level >= cb->level) {
-            init_event(&ev, cb->udata);
-            va_start(ev.ap, fmt);
-            cb->fn(&ev);
-            va_end(ev.ap);
-        }
-    }
-
-    unlock();
+    /* Primary output to syslog */
+    va_list ap;
+    va_start(ap, fmt);
+    char buf[2048];
+    vsnprintf(buf, sizeof(buf), fmt, ap);
+    va_end(ap);
+    syslog(syslog_levels[level], "%s:%d: %s", file, line, buf);
 }
 
-pthread_mutex_t MUTEX_LOG;
-void log_lock(bool lock, void *udata);
-
 void multithread_log_init() {
-    pthread_mutex_init(&MUTEX_LOG, NULL);
-    log_set_lock(log_lock, &MUTEX_LOG);
+    openlog("hvisor-tool", LOG_PID | LOG_NDELAY, LOG_DAEMON);
 }
 
-void mutithread_log_exit() { pthread_mutex_destroy(&MUTEX_LOG); }
-
-void log_lock(bool lock, void *udata) {
-    pthread_mutex_t *LOCK = (pthread_mutex_t *)(udata);
-    if (lock)
-        pthread_mutex_lock(LOCK);
-    else
-        pthread_mutex_unlock(LOCK);
-}
+void multithread_log_exit() { closelog(); }

tools/virtio.c

@@ -1010,7 +1010,7 @@ void virtio_close() {
                        zone_mem[i][j][MEM_SIZE]);
             }
     }
-    mutithread_log_exit();
+    multithread_log_exit();
     log_warn("virtio daemon exit successfully");
 }
 
@@ -1080,9 +1080,6 @@ void initialize_log() {
     log_level = LOG_WARN;
 #endif
     log_set_level(log_level);
-
-    FILE *log_file = fopen("log.txt", "w+");
-    log_add_fp(log_file, LOG_WARN);
 }
 
 int virtio_init() {

tools/virtio_console.c

@@ -68,12 +68,6 @@ static void virtio_console_event_handler(int fd, int epoll_type, void *param) {
             break;
         }
         len = readv(dev->master_fd, iov, n);
-        if (len > 0) {
-            for (int i = 0; i < len; i++) {
-                log_printf("%c", *(char *)&iov->iov_base[i]);
-            }
-            log_printf("] vq->last_avail_idx is %d\n", vq->last_avail_idx);
-        }
         if (len < 0 && errno == EWOULDBLOCK) {
             log_debug("no more bytes");
             vq->last_avail_idx--;
@@ -158,32 +152,12 @@ static void virtq_tx_handle_one_request(ConsoleDev *dev, VirtQueue *vq) {
     uint16_t idx;
     ssize_t len;
     struct iovec *iov = NULL;
-    static int count = 0;
-    count++;
     if (dev->master_fd <= 0) {
         log_error("Console master fd is not ready");
         return;
     }
 
     n = process_descriptor_chain(vq, &idx, &iov, NULL, 0, false);
-    // if (count % 100 == 0) {
-    //     log_info("console txq: n is %d, data is ", n);
-    //     for (int i=0; i<iov->iov_len; i++)
-    //         log_printf("%c", *(char*)&iov->iov_base[i]);
-    //     log_printf("\n");
-    // }
-
-    for (int i = 0; i < n; i++) {
-        log_printf("RAW:[");
-        for (int j = 0; j < iov[i].iov_len; j++) {
-            char x = *(char *)&iov[i].iov_base[j];
-            if (x == '\t' || x == '\n' || x == '\r') {
-                x = ' ';
-            }
-            log_printf("%c", x);
-        }
-        log_printf("]\n");
-    }
 
     if (n < 1) {
         return;