go: fix the async logger

Change-Id: I0e762e4590d8474ada265cd7c65811aba26cde16
This commit is contained in:
David Goetz
2016-03-28 22:21:04 -05:00
parent 3c4468b821
commit 7727b3a6ab
5 changed files with 30 additions and 30 deletions

View File

@@ -128,6 +128,7 @@ func CopyRequestHeaders(r *http.Request, dst *http.Request) {
type RequestLogger struct {
Request *http.Request
Logger SysLogLike
W *WebWriter
}
func (r RequestLogger) LogError(format string, args ...interface{}) {
@@ -145,13 +146,13 @@ func (r RequestLogger) LogDebug(format string, args ...interface{}) {
r.Logger.Debug(fmt.Sprintf(format, args...) + " (txn:" + transactionId + ")")
}
func (r RequestLogger) LogPanics(w *WebWriter) {
func (r RequestLogger) LogPanics(msg string) {
if e := recover(); e != nil {
transactionId := r.Request.Header.Get("X-Trans-Id")
r.Logger.Err(fmt.Sprintf("PANIC: %s: %s", e, debug.Stack()) + " (txn:" + transactionId + ")")
r.Logger.Err(fmt.Sprintf("PANIC (%s): %s: %s", msg, e, debug.Stack()) + " (txn:" + transactionId + ")")
// if we haven't set a status code yet, we can send a 500 response.
if !w.ResponseStarted {
StandardResponse(w, http.StatusInternalServerError)
if !r.W.ResponseStarted {
StandardResponse(r.W, http.StatusInternalServerError)
}
}
}
@@ -164,6 +165,7 @@ type LoggingContext interface {
LogError(format string, args ...interface{})
LogInfo(format string, args ...interface{})
LogDebug(format string, args ...interface{})
LogPanics(format string)
}
type SysLogLike interface {

View File

@@ -319,7 +319,7 @@ func (server *ObjectServer) ObjPutHandler(writer http.ResponseWriter, request *h
}
InvalidateHash(hashDir)
}()
server.containerUpdates(request, metadata, request.Header.Get("X-Delete-At"), vars)
server.containerUpdates(request, metadata, request.Header.Get("X-Delete-At"), vars, hummingbird.GetLogger(request))
hummingbird.StandardResponse(writer, http.StatusCreated)
}
@@ -434,7 +434,7 @@ func (server *ObjectServer) ObjDeleteHandler(writer http.ResponseWriter, request
}
InvalidateHash(hashDir)
}()
server.containerUpdates(request, metadata, deleteAt, vars)
server.containerUpdates(request, metadata, deleteAt, vars, hummingbird.GetLogger(request))
hummingbird.StandardResponse(writer, responseStatus)
}
@@ -589,9 +589,9 @@ func (server *ObjectServer) DiskUsageHandler(writer http.ResponseWriter, request
}
func (server *ObjectServer) LogRequest(next http.Handler) http.Handler {
fn := func(writer http.ResponseWriter, request *http.Request) {
requestLogger := &hummingbird.RequestLogger{Request: request, Logger: server.logger}
newWriter := &hummingbird.WebWriter{ResponseWriter: writer, Status: 500, ResponseStarted: false}
defer requestLogger.LogPanics(newWriter)
requestLogger := &hummingbird.RequestLogger{Request: request, Logger: server.logger, W: newWriter}
defer requestLogger.LogPanics("LOGGING REQUEST")
start := time.Now()
hummingbird.SetLogger(request, requestLogger)
next.ServeHTTP(newWriter, request)

View File

@@ -108,7 +108,7 @@ func (server *ObjectServer) saveAsync(method, account, container, obj, localDevi
}
}
func (server *ObjectServer) updateContainer(metadata map[string]string, request *http.Request, vars map[string]string) {
func (server *ObjectServer) updateContainer(metadata map[string]string, request *http.Request, vars map[string]string, logger hummingbird.LoggingContext) {
partition := request.Header.Get("X-Container-Partition")
hosts := splitHeader(request.Header.Get("X-Container-Host"))
devices := splitHeader(request.Header.Get("X-Container-Device"))
@@ -129,7 +129,7 @@ func (server *ObjectServer) updateContainer(metadata map[string]string, request
failures := 0
for index := range hosts {
if !server.sendContainerUpdate(hosts[index], devices[index], request.Method, partition, vars["account"], vars["container"], vars["obj"], requestHeaders) {
hummingbird.GetLogger(request).LogError("ERROR container update failed with %s/%s (saving for async update later)", hosts[index], devices[index])
logger.LogError("ERROR container update failed with %s/%s (saving for async update later)", hosts[index], devices[index])
failures++
}
}
@@ -138,7 +138,7 @@ func (server *ObjectServer) updateContainer(metadata map[string]string, request
}
}
func (server *ObjectServer) updateDeleteAt(request *http.Request, deleteAtStr string, vars map[string]string) {
func (server *ObjectServer) updateDeleteAt(request *http.Request, deleteAtStr string, vars map[string]string, logger hummingbird.LoggingContext) {
deleteAt, err := hummingbird.ParseDate(deleteAtStr)
if err != nil {
return
@@ -165,7 +165,7 @@ func (server *ObjectServer) updateDeleteAt(request *http.Request, deleteAtStr st
failures := 0
for index := range hosts {
if !server.sendContainerUpdate(hosts[index], devices[index], request.Method, partition, deleteAtAccount, container, obj, requestHeaders) {
hummingbird.GetLogger(request).LogError("ERROR container update failed with %s/%s (saving for async update later)", hosts[index], devices[index])
logger.LogError("ERROR container update failed with %s/%s (saving for async update later)", hosts[index], devices[index])
failures++
}
}
@@ -174,14 +174,15 @@ func (server *ObjectServer) updateDeleteAt(request *http.Request, deleteAtStr st
}
}
func (server *ObjectServer) containerUpdates(request *http.Request, metadata map[string]string, deleteAt string, vars map[string]string) {
func (server *ObjectServer) containerUpdates(request *http.Request, metadata map[string]string, deleteAt string, vars map[string]string, logger hummingbird.LoggingContext) {
defer logger.LogPanics("PANIC WHILE UPDATING CONTAINER LISTINGS")
if deleteAt != "" {
go server.updateDeleteAt(request, deleteAt, vars)
go server.updateDeleteAt(request, deleteAt, vars, logger)
}
firstDone := make(chan struct{}, 1)
go func() {
server.updateContainer(metadata, request, vars)
server.updateContainer(metadata, request, vars, logger)
firstDone <- struct{}{}
}()
go func() {

View File

@@ -40,10 +40,6 @@ func (a *DummyLogger) LogPanics(m string) {
}
}
func addDummyLogger(req *http.Request) {
hummingbird.SetLogger(req, &DummyLogger{})
}
func TestExpirerContainer(t *testing.T) {
ts, err := makeObjectServer()
require.Nil(t, err)
@@ -92,17 +88,17 @@ func TestUpdateDeleteAt(t *testing.T) {
req.Header.Add("X-Delete-At-Device", "sdb")
req.Header.Add("X-Timestamp", "12345.6789")
addDummyLogger(req)
dl := DummyLogger{}
vars := map[string]string{"account": "a", "container": "c", "obj": "o", "device": "sda"}
hummingbird.SetVars(req, vars)
defer context.Clear(req)
deleteAtStr := "1434707411"
server.updateDeleteAt(req, deleteAtStr, vars)
server.updateDeleteAt(req, deleteAtStr, vars, &dl)
require.True(t, requestSent)
cs.Close()
server.updateDeleteAt(req, deleteAtStr, vars)
server.updateDeleteAt(req, deleteAtStr, vars, &dl)
expectedFile := filepath.Join(ts.root, "sda", "async_pending", "8fc", "02cc012fe572f27e455edbea32da78fc-12345.6789")
require.True(t, hummingbird.Exists(expectedFile))
data, err := ioutil.ReadFile(expectedFile)
@@ -131,7 +127,7 @@ func TestUpdateDeleteAtNoHeaders(t *testing.T) {
hummingbird.SetVars(req, vars)
defer context.Clear(req)
deleteAtStr := "1434707411"
server.updateDeleteAt(req, deleteAtStr, vars)
server.updateDeleteAt(req, deleteAtStr, vars, &DummyLogger{})
expectedFile := filepath.Join(ts.root, "sda", "async_pending", "8fc", "02cc012fe572f27e455edbea32da78fc-12345.6789")
require.True(t, hummingbird.Exists(expectedFile))
data, err := ioutil.ReadFile(expectedFile)
@@ -171,7 +167,7 @@ func TestUpdateContainer(t *testing.T) {
req.Header.Add("X-Container-Device", "sdb")
req.Header.Add("X-Timestamp", "12345.6789")
addDummyLogger(req)
dl := DummyLogger{}
vars := map[string]string{"account": "a", "container": "c", "obj": "o", "device": "sda"}
hummingbird.SetVars(req, vars)
@@ -182,11 +178,11 @@ func TestUpdateContainer(t *testing.T) {
"Content-Length": "30",
"ETag": "ffffffffffffffffffffffffffffffff",
}
server.updateContainer(metadata, req, vars)
server.updateContainer(metadata, req, vars, &dl)
require.True(t, requestSent)
cs.Close()
server.updateContainer(metadata, req, vars)
server.updateContainer(metadata, req, vars, &dl)
expectedFile := filepath.Join(ts.root, "sda", "async_pending", "099", "2f714cd91b0e5d803cde2012b01d7099-12345.6789")
require.True(t, hummingbird.Exists(expectedFile))
data, err := ioutil.ReadFile(expectedFile)
@@ -226,11 +222,12 @@ func TestUpdateContainerNoHeaders(t *testing.T) {
"Content-Length": "30",
"ETag": "ffffffffffffffffffffffffffffffff",
}
server.updateContainer(metadata, req, vars)
dl := DummyLogger{}
server.updateContainer(metadata, req, vars, &dl)
require.False(t, requestSent)
cs.Close()
server.updateContainer(metadata, req, vars)
server.updateContainer(metadata, req, vars, &dl)
expectedFile := filepath.Join(ts.root, "sda", "async_pending", "099", "2f714cd91b0e5d803cde2012b01d7099-12345.6789")
require.False(t, hummingbird.Exists(expectedFile))
}

View File

@@ -40,9 +40,9 @@ type ProxyServer struct {
func (server *ProxyServer) LogRequest(next http.Handler) http.Handler {
fn := func(writer http.ResponseWriter, request *http.Request) {
requestLogger := &hummingbird.RequestLogger{Request: request, Logger: server.logger}
newWriter := &hummingbird.WebWriter{ResponseWriter: writer, Status: 500, ResponseStarted: false}
defer requestLogger.LogPanics(newWriter)
requestLogger := &hummingbird.RequestLogger{Request: request, Logger: server.logger, W: newWriter}
defer requestLogger.LogPanics("LOGGING REQUEST")
start := time.Now()
hummingbird.SetLogger(request, requestLogger)
request.Header.Set("X-Trans-Id", hummingbird.GetTransactionId())