logger.go (6256B)
1 package logging 2 3 import ( 4 "encoding/json" 5 "fmt" 6 "github.com/sirupsen/logrus" 7 "net/http" 8 "os" 9 "strings" 10 "time" 11 ) 12 13 var Logger *logrus.Logger 14 15 // The of cookies which should not be logged 16 var AccessLogCookiesBlacklist = []string{} 17 18 var LifecycleEnvVars = []string{"BUILD_NUMBER", "BUILD_HASH", "BUILD_DATE"} 19 20 func init() { 21 Set("info", false) 22 } 23 24 // Set creates a new Logger with the matching specification 25 func Set(level string, textLogging bool) error { 26 l, err := logrus.ParseLevel(level) 27 if err != nil { 28 return err 29 } 30 31 logger := logrus.New() 32 if textLogging { 33 logger.Formatter = &logrus.TextFormatter{} 34 } else { 35 logger.Formatter = &LogstashFormatter{TimestampFormat: time.RFC3339Nano} 36 } 37 logger.Level = l 38 Logger = logger 39 return nil 40 } 41 42 // Access logs an access entry with call duration and status code 43 func Access(r *http.Request, start time.Time, statusCode int) { 44 e := access(r, start, statusCode, nil) 45 46 var msg string 47 if len(r.URL.RawQuery) == 0 { 48 msg = fmt.Sprintf("%v ->%v %v", statusCode, r.Method, r.URL.Path) 49 } else { 50 msg = fmt.Sprintf("%v ->%v %v?...", statusCode, r.Method, r.URL.Path) 51 } 52 53 if statusCode >= 200 && statusCode <= 399 { 54 e.Info(msg) 55 } else if statusCode >= 400 && statusCode <= 499 { 56 e.Warn(msg) 57 } else { 58 e.Error(msg) 59 } 60 } 61 62 // AccessError logs an error while accessing 63 func AccessError(r *http.Request, start time.Time, err error) { 64 e := access(r, start, 0, err) 65 e.Errorf("ERROR ->%v %v", r.Method, r.URL.Path) 66 } 67 68 func access(r *http.Request, start time.Time, statusCode int, err error) *logrus.Entry { 69 url := r.URL.Path 70 if r.URL.RawQuery != "" { 71 url += "?" + r.URL.RawQuery 72 } 73 fields := logrus.Fields{ 74 "type": "access", 75 "@timestamp": start, 76 "remote_ip": getRemoteIp(r), 77 "host": r.Host, 78 "url": url, 79 "method": r.Method, 80 "proto": r.Proto, 81 "duration": time.Since(start).Nanoseconds() / 1000000, 82 "User_Agent": r.Header.Get("User-Agent"), 83 } 84 85 if statusCode != 0 { 86 fields["response_status"] = statusCode 87 } 88 89 if err != nil { 90 fields[logrus.ErrorKey] = err.Error() 91 } 92 93 setCorrelationIds(fields, r.Header) 94 95 cookies := map[string]string{} 96 for _, c := range r.Cookies() { 97 if !contains(AccessLogCookiesBlacklist, c.Name) { 98 cookies[c.Name] = c.Value 99 } 100 } 101 if len(cookies) > 0 { 102 fields["cookies"] = cookies 103 } 104 105 return Logger.WithFields(fields) 106 } 107 108 // Call logs the result of an outgoing call 109 func Call(r *http.Request, resp *http.Response, start time.Time, err error) { 110 url := r.URL.Path 111 if r.URL.RawQuery != "" { 112 url += "?" + r.URL.RawQuery 113 } 114 fields := logrus.Fields{ 115 "type": "call", 116 "@timestamp": start, 117 "host": r.Host, 118 "url": url, 119 "full_url": r.URL.String(), 120 "method": r.Method, 121 "duration": time.Since(start).Nanoseconds() / 1000000, 122 } 123 124 setCorrelationIds(fields, r.Header) 125 126 if err != nil { 127 fields[logrus.ErrorKey] = err.Error() 128 Logger.WithFields(fields).Error(err) 129 return 130 } 131 132 if resp != nil { 133 fields["response_status"] = resp.StatusCode 134 fields["content_type"] = resp.Header.Get("Content-Type") 135 e := Logger.WithFields(fields) 136 msg := fmt.Sprintf("%v %v-> %v", resp.StatusCode, r.Method, r.URL.String()) 137 138 if resp.StatusCode >= 200 && resp.StatusCode <= 399 { 139 e.Info(msg) 140 } else if resp.StatusCode >= 400 && resp.StatusCode <= 499 { 141 e.Warn(msg) 142 } else { 143 e.Error(msg) 144 } 145 return 146 } 147 148 Logger.WithFields(fields).Warn("call, but no response given") 149 } 150 151 // Cacheinfo logs the hit information a accessing a ressource 152 func Cacheinfo(url string, hit bool) { 153 var msg string 154 if hit { 155 msg = fmt.Sprintf("cache hit: %v", url) 156 } else { 157 msg = fmt.Sprintf("cache miss: %v", url) 158 } 159 Logger.WithFields( 160 logrus.Fields{ 161 "type": "cacheinfo", 162 "url": url, 163 "hit": hit, 164 }). 165 Debug(msg) 166 } 167 168 // Return a log entry for application logs, 169 // prefilled with the correlation ids out of the supplied request. 170 func Application(h http.Header) *logrus.Entry { 171 fields := logrus.Fields{ 172 "type": "application", 173 } 174 setCorrelationIds(fields, h) 175 return Logger.WithFields(fields) 176 } 177 178 // LifecycleStart logs the start of an application 179 // with the configuration struct or map as paramter. 180 func LifecycleStart(appName string, args interface{}) { 181 fields := logrus.Fields{} 182 183 jsonString, err := json.Marshal(args) 184 if err == nil { 185 err := json.Unmarshal(jsonString, &fields) 186 if err != nil { 187 fields["parse_error"] = err.Error() 188 } 189 } 190 fields["type"] = "lifecycle" 191 fields["event"] = "start" 192 for _, env := range LifecycleEnvVars { 193 if os.Getenv(env) != "" { 194 fields[strings.ToLower(env)] = os.Getenv(env) 195 } 196 } 197 198 Logger.WithFields(fields).Infof("starting application: %v", appName) 199 } 200 201 // LifecycleStop logs the stop of an application 202 func LifecycleStop(appName string, signal os.Signal, err error) { 203 fields := logrus.Fields{ 204 "type": "lifecycle", 205 "event": "stop", 206 } 207 if signal != nil { 208 fields["signal"] = signal.String() 209 } 210 211 if os.Getenv("BUILD_NUMBER") != "" { 212 fields["build_number"] = os.Getenv("BUILD_NUMBER") 213 } 214 215 if err != nil { 216 Logger.WithFields(fields). 217 WithError(err). 218 Errorf("stopping application: %v (%v)", appName, err) 219 } else { 220 Logger.WithFields(fields).Infof("stopping application: %v (%v)", appName, signal) 221 } 222 } 223 224 // LifecycleStop logs the stop of an application 225 func ServerClosed(appName string) { 226 fields := logrus.Fields{ 227 "type": "application", 228 "event": "stop", 229 } 230 231 if os.Getenv("BUILD_NUMBER") != "" { 232 fields["build_number"] = os.Getenv("BUILD_NUMBER") 233 } 234 235 Logger.WithFields(fields).Infof("http server was closed: %v", appName) 236 } 237 238 func getRemoteIp(r *http.Request) string { 239 if r.Header.Get("X-Cluster-Client-Ip") != "" { 240 return r.Header.Get("X-Cluster-Client-Ip") 241 } 242 if r.Header.Get("X-Real-Ip") != "" { 243 return r.Header.Get("X-Real-Ip") 244 } 245 return strings.Split(r.RemoteAddr, ":")[0] 246 } 247 248 func setCorrelationIds(fields logrus.Fields, h http.Header) { 249 correlationId := GetCorrelationId(h) 250 if correlationId != "" { 251 fields["correlation_id"] = correlationId 252 } 253 254 userCorrelationId := GetUserCorrelationId(h) 255 if userCorrelationId != "" { 256 fields["user_correlation_id"] = userCorrelationId 257 } 258 } 259 260 func contains(s []string, e string) bool { 261 for _, a := range s { 262 if a == e { 263 return true 264 } 265 } 266 return false 267 }