From 59ed0fc7da3f2e59115a203001b7e3ce7e5a6d91 Mon Sep 17 00:00:00 2001 From: Jordan Orelli Date: Sat, 1 Nov 2014 19:09:30 -0400 Subject: [PATCH] request ids --- global.go | 29 +++++++++++++++++++++++++++ main.go | 6 ++++-- requestId.go | 55 ++++++++++++++++++++++++++++++++++++++++++++++++++++ wrappers.go | 40 ++++++++++++++++++++++++++++++++++++++ 4 files changed, 128 insertions(+), 2 deletions(-) create mode 100644 global.go create mode 100644 requestId.go create mode 100644 wrappers.go diff --git a/global.go b/global.go new file mode 100644 index 0000000..5c3031c --- /dev/null +++ b/global.go @@ -0,0 +1,29 @@ +package main + +import ( + "crypto/md5" + "os" +) + +var global struct { + hostname string + machineId []byte + pid int + requestCounter uint32 +} + +func init() { + global.pid = os.Getpid() + var err error + global.hostname, err = os.Hostname() + if err != nil { + panic("failed to get hostname: " + err.Error()) + } + + hw := md5.New() + if _, err := hw.Write([]byte(global.hostname)); err != nil { + panic("unable to md5 hostname: " + err.Error()) + } + global.machineId = make([]byte, 3) + copy(global.machineId, hw.Sum(nil)) +} diff --git a/main.go b/main.go index 6555402..e8025e5 100644 --- a/main.go +++ b/main.go @@ -3,6 +3,7 @@ package main import ( "flag" "fmt" + "log" "net/http" "os" "strings" @@ -32,10 +33,10 @@ func main() { bail(1, "unable to get working directory: %v", err) } dir := http.Dir(cwd) - http.Handle("/", http.FileServer(dir)) + http.Handle("/", &logWrapper{http.FileServer(dir)}) addr := fmt.Sprintf("%s:%d", options.hostname, options.port) - fmt.Printf("serving %s on %s\n", cwd, addr) + log.Printf("init [pid: %d] [machineId: %x] [addr: %s] [cwd: %s]", global.pid, string(global.machineId), addr, cwd) if err := http.ListenAndServe(addr, nil); err != nil { bail(1, "unable to start server: %v", err) } @@ -44,4 +45,5 @@ func main() { func init() { flag.IntVar(&options.port, "port", 8000, "port to serve on") flag.StringVar(&options.hostname, "host", "", "hostname") + log.SetFlags(log.Ldate | log.Lmicroseconds) } diff --git a/requestId.go b/requestId.go new file mode 100644 index 0000000..d7b199c --- /dev/null +++ b/requestId.go @@ -0,0 +1,55 @@ +package main + +import ( + "encoding/binary" + "fmt" + "sync/atomic" + "time" +) + +// NewObjectId returns a new unique ObjectId. +// This function causes a runtime error if it fails to get the hostname +// of the current machine. +func newRequestId() RequestId { + b := make([]byte, 12) + // Timestamp, 4 bytes, big endian + binary.BigEndian.PutUint32(b, uint32(time.Now().Unix())) + b[4] = global.machineId[0] + b[5] = global.machineId[1] + b[6] = global.machineId[2] + // Pid, 2 bytes, specs don't specify endianness, but we use big endian. + b[7] = byte(global.pid >> 8) + b[8] = byte(global.pid) + // Increment, 3 bytes, big endian + i := atomic.AddUint32(&global.requestCounter, 1) + b[9] = byte(i >> 16) + b[10] = byte(i >> 8) + b[11] = byte(i) + return RequestId(b) +} + +// RequestId is used for tagging each incoming http request for logging +// purposes. The actual implementation is just the ObjectId implementation +// found in launchpad.net/mgo/bson. This will most likely change and evolve +// into its own format. +type RequestId string + +func (id RequestId) String() string { + return fmt.Sprintf("%x", string(id)) +} + +// Time returns the timestamp part of the id. +// It's a runtime error to call this method with an invalid id. +func (id RequestId) Time() time.Time { + secs := int64(binary.BigEndian.Uint32(id.byteSlice(0, 4))) + return time.Unix(secs, 0) +} + +// byteSlice returns byte slice of id from start to end. +// Calling this function with an invalid id will cause a runtime panic. +func (id RequestId) byteSlice(start, end int) []byte { + if len(id) != 12 { + panic(fmt.Sprintf("Invalid RequestId: %q", string(id))) + } + return []byte(string(id)[start:end]) +} diff --git a/wrappers.go b/wrappers.go new file mode 100644 index 0000000..1442458 --- /dev/null +++ b/wrappers.go @@ -0,0 +1,40 @@ +package main + +import ( + "log" + "net/http" + "time" +) + +type logWrapper struct { + http.Handler +} + +func (l *logWrapper) ServeHTTP(w http.ResponseWriter, r *http.Request) { + id := newRequestId() + log.Println(id, r.Method, r.URL) + statsThing := &writerWatcher{ResponseWriter: w} + start := time.Now() + l.Handler.ServeHTTP(statsThing, r) + log.Println(id, statsThing.headerWritten, statsThing.written, time.Since(start)) +} + +type writerWatcher struct { + http.ResponseWriter + written int + headerWritten int +} + +func (w *writerWatcher) Write(b []byte) (int, error) { + n, err := w.ResponseWriter.Write(b) + w.written += n + return n, err +} + +func (w *writerWatcher) WriteHeader(status int) { + if w.headerWritten != 0 { + log.Println("somehow we wrote two headers.") + } + w.headerWritten = status + w.ResponseWriter.WriteHeader(status) +}