[ARVADOS] created: da14fa3f2bc1b5cd2fc615b2feb5ab45f244b06a
Git user
git at public.curoverse.com
Fri Nov 18 01:51:47 EST 2016
at da14fa3f2bc1b5cd2fc615b2feb5ab45f244b06a (commit)
commit da14fa3f2bc1b5cd2fc615b2feb5ab45f244b06a
Author: Tom Clegg <tom at curoverse.com>
Date: Fri Nov 18 01:49:47 2016 -0500
10473: Log requests/responses in JSON format by default; add config option for text format.
diff --git a/sdk/go/httpserver/id_generator.go b/sdk/go/httpserver/id_generator.go
new file mode 100644
index 0000000..c2830f7
--- /dev/null
+++ b/sdk/go/httpserver/id_generator.go
@@ -0,0 +1,31 @@
+package httpserver
+
+import (
+ "strconv"
+ "sync"
+ "time"
+)
+
+// IDGenerator generates alphanumeric strings suitable for use as
+// unique IDs (a given IDGenerator will never return the same ID
+// twice).
+type IDGenerator struct {
+ // Prefix is prepended to each returned ID.
+ Prefix string
+
+ lastID int64
+ mtx sync.Mutex
+}
+
+// Next returns a new ID string. It is safe to call Next from multiple
+// goroutines.
+func (g *IDGenerator) Next() string {
+ id := time.Now().UnixNano()
+ g.mtx.Lock()
+ if id <= g.lastID {
+ id = g.lastID + 1
+ }
+ g.lastID = id
+ g.mtx.Unlock()
+ return g.Prefix + strconv.FormatInt(id, 36)
+}
diff --git a/services/keepstore/azure_blob_volume.go b/services/keepstore/azure_blob_volume.go
index 6ca31c3..43cf83a 100644
--- a/services/keepstore/azure_blob_volume.go
+++ b/services/keepstore/azure_blob_volume.go
@@ -8,7 +8,6 @@ import (
"fmt"
"io"
"io/ioutil"
- "log"
"net/http"
"os"
"regexp"
@@ -18,6 +17,7 @@ import (
"time"
"git.curoverse.com/arvados.git/sdk/go/arvados"
+ log "github.com/Sirupsen/logrus"
"github.com/curoverse/azure-sdk-for-go/storage"
)
diff --git a/services/keepstore/azure_blob_volume_test.go b/services/keepstore/azure_blob_volume_test.go
index d636a5e..c5dbc8f 100644
--- a/services/keepstore/azure_blob_volume_test.go
+++ b/services/keepstore/azure_blob_volume_test.go
@@ -9,7 +9,6 @@ import (
"flag"
"fmt"
"io/ioutil"
- "log"
"math/rand"
"net"
"net/http"
@@ -22,6 +21,7 @@ import (
"testing"
"time"
+ log "github.com/Sirupsen/logrus"
"github.com/curoverse/azure-sdk-for-go/storage"
)
diff --git a/services/keepstore/bufferpool.go b/services/keepstore/bufferpool.go
index 9a35094..38f97af 100644
--- a/services/keepstore/bufferpool.go
+++ b/services/keepstore/bufferpool.go
@@ -1,10 +1,11 @@
package main
import (
- "log"
"sync"
"sync/atomic"
"time"
+
+ log "github.com/Sirupsen/logrus"
)
type bufferPool struct {
diff --git a/services/keepstore/config.go b/services/keepstore/config.go
index dc06ef5..b2041c3 100644
--- a/services/keepstore/config.go
+++ b/services/keepstore/config.go
@@ -5,17 +5,19 @@ import (
"encoding/json"
"fmt"
"io/ioutil"
- "log"
"strings"
"time"
"git.curoverse.com/arvados.git/sdk/go/arvados"
+ log "github.com/Sirupsen/logrus"
)
type Config struct {
Debug bool
Listen string
+ LogFormat string
+
PIDFile string
MaxBuffers int
@@ -42,6 +44,7 @@ var theConfig = DefaultConfig()
func DefaultConfig() *Config {
return &Config{
Listen: ":25107",
+ LogFormat: "json",
MaxBuffers: 128,
RequireSignatures: true,
BlobSignatureTTL: arvados.Duration(14 * 24 * time.Hour),
@@ -55,12 +58,26 @@ func DefaultConfig() *Config {
// fields, and before using the config.
func (cfg *Config) Start() error {
if cfg.Debug {
+ log.SetLevel(log.DebugLevel)
cfg.debugLogf = log.Printf
cfg.debugLogf("debugging enabled")
} else {
cfg.debugLogf = func(string, ...interface{}) {}
}
+ switch strings.ToLower(cfg.LogFormat) {
+ case "text":
+ log.SetFormatter(&log.TextFormatter{
+ TimestampFormat: time.RFC3339Nano,
+ })
+ case "json":
+ log.SetFormatter(&log.JSONFormatter{
+ TimestampFormat: time.RFC3339Nano,
+ })
+ default:
+ return fmt.Errorf(`unsupported log format %q (try "text" or "json")`, cfg.LogFormat)
+ }
+
if cfg.MaxBuffers < 0 {
return fmt.Errorf("MaxBuffers must be greater than zero")
}
diff --git a/services/keepstore/config_test.go b/services/keepstore/config_test.go
index eaa0904..a6d46e5 100644
--- a/services/keepstore/config_test.go
+++ b/services/keepstore/config_test.go
@@ -1,7 +1,7 @@
package main
import (
- "log"
+ log "github.com/Sirupsen/logrus"
)
func init() {
diff --git a/services/keepstore/handler_test.go b/services/keepstore/handler_test.go
index 9708b4e..40b4839 100644
--- a/services/keepstore/handler_test.go
+++ b/services/keepstore/handler_test.go
@@ -958,7 +958,7 @@ func TestGetHandlerClientDisconnect(t *testing.T) {
ok := make(chan struct{})
go func() {
req, _ := http.NewRequest("GET", fmt.Sprintf("/%s+%d", TestHash, len(TestBlock)), nil)
- (&LoggingRESTRouter{MakeRESTRouter()}).ServeHTTP(resp, req)
+ (&LoggingRESTRouter{router: MakeRESTRouter()}).ServeHTTP(resp, req)
ok <- struct{}{}
}()
diff --git a/services/keepstore/handlers.go b/services/keepstore/handlers.go
index 289dce1..c86604d 100644
--- a/services/keepstore/handlers.go
+++ b/services/keepstore/handlers.go
@@ -15,7 +15,6 @@ import (
"fmt"
"github.com/gorilla/mux"
"io"
- "log"
"net/http"
"os"
"regexp"
@@ -24,6 +23,8 @@ import (
"strings"
"sync"
"time"
+
+ log "github.com/Sirupsen/logrus"
)
// MakeRESTRouter returns a new mux.Router that forwards all Keep
diff --git a/services/keepstore/keepstore.go b/services/keepstore/keepstore.go
index 2f5f8d4..df55799 100644
--- a/services/keepstore/keepstore.go
+++ b/services/keepstore/keepstore.go
@@ -3,7 +3,6 @@ package main
import (
"flag"
"fmt"
- "log"
"net"
"net/http"
"os"
@@ -15,6 +14,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/config"
"git.curoverse.com/arvados.git/sdk/go/httpserver"
"git.curoverse.com/arvados.git/sdk/go/keepclient"
+ log "github.com/Sirupsen/logrus"
"github.com/coreos/go-systemd/daemon"
"github.com/ghodss/yaml"
)
@@ -148,8 +148,7 @@ func main() {
// Middleware stack: logger, MaxRequests limiter, method handlers
http.Handle("/", &LoggingRESTRouter{
- httpserver.NewRequestLimiter(theConfig.MaxRequests,
- MakeRESTRouter()),
+ router: httpserver.NewRequestLimiter(theConfig.MaxRequests, MakeRESTRouter()),
})
// Set up a TCP listener.
diff --git a/services/keepstore/logging_router.go b/services/keepstore/logging_router.go
index 0f556b5..30b10b3 100644
--- a/services/keepstore/logging_router.go
+++ b/services/keepstore/logging_router.go
@@ -4,10 +4,12 @@ package main
// LoggingResponseWriter
import (
- "log"
"net/http"
"strings"
"time"
+
+ "git.curoverse.com/arvados.git/sdk/go/httpserver"
+ log "github.com/Sirupsen/logrus"
)
// LoggingResponseWriter has anonymous fields ResponseWriter and ResponseBody
@@ -57,21 +59,36 @@ func (resp *LoggingResponseWriter) Write(data []byte) (int, error) {
// LoggingRESTRouter is used to add logging capabilities to mux.Router
type LoggingRESTRouter struct {
- router http.Handler
+ router http.Handler
+ idGenerator httpserver.IDGenerator
}
func (loggingRouter *LoggingRESTRouter) ServeHTTP(wrappedResp http.ResponseWriter, req *http.Request) {
- t0 := time.Now()
+ tStart := time.Now()
+ lgr := log.WithFields(log.Fields{
+ "RequestID": loggingRouter.idGenerator.Next(),
+ "RemoteAddr": req.RemoteAddr,
+ "X-Forwarded-For": req.Header.Get("X-Forwarded-For"),
+ "ReqMethod": req.Method,
+ "ReqPath": req.URL.Path[1:],
+ "ReqBytes": req.ContentLength,
+ })
+ lgr.Info("request")
+
resp := LoggingResponseWriter{http.StatusOK, 0, wrappedResp, "", zeroTime}
loggingRouter.router.ServeHTTP(&resp, req)
statusText := http.StatusText(resp.Status)
if resp.Status >= 400 {
statusText = strings.Replace(resp.ResponseBody, "\n", "", -1)
}
- now := time.Now()
- tTotal := now.Sub(t0)
- tLatency := resp.sentHdr.Sub(t0)
- tResponse := now.Sub(resp.sentHdr)
- log.Printf("[%s] %s %s %d %.6fs %.6fs %.6fs %d %d \"%s\"", req.RemoteAddr, req.Method, req.URL.Path[1:], req.ContentLength, tTotal.Seconds(), tLatency.Seconds(), tResponse.Seconds(), resp.Status, resp.Length, statusText)
+ tDone := time.Now()
+ lgr.WithFields(log.Fields{
+ "TimeTotal": tDone.Sub(tStart).Seconds(),
+ "TimeToStatus": resp.sentHdr.Sub(tStart).Seconds(),
+ "TimeWriteBody": tDone.Sub(resp.sentHdr).Seconds(),
+ "RespStatusCode": resp.Status,
+ "RespStatus": statusText,
+ "RespBytes": resp.Length,
+ }).Info("response")
}
diff --git a/services/keepstore/pull_worker.go b/services/keepstore/pull_worker.go
index 12860bb..3c6278d 100644
--- a/services/keepstore/pull_worker.go
+++ b/services/keepstore/pull_worker.go
@@ -7,8 +7,9 @@ import (
"git.curoverse.com/arvados.git/sdk/go/keepclient"
"io"
"io/ioutil"
- "log"
"time"
+
+ log "github.com/Sirupsen/logrus"
)
// RunPullWorker is used by Keepstore to initiate pull worker channel goroutine.
diff --git a/services/keepstore/s3_volume.go b/services/keepstore/s3_volume.go
index 17923f8..2320eee 100644
--- a/services/keepstore/s3_volume.go
+++ b/services/keepstore/s3_volume.go
@@ -9,7 +9,6 @@ import (
"fmt"
"io"
"io/ioutil"
- "log"
"net/http"
"os"
"regexp"
@@ -20,6 +19,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/arvados"
"github.com/AdRoll/goamz/aws"
"github.com/AdRoll/goamz/s3"
+ log "github.com/Sirupsen/logrus"
)
const (
diff --git a/services/keepstore/s3_volume_test.go b/services/keepstore/s3_volume_test.go
index 63b1862..acc290e 100644
--- a/services/keepstore/s3_volume_test.go
+++ b/services/keepstore/s3_volume_test.go
@@ -6,13 +6,13 @@ import (
"crypto/md5"
"fmt"
"io/ioutil"
- "log"
"os"
"time"
"git.curoverse.com/arvados.git/sdk/go/arvados"
"github.com/AdRoll/goamz/s3"
"github.com/AdRoll/goamz/s3/s3test"
+ log "github.com/Sirupsen/logrus"
check "gopkg.in/check.v1"
)
diff --git a/services/keepstore/trash_worker.go b/services/keepstore/trash_worker.go
index 27d6216..696c3e5 100644
--- a/services/keepstore/trash_worker.go
+++ b/services/keepstore/trash_worker.go
@@ -2,10 +2,10 @@ package main
import (
"errors"
- "log"
"time"
"git.curoverse.com/arvados.git/sdk/go/arvados"
+ log "github.com/Sirupsen/logrus"
)
// RunTrashWorker is used by Keepstore to initiate trash worker channel goroutine.
diff --git a/services/keepstore/usage.go b/services/keepstore/usage.go
index 29f89f5..887cfd3 100644
--- a/services/keepstore/usage.go
+++ b/services/keepstore/usage.go
@@ -48,6 +48,10 @@ Listen:
"address" is a host IP address or name and "port" is a port number
or name.
+LogFormat:
+
+ Format of request/response and error logs: "json" or "text".
+
PIDFile:
Path to write PID file during startup. This file is kept open and
diff --git a/services/keepstore/volume_unix.go b/services/keepstore/volume_unix.go
index 5239ed3..ee4f633 100644
--- a/services/keepstore/volume_unix.go
+++ b/services/keepstore/volume_unix.go
@@ -7,7 +7,6 @@ import (
"fmt"
"io"
"io/ioutil"
- "log"
"os"
"path/filepath"
"regexp"
@@ -16,6 +15,8 @@ import (
"sync"
"syscall"
"time"
+
+ log "github.com/Sirupsen/logrus"
)
type unixVolumeAdder struct {
-----------------------------------------------------------------------
hooks/post-receive
--
More information about the arvados-commits
mailing list