Better logging of multi-line strings

When a logger needs to dump out a multi-line string (such as an incoming or outgoing REST payload), it now uses a utility to edit the lines to be printed so they include the session ID as a prefix to each line. This is needed to ensure that a query of the log for a given session ID will include multi-line messages for that session correctly.
tucats · Feb 6, 2022 · 172c328 · 172c328
1 parent 2877cde
commit 172c328
Show file tree

Hide file tree

Showing 6 changed files with 27 additions and 10 deletions.
diff --git a/buildver.txt b/buildver.txt
@@ -1 +1 @@
-1.2-439
+1.2-440
diff --git a/server/code.go b/server/code.go
@@ -15,6 +15,7 @@ import (
 	"github.com/tucats/ego/errors"
 	"github.com/tucats/ego/symbols"
 	"github.com/tucats/ego/tokenizer"
+	"github.com/tucats/ego/util"
 )
 
 // CodeHandler is the rest handler that accepts arbitrary Ego code
@@ -51,7 +52,7 @@ func CodeHandler(w http.ResponseWriter, r *http.Request) {
 	_, _ = buf.ReadFrom(r.Body)
 	text := buf.String()
 
-	ui.Debug(ui.ServerLogger, "[%d] %s /code request,\n%s", sessionID, r.Method, text)
+	ui.Debug(ui.ServerLogger, "[%d] %s /code request,\n%s", sessionID, r.Method, util.SessionLog(sessionID, text))
 	ui.Debug(ui.RestLogger, "[%d] User agent: %s", sessionID, r.Header.Get("User-Agent"))
 
 	// Tokenize the input

diff --git a/server/dbtables/rows.go b/server/dbtables/rows.go
@@ -150,7 +150,7 @@ func InsertRows(user string, isAdmin bool, tableName string, sessionID int32, w
 		_, _ = io.Copy(buf, r.Body)
 		rawPayload := buf.String()
 
-		ui.Debug(ui.RestLogger, "[%d] RAW payload:\n%s", sessionID, rawPayload)
+		ui.Debug(ui.RestLogger, "[%d] Raw payload:\n%s", sessionID, util.SessionLog(sessionID, rawPayload))
 
 		// Lets get the rows we are to insert. This is either a row set, or a single object.
 		rowSet := defs.DBRowSet{
@@ -181,7 +181,7 @@ func InsertRows(user string, isAdmin bool, tableName string, sessionID int32, w
 		if ui.LoggerIsActive(ui.RestLogger) {
 			b, _ := json.MarshalIndent(rowSet, ui.JSONIndentPrefix, ui.JSONIndentSpacer)
 
-			ui.Debug(ui.RestLogger, "[%d] Resolved REST Request payload:\n%s", sessionID, string(b))
+			ui.Debug(ui.RestLogger, "[%d] Resolved REST Request payload:\n%s", sessionID, util.SessionLog(sessionID, string(b)))
 		}
 
 		// If at this point we have an empty row set, then just bail out now. Return a success
@@ -459,7 +459,7 @@ func UpdateRows(user string, isAdmin bool, tableName string, sessionID int32, w
 		_, _ = io.Copy(buf, r.Body)
 		rawPayload := buf.String()
 
-		ui.Debug(ui.RestLogger, "[%d] RAW payload:\n%s", sessionID, rawPayload)
+		ui.Debug(ui.RestLogger, "[%d] Raw payload:\n%s", sessionID, util.SessionLog(sessionID, rawPayload))
 
 		// Lets get the rows we are to update. This is either a row set, or a single object.
 		rowSet := defs.DBRowSet{

diff --git a/server/dbtables/rowsAbstract.go b/server/dbtables/rowsAbstract.go
@@ -64,7 +64,7 @@ func InsertAbstractRows(user string, isAdmin bool, tableName string, sessionID i
 		_, _ = io.Copy(buf, r.Body)
 		rawPayload := buf.String()
 
-		ui.Debug(ui.RestLogger, "[%d] RAW payload:\n%s", sessionID, rawPayload)
+		ui.Debug(ui.RestLogger, "[%d] Raw payload:\n%s", sessionID, util.SessionLog(sessionID, rawPayload))
 
 		// Lets get the rows we are to insert. This is either a row set, or a single object.
 		rowSet := defs.DBAbstractRowSet{
@@ -103,7 +103,7 @@ func InsertAbstractRows(user string, isAdmin bool, tableName string, sessionID i
 		if ui.LoggerIsActive(ui.RestLogger) {
 			b, _ := json.MarshalIndent(rowSet, ui.JSONIndentPrefix, ui.JSONIndentSpacer)
 
-			ui.Debug(ui.RestLogger, "[%d] Resolved REST Request payload:\n%s", sessionID, string(b))
+			ui.Debug(ui.RestLogger, "[%d] Resolved REST Request payload:\n%s", sessionID, util.SessionLog(sessionID, string(b)))
 		}
 
 		// If at this point we have an empty row set, then just bail out now. Return a success
@@ -325,7 +325,7 @@ func UpdateAbstractRows(user string, isAdmin bool, tableName string, sessionID i
 		_, _ = io.Copy(buf, r.Body)
 		rawPayload := buf.String()
 
-		ui.Debug(ui.RestLogger, "[%d] RAW payload:\n%s", sessionID, rawPayload)
+		ui.Debug(ui.RestLogger, "[%d] Raw payload:\n%s", sessionID, util.SessionLog(sessionID, rawPayload))
 
 		// Lets get the rows we are to update. This is either a row set, or a single object.
 		rowSet := defs.DBAbstractRowSet{

diff --git a/server/dbtables/tables.go b/server/dbtables/tables.go
@@ -247,7 +247,7 @@ func ReadTable(user string, isAdmin bool, tableName string, sessionID int32, w h
 			"table": tableName,
 		})
 
-		ui.Debug(ui.DebugLogger, "[%d] Read unique with query string: \n%s", sessionID, q)
+		ui.Debug(ui.DebugLogger, "[%d] Read unique with query string: \n%s", sessionID, util.SessionLog(sessionID, q))
 
 		rows, err := db.Query(q)
 		if err != nil {
@@ -278,7 +278,7 @@ func ReadTable(user string, isAdmin bool, tableName string, sessionID int32, w h
 			"quote": "",
 		})
 
-		ui.Debug(ui.DebugLogger, "[%d] Read nullable with query string: \n%s", sessionID, q)
+		ui.Debug(ui.DebugLogger, "[%d] Read nullable with query string: \n%s", sessionID, util.SessionLog(sessionID, q))
 
 		nrows, err := db.Query(q)
 		if err != nil {

diff --git a/util/strings.go b/util/strings.go
@@ -1,8 +1,10 @@
 package util
 
 import (
+	"fmt"
 	"os"
 	"sort"
+	"strings"
 	"unicode"
 )
 
@@ -75,3 +77,17 @@ func StringMapKeys(data map[string]string) []string {
 
 	return keys
 }
+
+// Session log is used to take a multi-line message for the server log,
+// and insert prefixes on each line with the session number so the log
+// lines will be tagged with the appropriate session identifier, and
+// can be read with the server log query for a specific session.
+func SessionLog(id int32, text string) string {
+	lines := strings.Split(text, "\n")
+
+	for n := 0; n < len(lines); n++ {
+		lines[n] = fmt.Sprintf("                                   : [%d] %s", id, lines[n])
+	}
+
+	return strings.Join(lines, "\n")
+}