move docs

This commit is contained in:
Erik Winter 2021-12-15 16:27:11 +01:00
parent f881250143
commit a45fb3ca93
4 changed files with 0 additions and 621 deletions

View File

@ -1,299 +0,0 @@
= Unit Test Outbound HTTP Requests in Golang
Erik Winter <ik@erikwinter.nl>
2020-07-04
:kind: tutorial
:public: yes
:language: en
:tags: golang, tdd, http, rest, go-kit
In general, when one wants to test the interaction of multiple services and systems, one tries to set up an integration test. This often involves spinning up some Docker containers and a docker-compose file that orchestrates the dependencies between them and starts the integration test suite. In other words, this can be a lot of work.
Sometimes that is too much for the case at hand, but you still want to check that the outbound HTTP requests of your program are ok. Does it send the right body and the right headers? Does it do authentication? In a world where the main job of a lot of services is to talk to other services, this is important.
Luckily, it is possible to test this without all that Docker work. The standard library in Golang already provides a mock server for testing purposes: `httptest.NewServer` will give you one. It is designed to give mock responses to HTTP requests, for use in your tests. You can set it to respond with valid and invalid responses, so you can check that your code is able to handle all possible variations. After all, external services are unreliable and your app must be prepared for that.
This is good. But with a bit of extra code, we can extend these mocks and test the outbound requests as well.
To demonstrate this, let's look at a simple generic client for the Foo Cloud Service (tm). We'll examine the following parts:
* #the-code-we-want-to-test[The code we want to test]
* #setting-up-the-mock-server[Setting up the mock server]
* #writing-the-tests[Writing the tests]
* #checking-the-outbound-requests[Checking the outbound requests]
_Note: If you're the type of reader that likes code better than words, skip this explanation and go directly to the `test/doc` folder in https://git.sr.ht/~ewintr/go-kit/[this repository] that contains a complete working example of everything discussed below._
== The Code We Want to Test
We're not particularly interested in the specific implementation of `FooClient` right now. Let's try some TDD first. This is the functionality that we want in our code:
----
type FooClient struct {
...
}
func NewFooClient(url, username, password string) *FooClient{
...
}
func (fc *FooClient) DoStuff(param string) (string, error) {
...
}
----
And furthermore we have the requirements that:
* When `DoStuff` is called, a request is send out to the given url, extended with path `/path`.
* The request has a JSON body with a field `param` and the value that was passed to the function.
* The request contains the corresponding JSON headers.
* The request contains an authentication header that does basic authentication with the username and password.
* A succesful response will have status `200` and a JSON body with the field `result`. The value of this field is what we want to return from the method.
This is all very standard. I'm sure you've seen this type of code before. Let's move on!
== Setting up the Mock Server
So how do we set up our mock server?
To do so, first we need some types:
----
// MockResponse represents a response for the mock server to serve
type MockResponse struct {
StatusCode int
Headers http.Header
Body []byte
}
// MockServerProcedure ties a mock response to a url and a method
type MockServerProcedure struct {
URI string
HTTPMethod string
Response MockResponse
}
----
These types are just a convenient way to tell the mock server to what requests we want it to respond and what to respond with.
But there is more. We would also like to store the requests that our code makes for later inspection. That is, we want to use something that can record the requests. Let's go for a `Recorder` interface with a method `Record`:
----
// MockRecorder provides a way to record request information from every successful request.
type MockRecorder interface {
Record(r *http.Request)
}
----
Then we get to the actual mock server. Note that for the most part, it just builds on the mock server from the standard `httptest` package:
----
// NewMockServer return a mock HTTP server to test requests
func NewMockServer(rec Mockrecorder, procedures ...MockServerProcedure) *httptest.Server {
var handler http.Handler
handler = http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
for _, proc := range procedures {
if proc.URI == r.URL.RequestURI() && proc.HTTPMethod == r.Method {
headers := w.Header()
for hkey, hvalue := range proc.Response.Headers {
headers[hkey] = hvalue
}
code := proc.Response.StatusCode
if code == 0 {
code = http.StatusOK
}
w.WriteHeader(code)
w.Write(proc.Response.Body)
if rec != nil {
rec.Record(r)
}
return
}
}
w.WriteHeader(http.StatusNotFound)
return
})
return httptest.NewServer(handler)
}
----
This function returns a `*httptest.Server` with exactly one handler function. That handler function simply loops through all the given mock server procedures, checks whether the path and the HTTP method match with the request and if so, returns the specified mock response, with status code, headers and response body as configured.
On a succesful match and return, it records the request that was made through our `Recorder` interface. If there was no match, a `http.StatusNotFound` is returned.
That's all.
== Writing the Tests
How would we use this mock server in a test? We can, for instance, create one like this:
----
mockServer := NewMockServer(nil, MockServerProcedure{
URI: "/path",
HTTPMethod: http.MethodGet,
Response: MockResponse{
StatusCode: http.StatusOK,
Body: []byte(`First page`),
},
},
// define more if needed
)
----
And use it as follows:
----
func TestFooClientDoStuff(t *testing.T) {
path := "/path"
username := "username"
password := "password"
for _, tc := range []struct {
name string
param string
respCode int
respBody string
expErr error
expResult string
}{
{
name: "upstream failure",
respCode: http.StatusInternalServerError,
expErr: httpmock.ErrUpstreamFailure,
},
{
name: "valid response to bar",
param: "bar",
respCode: http.StatusOK,
respBody: `{"result":"ok"}`,
expResult: "ok",
},
{
name: "valid response to baz",
param: "baz",
respCode: http.StatusOK,
respBody: `{"result":"also ok"}`,
expResult: "also ok",
},
...
} {
t.Run(tc.name, func(t *testing.T) {
mockServer := test.NewMockServer(nil, test.MockServerProcedure{
URI: path,
HTTPMethod: http.MethodPost,
Response: test.MockResponse{
StatusCode: tc.respCode,
Body: []byte(tc.respBody),
},
})
client := httpmock.NewFooClient(mockServer.URL, username, password)
actResult, actErr := client.DoStuff(tc.param)
// check result
test.Equals(t, true, errors.Is(actErr, tc.expErr))
test.Equals(t, tc.expResult, actResult)
})
}
}
----
_Note: the `test.Equals` are part of the small test package in https://git.sr.ht/~ewintr/go-kit[this go-kit]. The discussed http mock also belongs to that package and together they form a minimal, but sufficient set of test helpers. But if you prefer, you can of course combine this with populair libraries like https://pkg.go.dev/github.com/stretchr/testify/assert?tab=doc[testify]._
We've set up a regular table driven test for calling `FooClient.DoStuff`. In the table we have three test cases. One pretends the external server is down en responds with an error status code. The other two mimick a working external server and test two possible inputs, with `param` `"bar`" and `param` `"baz"`.
This is just the simple version. It is not shown here, but we can also check different errors with the response body. What if we would set it to `[]byte("{what?")`. Would our code be able to handle that?
Also, because `NewMockServer` is a variadic function, we can pass in more mock procedures and test more complex scenario's. What if we need to login on a separate endpoint before we can make the request for `DoStuff`? Just add a mock for the login and check that it is called. And remember that the real server might not return the things you expect it to return, so test a failing login too.
== Checking the Outbound Requests
Now we come to the interesting part: the recording of our requests. In the code above we conveniantly ignored the first argument in `NewMockServer`. But it was this `Recorder` that caused us to set all this up in the first place.
The nice thing about interfaces is that you can implement them exactly the way you want for the case at hand. This is especially useful in testing, because different situations ask for different checks. However, the go-kit test package has a straightforward implementation called `MockAssertion` and it turns out that that implementation is already enough for 90% of the cases. You milage may vary, of course.
It would be too much to discuss all details of `MockAssertion` here. If you want, you can inspect the code in `test/httpmock.go` in the mentioned https://git.sr.ht/~ewintr/go-kit[go-kit] repository. For now, let's keep it at these observations:
----
// recordedRequest represents recorded structured information about each request
type recordedRequest struct {
hits int
requests []*http.Request
bodies [][]byte
}
// MockAssertion represents a common assertion for requests
type MockAssertion struct {
indexes map[string]int // indexation for key
recs []recordedRequest // request catalog
}
----
We have a slice with all the requests that were recorded and an index to look them up. This index consists of a string that combines the request uri and the http method. We can look up the requests with these methods:
----
// Hits returns the number of hits for a uri and method
func (m *MockAssertion) Hits(uri, method string) int
// Headers returns a slice of request headers
func (m *MockAssertion) Headers(uri, method string) []http.Header
// Body returns request body
func (m *MockAssertion) Body(uri, method string) [][]byte {
----
And if needed, we can reset the assertion:
----
// Reset sets all unexpected properties to their zero value
func (m *MockAssertion) Reset() error {
----
Armed with this, checking our outbound requests becomes a very simple task.
First, update the line that creates the mock server, so that we actually pass a recorder:
----
...
var record test.MockAssertion
mockServer := test.NewMockServer(&record, test.MockServerProcedure{
...
----
Then, add the following statements at the end of our test function body:
----
// check request was done
test.Equals(t, 1, record.Hits(path, http.MethodPost))
// check request body
expBody := fmt.Sprintf(`{"param":%q}`, tc.param)
actBody := string(record.Body(path, http.MethodPost)[0])
test.Equals(t, expBody, actBody)
// check request headers
expHeaders := []http.Header{{
"Authorization": []string{"Basic dXNlcm5hbWU6cGFzc3dvcmQ="},
"Content-Type": []string{"application/json;charset=utf-8"},
}}
test.Equals(t, expHeaders, record.Headers(path, http.MethodPost))
----
That's it! We now have tested each and every requirement that was listed above. Congratulations.
I hope you found this useful. As mentioned above, a complete implementation of `FooClient` that passes all tests can be found in the doc folder of https://git.sr.ht/~ewintr/go-kit/[this repository].
If you have comments, please let me know. Contact methods are listed on the /about/[About page].

View File

@ -1,72 +0,0 @@
package doc
import (
"bytes"
"encoding/json"
"errors"
"fmt"
"io/ioutil"
"net/http"
)
var (
ErrInternalFailure = errors.New("we did something wrong")
ErrUpstreamFailure = errors.New("someone else did something wrong")
)
type FooClient struct {
url string
username string
password string
client *http.Client
}
func NewFooClient(url, username, password string) *FooClient {
return &FooClient{
url: url,
username: username,
password: password,
client: &http.Client{},
}
}
func (fc *FooClient) DoStuff(param string) (string, error) {
reqBody := struct {
Param string `json:"param"`
}{
Param: param,
}
jReqBody, err := json.Marshal(reqBody)
req, err := http.NewRequest(http.MethodPost, fmt.Sprintf("%s/path", fc.url), bytes.NewBuffer(jReqBody))
if err != nil {
return "", fmt.Errorf("%w: %v", ErrInternalFailure, err)
}
req.SetBasicAuth(fc.username, fc.password)
req.Header.Set("Content-Type", "application/json;charset=utf-8")
resp, err := fc.client.Do(req)
if err != nil {
return "", fmt.Errorf("%w: %v", ErrUpstreamFailure, err)
}
if resp.StatusCode != http.StatusOK {
return "", fmt.Errorf("%w, server responded with status %d", ErrUpstreamFailure, resp.StatusCode)
}
defer resp.Body.Close()
body, err := ioutil.ReadAll(resp.Body)
if err != nil {
return "", fmt.Errorf("%w: %v", ErrUpstreamFailure, err)
}
var expResp struct {
Result string `json:"result"`
}
err = json.Unmarshal(body, &expResp)
if err != nil {
return "", fmt.Errorf("%w: %v", ErrUpstreamFailure, err)
}
return expResp.Result, nil
}

View File

@ -1,87 +0,0 @@
package doc_test
import (
"errors"
"fmt"
"net/http"
"testing"
httpmock "ewintr.nl/go-kit/doc"
"ewintr.nl/go-kit/test"
)
func TestFooClientDoStuff(t *testing.T) {
path := "/path"
username := "username"
password := "password"
for _, tc := range []struct {
name string
param string
respCode int
respBody string
expErr error
expResult string
}{
{
name: "upstream failure",
respCode: http.StatusInternalServerError,
expErr: httpmock.ErrUpstreamFailure,
},
{
name: "incorrect response body",
respCode: http.StatusOK,
respBody: `{"what?`,
expErr: httpmock.ErrUpstreamFailure,
},
{
name: "valid response to bar",
param: "bar",
respCode: http.StatusOK,
respBody: `{"result":"ok"}`,
expResult: "ok",
},
{
name: "valid response to baz",
param: "baz",
respCode: http.StatusOK,
respBody: `{"result":"also ok"}`,
expResult: "also ok",
},
} {
t.Run(tc.name, func(t *testing.T) {
var record test.MockAssertion
mockServer := test.NewMockServer(&record, test.MockServerProcedure{
URI: path,
HTTPMethod: http.MethodPost,
Response: test.MockResponse{
StatusCode: tc.respCode,
Body: []byte(tc.respBody),
},
})
client := httpmock.NewFooClient(mockServer.URL, username, password)
actResult, actErr := client.DoStuff(tc.param)
// ceck result
test.Equals(t, true, errors.Is(actErr, tc.expErr))
test.Equals(t, tc.expResult, actResult)
// check request was done
test.Equals(t, 1, record.Hits(path, http.MethodPost))
// check request body
expBody := fmt.Sprintf(`{"param":%q}`, tc.param)
actBody := string(record.Body(path, http.MethodPost)[0])
test.Equals(t, expBody, actBody)
// check request headers
expHeaders := []http.Header{{
"Authorization": []string{"Basic dXNlcm5hbWU6cGFzc3dvcmQ="},
"Content-Type": []string{"application/json;charset=utf-8"},
}}
test.Equals(t, expHeaders, record.Headers(path, http.MethodPost))
})
}
}

View File

@ -1,163 +0,0 @@
= My Take on Logging in Golang
Erik Winter <ik@erikwinter.nl>
2021-04-08
:kind: tutorial
:public: yes
:language: en
:tags: golang, go-kit
The subject of logging comes up every now and then, in every group of developers. Apparently it is something to be opinionated about, like code formatting. Or to something complain about, like leaving off the cap of the toothpaste. If only there was a `go fmt` for logging. Or toothpaste.
Anyway, as with most things computing, I like logging to be simple and pragmatic. Over the years, these are the things Ive come to consider important with this subject.
== Levels
When thinking about what logging levels are appropriate, it helps to define the intended audience for a certain level and what information that audience should get out of it. In addition to that, it also helps to remember what goals and what information are already covered by other systems.
For instance, logging is not to be confused with:
* Alerting
* Monitoring
* Metrics
If there are other systems in place to provide this functionality, adding information for it to the logs just increases the noise. If there are no other systems and you want to use logging for it, then make sure that appropriate procedurees are in place, or the information will still be noise. For instance, what use has the logging of a warning, when there is no-one who actually gets warned and people only see it when they happen to stumble upon it when they are looking for someting else?
What should be logged then and at what level? In https://dave.cheney.net/2015/11/05/lets-talk-about-logging[this article], Dave Cheney makes a good argument to minimize the logging interface and he states that the only useful levels are `debug` and `info`. However, he acknowledges that errors should be logged too and since we try to add structure to ours logs (see next section), it would be strange to log an `error` as `info` and then later use another way to add the semantic information that it is, in fact, an `error`.
Together, this gives the following levels and their intended audience:
* `debug` - Things that happened that developers care about when developing a feature, or fixing a bug.
* `info` - Things that happened that users and administrators care about, that dont impact the behavior of the application.
* `error` - Things that happened that users care about, because they do impact behavior. For instance, a lost connection can be re-established by the application itself, but there could be a small delay.
== Structured logging and standard log messages
At minimum a log line is just a line of text. Preferably with a timestamp somewhere in it. But since there are a lot of them and they tend to grow into big haystacks that may or may not have a needle in them, it helps if we can use scripts and other automation to help us search and analyze them. Thus we want something that is easy to parse.
I am not in favor of using JSON for everything everywhere, but I think this is an appropriate usecase. Everyline should be a line of JSON with some fields. One of the benefits of using JSON structured logging is that it becomes much easier to give context to a messages by adding data. Context can be very helpful when searching and filtering the logs, but this only works well if the data is labeled explicitly.
Any serious logging library (see also the next section) will provide a way to add fields to a message. Use this as much as possible, because otherwise it will be hard to see from the logs what is message and what is context:
----
// without JSON structured logging
logger.Printf("response with status %d received", response.Code)
// output:
2021-01-01 12:00:00 response with status 400 received
// with JSON and levels, but without fields
logger.Infof("response with status %d received", response.Code)
// output:
{
"level": "info",
"message": "response with status 400 received",
"time": "2021-01-01 12:00:00"
}
// with JSON, levels and fields
logger.With(log.Fields{
"status": response.Code,
}).Info("response received")
// output:
{
"level": "info",
"status": 400,
"message": "response received",
"time": "2021-01-01 12:00:00"
}
----
The last example will be most useful when analyzing the logs, as we can now filter for an exact message (“response received“) and get all the variations of received status codes in one search. Usually, one does not know the exact reason that caused things to fail, thats why we are analyzing after all. So we do not know the exact status code that we are looking for. Was the other server malfunctioning and did we receive a `500`? Or is our password expired and did we receive a `401`? When logging like the first couple of examples, we can only guess possible causes and try to predict the exact message before we can search for it. With the last approach, we just search for the message and then see what status was returned.
After that, we could either create a count of the different codes (x times `200`, y times `500`, etc) and see how they are distributed, or narrow down the search to a specific code. See https://erikwinter.nl/articles/2021/simple-log-file-analysis-for-your-kubernetes-pods-on-the-command-line/[this tutorial] for some pointers on how to do some useful quick analyses on the commandline.
Errors are excellent candidates to put in a field. If the level of the message is error, there should be a field with key "error” present:
----
// verbose implementation
logger.WithFields(log.Fields{
"error": err,
}).Error("something did not work")
// with shortcut method
logger.WithErr(err).Error("something did not work")
----
== Wrapping loggers
Another way to add structure is by wrapping loggers. Most loggers implement https://en.wikipedia.org/wiki/Method_chaining[method chaining] to provide what is called a fluent interface. That is, most methods on the logger have a new logger instance as a return type. We can use this to gradually add context as we pass the logger along:
----
// in main.go
logger := log.NewLogger(os.Stdout).WithFields(log.Fields{
"service": "someservice",
})
m := something.New(logger, ...)
// in something/something.go
type SomeThing struct{
logger log.Logger
...
}
func New(logger log.Logger, ...) *SomeThing {
...
return &SomeThing{
logger: logger.WithFields(log.Fields{
"package": "something",
}),
...
}
}
func (st *SomeThing) DoIt(...) {
logger := st.logger.WithFields(
"method": "doit",
)
...
logger.Info("something was done")
}
----
If you now ever encounter a message `“something was done“` in the logs, it will be accompanied by the fields `"service":"someservice"`, `"package":"something"` and `"method":"doit"`. It is not hard to imagine how this could help the debugging during an incident.
== Advanced structuring
There are more possibilities to add context and information, as can be seen from this example from the https://github.com/go-kit/kit/tree/master/log[go-kit log library]:
----
var logger log.Logger
logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr))
logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
logger.Log("msg", "hello")
// Output:
// ts=2016-01-01T12:34:56Z caller=main.go:15 msg=hello
----
Here `log.DefaultTimestampUTC` and `log.DefaultCaller` are functions. With a logger that accepts a contextual function as a value, one can create any structure that might be interesting. The function gets evaluated when the message is logged and the output is what gets stored. This way it is possible to add custom timers, add stack traces, etc.
== Injecting loggers versus returning errors
As can be seen in the examples above, when building context it helps to treat a logger as an instance of type Logger and use it it to create new instances, instead of relying on a single logger that is globally present. A natural consequence of this is that a logger should be a parameter that is passed around whenever necessary. At first sight it seems cumbersome and verbose to do that everywhere in your code.
However, it is not necessary to pass the logger to every part of the code, since not every part of the code has the need to log. If we examine a https://erikwinter.nl/notes/2021/my-default-golang-directory-structure/[basic directory structure for Go projects] and look what kind of packages each folder holds:
----
.
├── cmd // the different programs/services
├── internal // decoupled packages specific to this repository
└── pkg // decoupled packages that may be imported by other projects
----
Then we see that every action is initiated somewhere in `/cmd` and that the packages in `/internal` and `/pkg` are supposed to be decoupled from the rest. We can get by with the rule of thumb that the logging should be done in `/cmd` and that the packages in `/internal` and in `/pkg` should return errors that may or may not get wrapped and may or may not get logged when they arrive in `/cmd`.
Ever had some external library messing up things because they decided just to log to Stdout the way they saw fit? Not very helpful. If you https://erikwinter.nl/articles/2021/depend-less-on-dependencies-with-the-adapter-pattern-in-golang/[wrap external dependencies in an adapter], you can make sure that the errors also translate properly to the domain of your program. If a library really insists on having a logger and you still want to use it anyway, this is the place to add context.
== Example implementation
An example of how you can adapt a regular logging library to these practices is the `log` package in my https://git.sr.ht/~ewintr/go-kit[small personal go kit repository]. There is an interface definition in `log.go`, together with two implementations, one for https://github.com/Sirupsen/logrus[Logrus] and one for the https://gokit.io/[gokit.io] `log` package, and an implemention suitable for use in testing.