Skip to content

Commit

Permalink
Merge pull request #552 from ChinYikMing/feat/logging-api
Browse files Browse the repository at this point in the history
Standardize logging utility
  • Loading branch information
jserv authored Feb 4, 2025
2 parents 6e6cfb8 + 85701c4 commit 487149f
Show file tree
Hide file tree
Showing 16 changed files with 339 additions and 111 deletions.
75 changes: 37 additions & 38 deletions Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,10 @@ $(call set-feature, MOP_FUSION)
ENABLE_BLOCK_CHAINING ?= 1
$(call set-feature, BLOCK_CHAINING)

# Enable logging with color
ENABLE_LOG_COLOR ?= 1
$(call set-feature, LOG_COLOR)

# Enable system emulation
ENABLE_SYSTEM ?= 0
$(call set-feature, SYSTEM)
Expand Down Expand Up @@ -293,6 +297,7 @@ OBJS := \
syscall.o \
emulate.o \
riscv.o \
log.o \
elf.o \
cache.o \
mpool.o \
Expand Down Expand Up @@ -347,54 +352,48 @@ EXPECTED_puzzle = success in 2005 trials
EXPECTED_fcalc = Performed 12 tests, 0 failures, 100% success rate.
EXPECTED_pi = 3.141592653589793238462643383279502884197169399375105820974944592307816406286208998628034825342117067982148086

LOG_FILTER=sed -E '/^[0-9]{2}:[0-9]{2}:[0-9]{2} /d'

define exec
$(eval OUTPUT_FILE := $(shell mktemp))
$(eval _ := $(shell LC_ALL=C $(BIN) $(1) $(2) > $(OUTPUT_FILE)))
$(eval RC := $(.SHELLSTATUS))
endef

# $(1): rv32emu's extra CLI parameter
# $(2): ELF executable
# $(3): ELF executable name
# $(4): extra command in the pipeline
# $(5): expected output
define check-test
$(call exec, $(1), $(2))
$(Q)$(PRINTF) "Running $(3) ... "; \
if [ 0 -eq $(RC) ] && [ "$(strip $(shell cat $(OUTPUT_FILE) | $(LOG_FILTER) | $(4)))" = "$(strip $(5))" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
exit 1; \
fi; \
$(RM) $(OUTPUT_FILE)
endef

check-hello: $(BIN)
$(Q)$(PRINTF) "Running hello.elf ... "; \
if [ "$(shell LC_ALL=C $(BIN) $(OUT)/hello.elf | uniq)" = "$(strip $(EXPECTED_hello)) inferior exit code 0" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
exit 1; \
fi;
$(call check-test, , $(OUT)/hello.elf, hello.elf, uniq, $(EXPECTED_hello))

check: $(BIN) check-hello artifact
$(Q)$(foreach e,$(CHECK_ELF_FILES),\
$(PRINTF) "Running $(e) ... "; \
if [ "$(shell LC_ALL=C $(BIN) $(OUT)/riscv32/$(e) | uniq)" = "$(strip $(EXPECTED_$(e))) inferior exit code 0" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
exit 1; \
fi; \
)

EXPECTED_aes_sha1 = 1242a6757c8aef23e50b5264f5941a2f4b4a347e -
$(Q)$(foreach e, $(CHECK_ELF_FILES), $(call check-test, , $(OUT)/riscv32/$(e), $(e), uniq, $(EXPECTED_$(e))))

EXPECTED_aes_sha1 = 89169ec034bec1c6bb2c556b26728a736d350ca3 -
misalign: $(BIN) artifact
$(Q)$(PRINTF) "Running uaes ... ";
$(Q)if [ "$(shell LC_ALL=C $(BIN) -m $(OUT)/riscv32/uaes | $(SHA1SUM))" = "$(EXPECTED_aes_sha1)" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
fi
$(call check-test, -m, $(OUT)/riscv32/uaes, uaes.elf, $(SHA1SUM), $(EXPECTED_aes_sha1))

EXPECTED_misalign = MISALIGNED INSTRUCTION FETCH TEST PASSED!
misalign-in-blk-emu: $(BIN)
$(Q)$(PRINTF) "Running misalign.elf ... "; \
if [ "$(shell LC_ALL=C $(BIN) tests/system/alignment/misalign.elf | tail -n 2)" = "$(strip $(EXPECTED_misalign)) inferior exit code 0" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
exit 1; \
fi;
$(call check-test, , tests/system/alignment/misalign.elf, misalign.elf, tail -n 1, $(EXPECTED_misalign))

EXPECTED_mmu = STORE PAGE FAULT TEST PASSED!
mmu-test: $(BIN)
$(Q)$(PRINTF) "Running vm.elf ... "; \
if [ "$(shell LC_ALL=C $(BIN) tests/system/mmu/vm.elf | tail -n 2)" = "$(strip $(EXPECTED_mmu)) inferior exit code 0" ]; then \
$(call notice, [OK]); \
else \
$(PRINTF) "Failed.\n"; \
exit 1; \
fi;
$(call check-test, , tests/system/mmu/vm.elf, vm.elf, tail -n 1, $(EXPECTED_mmu))

# Non-trivial demonstration programs
ifeq ($(call has, SDL), 1)
Expand Down
1 change: 1 addition & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -155,6 +155,7 @@ The image containing all the necessary tools for development and testing can be
* `ENABLE_SYSTEM`: Experimental system emulation, allowing booting Linux kernel. To enable this feature, additional features must also be enabled. However, by default, when `ENABLE_SYSTEM` is enabled, CSR, fence, integer multiplication/division, and atomic Instructions are automatically enabled
* `ENABLE_MOP_FUSION` : Macro-operation fusion
* `ENABLE_BLOCK_CHAINING` : Block chaining of translated blocks
* `ENABLE_LOG_COLOR` : Logging with colors (default)

e.g., run `make ENABLE_EXT_F=0` for the build without floating-point support.

Expand Down
1 change: 1 addition & 0 deletions src/common.h
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
#include <stdint.h>

#include "feature.h"
#include "log.h"

#if defined(__GNUC__) || defined(__clang__)
#define UNUSED __attribute__((unused))
Expand Down
6 changes: 3 additions & 3 deletions src/devices/uart.c
Original file line number Diff line number Diff line change
Expand Up @@ -47,7 +47,7 @@ void u8250_check_ready(u8250_state_t *uart)
static void u8250_handle_out(u8250_state_t *uart, uint8_t value)
{
if (write(uart->out_fd, &value, 1) < 1)
fprintf(stderr, "failed to write UART output: %s\n", strerror(errno));
rv_log_error("Failed to write UART output: %s", strerror(errno));
}

static uint8_t u8250_handle_in(u8250_state_t *uart)
Expand All @@ -58,13 +58,13 @@ static uint8_t u8250_handle_in(u8250_state_t *uart)
return value;

if (read(uart->in_fd, &value, 1) < 0)
fprintf(stderr, "failed to read UART input: %s\n", strerror(errno));
rv_log_error("Failed to read UART input: %s", strerror(errno));
uart->in_ready = false;
u8250_check_ready(uart);

if (value == 1) { /* start of heading (Ctrl-a) */
if (getchar() == 120) { /* keyboard x */
printf("\n"); /* end emulator with newline */
rv_log_info("RISC-V emulator is destroyed");
exit(EXIT_SUCCESS);
}
}
Expand Down
27 changes: 13 additions & 14 deletions src/devices/virtio-blk.c
Original file line number Diff line number Diff line change
Expand Up @@ -190,7 +190,7 @@ static int virtio_blk_desc_handler(virtio_blk_state_t *vblk,
virtio_blk_write_handler(vblk, sector, vq_desc[1].addr, vq_desc[1].len);
break;
default:
fprintf(stderr, "unsupported virtio-blk operation!\n");
rv_log_error("Unsupported virtio-blk operation");
*status = VIRTIO_BLK_S_UNSUPP;
return -1;
}
Expand All @@ -215,7 +215,7 @@ static void virtio_queue_notify_handler(virtio_blk_state_t *vblk, int index)
/* Check for new buffers */
uint16_t new_avail = ram[queue->queue_avail] >> 16;
if (new_avail - queue->last_avail > (uint16_t) queue->queue_num) {
fprintf(stderr, "size check fail\n");
rv_log_error("Size check fail");
return virtio_blk_set_fail(vblk);
}

Expand Down Expand Up @@ -374,9 +374,8 @@ void virtio_blk_write(virtio_blk_state_t *vblk, uint32_t addr, uint32_t value)
uint32_t *virtio_blk_init(virtio_blk_state_t *vblk, char *disk_file)
{
if (vblk_dev_cnt >= VBLK_DEV_CNT_MAX) {
fprintf(stderr,
"Exceeded the number of virtio-blk devices that can be "
"allocated.\n");
rv_log_error(
"Exceeded the number of virtio-blk devices that can be allocated");
exit(EXIT_FAILURE);
}

Expand All @@ -394,7 +393,7 @@ uint32_t *virtio_blk_init(virtio_blk_state_t *vblk, char *disk_file)
/* Open disk file */
int disk_fd = open(disk_file, O_RDWR);
if (disk_fd < 0) {
fprintf(stderr, "could not open %s\n", disk_file);
rv_log_error("Could not open %s", disk_file);
exit(EXIT_FAILURE);
}

Expand All @@ -408,16 +407,12 @@ uint32_t *virtio_blk_init(virtio_blk_state_t *vblk, char *disk_file)
#if HAVE_MMAP
disk_mem = mmap(NULL, VBLK_PRIV(vblk)->disk_size, PROT_READ | PROT_WRITE,
MAP_SHARED, disk_fd, 0);
if (disk_mem == MAP_FAILED) {
fprintf(stderr, "Could not map disk\n");
return NULL;
}
if (disk_mem == MAP_FAILED)
goto err;
#else
disk_mem = malloc(VBLK_PRIV(vblk)->disk_size);
if (!disk_mem) {
fprintf(stderr, "Could not map disk\n");
return NULL;
}
if (!disk_mem)
goto err;
#endif
assert(!(((uintptr_t) disk_mem) & 0b11));
close(disk_fd);
Expand All @@ -427,6 +422,10 @@ uint32_t *virtio_blk_init(virtio_blk_state_t *vblk, char *disk_file)
(VBLK_PRIV(vblk)->disk_size - 1) / DISK_BLK_SIZE + 1;

return disk_mem;

err:
rv_log_error("Could not map disk %s", disk_file);
return NULL;
}

virtio_blk_state_t *vblk_new()
Expand Down
3 changes: 1 addition & 2 deletions src/emulate.c
Original file line number Diff line number Diff line change
Expand Up @@ -1131,7 +1131,6 @@ void rv_step(void *arg)

#ifdef __EMSCRIPTEN__
if (rv_has_halted(rv)) {
printf("inferior exit code %d\n", attr->exit_code);
emscripten_cancel_main_loop();
rv_delete(rv); /* clean up and reuse memory */
}
Expand Down Expand Up @@ -1346,7 +1345,7 @@ void dump_registers(riscv_t *rv, char *out_file_path)
{
FILE *f = out_file_path[0] == '-' ? stdout : fopen(out_file_path, "w");
if (!f) {
fprintf(stderr, "Cannot open registers output file.\n");
rv_log_error("Cannot open registers output file");
return;
}

Expand Down
5 changes: 5 additions & 0 deletions src/feature.h
Original file line number Diff line number Diff line change
Expand Up @@ -108,5 +108,10 @@
#define RV32_FEATURE_BLOCK_CHAINING 1
#endif

/* Logging with color */
#ifndef RV32_FEATURE_LOG_COLOR
#define RV32_FEATURE_LOG_COLOR 1
#endif

/* Feature test macro */
#define RV32_HAS(x) RV32_FEATURE_##x
125 changes: 125 additions & 0 deletions src/log.c
Original file line number Diff line number Diff line change
@@ -0,0 +1,125 @@
/*
* Copyright (c) 2020 rxi
*
* Permission is hereby granted, free of charge, to any person obtaining a copy
* of this software and associated documentation files (the "Software"), to
* deal in the Software without restriction, including without limitation the
* rights to use, copy, modify, merge, publish, distribute, sublicense, and/or
* sell copies of the Software, and to permit persons to whom the Software is
* furnished to do so, subject to the following conditions:
*
* The above copyright notice and this permission notice shall be included in
* all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
* IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
* FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
* AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
* LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
* FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
* IN THE SOFTWARE.
*/

#include "log.h"

static struct {
void *udata;
log_lock_func_t lock;
int level;
bool quiet;
} L;

static const char *level_strings[] = {
"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL",
};

#if RV32_HAS(LOG_COLOR)
static const char *level_colors[] = {
"\x1b[94m", "\x1b[36m", "\x1b[32m", "\x1b[33m", "\x1b[31m", "\x1b[35m",
};
#endif /* RV32_HAS(LOG_COLOR) */

static void stdout_callback(log_event_t *ev)
{
char buf[16];
buf[strftime(buf, sizeof(buf), "%H:%M:%S", ev->time)] = '\0';
#if RV32_HAS(LOG_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 /* RV32_HAS(LOG_COLOR) */
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);
}

const char *log_level_string(int level)
{
return level_strings[level];
}

void log_set_lock(log_lock_func_t 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;
}

static void init_event(log_event_t *ev, void *udata)
{
if (!ev->time) {
time_t t = time(NULL);
ev->time = localtime(&t);
}
ev->udata = udata;
}

void log_set_stdout_stream(FILE *stream)
{
L.udata = stream;
}

void log_impl(int level, const char *file, int line, const char *fmt, ...)
{
log_event_t ev = {
.fmt = fmt,
.file = file,
.line = line,
.level = level,
};

lock();

if (!L.quiet && level >= L.level) {
init_event(&ev, L.udata ? L.udata : stdout);
va_start(ev.ap, fmt);
stdout_callback(&ev);
va_end(ev.ap);
}

unlock();
}
Loading

0 comments on commit 487149f

Please sign in to comment.