Is it just me that can't find any examples about l...

# http4k

[Johannes Wirde]

Is it just me that can't find any examples about logging with http4k?

[James Richardson]

AFAIK http4k doesn't have any logging dependencies. However there are all sorts of ways to put whatever logging you want into the system.
What is it that you want to see?

[Johannes Wirde]

Today I had a NPE that didn't print a thing to the terminal...

[Johannes Wirde]

A bit hard to debug :/

[Johannes Wirde]

So you use lenses for log formatting? Or do you just println?

[James Richardson]

It depends on where you want to deploy....

So usually I wouldn't use log4j etc, but rather send structured logs (jsonl) to stdout. This matches the need in containerised environments, and means that the logs are instantly parsed by almost all log collation systems.

[James Richardson]

Then, in the request handling filter stack, i'd add a filter like this:

object UncaughtExceptionFilter {
    operator fun invoke(events: Events): Filter {
        return Filter { next ->
            {
                try {
                    next(it)
                } catch (t: Throwable) {
                    events(UncaughtExceptionEvent(t))
                    Response(Status.INTERNAL_SERVER_ERROR)
                }
            }
        }
    }
}

or you could use ServerFilters.CatchAll( { .... your code } )

[James Richardson]

building up a set of filters that are invoked to handle your request is pretty idiomatic for http4k. Here is an example from a production app...

app = Filter.NoOp
        .then(ServerFilters.InitialiseRequestContext(contexts))
        .then(maybeLogRequestsAndResponsesFilter)
        .then(OpenTelemetry.openTelemetryFilter(environment, serviceName))
        .then(
            ResponseFilters.ReportHttpTransaction {
                if (shouldLogTransaction(it)) {
                    events(HttpEvent.Incoming(it).plus("user-agent" to (it.request.header("user-agent") ?: "none")))
                }
            })
        .then(UncaughtExceptionFilter(events))
        .then(ServerFilters.CatchLensFailure)
        .then(
            routes(
                Health(checks = checks()),
                versionRoute("/api/version", appVersion()),
                createRoutes()
            )
        )

here you can see that
• initialise request context - so that later filters can attach identity to requests
• maybe debug logging of request and responses (but not in production)
• open telemetry reporting for sending stuff to honeycomb
• inbound http request logging - path, status etc
• uncaught exceptions reporting - i consider every single error 500 a bug
• catch lens failure -> automatically return 400
• then adding some heath endoints, including api version and health checks
• then finally, whatever the app itself is doing...

[James Richardson]

this filter stack is "the standard one" that app service apps get.. then then add their own functionality in there too... they may add other filters routes etc etc.

[James Richardson]

does that make sense / is useful?

[dave]

Page on events and structured logging: https://www.http4k.org/guide/howto/structure_your_logs_with_events/

[Johannes Wirde]

I'm out and about rn but thanks the two of you for the responses!

[Andrew O'Hara]

I still haven't gotten on the structured logging train. Here's what I use:

• Log Summary
• Log Errors
Normally used like this:

val client = ResponseFilters.logSummary()
    .then(ClientFilters.mdcToRequestId("CC-Request-ID"))
    .then(JavaHttpClient())
    .let { ExternalApi(it, apiHost) }

val server = ServerFilters
    .then(ResponseFilters.logSummary())
    .then(ServerFilters.requestIdToMdc("CC-Request-ID", generateRequestId = { IdGenerator.nextBase36(8) }))
    .then(ServerFilters.logErrors())
    .then(routes)

the MDC filters are my "poor man's" tracing, where a request id is generated and added to the SLF4j MDC to be included in all logs for that transaction (based on your logger config).

[Johannes Wirde]

@Andrew O'Hara Where is the ResponseFilters.logSummary defined?

[Johannes Wirde]

@dave I need both HTTP and WS support in the app

[James Richardson]

I think logSummary() some of the other filters are just filters that he's written, rather than http4k standard ones.

maybe if you could explain what you want to achieve in a bit more detail, could give more specific example.

[Andrew O'Hara]

Sorry @Johannes Wirde, logSummary was in the Report HTTP Transactions link, which I've now renamed to match. All the filters used in my example are custom ones I've written, which you're free to copy from the links I've provided.

[Bogdan Costea]

Hello guys,
I'm pretty new to the http4k world, but I've seen this thread related to the issue I'm facing. My team wants to enrich the logs with a value that represents the tracing id. From the official documentation, I couldn't find any advice regarding this problem. Is there any official way to do it? From what I've read so far, introducing slf4j is not a recommended way to go.

[Andrew O'Hara]

The http4k maintainers aren't fans of non-structured logging, but I maintain a utility class with useful filters.
https://github.com/oharaandrew314/service-utils/blob/master/src/main/kotlin/dev/andrewohara/utils/http4k/slf4jExtensions.kt

Here's an example:

val internet = ClientFilters
  .mdcToRequestId("My-Trace-Id")
  .then(JavaHttpClient())

// pass internet into clients

val api = TODO("build service graph and generate API HttpHandler")

ResponseFilters.logSummary()
    .then(ServerFilters.requestIdToMdc("My-Trace-Id", generateRequestId = { IdGenerator.nextBase36(8) }))
    .then(ServerFilters.logErrors())
    .then(myApi)
    .asServer(Jetty(8000))
    .start()

This assumes you're not using a tracing framework and just want to have a trace id appear in all your request logs. The server filter puts the request id into the slf4j MDC context (from the request headers, or generates a new one), and the client filter puts the trace id from the MDC context into the outgoing request headers; this, of course, only works on the same thread.

You'll need to update your logger's conf to output the MDC content. For example, with log4j2, it's the %X tag:

<Console name="Console" target="SYSTEM_OUT">
    <PatternLayout pattern="%d{ISO8601} %X %F:%L %-5level %logger{36} - %msg%n"/>
</Console>

You'll end up with something like

2025-03-20T10:43:01,185 {My-Trace-Id=FWI9BVLC} slf4jExtensions.kt:91 INFO  root - GET /: 200 OK in 4 ms from [0:0:0:0:0:0:0:1]

EDIT: I see I've already posted something very much like this in this thread. If it's not what you're looking for, can you clarify?

[Bogdan Costea]

Thanks Andrew, for the prompt answer.
This is exactly what I was looking for, but I just wanted to double-check if the framework doesn't introduce a more native way to fix this issue without involving SLF4J.
Due to time constraints, I believe that now I will simply use SLF4J. Using MDC can introduce any issues when talking about multithreading, I'm thinking if the framework is using the concurrencycoroutines) behind the scenes(?

[James Richardson]

I can state with certainty that there are no coroutines behind the scenes.

At the same time I don't quite follow your query regarding "without involving slf4j".. http4k doesn't rely on or use any logging framework at all, so you, as the library user, can use whatever you like - it has all the extension points you need to log anything you like. So whatever the solution is, it doesn't "rely" on slf4j, but you certainly can use it. Mostly http4k users seem to use structured logging to stdout and send the information then to splunk or similar, or use wide trace events and send them to an otel service like honeycomb.

[Bogdan Costea]

Thanks @James Richardson, for confirming it.
Sorry, maybe I wasn't so clear enough. I will try to explain it better, so after I read a couple of threads, I saw that the recommended approach is to use structured logging. We already follow that strategy in our project, but we are using GCP as a cloud provider (regarding Observability/Monitoring we are using their services), so to associate the logs and traces, we must use a trace id generated by GCP and passed to us as a header. For the logs, we have to enhance them with that value, so I was looking for a solution that takes care of the traceId and automatically add it to the final log without being forced to pass it through the entire chain (similar to what MDC does in SLF4J or a request context), but to stay close to the structured logging approach recommended by HTTP4K.
I hope this clarifies a bit more my intention, 😄

[dave]

There are 2 distributed tracing solutions that are supported by http4k, both using Filters which are attached to the inbound and outbound http handlers:

1. X-B3 traces - by default this is implemented using a ThreadLocal which stores the trace id for the request
2. OpenTelemetry - this uses the OTel API singletons for storage.
I'm not familiar with GCP tracing, but it should be trivial to use the same mechanic as 1 to just grab a different header and put it into whatever MDC-type singleton that you're using for your logging. If you want to use the http4k structured events, it's just a case of creating an EventFilter to grab the value out of that and attach it to the events as metadata.

If you also want to do span rolling with GCP (to create a distributed tracing graph) then you will need to implement both Server and Client filters and attach them in the correct places.

[dave]

you should look at ServerFilters.RequestTracing() and ClientFilters.RequestTracing() for inspiration 🙂