diff --git a/.vscode/launch.json b/.vscode/launch.json index 4551e749..97160102 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -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", diff --git a/app-cli/app/actions.go b/app-cli/app/actions.go index 469b66b0..04c7924c 100644 --- a/app-cli/app/actions.go +++ b/app-cli/app/actions.go @@ -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 { diff --git a/app-cli/app/app.go b/app-cli/app/app.go index 18bd7f85..55fef0f1 100644 --- a/app-cli/app/app.go +++ b/app-cli/app/app.go @@ -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 diff --git a/app-cli/app/library.go b/app-cli/app/library.go index c8dda15c..b853f5fa 100644 --- a/app-cli/app/library.go +++ b/app-cli/app/library.go @@ -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 } diff --git a/app-cli/app/run.go b/app-cli/app/run.go index 0e3f64ba..06cfb3a0 100644 --- a/app-cli/app/run.go +++ b/app-cli/app/run.go @@ -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", diff --git a/app-cli/cli/query.go b/app-cli/cli/query.go index 4ff71da0..63024d88 100644 --- a/app-cli/cli/query.go +++ b/app-cli/cli/query.go @@ -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 { diff --git a/app-cli/ui/messaging.go b/app-cli/ui/messaging.go index 58893b05..3f4e5275 100644 --- a/app-cli/ui/messaging.go +++ b/app-cli/ui/messaging.go @@ -4,11 +4,13 @@ package ui import ( + "encoding/json" "fmt" "strings" "sync" "time" + "github.com/tucats/ego/defs" "github.com/tucats/ego/i18n" ) @@ -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 @@ -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() @@ -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 diff --git a/app-cli/ui/messaging_test.go b/app-cli/ui/messaging_test.go index 25a29c1a..571b8741 100644 --- a/app-cli/ui/messaging_test.go +++ b/app-cli/ui/messaging_test.go @@ -4,6 +4,7 @@ package ui import ( + "os" "testing" ) @@ -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 diff --git a/commands/routes.go b/commands/routes.go index 847f8242..75f67a88 100644 --- a/commands/routes.go +++ b/commands/routes.go @@ -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") diff --git a/commands/server.go b/commands/server.go index e2c69280..bf40e96a 100644 --- a/commands/server.go +++ b/commands/server.go @@ -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. @@ -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 @@ -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 { diff --git a/defs/config.go b/defs/config.go index 50316d40..3e132002 100644 --- a/defs/config.go +++ b/defs/config.go @@ -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." @@ -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 diff --git a/defs/rest.go b/defs/rest.go index d6271d48..07b81848 100644 --- a/defs/rest.go +++ b/defs/rest.go @@ -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 diff --git a/i18n/languages/messages_en.txt b/i18n/languages/messages_en.txt index 262d222e..882027f2 100644 --- a/i18n/languages/messages_en.txt +++ b/i18n/languages/messages_en.txt @@ -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 @@ -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 @@ -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}} \ No newline at end of file diff --git a/main.go b/main.go index c06497c7..9b7197bb 100644 --- a/main.go +++ b/main.go @@ -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 @@ -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")). diff --git a/server/server/router.go b/server/server/router.go index 87c35f3f..4cf4b676 100644 --- a/server/server/router.go +++ b/server/server/router.go @@ -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{ diff --git a/server/server/serve.go b/server/server/serve.go index 893a7a87..2f12e0bb 100644 --- a/server/server/serve.go +++ b/server/server/serve.go @@ -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. diff --git a/server/services/child.go b/server/services/child.go index 9704b7aa..11242f25 100644 --- a/server/services/child.go +++ b/server/services/child.go @@ -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") diff --git a/server/services/service.go b/server/services/service.go index 06761330..7d87daca 100644 --- a/server/services/service.go +++ b/server/services/service.go @@ -343,7 +343,7 @@ func setupServerSymbols(r *http.Request, session *server.Session, requestor stri // Define information we know about our running session and the caller, independent of // the service being invoked. symbolTable.SetAlways(defs.PidVariable, os.Getpid()) - symbolTable.SetAlways(defs.InstanceUUIDVariable, defs.ServerInstanceID) + symbolTable.SetAlways(defs.InstanceUUIDVariable, defs.InstanceID) symbolTable.SetAlways(defs.SessionVariable, session.ID) symbolTable.SetAlways(defs.MethodVariable, r.Method) symbolTable.SetAlways(defs.ModeVariable, "server") diff --git a/util/rest.go b/util/rest.go index 78228f5f..960df33d 100644 --- a/util/rest.go +++ b/util/rest.go @@ -17,7 +17,7 @@ func MakeServerInfo(sessionID int) defs.ServerInfo { hostName := Hostname() result := defs.ServerInfo{ Hostname: hostName, - ID: defs.ServerInstanceID, + ID: defs.InstanceID, Session: sessionID, Version: defs.APIVersion, }