From 625515d237a2865fe9d7d64d84065f316384ba5b Mon Sep 17 00:00:00 2001 From: Patrick Hener Date: Fri, 15 Nov 2024 11:45:56 +0100 Subject: [PATCH] refine verbose logging and add request body logging for arbitrary post requests. Also detect and decode base64 strings --- httpserver/log.go | 13 +++++++ httpserver/server.go | 14 +++++-- logger/logger.go | 89 +++++++++++++++++++++++++++++++++++++------- 3 files changed, 100 insertions(+), 16 deletions(-) create mode 100644 httpserver/log.go diff --git a/httpserver/log.go b/httpserver/log.go new file mode 100644 index 0000000..60921d3 --- /dev/null +++ b/httpserver/log.go @@ -0,0 +1,13 @@ +package httpserver + +import ( + "net/http" + + "github.com/patrickhener/goshs/logger" +) + +func (fs *FileServer) logOnly(w http.ResponseWriter, req *http.Request) { + logger.LogRequest(req, http.StatusOK, fs.Verbose) + w.WriteHeader(200) + w.Write([]byte("ok\n")) +} diff --git a/httpserver/server.go b/httpserver/server.go index 530935d..6038745 100644 --- a/httpserver/server.go +++ b/httpserver/server.go @@ -26,9 +26,17 @@ func (fs *FileServer) SetupMux(mux *mux.Router, what string) string { switch what { case modeWeb: mux.Methods(http.MethodPost).HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - fs.upload(w, r) - // Run garbage collector to make sure file handle is synced and close properly - runtime.GC() + logger.Debug("POST request incoming") + logger.Debug(r.URL.Path) + if r.URL.Path == "/upload" { + logger.Debug("This is a valid upload request") + fs.upload(w, r) + // Run garbage collector to make sure file handle is synced and close properly + runtime.GC() + } else { + logger.Debug("This is meant to be used with verbose logging") + fs.logOnly(w, r) + } }) mux.PathPrefix("/").HandlerFunc(fs.handler) diff --git a/logger/logger.go b/logger/logger.go index bc5138b..809c510 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -6,15 +6,36 @@ import ( "encoding/base64" "encoding/json" "fmt" + "io" "net/http" + "net/url" "os" "strings" "github.com/sirupsen/logrus" ) +func isBase64(s string) bool { + _, err := base64.StdEncoding.DecodeString(s) + return err == nil +} + +func validateAndParseJSON(input []byte) (bool, interface{}) { + var data interface{} + + // Attempt to unmarshal the input + err := json.Unmarshal(input, &data) + if err != nil { + return false, nil + } + + // If successful, return true and the parsed JSON + return true, data +} + // LogRequest will log the request in a uniform way func LogRequest(req *http.Request, status int, verbose bool) { + logger.Debug("We are about to log a request") if status == http.StatusInternalServerError || status == http.StatusNotFound || status == http.StatusUnauthorized { logger.Errorf("%s - [\x1b[1;31m%d\x1b[0m] - \"%s %s %s\"", req.RemoteAddr, status, req.Method, req.URL, req.Proto) } else if status == http.StatusSeeOther || status == http.StatusMovedPermanently || status == http.StatusTemporaryRedirect || status == http.StatusPermanentRedirect { @@ -30,12 +51,15 @@ func LogRequest(req *http.Request, status int, verbose bool) { } } if verbose { + logger.Debug("We are using verbose logging") logVerbose(req) } } func logVerbose(req *http.Request) { + // User Agent logger.Infof("User Agent: %s", req.UserAgent()) + // Authentication auth := req.Header.Get("Authorization") if auth != "" { logger.Infof("Authorization Header: %s", auth) @@ -48,23 +72,62 @@ func logVerbose(req *http.Request) { logger.Infof("Decoded Authorization is: '%s'", decodedAuth) } } + // URL Parameter for k, v := range req.URL.Query() { logger.Infof("Parameter %s is", k) - var x struct{} - if err := json.Unmarshal([]byte(v[0]), &x); err != nil { - logger.Debug("Not JSON format printing plain") - fmt.Println(v[0]) - } else { + input, err := url.QueryUnescape(v[0]) + if err != nil { + logger.Warnf("error unescaping url parameter: %+v", err) + } + isValid, _ := validateAndParseJSON([]byte(input)) + if isValid { + logger.Debug("JSON format detected") dst := &bytes.Buffer{} - err := json.Indent(dst, []byte(v[0]), "", " ") - if err != nil { - logger.Debug("Not JSON format printing plain") - fmt.Println(v[0]) - } else { - logger.Debug("It is JSON - pretty print") - // fmt.Println(v[0]) - fmt.Println(dst.String()) + json.Indent(dst, []byte(v[0]), "", " ") + fmt.Println(dst.String()) + continue + } + + if isBase64(v[0]) { + logger.Debug("Base64 detected") + logger.Info("Decoding Base64 before printing") + decodedBytes, _ := base64.StdEncoding.DecodeString(v[0]) + fmt.Println(string(decodedBytes)) + + continue + } + + logger.Debug("Neither JSON nor Base64 parameter, so printing plain") + fmt.Println(v[0]) + } + + // Body + if req.Body != nil { + logger.Debug("Body is detected") + body, err := io.ReadAll(req.Body) + if err != nil { + Warnf("error reading body: %+v", err) + } + defer req.Body.Close() + + if len(body) > 0 { + logger.Debug("Body is actually not empty") + if req.Header.Get("Content-Type") == "application/json" { + var prettyJson bytes.Buffer + err := json.Indent(&prettyJson, body, "", " ") + if err != nil { + Warnf("error printing pretty json body: %+v", err) + } + logger.Infof("JSON Request Body: \n%s\n", prettyJson.String()) + return } + if isBase64(string(body)) { + decodedBytes, _ := base64.StdEncoding.DecodeString(string(body)) + logger.Infof("Base64 Request Body: \n%s\n", decodedBytes) + return + } + + logger.Infof("Request Body: \n%s\n", body) } } }