diff options
| -rw-r--r-- | core/logger.c | 84 | ||||
| -rwxr-xr-x | salis.py | 97 | ||||
| -rw-r--r-- | ui/curses/ui.c | 48 | ||||
| -rw-r--r-- | ui/daemon/ui.c | 52 |
4 files changed, 148 insertions, 133 deletions
diff --git a/core/logger.c b/core/logger.c new file mode 100644 index 0000000..38ac8ed --- /dev/null +++ b/core/logger.c @@ -0,0 +1,84 @@ +#define LOG_LINE_SIZE 1024 + +enum LogLevel { + LOG_INFO, + LOG_WARN, + LOG_ERRO, +}; + +char g_log_buff[LOG_LINE_SIZE]; + +void log_msg_to_buff(char *out, int size, enum LogLevel level, const char *format, va_list args) { + assert(out); + assert(size); + assert(level == LOG_INFO || level == LOG_WARN || level == LOG_ERRO); + assert(format); + + struct timespec ts; + clock_gettime(CLOCK_REALTIME, &ts); + long msec = ts.tv_nsec / 1000000; + struct tm tm = *localtime(&ts.tv_sec); + int pid = getpid(); + + char *level_str = NULL; + switch (level) { + case LOG_INFO: level_str = "INFO"; break; + case LOG_WARN: level_str = "WARN"; break; + case LOG_ERRO: level_str = "ERRO"; break; + default: assert(false); + } + + int col = snprintf( + out, + size, + "%d-%02d-%02d %02d:%02d:%02d.%03ld %d [%s] ", + tm.tm_year + 1900, + tm.tm_mon + 1, + tm.tm_mday, + tm.tm_hour, + tm.tm_min, + tm.tm_sec, + msec, + pid, + level_str + ); + + vsnprintf(out + col, size - col, format, args); +} + +void log_msg(enum LogLevel level, const char *format, va_list args) { + assert(level == LOG_INFO || level == LOG_WARN || level == LOG_ERRO); + assert(format); + + log_msg_to_buff(g_log_buff, LOG_LINE_SIZE, level, format, args); + printf("\r%s\n", g_log_buff); +} + +void log_info(const char *format, ...) { + assert(format); + + va_list args; + va_start(args, format); + log_msg(LOG_INFO, format, args); + va_end(args); +} + +void log_warn(const char *format, ...) { + assert(format); + + va_list args; + va_start(args, format); + log_msg(LOG_WARN, format, args); + va_end(args); +} + +void log_erro(const char *format, ...) { + assert(format); + + va_list args; + va_start(args, format); + log_msg(LOG_ERRO, format, args); + va_end(args); + + exit(1); +} @@ -1,7 +1,7 @@ #!/usr/bin/env -S PYTHONDONTWRITEBYTECODE=1 python import contextlib -import datetime +import ctypes import json import os import random @@ -9,7 +9,6 @@ import shutil import sqlite3 import subprocess import sys -import threading import urllib.parse import urllib.request @@ -117,28 +116,42 @@ for parser, option in parser_map: args = main_parser.parse_args() # ------------------------------------------------------------------------------ -# Logging +# Bootstrap logging system # ------------------------------------------------------------------------------ -log_lock = threading.Lock() +tempdir = TemporaryDirectory(prefix="salis_", delete=not args.keep_temp_dir) +logger_flags = set() +logger_includes = set() +logger_defines = set() -def now(): - return f"{datetime.datetime.now():%Y-%m-%d %H:%M:%S}" +logger_flags.update({*args.compiler_flags.split(), "-shared", "-fPIC"}) +logger_includes.update({"assert.h", "stdarg.h", "stdbool.h", "stdio.h", "stdlib.h", "time.h", "unistd.h"}) -def info(msg, val=""): - with log_lock: print(f"\r{now()} ++ \033[1;34mINFO\033[0m {msg}", val, flush=True) +if args.optimized: + logger_flags.add("-O3") + logger_defines.add("-DNDEBUG") +else: + logger_flags.add("-ggdb") -def warn(msg, val=""): - with log_lock: print(f"\r{now()} ++ \033[1;33mWARN\033[0m {msg}", val, flush=True) +logger_so = os.path.join(tempdir.name, "log.so") +logger_build_cmd = [args.compiler, "core/logger.c", "-o", logger_so] +logger_build_cmd.extend(logger_flags) +logger_build_cmd.extend(sum(map(lambda include: ["-include", include], logger_includes), [])) +logger_build_cmd.extend(logger_defines) +subprocess.run(logger_build_cmd, check=True) -def error(msg, val=""): - with log_lock: print(f"\r{now()} ++ \033[1;31mERROR\033[0m {msg}", val, flush=True) - sys.exit(1) +logger_dll = ctypes.CDLL(logger_so) +def info(msg): logger_dll.log_info(msg.encode()) +def warn(msg): logger_dll.log_warn(msg.encode()) +def erro(msg): logger_dll.log_erro(msg.encode()) and sys.exit(1) # ------------------------------------------------------------------------------ # Load configuration # ------------------------------------------------------------------------------ info(description) -info(f"Called '{prog} {args.command}' with the following options:", vars(args)) +info(f"Called '{prog} {args.command}' with the following options: {vars(args)}") +info(f"Using temporary directory: {tempdir.name}") +info(f"Using logging dl: {logger_so}") +info(f"Built with command: {logger_build_cmd}") if args.command in ["load", "new", "serve"]: sim_dir = os.path.join(os.environ["HOME"], ".salis", args.name) @@ -147,7 +160,7 @@ if args.command in ["load", "new", "serve"]: if args.command in ["load", "serve"]: if not os.path.isdir(sim_dir): - error("No simulation found named:", args.name) + erro(f"No simulation found named: {args.name}") sys.path.append(sim_dir) import opts @@ -157,25 +170,25 @@ if args.command in ["load", "serve"]: for key, val in opt_vars.items(): setattr(args, key, val) - info(f"Sourced configuration from: '{sim_opts}':", opt_vars) + info(f"Sourced configuration from: '{sim_opts}': {opt_vars}") if args.command in ["new"]: if args.data_push_pow and args.data_push_pow < args.sync_pow: - error("Data push power must be equal or greater than thread sync power") + erro("Data push power must be equal or greater than thread sync power") if os.path.isdir(sim_dir) and args.force: - warn("Force flag used! Wiping old simulation at:", sim_dir) + warn(f"Force flag used! Wiping old simulation at: {sim_dir}") shutil.rmtree(sim_dir) if os.path.isdir(sim_dir): - error("Simulation directory found at:", sim_dir) + erro(f"Simulation directory found at: {sim_dir}") if args.seed == -1: args.seed = random.getrandbits(64) - info("Using random seed:", args.seed) + info(f"Using random seed: {args.seed}") - info("Creating new simulation directory at:", sim_dir) - info("Creating configuration file at:", sim_opts) + info(f"Creating new simulation directory at: {sim_dir}") + info(f"Creating configuration file at: {sim_opts}") os.mkdir(sim_dir) @@ -193,7 +206,7 @@ if args.command in ["new"]: # Load architecture variables # ------------------------------------------------------------------------------ arch_path = os.path.join("arch", args.arch) -info("Loading architecture variables from:", os.path.join(arch_path, "arch_vars.py")) +info(f"Loading architecture variables from: {os.path.join(arch_path, "arch_vars.py")}") sys.path.append(arch_path) from arch_vars import ArchVars arch_vars = ArchVars(args) @@ -209,7 +222,7 @@ if args.command in ["serve"]: "vue@latest": "https://unpkg.com/vue@latest", } - info("Updating vendors:", vendors) + info(f"Updating vendors: {vendors}") for file, url in vendors.items(): with urllib.request.urlopen(url) as response: @@ -235,18 +248,15 @@ if args.command in ["serve"]: sqlx_links.add("-lz") - sqlx_tempdir = TemporaryDirectory(prefix="salis_sqlx_", delete=not args.keep_temp_dir) - info("Created a temporary salis SQLite extension directory at:", sqlx_tempdir.name) - - sqlx_so = os.path.join(sqlx_tempdir.name, "render.so") - info("Building salis SQLite extension at:", sqlx_so) + sqlx_so = os.path.join(tempdir.name, "render.so") + info(f"Building salis SQLite extension at: {sqlx_so}") sqlx_build_cmd = [args.compiler, "core/render.c", "-o", sqlx_so] sqlx_build_cmd.extend(sqlx_flags) sqlx_build_cmd.extend(sqlx_defines) sqlx_build_cmd.extend(sqlx_links) - info("Using build command:", sqlx_build_cmd) + info(f"Using build command: {sqlx_build_cmd}") subprocess.run(sqlx_build_cmd, check=True) # Generate configuration so front-end knows how to render the plots. @@ -309,8 +319,8 @@ if args.command in ["serve"]: for key in arch_vars.heatmaps: heatmaps[key] = (heatmaps[key] if key in heatmaps else {}) | arch_vars.heatmaps[key] - info("Generated plot configuration:", plots) - info("Generated heatmap configuration:", heatmaps) + info(f"Generated plot configuration: {plots}") + info(f"Generated heatmap configuration: {heatmaps}") # NOTE: this server implementation is very minimal and has no built-in security. # Please do not put this on the internet! Only run the data server within secure @@ -411,7 +421,7 @@ if args.command in ["bench", "new"] and args.anc is not None: anc_path = os.path.join("anc", args.arch, f"{args.anc}.asm") if not os.path.isfile(anc_path): - error("Could not find ancestor file:", anc_path) + erro(f"Could not find ancestor file: {anc_path}") with open(anc_path, "r") as file: lines = file.read().splitlines() @@ -433,10 +443,10 @@ if args.command in ["bench", "new"] and args.anc is not None: break if not found: - error("Unrecognized instruction in ancestor file:", line) + erro(f"Unrecognized instruction in ancestor file: {line}") anc_bytes_repr = ",".join(map(str, anc_bytes)) - info(f"Compiled ancestor file '{anc_path}' into byte array:", f"{{{anc_bytes_repr}}}") + info(f"Compiled ancestor file '{anc_path}' into byte array: {{{anc_bytes_repr}}}") # ------------------------------------------------------------------------------ # Populate compiler flags @@ -446,7 +456,7 @@ includes = set() defines = set() links = set() -flags.update({*args.compiler_flags.split(), f"-Iarch/{args.arch}"}) +flags.update({*args.compiler_flags.split(), f"-Iarch/{args.arch}", "-Icore"}) defines.add(f"-DARCH=\"{args.arch}\"") defines.add(f"-DCOMMAND_{args.command.upper()}") @@ -488,7 +498,7 @@ if args.command in ["bench", "new"]: if args.command in ["load", "new"]: ui_path = os.path.join("ui", args.ui) - info("Loading UI variables from:", os.path.join(ui_path, "ui_vars.py")) + info(f"Loading UI variables from: {os.path.join(ui_path, "ui_vars.py")}") sys.path.append(ui_path) from ui_vars import UIVars ui_vars = UIVars(args) @@ -509,7 +519,7 @@ if args.command in ["load", "new"]: defines.add(f"-DDATA_PUSH_INTERVAL={2 ** args.data_push_pow}ul") defines.add(f"-DDATA_PUSH_PATH=\"{data_push_path}\"") links.update({"-lsqlite3", "-lz"}) - info("Data will be aggregated at:", data_push_path) + info(f"Data will be aggregated at: {data_push_path}") else: warn("Data aggregation disabled") @@ -524,11 +534,8 @@ if args.command in ["load", "new"]: # ------------------------------------------------------------------------------ # Build executable # ------------------------------------------------------------------------------ -tempdir = TemporaryDirectory(prefix="salis_", delete=not args.keep_temp_dir) -info("Created a temporary salis directory at:", tempdir.name) - salis_bin = os.path.join(tempdir.name, "salis_bin") -info("Building salis binary at:", salis_bin) +info(f"Building salis binary at: {salis_bin}") build_cmd = [args.compiler, "core/salis.c", "-o", salis_bin] build_cmd.extend(flags) @@ -536,7 +543,7 @@ build_cmd.extend(sum(map(lambda include: ["-include", include], includes), [])) build_cmd.extend(defines) build_cmd.extend(links) -info("Using build command:", build_cmd) +info(f"Using build command: {build_cmd}") subprocess.run(build_cmd, check=True) # ------------------------------------------------------------------------------ @@ -547,7 +554,7 @@ info("Running salis binary...") run_cmd = [args.pre_cmd] if args.pre_cmd else [] run_cmd.append(salis_bin) -info("Using run command:", " ".join(run_cmd)) +info(f"Using run command: {" ".join(run_cmd)}") salis_sp = subprocess.Popen(run_cmd, stdout=sys.stdout, stderr=sys.stderr) # When using signals (e.g. SIGTERM), they must be sent to the entire process group @@ -561,4 +568,4 @@ except KeyboardInterrupt: code = salis_sp.returncode if code != 0: - error("Salis binary returned code:", code) + erro(f"Salis binary returned code: {code}") diff --git a/ui/curses/ui.c b/ui/curses/ui.c index 0f87c2d..3564ef3 100644 --- a/ui/curses/ui.c +++ b/ui/curses/ui.c @@ -1,5 +1,6 @@ +#include "logger.c" + #define LOG_LINE_COUNT 1024 -#define LOG_LINE_SIZE 1024 #define PANE_WIDTH 27 #define PROC_FIELD_WIDTH 21 #define PROC_PAGE_LINES 12 @@ -68,8 +69,6 @@ uint64_t g_wcursor_pointed; uint64_t g_log_cnt; unsigned g_log_ptr; unsigned g_log_scroll; -bool g_log_warns[LOG_LINE_COUNT]; -time_t g_log_times[LOG_LINE_COUNT]; char g_logs[LOG_LINE_COUNT][LOG_LINE_SIZE]; uint64_t g_vlin; uint64_t g_vsiz; @@ -796,12 +795,12 @@ void ui_print_ipc(int l) { // Log page functions // ---------------------------------------------------------------------------- void ui_info_impl(const char *format, ...) { - g_log_warns[g_log_ptr] = false; - g_log_times[g_log_ptr] = time(NULL); + assert(format); + assert(false); va_list args; va_start(args, format); - vsnprintf(g_logs[g_log_ptr], LOG_LINE_SIZE, format, args); + log_msg_to_buff(g_logs[g_log_ptr], LOG_LINE_SIZE, LOG_INFO, format, args); va_end(args); g_log_cnt++; @@ -809,12 +808,11 @@ void ui_info_impl(const char *format, ...) { } void ui_warn_impl(const char *format, ...) { - g_log_warns[g_log_ptr] = true; - g_log_times[g_log_ptr] = time(NULL); + assert(format); va_list args; va_start(args, format); - vsnprintf(g_logs[g_log_ptr], LOG_LINE_SIZE, format, args); + log_msg_to_buff(g_logs[g_log_ptr], LOG_LINE_SIZE, LOG_WARN, format, args); va_end(args); g_log_cnt++; @@ -833,37 +831,7 @@ void ui_print_log_line(unsigned lptr, int line) { ui_clear_log_line(line); if (strlen(g_logs[lptr])) { - struct tm tm = *localtime(&g_log_times[lptr]); - - ui_field( - line, - PANE_WIDTH, - PAIR_NORMAL, - A_NORMAL, - " %d-%02d-%02d %02d:%02d:%02d --", - tm.tm_year + 1900, - tm.tm_mon + 1, - tm.tm_mday, - tm.tm_hour, - tm.tm_min, - tm.tm_sec - ); - - ui_field( - line, - PANE_WIDTH + 25, - g_log_warns[lptr] ? PAIR_WARN : PAIR_HEADER, - A_NORMAL, - g_log_warns[lptr] ? "WARN" : "INFO" - ); - - ui_field( - line, - PANE_WIDTH + 30, - PAIR_NORMAL, - A_NORMAL, - g_logs[lptr] - ); + ui_field(line, PANE_WIDTH + 2, PAIR_NORMAL, A_NORMAL, g_logs[lptr]); } } diff --git a/ui/daemon/ui.c b/ui/daemon/ui.c index 269d5d7..0e4ea15 100644 --- a/ui/daemon/ui.c +++ b/ui/daemon/ui.c @@ -1,52 +1,8 @@ +#include "logger.c" + volatile bool g_running; uint64_t g_step_block; -void info_impl(const char *restrict fmt, ...) { - assert(fmt); - - time_t t = time(NULL); - struct tm tm = *localtime(&t); - printf( - "\r%d-%02d-%02d %02d:%02d:%02d -- \033[1;34mINFO\033[0m ", - tm.tm_year + 1900, - tm.tm_mon + 1, - tm.tm_mday, - tm.tm_hour, - tm.tm_min, - tm.tm_sec - ); - - va_list args; - va_start(args, fmt); - vprintf(fmt, args); - va_end(args); - - printf("\n"); -} - -void warn_impl(const char *restrict fmt, ...) { - assert(fmt); - - time_t t = time(NULL); - struct tm tm = *localtime(&t); - printf( - "\r%d-%02d-%02d %02d:%02d:%02d -- \033[1;33mWARN\033[0m ", - tm.tm_year + 1900, - tm.tm_mon + 1, - tm.tm_mday, - tm.tm_hour, - tm.tm_min, - tm.tm_sec - ); - - va_list args; - va_start(args, fmt); - vprintf(fmt, args); - va_end(args); - - printf("\n"); -} - void sig_handler(int signo) { (void)signo; @@ -78,8 +34,8 @@ void step_block(void) { int main(void) { g_running = true; g_step_block = 1; - g_info = info_impl; - g_warn = warn_impl; + g_info = log_info; + g_warn = log_warn; signal(SIGINT, sig_handler); signal(SIGTERM, sig_handler); |
