From f4ef362346ffa7307e33e6edc26fe9b609d55d72 Mon Sep 17 00:00:00 2001 From: AIRONAX Developer Date: Sun, 6 Sep 2026 04:23:17 +0530 Subject: [PATCH] refactor(logging): collapse classifiers and Event boilerplate Share ClassifyLogCode across ORM/web, drop logORMOperationKV and double-logs, and slim SQL debug wrappers without changing the ErrorCode/WarnCode contract. --- core/applog/logger.go | 7 +-- core/applog/scrub.go | 8 +-- core/applog/stdio.go | 27 ++------- core/orm/audit.go | 39 ++++++------- core/orm/classify_log_code.go | 31 ++++++++++ core/orm/crud_search.go | 6 +- core/orm/crud_search_one.go | 2 +- core/orm/crud_sideeffects.go | 10 +--- core/orm/crud_tx.go | 11 +--- core/orm/db_dev_log.go | 78 +++++++------------------- core/orm/orm_op_log.go | 32 +---------- core/orm/outbox_drain.go | 52 +++++++---------- core/orm/ui_view_lookup.go | 8 ++- core/scheduler/scheduler.go | 4 +- core/server/web/record_error_flash.go | 30 +--------- core/server/web/setup_handlers.go | 20 +++---- core/server/web/shell_render.go | 33 ++++++----- core/server/web/web_request_helpers.go | 8 +-- core/server/web/workspace.go | 43 +++++++------- 19 files changed, 162 insertions(+), 287 deletions(-) create mode 100644 core/orm/classify_log_code.go diff --git a/core/applog/logger.go b/core/applog/logger.go index 99fa55f4..698d38da 100644 --- a/core/applog/logger.go +++ b/core/applog/logger.go @@ -58,17 +58,16 @@ func L(ctx context.Context) *slog.Logger { // Fatal logs at error level and exits the process. func Fatal(ctx context.Context, msg string, keysAndValues ...interface{}) { - attrs := keysAndValues ev := Event{ Message: msg, Code: errcode.InternalError, Component: "server", Status: "failure", } - if len(attrs) > 0 { - ev.Context = kvPairsToMap(attrs) + if len(keysAndValues) > 0 { + ev.Context = kvPairsToMap(keysAndValues) } - ErrorCode(ctx, errcode.InternalError, msg, ev) + Error(ctx, ev) os.Exit(1) } diff --git a/core/applog/scrub.go b/core/applog/scrub.go index f370c2ee..92041ae5 100644 --- a/core/applog/scrub.go +++ b/core/applog/scrub.go @@ -2,10 +2,8 @@ package applog import "strings" -// RedactedPlaceholder replaces secret values in logs and dumps. const RedactedPlaceholder = "***" -// ScrubMap returns a copy of fields with secret field values redacted. func ScrubMap(fields map[string]interface{}) map[string]interface{} { if fields == nil { return nil @@ -17,7 +15,6 @@ func ScrubMap(fields map[string]interface{}) map[string]interface{} { return scrubbed } -// ScrubValue redacts value when fieldName is secret; walks nested maps and slices. func ScrubValue(fieldName string, value any) any { if IsSecretKey(fieldName) { return RedactedPlaceholder @@ -48,14 +45,12 @@ func ScrubValue(fieldName string, value any) any { } } -// IsSecretKey reports whether a field name must never be logged in cleartext. -// "sid" matches the full field name only (avoids false positives like "inside"). +// IsSecretKey: "sid" is exact-match only (avoids "inside"). func IsSecretKey(fieldName string) bool { normalized := strings.ToLower(strings.TrimSpace(fieldName)) return normalized == "sid" || (normalized != "" && containsSecretKeyword(normalized)) } -// TextContainsSecretKeyword reports whether free text (e.g. SQL) mentions a secret term. func TextContainsSecretKeyword(text string) bool { lowered := strings.ToLower(text) return strings.Contains(lowered, "sid") || containsSecretKeyword(lowered) @@ -70,7 +65,6 @@ func containsSecretKeyword(haystack string) bool { return false } -// secretKeywords match as substrings of field names and of free text (including totp*). var secretKeywords = []string{ "password", "token", "secret", "authorization", "cookie", "session", "api_key", "apikey", "key_hash", "csrf", "totp", diff --git a/core/applog/stdio.go b/core/applog/stdio.go index 923a1042..9b2c2f6f 100644 --- a/core/applog/stdio.go +++ b/core/applog/stdio.go @@ -2,41 +2,27 @@ package applog import "context" -// InfoMsg logs a structured info event with the logging contract. func InfoMsg(ctx context.Context, component, operation, message string, ctxFields map[string]interface{}) { Info(ctx, Event{ - Message: message, - Component: component, - Operation: operation, - Status: "success", - Context: ctxFields, + Message: message, Component: component, Operation: operation, + Status: "success", Context: ctxFields, }) } -// WarnMsg logs a structured warning event with the logging contract. func WarnMsg(ctx context.Context, component, operation, message string, err error, ctxFields map[string]interface{}) { Warn(ctx, Event{ - Message: message, - Component: component, - Operation: operation, - Status: "partial", - Context: ctxFields, - Err: err, + Message: message, Component: component, Operation: operation, + Status: "partial", Context: ctxFields, Err: err, }) } -// DebugMsg logs a structured debug event with the logging contract. func DebugMsg(ctx context.Context, component, operation, message string, ctxFields map[string]interface{}) { Debug(ctx, Event{ - Message: message, - Component: component, - Operation: operation, - Status: "success", - Context: ctxFields, + Message: message, Component: component, Operation: operation, + Status: "success", Context: ctxFields, }) } -// ErrorCode logs a failure with a stable machine code and human message. func ErrorCode(ctx context.Context, code, message string, ev Event) { ev.Code = code if message != "" { @@ -48,7 +34,6 @@ func ErrorCode(ctx context.Context, code, message string, ev Event) { Error(ctx, ev) } -// WarnCode logs a warning with a stable machine code and human message. func WarnCode(ctx context.Context, code, message string, ev Event) { ev.Code = code if message != "" { diff --git a/core/orm/audit.go b/core/orm/audit.go index 24ee2f5a..22ffab65 100644 --- a/core/orm/audit.go +++ b/core/orm/audit.go @@ -23,30 +23,10 @@ func auditValues(ctx context.Context, action, model string, resID int64, before, uid := SecurityUID(ctx) var beforeJSON, afterJSON string if before != nil { - if b, err := json.Marshal(scrubAuditMap(before)); err == nil { - beforeJSON = string(b) - } else { - applog.WarnCode(ctx, errcode.InternalError, "Audit before_json marshal failed", applog.Event{ - Component: "orm", - Operation: "audit", - Status: "partial", - Context: map[string]interface{}{"resource": model, "resource_id": resID}, - Err: err, - }) - } + beforeJSON = marshalAuditJSON(ctx, "before_json", model, resID, before) } if after != nil { - if b, err := json.Marshal(scrubAuditMap(after)); err == nil { - afterJSON = string(b) - } else { - applog.WarnCode(ctx, errcode.InternalError, "Audit after_json marshal failed", applog.Event{ - Component: "orm", - Operation: "audit", - Status: "partial", - Context: map[string]interface{}{"resource": model, "resource_id": resID}, - Err: err, - }) - } + afterJSON = marshalAuditJSON(ctx, "after_json", model, resID, after) } vals := map[string]interface{}{ "action": action, @@ -63,6 +43,21 @@ func auditValues(ctx context.Context, action, model string, resID int64, before, return vals } +func marshalAuditJSON(ctx context.Context, field, model string, resID int64, values map[string]interface{}) string { + b, err := json.Marshal(scrubAuditMap(values)) + if err != nil { + applog.WarnCode(ctx, errcode.InternalError, "Audit "+field+" marshal failed", applog.Event{ + Component: "orm", + Operation: "audit", + Status: "partial", + Context: map[string]interface{}{"resource": model, "resource_id": resID}, + Err: err, + }) + return "" + } + return string(b) +} + // AppendAudit writes an immutable audit row (best-effort; never fails the caller). func AppendAudit(ctx context.Context, action, model string, resID int64, before, after map[string]interface{}, detail string) { AppendAuditTx(ctx, nil, action, model, resID, before, after, detail) diff --git a/core/orm/classify_log_code.go b/core/orm/classify_log_code.go new file mode 100644 index 00000000..2f7233a4 --- /dev/null +++ b/core/orm/classify_log_code.go @@ -0,0 +1,31 @@ +package orm + +import ( + "errors" + "strings" + + "sumeru/core/errcode" +) + +// ClassifyLogCode maps an error to a stable applog/errcode machine id. +func ClassifyLogCode(err error) string { + if err == nil { + return errcode.InternalError + } + if IsAccessDenied(err) || IsRecordRuleFailed(err) { + return errcode.AccessDenied + } + var fieldErr *FieldValidationError + if errors.As(err, &fieldErr) { + return errcode.ValidationError + } + msg := strings.ToLower(err.Error()) + switch { + case strings.Contains(msg, "record(s) not found"), strings.Contains(msg, "not found"): + return errcode.RecordNotFound + case strings.Contains(msg, "validation"), strings.Contains(msg, "invalid"), strings.Contains(msg, "required"): + return errcode.ValidationError + default: + return errcode.InternalError + } +} diff --git a/core/orm/crud_search.go b/core/orm/crud_search.go index aa4204a9..22d43e13 100644 --- a/core/orm/crud_search.go +++ b/core/orm/crud_search.go @@ -92,7 +92,7 @@ func Search(ctx context.Context, modelName string, domain [][]interface{}) (resu if results != nil { n = len(results) } - logORMOperationKV(ctx, start, "search", modelName, err, "rows", n) + logORMOperation(ctx, start, "search", modelName, err, map[string]interface{}{"rows": n}) }() results, err = execSearchQuery(ctx, modelName, domain, nil) if err != nil { @@ -124,7 +124,7 @@ func SearchPage(ctx context.Context, modelName string, domain [][]interface{}, l if results != nil { n = len(results) } - logORMOperationKV(ctx, start, "search_page", modelName, err, "rows", n, "limit", limit, "offset", offset) + logORMOperation(ctx, start, "search_page", modelName, err, map[string]interface{}{"rows": n, "limit": limit, "offset": offset}) }() if limit <= 0 || limit > maxSearchLimit { limit = maxSearchLimit @@ -150,7 +150,7 @@ func SearchPage(ctx context.Context, modelName string, domain [][]interface{}, l func SearchCount(ctx context.Context, modelName string, domain [][]interface{}) (n int, err error) { start := time.Now() defer func() { - logORMOperationKV(ctx, start, "search_count", modelName, err, "count", n) + logORMOperation(ctx, start, "search_count", modelName, err, map[string]interface{}{"count": n}) }() ctx = ContextWithReadReplica(ctx, true) _, whereClause, args, _, err := prepareSearchRead(ctx, modelName, domain) diff --git a/core/orm/crud_search_one.go b/core/orm/crud_search_one.go index 2d2b524d..72d363cd 100644 --- a/core/orm/crud_search_one.go +++ b/core/orm/crud_search_one.go @@ -31,7 +31,7 @@ func CriteriaToDomain(criteria map[string]interface{}) [][]interface{} { func SearchOne(ctx context.Context, modelName string, criteria map[string]interface{}) (result map[string]interface{}, err error) { start := time.Now() defer func() { - logORMOperationKV(ctx, start, "search_one", modelName, err, "has_row", result != nil) + logORMOperation(ctx, start, "search_one", modelName, err, map[string]interface{}{"has_row": result != nil}) }() if _, ok := Registry[modelName]; !ok { return nil, fmt.Errorf("model %s not registered", modelName) diff --git a/core/orm/crud_sideeffects.go b/core/orm/crud_sideeffects.go index 220ebd38..326514ad 100644 --- a/core/orm/crud_sideeffects.go +++ b/core/orm/crud_sideeffects.go @@ -32,15 +32,7 @@ func emitSideEffectsOnTx(ctx context.Context, tx TxWrapper, modelName string, ui "model": modelName, "id": int(row.ResID), }); err != nil { - applog.WarnCode(ctx, errcode.InternalError, "outbox enqueue after mutation failed", applog.Event{ - Component: "orm", - Operation: "side_effects", - Status: "partial", - Context: map[string]interface{}{ - "model": modelName, "event": row.EventName, - }, - Err: err, - }) + logSideEffectWarn(ctx, "outbox_enqueue", modelName, err, "event", row.EventName) } } } diff --git a/core/orm/crud_tx.go b/core/orm/crud_tx.go index 4b103997..f268ec37 100644 --- a/core/orm/crud_tx.go +++ b/core/orm/crud_tx.go @@ -4,9 +4,6 @@ import ( "context" "fmt" "strings" - - "sumeru/core/applog" - "sumeru/core/errcode" ) func insertPreparedOnTx(ctx context.Context, tx TxWrapper, model Model, prepared map[string]interface{}) (int, error) { @@ -106,13 +103,7 @@ func insertSideEffectRow(ctx context.Context, tx TxWrapper, registryKey string, } _, err := Create(bypass, inst, vals) if err != nil { - applog.WarnCode(ctx, errcode.InternalError, "Side effect insert failed", applog.Event{ - Component: "orm", - Operation: "insert_side_effect", - Status: "partial", - Context: map[string]interface{}{"resource": registryKey}, - Err: err, - }) + logSideEffectWarn(ctx, "insert_side_effect", registryKey, err) } return err } diff --git a/core/orm/db_dev_log.go b/core/orm/db_dev_log.go index ca2f0e70..12efc274 100644 --- a/core/orm/db_dev_log.go +++ b/core/orm/db_dev_log.go @@ -6,7 +6,7 @@ import ( "strings" "time" - applog "sumeru/core/applog" + "sumeru/core/applog" ) type loggingDBWrapper struct { @@ -20,41 +20,21 @@ func wrapDevLogging(db DBWrapper) DBWrapper { return &loggingDBWrapper{inner: db} } -type sqlLogEntry struct { - Op string - Query string - Args []interface{} - Err error - Dur time.Duration -} - -func logSQL(ctx context.Context, in sqlLogEntry) { - if !DevFeatureEnabled("sql") { - return - } - q := strings.Join(strings.Fields(in.Query), " ") +func logSQL(ctx context.Context, op, query string, args []interface{}, err error, dur time.Duration) { + q := strings.Join(strings.Fields(query), " ") if len(q) > 500 { q = q[:500] + "…" } - ctxMap := map[string]interface{}{ - "op": in.Op, - "sql": q, - "ms": in.Dur.Milliseconds(), - } - if len(in.Args) > 0 { - ctxMap["args"] = scrubSQLArgs(in.Query, in.Args) + ctxMap := map[string]interface{}{"op": op, "sql": q, "ms": dur.Milliseconds()} + if len(args) > 0 { + ctxMap["args"] = scrubSQLArgs(query, args) } status := "success" - if in.Err != nil { + if err != nil { status = "failure" } applog.Debug(ctx, applog.Event{ - Message: "SQL", - Component: "orm", - Operation: "sql", - Status: status, - Context: ctxMap, - Err: in.Err, + Message: "SQL", Component: "orm", Operation: "sql", Status: status, Context: ctxMap, Err: err, }) } @@ -73,44 +53,35 @@ func scrubSQLArgs(query string, args []interface{}) interface{} { } func (w *loggingDBWrapper) Exec(query string, args ...interface{}) (sql.Result, error) { - start := time.Now() - res, err := w.inner.Exec(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "exec", Query: query, Args: args, Err: err, Dur: time.Since(start)}) - return res, err + return w.ExecContext(context.Background(), query, args...) } func (w *loggingDBWrapper) ExecContext(ctx context.Context, query string, args ...interface{}) (sql.Result, error) { start := time.Now() res, err := w.inner.ExecContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "exec", Query: query, Args: args, Err: err, Dur: time.Since(start)}) + logSQL(ctx, "exec", query, args, err, time.Since(start)) return res, err } func (w *loggingDBWrapper) Query(query string, args ...interface{}) (*sql.Rows, error) { - start := time.Now() - rows, err := w.inner.Query(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "query", Query: query, Args: args, Err: err, Dur: time.Since(start)}) - return rows, err + return w.QueryContext(context.Background(), query, args...) } func (w *loggingDBWrapper) QueryContext(ctx context.Context, query string, args ...interface{}) (*sql.Rows, error) { start := time.Now() rows, err := w.inner.QueryContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "query", Query: query, Args: args, Err: err, Dur: time.Since(start)}) + logSQL(ctx, "query", query, args, err, time.Since(start)) return rows, err } func (w *loggingDBWrapper) QueryRow(query string, args ...interface{}) *sql.Row { - start := time.Now() - row := w.inner.QueryRow(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "query_row", Query: query, Args: args, Dur: time.Since(start)}) - return row + return w.QueryRowContext(context.Background(), query, args...) } func (w *loggingDBWrapper) QueryRowContext(ctx context.Context, query string, args ...interface{}) *sql.Row { start := time.Now() row := w.inner.QueryRowContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "query_row", Query: query, Args: args, Dur: time.Since(start)}) + logSQL(ctx, "query_row", query, args, nil, time.Since(start)) return row } @@ -138,44 +109,35 @@ type loggingTxWrapper struct { } func (w *loggingTxWrapper) Exec(query string, args ...interface{}) (sql.Result, error) { - start := time.Now() - res, err := w.inner.Exec(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "tx_exec", Query: query, Args: args, Err: err, Dur: time.Since(start)}) - return res, err + return w.ExecContext(context.Background(), query, args...) } func (w *loggingTxWrapper) ExecContext(ctx context.Context, query string, args ...interface{}) (sql.Result, error) { start := time.Now() res, err := w.inner.ExecContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "tx_exec", Query: query, Args: args, Err: err, Dur: time.Since(start)}) + logSQL(ctx, "tx_exec", query, args, err, time.Since(start)) return res, err } func (w *loggingTxWrapper) Query(query string, args ...interface{}) (*sql.Rows, error) { - start := time.Now() - rows, err := w.inner.Query(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "tx_query", Query: query, Args: args, Err: err, Dur: time.Since(start)}) - return rows, err + return w.QueryContext(context.Background(), query, args...) } func (w *loggingTxWrapper) QueryContext(ctx context.Context, query string, args ...interface{}) (*sql.Rows, error) { start := time.Now() rows, err := w.inner.QueryContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "tx_query", Query: query, Args: args, Err: err, Dur: time.Since(start)}) + logSQL(ctx, "tx_query", query, args, err, time.Since(start)) return rows, err } func (w *loggingTxWrapper) QueryRow(query string, args ...interface{}) *sql.Row { - start := time.Now() - row := w.inner.QueryRow(query, args...) - logSQL(context.Background(), sqlLogEntry{Op: "tx_query_row", Query: query, Args: args, Dur: time.Since(start)}) - return row + return w.QueryRowContext(context.Background(), query, args...) } func (w *loggingTxWrapper) QueryRowContext(ctx context.Context, query string, args ...interface{}) *sql.Row { start := time.Now() row := w.inner.QueryRowContext(ctx, query, args...) - logSQL(ctx, sqlLogEntry{Op: "tx_query_row", Query: query, Args: args, Dur: time.Since(start)}) + logSQL(ctx, "tx_query_row", query, args, nil, time.Since(start)) return row } diff --git a/core/orm/orm_op_log.go b/core/orm/orm_op_log.go index b6859019..b2acfb4d 100644 --- a/core/orm/orm_op_log.go +++ b/core/orm/orm_op_log.go @@ -3,11 +3,9 @@ package orm import ( "context" "fmt" - "strings" "time" "sumeru/core/applog" - "sumeru/core/errcode" "sumeru/core/metrics" ) @@ -32,7 +30,7 @@ func logORMOperation(ctx context.Context, start time.Time, operation, modelName if err != nil { ev.Message = humanORMMessage(operation, modelName, false) ev.Status = "failure" - ev.Code = classifyORMError(err) + ev.Code = ClassifyLogCode(err) applog.ErrorCode(ctx, ev.Code, ev.Message, ev) return } @@ -45,23 +43,6 @@ func logORMOperation(ctx context.Context, start time.Time, operation, modelName applog.Info(ctx, ev) } -func classifyORMError(err error) string { - if err == nil { - return errcode.InternalError - } - if IsAccessDenied(err) || IsRecordRuleFailed(err) { - return errcode.AccessDenied - } - msg := strings.ToLower(err.Error()) - if strings.Contains(msg, "record(s) not found") || strings.Contains(msg, "not found") { - return errcode.RecordNotFound - } - if strings.Contains(msg, "validation") || strings.Contains(msg, "invalid") { - return errcode.ValidationError - } - return errcode.InternalError -} - func humanORMMessage(operation, modelName string, success bool) string { switch operation { case "create": @@ -96,14 +77,3 @@ func humanORMMessage(operation, modelName string, success bool) string { return fmt.Sprintf("%s on %s failed", operation, modelName) } } - -// logORMOperationKV adapts legacy key-value call sites during migration. -func logORMOperationKV(ctx context.Context, start time.Time, operation, modelName string, err error, keysAndValues ...interface{}) { - ctxMap := map[string]interface{}{} - for i := 0; i+1 < len(keysAndValues); i += 2 { - if k, ok := keysAndValues[i].(string); ok { - ctxMap[k] = keysAndValues[i+1] - } - } - logORMOperation(ctx, start, operation, modelName, err, ctxMap) -} diff --git a/core/orm/outbox_drain.go b/core/orm/outbox_drain.go index 6df1cc0c..93b15d56 100644 --- a/core/orm/outbox_drain.go +++ b/core/orm/outbox_drain.go @@ -31,12 +31,7 @@ func DrainOutboxOnce(ctx context.Context) int { `SELECT id, name, COALESCE(payload_json,''), COALESCE(actor,0) FROM `+tbl+ ` WHERE published_at IS NULL ORDER BY id LIMIT 100`) if err != nil { - applog.WarnCode(bypass, errcode.InternalError, "outbox drain query failed", applog.Event{ - Component: "orm", - Operation: "outbox_drain", - Status: "partial", - Err: err, - }) + warnOutbox(bypass, "outbox drain query failed", err, nil) return 0 } defer rows.Close() @@ -48,34 +43,17 @@ func DrainOutboxOnce(ctx context.Context) int { var name, payloadJSON string var actor int if err := rows.Scan(&id, &name, &payloadJSON, &actor); err != nil { - applog.WarnCode(bypass, errcode.InternalError, "outbox drain scan failed", applog.Event{ - Component: "orm", - Operation: "outbox_drain", - Status: "partial", - Err: err, - }) + warnOutbox(bypass, "outbox drain scan failed", err, nil) continue } payload := map[string]interface{}{} if payloadJSON != "" { if err := json.Unmarshal([]byte(payloadJSON), &payload); err != nil { - applog.WarnCode(bypass, errcode.InternalError, "outbox payload unmarshal failed", applog.Event{ - Component: "orm", - Operation: "outbox_drain", - Status: "partial", - Context: map[string]interface{}{"outbox_id": id, "event": name}, - Err: err, - }) + warnOutbox(bypass, "outbox payload unmarshal failed", err, map[string]interface{}{"outbox_id": id, "event": name}) } } if errs := event.Publish(bypass, event.Event{Name: name, Actor: actor, Payload: payload}); len(errs) > 0 { - applog.WarnCode(bypass, errcode.InternalError, "outbox publish failed", applog.Event{ - Component: "orm", - Operation: "outbox_drain", - Status: "failure", - Context: map[string]interface{}{"outbox_id": id, "event": name}, - Err: errs[0], - }) + warnOutbox(bypass, "outbox publish failed", errs[0], map[string]interface{}{"outbox_id": id, "event": name}) continue } queue.Publish(bypass, "outbox", map[string]interface{}{ @@ -83,13 +61,7 @@ func DrainOutboxOnce(ctx context.Context) int { }) if _, err := DB.ExecContext(bypass, `UPDATE `+tbl+` SET published_at = $1 WHERE id = $2`, now, id); err != nil { - applog.WarnCode(bypass, errcode.InternalError, "outbox mark published failed", applog.Event{ - Component: "orm", - Operation: "outbox_drain", - Status: "partial", - Context: map[string]interface{}{"outbox_id": id, "event": name}, - Err: err, - }) + warnOutbox(bypass, "outbox mark published failed", err, map[string]interface{}{"outbox_id": id, "event": name}) continue } published++ @@ -97,6 +69,20 @@ func DrainOutboxOnce(ctx context.Context) int { return published } +func warnOutbox(ctx context.Context, message string, err error, fields map[string]interface{}) { + status := "partial" + if message == "outbox publish failed" { + status = "failure" + } + applog.WarnCode(ctx, errcode.InternalError, message, applog.Event{ + Component: "orm", + Operation: "outbox_drain", + Status: status, + Context: fields, + Err: err, + }) +} + // StartOutboxDrain begins a background ticker that drains pending outbox rows. func StartOutboxDrain(parent context.Context, every time.Duration) { outboxMu.Lock() diff --git a/core/orm/ui_view_lookup.go b/core/orm/ui_view_lookup.go index fa7039ee..edd9c65b 100644 --- a/core/orm/ui_view_lookup.go +++ b/core/orm/ui_view_lookup.go @@ -21,7 +21,9 @@ func uiViewLookupLogErr(err error) error { func FindUIDefaultView(ctx context.Context, modelName, viewType string) (result map[string]interface{}, err error) { start := time.Now() defer func() { - logORMOperationKV(ctx, start, "find_ui_view", "sys.view", uiViewLookupLogErr(err), "target_model", modelName, "view_type", viewType, "found", result != nil) + logORMOperation(ctx, start, "find_ui_view", "sys.view", uiViewLookupLogErr(err), map[string]interface{}{ + "target_model": modelName, "view_type": viewType, "found": result != nil, + }) }() if _, ok := Registry["sys.view"]; !ok { return nil, fmt.Errorf("model sys.view not registered") @@ -78,7 +80,9 @@ func findUIDefaultViewByType(ctx context.Context, uid int, modelName, vt string) func FindUIViewByName(ctx context.Context, modelName, viewType, viewName string) (result map[string]interface{}, err error) { start := time.Now() defer func() { - logORMOperationKV(ctx, start, "find_ui_view_by_name", "sys.view", uiViewLookupLogErr(err), "target_model", modelName, "view_type", viewType, "view_name", viewName, "found", result != nil) + logORMOperation(ctx, start, "find_ui_view_by_name", "sys.view", uiViewLookupLogErr(err), map[string]interface{}{ + "target_model": modelName, "view_type": viewType, "view_name": viewName, "found": result != nil, + }) }() viewName = strings.TrimSpace(viewName) if viewName == "" { diff --git a/core/scheduler/scheduler.go b/core/scheduler/scheduler.go index 602b0aed..a09be919 100644 --- a/core/scheduler/scheduler.go +++ b/core/scheduler/scheduler.go @@ -158,8 +158,8 @@ type CronRunInput struct { } func executeCron(ctx context.Context, in CronRunInput) { - applog.Info(ctx, applog.Event{ - Message: "cron job started", + applog.Debug(ctx, applog.Event{ + Message: "cron job starting", Component: "scheduler", Operation: "cron_run", Status: "success", diff --git a/core/server/web/record_error_flash.go b/core/server/web/record_error_flash.go index 616f5924..0760c56d 100644 --- a/core/server/web/record_error_flash.go +++ b/core/server/web/record_error_flash.go @@ -7,8 +7,6 @@ import ( "net/url" "strings" - "sumeru/core/applog" - "sumeru/core/errcode" "sumeru/core/orm" ) @@ -132,14 +130,10 @@ func redirectRecordError(w http.ResponseWriter, r *http.Request, nextURL, operat title, body, details, fieldErrors := userFacingRecordError(operation, model, err) WebLogEvent(ctx, WebLogInput{ Route: operationRoute(operation), Message: body, - Code: classifyRecordErrorCode(err), + Code: orm.ClassifyLogCode(err), Operation: operation, Status: logStatusFailure, Err: err, ContextFields: map[string]interface{}{"model": model}, }) - applog.DebugMsg(ctx, webLogComponent, operation, "record POST failed", map[string]interface{}{ - "model": model, - "error": err.Error(), - }) SetRecordErrorFlash(w, PageFlash{ Kind: "error", Title: title, @@ -178,28 +172,6 @@ func operationRoute(operation string) string { } } -func classifyRecordErrorCode(err error) string { - if err == nil { - return errcode.InternalError - } - if orm.IsAccessDenied(err) || orm.IsRecordRuleFailed(err) { - return errcode.AccessDenied - } - var fve *orm.FieldValidationError - if errors.As(err, &fve) { - return errcode.ValidationError - } - msg := strings.ToLower(err.Error()) - switch { - case strings.Contains(msg, "not found"): - return errcode.RecordNotFound - case strings.Contains(msg, "validation"), strings.Contains(msg, "invalid"), strings.Contains(msg, "required"): - return errcode.ValidationError - default: - return errcode.InternalError - } -} - func ensureFormEditRedirectURL(rawNext string, clearRecordID bool) string { nextPath := SafeWebNext(rawNext, homeRoute) parsed, err := url.Parse(nextPath) diff --git a/core/server/web/setup_handlers.go b/core/server/web/setup_handlers.go index e5450285..bf8017f2 100644 --- a/core/server/web/setup_handlers.go +++ b/core/server/web/setup_handlers.go @@ -116,13 +116,17 @@ func runFirstTimeSetup(ctx context.Context, adminParams orm.SetupAdminParams) er return nil } -func logSetupFailure(ctx context.Context, message string, err error) { - applog.ErrorCode(ctx, errcode.InternalError, message, applog.Event{ +func logSetupFailure(ctx context.Context, message string, err error, fields ...map[string]interface{}) { + ev := applog.Event{ Component: "web", Operation: setupOperation, Status: "failure", Err: err, - }) + } + if len(fields) > 0 { + ev.Context = fields[0] + } + applog.ErrorCode(ctx, errcode.InternalError, message, ev) } func scheduleSetupRestart() { @@ -147,19 +151,13 @@ func writeSetupPage(w http.ResponseWriter, ctx context.Context, pageData setupPa templatePath := filepath.Join(config.AppConfig.TemplatesPath, setupTemplateFile) templateFile, err := template.ParseFiles(templatePath) if err != nil { - applog.ErrorCode(ctx, errcode.InternalError, "Failed to parse setup template", applog.Event{ - Component: "web", Operation: setupOperation, - Status: "failure", Err: err, Context: map[string]interface{}{"template": templatePath}, - }) + logSetupFailure(ctx, "Failed to parse setup template", err, map[string]interface{}{"template": templatePath}) http.Error(w, "Setup template missing", http.StatusInternalServerError) return } w.Header().Set("Content-Type", "text/html; charset=utf-8") if err := templateFile.Execute(w, pageData); err != nil { - applog.ErrorCode(ctx, errcode.InternalError, "Failed to execute setup template", applog.Event{ - Component: "web", Operation: setupOperation, - Status: "failure", Err: err, - }) + logSetupFailure(ctx, "Failed to execute setup template", err) } } diff --git a/core/server/web/shell_render.go b/core/server/web/shell_render.go index a29e32e4..891e13f8 100644 --- a/core/server/web/shell_render.go +++ b/core/server/web/shell_render.go @@ -35,10 +35,7 @@ func renderShellPage(w http.ResponseWriter, r *http.Request, opts shellPageOpts) page := finalizeShellPage(ctx, r, opts, innerHTML, route) layoutHTML, err := render.RenderPage(ctx, config.AppConfig.TemplatesPath, page) if err != nil { - WebLogEvent(ctx, WebLogInput{ - Route: route, Message: "Failed to render page layout", - Code: errcode.InternalError, Operation: "render", Status: "failure", Err: err, - }) + webLogFail(ctx, route, "render", "Failed to render page layout", err, logStatusFailure, nil) http.Error(w, "Layout render error", http.StatusInternalServerError) return } @@ -59,21 +56,14 @@ func executeInnerTemplate(ctx context.Context, w http.ResponseWriter, route stri } templateFile, err := template.ParseFiles(templatePaths...) if err != nil { - WebLogEvent(ctx, WebLogInput{ - Route: route, Message: "Failed to parse inner template", - Code: errcode.InternalError, Operation: "render", Status: "failure", Err: err, - ContextFields: map[string]interface{}{"template": opts.InnerTemplate}, - }) + webLogFail(ctx, route, "render", "Failed to parse inner template", err, logStatusFailure, map[string]interface{}{"template": opts.InnerTemplate}) http.Error(w, "Template error", http.StatusInternalServerError) return "", false } var innerBuffer bytes.Buffer if err := templateFile.Execute(&innerBuffer, opts.InnerData); err != nil { - WebLogEvent(ctx, WebLogInput{ - Route: route, Message: "Failed to execute inner template", - Code: errcode.InternalError, Operation: "render", Status: "failure", Err: err, - }) + webLogFail(ctx, route, "render", "Failed to execute inner template", err, logStatusFailure, nil) http.Error(w, "Template error", http.StatusInternalServerError) return "", false } @@ -147,9 +137,18 @@ func resolveExtraScripts(pageScripts, optScripts []string) []string { func writeHTML(w http.ResponseWriter, ctx context.Context, route, html string) { w.Header().Set("Content-Type", "text/html; charset=utf-8") if _, err := w.Write([]byte(html)); err != nil { - WebLogEvent(ctx, WebLogInput{ - Route: route, Message: "Failed to write HTML response", - Code: errcode.InternalError, Operation: "write", Status: "partial", Err: err, - }) + webLogFail(ctx, route, "write", "Failed to write HTML response", err, logStatusPartial, nil) } } + +func webLogFail(ctx context.Context, route, operation, message string, err error, status string, fields map[string]interface{}) { + WebLogEvent(ctx, WebLogInput{ + Route: route, + Message: message, + Code: errcode.InternalError, + Operation: operation, + Status: status, + Err: err, + ContextFields: fields, + }) +} diff --git a/core/server/web/web_request_helpers.go b/core/server/web/web_request_helpers.go index 4eb75cbf..9718093c 100644 --- a/core/server/web/web_request_helpers.go +++ b/core/server/web/web_request_helpers.go @@ -12,7 +12,6 @@ import ( "sumeru/core/orm" ) -// WebLogInput holds structured web log event fields. type WebLogInput struct { Route string Message string @@ -23,7 +22,6 @@ type WebLogInput struct { ContextFields map[string]interface{} } -// WebLogEvent logs a structured web event using the applog contract. func WebLogEvent(ctx context.Context, in WebLogInput) { contextFields := in.ContextFields if contextFields == nil { @@ -40,10 +38,6 @@ func WebLogEvent(ctx context.Context, in WebLogInput) { Context: contextFields, Err: in.Err, } - emitWebLogEvent(ctx, event) -} - -func emitWebLogEvent(ctx context.Context, event applog.Event) { switch { case event.Err != nil || event.Status == logStatusFailure: if event.Status == "" { @@ -75,7 +69,7 @@ func WebLogf(ctx context.Context, route, format string, args ...interface{}) { }) } -// WebLogNavigation emits an INFO-level audit event for successful navigation (menu, view, module, company). +// WebLogNavigation emits INFO for successful UI navigation. func WebLogNavigation(ctx context.Context, route, operation, message string, fields map[string]interface{}) { WebLogEvent(ctx, WebLogInput{ Route: route, Message: message, Operation: operation, Status: logStatusSuccess, ContextFields: fields, diff --git a/core/server/web/workspace.go b/core/server/web/workspace.go index b6bd7f12..1095613e 100644 --- a/core/server/web/workspace.go +++ b/core/server/web/workspace.go @@ -122,16 +122,7 @@ func respondActionNotFound(w http.ResponseWriter, actionID int) { } func respondWorkspaceLoadError(w http.ResponseWriter, ctx context.Context, err error) { - code := errcode.InternalError - msg := err.Error() - switch { - case strings.Contains(msg, "access denied"): - code = errcode.AccessDenied - case strings.Contains(msg, workspaceErrInvalidID): - code = errcode.ValidationError - case strings.Contains(msg, workspaceErrNoView), strings.Contains(msg, workspaceErrNotFound): - code = errcode.NotFound - } + code, status := classifyWorkspaceLoadError(err) WebLogEvent(ctx, WebLogInput{ Route: workspaceRoute, Message: "load view data failed", @@ -140,23 +131,35 @@ func respondWorkspaceLoadError(w http.ResponseWriter, ctx context.Context, err e Status: logStatusFailure, Err: err, }) - http.Error(w, err.Error(), httpStatusFromWorkspaceError(err)) + http.Error(w, err.Error(), status) } -func httpStatusFromWorkspaceError(err error) int { - message := err.Error() +func classifyWorkspaceLoadError(err error) (code string, status int) { + code = orm.ClassifyLogCode(err) + msg := err.Error() switch { - case strings.Contains(message, workspaceErrInvalidID): - return http.StatusBadRequest - case strings.Contains(message, workspaceErrNoView), strings.Contains(message, workspaceErrNotFound): - return http.StatusNotFound - case strings.Contains(message, "access denied"): - return http.StatusForbidden + case strings.Contains(msg, workspaceErrInvalidID): + return errcode.ValidationError, http.StatusBadRequest + case strings.Contains(msg, workspaceErrNoView), strings.Contains(msg, workspaceErrNotFound): + return errcode.NotFound, http.StatusNotFound + } + switch code { + case errcode.AccessDenied: + return code, http.StatusForbidden + case errcode.RecordNotFound, errcode.NotFound: + return code, http.StatusNotFound + case errcode.ValidationError: + return code, http.StatusBadRequest default: - return http.StatusInternalServerError + return code, http.StatusInternalServerError } } +func httpStatusFromWorkspaceError(err error) int { + _, status := classifyWorkspaceLoadError(err) + return status +} + func logWorkspaceViewOpened(ctx context.Context, route string, req workspaceRequest, actionID int, resolved *resolvedWorkspaceView) { recordID, _ := parsePositiveRecordID(req.recordID) WebLogNavigation(ctx, route, workspaceViewOpenOp, "Workspace view opened", map[string]interface{}{