loginsrv

Unnamed repository; edit this file 'description' to name the repository.
git clone git@jamesshield.xyz:repos/loginsrv.git
Log | Files | Refs | README | LICENSE

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 }