Commit 829723543a62ad2f902bc9fcfedc71edab077f0b

Authored by Marko Tikvić
1 parent 03121daf9b
Exists in master

Improved tracing. Split tracing and HTTP logging in separate files.

Showing 3 changed files with 144 additions and 88 deletions   Show diff stats
File was created 1 package gologger
2
3 import (
4 "bytes"
5 "fmt"
6 "net/http"
7 "net/http/httputil"
8 "os"
9 "strings"
10 "time"
11 )
12
13 // LogHTTPRequest ...
14 func (l *Logger) LogHTTPRequest(req *http.Request, userID string) string {
15 if userID == "" {
16 userID = "-"
17 }
18
19 var b strings.Builder
20
21 b.WriteString("Request:\n")
22 // CLF-like header
23 fmt.Fprintf(&b, "%s %s %s\n", req.RemoteAddr, userID, time.Now().Format(dateTimeFormat))
24
25 body, err := httputil.DumpRequest(req, true)
26 if err != nil {
27 fmt.Fprintf(os.Stderr, "%v\n", err)
28 }
29
30 const sepStr = "\r\n\r\n"
31 sepIndex := bytes.Index(body, []byte(sepStr))
32 if sepIndex == -1 {
33 b.WriteString(string(body) + "\n\n")
34 } else {
35 sepIndex += len(sepStr)
36 payload, _ := printJSON(body[sepIndex:])
37 b.WriteString(string(body[:sepIndex]) + string(payload) + "\n\n")
38 }
39
40 return b.String()
41 }
42
43 const splitLine = "=============================================================="
44
45 // LogHTTPResponse ...
46 func (l *Logger) LogHTTPResponse(status int, duration time.Duration, size int) string {
47 return fmt.Sprintf("Response:\n%d %v %dB\n%s\n", status, duration, size, splitLine)
48 }
49
50 // CombineHTTPLogs ...
51 func (l *Logger) CombineHTTPLogs(in string, out string) {
52 if l.outputFile == nil {
53 return
54 }
55
56 l.mu.Lock()
57 defer l.mu.Unlock()
58
59 msg := in + out
60 if l.shouldSplit(len(msg)) {
61 l.split()
62 }
63 l.outputFile.WriteString(msg)
64 }
65
1 package gologger 1 package gologger
2 2
3 import ( 3 import (
4 "bytes" 4 "bytes"
5 "encoding/json" 5 "encoding/json"
6 "fmt" 6 "fmt"
7 "net/http"
8 "net/http/httputil"
9 "os" 7 "os"
10 "path/filepath" 8 "path/filepath"
11 "runtime"
12 "strings" 9 "strings"
13 "sync" 10 "sync"
14 "time" 11 "time"
15 ) 12 )
16 13
17 const dateTimeFormat = "2006-01-02 15:04:05" 14 const dateTimeFormat = "2006-01-02 15:04:05"
15 const thisFile = ""
18 16
19 // Block ... 17 // Block ...
20 const ( 18 const (
21 MaxLogSize5MB int64 = 5 * 1024 * 1024 19 MaxLogSize5MB int64 = 5 * 1024 * 1024
22 MaxLogSize1MB int64 = 1 * 1024 * 1024 20 MaxLogSize1MB int64 = 1 * 1024 * 1024
23 MaxLogSize500KB int64 = 500 * 1024 21 MaxLogSize500KB int64 = 500 * 1024
24 MaxLogSize100KB int64 = 100 * 1024 22 MaxLogSize100KB int64 = 100 * 1024
25 MaxLogSize512B int64 = 512 23 MaxLogSize512B int64 = 512
26 ) 24 )
27 25
28 // Logger ... 26 // Logger ...
29 type Logger struct { 27 type Logger struct {
30 mu *sync.Mutex 28 mu *sync.Mutex
31 outputFile *os.File 29 outputFile *os.File
32 30
33 outputFileName string 31 outputFileName string
34 fullName string 32 fullName string
35 maxFileSize int64 33 maxFileSize int64
36 34
37 splitCount int 35 splitCount int
38 36
39 directory string 37 directory string
40 } 38 }
41 39
42 // New ... 40 // New ...
43 func New(name, dir string, maxFileSize int64) (logger *Logger, err error) { 41 func New(name, dir string, maxFileSize int64) (logger *Logger, err error) {
44 logger = &Logger{} 42 logger = &Logger{}
45 43
46 logger.outputFileName = name 44 logger.outputFileName = name
47 logger.mu = &sync.Mutex{} 45 logger.mu = &sync.Mutex{}
48 logger.maxFileSize = maxFileSize 46 logger.maxFileSize = maxFileSize
49 logger.directory = dir 47 logger.directory = dir
50 48
51 err = os.Mkdir(dir, os.ModePerm) 49 err = os.Mkdir(dir, os.ModePerm)
52 if err != nil { 50 if err != nil {
53 if !os.IsExist(err) { 51 if !os.IsExist(err) {
54 return nil, err 52 return nil, err
55 } 53 }
56 } 54 }
57 55
58 date := strings.Replace(time.Now().Format(dateTimeFormat), ":", ".", -1) 56 date := strings.Replace(time.Now().Format(dateTimeFormat), ":", ".", -1)
59 logger.outputFileName += " " + date 57 logger.outputFileName += " " + date
60 logger.fullName = logger.outputFileName + ".txt" 58 logger.fullName = logger.outputFileName + ".txt"
61 path := filepath.Join(dir, logger.fullName) 59 path := filepath.Join(dir, logger.fullName)
62 if logger.outputFile, err = os.Create(path); err != nil { 60 if logger.outputFile, err = os.Create(path); err != nil {
63 return nil, err 61 return nil, err
64 } 62 }
65 63
66 return logger, nil 64 return logger, nil
67 } 65 }
68 66
69 // Log ... 67 // Log ...
70 func (l *Logger) Log(format string, v ...interface{}) { 68 func (l *Logger) Log(format string, v ...interface{}) {
71 if l.outputFile == nil { 69 if l.outputFile == nil {
72 return 70 return
73 } 71 }
74 72
75 l.mu.Lock() 73 l.mu.Lock()
76 defer l.mu.Unlock() 74 defer l.mu.Unlock()
77 75
78 msg := fmt.Sprintf(format, v...) 76 msg := fmt.Sprintf(format, v...)
79 s := time.Now().Format(dateTimeFormat) + ": " + msg + "\n" 77 s := time.Now().Format(dateTimeFormat) + ": " + msg + "\n"
80 if l.shouldSplit(len(s)) { 78 if l.shouldSplit(len(s)) {
81 l.split() 79 l.split()
82 } 80 }
83 l.outputFile.WriteString(s) 81 l.outputFile.WriteString(s)
84 } 82 }
85 83
86 // Print ... 84 // Print ...
87 func (l *Logger) Print(format string, v ...interface{}) { 85 func (l *Logger) Print(format string, v ...interface{}) {
88 msg := fmt.Sprintf(format, v...) 86 msg := fmt.Sprintf(format, v...)
89 fmt.Printf("%s: %s\n", time.Now().Format(dateTimeFormat), msg) 87 fmt.Printf("%s: %s\n", time.Now().Format(dateTimeFormat), msg)
90 } 88 }
91 89
92 const MaxStackDepth = 10000
93
94 // CallStack
95 func CallStack() (stack string) {
96 callers := make([]uintptr, MaxStackDepth) // min 1
97 stackDepth := runtime.Callers(2, callers)
98 frames := runtime.CallersFrames(callers)
99
100 for i := 0; i < stackDepth; i++ {
101 if i >= 2 { // skip runtime and startup
102 frame, next := frames.Next()
103 stack += fmt.Sprintf("[%s %d]\n", frame.File, frame.Line)
104 if !next {
105 break
106 }
107 }
108 }
109
110 return
111 }
112
113 // PrintTrace ... 90 // PrintTrace ...
114 func (l *Logger) PrintTrace(format string, v ...interface{}) { 91 func (l *Logger) PrintTrace(format string, v ...interface{}) {
115 stack := CallStack() 92 s := getTrace(format, v...)
116 msg := fmt.Sprintf(format, v...) 93 fmt.Printf("%s", s)
117 fmt.Printf("%s:\n%s\n%s\n", time.Now().Format(dateTimeFormat), stack, msg)
118 } 94 }
119 95
120 // Trace ... 96 // Trace ...
121 func (l *Logger) Trace(format string, v ...interface{}) { 97 func (l *Logger) Trace(format string, v ...interface{}) string {
122 if l.outputFile == nil { 98 if l.outputFile == nil {
123 return 99 return ""
124 } 100 }
125 101
126 l.mu.Lock() 102 l.mu.Lock()
127 defer l.mu.Unlock() 103 defer l.mu.Unlock()
128 104
129 stack := CallStack() 105 s := getTrace(format, v...)
130
131 msg := fmt.Sprintf(format, v...)
132 s := fmt.Sprintf("%s:\n%s\n%s\n\n", time.Now().Format(dateTimeFormat), stack, msg)
133 106
134 if l.shouldSplit(len(s)) { 107 if l.shouldSplit(len(s)) {
135 l.split() 108 l.split()
136 } 109 }
137 l.outputFile.WriteString(s) 110 l.outputFile.WriteString(s)
111
112 return s
138 } 113 }
139 114
140 // PrintAndTrace ... 115 // PrintAndTrace ...
141 func (l *Logger) PrintAndTrace(format string, v ...interface{}) { 116 func (l *Logger) PrintAndTrace(format string, v ...interface{}) {
142 l.Print(format, v...) 117 t := l.Trace(format, v...)
143 l.Trace(format, v...) 118 fmt.Println(t)
144 }
145
146 // LogHTTPRequest ...
147 func (l *Logger) LogHTTPRequest(req *http.Request, userID string) string {
148 if userID == "" {
149 userID = "-"
150 }
151
152 var b strings.Builder
153
154 b.WriteString("Request:\n")
155 // CLF-like header
156 fmt.Fprintf(&b, "%s %s %s\n", req.RemoteAddr, userID, time.Now().Format(dateTimeFormat))
157
158 body, err := httputil.DumpRequest(req, true)
159 if err != nil {
160 fmt.Fprintf(os.Stderr, "%v\n", err)
161 }
162
163 const sepStr = "\r\n\r\n"
164 sepIndex := bytes.Index(body, []byte(sepStr))
165 if sepIndex == -1 {
166 b.WriteString(string(body) + "\n\n")
167 } else {
168 sepIndex += len(sepStr)
169 payload, _ := printJSON(body[sepIndex:])
170 b.WriteString(string(body[:sepIndex]) + string(payload) + "\n\n")
171 }
172
173 return b.String()
174 }
175
176 const splitLine = "=============================================================="
177
178 // LogHTTPResponse ...
179 func (l *Logger) LogHTTPResponse(status int, duration time.Duration, size int) string {
180 return fmt.Sprintf("Response:\n%d %v %dB\n%s\n", status, duration, size, splitLine)
181 }
182
183 // CombineHTTPLogs ...
184 func (l *Logger) CombineHTTPLogs(in string, out string) {
185 if l.outputFile == nil {
186 return
187 }
188
189 l.mu.Lock()
190 defer l.mu.Unlock()
191
192 msg := in + out
193 if l.shouldSplit(len(msg)) {
194 l.split()
195 }
196 l.outputFile.WriteString(msg)
197 } 119 }
198 120
199 // Close ... 121 // Close ...
200 func (l *Logger) Close() error { 122 func (l *Logger) Close() error {
201 if l.outputFile == nil { 123 if l.outputFile == nil {
202 return nil 124 return nil
203 } 125 }
204 126
205 return l.outputFile.Close() 127 return l.outputFile.Close()
206 } 128 }
207 129
208 func (l *Logger) split() error { 130 func (l *Logger) split() error {
209 if l.outputFile == nil { 131 if l.outputFile == nil {
210 return nil 132 return nil
211 } 133 }
212 134
213 // close old file 135 // close old file
214 err := l.outputFile.Close() 136 err := l.outputFile.Close()
215 if err != nil { 137 if err != nil {
216 return err 138 return err
217 } 139 }
218 140
219 // open new file 141 // open new file
220 l.splitCount++ 142 l.splitCount++
221 path := filepath.Join(l.directory, l.outputFileName+fmt.Sprintf("(%d)", l.splitCount)+".txt") 143 path := filepath.Join(l.directory, l.outputFileName+fmt.Sprintf("(%d)", l.splitCount)+".txt")
222 l.outputFile, err = os.Create(path) 144 l.outputFile, err = os.Create(path)
223 145
224 return err 146 return err
225 } 147 }
226 148
227 func (l *Logger) shouldSplit(nextEntrySize int) bool { 149 func (l *Logger) shouldSplit(nextEntrySize int) bool {
228 stats, _ := l.outputFile.Stat() 150 stats, _ := l.outputFile.Stat()
229 return int64(nextEntrySize) >= (l.maxFileSize - stats.Size()) 151 return int64(nextEntrySize) >= (l.maxFileSize - stats.Size())
230 } 152 }
231 153
232 func printJSON(in []byte) (out []byte, err error) { 154 func printJSON(in []byte) (out []byte, err error) {
233 var buf bytes.Buffer 155 var buf bytes.Buffer
234 err = json.Indent(&buf, in, "", " ") 156 err = json.Indent(&buf, in, "", " ")
File was created 1 package gologger
2
3 import (
4 "fmt"
5 "math"
6 "runtime"
7 "strings"
8 "time"
9 )
10
11 // getCallStack
12 func getCallStack() (stack []string) {
13 const (
14 maxStackDepth = 10000
15 skipRuntime = 2 // skip runtime and startup
16 skipCallers = 2
17 thisPackage = "gologger"
18 )
19
20 callers := make([]uintptr, maxStackDepth) // min 1
21
22 stackDepth := runtime.Callers(skipCallers, callers)
23 frames := runtime.CallersFrames(callers)
24
25 for i := 0; i < skipRuntime; i++ {
26 frames.Next()
27 }
28
29 for i := 0; i < stackDepth-skipRuntime-skipCallers; i++ {
30 frame, next := frames.Next()
31 if !strings.Contains(frame.File, thisPackage) {
32 stack = append(stack, fmt.Sprintf("[%s %d]", frame.File, frame.Line))
33 }
34 if !next {
35 break
36 }
37 }
38
39 reverseStack(stack)
40
41 return stack
42 }
43
44 // in place
45 func reverseStack(stack []string) {
46 middle := int(math.Floor(float64(len(stack)) / 2.0))
47
48 lastIndex := len(stack) - 1
49 for i := 0; i < middle; i++ {
50 stack[i], stack[lastIndex] = stack[lastIndex], stack[i]
51 lastIndex--
52 }
53 }
54
55 func getTrace(format string, v ...interface{}) (t string) {
56 stack := getCallStack()
57
58 t = time.Now().Format(dateTimeFormat) + ":\n"
59 for _, s := range stack {
60 t += s + "\n"
61 }
62 t += fmt.Sprintf(format, v...) + "\n"
63
64 return t
65 }
66