Merge pull request #639 from harshavardhana/pr_out_enhance_logging_handler_to_print_in_humanize_form_for_contentlength

pkg/api/logging/logging.go

@@ -22,25 +22,31 @@ import (
 	"io"
 	"net/http"
 	"os"
+	"strconv"
 	"time"
 
+	"github.com/dustin/go-humanize"
 	"github.com/minio/minio/pkg/iodine"
 	"github.com/minio/minio/pkg/utils/log"
 )
 
 type logHandler struct {
 	http.Handler
-	Logger chan<- string
+	Logger chan<- []byte
 }
 
 // LogMessage is a serializable json log message
 type LogMessage struct {
-	Request         *http.Request
 	StartTime     time.Time
 	Duration      time.Duration
-	Status          int
-	StatusText      string
+	StatusMessage string // human readable http status message
+	ContentLength string // human readable content length
+
+	// HTTP detailed message
+	HTTP struct {
 		ResponseHeaders http.Header
+		Request         *http.Request
+	}
 }
 
 // LogWriter is used to capture status for log messages
@@ -51,8 +57,7 @@ type LogWriter struct {
 
 // WriteHeader writes headers and stores status in LogMessage
 func (w *LogWriter) WriteHeader(status int) {
-	w.LogMessage.StatusText = http.StatusText(status)
-	w.LogMessage.Status = status
+	w.LogMessage.StatusMessage = http.StatusText(status)
 	w.ResponseWriter.WriteHeader(status)
 }
 
@@ -72,11 +77,21 @@ func (h *logHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {
 	}
 	logWriter := &LogWriter{ResponseWriter: w, LogMessage: logMessage}
 	h.Handler.ServeHTTP(logWriter, req)
-	logMessage.ResponseHeaders = w.Header()
-	logMessage.Request = req
+	h.Logger <- getLogMessage(logMessage, w, req)
+}
+
+func getLogMessage(logMessage *LogMessage, w http.ResponseWriter, req *http.Request) []byte {
+	// store lower level details
+	logMessage.HTTP.ResponseHeaders = w.Header()
+	logMessage.HTTP.Request = req
+
+	// humanize content-length to be printed in logs
+	contentLength, _ := strconv.Atoi(logMessage.HTTP.ResponseHeaders.Get("Content-Length"))
+	logMessage.ContentLength = humanize.IBytes(uint64(contentLength))
 	logMessage.Duration = time.Now().UTC().Sub(logMessage.StartTime)
 	js, _ := json.Marshal(logMessage)
-	h.Logger <- string(js)
+	js = append(js, byte('\n')) // append a new line
+	return js
 }
 
 // LogHandler logs requests
@@ -86,15 +101,15 @@ func LogHandler(h http.Handler) http.Handler {
 }
 
 // FileLogger returns a channel that is used to write to the logger
-func FileLogger(filename string) (chan<- string, error) {
-	ch := make(chan string)
+func FileLogger(filename string) (chan<- []byte, error) {
+	ch := make(chan []byte)
 	file, err := os.OpenFile(filename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0600)
 	if err != nil {
 		return nil, iodine.New(err, map[string]string{"logfile": filename})
 	}
 	go func() {
 		for message := range ch {
-			if _, err := io.Copy(file, bytes.NewBufferString(message+"\n")); err != nil {
+			if _, err := io.Copy(file, bytes.NewBuffer(message)); err != nil {
 				log.Println(iodine.New(err, nil))
 			}
 		}