// Copyright (c) 2026 Charles KWON OhJun (charleskwonohjun@gmail.com) // All rights reserved. // Rich diagnostic error-log writer — Harbour FiveWin ErrSysW.prg style. // // Produces a structured `error.log` when an unhandled error fires. // Sections: // 1. Application: exe path, size, Go/OS version, start time, error time // 2. Error: description, operation, subsystem, gencode, args // 3. Stack: full call stack (function, source, line) // 4. Workareas: every open area's alias, RecNo, RecCount, BOF, EOF, // DELETED, active index tag, field list // 5. Classes: every registered class name // 6. Runtime: goroutines, MemStats, CPU count // // Wire-in from PRG: // ErrorBlock({|e| HB_ErrorLog(e), Break(e)}) // // Control: // HB_SetErrorLogPath(cPath) — default "./error.log" // HB_SetErrorLogHook(bBlock) — receive (oError, cLogPath) after write // // Reference: harbour-core/contrib/FiveWin/source/ErrSysW.prg package hbrtl import ( "fmt" "os" "os/user" "runtime" "runtime/debug" "sort" "strings" "sync" "time" "five/hbrdd" "five/hbrt" ) var ( errLogMu sync.Mutex errLogPath = "error.log" errLogHook hbrt.Value // optional block: receives (oErr, cPath) errLogStartAt = time.Now() ) // Sensitive-key detection. Substring match on upper-cased key/arg name — // false positives are acceptable, false negatives (leaked secret) are not. // PWD is deliberately excluded — it collides with the Unix env var for // "present working directory", which we want to keep visible. var redactPatterns = []string{ "PASSWORD", "PASSWD", "SECRET", "TOKEN", "CREDENTIAL", "AUTH", "APIKEY", "API_KEY", "ACCESS_KEY", "PRIVATE_KEY", "SESSION", "COOKIE", "BEARER", } // Env vars safe to include — anything outside this list is dropped even // if it doesn't match a redact pattern. Rationale: a senior engineer // needs locale/path info; nothing else is worth the leakage risk. var envAllowlist = []string{ "PATH", "LANG", "LC_ALL", "LC_CTYPE", "LC_TIME", "LC_NUMERIC", "TZ", "HOME", "USER", "LOGNAME", "SHELL", "TERM", "PWD", "GOMAXPROCS", "GOGC", "GOTRACEBACK", "GOOS", "GOARCH", "FIVE_KEEP_BUILD", "HB_LANG", } func isSensitiveKey(k string) bool { u := strings.ToUpper(k) for _, p := range redactPatterns { if strings.Contains(u, p) { return true } } return false } // redactArg masks the value portion of --flag=value / -flag=value when // the flag name looks sensitive. Plain positional args that happen to // look like secrets are left alone — we can't know without context. func redactArg(a string) string { for _, sep := range []string{"=", ":"} { if idx := strings.Index(a, sep); idx > 0 { key := strings.TrimLeft(a[:idx], "-") if isSensitiveKey(key) { return a[:idx+1] + "***REDACTED***" } } } return a } // Previous-errors ring buffer — cascading failures usually have a // precursor. Five entries is enough for most debugging sessions without // bloating the log. type ringEntry struct { ts time.Time desc string op string where string } var ( errRingMu sync.Mutex errRing []ringEntry ) const errRingSize = 5 func recordError(desc, op, where string) { errRingMu.Lock() defer errRingMu.Unlock() if len(errRing) >= errRingSize { errRing = errRing[1:] } errRing = append(errRing, ringEntry{time.Now(), desc, op, where}) } func snapshotErrRing() []ringEntry { errRingMu.Lock() defer errRingMu.Unlock() out := make([]ringEntry, len(errRing)) copy(out, errRing) return out } // init installs Five's default error handler and the debugger's // diagnostic renderer. Any *HbError that escapes Main — array OOB, // type mismatch, divide-by-zero, etc. — triggers an error.log dump // without the PRG having to wire ErrorBlock. Matches Harbour/FiveWin's // ErrorSys/ErrSysW default behavior. The diagnostic hook reuses the // same section writers so the debugger's `diag` command shows // error.log content at the break point. func init() { hbrt.DebugDiagnosticHook = func(t *hbrt.Thread, section string, emit func(string)) { var b strings.Builder switch section { case "wa": writeWorkareas(&b, t) case "set": writeSetState(&b) case "mem": writeRuntime(&b, time.Now()) default: emit("-- Workareas --") writeWorkareas(&b, t) emit(b.String()) b.Reset() emit("-- SET state --") writeSetState(&b) emit(b.String()) b.Reset() emit("-- Runtime --") writeRuntime(&b, time.Now()) emit(b.String()) return } emit(b.String()) } hbrt.DefaultErrorHook = func(t *hbrt.Thread, r interface{}) { var oErr hbrt.Value var stack []hbrt.DebugStackFrame var desc, op string switch v := r.(type) { case *hbrt.HbError: oErr = hbErrorToHash(v) stack = v.Stack desc, op = v.Description, v.Operation case BreakValue: oErr = v.Value desc = describe(v.Value) default: oErr = hbrt.MakeString(fmt.Sprintf("%v", r)) desc = fmt.Sprintf("%v", r) } // Record the error in the ring buffer BEFORE writing the log so // the "Previous errors" section includes this one as the tail. where := "(unknown)" if len(stack) > 0 { where = fmt.Sprintf("%s (%s:%d)", stack[0].Function, stack[0].Module, stack[0].Line) } recordError(desc, op, where) body := buildErrorLog(t, oErr, stack) errLogMu.Lock() path := errLogPath errLogMu.Unlock() if werr := os.WriteFile(path, []byte(body), 0o644); werr != nil { fmt.Fprintf(os.Stderr, "hb_errorlog: failed to write %s: %v\n", path, werr) return } fmt.Fprintf(os.Stderr, "error logged to %s\n", path) } } // hbErrorToHash lifts the runtime's lightweight *HbError into the same // hash shape used by ErrorNew / FiveWin's oErr, so the log writer has a // uniform input. func hbErrorToHash(e *hbrt.HbError) hbrt.Value { h := &hbrt.HbHash{} add := func(k string, v hbrt.Value) { h.Keys = append(h.Keys, hbrt.MakeString(k)) h.Values = append(h.Values, v) } add("DESCRIPTION", hbrt.MakeString(e.Description)) add("OPERATION", hbrt.MakeString(e.Operation)) add("SUBSYSTEM", hbrt.MakeString(e.SubSystem)) add("GENCODE", hbrt.MakeInt(e.GenCode)) add("SUBCODE", hbrt.MakeInt(0)) add("SEVERITY", hbrt.MakeInt(2)) add("OSCODE", hbrt.MakeInt(0)) if len(e.Args) > 0 { add("ARGS", hbrt.MakeArrayFrom(e.Args)) } h.Order = make([]int, len(h.Keys)) for i := range h.Order { h.Order[i] = i } return hbrt.MakeHashFrom(h) } // HB_SetErrorLogPath(cPath) → cOldPath func HbSetErrorLogPath(t *hbrt.Thread) { nParams := t.ParamCount() t.Frame(nParams, 0) defer t.EndProc() errLogMu.Lock() old := errLogPath if nParams >= 1 && !t.Local(1).IsNil() { errLogPath = t.Local(1).AsString() } errLogMu.Unlock() t.RetString(old) } // HB_SetErrorLogHook(bBlock) → bOldBlock func HbSetErrorLogHook(t *hbrt.Thread) { nParams := t.ParamCount() t.Frame(nParams, 0) defer t.EndProc() errLogMu.Lock() old := errLogHook if nParams >= 1 && t.Local(1).IsBlock() { errLogHook = t.Local(1) } errLogMu.Unlock() if old.IsNil() || !old.IsBlock() { t.RetNil() } else { t.RetVal(old) } } // HB_ErrorLog(oError) → cLogPath // // Writes a full diagnostic dump for oError and returns the path. Callers // typically wire it through ErrorBlock: // // ErrorBlock({|e| HB_ErrorLog(e), Break(e)}) func HbErrorLog(t *hbrt.Thread) { nParams := t.ParamCount() t.Frame(nParams, 0) defer t.EndProc() var oErr hbrt.Value if nParams >= 1 { oErr = t.Local(1) } else { oErr = hbrt.MakeNil() } errLogMu.Lock() path := errLogPath hook := errLogHook errLogMu.Unlock() body := buildErrorLog(t, oErr, nil) if err := os.WriteFile(path, []byte(body), 0o644); err != nil { // Log-write failures should not crash the program — dump to stderr // so the operator sees something. fmt.Fprintf(os.Stderr, "hb_errorlog: failed to write %s: %v\n", path, err) } // User-supplied post-action — e.g. send to a remote endpoint, show a // dialog, etc. Block receives (oErr, cPath). if hook.IsBlock() { t.PushValue(hook) t.PushValue(oErr) t.PushString(path) t.PendingParams2(2) hook.AsBlock().Fn(t) _ = t.Pop2() // discard block return } t.RetString(path) } // buildErrorLog is pure-text composition so it can be unit-tested without // actually writing to disk. If preStack is non-nil it overrides the live // call stack — used by the DefaultErrorHook to show the PRG stack as it // was at the moment of panic (before BEGIN SEQUENCE / EndProc unwound it). func buildErrorLog(t *hbrt.Thread, oErr hbrt.Value, preStack []hbrt.DebugStackFrame) string { var b strings.Builder nowTs := time.Now() sect := func(title string) { b.WriteString("\n") b.WriteString(title) b.WriteString("\n") b.WriteString(strings.Repeat("=", len(title))) b.WriteString("\n") } // --- Application --- sect("Application") exe, _ := os.Executable() fmt.Fprintf(&b, " Path and name: %s\n", exe) if fi, err := os.Stat(exe); err == nil { fmt.Fprintf(&b, " Size: %s bytes\n", addCommas(fi.Size())) fmt.Fprintf(&b, " Built at: %s\n", fi.ModTime().Format("2006-01-02 15:04:05")) } fmt.Fprintf(&b, " Five runtime: Go %s, %s/%s\n", runtime.Version(), runtime.GOOS, runtime.GOARCH) if bi, ok := debug.ReadBuildInfo(); ok { fmt.Fprintf(&b, " Module: %s\n", bi.Main.Path) if bi.Main.Version != "" && bi.Main.Version != "(devel)" { fmt.Fprintf(&b, " Version: %s\n", bi.Main.Version) } if rev := buildSetting(bi, "vcs.revision"); rev != "" { mod := buildSetting(bi, "vcs.modified") dirty := "" if mod == "true" { dirty = " (dirty)" } fmt.Fprintf(&b, " VCS: %s%s\n", rev, dirty) } } host, _ := os.Hostname() fmt.Fprintf(&b, " Host: %s, PID: %d\n", host, os.Getpid()) elapsed := nowTs.Sub(errLogStartAt) fmt.Fprintf(&b, " Time from start: %s\n", elapsed.Round(time.Millisecond)) fmt.Fprintf(&b, " Error occurred at: %s\n", nowTs.Format("2006-01-02 15:04:05.000")) // --- Error description --- sect("Error") writeErrorSection(&b, oErr) // --- Stack trace --- sect("Stack Calls") frames := preStack if frames == nil { frames = t.DebugCallStack() } if len(frames) == 0 { b.WriteString(" (no stack info available)\n") } for i, f := range frames { fmt.Fprintf(&b, " [%3d] %s (%s:%d)\n", i, f.Function, f.Module, f.Line) } // --- Workareas --- sect("Workareas") writeWorkareas(&b, t) // --- SET state --- sect("SET state") writeSetState(&b) // --- Classes --- sect("Classes in use") names := hbrt.ListClassNames() sort.Strings(names) for i, n := range names { fmt.Fprintf(&b, " [%3d] %s\n", i+1, n) } if len(names) == 0 { b.WriteString(" (no classes registered)\n") } // --- Previous errors --- sect("Previous errors") writePrevErrors(&b) // --- Environment --- sect("Environment") writeEnvironment(&b) // --- Runtime --- sect("Runtime") writeRuntime(&b, nowTs) // --- Goroutine dump (only if the PRG actually spawned concurrency) --- // Baseline is 3: main + signal handler + shutdown watcher. We only // care when user code produced extra goroutines (hb_Thread*, channels, // etc.), which is where concurrency bugs actually live. if runtime.NumGoroutine() > 3 { sect("Goroutines") writeGoroutineDump(&b) } return b.String() } func buildSetting(bi *debug.BuildInfo, key string) string { for _, s := range bi.Settings { if s.Key == key { return s.Value } } return "" } // writeSetState dumps the SET values a senior engineer actually looks // at when reproducing an error: date handling, deleted filter, string // comparison mode, open-mode default. func writeSetState(b *strings.Builder) { fmt.Fprintf(b, " DATEFORMAT: %s\n", GetSetDateFormat()) fmt.Fprintf(b, " EPOCH: %d\n", GetSetEpoch()) fmt.Fprintf(b, " DELETED: %v (filter-out hidden records)\n", GetSetDeleted()) fmt.Fprintf(b, " EXACT: %v\n", GetSetExact()) fmt.Fprintf(b, " SOFTSEEK: %v\n", GetSetSoftSeek()) fmt.Fprintf(b, " DECIMALS: %d\n", GetSetDecimals()) } // writePrevErrors prints the ring buffer of recent errors. The current // error is recorded as the last entry, so the list doubles as a // "errors leading to this one" trace. func writePrevErrors(b *strings.Builder) { entries := snapshotErrRing() if len(entries) == 0 { b.WriteString(" (none)\n") return } for i, e := range entries { age := time.Since(e.ts).Round(time.Millisecond) fmt.Fprintf(b, " [%d] -%s %s (op: %s) at %s\n", i+1, age, e.desc, e.op, e.where) } } // writeEnvironment writes non-secret context a senior engineer needs to // tell dev-vs-prod apart. Sensitive env vars are filtered via an // allowlist; command-line args are redacted on flag name match. func writeEnvironment(b *strings.Builder) { if cwd, err := os.Getwd(); err == nil { fmt.Fprintf(b, " CWD: %s\n", cwd) } if u, err := user.Current(); err == nil { fmt.Fprintf(b, " User: %s (uid=%s, gid=%s)\n", u.Username, u.Uid, u.Gid) } fmt.Fprintf(b, " TZ: %s\n", time.Now().Format("MST -0700")) if len(os.Args) > 0 { fmt.Fprintf(b, " Args (%d):\n", len(os.Args)) for i, a := range os.Args { fmt.Fprintf(b, " [%d] %s\n", i, redactArg(a)) } } // Environment: allowlist only; anything else (including sensitive // unknowns) is dropped on the floor. shown := 0 for _, k := range envAllowlist { if v, ok := os.LookupEnv(k); ok { if shown == 0 { b.WriteString(" Env (allowlisted):\n") } if isSensitiveKey(k) { v = "***REDACTED***" } fmt.Fprintf(b, " %s=%s\n", k, v) shown++ } } } // writeRuntime dumps Go scheduler + GC state. GC pause totals often // reveal "the error happened because GC was running 30% of the time" // class problems. func writeRuntime(b *strings.Builder, nowTs time.Time) { var ms runtime.MemStats runtime.ReadMemStats(&ms) fmt.Fprintf(b, " NumCPU: %d, GOMAXPROCS: %d, NumGoroutine: %d\n", runtime.NumCPU(), runtime.GOMAXPROCS(0), runtime.NumGoroutine()) fmt.Fprintf(b, " Alloc: %s, TotalAlloc: %s, Sys: %s\n", addCommas(int64(ms.Alloc)), addCommas(int64(ms.TotalAlloc)), addCommas(int64(ms.Sys))) fmt.Fprintf(b, " HeapObjects: %d, HeapInuse: %s\n", ms.HeapObjects, addCommas(int64(ms.HeapInuse))) fmt.Fprintf(b, " NumGC: %d, PauseTotal: %s, GCCPUFraction: %.4f%%\n", ms.NumGC, time.Duration(ms.PauseTotalNs).Round(time.Microsecond), ms.GCCPUFraction*100) if ms.NumGC > 0 { lastGC := time.Unix(0, int64(ms.LastGC)) fmt.Fprintf(b, " Last GC: %s ago\n", nowTs.Sub(lastGC).Round(time.Millisecond)) } if n := openFDCount(); n >= 0 { fmt.Fprintf(b, " Open FDs: %d\n", n) } } // writeGoroutineDump captures runtime.Stack — only invoked when > 1 // goroutine is alive, since for single-threaded PRG programs this just // duplicates the Stack Calls section. func writeGoroutineDump(b *strings.Builder) { buf := make([]byte, 64*1024) n := runtime.Stack(buf, true) if n == len(buf) { // Grew past buffer — try one larger. Capping at 256K to avoid // writing megabytes of logs on a runaway goroutine count. buf = make([]byte, 256*1024) n = runtime.Stack(buf, true) } b.Write(buf[:n]) b.WriteString("\n") } func writeErrorSection(b *strings.Builder, oErr hbrt.Value) { if oErr.IsNil() { b.WriteString(" (no error object supplied)\n") return } if oErr.IsHash() { writeHashErr(b, oErr) return } // Unexpected shape — dump raw fmt.Fprintf(b, " (unexpected error shape: type %s)\n value: %s\n", typeName(oErr), describe(oErr)) } // severityLabel maps the numeric ES_* constant to its Harbour name. // Anything outside the known set falls back to the raw number. func severityLabel(s int) string { switch s { case 0: return "INFO" case 1: return "WARNING" case 2: return "ERROR" case 3: return "CATASTROPHIC" } return "UNKNOWN" } // typeName returns a readable type label (mirrors Harbour's ValType plus // a few Five-specific niceties). func typeName(v hbrt.Value) string { switch { case v.IsNil(): return "NIL" case v.IsLogical(): return "LOGICAL" case v.IsNumeric(): return "NUMERIC" case v.IsString(): return "STRING" case v.IsDate(): return "DATE" case v.IsTimestamp(): return "TIMESTAMP" case v.IsArray(): return "ARRAY" case v.IsObject(): return "OBJECT" case v.IsHash(): return "HASH" case v.IsBlock(): return "BLOCK" case v.IsPointer(): return "POINTER" case v.IsSymbol(): return "SYMBOL" } return "UNKNOWN" } // describe renders a best-effort string form. Strings come back unquoted and // truncated; everything else falls back to Value.String(). func describe(v hbrt.Value) string { if v.IsString() { s := v.AsString() if len(s) > 200 { return s[:200] + "…" } return s } if v.IsNumeric() { if v.IsInt() { return fmt.Sprintf("%d", v.AsNumInt()) } return fmt.Sprintf("%g", v.AsNumDouble()) } return v.String() } func writeHashErr(b *strings.Builder, oErr hbrt.Value) { h := oErr.AsHash() getStr := func(key string) string { if idx := h.Lookup(hbrt.MakeString(key)); idx >= 0 { return describe(h.Values[idx]) } return "" } getInt := func(key string) int64 { if idx := h.Lookup(hbrt.MakeString(key)); idx >= 0 { v := h.Values[idx] if v.IsNumeric() { return v.AsNumInt() } } return 0 } fmt.Fprintf(b, " Description: %s\n", getStr("DESCRIPTION")) fmt.Fprintf(b, " Operation: %s\n", getStr("OPERATION")) fmt.Fprintf(b, " SubSystem: %s (GenCode %d, SubCode %d)\n", getStr("SUBSYSTEM"), getInt("GENCODE"), getInt("SUBCODE")) fmt.Fprintf(b, " Severity: %s (%d), OsCode: %d\n", severityLabel(int(getInt("SEVERITY"))), getInt("SEVERITY"), getInt("OSCODE")) if fn := getStr("FILENAME"); fn != "" { fmt.Fprintf(b, " FileName: %s\n", fn) } // Most recent file/DOS errors — often the *cause* of the Harbour // error one level up (open failed → field access panic'd). if lastFErr != 0 || lastDosErr != 0 { fmt.Fprintf(b, " FError: %d, DosError: %d\n", lastFErr, lastDosErr) } if idx := h.Lookup(hbrt.MakeString("ARGS")); idx >= 0 { args := h.Values[idx] if args.IsArray() { arr := args.AsArray() if len(arr.Items) > 0 { op := getStr("OPERATION") // Blanket-redact all args when the operation itself looks // like a credential-handling call (e.g. "LOGIN", "SIGNIN", // "AUTHENTICATE") — we can't know which slot held the // secret so we mask the lot. mask := isSensitiveKey(op) fmt.Fprintf(b, " Args (%d):\n", len(arr.Items)) for i, a := range arr.Items { val := describe(a) if mask && a.IsString() { val = "***REDACTED***" } fmt.Fprintf(b, " [%d] %s = %s\n", i+1, typeName(a), val) } } } } } func writeWorkareas(b *strings.Builder, t *hbrt.Thread) { wam, ok := t.WA.(*hbrdd.WorkAreaManager) if !ok || wam == nil { b.WriteString(" (no workarea manager)\n") return } count := 0 current := wam.CurrentNum() wam.EnumerateAreas(func(nWA uint16, alias string, area hbrdd.Area) { count++ marker := " " if nWA == current { marker = "=> " } recCount, _ := area.RecCount() fmt.Fprintf(b, " %s[%3d] %-15s driver=%s rec=%d/%d eof=%v bof=%v del=%v\n", marker, nWA, alias, area.Driver().Name(), area.RecNo(), recCount, area.EOF(), area.BOF(), area.Deleted()) // Open mode — shared/exclusive/readonly — critical for "works on // my machine" bugs. Optional via type assertion since the Area // interface doesn't mandate these methods. type openModer interface { IsShared() bool IsReadOnly() bool } if om, ok := area.(openModer); ok { mode := "exclusive" if om.IsShared() { mode = "shared" } if om.IsReadOnly() { mode += ", readonly" } fmt.Fprintf(b, " mode: %s\n", mode) } // Active index: shows which ordering is applied to the area at // the moment of error. An EOF'd workarea is often actually just // "filter cut it off" — knowing the tag saves hours. type orderInfo interface { CurrentOrder() int OrderInfo(ordNo int) (*hbrdd.OrderInfo, error) } if oi, ok := area.(orderInfo); ok { if n := oi.CurrentOrder(); n > 0 { if info, err := oi.OrderInfo(n); err == nil && info != nil { fmt.Fprintf(b, " order: %s key=%q", info.Name, info.KeyExpr) if info.ForExpr != "" { fmt.Fprintf(b, " for=%q", info.ForExpr) } if info.Unique { b.WriteString(" unique") } if info.Descending { b.WriteString(" desc") } b.WriteString("\n") } } } // Fields nF := area.FieldCount() if nF > 0 { fmt.Fprintf(b, " fields (%d): ", nF) for i := 0; i < nF && i < 20; i++ { fi := area.GetFieldInfo(i) if i > 0 { b.WriteString(", ") } fmt.Fprintf(b, "%s(%c/%d)", fi.Name, fi.Type, fi.Len) } if nF > 20 { fmt.Fprintf(b, ", … %d more", nF-20) } b.WriteString("\n") } }) if count == 0 { b.WriteString(" (no open workareas)\n") } } // addCommas formats an int64 with thousands separators so big byte counts // are legible in the log. No allocation beyond the strings.Builder. func addCommas(n int64) string { neg := n < 0 if neg { n = -n } s := fmt.Sprintf("%d", n) if len(s) <= 3 { if neg { return "-" + s } return s } var out strings.Builder if neg { out.WriteByte('-') } // Insert commas every 3 digits from the right. first := len(s) % 3 if first > 0 { out.WriteString(s[:first]) if len(s) > first { out.WriteByte(',') } } for i := first; i < len(s); i += 3 { out.WriteString(s[i : i+3]) if i+3 < len(s) { out.WriteByte(',') } } return out.String() }