diff --git a/cache/cache.go b/cache/cache.go index c0e8b649..a7c020b9 100644 --- a/cache/cache.go +++ b/cache/cache.go @@ -23,6 +23,7 @@ import ( log "github.com/sirupsen/logrus" "github.com/fabiocicerchia/go-proxy-cache/cache/engine" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/utils" "github.com/fabiocicerchia/go-proxy-cache/utils/slice" ) @@ -136,7 +137,7 @@ func (c Object) handleMetadata(domainID string, targetURL url.URL, expiration ti // StoreFullPage - Stores the whole page response in cache. func (c Object) StoreFullPage(expiration time.Duration) (bool, error) { if !c.IsStatusAllowed() || !c.IsMethodAllowed() || expiration < 1 { - log.WithFields(log.Fields{ + logger.GetGlobal().WithFields(log.Fields{ "ReqID": c.ReqID, }).Debugf( "Not allowed to be stored. Status: %v - Method: %v - Expiration: %v", @@ -195,7 +196,7 @@ func (c *Object) RetrieveFullPage() error { } key := StorageKey(c.CurrentURIObject, meta) - log.WithFields(log.Fields{ + logger.GetGlobal().WithFields(log.Fields{ "ReqID": c.ReqID, }).Debugf("StorageKey: %s", key) diff --git a/cache/engine/client/client.go b/cache/engine/client/client.go index c6053a15..91bad36c 100644 --- a/cache/engine/client/client.go +++ b/cache/engine/client/client.go @@ -91,7 +91,7 @@ func (rdb *RedisClient) unlock(key string) error { // PurgeAll - Purges all the existing keys on a DB. func (rdb *RedisClient) PurgeAll() (bool, error) { - _, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + _, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { err := rdb.Client.FlushDB(ctx).Err() return nil, err }) @@ -101,7 +101,7 @@ func (rdb *RedisClient) PurgeAll() (bool, error) { // Ping - Tests the connection. func (rdb *RedisClient) Ping() bool { - _, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + _, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { err := rdb.Client.Ping(ctx).Err() return nil, err }) @@ -111,7 +111,7 @@ func (rdb *RedisClient) Ping() bool { // Set - Sets a key, with certain value, with TTL for expiring (soft and hard eviction). func (rdb *RedisClient) Set(key string, value string, expiration time.Duration) (bool, error) { - _, err := circuitbreaker.CB(rdb.Name).Execute(rdb.doSet(key, value, expiration)) + _, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(rdb.doSet(key, value, expiration)) return err == nil, err } @@ -134,7 +134,7 @@ func (rdb *RedisClient) doSet(key string, value string, expiration time.Duration // Get - Gets a key. func (rdb *RedisClient) Get(key string) (string, error) { - value, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + value, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { value, err := rdb.Client.Get(ctx, key).Result() if value == "" && err != nil && err.Error() == "redis: nil" { return value, nil @@ -155,7 +155,7 @@ func (rdb *RedisClient) Del(key string) error { // DelWildcard - Removes the matching keys based on a pattern. func (rdb *RedisClient) DelWildcard(key string) (int, error) { - k, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + k, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { keys, err := rdb.Client.Keys(ctx, key).Result() return keys, err }) @@ -175,7 +175,7 @@ func (rdb *RedisClient) deleteKeys(keyID string, keys []string) (int, error) { return 0, nil } - _, errDel := circuitbreaker.CB(rdb.Name).Execute(rdb.doDeleteKeys(keyID, keys)) + _, errDel := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(rdb.doDeleteKeys(keyID, keys)) return l, errDel } @@ -198,7 +198,7 @@ func (rdb *RedisClient) doDeleteKeys(keyID string, keys []string) func() (interf // List - Returns the values in a list. func (rdb *RedisClient) List(key string) ([]string, error) { - value, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + value, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { value, err := rdb.Client.LRange(ctx, key, 0, -1).Result() return value, err }) @@ -212,7 +212,7 @@ func (rdb *RedisClient) List(key string) ([]string, error) { // Push - Append values to a list. func (rdb *RedisClient) Push(key string, values []string) error { - _, err := circuitbreaker.CB(rdb.Name).Execute(rdb.doPushKey(key, values)) + _, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(rdb.doPushKey(key, values)) return err } @@ -235,7 +235,7 @@ func (rdb *RedisClient) doPushKey(key string, values []string) func() (interface // Expire - Sets a TTL on a key (hard eviction only). func (rdb *RedisClient) Expire(key string, expiration time.Duration) error { - _, err := circuitbreaker.CB(rdb.Name).Execute(func() (interface{}, error) { + _, err := circuitbreaker.CB(rdb.Name, rdb.logger).Execute(func() (interface{}, error) { err := rdb.Client.Expire(ctx, key, expiration).Err() return nil, err }) diff --git a/cache/engine/client/client_test.go b/cache/engine/client/client_test.go index 64f3b74d..e5a9e8c0 100644 --- a/cache/engine/client/client_test.go +++ b/cache/engine/client/client_test.go @@ -21,6 +21,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine/client" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/utils" circuit_breaker "github.com/fabiocicerchia/go-proxy-cache/utils/circuit-breaker" ) @@ -56,27 +57,27 @@ func TestCircuitBreakerWithPingTimeout(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) - assert.Equal(t, "closed", circuit_breaker.CB(redisConnName).State().String()) + assert.Equal(t, "closed", circuit_breaker.CB(redisConnName, logger.GetGlobal()).State().String()) val := rdb.Ping() assert.True(t, val) - assert.Equal(t, "closed", circuit_breaker.CB(redisConnName).State().String()) + assert.Equal(t, "closed", circuit_breaker.CB(redisConnName, logger.GetGlobal()).State().String()) _ = rdb.Close() val = rdb.Ping() assert.False(t, val) - assert.Equal(t, "half-open", circuit_breaker.CB(redisConnName).State().String()) + assert.Equal(t, "half-open", circuit_breaker.CB(redisConnName, logger.GetGlobal()).State().String()) rdb = client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) val = rdb.Ping() assert.True(t, val) - assert.Equal(t, "closed", circuit_breaker.CB(redisConnName).State().String()) + assert.Equal(t, "closed", circuit_breaker.CB(redisConnName, logger.GetGlobal()).State().String()) } func TestClose(t *testing.T) { @@ -96,7 +97,7 @@ func TestClose(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -124,7 +125,7 @@ func TestSetGet(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -154,7 +155,7 @@ func TestSetGetWithExpiration(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -186,7 +187,7 @@ func TestDel(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -223,7 +224,7 @@ func TestExpire(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -259,7 +260,7 @@ func TestPushList(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -288,7 +289,7 @@ func TestDelWildcardNoMatch(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -344,7 +345,7 @@ func TestDelWildcard(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -400,7 +401,7 @@ func TestPurgeAll(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) @@ -456,7 +457,7 @@ func TestEncodeDecode(t *testing.T) { }, } - circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(redisConnName, cfg.CircuitBreaker, logger.GetGlobal()) rdb := client.Connect(redisConnName, cfg.Cache, log.StandardLogger()) diff --git a/cache/engine/redis.go b/cache/engine/redis.go index 5b435830..09130fee 100644 --- a/cache/engine/redis.go +++ b/cache/engine/redis.go @@ -14,6 +14,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine/client" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" ) var rdb map[string]*client.RedisClient @@ -24,7 +25,7 @@ func GetConn(connName string) *client.RedisClient { return conn } - log.Errorf("Missing redis connection for %s", connName) + logger.GetGlobal().Errorf("Missing redis connection for %s", connName) return nil } diff --git a/config.yml.dist b/config.yml.dist index b39276c2..24a19f79 100644 --- a/config.yml.dist +++ b/config.yml.dist @@ -156,7 +156,8 @@ server: # Values: http, https, ws, wss. scheme: ~ # Load Balancing Algorithm to be used when present multiple endpoints. - # Allowed formats: ip-hash, least-connections, random, round-robin (default). + # Default: round-robin + # Allowed formats: ip-hash, least-connections, random, round-robin. balancing_algorithm: round-robin # List of IPs/Hostnames to be used as load balanced backend servers. # They'll be selected using the chosen algorithm (or round-robin). @@ -252,19 +253,37 @@ log: # Ref: https://golang.org/src/time/format.go time_format: "2006/01/02 15:04:05" # Available variables: - # - $host = request host - # - $remote_addr = request remote addr - # - $remote_user = - - # - $time_local = local time with format of `time_format` - # - $protocol = protocol - # - $request_method = method - # - $request = full URI - # - $status = status code - # - $body_bytes_sent = number of bytes in content body - # - $http_referer = referer - # - $http_user_agent = user agent - # - $cached_status = cache flag + # - $host = request host + # - $remote_addr = request remote addr + # - $remote_user = - + # - $time_local = local time with format of `time_format` + # - $protocol = protocol + # - $request_method = method + # - $request = full URI + # - $status = status code + # - $body_bytes_sent = number of bytes in content body + # - $http_referer = referer + # - $http_user_agent = user agent + # - $cached_status = cache flag + # - $cached_status_label = cached flag label (HIT/MISS/STALE) format: $host - $remote_addr - $remote_user $protocol $request_method "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" $cached_status + # Sentry DSN + # All errors will be tracked and sent to Sentry. + # Logged levels: warning, error, fatal, panic. + # Default (empty) + sentry_dsn: ~ + # Syslog Protocol + # If no protocol and no endpoint is specified, all the logs will be sent to + # the local syslog. + # Default (empty) + syslog_protocol: ~ + # Syslog Endpoint + # If no protocol and no endpoint is specified, all the logs will be sent to + # the local syslog. + # All errors will be tracked and sent to syslog. + # Logged levels: warning, error, critical, alert, emergency. + # Default (empty) + syslog_endpoint: ~ # --- TRACING tracing: diff --git a/config/config.go b/config/config.go index d79a6fe4..99d5daf1 100644 --- a/config/config.go +++ b/config/config.go @@ -137,6 +137,7 @@ func (c *Configuration) CopyOverWith(overrides Configuration, file *string) { c.copyOverWithUpstream(overrides.Server) c.copyOverWithCache(overrides.Cache) c.copyOverWithTracing(overrides.Tracing) + c.copyOverWithLog(overrides.Log) } // --- SERVER. @@ -205,6 +206,13 @@ func (c *Configuration) copyOverWithTracing(overrides Tracing) { c.Tracing.Enabled = utils.Coalesce(overrides.Enabled, c.Tracing.Enabled).(bool) } +// --- LOG. +func (c *Configuration) copyOverWithLog(overrides Log) { + c.Log.SentryDsn = utils.Coalesce(overrides.SentryDsn, c.Log.SentryDsn).(string) + c.Log.SyslogProtocol = utils.Coalesce(overrides.SyslogProtocol, c.Log.SyslogProtocol).(string) + c.Log.SyslogEndpoint = utils.Coalesce(overrides.SyslogEndpoint, c.Log.SyslogEndpoint).(string) +} + // Print - Shows the current configuration. func Print() { obfuscatedConfig := Configuration{} diff --git a/config/model.go b/config/model.go index 36c55a2e..b9013bde 100644 --- a/config/model.go +++ b/config/model.go @@ -134,8 +134,11 @@ type Cache struct { // Log - Defines the config for the logs. type Log struct { - TimeFormat string `yaml:"time_format"` - Format string `yaml:"format"` + TimeFormat string `yaml:"time_format"` + Format string `yaml:"format"` + SentryDsn string `yaml:"sentry_dsn" envconfig:"SENTRY_DSN"` + SyslogProtocol string `yaml:"syslog_protocol" envconfig:"SYSLOG_PROTOCOL"` + SyslogEndpoint string `yaml:"syslog_endpoint" envconfig:"SYSLOG_ENDPOINT"` } // Tracing - Defines the config for the OpenTelemetry tracing. diff --git a/docs/CONFIGURATION.md b/docs/CONFIGURATION.md index 32f92847..7c5c7744 100644 --- a/docs/CONFIGURATION.md +++ b/docs/CONFIGURATION.md @@ -25,8 +25,11 @@ - `REDIS_HOST` - `REDIS_PASSWORD` - `REDIS_PORT` +- `SENTRY_DSN` - `SERVER_HTTPS_PORT` - `SERVER_HTTP_PORT` +- `SYSLOG_ENDPOINT` +- `SYSLOG_PROTOCOL` - `TIMEOUT_HANDLER` - `TIMEOUT_IDLE` - `TIMEOUT_READ_HEADER` @@ -200,7 +203,8 @@ server: # Values: http, https, ws, wss. scheme: https # Load Balancing Algorithm to be used when present multiple endpoints. - # Allowed formats: ip-hash, least-connections, random, round-robin (default). + # Default: round-robin + # Allowed formats: ip-hash, least-connections, random, round-robin. balancing_algorithm: round-robin # List of IPs/Hostnames to be used as load balanced backend servers. # They'll be selected using the chosen algorithm (or round-robin). @@ -296,19 +300,37 @@ log: # Ref: https://golang.org/src/time/format.go time_format: "2006/01/02 15:04:05" # Available variables: - # - $host = request host - # - $remote_addr = request remote addr - # - $remote_user = - - # - $time_local = local time with format of `time_format` - # - $protocol = protocol - # - $request_method = method - # - $request = full URI - # - $status = status code - # - $body_bytes_sent = number of bytes in content body - # - $http_referer = referer - # - $http_user_agent = user agent - # - $cached_status = cache flag + # - $host = request host + # - $remote_addr = request remote addr + # - $remote_user = - + # - $time_local = local time with format of `time_format` + # - $protocol = protocol + # - $request_method = method + # - $request = full URI + # - $status = status code + # - $body_bytes_sent = number of bytes in content body + # - $http_referer = referer + # - $http_user_agent = user agent + # - $cached_status = cache flag + # - $cached_status_label = cache flag label (HIT/MISS/STALE) format: $host - $remote_addr - $remote_user $protocol $request_method "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" $cached_status + # Sentry DSN + # All errors will be tracked and sent to Sentry + # Logged levels: warning, error, fatal, panic. + # Default (empty) + sentry_dsn: ~ + # Syslog Protocol + # If no protocol and no endpoint is specified, all the logs will be sent to + # the local syslog. + # Default (empty) + syslog_protocol: ~ + # Syslog Endpoint + # If no protocol and no endpoint is specified, all the logs will be sent to + # the local syslog. + # All errors will be tracked and sent to syslog. + # Logged levels: warning, error, critical, alert, emergency. + # Default (empty) + syslog_endpoint: ~ # --- TRACING tracing: diff --git a/docs/DEV.md b/docs/DEV.md index 51246121..71b25900 100644 --- a/docs/DEV.md +++ b/docs/DEV.md @@ -31,6 +31,20 @@ There is a JSON export of the dashboard stored in `test/full-setup/grafana/gpc-d Note: the Data Source must be configured in Grafana to point to `http://prometheus:9090`. +# Logging + +In case of testing Sentry, follow this steps: + + - Start docker-compose. + - Run patching commands: + - `SENTRY_SECRET_KEY=$(docker run --rm sentry config generate-secret-key)` + - `docker run --network full-setup_default -it --rm -e SENTRY_REDIS_HOST=redis -e SENTRY_POSTGRES_HOST=postgres -e SENTRY_SECRET_KEY=$SENTRY_SECRET_KEY -e SENTRY_DB_USER=sentry -e SENTRY_DB_PASSWORD=secret --link full-setup_postgres_1:postgres --link full-setup_redis_1:redis sentry upgrade` + - `docker run --network full-setup_default -it --rm -e SENTRY_REDIS_HOST=redis -e SENTRY_POSTGRES_HOST=postgres -e SENTRY_SECRET_KEY=$SENTRY_SECRET_KEY -e SENTRY_DB_USER=sentry -e SENTRY_DB_PASSWORD=secret --link full-setup_postgres_1:postgres --link full-setup_redis_1:redis sentry run worker` + - Configure new accounts in the [admin panel](http://127.0.0.1:9000/). + - Retrieve the Sentry DSN [here](http://127.0.0.1:9000/sentry/internal/getting-started/). + - Change the setting `sentry_dsn` in the `config.yml` file. + - Stop docker-compose and start again. + ## Test **NOTE:** In order to have a fully working environment you need to put in the host file `127.0.0.1 nginx`. diff --git a/go.mod b/go.mod index 924c4ab8..b0e32c05 100644 --- a/go.mod +++ b/go.mod @@ -4,6 +4,9 @@ go 1.14 require ( github.com/HdrHistogram/hdrhistogram-go v1.1.2 // indirect + github.com/certifi/gocertifi v0.0.0-20210507211836-431795d63e8d // indirect + github.com/evalphobia/logrus_sentry v0.8.2 + github.com/getsentry/raven-go v0.2.0 // indirect github.com/go-http-utils/fresh v0.0.0-20161124030543-7231e26a4b27 github.com/go-http-utils/headers v0.0.0-20181008091004-fed159eddc2a github.com/go-redis/redis/v8 v8.11.3 diff --git a/go.sum b/go.sum index f0c252b6..b9d4e542 100644 --- a/go.sum +++ b/go.sum @@ -13,6 +13,8 @@ github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24 github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8= github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM= github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw= +github.com/certifi/gocertifi v0.0.0-20210507211836-431795d63e8d h1:S2NE3iHSwP0XV47EEXL8mWmRdEfGscSJ+7EgePNgt0s= +github.com/certifi/gocertifi v0.0.0-20210507211836-431795d63e8d/go.mod h1:sGbDF6GwGcLpkNXPUTkMRoywsNa/ol15pxFe6ERfguA= github.com/cespare/xxhash/v2 v2.1.1 h1:6MnRN8NT7+YBpUIWxHtefFZOKTAPgGjpQSxqLNn0+qY= github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= @@ -21,12 +23,16 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f h1:lO4WD4F/rVNCu3HqELle0jiPLLBs70cWOduZpkS1E78= github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f/go.mod h1:cuUVRXasLTGF7a8hSLbxyZXjz+1KgoB3wDUb6vlszIc= +github.com/evalphobia/logrus_sentry v0.8.2 h1:dotxHq+YLZsT1Bb45bB5UQbfCh3gM/nFFetyN46VoDQ= +github.com/evalphobia/logrus_sentry v0.8.2/go.mod h1:pKcp+vriitUqu9KiWj/VRFbRfFNUwz95/UkgG8a6MNc= github.com/felixge/httpsnoop v1.0.2 h1:+nS9g82KMXccJ/wp0zyRW9ZBHFETmMGtkk+2CTTrW4o= github.com/felixge/httpsnoop v1.0.2/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U= github.com/fogleman/gg v1.2.1-0.20190220221249-0403632d5b90/go.mod h1:R/bRT+9gY/C5z7JzPU0zXsXHKM4/ayA+zqcVNZzPa1k= github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo= github.com/fsnotify/fsnotify v1.4.9 h1:hsms1Qyu0jgnwNXIxa+/V/PDsU6CfLf6CNO8H7IWoS4= github.com/fsnotify/fsnotify v1.4.9/go.mod h1:znqG4EE+3YCdAaPaxE2ZRY/06pZUdp0tY4IgpuI1SZQ= +github.com/getsentry/raven-go v0.2.0 h1:no+xWJRb5ZI7eE8TWgIq1jLulQiIoLG0IfYxv5JYMGs= +github.com/getsentry/raven-go v0.2.0/go.mod h1:KungGk8q33+aIAZUIVWZDr2OfAEBsO49PX4NzFV5kcQ= github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9AVAgeJqvqgH9Q5CA+iKCZ2gyEVpxRU= github.com/go-http-utils/fresh v0.0.0-20161124030543-7231e26a4b27 h1:O6yi4xa9b2DMosGsXzlMe2E9qXgXCVkRLCoRX+5amxI= github.com/go-http-utils/fresh v0.0.0-20161124030543-7231e26a4b27/go.mod h1:AYvN8omj7nKLmbcXS2dyABYU6JB1Lz1bHmkkq1kf4I4= diff --git a/logger/log.go b/logger/log.go new file mode 100644 index 00000000..0f5ba6ec --- /dev/null +++ b/logger/log.go @@ -0,0 +1,179 @@ +package logger + +// __ +// .-----.-----.______.-----.----.-----.--.--.--.--.______.----.---.-.----| |--.-----. +// | _ | _ |______| _ | _| _ |_ _| | |______| __| _ | __| | -__| +// |___ |_____| | __|__| |_____|__.__|___ | |____|___._|____|__|__|_____| +// |_____| |__| |_____| +// +// Copyright (c) 2020 Fabio Cicerchia. https://fabiocicerchia.it. MIT License +// Repo: https://github.com/fabiocicerchia/go-proxy-cache + +import ( + "fmt" + "io" + "log/syslog" + "net/http" + "os" + "path/filepath" + "strconv" + "strings" + "time" + + "github.com/evalphobia/logrus_sentry" + "github.com/sirupsen/logrus" + lSyslog "github.com/sirupsen/logrus/hooks/syslog" + + "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/utils" +) + +var logFileHandle *os.File +var logLevel logrus.Level = logrus.InfoLevel +var log *logrus.Logger + +func InitLogs(verboseFlag bool, logFile string) { + logrus.SetFormatter(&logrus.TextFormatter{ + ForceColors: true, + FullTimestamp: true, + TimestampFormat: "2006/01/02 15:04:05", + }) + + logrus.SetReportCaller(verboseFlag) + logrus.SetLevel(logLevel) + logrus.SetOutput(os.Stdout) + + if logFile != "" { + logFileHandle = getLogFileWriter(logFile) + logrus.SetOutput(io.MultiWriter(logFileHandle)) + logrus.RegisterExitHandler(closeLogFile) + } +} + +func SetDebugLevel() { + logLevel = logrus.DebugLevel +} + +func getLogFileWriter(logFile string) *os.File { + f, err := os.OpenFile(filepath.Clean(logFile), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) + if err != nil { + logrus.Fatal(err) + } + + return f +} + +func closeLogFile() { + if logFileHandle != nil { + _ = logFileHandle.Close() + } +} + +// Log - Logs against a requested URL. +func Log(req http.Request, reqID string, message string) { + logLine := fmt.Sprintf("%s %s %s - %s", req.Proto, req.Method, req.URL.String(), message) + + logrus.WithFields(logrus.Fields{"ReqID": reqID}).Info(logLine) +} + +// LogRequest - Logs the requested URL. +func LogRequest(req http.Request, statusCode int, lenContent int, reqID string, cached bool, cached_label string) { + // NOTE: THIS IS FOR EVERY DOMAIN, NO DOMAIN OVERRIDE. + // WHEN SHARING SAME PORT NO CUSTOM OVERRIDES ON CRITICAL SETTINGS. + logLine := config.Config.Log.Format + + protocol := strings.Trim(req.Proto, " ") + if protocol == "" { + protocol = "?" + } + + method := strings.Trim(req.Method, " ") + if method == "" { + method = "?" + } + + r := strings.NewReplacer( + `$host`, req.Host, + `$remote_addr`, req.RemoteAddr, + `$remote_user`, "-", + `$time_local`, time.Now().Local().Format(config.Config.Log.TimeFormat), + `$protocol`, protocol, + `$request_method`, method, + `$request`, req.URL.String(), + `$status`, strconv.Itoa(statusCode), + `$body_bytes_sent`, strconv.Itoa(lenContent), + `$http_referer`, req.Referer(), + `$http_user_agent`, req.UserAgent(), + `$cached_status_label`, cached_label, + `$cached_status`, fmt.Sprintf("%v", cached), + ) + + logLine = r.Replace(logLine) + + logrus.WithFields(logrus.Fields{"ReqID": reqID}).Info(logLine) +} + +// LogSetup - Logs the env variables required for a reverse proxy. +func LogSetup(server config.Server) { + forwardHost := utils.IfEmpty(server.Upstream.Host, "*") + forwardProto := server.Upstream.Scheme + + lbEndpointList := fmt.Sprintf("%v", server.Upstream.Endpoints) + if len(server.Upstream.Endpoints) == 0 { + lbEndpointList = "VOID" + } + + logrus.Infof("Server will run on :%s and :%s and redirects to url: %s://%s -> %s\n", server.Port.HTTP, server.Port.HTTPS, forwardProto, forwardHost, lbEndpointList) +} + +func New() *logrus.Logger { + return logrus.New() +} + +func NewGlobal() *logrus.Logger { + log = New() + return log +} + +func GetGlobal() *logrus.Logger { + if log == nil { + return NewGlobal() + } + + return log +} + +func HookSentry(log *logrus.Logger, sentryDsn string) { + if sentryDsn == "" { + return + } + + hook, err := logrus_sentry.NewSentryHook(sentryDsn, []logrus.Level{ + // TODO: Make them customizable? + logrus.PanicLevel, + logrus.FatalLevel, + logrus.ErrorLevel, + logrus.WarnLevel, + }) + + if err != nil { + panic(err) + } + + hook.StacktraceConfiguration.Enable = true + log.Hooks.Add(hook) +} + +func HookSyslog(log *logrus.Logger, syslogProtocol string, syslogEndpoint string) { + if syslogEndpoint == "" { + return + } + + hook, err := lSyslog.NewSyslogHook(syslogProtocol, syslogEndpoint, syslog.LOG_WARNING, "") + + if err != nil { + panic(err) + } + + log.Hooks.Add(hook) +} diff --git a/server/logger/log_test.go b/logger/log_test.go similarity index 96% rename from server/logger/log_test.go rename to logger/log_test.go index 4fb0fba4..ad2fe071 100644 --- a/server/logger/log_test.go +++ b/logger/log_test.go @@ -23,7 +23,7 @@ import ( "github.com/stretchr/testify/assert" "github.com/fabiocicerchia/go-proxy-cache/config" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/response" ) @@ -89,7 +89,7 @@ func TestLogRequest(t *testing.T) { }, } - logger.LogRequest(reqMock, lwrMock, "TestLogRequest", true, "HIT") + logger.LogRequest(reqMock, lwrMock.StatusCode, lwrMock.Content.Len(), "TestLogRequest", true, "HIT") expectedOut := `time=" " level=info msg="example.org - 127.0.0.1 - - ? ? \"/path/to/file\" 404 7 \"https://www.google.com\" \"GoProxyCache\" true HIT" ReqID=TestLogRequest` + "\n" diff --git a/main.go b/main.go index f519484f..2be93ff0 100644 --- a/main.go +++ b/main.go @@ -12,21 +12,18 @@ package main import ( "flag" "fmt" - "io" "os" - "path/filepath" "runtime" log "github.com/sirupsen/logrus" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server" ) var configFile string -var logLevel log.Level = log.InfoLevel var logFile string -var logFileHandle *os.File var verboseFlag bool var testFlag bool @@ -54,7 +51,7 @@ func initFlags() { } if debug { - setDebugLevel() + logger.SetDebugLevel() } } @@ -74,43 +71,6 @@ func testConfiguration(configFile string) { os.Exit(0) } -func setDebugLevel() { - logLevel = log.DebugLevel -} - -func getLogFileWriter(logFile string) *os.File { - f, err := os.OpenFile(filepath.Clean(logFile), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600) - if err != nil { - log.Fatal(err) - } - - return f -} - -func initLogs() { - log.SetFormatter(&log.TextFormatter{ - ForceColors: true, - FullTimestamp: true, - TimestampFormat: "2006/01/02 15:04:05", - }) - - log.SetReportCaller(verboseFlag) - log.SetLevel(logLevel) - log.SetOutput(os.Stdout) - - if logFile != "" { - logFileHandle = getLogFileWriter(logFile) - log.SetOutput(io.MultiWriter(logFileHandle)) - log.RegisterExitHandler(closeLogFile) - } -} - -func closeLogFile() { - if logFileHandle != nil { - _ = logFileHandle.Close() - } -} - func printBanner() { log.Debugf(" __") log.Debugf(".-----.-----.______.-----.----.-----.--.--.--.--.______.----.---.-.----| |--.-----.") @@ -125,7 +85,7 @@ func main() { runtime.GOMAXPROCS(runtime.NumCPU()) initFlags() - initLogs() + logger.InitLogs(verboseFlag, logFile) printBanner() diff --git a/server/balancer/balancer.go b/server/balancer/balancer.go index d980b9de..2f8187c8 100644 --- a/server/balancer/balancer.go +++ b/server/balancer/balancer.go @@ -17,9 +17,8 @@ import ( "strconv" "time" - log "github.com/sirupsen/logrus" - "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/telemetry" "github.com/fabiocicerchia/go-proxy-cache/utils/slice" ) @@ -195,19 +194,19 @@ func doHealthCheck(v *Item, config config.HealthCheck) { req, err := http.NewRequest("HEAD", endpointURL, nil) if err != nil { - log.Errorf("Healthcheck request failed for %s: %s", endpointURL, err) // TODO: Add to trace span? + logger.GetGlobal().Errorf("Healthcheck request failed for %s: %s", endpointURL, err) // TODO: Add to trace span? return } res, err := getClient(config.Timeout, scheme == "https").Do(req) v.Healthy = err == nil if err != nil { - log.Errorf("Healthcheck failed for %s: %s", endpointURL, err) // TODO: Add to trace span? + logger.GetGlobal().Errorf("Healthcheck failed for %s: %s", endpointURL, err) // TODO: Add to trace span? } else { v.Healthy = slice.ContainsString(config.StatusCodes, strconv.Itoa(res.StatusCode)) if !v.Healthy { - log.Errorf("Endpoint %s is not healthy (%d).", endpointURL, res.StatusCode) // TODO: Add to trace span? + logger.GetGlobal().Errorf("Endpoint %s is not healthy (%d).", endpointURL, res.StatusCode) // TODO: Add to trace span? } } } diff --git a/server/handler/connect_test.go b/server/handler/connect_test.go index 3b5891ec..fd7b9f9a 100644 --- a/server/handler/connect_test.go +++ b/server/handler/connect_test.go @@ -24,6 +24,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/handler" "github.com/fabiocicerchia/go-proxy-cache/utils" @@ -58,7 +59,7 @@ func TestEndToEndCallConnect(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) req, err := http.NewRequest("CONNECT", "/", nil) diff --git a/server/handler/handler.go b/server/handler/handler.go index 2ad7f515..6701cebd 100644 --- a/server/handler/handler.go +++ b/server/handler/handler.go @@ -18,7 +18,7 @@ import ( "github.com/rs/xid" "github.com/fabiocicerchia/go-proxy-cache/config" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/response" "github.com/fabiocicerchia/go-proxy-cache/telemetry" "github.com/fabiocicerchia/go-proxy-cache/telemetry/tracing" @@ -48,7 +48,7 @@ func HandleRequest(res http.ResponseWriter, req *http.Request) { if rc.Request.Method == http.MethodConnect { if enableLoggingRequest { - logger.LogRequest(rc.Request, *rc.Response, rc.ReqID, false, "-") + logger.LogRequest(rc.Request, rc.Response.StatusCode, rc.Response.Content.Len(), rc.ReqID, false, "-") } rc.SendMethodNotAllowed(ctx) @@ -93,7 +93,7 @@ func initRequestParams(ctx context.Context, res http.ResponseWriter, req *http.R if !configFound || !rc.IsLegitRequest(ctx, listeningPort) { rc.SendNotImplemented(ctx) - logger.LogRequest(rc.Request, *rc.Response, rc.ReqID, false, CacheStatusLabel[CacheStatusMiss]) + logger.LogRequest(rc.Request, rc.Response.StatusCode, rc.Response.Content.Len(), rc.ReqID, false, CacheStatusLabel[CacheStatusMiss]) return RequestCall{}, fmt.Errorf("Request for %s (listening on :%s) is not allowed (mostly likely it's a configuration mismatch).", rc.Request.Host, listeningPort) } diff --git a/server/handler/healthcheck_test.go b/server/handler/healthcheck_test.go index fa32e03b..9e823323 100644 --- a/server/handler/healthcheck_test.go +++ b/server/handler/healthcheck_test.go @@ -23,6 +23,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/handler" "github.com/fabiocicerchia/go-proxy-cache/utils" circuit_breaker "github.com/fabiocicerchia/go-proxy-cache/utils/circuit-breaker" @@ -53,7 +54,7 @@ func TestHealthcheckWithoutRedis(t *testing.T) { } domainID := config.Config.Server.Upstream.GetDomainID() - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) engine.GetConn(domainID).Close() @@ -99,7 +100,7 @@ func TestHealthcheckWithRedis(t *testing.T) { } domainID := config.Config.Server.Upstream.GetDomainID() - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) req, err := http.NewRequest("GET", "/healthcheck", nil) diff --git a/server/handler/http.go b/server/handler/http.go index 89f5d456..0d95214c 100644 --- a/server/handler/http.go +++ b/server/handler/http.go @@ -17,7 +17,7 @@ import ( "time" "github.com/fabiocicerchia/go-proxy-cache/config" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/response" "github.com/fabiocicerchia/go-proxy-cache/server/storage" "github.com/fabiocicerchia/go-proxy-cache/server/transport" @@ -83,7 +83,7 @@ func (rc RequestCall) HandleHTTPRequestAndProxy(ctx context.Context) { if enableLoggingRequest { // HIT and STALE considered the same. - logger.LogRequest(rc.Request, *rc.Response, rc.ReqID, cached != CacheStatusMiss, CacheStatusLabel[cached]) + logger.LogRequest(rc.Request, rc.Response.StatusCode, rc.Response.Content.Len(), rc.ReqID, cached != CacheStatusMiss, CacheStatusLabel[cached]) } } diff --git a/server/handler/http_functional_test.go b/server/handler/http_functional_test.go index ecb462c8..1b4b1921 100644 --- a/server/handler/http_functional_test.go +++ b/server/handler/http_functional_test.go @@ -24,6 +24,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/handler" "github.com/fabiocicerchia/go-proxy-cache/utils" @@ -66,7 +67,7 @@ func TestHTTPEndToEndCallRedirect(t *testing.T) { config.Config.Server.Upstream.RedirectStatusCode = 301 domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) req, err := http.NewRequest("GET", "/", nil) @@ -101,7 +102,7 @@ func TestHTTPEndToEndCallWithoutCache(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) engine.GetConn(domainID).Close() @@ -142,7 +143,7 @@ func TestHTTPEndToEndCallWithCacheMiss(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, err := engine.GetConn(domainID).PurgeAll() @@ -198,7 +199,7 @@ func TestHTTPEndToEndCallWithCacheHit(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, _ = engine.GetConn(domainID).PurgeAll() @@ -276,7 +277,7 @@ func TestHTTPEndToEndCallWithCacheBypass(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, _ = engine.GetConn(domainID).PurgeAll() @@ -379,7 +380,7 @@ func TestHTTPEndToEndCallWithCacheStale(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, _ = engine.GetConn(domainID).PurgeAll() @@ -507,7 +508,7 @@ func TestHTTPEndToEndCallWithMissingDomain(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) engine.GetConn(domainID).Close() @@ -545,7 +546,7 @@ func TestHTTPSEndToEndCallRedirect(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) req, err := http.NewRequest("GET", "/", nil) @@ -580,7 +581,7 @@ func TestHTTPSEndToEndCallWithoutCache(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) engine.GetConn(domainID).Close() @@ -621,7 +622,7 @@ func TestHTTPSEndToEndCallWithCacheMiss(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, err := engine.GetConn(domainID).PurgeAll() @@ -678,7 +679,7 @@ func TestHTTPSEndToEndCallWithCacheHit(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) _, _ = engine.GetConn(domainID).PurgeAll() @@ -746,7 +747,7 @@ func TestHTTPSEndToEndCallWithMissingDomain(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) engine.GetConn(domainID).Close() diff --git a/server/handler/model.go b/server/handler/model.go index 8b99f72c..4856bd55 100644 --- a/server/handler/model.go +++ b/server/handler/model.go @@ -21,6 +21,7 @@ import ( "go.opentelemetry.io/otel/trace" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/response" "github.com/fabiocicerchia/go-proxy-cache/telemetry" ) @@ -49,7 +50,7 @@ type RequestCall struct { // GetLogger - Get logger instance with RequestID. func (rc RequestCall) GetLogger() *log.Entry { - return log.WithFields(log.Fields{ + return logger.GetGlobal().WithFields(log.Fields{ "ReqID": rc.ReqID, }) } diff --git a/server/handler/purge.go b/server/handler/purge.go index 410a27ff..7638a1b1 100644 --- a/server/handler/purge.go +++ b/server/handler/purge.go @@ -13,7 +13,7 @@ import ( "context" "net/http" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/storage" "github.com/fabiocicerchia/go-proxy-cache/telemetry" ) @@ -42,6 +42,6 @@ func (rc RequestCall) HandlePurge(ctx context.Context) { telemetry.From(ctx).RegisterStatusCode(http.StatusOK) if enableLoggingRequest { - logger.LogRequest(rc.Request, *rc.Response, rc.ReqID, false, "-") + logger.LogRequest(rc.Request, rc.Response.StatusCode, rc.Response.Content.Len(), rc.ReqID, false, "-") } } diff --git a/server/handler/purge_test.go b/server/handler/purge_test.go index 8bf099fd..6f334aab 100644 --- a/server/handler/purge_test.go +++ b/server/handler/purge_test.go @@ -24,6 +24,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/handler" "github.com/fabiocicerchia/go-proxy-cache/utils" @@ -57,7 +58,7 @@ func TestEndToEndCallPurgeDoNothing(t *testing.T) { } domainID := config.Config.Server.Upstream.GetDomainID() - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) // --- PURGE @@ -111,7 +112,7 @@ func TestEndToEndCallPurge(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) // --- MISS diff --git a/server/handler/utils.go b/server/handler/utils.go index 6d5f0ee5..ab3833c5 100644 --- a/server/handler/utils.go +++ b/server/handler/utils.go @@ -21,10 +21,10 @@ import ( "github.com/opentracing/opentracing-go" "github.com/rs/dnscache" - log "github.com/sirupsen/logrus" "github.com/fabiocicerchia/go-proxy-cache/cache" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/storage" "github.com/fabiocicerchia/go-proxy-cache/telemetry/tracing" @@ -81,7 +81,7 @@ func getListeningPort(ctx context.Context) string { func isLegitPort(port config.Port, listeningPort string) bool { // When running the functional tests there's no server listening (so no port open). if os.Getenv("TESTING") == "1" && listeningPort == "" { - log.Warn("Testing Environment found, and listening port is empty") + logger.GetGlobal().Warn("Testing Environment found, and listening port is empty") return true } diff --git a/server/handler/ws.go b/server/handler/ws.go index 89670d9e..30427180 100644 --- a/server/handler/ws.go +++ b/server/handler/ws.go @@ -15,7 +15,7 @@ import ( "github.com/yhat/wsutil" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/telemetry" "github.com/fabiocicerchia/go-proxy-cache/telemetry/tracing" ) @@ -25,7 +25,7 @@ func (rc RequestCall) HandleWSRequestAndProxy(ctx context.Context) { rc.serveReverseProxyWS(ctx) if enableLoggingRequest { - logger.LogRequest(rc.Request, *rc.Response, rc.ReqID, false, CacheStatusLabel[CacheStatusMiss]) + logger.LogRequest(rc.Request, rc.Response.StatusCode, rc.Response.Content.Len(), rc.ReqID, false, CacheStatusLabel[CacheStatusMiss]) } } diff --git a/server/handler/ws_test.go b/server/handler/ws_test.go index 41453e15..80044f78 100644 --- a/server/handler/ws_test.go +++ b/server/handler/ws_test.go @@ -24,6 +24,7 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/handler" "github.com/fabiocicerchia/go-proxy-cache/utils" @@ -58,7 +59,7 @@ func TestEndToEndHandleWSRequestAndProxy(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) // --- WEBSOCKET @@ -116,7 +117,7 @@ func TestEndToEndHandleWSRequestAndProxySecure(t *testing.T) { domainID := config.Config.Server.Upstream.GetDomainID() balancer.InitRoundRobin(domainID, config.Config.Server.Upstream, false) - circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker) + circuit_breaker.InitCircuitBreaker(domainID, config.Config.CircuitBreaker, logger.GetGlobal()) engine.InitConn(domainID, config.Config.Cache, log.StandardLogger()) // --- WEBSOCKET diff --git a/server/logger/log.go b/server/logger/log.go deleted file mode 100644 index c5bc41c5..00000000 --- a/server/logger/log.go +++ /dev/null @@ -1,81 +0,0 @@ -package logger - -// __ -// .-----.-----.______.-----.----.-----.--.--.--.--.______.----.---.-.----| |--.-----. -// | _ | _ |______| _ | _| _ |_ _| | |______| __| _ | __| | -__| -// |___ |_____| | __|__| |_____|__.__|___ | |____|___._|____|__|__|_____| -// |_____| |__| |_____| -// -// Copyright (c) 2020 Fabio Cicerchia. https://fabiocicerchia.it. MIT License -// Repo: https://github.com/fabiocicerchia/go-proxy-cache - -import ( - "fmt" - "net/http" - "strconv" - "strings" - "time" - - log "github.com/sirupsen/logrus" - - "github.com/fabiocicerchia/go-proxy-cache/config" - "github.com/fabiocicerchia/go-proxy-cache/server/response" - "github.com/fabiocicerchia/go-proxy-cache/utils" -) - -// Log - Logs against a requested URL. -func Log(req http.Request, reqID string, message string) { - logLine := fmt.Sprintf("%s %s %s - %s", req.Proto, req.Method, req.URL.String(), message) - - log.WithFields(log.Fields{"ReqID": reqID}).Info(logLine) -} - -// LogRequest - Logs the requested URL. -func LogRequest(req http.Request, lwr response.LoggedResponseWriter, reqID string, cached bool, cached_label string) { - // NOTE: THIS IS FOR EVERY DOMAIN, NO DOMAIN OVERRIDE. - // WHEN SHARING SAME PORT NO CUSTOM OVERRIDES ON CRITICAL SETTINGS. - logLine := config.Config.Log.Format - - protocol := strings.Trim(req.Proto, " ") - if protocol == "" { - protocol = "?" - } - - method := strings.Trim(req.Method, " ") - if method == "" { - method = "?" - } - - r := strings.NewReplacer( - `$host`, req.Host, - `$remote_addr`, req.RemoteAddr, - `$remote_user`, "-", - `$time_local`, time.Now().Local().Format(config.Config.Log.TimeFormat), - `$protocol`, protocol, - `$request_method`, method, - `$request`, req.URL.String(), - `$status`, strconv.Itoa(lwr.StatusCode), - `$body_bytes_sent`, strconv.Itoa(lwr.Content.Len()), - `$http_referer`, req.Referer(), - `$http_user_agent`, req.UserAgent(), - `$cached_status_label`, cached_label, - `$cached_status`, fmt.Sprintf("%v", cached), - ) - - logLine = r.Replace(logLine) - - log.WithFields(log.Fields{"ReqID": reqID}).Info(logLine) -} - -// LogSetup - Logs the env variables required for a reverse proxy. -func LogSetup(server config.Server) { - forwardHost := utils.IfEmpty(server.Upstream.Host, "*") - forwardProto := server.Upstream.Scheme - - lbEndpointList := fmt.Sprintf("%v", server.Upstream.Endpoints) - if len(server.Upstream.Endpoints) == 0 { - lbEndpointList = "VOID" - } - - log.Infof("Server will run on :%s and :%s and redirects to url: %s://%s -> %s\n", server.Port.HTTP, server.Port.HTTPS, forwardProto, forwardHost, lbEndpointList) -} diff --git a/server/response/utils.go b/server/response/utils.go index 53c55f8a..14876e98 100644 --- a/server/response/utils.go +++ b/server/response/utils.go @@ -11,11 +11,13 @@ package response import ( log "github.com/sirupsen/logrus" + + "github.com/fabiocicerchia/go-proxy-cache/logger" ) // LoggedResponseWriter - Decorator for http.ResponseWriter. func (lwr LoggedResponseWriter) GetLogger() *log.Entry { - return log.WithFields(log.Fields{ + return logger.GetGlobal().WithFields(log.Fields{ "ReqID": lwr.ReqID, }) } diff --git a/server/server.go b/server/server.go index 13885437..ba544300 100644 --- a/server/server.go +++ b/server/server.go @@ -23,9 +23,9 @@ import ( "github.com/fabiocicerchia/go-proxy-cache/cache/engine" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "github.com/fabiocicerchia/go-proxy-cache/server/balancer" "github.com/fabiocicerchia/go-proxy-cache/server/handler" - "github.com/fabiocicerchia/go-proxy-cache/server/logger" srvtls "github.com/fabiocicerchia/go-proxy-cache/server/tls" "github.com/fabiocicerchia/go-proxy-cache/telemetry/metrics" "github.com/fabiocicerchia/go-proxy-cache/telemetry/tracing" @@ -64,6 +64,11 @@ func Run(appVersion string, configFile string) { config.InitConfigFromFileOrEnv(configFile) config.Print() + // Logging Hooks + log := logger.NewGlobal() + logger.HookSentry(log, config.Config.Log.SentryDsn) + logger.HookSyslog(log, config.Config.Log.SyslogProtocol, config.Config.Log.SyslogEndpoint) + // Init tracing tracer, closer, err := tracing.NewJaegerProvider( appVersion, @@ -175,8 +180,8 @@ func (s *Servers) InitServers(domain string, domainConfig config.Configuration) err := srvtls.ServerOverrides(domain, &srvHTTPS, domainConfig.Server) if err != nil { - log.Errorf("Skipping '%s' TLS server configuration: %s", domain, err) - log.Errorf("No HTTPS server will be listening on '%s'", domain) + logger.GetGlobal().Errorf("Skipping '%s' TLS server configuration: %s", domain, err) + logger.GetGlobal().Errorf("No HTTPS server will be listening on '%s'", domain) return } @@ -188,7 +193,7 @@ func (s *Servers) InitServers(domain string, domainConfig config.Configuration) func (s *Servers) StartDomainServer(domain string, scheme string) { domainConfig, found := config.DomainConf(domain, scheme) if !found { - log.Errorf("Missing configuration for %s.", domain) + logger.GetGlobal().Errorf("Missing configuration for %s.", domain) return } @@ -198,8 +203,8 @@ func (s *Servers) StartDomainServer(domain string, scheme string) { logger.LogSetup(domainConfig.Server) // redis connect - circuitbreaker.InitCircuitBreaker(domainID, domainConfig.CircuitBreaker) - engine.InitConn(domainID, domainConfig.Cache, log.StandardLogger()) + circuitbreaker.InitCircuitBreaker(domainID, domainConfig.CircuitBreaker, logger.GetGlobal()) + engine.InitConn(domainID, domainConfig.Cache, logger.GetGlobal()) // config server http & https s.InitServers(domain, domainConfig) @@ -213,7 +218,7 @@ func (s Servers) startListeners() { srvHTTP.HttpSrv.Addr = ":" + port go func(srv http.Server) { - log.Fatal(srv.ListenAndServe()) + logger.GetGlobal().Fatal(srv.ListenAndServe()) }(srvHTTP.HttpSrv) } @@ -221,7 +226,7 @@ func (s Servers) startListeners() { srvHTTPS.HttpSrv.Addr = ":" + port go func(srv http.Server) { - log.Fatal(srv.ListenAndServeTLS("", "")) + logger.GetGlobal().Fatal(srv.ListenAndServeTLS("", "")) }(srvHTTPS.HttpSrv) } } @@ -230,14 +235,14 @@ func (s Servers) shutdownServers(ctx context.Context) { for k, v := range s.HTTP { err := v.HttpSrv.Shutdown(ctx) if err != nil { - log.Fatalf("Cannot shutdown server %s: %s", k, err) + logger.GetGlobal().Fatalf("Cannot shutdown server %s: %s", k, err) } } for k, v := range s.HTTPS { err := v.HttpSrv.Shutdown(ctx) if err != nil { - log.Fatalf("Cannot shutdown server %s: %s", k, err) + logger.GetGlobal().Fatalf("Cannot shutdown server %s: %s", k, err) } } } diff --git a/server/tls/tls.go b/server/tls/tls.go index 197d5990..80a28365 100644 --- a/server/tls/tls.go +++ b/server/tls/tls.go @@ -15,9 +15,9 @@ import ( "net/http" "github.com/pkg/errors" - log "github.com/sirupsen/logrus" "github.com/fabiocicerchia/go-proxy-cache/config" + "github.com/fabiocicerchia/go-proxy-cache/logger" "golang.org/x/crypto/acme/autocert" ) @@ -90,7 +90,7 @@ func Config(domain string, domainConfigTLS config.TLS) (*crypto_tls.Config, erro } func returnCert(helloInfo *crypto_tls.ClientHelloInfo) (*crypto_tls.Certificate, error) { - log.Debugf("HelloInfo: %+v\n", helloInfo) // TODO: Add to trace span? + logger.GetGlobal().Debugf("HelloInfo: %+v\n", helloInfo) // TODO: Add to trace span? if val, ok := certificates[helloInfo.ServerName]; ok { return val, nil @@ -103,7 +103,7 @@ func returnCert(helloInfo *crypto_tls.ClientHelloInfo) (*crypto_tls.Certificate, func InitCertManager(host string, email string) *autocert.Manager { cacheDir, err := ioutil.TempDir("", "cache_dir") if err != nil { - log.Fatal(err) + logger.GetGlobal().Fatal(err) return nil } diff --git a/test/full-setup/config.yml b/test/full-setup/config.yml index e8aca7ea..c22eae22 100644 --- a/test/full-setup/config.yml +++ b/test/full-setup/config.yml @@ -30,6 +30,11 @@ tracing: jaeger_endpoint: jaeger:6831 enabled: true +log: + sentry_dsn: http://ff6cc3b0c994483f829c8da224973b47:8ffc03c8fd7a474eb8acaea55d6402a1@sentry:9000/2 + syslog_protocol: udp + syslog_endpoint: syslog:514 + domains: example_com: server: diff --git a/test/full-setup/docker-compose.yml b/test/full-setup/docker-compose.yml index 1e77e5e3..d09f10f5 100644 --- a/test/full-setup/docker-compose.yml +++ b/test/full-setup/docker-compose.yml @@ -10,6 +10,8 @@ version: '3.8' services: + # CORE - GOPROXYCACHE + ############################################################################## go-proxy-cache: build: context: ../.. @@ -33,6 +35,8 @@ services: - ./config.yml:/app/config.yml - ./certs:/app/certs + # STORAGE - REDIS + ############################################################################## redis: image: redis:6.2.5-alpine3.14 ports: @@ -47,6 +51,8 @@ services: timeout: 3s retries: 30 + # UPSTREAM 1 - NGINX + ############################################################################## nginx: build: context: . @@ -65,6 +71,8 @@ services: - "40081:40081" # WS - "40082:40082" # WSS + # UPSTREAM 2 - NODEJS + ############################################################################## node: image: node:16.7.0-alpine3.14 restart: always @@ -81,6 +89,8 @@ services: - "9001:9001" # WS - "9002:9002" # WSS + # TRACING - JAEGER + ############################################################################## jaeger: image: jaegertracing/all-in-one:1.26.0 ports: @@ -98,15 +108,53 @@ services: retries: 5 start_period: 10s + # METRICS - PROMETHEUS + ############################################################################## prometheus: - image: prom/prometheus + image: prom/prometheus:v2.30.0 ports: - - "9090:9090" # Prometheus + - "9090:9090" # Prometheuspbertera/syslogserver command: --config.file=/etc/prometheus/prometheus.yml volumes: - ./prometheus/prometheus.yml:/etc/prometheus/prometheus.yml + # DASHBOARD - GRAFANA + ############################################################################## grafana: - image: grafana/grafana + image: grafana/grafana:8.1.4-ubuntu ports: - "3001:3000" # Grafana + + # LOGS - SYSLOG + ############################################################################## + syslog: + image: pbertera/syslogserver:latest + environment: + SYSLOG_USERNAME: admin + SYSLOG_PASSWORD: 1234 + ports: + - "8080:80" # pimpmylogs + - "514:514/udp" # rsyslog + + # LOGS - SENTRY + ############################################################################## + sentry: + image: sentry:9.1.2 + depends_on: + - postgres + - redis + environment: + SENTRY_SECRET_KEY: test + SENTRY_REDIS_HOST: redis + SENTRY_POSTGRES_HOST: postgres + SENTRY_DB_USER: sentry + SENTRY_DB_PASSWORD: secret + ports: + - "9000:9000" # sentry + postgres: + image: postgres:13.4-alpine3.14 + environment: + POSTGRES_USER: sentry + POSTGRES_PASSWORD: secret + ports: + - "5432:5432" # postgres diff --git a/utils/circuit-breaker/circuit-breaker.go b/utils/circuit-breaker/circuit-breaker.go index 4e1c4cff..94285709 100644 --- a/utils/circuit-breaker/circuit-breaker.go +++ b/utils/circuit-breaker/circuit-breaker.go @@ -12,7 +12,7 @@ package circuitbreaker import ( "time" - log "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus" "github.com/sony/gobreaker" ) @@ -28,14 +28,14 @@ type CircuitBreaker struct { } // InitCircuitBreaker - Initialise the Circuit Breaker. -func InitCircuitBreaker(name string, config CircuitBreaker) { +func InitCircuitBreaker(name string, config CircuitBreaker, logger *logrus.Logger) { st := gobreaker.Settings{ Name: name, MaxRequests: config.MaxRequests, Interval: config.Interval, Timeout: config.Timeout, ReadyToTrip: cbReadyToTrip(config), - OnStateChange: cbOnStateChange, + OnStateChange: cbOnStateChange(logger), } cb[name] = gobreaker.NewCircuitBreaker(st) @@ -49,12 +49,14 @@ func cbReadyToTrip(config CircuitBreaker) func(counts gobreaker.Counts) bool { } } -func cbOnStateChange(name string, from gobreaker.State, to gobreaker.State) { - log.Warnf("Circuit Breaker '%s' - Changed from %s to %s", name, from.String(), to.String()) +func cbOnStateChange(log *logrus.Logger) func(name string, from gobreaker.State, to gobreaker.State) { + return func(name string, from gobreaker.State, to gobreaker.State) { + log.Warnf("Circuit Breaker '%s' - Changed from %s to %s", name, from.String(), to.String()) + } } // CB - Returns instance of gobreaker.CircuitBreaker. -func CB(name string) *gobreaker.CircuitBreaker { +func CB(name string, log *logrus.Logger) *gobreaker.CircuitBreaker { if val, ok := cb[name]; ok { return val }