Skip to content

Commit

Permalink
Refactor logging: checkpoint #1
Browse files Browse the repository at this point in the history
  • Loading branch information
@codemental
codemental committed Feb 1, 2024
1 parent 23e535d commit 68e1a13
Show file tree
Hide file tree
Showing 4 changed files with 98 additions and 85 deletions.
85 changes: 45 additions & 40 deletions client/endpoint.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
Expand All @@ -24,13 +24,15 @@ type Endpoint struct {
contentType string
client *http.Client
responseChannel chan *responsePair
logger *logging.Logger
}

type responsePair struct {
response *http.Response
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),
Expand All @@ -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{
Expand All @@ -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)
}
}()

Expand All @@ -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)
}
}

Expand Down Expand Up @@ -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
}

Expand All @@ -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)
}
13 changes: 8 additions & 5 deletions client/endpoint_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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")
}
Expand Down
Loading

0 comments on commit 68e1a13

Please sign in to comment.