Skip to content

Commit

Permalink
feat: allow logs to be formatted as JSON
Browse files Browse the repository at this point in the history
ego.console.log.format can be "text", "json", or "indented" and affects the format
of log messages sent to the console or a log file.

If log messages are localized text with "log." prefix, they will be converted and
the argument map appaers in the JSON. Otherwise, the JSON contains the text of the
log message as generated for text output.

Conversion of log messages to localized format will support language-independent
log files. A future change will allow the ego log command to translate JSON log
files back to text in the current localization.
  • Loading branch information
tucats committed Jan 19, 2025
1 parent b07664b commit 9eb9318
Show file tree
Hide file tree
Showing 19 changed files with 167 additions and 23 deletions.
4 changes: 2 additions & 2 deletions .vscode/launch.json
Original file line number Diff line number Diff line change
Expand Up @@ -228,8 +228,8 @@
"request": "launch",
"mode": "debug",
"program": "${workspaceFolder}",
"env": {"EGO_DEFAULT_LOGGING":"APP"},
"args": ["-p", "server", "config", "show"]
"env": {"EGO_DEFAULT_LOGGING":"APP","EGO_LOG_FORMAT":"json"},
"args": ["run", "test.ego"]
},
{
"name": "Detached ego server",
Expand Down
16 changes: 16 additions & 0 deletions app-cli/app/actions.go
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,22 @@ func OutputFormatAction(c *cli.Context) error {
return nil
}

// LogFormatAction sets the default log format to use. This must be one of
// the supported types "test"", "json"", or "indented").
func LogFormatAction(c *cli.Context) error {
if formatString, present := c.FindGlobal().String("log-format"); present {
if !util.InList(strings.ToLower(formatString),
ui.JSONIndentedFormat, ui.JSONFormat, ui.TextFormat) {
return errors.ErrInvalidOutputFormat.Context(formatString)
}

ui.LogFormat = strings.ToLower(formatString)
settings.SetDefault(defs.LogFormatSetting, ui.LogFormat)
}

return nil
}

// LanguageAction sets the default language to use. This must be one of the
// supported languages ("en", "es", "fr", "de", "it", "pt", "ru", "zh").
func LanguageAction(c *cli.Context) error {
Expand Down
1 change: 1 addition & 0 deletions app-cli/app/app.go
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,7 @@ func New(appName string) *App {
appName = strings.TrimSpace(appName[:i])
}

// Build the App object
app := &App{Name: appName, Description: appDescription}

return app
Expand Down
2 changes: 1 addition & 1 deletion app-cli/app/library.go
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ func LibraryInit() error {
}

if _, err = os.Stat(path); err == nil {
ui.Log(ui.AppLogger, "Runtime library found at %s", path)
ui.Log(ui.AppLogger, "log.runtime.lib.path", map[string]interface{}{"path": path})

return nil
}
Expand Down
8 changes: 8 additions & 0 deletions app-cli/app/run.go
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,14 @@ func runFromContext(context *cli.Context) error {
Action: OutputFormatAction,
EnvVar: "EGO_OUTPUT_FORMAT",
},
{
LongName: "log-format",
Description: "global.log.format",
OptionType: cli.KeywordType,
Keywords: []string{ui.JSONFormat, ui.JSONIndentedFormat, ui.TextFormat},
Action: LogFormatAction,
EnvVar: "EGO_LOG_FORMAT",
},
{
ShortName: "v",
LongName: "version",
Expand Down
6 changes: 3 additions & 3 deletions app-cli/cli/query.go
Original file line number Diff line number Diff line change
Expand Up @@ -105,9 +105,9 @@ func (c *Context) Boolean(name string) bool {
func (c *Context) String(name string) (string, bool) {
for _, entry := range c.Grammar {
if entry.OptionType == Subcommand && entry.Found {
subContext := entry.Value.(Context)

return subContext.String(name)
if subContext, ok := entry.Value.(Context); ok {
return subContext.String(name)
}
}

if entry.Found && (entry.OptionType == StringListType || entry.OptionType == KeywordType || entry.OptionType == UUIDType || entry.OptionType == StringType) && name == entry.LongName {
Expand Down
101 changes: 98 additions & 3 deletions app-cli/ui/messaging.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,13 @@
package ui

import (
"encoding/json"
"fmt"
"strings"
"sync"
"time"

"github.com/tucats/ego/defs"
"github.com/tucats/ego/i18n"
)

Expand All @@ -35,10 +37,23 @@ const (
NoSuchLogger = -1
)

type LogEntry struct {
Timestamp string `json:"time"`
ID string `json:"id"`
Sequence int `json:"seq"`
Session int `json:"session,omitempty"`
Class string `json:"class"`
Message string `json:"msg"`
Args map[string]interface{} `json:"args,omitempty"`
}

// OutputFormat is the default output format if not overridden by a global option
// or explicit call from the user.
var OutputFormat = TextFormat

// Format for logging messages. (text or JSON).
var LogFormat = TextFormat

// QuietMode determines if optional messaging is performed.
var QuietMode = false

Expand Down Expand Up @@ -271,9 +286,6 @@ func formatLogMessage(class int, format string, args ...interface{}) string {
return ""
}

className := loggers[class].name
s := fmt.Sprintf(format, args...)

sequenceMux.Lock()
defer sequenceMux.Unlock()

Expand All @@ -284,11 +296,94 @@ func formatLogMessage(class int, format string, args ...interface{}) string {
LogTimeStampFormat = "2006-01-02 15:04:05"
}

if LogFormat != TextFormat {
text, err := formatJSONLogEntry(class, format, args)
if err != nil {
return fmt.Sprintf("Error formatting JSON log entry: %v", err)
}

return text
}

// Not JSON logging, but let's get the localized version of the log message if there is one.
// If the argument is a map, use it to localize the message.
if len(args) > 0 {
if argsMap, ok := args[0].(map[string]interface{}); ok {
format = i18n.T(format, argsMap)
args = args[1:]
}
} else {
format = i18n.T(format)
}

className := loggers[class].name
s := fmt.Sprintf(format, args...)

s = fmt.Sprintf("[%s] %-5s %-7s: %s", time.Now().Format(LogTimeStampFormat), sequenceString, className, s)

return s
}

func formatJSONLogEntry(class int, format string, args []interface{}) (string, error) {
var (
err error
jsonBytes []byte
)

entry := LogEntry{
Timestamp: time.Now().Format(LogTimeStampFormat),
Class: strings.ToLower(loggers[class].name),
ID: defs.InstanceID,
Sequence: sequence,
}

// Is this a message with a localized value?
if i18n.T(format) != format {
entry.Message = format
// Look for a map which will be used for args, or an integer which is the thread number
for n, arg := range args {
if argsMap, ok := arg.(map[string]interface{}); ok {
entry.Args = argsMap

continue
}

if thread, ok := arg.(int); ok {
entry.Session = thread

continue
}

if entry.Args == nil {
entry.Args = make(map[string]interface{})
}

entry.Args[fmt.Sprintf("arg%d", n+1)] = arg
}
} else {
// Not a formatted log message. But, if it starts with a thread id, then extract it and format the message accordingly
format = strings.TrimSpace(format)
if strings.HasPrefix(format, "[%d] ") {
if thread, ok := args[0].(int); ok {
format = format[3:]
entry.Session = thread
args = args[1:]
}
}

entry.Message = fmt.Sprintf(format, args...)
}

// Format the entry as a JSON string
if LogFormat == JSONFormat {
jsonBytes, err = json.Marshal(entry)
} else {
jsonBytes, err = json.MarshalIndent(entry, "", " ")
}

return string(jsonBytes), err
}

// Say displays a message to the user unless we are in "quiet" mode.
// If there are no arguments, the format string is output without
// further processing (that is, safe even if it contains formatting
Expand Down
6 changes: 6 additions & 0 deletions app-cli/ui/messaging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
package ui

import (
"os"
"testing"
)

Expand Down Expand Up @@ -41,6 +42,11 @@ func TestLogMessage(t *testing.T) {

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
// Tests assume TextFormat is the default output format
LogFormat = TextFormat

os.Setenv("EGO_LOG_FORMAT", "text")

logger := LoggerByName(tt.args.class)
got := formatLogMessage(logger, tt.args.format, tt.args.args...)
// Mask out the parts that are variable and un-testable, which
Expand Down
2 changes: 1 addition & 1 deletion commands/routes.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ const (
func defineStaticRoutes() *server.Router {
// Let's use a private router for more flexibility with path patterns and providing session
// context to the handler functions.
router := server.NewRouter(defs.ServerInstanceID)
router := server.NewRouter(defs.InstanceID)

// Establish the admin endpoints
ui.Log(ui.ServerLogger, "Enabling /admin endpoints")
Expand Down
11 changes: 6 additions & 5 deletions commands/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ func RunServer(c *cli.Context) error {
}
}

ui.Log(ui.ServerLogger, "Starting server (Ego %s), instance %s", c.Version, defs.ServerInstanceID)
ui.Log(ui.ServerLogger, "Starting server (Ego %s), instance %s", c.Version, defs.InstanceID)
ui.Log(ui.ServerLogger, "Active loggers: %s", ui.ActiveLoggers())

// Did we generate a new token? Now's a good time to log this.
Expand Down Expand Up @@ -320,12 +320,13 @@ func setServerDefaults(c *cli.Context) (string, string, error) {
// we'll use the default value created during symbol table startup.
var found bool

defs.ServerInstanceID, found = c.String("session-uuid")
defs.InstanceID, found = c.String("session-uuid")
if found {
symbols.RootSymbolTable.SetAlways(defs.InstanceUUIDVariable, defs.ServerInstanceID)
symbols.RootSymbolTable.SetAlways(defs.InstanceUUIDVariable, defs.InstanceID)
ui.Log(ui.AppLogger, "Explicit session ID set to: %s", defs.InstanceID)
} else {
s, _ := symbols.RootSymbolTable.Get(defs.InstanceUUIDVariable)
defs.ServerInstanceID = data.String(s)
defs.InstanceID = data.String(s)
}

server.Version = c.Version
Expand Down Expand Up @@ -558,7 +559,7 @@ func redirectToHTTPS(insecure, secure int, router *server.Router) {

// Stamp the response with the instance ID of this server and the
// session ID for this request.
w.Header()[defs.EgoServerInstanceHeader] = []string{fmt.Sprintf("%s:%d", defs.ServerInstanceID, sessionID)}
w.Header()[defs.EgoServerInstanceHeader] = []string{fmt.Sprintf("%s:%d", defs.InstanceID, sessionID)}

host := r.Host
if i := strings.Index(host, ":"); i >= 0 {
Expand Down
5 changes: 5 additions & 0 deletions defs/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,10 @@ const (
// that could return either "text" , "indented", or "json" output.
OutputFormatSetting = ConsoleKeyPrefix + "output"

// What is the log format that should be used by default for logging.
// Valid choices are "text", "json", and "indented".
LogFormatSetting = ConsoleKeyPrefix + "log"

// TABLE CONFIGURATION KEYS
//The prefix for database table configuration keys.
TableKeyPrefix = PrivilegedKeyPrefix + "table."
Expand Down Expand Up @@ -373,6 +377,7 @@ var ValidSettings map[string]bool = map[string]bool{
UnusedVarsSetting: true,
UnusedVarLoggingSetting: true,
ServerReportFQDNSetting: true,
LogFormatSetting: true,
}

// RestrictedSettings is a list of settings that cannot be read using the
Expand Down
4 changes: 2 additions & 2 deletions defs/rest.go
Original file line number Diff line number Diff line change
Expand Up @@ -96,5 +96,5 @@ const (
EgoServerInstanceHeader = "X-Ego-Server"
)

// ServerInstanceID is the UUID of the current Server Instance.
var ServerInstanceID string
// InstanceID is the UUID of the current Server Instance.
var InstanceID string
6 changes: 6 additions & 0 deletions i18n/languages/messages_en.txt
Original file line number Diff line number Diff line change
Expand Up @@ -488,6 +488,7 @@ filter=List of optional filter clauses
global.archive-log=Name of archive for purged log files, if any
global.format=Specify text, json or indented output format
global.log=Loggers to enable
global.log.format=Specify text, json, or indented log format
global.log.file=Name of file where log messages are written
global.maxcpus=Maximum number of cpus to use to schedule Go routines
global.profile=Name of profile to use
Expand Down Expand Up @@ -581,6 +582,7 @@ compiler.types=Specify strict, relaxed, or dynamic types
compiler.unused.var.error=If true, variables created or set but not read are an error
compiler.var.usage.logging=If true, include COMPILER log messages for variable usage
console.format=Specify output format of text, json, or indented
console.log=Specify log format of text, json, or indented
console.no.copyright=Suppress the copyright message
console.exit.on.blank=If true, exit REPL mode on a blank line
console.output=Specify output destination of stdout or file
Expand Down Expand Up @@ -646,3 +648,7 @@ table.insert=table-name [column=value...]
table.name=table-name
table.update=table-name column=value [column=value...]

# The "log" section is for logging messages

[log]
runtime.lib.path=Runtime library found at {{path}}
6 changes: 6 additions & 0 deletions main.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,9 +11,11 @@ import (
"github.com/tucats/ego/bytecode"
"github.com/tucats/ego/commands"
"github.com/tucats/ego/data"
"github.com/tucats/ego/defs"
"github.com/tucats/ego/errors"
"github.com/tucats/ego/i18n"
"github.com/tucats/ego/profiling"
"github.com/tucats/ego/symbols"
)

// BuildVersion is the incremental build version. This is normally
Expand All @@ -30,6 +32,10 @@ var Copyright = "(C) Copyright Tom Cole 2020 - 2025"
func main() {
start := time.Now()

if id, found := symbols.RootSymbolTable.Get("_instance"); found {
defs.InstanceID = id.(string)
}

// Create a new Ego application object, and set the application's
// attributes such as version, copyright string, etc.
app := app.New("ego: " + i18n.T("ego")).
Expand Down
2 changes: 1 addition & 1 deletion server/server/router.go
Original file line number Diff line number Diff line change
Expand Up @@ -190,7 +190,7 @@ type Router struct {
// instance if not specified.
func NewRouter(name string) *Router {
if name == "" {
name = defs.ServerInstanceID
name = defs.InstanceID
}

mux := Router{
Expand Down
2 changes: 1 addition & 1 deletion server/server/serve.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ func (m *Router) ServeHTTP(w http.ResponseWriter, r *http.Request) {

// Stamp the response with the instance ID of this server and the
// session ID for this request.
w.Header()[defs.EgoServerInstanceHeader] = []string{fmt.Sprintf("%s:%d", defs.ServerInstanceID, sessionID)}
w.Header()[defs.EgoServerInstanceHeader] = []string{fmt.Sprintf("%s:%d", defs.InstanceID, sessionID)}

// Problem with the path? Log it based on whether the method was not found or
// unsupported.
Expand Down
4 changes: 2 additions & 2 deletions server/services/child.go
Original file line number Diff line number Diff line change
Expand Up @@ -299,11 +299,11 @@ func ChildService(filename string) error {
symbolTable := symbols.NewRootSymbolTable(r.Method + " " + data.SanitizeName(r.Path))

// Some globals must be set up as if this was a server instance.
defs.ServerInstanceID = r.ServerID
defs.InstanceID = r.ServerID

symbolTable.SetAlways(defs.StartTimeVariable, r.StartTime)
symbolTable.SetAlways(defs.PidVariable, os.Getpid())
symbolTable.SetAlways(defs.InstanceUUIDVariable, defs.ServerInstanceID)
symbolTable.SetAlways(defs.InstanceUUIDVariable, defs.InstanceID)
symbolTable.SetAlways(defs.SessionVariable, r.SessionID)
symbolTable.SetAlways(defs.MethodVariable, r.Method)
symbolTable.SetAlways(defs.ModeVariable, "server")
Expand Down
Loading

0 comments on commit 9eb9318

Please sign in to comment.