commit 85165aafc2dca81d4df459965dbece1f75f9c2cb from: Benjamin Stürz date: Sat Jun 15 22:18:45 2024 UTC improve logging 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 #include +#include #include #include +#include #include #include #include @@ -9,6 +11,15 @@ #include #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 #include -#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))