commit d370bc33fa26d4807fdf46b184fa828d19d32c8d
parent 35e397917bdb4f431812d56eac3a9f8696a22f42
Author: lash <dev@holbrook.no>
Date: Tue, 18 Apr 2023 09:48:20 +0100
Implement context logging
Diffstat:
5 files changed, 82 insertions(+), 56 deletions(-)
diff --git a/engine/engine.go b/engine/engine.go
@@ -54,7 +54,7 @@ func NewEngine(cfg Config, st *state.State, rs resource.Resource, ca cache.Memor
// It loads and executes code for the start node.
func(en *Engine) Init(ctx context.Context) (bool, error) {
if en.initd {
- Logg.Debugf("already initialized")
+ Logg.DebugCtxf(ctx, "already initialized")
return true, nil
}
sym := en.root
@@ -67,13 +67,13 @@ func(en *Engine) Init(ctx context.Context) (bool, error) {
return false, err
}
b := vm.NewLine(nil, vm.MOVE, []string{sym}, nil, nil)
- Logg.Debugf("start new init VM run", "code", b)
+ Logg.DebugCtxf(ctx, "start new init VM run", "code", b)
b, err = en.vm.Run(b, ctx)
if err != nil {
return false, err
}
- Logg.Debugf("end new init VM run", "code", b)
+ Logg.DebugCtxf(ctx, "end new init VM run", "code", b)
en.st.SetCode(b)
err = en.st.SetInput(inSave)
if err != nil {
@@ -110,7 +110,7 @@ func (en *Engine) Exec(input []byte, ctx context.Context) (bool, error) {
return false, err
}
- Logg.Infof("new VM execution with input", "input", string(input))
+ Logg.InfoCtxf(ctx, "new VM execution with input", "input", string(input))
code, err := en.st.GetCode()
if err != nil {
return false, err
diff --git a/engine/loop.go b/engine/loop.go
@@ -30,7 +30,7 @@ func Loop(en *Engine, reader io.Reader, writer io.Writer, ctx context.Context) e
for running {
in, err := bufReader.ReadString('\n')
if err == io.EOF {
- Logg.Debugf("EOF found, that's all folks")
+ Logg.DebugCtxf(ctx, "EOF found, that's all folks")
return nil
}
if err != nil {
diff --git a/logging/logging.go b/logging/logging.go
@@ -29,6 +29,12 @@ var (
LogWriter = os.Stderr
)
+
+func AsString(level int) string {
+ return levelStr[level]
+}
+
+
type Logger interface {
Writef(w io.Writer, level int, msg string, args ...any)
WriteCtxf(ctx context.Context, w io.Writer, level int, msg string, args ...any)
@@ -44,5 +50,5 @@ type Logger interface {
WarnCtxf(ctx context.Context, msg string, args ...any)
Errorf(msg string, args ...any)
ErrorCtxf(ctx context.Context, msg string, args ...any)
- AsString(level int) string
}
+
diff --git a/logging/vanilla.go b/logging/vanilla.go
@@ -8,11 +8,13 @@ import (
"runtime"
)
+// Vanilla is a basic single-line structured output logger for terminal output.
type Vanilla struct {
domain string
levelFilter int
}
+// NewVanilla creates a new Vanilla logger.
func NewVanilla() Vanilla {
return Vanilla{
domain: "main",
@@ -20,124 +22,116 @@ func NewVanilla() Vanilla {
}
}
+// WithDomain sets the logging domain. It is prepended to the caller file/line information.
func(v Vanilla) WithDomain(domain string) Vanilla {
v.domain = domain
return v
}
+// WithLevel overrides the globally set loglevel for the logger instance.
func(v Vanilla) WithLevel(level int) Vanilla {
v.levelFilter = level
return v
}
+// Printf logs to the global writer.
func(v Vanilla) Printf(level int, msg string, args ...any) {
v.Writef(LogWriter, level, msg, args...)
}
+// compile log line from inputs and send to given writer.
func(v Vanilla) writef(w io.Writer, file string, line int, level int, msg string, args ...any) {
if level > v.levelFilter {
return
}
argsStr := argsToString(args)
if len(msg) > 0 {
- fmt.Fprintf(w, "[%s] %s:%s:%v %s\t%s\n", v.AsString(level), v.domain, file, line, msg, argsStr)
+ fmt.Fprintf(w, "[%s] %s:%s:%v %s\t%s\n", AsString(level), v.domain, file, line, msg, argsStr)
} else {
- fmt.Fprintf(w, "[%s] %s:%s:%v %s\n", v.AsString(level), v.domain, file, line, argsStr)
+ fmt.Fprintf(w, "[%s] %s:%s:%v %s\n", AsString(level), v.domain, file, line, argsStr)
}
}
+// Writef logs to the given writer.
func(v Vanilla) Writef(w io.Writer, level int, msg string, args ...any) {
file, line := getCaller(2)
v.writef(w, file, line, level, msg, args)
}
-func argsToString(args []any) string {
- var s string
- c := len(args)
- var i int
- for i = 0; i < c; i += 2 {
- if len(s) > 0 {
- s += ", "
- }
-
- if i + 1 < c {
- var argByte []byte
- var ok bool
- argByte, ok = args[i+1].([]byte)
- if ok {
- s += fmt.Sprintf("%s=%x", args[i], argByte)
- } else {
- s += fmt.Sprintf("%s=%v", args[i], args[i+1])
- }
- } else {
- s += fmt.Sprintf("%s=??", args[i])
- }
- }
- return s
-}
-
+// WriteCtxf logs with context to the given writer.
func(v Vanilla) WriteCtxf(ctx context.Context, w io.Writer, level int, msg string, args ...any) {
- v.Writef(w, level, msg, args...)
+ file, line := getCaller(2)
+ v.writef(w, file, line, level, msg, args...)
}
+// get caller information and pass on to writef
func(v Vanilla) printf(level int, msg string, args ...any) {
file, line := getCaller(3)
v.writef(LogWriter, file, line, level, msg, args...)
}
+// get caller information and pass on to writef
func(v Vanilla) printCtxf(ctx context.Context, level int, msg string, args ...any) {
file, line := getCaller(3)
v.writef(LogWriter, file, line, level, msg, args...)
}
+// PrintCtxf logs with context to the global writer.
func(v Vanilla) PrintCtxf(ctx context.Context, level int, msg string, args ...any) {
v.printf(level, msg, args...)
}
-func(v Vanilla) AsString(level int) string {
- return levelStr[level]
-}
-
+// Tracef logs a line with level TRACE to the global writer.
func(v Vanilla) Tracef(msg string, args ...any) {
v.printf(LVL_TRACE, msg, args...)
}
+// Tracef logs a line with level DEBUG to the global writer.
func(v Vanilla) Debugf(msg string, args ...any) {
v.printf(LVL_DEBUG, msg, args...)
}
+// Tracef logs a line with level INFO to the global writer.
func(v Vanilla) Infof(msg string, args ...any) {
v.printf(LVL_INFO, msg, args...)
}
+// Tracef logs a line with level WARN to the global writer.
func(v Vanilla) Warnf(msg string, args ...any) {
v.printf(LVL_WARN, msg, args...)
}
+// Tracef logs a line with level ERROR to the global writer.
func(v Vanilla) Errorf(msg string, args ...any) {
v.printf(LVL_ERROR, msg, args...)
}
+// Tracef logs a line with context with level TRACE to the global writer.
func(v Vanilla) TraceCtxf(ctx context.Context, msg string, args ...any) {
v.printCtxf(ctx, LVL_TRACE, msg, args...)
}
+// Tracef logs a line with context with level DEBUG to the global writer.
func(v Vanilla) DebugCtxf(ctx context.Context, msg string, args ...any) {
v.printCtxf(ctx, LVL_DEBUG, msg, args...)
}
+// Tracef logs a line with context with level INFO to the global writer.
func(v Vanilla) InfoCtxf(ctx context.Context, msg string, args ...any) {
v.printCtxf(ctx, LVL_INFO, msg, args...)
}
+// Tracef logs a line with context with level WARN to the global writer.
func(v Vanilla) WarnCtxf(ctx context.Context, msg string, args ...any) {
v.printCtxf(ctx, LVL_WARN, msg, args...)
}
+// Tracef logs a line with context with level ERROR to the global writer.
func(v Vanilla) ErrorCtxf(ctx context.Context, msg string, args ...any) {
v.printCtxf(ctx, LVL_ERROR, msg, args...)
}
+// return file basename and line for caller information.
func getCaller(depth int) (string, int) {
var file string
var line int
@@ -145,3 +139,29 @@ func getCaller(depth int) (string, int) {
baseFile := path.Base(file)
return baseFile, line
}
+
+// string representation of the given structured log args.
+func argsToString(args []any) string {
+ var s string
+ c := len(args)
+ var i int
+ for i = 0; i < c; i += 2 {
+ if len(s) > 0 {
+ s += ", "
+ }
+
+ if i + 1 < c {
+ var argByte []byte
+ var ok bool
+ argByte, ok = args[i+1].([]byte)
+ if ok {
+ s += fmt.Sprintf("%s=%x", args[i], argByte)
+ } else {
+ s += fmt.Sprintf("%s=%v", args[i], args[i+1])
+ }
+ } else {
+ s += fmt.Sprintf("%s=??", args[i])
+ }
+ }
+ return s
+}
diff --git a/vm/runner.go b/vm/runner.go
@@ -58,7 +58,7 @@ func(vm *Vm) Run(b []byte, ctx context.Context) ([]byte, error) {
}
if r {
//log.Printf("terminate set! bailing!")
- Logg.Infof("terminate set! bailing")
+ Logg.InfoCtxf(ctx, "terminate set! bailing")
return []byte{}, nil
}
//vm.st.ResetBaseFlags()
@@ -87,8 +87,8 @@ func(vm *Vm) Run(b []byte, ctx context.Context) ([]byte, error) {
return b, err
}
b = bb
- Logg.Debugf("execute code", "opcode", op, "op", OpcodeString[op], "code", b)
- Logg.Debugf("", "state", vm.st)
+ Logg.DebugCtxf(ctx, "execute code", "opcode", op, "op", OpcodeString[op], "code", b)
+ Logg.DebugCtxf(ctx, "", "state", vm.st)
switch op {
case CATCH:
b, err = vm.RunCatch(b, ctx)
@@ -150,7 +150,7 @@ func(vm *Vm) RunDeadCheck(b []byte, ctx context.Context) ([]byte, error) {
panic(err)
}
if r {
- Logg.Debugf("Not processing input. Setting terminate")
+ Logg.DebugCtxf(ctx, "Not processing input. Setting terminate")
_, err := vm.st.SetFlag(state.FLAG_TERMINATE)
if err != nil {
panic(err)
@@ -162,12 +162,12 @@ func(vm *Vm) RunDeadCheck(b []byte, ctx context.Context) ([]byte, error) {
panic(err)
}
if r {
- Logg.Tracef("Terminate found!!")
+ Logg.TraceCtxf(ctx, "Terminate found!!")
return b, nil
}
- Logg.Tracef("no code remaining but not terminating")
+ Logg.TraceCtxf(ctx, "no code remaining but not terminating")
location, _ := vm.st.Where()
if location == "" {
return b, fmt.Errorf("dead runner with no current location")
@@ -196,7 +196,7 @@ func(vm *Vm) RunCatch(b []byte, ctx context.Context) ([]byte, error) {
if perr != nil {
panic(perr)
}
- Logg.Tracef("terminate set")
+ Logg.TraceCtxf(ctx, "terminate set")
return b, err
}
if r {
@@ -207,7 +207,7 @@ func(vm *Vm) RunCatch(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- Logg.Infof("catch!", "flag", sig, "sym", sym, "target", actualSym)
+ Logg.InfoCtxf(ctx, "catch!", "flag", sig, "sym", sym, "target", actualSym)
sym = actualSym
bh, err := vm.rs.GetCode(sym)
if err != nil {
@@ -229,7 +229,7 @@ func(vm *Vm) RunCroak(b []byte, ctx context.Context) ([]byte, error) {
return b, err
}
if r {
- Logg.Infof("croak at flag %v, purging and moving to top", "signal", sig)
+ Logg.InfoCtxf(ctx, "croak at flag %v, purging and moving to top", "signal", sig)
vm.Reset()
vm.pg.Reset()
vm.ca.Reset()
@@ -291,7 +291,7 @@ func(vm *Vm) RunMove(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- Logg.Debugf("loaded code", "sym", sym, "code", code)
+ Logg.DebugCtxf(ctx, "loaded code", "sym", sym, "code", code)
b = append(b, code...)
vm.Reset()
return b, nil
@@ -315,7 +315,7 @@ func(vm *Vm) RunInCmp(b []byte, ctx context.Context) ([]byte, error) {
}
if have {
if reading {
- Logg.Debugf("ignoring input - already have match", "input", sym)
+ Logg.DebugCtxf(ctx, "ignoring input - already have match", "input", sym)
return b, nil
}
} else {
@@ -328,15 +328,15 @@ func(vm *Vm) RunInCmp(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- Logg.Tracef("testing sym", "sym", sym, "input", input)
+ Logg.TraceCtxf(ctx, "testing sym", "sym", sym, "input", input)
if !have && sym == "*" {
- Logg.Debugf("input wildcard match", "input", input, "target", target)
+ Logg.DebugCtxf(ctx, "input wildcard match", "input", input, "target", target)
} else {
if sym != string(input) {
return b, nil
}
- Logg.Infof("input match", "input", input, "target", target)
+ Logg.InfoCtxf(ctx, "input match", "input", input, "target", target)
}
_, err = vm.st.SetFlag(state.FLAG_INMATCH)
if err != nil {
@@ -368,7 +368,7 @@ func(vm *Vm) RunInCmp(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- Logg.Debugf("loaded additional code", "target", target, "code", code)
+ Logg.DebugCtxf(ctx, "loaded additional code", "target", target, "code", code)
b = append(b, code...)
return b, err
}
@@ -380,7 +380,7 @@ func(vm *Vm) RunHalt(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- Logg.Debugf("found HALT, stopping")
+ Logg.DebugCtxf(ctx, "found HALT, stopping")
_, err = vm.st.SetFlag(state.FLAG_WAIT)
if err != nil {
@@ -391,7 +391,7 @@ func(vm *Vm) RunHalt(b []byte, ctx context.Context) ([]byte, error) {
// RunMSize executes the MSIZE opcode
func(vm *Vm) RunMSize(b []byte, ctx context.Context) ([]byte, error) {
- Logg.Warnf("MSIZE not yet implemented")
+ Logg.WarnCtxf(ctx, "MSIZE not yet implemented")
_, _, b, err := ParseMSize(b)
return b, err
}
@@ -472,7 +472,7 @@ func(vm *Vm) refresh(key string, rs resource.Resource, ctx context.Context) (str
input, _ := vm.st.GetInput()
r, err := fn(key, input, ctx)
if err != nil {
- Logg.Tracef("loadfail", "err", err)
+ Logg.TraceCtxf(ctx, "loadfail", "err", err)
var perr error
_, perr = vm.st.SetFlag(state.FLAG_LOADFAIL)
if perr != nil {
