commit b616b16c4668f2135ef5ecd52e78e8a6927b5c1d
parent 5b0fef09239aecf1d68cac0204fdd924fbbb9f47
Author: lash <dev@holbrook.no>
Date: Tue, 18 Apr 2023 09:16:53 +0100
Add logging interface, vanilla implementation
Diffstat:
30 files changed, 371 insertions(+), 77 deletions(-)
diff --git a/asm/asm.go b/asm/asm.go
@@ -5,7 +5,6 @@ import (
"encoding/binary"
"fmt"
"io"
- "log"
"math"
"strconv"
"strings"
@@ -184,7 +183,7 @@ func parseOne(op vm.Opcode, instruction *Instruction, w io.Writer) (int, error)
// Catch
if a.Selector != nil {
- log.Printf("entering twosym for %v", op)
+ Logg.Tracef("entring twosym", "op", op)
n, err := parseTwoSym(b, a)
n_buf += n
if err != nil {
@@ -355,7 +354,7 @@ func(bt *Batcher) MenuAdd(w io.Writer, code string, arg Arg) (int, error) {
} else if arg.Sym != nil {
sym = *arg.Sym
}
- log.Printf("menu processor add %v '%v' '%v' '%v'", code, selector, *arg.Desc, sym)
+ Logg.Debugf("menu processor add", "code", code, "selector", selector, "desc", *arg.Desc, "sym", sym) //%v '%v' '%v' '%v'", code, selector, *arg.Desc, sym)
err := bt.menuProcessor.Add(code, selector, *arg.Desc, sym)
return 0, err
}
@@ -379,7 +378,7 @@ func Parse(s string, w io.Writer) (int, error) {
var rn int
for _, v := range ast.Instructions {
- log.Printf("parsing line %v: %v", v.OpCode, v.OpArg)
+ Logg.Debugf("parsing line", "opcode", v.OpCode, "args", v.OpArg)
op, ok := vm.OpcodeIndex[v.OpCode]
if !ok {
n, err := batch.MenuAdd(w, v.OpCode, v.OpArg)
@@ -398,7 +397,7 @@ func Parse(s string, w io.Writer) (int, error) {
if err != nil {
return rn, err
}
- log.Printf("wrote %v bytes for %v", n, v.OpArg)
+ Logg.Debugf("wrote bytecode", "bytes", n, "args", v.OpArg)
}
}
n, err := batch.Exit(w)
diff --git a/asm/log.go b/asm/log.go
@@ -0,0 +1,9 @@
+package asm
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("asm")
+)
diff --git a/cache/cache.go b/cache/cache.go
@@ -2,7 +2,6 @@ package cache
import (
"fmt"
- "log"
)
// Cache stores loaded content, enforcing size limits and keeping track of size usage.
@@ -46,7 +45,7 @@ func(ca *Cache) Add(key string, value string, sizeLimit uint16) error {
checkFrame := ca.frameOf(key)
if checkFrame > -1 {
if checkFrame == len(ca.Cache) - 1 {
- log.Printf("Ignoring load request on frame that has symbol already loaded")
+ Logg.Debugf("Ignoring load request on frame that has symbol already loaded")
return nil
}
return fmt.Errorf("key %v already defined in frame %v", key, checkFrame)
@@ -58,7 +57,8 @@ func(ca *Cache) Add(key string, value string, sizeLimit uint16) error {
return fmt.Errorf("Cache capacity exceeded %v of %v", ca.CacheUseSize + sz, ca.CacheSize)
}
}
- log.Printf("add key %s value size %v limit %v", key, sz, sizeLimit)
+ Logg.Infof("Cache add", "key", key, "size", sz, "limit", sizeLimit)
+ Logg.Tracef("", "Cache add data", value)
ca.Cache[len(ca.Cache)-1][key] = value
ca.CacheUseSize += sz
ca.Sizes[key] = sizeLimit
@@ -152,7 +152,7 @@ func (ca *Cache) Pop() error {
for k, v := range m {
sz := len(v)
ca.CacheUseSize -= uint32(sz)
- log.Printf("free frame %v key %v value size %v", l, k, sz)
+ Logg.Debugf("Cache free", "frame", l, "key", k, "size", sz)
}
ca.Cache = ca.Cache[:l]
//ca.resetCurrent()
diff --git a/cache/log.go b/cache/log.go
@@ -0,0 +1,9 @@
+package cache
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("cache")
+)
diff --git a/engine/engine.go b/engine/engine.go
@@ -4,7 +4,6 @@ import (
"context"
"fmt"
"io"
- "log"
"git.defalsify.org/vise/cache"
"git.defalsify.org/vise/render"
@@ -55,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 {
- log.Printf("already initialized")
+ Logg.Debugf("already initialized")
return true, nil
}
sym := en.root
@@ -68,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)
- log.Printf("start new init VM run with code %x", b)
+ Logg.Debugf("start new init VM run", "code", b)
b, err = en.vm.Run(b, ctx)
if err != nil {
return false, err
}
- log.Printf("ended init VM run with code %x", b)
+ Logg.Debugf("end new init VM run", "code", b)
en.st.SetCode(b)
err = en.st.SetInput(inSave)
if err != nil {
@@ -111,7 +110,7 @@ func (en *Engine) Exec(input []byte, ctx context.Context) (bool, error) {
return false, err
}
- log.Printf("new execution with input '%s' (0x%x)", input, input)
+ Logg.Infof("new VM execution with input", "input", string(input))
code, err := en.st.GetCode()
if err != nil {
return false, err
@@ -120,12 +119,12 @@ func (en *Engine) Exec(input []byte, ctx context.Context) (bool, error) {
return false, fmt.Errorf("no code to execute")
}
- log.Printf("start new VM run with code %x", code)
+ Logg.Debugf("start new VM run", "code", code)
code, err = en.vm.Run(code, ctx)
if err != nil {
return false, err
}
- log.Printf("ended VM run with code %x", code)
+ Logg.Debugf("end new VM run", "code", code)
v, err := en.st.MatchFlag(state.FLAG_TERMINATE, false)
if err != nil {
@@ -133,14 +132,14 @@ func (en *Engine) Exec(input []byte, ctx context.Context) (bool, error) {
}
if v {
if len(code) > 0 {
- log.Printf("terminated with code remaining: %x", code)
+ Logg.Debugf("terminated with code remaining", "code", code)
}
return false, err
}
en.st.SetCode(code)
if len(code) == 0 {
- log.Printf("runner finished with no remaining code")
+ Logg.Infof("runner finished with no remaining code")
_, err = en.reset(ctx)
return false, err
}
diff --git a/engine/log.go b/engine/log.go
@@ -0,0 +1,9 @@
+package engine
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("engine")
+)
diff --git a/engine/loop.go b/engine/loop.go
@@ -5,7 +5,6 @@ import (
"context"
"fmt"
"io"
- "log"
"strings"
)
@@ -31,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 {
- log.Printf("EOF found, that's all folks")
+ Logg.Debugf("EOF found, that's all folks")
return nil
}
if err != nil {
diff --git a/logging/debug.go b/logging/debug.go
@@ -0,0 +1,7 @@
+// +build logdebug
+
+package logging
+
+var (
+ LogLevel = LVL_DEBUG
+)
diff --git a/logging/default.go b/logging/default.go
@@ -0,0 +1,7 @@
+// +build logwarn
+
+package logging
+
+var (
+ LogLevel = LVL_WARN
+)
diff --git a/logging/error.go b/logging/error.go
@@ -0,0 +1,7 @@
+// +build logerror
+
+package logging
+
+var (
+ LogLevel = LVL_ERROR
+)
diff --git a/logging/info.go b/logging/info.go
@@ -0,0 +1,7 @@
+// +build loginfo
+
+package logging
+
+var (
+ LogLevel = LVL_DEBUG
+)
diff --git a/logging/logging.go b/logging/logging.go
@@ -0,0 +1,48 @@
+package logging
+
+import (
+ "context"
+ "io"
+ "os"
+)
+
+const (
+ LVL_NONE = iota
+ LVL_ERROR
+ LVL_WARN
+ LVL_INFO
+ LVL_DEBUG
+ LVL_TRACE
+)
+
+var (
+ levelStr = map[int]string{
+ LVL_ERROR: "E",
+ LVL_WARN: "W",
+ LVL_INFO: "I",
+ LVL_DEBUG: "D",
+ LVL_TRACE: "T",
+ }
+)
+
+var (
+ LogWriter = os.Stderr
+)
+
+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)
+ Printf(level int, msg string, args ...any)
+ PrintCtxf(ctx context.Context, level int, msg string, args ...any)
+ Tracef(msg string, args ...any)
+ TraceCtxf(ctx context.Context, msg string, args ...any)
+ Debugf(msg string, args ...any)
+ DebugCtxf(ctx context.Context, msg string, args ...any)
+ Infof(msg string, args ...any)
+ InfoCtxf(ctx context.Context, msg string, args ...any)
+ Warnf(msg string, args ...any)
+ 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/none.go b/logging/none.go
@@ -0,0 +1,7 @@
+// +build !logdebug,!loginfo,!logtrace,!logerror,!logwarn
+
+package logging
+
+var (
+ LogLevel = LVL_NONE
+)
diff --git a/logging/trace.go b/logging/trace.go
@@ -0,0 +1,7 @@
+// +build logtrace
+
+package logging
+
+var (
+ LogLevel = LVL_TRACE
+)
diff --git a/logging/vanilla.go b/logging/vanilla.go
@@ -0,0 +1,128 @@
+package logging
+
+import (
+ "context"
+ "fmt"
+ "io"
+ "path"
+ "runtime"
+)
+
+type Vanilla struct {
+ domain string
+ levelFilter int
+}
+
+func NewVanilla() Vanilla {
+ return Vanilla{
+ domain: "main",
+ levelFilter: LogLevel,
+ }
+}
+
+func(v Vanilla) WithDomain(domain string) Vanilla {
+ v.domain = domain
+ return v
+}
+
+func(v Vanilla) WithLevel(level int) Vanilla {
+ v.levelFilter = level
+ return v
+}
+
+func(v Vanilla) Printf(level int, msg string, args ...any) {
+ v.Writef(LogWriter, level, msg, args...)
+}
+
+func(v Vanilla) Writef(w io.Writer, level int, msg string, args ...any) {
+ if level > v.levelFilter {
+ return
+ }
+ var file string
+ var line int
+ _, file, line, _ = runtime.Caller(0) // BUG: needs to be passed from top to aliased private functions
+ basefile := path.Base(file)
+ argsStr := argsToString(args)
+ if len(msg) > 0 {
+ fmt.Fprintf(w, "[%s] %s:%s:%v %s\t%s\n", v.AsString(level), v.domain, basefile, line, msg, argsStr)
+ } else {
+ fmt.Fprintf(w, "[%s] %s:%s:%v %s\n", v.AsString(level), v.domain, basefile, line, argsStr)
+ }
+}
+
+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
+}
+
+func(v Vanilla) WriteCtxf(ctx context.Context, w io.Writer, level int, msg string, args ...any) {
+ v.Writef(w, level, msg, args...)
+}
+
+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]
+}
+
+func(v Vanilla) Tracef(msg string, args ...any) {
+ v.Printf(LVL_TRACE, msg, args...)
+}
+
+func(v Vanilla) Debugf(msg string, args ...any) {
+ v.Printf(LVL_DEBUG, msg, args...)
+}
+
+func(v Vanilla) Infof(msg string, args ...any) {
+ v.Printf(LVL_INFO, msg, args...)
+}
+
+func(v Vanilla) Warnf(msg string, args ...any) {
+ v.Printf(LVL_WARN, msg, args...)
+}
+
+func(v Vanilla) Errorf(msg string, args ...any) {
+ v.Printf(LVL_ERROR, msg, args...)
+}
+
+func(v Vanilla) TraceCtxf(ctx context.Context, msg string, args ...any) {
+ v.PrintCtxf(ctx, LVL_TRACE, msg, args...)
+}
+
+func(v Vanilla) DebugCtxf(ctx context.Context, msg string, args ...any) {
+ v.PrintCtxf(ctx, LVL_DEBUG, msg, args...)
+}
+
+func(v Vanilla) InfoCtxf(ctx context.Context, msg string, args ...any) {
+ v.PrintCtxf(ctx, LVL_INFO, msg, args...)
+}
+
+func(v Vanilla) WarnCtxf(ctx context.Context, msg string, args ...any) {
+ v.PrintCtxf(ctx, LVL_WARN, msg, args...)
+}
+
+func(v Vanilla) ErrorCtxf(ctx context.Context, msg string, args ...any) {
+ v.PrintCtxf(ctx, LVL_ERROR, msg, args...)
+}
diff --git a/logging/vanilla_test.go b/logging/vanilla_test.go
@@ -0,0 +1,20 @@
+package logging
+
+import (
+ "bytes"
+ "testing"
+)
+
+func TestVanilla(t *testing.T) {
+ logg := NewVanilla().WithDomain("test").WithLevel(LVL_WARN)
+ w := bytes.NewBuffer(nil)
+ logg.Writef(w, LVL_DEBUG, "message", "xyzzy", 666, "inky", "pinky")
+ if len(w.Bytes()) > 0 {
+ t.Errorf("expected nothing, got %s", w.Bytes())
+ }
+ logg = logg.WithLevel(LVL_DEBUG)
+ logg.Writef(w, LVL_DEBUG, "message", "xyzzy", 666, "inky", "pinky")
+ if len(w.Bytes()) == 0 {
+ t.Errorf("expected output")
+ }
+}
diff --git a/persist/fs.go b/persist/fs.go
@@ -2,7 +2,6 @@ package persist
import (
"io/ioutil"
- "log"
"path"
"path/filepath"
"github.com/fxamacker/cbor/v2"
@@ -68,7 +67,7 @@ func(p *FsPersister) Save(key string) error {
return err
}
fp := path.Join(p.dir, key)
- log.Printf("saved key %v state %x", key, p.State.Code)
+ Logg.Debugf("saved state and cache", "key", key, "bytecode", p.State.Code)
return ioutil.WriteFile(fp, b, 0600)
}
@@ -80,6 +79,6 @@ func(p *FsPersister) Load(key string) error {
return err
}
err = p.Deserialize(b)
- log.Printf("loaded key %v state %x", key, p.State.Code)
+ Logg.Debugf("loaded state and cache", "key", key, "bytecode", p.State.Code)
return err
}
diff --git a/persist/fs_test.go b/persist/fs_test.go
@@ -3,7 +3,6 @@ package persist
import (
"bytes"
"io/ioutil"
- "log"
"reflect"
"testing"
@@ -33,7 +32,6 @@ func TestSerializeState(t *testing.T) {
if err != nil {
t.Error(err)
}
- log.Printf("v %b", v)
prnew := NewFsPersister(".")
err = prnew.Deserialize(v)
diff --git a/persist/log.go b/persist/log.go
@@ -0,0 +1,9 @@
+package persist
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("persist")
+)
diff --git a/render/log.go b/render/log.go
@@ -0,0 +1,9 @@
+package render
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("render")
+)
diff --git a/render/page.go b/render/page.go
@@ -3,7 +3,6 @@ package render
import (
"bytes"
"fmt"
- "log"
"strings"
"text/template"
@@ -59,7 +58,6 @@ func(pg *Page) Usage() (uint32, uint32, error) {
return 0, 0, err
}
c += sz
- log.Printf("v %x %v %v %v %v", []byte(v), len(v), l, sz, c)
}
r := uint32(l)
rsv := uint32(c)-r
@@ -96,7 +94,7 @@ func(pg *Page) Map(key string) error {
return err
}
}
- log.Printf("mapped %s", key)
+ Logg.Tracef("mapped", "key", key)
return nil
}
@@ -144,7 +142,7 @@ func(pg *Page) RenderTemplate(sym string, values map[string]string, idx uint16)
} else if idx > 0 {
return "", fmt.Errorf("sizer needed for indexed render")
}
- log.Printf("render for index: %v", idx)
+ Logg.Debugf("render for", "index", idx)
tp, err := template.New("tester").Option("missingkey=error").Parse(tpl)
if err != nil {
@@ -200,13 +198,13 @@ func(pg *Page) prepare(sym string, values map[string]string, idx uint16) (map[st
sink = k
sinkValues = strings.Split(v, "\n")
v = ""
- log.Printf("found sink %s with field count %v", k, len(sinkValues))
+ Logg.Infof("found sink", "sym", k, "fields", len(sinkValues))
}
noSinkValues[k] = v
}
if sink == "" {
- log.Printf("no sink found for sym %s", sym)
+ Logg.Tracef("no sink found", "sym", sym)
return values, nil
}
@@ -244,7 +242,7 @@ func(pg *Page) prepare(sym string, values map[string]string, idx uint16) (map[st
menuSizes[3] = menuSizes[1] + menuSizes[2]
}
- log.Printf("%v bytes available for sink split before navigation", remaining)
+ Logg.Debugf("calculated pre-navigation allocation", "bytes", remaining)
l := 0
var count uint16
@@ -258,7 +256,7 @@ func(pg *Page) prepare(sym string, values map[string]string, idx uint16) (map[st
for i, v := range sinkValues {
l += len(v)
- log.Printf("processing sinkvalue %v: %s", i, v)
+ Logg.Tracef("processing sink", "idx", i, "value", v)
if uint32(l) > netRemaining - 1 {
if tb.Len() == 0 {
return nil, fmt.Errorf("capacity insufficient for sink field %v", i)
@@ -296,7 +294,7 @@ func(pg *Page) prepare(sym string, values map[string]string, idx uint16) (map[st
}
for i, v := range strings.Split(r, "\n") {
- log.Printf("nosinkvalue %v: %s", i, v)
+ Logg.Tracef("nosinkvalue", "idx", i, "value", v)
}
return noSinkValues, nil
@@ -310,7 +308,7 @@ func(pg *Page) render(sym string, values map[string]string, idx uint16) (string,
if err != nil {
return "", err
}
- log.Printf("rendered %v bytes for template", len(s))
+ Logg.Debugf("rendered template", "bytes", len(s))
r += s
if pg.menu != nil {
@@ -318,7 +316,7 @@ func(pg *Page) render(sym string, values map[string]string, idx uint16) (string,
if err != nil {
return "", err
}
- log.Printf("rendered %v bytes for menu", len(s))
+ Logg.Debugf("rendered menu", "bytes", len(s))
if len(s) > 0 {
r += "\n" + s
}
@@ -332,4 +330,3 @@ func(pg *Page) render(sym string, values map[string]string, idx uint16) (string,
}
return r, nil
}
-
diff --git a/render/size.go b/render/size.go
@@ -3,7 +3,6 @@ package render
import (
"bytes"
"fmt"
- "log"
"strings"
)
@@ -46,8 +45,8 @@ func(szr *Sizer) Check(s string) (uint32, bool) {
l := uint32(len(s))
if szr.outputSize > 0 {
if l > szr.outputSize {
- log.Printf("sizer check fails with length %v: %s", l, szr)
- log.Printf("sizer contents:\n%s", s)
+ Logg.Infof("sized check fails", "length", l, "sizer", szr)
+ Logg.Tracef("", "sizer contents", s)
return 0, false
}
l = szr.outputSize - l
@@ -82,7 +81,7 @@ func(szr *Sizer) MenuSize() uint16 {
// AddCursor adds a pagination cursor for the paged sink content.
func(szr *Sizer) AddCursor(c uint32) {
- log.Printf("added cursor: %v", c)
+ Logg.Debugf("Added cursor", "offset", c)
szr.crsrs = append(szr.crsrs, c)
}
diff --git a/resource/fs.go b/resource/fs.go
@@ -4,7 +4,6 @@ import (
"context"
"fmt"
"io/ioutil"
- "log"
"path"
"path/filepath"
"strings"
@@ -69,7 +68,7 @@ func(fs FsResource) getFunc(sym string, input []byte, ctx context.Context) (Resu
func(fs FsResource) getFuncNoCtx(sym string, input []byte) (Result, error) {
fb := sym + ".txt"
fp := path.Join(fs.Path, fb)
- log.Printf("getfunc search dir %s %s for %s", fs.Path, fp, sym)
+ Logg.Debugf("getfunc search dir", "dir", fs.Path, "path", fp, "sym", sym)
r, err := ioutil.ReadFile(fp)
if err != nil {
return Result{}, fmt.Errorf("failed getting data for sym '%s': %v", sym, err)
diff --git a/resource/log.go b/resource/log.go
@@ -0,0 +1,9 @@
+package resource
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("resource")
+)
diff --git a/state/flag.go b/state/flag.go
@@ -27,4 +27,3 @@ func getFlag(bitIndex uint32, bitField []byte) bool {
b := bitField[byteIndex]
return (b & (1 << localBitIndex)) > 0
}
-
diff --git a/state/log.go b/state/log.go
@@ -0,0 +1,9 @@
+package state
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("state")
+)
diff --git a/state/state.go b/state/state.go
@@ -2,7 +2,6 @@ package state
import (
"fmt"
- "log"
"strings"
)
@@ -209,7 +208,7 @@ func(st *State) Next() (uint16, error) {
}
st.SizeIdx += 1
s, idx := st.Where()
- log.Printf("next page for %s: %v", s, idx)
+ Logg.Debugf("next page", "location", s, "index", idx)
st.Moves += 1
return st.SizeIdx, nil
}
@@ -230,7 +229,7 @@ func(st *State) Previous() (uint16, error) {
}
st.SizeIdx -= 1
s, idx := st.Where()
- log.Printf("previous page for %s: %v", s, idx)
+ Logg.Debugf("previous page", "location", s, "index", idx)
st.Moves += 1
return st.SizeIdx, nil
}
@@ -243,7 +242,7 @@ func(st *State) Sides() (bool, bool) {
return false, false
}
next := true
- log.Printf("sides %v", st.SizeIdx)
+ Logg.Tracef("sides", "index", st.SizeIdx)
if st.SizeIdx == 0 {
return next, false
}
@@ -282,14 +281,14 @@ func(st *State) Up() (string, error) {
if l == 0 {
return "", fmt.Errorf("exit called beyond top frame")
}
- log.Printf("execpath before %v", st.ExecPath)
+ Logg.Tracef("execpath before", "path", st.ExecPath)
st.ExecPath = st.ExecPath[:l-1]
sym := ""
if len(st.ExecPath) > 0 {
sym = st.ExecPath[len(st.ExecPath)-1]
}
st.SizeIdx = 0
- log.Printf("execpath after %v", st.ExecPath)
+ Logg.Tracef("execpath after", "path", st.ExecPath)
st.Moves += 1
return sym, nil
}
@@ -302,13 +301,13 @@ func(st *State) Depth() uint8 {
// Appendcode adds the given bytecode to the end of the existing code.
func(st *State) AppendCode(b []byte) error {
st.Code = append(st.Code, b...)
- log.Printf("code changed to 0x%x", b)
+ Logg.Debugf("code changed (append)", "code", b)
return nil
}
// SetCode replaces the current bytecode with the given bytecode.
func(st *State) SetCode(b []byte) {
- log.Printf("code set to 0x%x", b)
+ Logg.Debugf("code changed (set)", "code", b)
st.Code = b
}
diff --git a/vm/debug.go b/vm/debug.go
@@ -4,7 +4,6 @@ import (
"bytes"
"fmt"
"io"
- "log"
)
// ToString verifies all instructions in bytecode and returns an assmebly code instruction for it.
@@ -14,7 +13,7 @@ func ToString(b []byte) (string, error) {
if err != nil {
return "", err
}
- log.Printf("Total %v bytes written to string buffer", n)
+ Logg.Tracef("", "bytes_written", n)
return buf.String(), nil
}
@@ -155,7 +154,7 @@ func ParseAll(b []byte, w io.Writer) (int, error) {
return rn, err
}
rn += n
- log.Printf("wrote %v bytes for instruction %v", n, s)
+ Logg.Tracef("instruction debug write", "bytes", n, "instruction", s)
}
//rs += "\n"
diff --git a/vm/log.go b/vm/log.go
@@ -0,0 +1,9 @@
+package vm
+
+import (
+ "git.defalsify.org/vise/logging"
+)
+
+var (
+ Logg logging.Logger = logging.NewVanilla().WithDomain("vm")
+)
diff --git a/vm/runner.go b/vm/runner.go
@@ -3,7 +3,6 @@ package vm
import (
"context"
"fmt"
- "log"
"git.defalsify.org/vise/cache"
"git.defalsify.org/vise/render"
@@ -31,7 +30,7 @@ func NewVm(st *state.State, rs resource.Resource, ca cache.Memory, sizer *render
sizer: sizer,
}
vmi.Reset()
- log.Printf("vm created with state: %v", st)
+ Logg.Infof("vm created with state", "state", st)
return vmi
}
@@ -58,7 +57,8 @@ func(vm *Vm) Run(b []byte, ctx context.Context) ([]byte, error) {
panic(err)
}
if r {
- log.Printf("terminate set! bailing!")
+ //log.Printf("terminate set! bailing!")
+ Logg.Infof("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
- log.Printf("execute code %x (%s) %x", op, OpcodeString[op], b)
- log.Printf("state: %v", vm.st)
+ Logg.Debugf("execute code", "opcode", op, "op", OpcodeString[op], "code", b)
+ Logg.Debugf("", "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 {
- log.Printf("Not processing input. Setting terminate")
+ Logg.Debugf("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 {
- log.Printf("Terminate found!!")
+ Logg.Tracef("Terminate found!!")
return b, nil
}
- log.Printf("no code remaining but not terminating")
+ Logg.Tracef("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)
}
- log.Printf("terminate set")
+ Logg.Tracef("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
}
- log.Printf("catch at flag %v, moving to '%v' ('%v')", sig, sym, actualSym)
+ Logg.Infof("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 {
- log.Printf("croak at flag %v, purging and moving to top", sig)
+ Logg.Infof("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
}
- log.Printf("loaded code for %s: %x", sym, code)
+ Logg.Debugf("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 {
- log.Printf("ignoring input %s, already have match", sym)
+ Logg.Debugf("ignoring input - already have match", "input", sym)
return b, nil
}
} else {
@@ -328,16 +328,15 @@ func(vm *Vm) RunInCmp(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- log.Printf("testing sym %s input %s", sym, input)
+ Logg.Tracef("testing sym", "sym", sym, "input", input)
if !have && sym == "*" {
- log.Printf("input wildcard match ('%s'), target '%s'", input, target)
+ Logg.Debugf("input wildcard match", "input", input, "target", target)
} else {
if sym != string(input) {
- log.Printf("foo")
return b, nil
}
- log.Printf("input match for '%s', target '%s'", input, target)
+ Logg.Infof("input match", "input", input, "target", target)
}
_, err = vm.st.SetFlag(state.FLAG_INMATCH)
if err != nil {
@@ -369,8 +368,7 @@ func(vm *Vm) RunInCmp(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- log.Printf("bar")
- log.Printf("loaded additional code for target '%s': %x", target, code)
+ Logg.Debugf("loaded additional code", "target", target, "code", code)
b = append(b, code...)
return b, err
}
@@ -382,7 +380,7 @@ func(vm *Vm) RunHalt(b []byte, ctx context.Context) ([]byte, error) {
if err != nil {
return b, err
}
- log.Printf("found HALT, stopping")
+ Logg.Debugf("found HALT, stopping")
_, err = vm.st.SetFlag(state.FLAG_WAIT)
if err != nil {
@@ -393,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) {
- log.Printf("WARNING MSIZE not yet implemented")
+ Logg.Warnf("MSIZE not yet implemented")
_, _, b, err := ParseMSize(b)
return b, err
}
@@ -474,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 {
- log.Printf("loadfail %v", err)
+ Logg.Tracef("loadfail", "err", err)
var perr error
_, perr = vm.st.SetFlag(state.FLAG_LOADFAIL)
if perr != nil {
