From 829723543a62ad2f902bc9fcfedc71edab077f0b Mon Sep 17 00:00:00 2001 From: "marko.tikvic" Date: Tue, 13 Aug 2019 11:05:53 +0200 Subject: [PATCH] Improved tracing. Split tracing and HTTP logging in separate files. --- http_logs.go | 64 +++++++++++++++++++++++++++++++++++++ main.go | 103 +++++++++-------------------------------------------------- tracing.go | 65 +++++++++++++++++++++++++++++++++++++ 3 files changed, 144 insertions(+), 88 deletions(-) create mode 100644 http_logs.go create mode 100644 tracing.go diff --git a/http_logs.go b/http_logs.go new file mode 100644 index 0000000..dac0814 --- /dev/null +++ b/http_logs.go @@ -0,0 +1,64 @@ +package gologger + +import ( + "bytes" + "fmt" + "net/http" + "net/http/httputil" + "os" + "strings" + "time" +) + +// LogHTTPRequest ... +func (l *Logger) LogHTTPRequest(req *http.Request, userID string) string { + if userID == "" { + userID = "-" + } + + var b strings.Builder + + b.WriteString("Request:\n") + // CLF-like header + fmt.Fprintf(&b, "%s %s %s\n", req.RemoteAddr, userID, time.Now().Format(dateTimeFormat)) + + body, err := httputil.DumpRequest(req, true) + if err != nil { + fmt.Fprintf(os.Stderr, "%v\n", err) + } + + const sepStr = "\r\n\r\n" + sepIndex := bytes.Index(body, []byte(sepStr)) + if sepIndex == -1 { + b.WriteString(string(body) + "\n\n") + } else { + sepIndex += len(sepStr) + payload, _ := printJSON(body[sepIndex:]) + b.WriteString(string(body[:sepIndex]) + string(payload) + "\n\n") + } + + return b.String() +} + +const splitLine = "==============================================================" + +// LogHTTPResponse ... +func (l *Logger) LogHTTPResponse(status int, duration time.Duration, size int) string { + return fmt.Sprintf("Response:\n%d %v %dB\n%s\n", status, duration, size, splitLine) +} + +// CombineHTTPLogs ... +func (l *Logger) CombineHTTPLogs(in string, out string) { + if l.outputFile == nil { + return + } + + l.mu.Lock() + defer l.mu.Unlock() + + msg := in + out + if l.shouldSplit(len(msg)) { + l.split() + } + l.outputFile.WriteString(msg) +} diff --git a/main.go b/main.go index f772657..a27bbff 100644 --- a/main.go +++ b/main.go @@ -4,17 +4,15 @@ import ( "bytes" "encoding/json" "fmt" - "net/http" - "net/http/httputil" "os" "path/filepath" - "runtime" "strings" "sync" "time" ) const dateTimeFormat = "2006-01-02 15:04:05" +const thisFile = "" // Block ... const ( @@ -89,111 +87,35 @@ func (l *Logger) Print(format string, v ...interface{}) { fmt.Printf("%s: %s\n", time.Now().Format(dateTimeFormat), msg) } -const MaxStackDepth = 10000 - -// CallStack -func CallStack() (stack string) { - callers := make([]uintptr, MaxStackDepth) // min 1 - stackDepth := runtime.Callers(2, callers) - frames := runtime.CallersFrames(callers) - - for i := 0; i < stackDepth; i++ { - if i >= 2 { // skip runtime and startup - frame, next := frames.Next() - stack += fmt.Sprintf("[%s %d]\n", frame.File, frame.Line) - if !next { - break - } - } - } - - return -} - // PrintTrace ... func (l *Logger) PrintTrace(format string, v ...interface{}) { - stack := CallStack() - msg := fmt.Sprintf(format, v...) - fmt.Printf("%s:\n%s\n%s\n", time.Now().Format(dateTimeFormat), stack, msg) + s := getTrace(format, v...) + fmt.Printf("%s", s) } // Trace ... -func (l *Logger) Trace(format string, v ...interface{}) { +func (l *Logger) Trace(format string, v ...interface{}) string { if l.outputFile == nil { - return + return "" } l.mu.Lock() defer l.mu.Unlock() - stack := CallStack() - - msg := fmt.Sprintf(format, v...) - s := fmt.Sprintf("%s:\n%s\n%s\n\n", time.Now().Format(dateTimeFormat), stack, msg) + s := getTrace(format, v...) if l.shouldSplit(len(s)) { l.split() } l.outputFile.WriteString(s) + + return s } // PrintAndTrace ... func (l *Logger) PrintAndTrace(format string, v ...interface{}) { - l.Print(format, v...) - l.Trace(format, v...) -} - -// LogHTTPRequest ... -func (l *Logger) LogHTTPRequest(req *http.Request, userID string) string { - if userID == "" { - userID = "-" - } - - var b strings.Builder - - b.WriteString("Request:\n") - // CLF-like header - fmt.Fprintf(&b, "%s %s %s\n", req.RemoteAddr, userID, time.Now().Format(dateTimeFormat)) - - body, err := httputil.DumpRequest(req, true) - if err != nil { - fmt.Fprintf(os.Stderr, "%v\n", err) - } - - const sepStr = "\r\n\r\n" - sepIndex := bytes.Index(body, []byte(sepStr)) - if sepIndex == -1 { - b.WriteString(string(body) + "\n\n") - } else { - sepIndex += len(sepStr) - payload, _ := printJSON(body[sepIndex:]) - b.WriteString(string(body[:sepIndex]) + string(payload) + "\n\n") - } - - return b.String() -} - -const splitLine = "==============================================================" - -// LogHTTPResponse ... -func (l *Logger) LogHTTPResponse(status int, duration time.Duration, size int) string { - return fmt.Sprintf("Response:\n%d %v %dB\n%s\n", status, duration, size, splitLine) -} - -// CombineHTTPLogs ... -func (l *Logger) CombineHTTPLogs(in string, out string) { - if l.outputFile == nil { - return - } - - l.mu.Lock() - defer l.mu.Unlock() - - msg := in + out - if l.shouldSplit(len(msg)) { - l.split() - } - l.outputFile.WriteString(msg) + t := l.Trace(format, v...) + fmt.Println(t) } // Close ... @@ -234,3 +156,8 @@ func printJSON(in []byte) (out []byte, err error) { err = json.Indent(&buf, in, "", " ") return buf.Bytes(), err } + +// GetOutDir ... +func (l *Logger) GetOutDir() string { + return l.directory +} diff --git a/tracing.go b/tracing.go new file mode 100644 index 0000000..28a6477 --- /dev/null +++ b/tracing.go @@ -0,0 +1,65 @@ +package gologger + +import ( + "fmt" + "math" + "runtime" + "strings" + "time" +) + +// getCallStack +func getCallStack() (stack []string) { + const ( + maxStackDepth = 10000 + skipRuntime = 2 // skip runtime and startup + skipCallers = 2 + thisPackage = "gologger" + ) + + callers := make([]uintptr, maxStackDepth) // min 1 + + stackDepth := runtime.Callers(skipCallers, callers) + frames := runtime.CallersFrames(callers) + + for i := 0; i < skipRuntime; i++ { + frames.Next() + } + + for i := 0; i < stackDepth-skipRuntime-skipCallers; i++ { + frame, next := frames.Next() + if !strings.Contains(frame.File, thisPackage) { + stack = append(stack, fmt.Sprintf("[%s %d]", frame.File, frame.Line)) + } + if !next { + break + } + } + + reverseStack(stack) + + return stack +} + +// in place +func reverseStack(stack []string) { + middle := int(math.Floor(float64(len(stack)) / 2.0)) + + lastIndex := len(stack) - 1 + for i := 0; i < middle; i++ { + stack[i], stack[lastIndex] = stack[lastIndex], stack[i] + lastIndex-- + } +} + +func getTrace(format string, v ...interface{}) (t string) { + stack := getCallStack() + + t = time.Now().Format(dateTimeFormat) + ":\n" + for _, s := range stack { + t += s + "\n" + } + t += fmt.Sprintf(format, v...) + "\n" + + return t +} -- 1.8.1.2