Use context with logs

The go Context carries data from the moment the server receives an inbound request to the moment the server makes an outbound request. This means you can use it to propagate data between services and processes. With gosoline, you can use log functions to store data from the request lifecycle in the Context and attach that data to logs to provide more details.

In this guide, you'll add some logs to a CRUD server used for managing a "To do list".

info

This tutorial is about logging, so you won't build the app here. However, if you'd like to learn how to build it, check out the dedicated tutorial.

Before you begin

Before you begin, make sure you have Golang installed on your machine.

You'll also need to download the sample code for the service:

git clone https://github.com/justtrackio/gosoline.git
cp -R gosoline/docs/docs/quickstart/http-server/src/write-crud-sql-app crud-app

Truncate todo text

With this service, users can create, read, update, and delete todos. For the purposes of this tutorial, you'll add some new logic. Instead of accepting any text for a todo, you'll limit the length of that string to prevent users from posting huge amounts of text in their todos.

In handler.go, add a new function:

handler.go
func truncate(ctx context.Context, text string) string {
	r := []rune(text)
	length := len(r)

	log.MutateContextFields(ctx, map[string]any{
		"original_length": length,
	})

	if length > 50 {
		text = string(r[:50]) + "..."
	}

	return text
}

In this function, you:

Accept a Context and a string as arguments
Capture the length of the string
Mutate the Context to store the original length of the string
Truncate the string if it is longer than 50 runes.
Return the potentially truncated string

For this tutorial, the important thing to pay attention to is where you mutate the Context:

log.MutateContextFields(ctx, map[string]any{
    "original_length": length,
})

With Gosoline, you can initilize specific fields that you can use with a Logger. (You'll do this in the next step.) Once those fields are initialized, you can append or mutate the fields as you've done here.

info

Read more about appending and mutating context fields in our log package reference.

Use your new function

Now that you have a function that can truncate todo text, use it in TransformCreate():

handler.go
func (h TodoCrudHandlerV0) TransformCreate(ctx context.Context, input interface{}, model db_repo.ModelBased) error {
	in := input.(*CreateInput)
	m := model.(*Todo)

	localctx := log.InitContext(ctx)
	m.Text = truncate(localctx, in.Text)
	m.DueDate = in.DueDate

	return nil
}

Then, use it in TransformUpdate():

handler.go
func (h TodoCrudHandlerV0) TransformUpdate(ctx context.Context, input interface{}, model db_repo.ModelBased) error {
	in := input.(*UpdateInput)
	m := model.(*Todo)

	localctx := log.InitContext(ctx)
	m.Text = truncate(localctx, in.Text)

	return nil
}

Here, you first call log.InitContext(). This function creates two sets of log-related fields in the Context:

localFields: These fields are limited to the application in which they are set. They are not propagated to downstream services in any way.
globalFields: These fields aren't limited to the application in which they are set. They are propagated to downstream services.

Then, it returns a Context in which these local and global fields are mutable. You pass this Context as the first parameter to truncate().

Technical Detail

Actually, this call to log.InitContext() is not required because gosoline will have already initialized the Context earlier in the request lifecycle. In this case, the ctx you pass to log.InitContext() is returned, unchanged. Therefore, localctx and ctx are the same, so you could have passed ctx to truncate() instead.

However, this example illustrates where to call log.InitContext() if you were to create or receive a Context from somewhere else. If you initialized the Context inside truncate(), the log-related fields would go out of scope when the function returns. Instead, you initilize the Context and pass it in, so you can make use of the log-related fields later.

Use your `Context` with logs

If you run your service now, you'll see the results of your work. Gosoline has some built-in logs that will show your Context fields. However, you can also manually add the Context to a new logger.

First, add a logger to your TodoCrudHandlerV0:

handler.go
type TodoCrudHandlerV0 struct {
	logger log.Logger
	repo   db_repo.Repository
}

Now, you can make use of this logger in any of the handler's methods.

Next, when you initilize the handler, pass a logger:

handler.go
func NewTodoCrudHandler(ctx context.Context, config cfg.Config, logger log.Logger) (*TodoCrudHandlerV0, error) {
	var err error
	var repo db_repo.Repository

	if repo, err = db_repo.New(ctx, config, logger, settings); err != nil {
		return nil, fmt.Errorf("can not create db_repo.Repositorys: %w", err)
	}

	handler := &TodoCrudHandlerV0{
		logger: logger,
		repo:   repo,
	}

	return handler, nil
}

Finally, in TransformCreate() or TransformUpdate(), you can use the logger:

handler.go

h.logger.WithContext(localctx).Info("creating new task due at %v", m.DueDate)

Here, you use .WithContext() to apply the Context to the logger.

Test your work

Now it's time to test your work.

Start MySQL

First, start your MySQL container:

docker-compose up

Now, you have a MySQL database running in a container. You can see it running on port 3306 with docker ps in another shell:

CONTAINER ID   IMAGE          COMMAND                  CREATED          STATUS          PORTS                               NAMES
ccf507fd70e4   mysql:8.0.31   "docker-entrypoint.s…"   10 minutes ago   Up 10 minutes   0.0.0.0:3306->3306/tcp, 33060/tcp   write-crud-sql-app-mysql-1

Run your server

In another shell, navigate to the root crud directory of this project and spin up your server:

go mod init crud/m
go mod tidy
go run .

You'll see logs of your server running.

Make requests

Finally, in a third shell, make requests to your service. For example, create a todo:

curl -d '{"text":"do it!", "dueDate":"2023-09-08T15:00:00Z"}' -H "Content-Type: application/json" -X POST localhost:8080/v0/todo

Update the todo:

curl -d '{"text":"do it!!!"}' -H "Content-Type: application/json" -X PUT localhost:8080/v0/todo/1

In your logs, you should see the original_length field you added in the first step:

13:32:05.145 http    info    POST /v0/todo HTTP/1.1
original_length: 115 
application: server
bytes: 174
client_ip: 127.0.0.1
group: crud
host:
localhost:8080
protocol: HTTP/1.1
request_bytes: 160
request_method: POST
request_path: /v0/todo
request_path_raw: /v0/todo
request_query: 
request_query_parameters: map[]
request_referer: 
request_time: 0.011703875
request_user_agent: curl/8.1.2
scheme: http
status: 200

This is included in the log because we automatically resolve the local and global fields and include them in the log output.

If you need to create a new logger, you have to resolve the fields yourself. However, we've made this easy for you. Just call WithContext():

logger := log.NewLogger()
logger.WithContext(ctx).Info("My message with context")

Conclusion

Great work! In this tutorial, you used Gosoline to add some context to your logs.

Before you begin​

Truncate todo text​

Use your new function​

Use your Context with logs​

Test your work​

Start MySQL​

Run your server​

Make requests​

Conclusion​