Merge pull request #173 from ivanpesin/log-request-id

Add request-id to verbose log messages
This commit is contained in:
Adnan Hajdarević 2017-09-14 19:34:47 +02:00 committed by GitHub
commit 71269d8b45

View file

@ -17,6 +17,7 @@ import (
"github.com/codegangsta/negroni" "github.com/codegangsta/negroni"
"github.com/gorilla/mux" "github.com/gorilla/mux"
"github.com/satori/go.uuid"
fsnotify "gopkg.in/fsnotify.v1" fsnotify "gopkg.in/fsnotify.v1"
) )
@ -198,7 +199,11 @@ func main() {
} }
func hookHandler(w http.ResponseWriter, r *http.Request) { func hookHandler(w http.ResponseWriter, r *http.Request) {
log.Printf("incoming HTTP request from %s\n", r.RemoteAddr)
// generate a request id for logging
rid := uuid.NewV4().String()[:6]
log.Printf("[%s] incoming HTTP request from %s\n", rid, r.RemoteAddr)
for _, responseHeader := range responseHeaders { for _, responseHeader := range responseHeaders {
w.Header().Set(responseHeader.Name, responseHeader.Value) w.Header().Set(responseHeader.Name, responseHeader.Value)
@ -207,11 +212,11 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
id := mux.Vars(r)["id"] id := mux.Vars(r)["id"]
if matchedHook := matchLoadedHook(id); matchedHook != nil { if matchedHook := matchLoadedHook(id); matchedHook != nil {
log.Printf("%s got matched\n", id) log.Printf("[%s] %s got matched\n", rid, id)
body, err := ioutil.ReadAll(r.Body) body, err := ioutil.ReadAll(r.Body)
if err != nil { if err != nil {
log.Printf("error reading the request body. %+v\n", err) log.Printf("[%s] error reading the request body. %+v\n", rid, err)
} }
// parse headers // parse headers
@ -232,12 +237,12 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
err := decoder.Decode(&payload) err := decoder.Decode(&payload)
if err != nil { if err != nil {
log.Printf("error parsing JSON payload %+v\n", err) log.Printf("[%s] error parsing JSON payload %+v\n", rid, err)
} }
} else if strings.Contains(contentType, "form") { } else if strings.Contains(contentType, "form") {
fd, err := url.ParseQuery(string(body)) fd, err := url.ParseQuery(string(body))
if err != nil { if err != nil {
log.Printf("error parsing form payload %+v\n", err) log.Printf("[%s] error parsing form payload %+v\n", rid, err)
} else { } else {
payload = valuesToMap(fd) payload = valuesToMap(fd)
} }
@ -246,7 +251,7 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
// handle hook // handle hook
if errors := matchedHook.ParseJSONParameters(&headers, &query, &payload); errors != nil { if errors := matchedHook.ParseJSONParameters(&headers, &query, &payload); errors != nil {
for _, err := range errors { for _, err := range errors {
log.Printf("error parsing JSON parameters: %s\n", err) log.Printf("[%s] error parsing JSON parameters: %s\n", rid, err)
} }
} }
@ -257,7 +262,7 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
} else { } else {
ok, err = matchedHook.TriggerRule.Evaluate(&headers, &query, &payload, &body, r.RemoteAddr) ok, err = matchedHook.TriggerRule.Evaluate(&headers, &query, &payload, &body, r.RemoteAddr)
if err != nil { if err != nil {
msg := fmt.Sprintf("error evaluating hook: %s", err) msg := fmt.Sprintf("[%s] error evaluating hook: %s", rid, err)
log.Printf(msg) log.Printf(msg)
w.WriteHeader(http.StatusInternalServerError) w.WriteHeader(http.StatusInternalServerError)
fmt.Fprintf(w, "Error occurred while evaluating hook rules.") fmt.Fprintf(w, "Error occurred while evaluating hook rules.")
@ -266,14 +271,14 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
} }
if ok { if ok {
log.Printf("%s hook triggered successfully\n", matchedHook.ID) log.Printf("[%s] %s hook triggered successfully\n", rid, matchedHook.ID)
for _, responseHeader := range matchedHook.ResponseHeaders { for _, responseHeader := range matchedHook.ResponseHeaders {
w.Header().Set(responseHeader.Name, responseHeader.Value) w.Header().Set(responseHeader.Name, responseHeader.Value)
} }
if matchedHook.CaptureCommandOutput { if matchedHook.CaptureCommandOutput {
response, err := handleHook(matchedHook, &headers, &query, &payload, &body) response, err := handleHook(matchedHook, rid, &headers, &query, &payload, &body)
if err != nil { if err != nil {
w.Header().Set("Content-Type", "text/plain; charset=utf-8") w.Header().Set("Content-Type", "text/plain; charset=utf-8")
@ -283,7 +288,7 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
fmt.Fprintf(w, response) fmt.Fprintf(w, response)
} }
} else { } else {
go handleHook(matchedHook, &headers, &query, &payload, &body) go handleHook(matchedHook, rid, &headers, &query, &payload, &body)
fmt.Fprintf(w, matchedHook.ResponseMessage) fmt.Fprintf(w, matchedHook.ResponseMessage)
} }
return return
@ -296,12 +301,12 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
if len(http.StatusText(matchedHook.TriggerRuleMismatchHttpResponseCode)) > 0 { if len(http.StatusText(matchedHook.TriggerRuleMismatchHttpResponseCode)) > 0 {
w.WriteHeader(matchedHook.TriggerRuleMismatchHttpResponseCode) w.WriteHeader(matchedHook.TriggerRuleMismatchHttpResponseCode)
} else { } else {
log.Printf("%s got matched, but the configured return code %d is unknown - defaulting to 200\n", matchedHook.ID, matchedHook.TriggerRuleMismatchHttpResponseCode) log.Printf("[%s] %s got matched, but the configured return code %d is unknown - defaulting to 200\n", rid, matchedHook.ID, matchedHook.TriggerRuleMismatchHttpResponseCode)
} }
} }
// if none of the hooks got triggered // if none of the hooks got triggered
log.Printf("%s got matched, but didn't get triggered because the trigger rules were not satisfied\n", matchedHook.ID) log.Printf("[%s] %s got matched, but didn't get triggered because the trigger rules were not satisfied\n", rid, matchedHook.ID)
fmt.Fprintf(w, "Hook rules were not satisfied.") fmt.Fprintf(w, "Hook rules were not satisfied.")
} else { } else {
@ -310,7 +315,7 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
} }
} }
func handleHook(h *hook.Hook, headers, query, payload *map[string]interface{}, body *[]byte) (string, error) { func handleHook(h *hook.Hook, rid string, headers, query, payload *map[string]interface{}, body *[]byte) (string, error) {
var errors []error var errors []error
cmd := exec.Command(h.ExecuteCommand) cmd := exec.Command(h.ExecuteCommand)
@ -319,7 +324,7 @@ func handleHook(h *hook.Hook, headers, query, payload *map[string]interface{}, b
cmd.Args, errors = h.ExtractCommandArguments(headers, query, payload) cmd.Args, errors = h.ExtractCommandArguments(headers, query, payload)
if errors != nil { if errors != nil {
for _, err := range errors { for _, err := range errors {
log.Printf("error extracting command arguments: %s\n", err) log.Printf("[%s] error extracting command arguments: %s\n", rid, err)
} }
} }
@ -328,23 +333,23 @@ func handleHook(h *hook.Hook, headers, query, payload *map[string]interface{}, b
if errors != nil { if errors != nil {
for _, err := range errors { for _, err := range errors {
log.Printf("error extracting command arguments for environment: %s\n", err) log.Printf("[%s] error extracting command arguments for environment: %s\n", rid, err)
} }
} }
cmd.Env = append(os.Environ(), envs...) cmd.Env = append(os.Environ(), envs...)
log.Printf("executing %s (%s) with arguments %q and environment %s using %s as cwd\n", h.ExecuteCommand, cmd.Path, cmd.Args, envs, cmd.Dir) log.Printf("[%s] executing %s (%s) with arguments %q and environment %s using %s as cwd\n", rid, h.ExecuteCommand, cmd.Path, cmd.Args, envs, cmd.Dir)
out, err := cmd.CombinedOutput() out, err := cmd.CombinedOutput()
log.Printf("command output: %s\n", out) log.Printf("[%s] command output: %s\n", rid, out)
if err != nil { if err != nil {
log.Printf("error occurred: %+v\n", err) log.Printf("[%s] error occurred: %+v\n", rid, err)
} }
log.Printf("finished handling %s\n", h.ID) log.Printf("[%s] finished handling %s\n", rid, h.ID)
return string(out), err return string(out), err
} }