Benni's Git/Got Repository (2)

Commit Diff

Commit:: 85165aafc2dca81d4df459965dbece1f75f9c2cb
From:: Benjamin Stürz <benni@stuerz.xyz>
Date:: Sat Jun 15 22:18:45 2024 UTC
Message:: improve logging
Actions:: Patch | Tree
commit - d68efc51bceae0ebcb0917fc3b90eb5af74ea76a
commit + 85165aafc2dca81d4df459965dbece1f75f9c2cb
blob - 7f88c1790ad9c4ed9776a28bab20fdbea8ae19be
blob + cf9d917af65dec853f6d7828188c8e3fe8ff08a2
--- src/cpu.c
+++ src/cpu.c
@@ -2,7 +2,7 @@
 #include "linurv.h"
 
 static u64 regs[31];
-u64 pc;
+u64 pc, next_pc;
 
 void cpu_set (size_t reg, u64 val)
 {
@@ -18,8 +18,7 @@ u64 cpu_get (size_t reg)
 u32 cpu_fetch (void)
 {
 	const u32 i = *(const u32 *)(size_t)pc;
-	//eprintf ("%08x: %08x\n", cpu->pc, i);
-	pc += 4;
+	next_pc = pc + 4;
 	return i;
 }
 
@@ -28,7 +27,6 @@ static i64 extend (i32 x)
 	return x;
 }
 
-#define log(fmt, ...) eprintf ("%08"PRIx64": " fmt "\n", pc - 4, __VA_ARGS__)
 void cpu_exec (u32 instr)
 {
 	[[maybe_unused]] const char *sufx;
@@ -65,12 +63,12 @@ void cpu_exec (u32 instr)
 	u64 a, b, c;
 	switch (instr & 0x7f) {
 	case 0b0110111: // lui rd, uimm
-		log ("lui x%u, %"PRIu64, (uint)rd, imm_u);
+		vdebug ("lui x%u, %"PRIu64, (uint)rd, imm_u);
 		cpu_set (rd, imm_u);
 		break;
 	case 0b0010111: // auipc rd, uimm
-		a = pc + imm_u - 4;
-		log ("auipc x%u, %"PRIu64 " ; %"PRIu64, (uint)rd, imm_u, a);
+		a = pc + imm_u;
+		vdebug ("auipc x%u, %"PRIu64 " ; %"PRIu64, (uint)rd, imm_u, a);
 		cpu_set (rd, a);
 		break;
 	case 0b0101111: // atomics
@@ -81,24 +79,24 @@ void cpu_exec (u32 instr)
 		case 0b00010'010: // lr.w
 			if (rs2 != 0)
 				goto ud;
-			log ("lr.w%s x%u, (x%u) ; *%p", sufx, (uint)rs1, (uint)rs2, (void *)a);
+			vdebug ("lr.w%s x%u, (x%u) ; *%p", sufx, (uint)rs1, (uint)rs2, (void *)a);
 			b = read_i32 (a);
 			cpu_set (rd, b);
 			break;
 		case 0b00011'010: // sc.w
-			log ("sc.w%s x%u, x%u, (x%u) ; *%p = %"PRId64, sufx, (uint)rd, (uint)rs1, (uint)rs2, (void *)a, b);
+			vdebug ("sc.w%s x%u, x%u, (x%u) ; *%p = %"PRId64, sufx, (uint)rd, (uint)rs1, (uint)rs2, (void *)a, b);
 			write_u32 (a, b);
 			cpu_set (rd, 0);
 			break;
 		case 0b00010'011: // lr.d
 			if (rs2 != 0)
 				goto ud;
-			log ("lr.d%s x%u, (x%u) ; *%p", sufx, (uint)rs1, (uint)rs2, (void *)a);
+			vdebug ("lr.d%s x%u, (x%u) ; *%p", sufx, (uint)rs1, (uint)rs2, (void *)a);
 			b = read_i64 (a);
 			cpu_set (rd, b);
 			break;
 		case 0b00011'011: // sc.w
-			log ("sc.d%s x%u, x%u, (x%u) ; *%p = %"PRId64, sufx, (uint)rd, (uint)rs1, (uint)rs2, (void *)a, b);
+			vdebug ("sc.d%s x%u, x%u, (x%u) ; *%p = %"PRId64, sufx, (uint)rd, (uint)rs1, (uint)rs2, (void *)a, b);
 			write_u64 (a, b);
 			cpu_set (rd, 0);
 			break;
@@ -107,22 +105,22 @@ void cpu_exec (u32 instr)
 		}
 		break;
 	case 0b1101111: // jal rd, jimm
-		log ("jal x%u, %"PRId64, (uint)rd, imm_j);
-		cpu_set (rd, pc);
-		pc += imm_j - 4;
+		vdebug ("jal x%u, %"PRId64, (uint)rd, imm_j);
+		cpu_set (rd, pc + 4);
+		next_pc = pc + imm_j;
 		break;
 	case 0b1100111: // jalr rd, rs1, iimm
 		switch (funct3) {
 		case 0b000:
-			log ("jalr x%u, x%u, %"PRId64, (uint)rd, (uint)rs1, imm_i);
-			cpu_set (rd, pc);
-			pc = cpu_get (rs1);
+			vdebug ("jalr x%u, x%u, %"PRId64, (uint)rd, (uint)rs1, imm_i);
+			cpu_set (rd, pc + 4);
+			next_pc = cpu_get (rs1);
 			break;
 		default:
 			goto ud;
 		}
 		break;
-#define br(name) log (name " x%u, x%u, %d ; %s", (uint)rs1, (uint)rs2, (int)imm_b, c ? "true" : "false")
+#define br(name) vdebug (name " x%u, x%u, %d ; %s", (uint)rs1, (uint)rs2, (int)imm_b, c ? "true" : "false")
 	case 0b1100011: // bcc rs1, rs2, bimm
 		a = cpu_get (rs1);
 		b = cpu_get (rs2);
@@ -155,10 +153,10 @@ void cpu_exec (u32 instr)
 			goto ud;
 		}
 		if (c)
-			pc += imm_b - 4;
+			next_pc = pc + imm_b;
 		break;
 #undef br
-#define lx(name) log (name " x%u, %d(x%u) ; *%p", (uint)rs2, (int)imm_i, (uint)rs1, (void *)a)
+#define lx(name) vdebug (name " x%u, %d(x%u) ; *%p", (uint)rs2, (int)imm_i, (uint)rs1, (void *)a)
 	case 0b0000011: // lx rd, iimm(rs1)
 		a = cpu_get (rs1) + imm_i;
 		switch (funct3) {
@@ -196,7 +194,7 @@ void cpu_exec (u32 instr)
 		cpu_set (rd, b);
 		break;
 #undef lx
-#define sx(name) log (name " x%u, %d(x%u) ; *%p = %u", (uint)rs2, (int)imm_s, (uint)rs1, (void *)b, (uint)a)
+#define sx(name) vdebug (name " x%u, %d(x%u) ; *%p = %u", (uint)rs2, (int)imm_s, (uint)rs1, (void *)b, (uint)a)
 	case 0b0100011: // sx rs2, simm(rs1)
 		a = cpu_get (rs2);
 		b = cpu_get (rs1) + imm_s;
@@ -222,7 +220,7 @@ void cpu_exec (u32 instr)
 		}
 		break;
 #undef sx
-#define alui(name) log (name " x%u, x%u, %"PRId64" ; "name"(%"PRId64", %"PRId64") = %"PRId64, \
+#define alui(name) vdebug (name " x%u, x%u, %"PRId64" ; "name"(%"PRId64", %"PRId64") = %"PRId64, \
 	(uint)rd, (uint)rs1, b, a, b, c)
 	case 0b0010011: // alui rd, rs1, iimm
 		a = cpu_get (rs1);
@@ -314,7 +312,7 @@ void cpu_exec (u32 instr)
 		cpu_set (rd, c);
 		break;
 #undef alui
-#define alu(name) log (name " x%u, x%u, x%u ; "name"(%"PRId64", %"PRId64") = %"PRId64, (uint)rd, (uint)rs1, (uint)rs2, a, b, c)
+#define alu(name) vdebug (name " x%u, x%u, x%u ; "name"(%"PRId64", %"PRId64") = %"PRId64, (uint)rd, (uint)rs1, (uint)rs2, a, b, c)
 	case 0b0110011: // alu rd, rs1, rs2
 		a = cpu_get (rs1);
 		b = cpu_get (rs2);
@@ -445,11 +443,11 @@ void cpu_exec (u32 instr)
 		break;
 #undef alu
 	case 0b0001111: // fence/fence.tso/pause
-		eprintf ("%08"PRIx64": efence\n", pc - 4);
+		vdebug ("fence");
 		break;
 	case 0b1110011: // ecall/ebreak
 		if ((instr >> 20) & 1) {
-			eprintf ("%08"PRIx64": ebreak\n", pc - 4);
+			vdebug ("ebreak");
 			__builtin_trap ();
 		} else {
 			ecall ();
@@ -457,7 +455,8 @@ void cpu_exec (u32 instr)
 		break;
 	default:
 	ud:
-		errx (1, "%08"PRIx64": invalid instruction: %08x", pc - 4, instr);
+		error ("invalid instruction: %08x", instr);
 	}
+	pc = next_pc;
 }
 
blob - 01b46c983168538311f45df9dc221aa051b068db
blob + 9531dd891e95809b8f341424073df5a2e1596f40
--- src/ecall.c
+++ src/ecall.c
@@ -133,7 +133,7 @@ static void utsname_to_linux_utsname (struct linux_uts
 
 static int enosys (const char *sys)
 {
-	warnx ("unimplemented syscall: %s", sys);
+	warn ("unimplemented syscall: %s", sys);
 	return -map_errno (ENOSYS);
 }
 
@@ -142,14 +142,14 @@ static u64 my_brk (u64 new)
 	size_t ps;
 	void *ptr;
 
-	eprintf ("brk(%"PRIx64", %"PRIx64");", new, brkval);
+	debug ("brk(%"PRIx64", %"PRIx64");", new, brkval);
 
 	if (new < brkval)
 		return brkval;
 
 	ps = getpagesize ();
 	new = (new + ps - 1) & ~(ps - 1);
-	eprintf ("mmap (%p, %zu);", (void *)brkval, (size_t)(new - brkval));
+	debug ("mmap (%p, %zu);", (void *)brkval, (size_t)(new - brkval));
 	ptr = mmap (
 		(void *)brkval,
 		new - brkval,
@@ -223,7 +223,7 @@ static int open_flags (int x)
 	if (x & LO_CLOEXEC)
 		o |= O_CLOEXEC;
 
-	eprintf ("open_flags(%d) = %d\n", x, o);
+	debug ("open_flags(%d) = %d", x, o);
 	return o;
 }
 
@@ -273,8 +273,8 @@ void ecall (void)
 	if (a7 <= SYS_debug)
 		name = syscall_names[a7];
 
-	eprintf (
-			"ecall a7=%"PRIu64" [%s], a0=%"PRIu64", a1=%"PRIu64", a2=%"PRIu64", a3=%"PRIu64", a4=%"PRIu64", a5=%"PRIu64 "\n",
+	debug (
+			"ecall a7=%"PRIu64" [%s], a0=%"PRIu64", a1=%"PRIu64", a2=%"PRIu64", a3=%"PRIu64", a4=%"PRIu64", a5=%"PRIu64,
 			a7, name, a0, a1, a2, a3, a4, a5
 	);
 
@@ -374,7 +374,7 @@ void ecall (void)
 		if (tmp == -100)
 			tmp = AT_FDCWD;
 		tmp2 = open_flags ((int)a2);
-		eprintf ("openat(%d, %s, %d, %d);\n", tmp, str (a1), tmp2, (int)a3);
+		debug ("openat(%d, %s, %d, %d);", tmp, str (a1), tmp2, (int)a3);
 		ret = map (openat (tmp, str (a1), tmp2, (int)a3));
 		break;
 	case SYS_close:
@@ -501,7 +501,7 @@ void ecall (void)
 		ret = enosys ("waitid");
 		break;
 	case SYS_set_tid_address:
-		warnx ("set_tid_address(): not implemented");
+		warn ("set_tid_address(): not implemented");
 		ret = getpid ();
 		break;
 	case SYS_unshare:
@@ -862,9 +862,9 @@ void ecall (void)
 	case SYS_mmap:
 		tmp = mmap_flags ((int)a3);
 		tmp2 = mmap_prot ((int)a2);
-		eprintf ("mmap (%p, %zu, %d, %d, %d, %lld);\n", ptr (void, a0), (size_t)a1, tmp2, tmp, (int)a4, (off_t)a5);
+		debug ("mmap (%p, %zu, %d, %d, %d, %lld);", ptr (void, a0), (size_t)a1, tmp2, tmp, (int)a4, (off_t)a5);
 		ptr = mmap (ptr (void, a0), (size_t)a1, tmp2, tmp, (int)a4, (off_t)a5);
-		eprintf ("ptr = %p", ptr);
+		debug ("ptr = %p", ptr);
 		if (ptr == NULL) {
 			ret = -map_errno (errno);
 		} else {
@@ -1091,11 +1091,11 @@ void ecall (void)
 		ret = enosys ("getmainvars");
 		break;
 	case SYS_debug:
-		fprintf (stderr, "DEBUG: %"PRIu64"\n", a0);
+		warn ("%"PRIu64, a0);
 		ret = 0;
 		break;
 	default:
-		warnx ("%08"PRIx64": unimplemented syscall %"PRIu64, pc - 4, a7);
+		warn ("unimplemented syscall %"PRIu64, a7);
 		ret = -map_errno (ENOSYS);
 		break;
 	}
blob - 4d5956003429e36105db5398413c20e8fa4d9674
blob + 61c6296fb607bcc75bf8caf387157710c9e5b6f3
--- src/linurv.c
+++ src/linurv.c
@@ -1,7 +1,9 @@
 #include <sys/resource.h>
 #include <sys/mman.h>
+#include <inttypes.h>
 #include <unistd.h>
 #include <string.h>
+#include <stdarg.h>
 #include <stdlib.h>
 #include <assert.h>
 #include <libgen.h>
@@ -9,6 +11,15 @@
 #include <errno.h>
 #include "linurv.h"
 
+static const char *levelstr[] = {
+	[LOG_SILENT]	= "FATAL",
+	[LOG_ERROR]	= "ERROR",
+	[LOG_WARN]	= "WARN ",
+	[LOG_DEBUG]	= "DEBUG",
+	[LOG_VDEBUG]	= "DEBUG",
+};
+
+enum log_level curlevel;
 u64 brkval = 0;
 
 static void load_segment (int fd, Elf64_Phdr phdr)
@@ -33,7 +44,7 @@ static void load_segment (int fd, Elf64_Phdr phdr)
 		-1,
 		0
 	);
-	eprintf ("mmap (%p, %#zx) = %p;\n", addr, len, ptr);
+	debug ("mmap (%p, %#zx) = %p;", addr, len, ptr);
 
 	if (ptr == NULL)
 		err (1, "mmap()");
@@ -152,6 +163,26 @@ static void setup_stack (
 	cpu_push (argc);
 }
 
+void logger (enum log_level level, const char *file, int line, const char *fmt, ...)
+{
+	va_list ap;
+
+	if (curlevel < level)
+		return;
+	
+	fprintf (stderr, "%s %s:%d: %08"PRIx64": ", levelstr[level], file, line, pc);
+	va_start (ap, fmt);
+	vfprintf (stderr, fmt, ap);
+	va_end (ap);
+	fputc ('\n', stderr);
+}
+
+static int usage (void)
+{
+	fputs ("Usage: linurv [-v|-l level] file [args...]\n", stderr);
+	return 1;
+}
+
 int main (int argc, char *argv[], char *envp[])
 {
 	const char *filename;
@@ -159,16 +190,40 @@ int main (int argc, char *argv[], char *envp[])
 	size_t stack_size;
 	int envc;
 	char *base;
+	int option;
 
+	curlevel = LOG_WARN;
 	base = basename (argv[0]);
 
 	if (strcmp (base, "linurv") == 0) {
-		if (argc < 2)
-			errx (1, "usage: linurv file");
-		++argv;
-		--argc;
+		while ((option = getopt (argc, argv, "vl:")) != -1) {
+			switch (option) {
+			case 'l':
+				for (int i = 0; i <= LOG_VDEBUG; ++i) {
+					if (strcmp (optarg, levelstr[i]) == 0) {
+						curlevel = i;
+						break;
+					}
+				}
+				break;
+			case 'v':
+				if (curlevel < LOG_DEBUG) {
+					curlevel = LOG_DEBUG;
+				} else if (curlevel == LOG_DEBUG) {
+					curlevel = LOG_VDEBUG;
+				}
+				break;
+			default:
+				return usage ();
+			}
+		}
+		argv += optind;
+		argc -= optind;
 	}
 
+	if (argc < 1)
+		return usage ();
+
 	filename = argv[0];
 	load_image (filename);
 
blob - 733bc6a143bc3c452314d63bcd9212448a2861ba
blob + 9d4d706388fd3ee14b387733af2623db578b5fc2
--- src/linurv.h
+++ src/linurv.h
@@ -4,14 +4,14 @@
 #include <stdio.h>
 #include <err.h>
 
-#define DEBUG 0
+enum log_level {
+	LOG_SILENT,	// don't print anything
+	LOG_ERROR,	// only print errors
+	LOG_WARN,	// also print warnings
+	LOG_DEBUG,	// also print ecalls
+	LOG_VDEBUG,	// also print instructions
+};
 
-#if DEBUG
-# define eprintf(...) fprintf (stderr, __VA_ARGS__)
-#else
-# define eprintf(...)
-#endif
-
 enum {
 	REG_zero,
 	REG_ra,
@@ -64,6 +64,7 @@ typedef unsigned int uint;
 extern u64 pc;
 extern u64 brkval;
 extern const char *interpreter;
+extern enum log_level curlevel;
 
 u32 cpu_fetch (void);
 u64 cpu_get (size_t reg);
@@ -72,7 +73,15 @@ void cpu_exec (u32 instr);
 void ecall (void);
 int my_execve (const char *path, char **argv, char **envp);
 int is_executable (const Elf64_Ehdr *);
+void logger (enum log_level, const char *, int, const char *, ...);
 
+#define log(level, ...) logger ((level), __FILE__, __LINE__, __VA_ARGS__)
+#define fatal(...) log (LOG_SILENT, __VA_ARGS__)
+#define error(...) log (LOG_ERROR, __VA_ARGS__)
+#define warn(...) log (LOG_WARN, __VA_ARGS__)
+#define debug(...) log (LOG_DEBUG, __VA_ARGS__)
+#define vdebug(...) log (LOG_VDEBUG, __VA_ARGS__)
+
 #define read_u8(ptr)		(*(const u8 *)(size_t)(ptr))
 #define read_u16(ptr)		(*(const u16 *)(size_t)(ptr))
 #define read_u32(ptr)		(*(const u32 *)(size_t)(ptr))