diff --git a/client/endpoint.go b/client/endpoint.go index 0267817..bb9f8f6 100644 --- a/client/endpoint.go +++ b/client/endpoint.go @@ -7,13 +7,13 @@ import ( "github.com/goclarum/clarum/core/config" "github.com/goclarum/clarum/core/control" "github.com/goclarum/clarum/core/durations" + "github.com/goclarum/clarum/core/logging" clarumstrings "github.com/goclarum/clarum/core/validators/strings" "github.com/goclarum/clarum/http/constants" "github.com/goclarum/clarum/http/internal/utils" "github.com/goclarum/clarum/http/internal/validators" "github.com/goclarum/clarum/http/message" "io" - "log/slog" "net/http" "time" ) @@ -24,6 +24,7 @@ type Endpoint struct { contentType string client *http.Client responseChannel chan *responsePair + logger *logging.Logger } type responsePair struct { @@ -31,6 +32,7 @@ type responsePair struct { error error } +// TODO: handle empty name func newEndpoint(name string, baseUrl string, contentType string, timeout time.Duration) *Endpoint { client := http.Client{ Timeout: durations.GetDurationWithDefault(timeout, 10*time.Second), @@ -42,44 +44,43 @@ func newEndpoint(name string, baseUrl string, contentType string, timeout time.D contentType: contentType, client: &client, responseChannel: make(chan *responsePair), + logger: logging.NewLogger(clientLogPrefix(name)), } } func (endpoint *Endpoint) send(message *message.RequestMessage) error { - logPrefix := clientLogPrefix(endpoint.name) - if message == nil { - return handleError("%s: message to send is nil", logPrefix) + return endpoint.handleError("message to send is nil", nil) } - slog.Debug(fmt.Sprintf("%s: message to send %s", logPrefix, message.ToString())) + endpoint.logger.Debugf("message to send %s", message.ToString()) messageToSend := endpoint.getMessageToSend(message) - slog.Debug(fmt.Sprintf("%s: will send message %s", logPrefix, messageToSend.ToString())) + endpoint.logger.Debugf("will send message %s", messageToSend.ToString()) - if err := validateMessageToSend(logPrefix, messageToSend); err != nil { + if err := endpoint.validateMessageToSend(messageToSend); err != nil { return err } - req, err := buildRequest(endpoint.name, messageToSend) + req, err := endpoint.buildRequest(messageToSend) // we return error here directly and not in the goroutine below // this way we can signal to the test synchronously that there was an error if err != nil { - return handleError("%s: canceled message - %s", logPrefix, err) + return endpoint.handleError("canceled message", err) } go func() { control.RunningActions.Add(1) defer control.RunningActions.Done() - logOutgoingRequest(logPrefix, message.MessagePayload, req) + endpoint.logOutgoingRequest(message.MessagePayload, req) res, err := endpoint.client.Do(req) // we log the error here directly, but will do error handling downstream if err != nil { - slog.Error(fmt.Sprintf("%s: error on response - %s", logPrefix, err)) + endpoint.logger.Errorf("error on response - %s", err) } else { - logIncomingResponse(logPrefix, res) + endpoint.logIncomingResponse(res) } responsePair := &responsePair{ @@ -91,7 +92,7 @@ func (endpoint *Endpoint) send(message *message.RequestMessage) error { // we send the error downstream for it to be returned when an action is called case endpoint.responseChannel <- responsePair: case <-time.After(config.ActionTimeout()): - handleError("%s: action timed out - no client receive action called in test", logPrefix) + endpoint.handleError("action timed out - no client receive action called in test", nil) } }() @@ -100,25 +101,24 @@ func (endpoint *Endpoint) send(message *message.RequestMessage) error { // validationOptions pass by value is intentional func (endpoint *Endpoint) receive(message *message.ResponseMessage, validationOptions receiveOptions) (*http.Response, error) { - logPrefix := clientLogPrefix(endpoint.name) - slog.Debug(fmt.Sprintf("%s: message to receive %s", logPrefix, message.ToString())) + endpoint.logger.Debugf("message to receive %s", message.ToString()) select { case responsePair := <-endpoint.responseChannel: if responsePair.error != nil { - return responsePair.response, handleError("%s: error while receiving response - %s", logPrefix, responsePair.error) + return responsePair.response, endpoint.handleError("error while receiving response", responsePair.error) } messageToReceive := endpoint.getMessageToReceive(message) - slog.Debug(fmt.Sprintf("%s: validating message %s", logPrefix, messageToReceive.ToString())) + endpoint.logger.Debugf("validating message %s", messageToReceive.ToString()) return responsePair.response, errors.Join( - validators.ValidateHttpStatusCode(logPrefix, messageToReceive, responsePair.response.StatusCode), - validators.ValidateHttpHeaders(logPrefix, &messageToReceive.Message, responsePair.response.Header), - validators.ValidateHttpPayload(logPrefix, &messageToReceive.Message, responsePair.response.Body, - validationOptions.expectedPayloadType)) + validators.ValidateHttpStatusCode(messageToReceive, responsePair.response.StatusCode, endpoint.logger), + validators.ValidateHttpHeaders(&messageToReceive.Message, responsePair.response.Header, endpoint.logger), + validators.ValidateHttpPayload(&messageToReceive.Message, responsePair.response.Body, + validationOptions.expectedPayloadType, endpoint.logger)) case <-time.After(config.ActionTimeout()): - return nil, handleError("%s: receive action timed out - no response received for validation", logPrefix) + return nil, endpoint.handleError("receive action timed out - no response received for validation", nil) } } @@ -151,26 +151,26 @@ func (endpoint *Endpoint) getMessageToReceive(message *message.ResponseMessage) return finalMessage } -func validateMessageToSend(prefix string, messageToSend *message.RequestMessage) error { +func (endpoint *Endpoint) validateMessageToSend(messageToSend *message.RequestMessage) error { if clarumstrings.IsBlank(messageToSend.Method) { - return handleError("%s: message to send is invalid - missing HTTP method", prefix) + return endpoint.handleError("message to send is invalid - missing HTTP method", nil) } if clarumstrings.IsBlank(messageToSend.Url) { - return handleError("%s: message to send is invalid - missing url", prefix) + return endpoint.handleError("message to send is invalid - missing url", nil) } if !utils.IsValidUrl(messageToSend.Url) { - return handleError("%s: message to send is invalid - invalid url", prefix) + return endpoint.handleError("message to send is invalid - invalid url", nil) } return nil } -func buildRequest(prefix string, message *message.RequestMessage) (*http.Request, error) { +func (endpoint *Endpoint) buildRequest(message *message.RequestMessage) (*http.Request, error) { url := utils.BuildPath(message.Url, message.Path) req, err := http.NewRequest(message.Method, url, bytes.NewBufferString(message.MessagePayload)) if err != nil { - slog.Error(fmt.Sprintf("%s: error - %s", prefix, err)) + endpoint.logger.Errorf("error - %s", err) return nil, err } @@ -189,44 +189,49 @@ func buildRequest(prefix string, message *message.RequestMessage) (*http.Request return req, nil } -func handleError(format string, a ...any) error { - errorMessage := fmt.Sprintf(format, a...) - slog.Error(errorMessage) - return errors.New(errorMessage) +func (endpoint *Endpoint) handleError(message string, err error) error { + var errorMessage string + if err != nil { + errorMessage = message + " - " + err.Error() + } else { + errorMessage = message + } + endpoint.logger.Errorf(errorMessage) + return errors.New(endpoint.logger.Prefix() + errorMessage) } -func logOutgoingRequest(prefix string, payload string, req *http.Request) { - slog.Info(fmt.Sprintf("%s: sending request ["+ +func (endpoint *Endpoint) logOutgoingRequest(payload string, req *http.Request) { + endpoint.logger.Infof("sending HTTP request ["+ "method: %s, "+ "url: %s, "+ "headers: %s, "+ "payload: %s"+ "]", - prefix, req.Method, req.URL, req.Header, payload)) + req.Method, req.URL, req.Header, payload) } // we read the body 'as is' for logging, after which we put it back into the response // with an open reader so that it can be read downstream again -func logIncomingResponse(prefix string, res *http.Response) { +func (endpoint *Endpoint) logIncomingResponse(res *http.Response) { bodyBytes, _ := io.ReadAll(res.Body) bodyString := "" err := res.Body.Close() if err != nil { - slog.Error(fmt.Sprintf("%s: could not read response body - %s", prefix, err)) + endpoint.logger.Errorf("could not read response body - %s", err) } else { res.Body = io.NopCloser(bytes.NewBuffer(bodyBytes)) bodyString = string(bodyBytes) } - slog.Info(fmt.Sprintf("%s: received response ["+ + endpoint.logger.Infof("received HTTP response ["+ "status: %s, "+ "headers: %s, "+ "payload: %s"+ "]", - prefix, res.Status, res.Header, bodyString)) + res.Status, res.Header, bodyString) } func clientLogPrefix(endpointName string) string { - return fmt.Sprintf("HTTP client %s", endpointName) + return fmt.Sprintf("%s: ", endpointName) } diff --git a/client/endpoint_test.go b/client/endpoint_test.go index 91c573c..d17cccc 100644 --- a/client/endpoint_test.go +++ b/client/endpoint_test.go @@ -121,37 +121,40 @@ func TestGetMessageToReceiveNoChangeInFinalResponse(t *testing.T) { } func TestValidateMessageToSend(t *testing.T) { + endpoint := newEndpoint("name", "baseUrl", "", 0) request := message.Get("my-url"). BaseUrl("http://localhost:8080") - if err := validateMessageToSend("prefix", request); err != nil { + if err := endpoint.validateMessageToSend(request); err != nil { t.Errorf("request must be valid") } request = message.Get("my-url") - if err := validateMessageToSend("prefix", request); !(err != nil && err.Error() == "prefix: message to send is invalid - missing url") { + if err := endpoint.validateMessageToSend(request); !(err != nil && err.Error() == "name: message to send is invalid - missing url") { t.Errorf("invalid error") } request = message.Get("my-url").BaseUrl("something") - if err := validateMessageToSend("prefix", request); !(err != nil && err.Error() == "prefix: message to send is invalid - invalid url") { + if err := endpoint.validateMessageToSend(request); !(err != nil && err.Error() == "name: message to send is invalid - invalid url") { t.Errorf("invalid error") } request = &message.RequestMessage{} - if err := validateMessageToSend("prefix", request); !(err != nil && err.Error() == "prefix: message to send is invalid - missing HTTP method") { + if err := endpoint.validateMessageToSend(request); !(err != nil && err.Error() == "name: message to send is invalid - missing HTTP method") { t.Errorf("invalid error") } } func TestBuildRequest(t *testing.T) { + endpoint := newEndpoint("name", "baseUrl", "", 0) + requestMessage := message.Post("my", "api/v0"). BaseUrl("http://localhost:8080"). ContentType("text/plain"). QueryParam("someParameter", "someValue"). Payload("batman!") - newRequest, err := buildRequest("prefix", requestMessage) + newRequest, err := endpoint.buildRequest(requestMessage) if err != nil { t.Errorf("error is unexpected") } diff --git a/internal/validators/validators.go b/internal/validators/validators.go index be0db84..08aea78 100644 --- a/internal/validators/validators.go +++ b/internal/validators/validators.go @@ -6,6 +6,7 @@ import ( "github.com/go-clarum/clarum-json/comparator" "github.com/go-clarum/clarum-json/recorder" "github.com/goclarum/clarum/core/arrays" + "github.com/goclarum/clarum/core/logging" clarumstrings "github.com/goclarum/clarum/core/validators/strings" "github.com/goclarum/clarum/http/internal" "github.com/goclarum/clarum/http/message" @@ -17,36 +18,36 @@ import ( "strings" ) -func ValidatePath(logPrefix string, expectedMessage *message.RequestMessage, actualUrl *url.URL) error { +func ValidatePath(expectedMessage *message.RequestMessage, actualUrl *url.URL, logger *logging.Logger) error { cleanedExpected := cleanPath(expectedMessage.Path) cleanedActual := cleanPath(actualUrl.Path) if cleanedExpected != cleanedActual { - return handleError("%s: validation error - HTTP path mismatch - expected [%s] but received [%s]", - logPrefix, cleanedExpected, cleanedActual) + return handleError(logger, "validation error - HTTP path mismatch - expected [%s] but received [%s]", + cleanedExpected, cleanedActual) } else { - slog.Info(fmt.Sprintf("%s: HTTP path validation successful", logPrefix)) + logger.Info("HTTP path validation successful") } return nil } -func ValidateHttpMethod(logPrefix string, expectedMessage *message.RequestMessage, actualMethod string) error { +func ValidateHttpMethod(expectedMessage *message.RequestMessage, actualMethod string, logger *logging.Logger) error { if expectedMessage.Method != actualMethod { - return handleError("%s: validation error - HTTP method mismatch - expected [%s] but received [%s]", - logPrefix, expectedMessage.Method, actualMethod) + return handleError(logger, "validation error - HTTP method mismatch - expected [%s] but received [%s]", + expectedMessage.Method, actualMethod) } else { - slog.Info(fmt.Sprintf("%s: HTTP method validation successful", logPrefix)) + logger.Info("HTTP method validation successful") } return nil } -func ValidateHttpHeaders(logPrefix string, expectedMessage *message.Message, actualHeaders http.Header) error { +func ValidateHttpHeaders(expectedMessage *message.Message, actualHeaders http.Header, logger *logging.Logger) error { if err := validateHeaders(expectedMessage, actualHeaders); err != nil { - return handleError("%s: %s", logPrefix, err) + return handleError(logger, "%s", err) } else { - slog.Info(fmt.Sprintf("%s: header validation successful", logPrefix)) + logger.Info("header validation successful") } return nil @@ -74,11 +75,11 @@ func validateHeaders(message *message.Message, headers http.Header) error { return nil } -func ValidateHttpQueryParams(logPrefix string, expectedMessage *message.RequestMessage, actualUrl *url.URL) error { +func ValidateHttpQueryParams(expectedMessage *message.RequestMessage, actualUrl *url.URL, logger *logging.Logger) error { if err := validateQueryParams(expectedMessage, actualUrl.Query()); err != nil { - return handleError("%s: %s", logPrefix, err) + return handleError(logger, "%s", err) } else { - slog.Info(fmt.Sprintf("%s: query params validation successful", logPrefix)) + logger.Info("query params validation successful") } return nil @@ -105,42 +106,43 @@ func validateQueryParams(message *message.RequestMessage, params url.Values) err return nil } -func ValidateHttpStatusCode(logPrefix string, expectedMessage *message.ResponseMessage, actualStatusCode int) error { +func ValidateHttpStatusCode(expectedMessage *message.ResponseMessage, actualStatusCode int, logger *logging.Logger) error { if actualStatusCode != expectedMessage.StatusCode { - return handleError("%s: validation error - HTTP status mismatch - expected [%d] but received [%d]", logPrefix, expectedMessage.StatusCode, actualStatusCode) + return handleError(logger, "validation error - HTTP status mismatch - expected [%d] but received [%d]", + expectedMessage.StatusCode, actualStatusCode) } else { - slog.Info(fmt.Sprintf("%s: HTTP status validation successful", logPrefix)) + logger.Info("HTTP status validation successful") } return nil } -func ValidateHttpPayload(logPrefix string, expectedMessage *message.Message, actualPayload io.ReadCloser, - payloadType internal.PayloadType) error { - defer closeBody(logPrefix, actualPayload) +func ValidateHttpPayload(expectedMessage *message.Message, actualPayload io.ReadCloser, + payloadType internal.PayloadType, logger *logging.Logger) error { + defer closeBody(logger, actualPayload) if clarumstrings.IsBlank(expectedMessage.MessagePayload) { - slog.Info(fmt.Sprintf("%s: message payload is empty - no body validation will be done", logPrefix)) + logger.Info("message payload is empty - no body validation will be done") return nil } bodyBytes, err := io.ReadAll(actualPayload) if err != nil { - return handleError("%s: could not read response body - %s", logPrefix, err) + return handleError(logger, "could not read response body - %s", err) } if err := validatePayload(expectedMessage, bodyBytes, payloadType); err != nil { - return handleError("%s: %s", logPrefix, err) + return handleError(logger, "%s", err) } else { - slog.Info(fmt.Sprintf("%s: payload validation successful", logPrefix)) + logger.Info("payload validation successful") } return nil } -func closeBody(logPrefix string, body io.ReadCloser) { +func closeBody(logger *logging.Logger, body io.ReadCloser) { if err := body.Close(); err != nil { - slog.Error(fmt.Sprintf("%s: unable to close body - %s", logPrefix, err)) + logger.Errorf("unable to close body - %s", err) } } @@ -173,9 +175,9 @@ func validatePayload(message *message.Message, actual []byte, payloadType intern return nil } -func handleError(format string, a ...any) error { +func handleError(logger *logging.Logger, format string, a ...any) error { errorMessage := fmt.Sprintf(format, a...) - slog.Error(errorMessage) + logger.Errorf(errorMessage) return errors.New(errorMessage) } diff --git a/internal/validators/validators_test.go b/internal/validators/validators_test.go index ed00956..3f4c611 100644 --- a/internal/validators/validators_test.go +++ b/internal/validators/validators_test.go @@ -1,17 +1,20 @@ package validators import ( + "github.com/goclarum/clarum/core/logging" "github.com/goclarum/clarum/http/constants" "github.com/goclarum/clarum/http/message" "net/http" "testing" ) +var logger = logging.NewLogger("validators test") + func TestValidatePathOK(t *testing.T) { expectedMessage := createTestMessageWithHeaders() req := createRealRequest() - if err := ValidatePath("pathOKTest", expectedMessage, req.URL); err != nil { + if err := ValidatePath(expectedMessage, req.URL, logger); err != nil { t.Errorf("No header validation error expected, but got %s", err) } } @@ -21,7 +24,7 @@ func TestValidatePathError(t *testing.T) { expectedMessage.Path = "blup/" req := createRealRequest() - err := ValidatePath("pathErrorTest", expectedMessage, req.URL) + err := ValidatePath(expectedMessage, req.URL, logger) if err == nil { t.Errorf("Path validation error expected, but got none") @@ -36,7 +39,7 @@ func TestValidateMethodOK(t *testing.T) { expectedMessage := createTestMessageWithHeaders() req := createRealRequest() - if err := ValidateHttpMethod("methodOKTest", expectedMessage, req.Method); err != nil { + if err := ValidateHttpMethod(expectedMessage, req.Method, logger); err != nil { t.Errorf("No header validation error expected, but got %s", err) } } @@ -46,7 +49,7 @@ func TestValidateMethodError(t *testing.T) { expectedMessage.Method = http.MethodOptions req := createRealRequest() - err := ValidateHttpMethod("methodErrorTest", expectedMessage, req.Method) + err := ValidateHttpMethod(expectedMessage, req.Method, logger) if err == nil { t.Errorf("Method validation error expected, but got none") @@ -61,7 +64,7 @@ func TestValidateHeadersOK(t *testing.T) { expectedMessage := createTestMessageWithHeaders() req := createRealRequest() - if err := ValidateHttpHeaders("headersOKTest", &expectedMessage.Message, req.Header); err != nil { + if err := ValidateHttpHeaders(&expectedMessage.Message, req.Header, logger); err != nil { t.Errorf("No header validation error expected, but got %s", err) } } @@ -72,7 +75,7 @@ func TestValidateHeaderValueError(t *testing.T) { req := createRealRequest() - err := ValidateHttpHeaders("headersErrorTest", &expectedMessage.Message, req.Header) + err := ValidateHttpHeaders(&expectedMessage.Message, req.Header, logger) if err == nil { t.Errorf("Header validation error expected, but got none") @@ -89,7 +92,7 @@ func TestValidateMissingHeaderError(t *testing.T) { req := createRealRequest() - err := ValidateHttpHeaders("headersErrorTest", &expectedMessage.Message, req.Header) + err := ValidateHttpHeaders(&expectedMessage.Message, req.Header, logger) if err == nil { t.Errorf("Header validation error expected, but got none") @@ -111,7 +114,7 @@ func TestValidateQueryParamsOK(t *testing.T) { qParams.Set("param2", "value2") req.URL.RawQuery = qParams.Encode() - if err := ValidateHttpQueryParams("queryParamsOKTest", expectedMessage, req.URL); err != nil { + if err := ValidateHttpQueryParams(expectedMessage, req.URL, logger); err != nil { t.Errorf("No query param validation error expected, but got %s", err) } } @@ -127,7 +130,7 @@ func TestValidateQueryParamsParamMismatch(t *testing.T) { qParams.Set("param3", "value2") req.URL.RawQuery = qParams.Encode() - err := ValidateHttpQueryParams("queryParamsErrorTest", expectedMessage, req.URL) + err := ValidateHttpQueryParams(expectedMessage, req.URL, logger) if err == nil { t.Errorf("Query param validation error expected, but got none") } @@ -148,7 +151,7 @@ func TestValidateQueryParamsValueMismatch(t *testing.T) { qParams.Set("param2", "value22") req.URL.RawQuery = qParams.Encode() - err := ValidateHttpQueryParams("queryParamValueErrorTest", expectedMessage, req.URL) + err := ValidateHttpQueryParams(expectedMessage, req.URL, logger) if err == nil { t.Errorf("Query param validation error expected, but got none") } @@ -170,7 +173,7 @@ func TestValidateQueryParamsMultiValueOK(t *testing.T) { qParams.Add("param1", "value3") req.URL.RawQuery = qParams.Encode() - if err := ValidateHttpQueryParams("queryParamsMultiValueOKTest", expectedMessage, req.URL); err != nil { + if err := ValidateHttpQueryParams(expectedMessage, req.URL, logger); err != nil { t.Errorf("No query param validation error expected, but got %s", err) } } @@ -186,7 +189,7 @@ func TestValidateQueryParamsMultiValueMismatch(t *testing.T) { qParams.Add("param1", "value3") req.URL.RawQuery = qParams.Encode() - err := ValidateHttpQueryParams("queryParamsMultiValueErrorTest", expectedMessage, req.URL) + err := ValidateHttpQueryParams(expectedMessage, req.URL, logger) if err == nil { t.Errorf("Query param validation error expected, but got none") }