You can also see structured logging in use in the ...
# http4k
d
e
I just came across the structured-logging yesterday. Is there a way to test that structured logging is happening when EventFilters are used in-combination with the Http filters?
I have my filter defined like this
Copy code
data class IncomingHttpRequest(val message: String = "", val status: Int = 0, val duration: Long = 0L) : Event

object ReportHttpTransactionFilter {
  operator fun invoke(
    events: Events = EventFilters.AddTimestamp().then(AutoMarshallingEvents(Jackson)),
    event: Event? = null
  ): Filter = Filter { next ->
    { request ->
      next(request).apply {
        ResponseFilters.ReportHttpTransaction { httpTransaction ->
          events(event ?: IncomingHttpRequest(
            httpTransaction.request.toMessage(),
            httpTransaction.response.status.code,
            httpTransaction.duration.toMillis())
          )
        }
      }
    }
  }
}
And my test class like this: (which fails)
Copy code
class ReportHttpTransactionFilterSpec : Spek({

  val request = Request(Method.GET, "/bob")
  val response = Response(OK)
  val recording = RecordingEvents()

  test("report http transaction filter emits events with timestamp") {
    val events = EventFilters.AddTimestamp().then(AutoMarshallingEvents(Jackson)).then(recording)
    val event = IncomingHttpRequest("some message", 200, 10)
    val handler = ReportHttpTransactionFilter(events, event).then { response }

    expectThat(handler(request)).isEqualTo(response)
    expectThat(recording.toList()).isEqualTo(listOf<Event>(MetadataEvent(
      event,
      mapOf("timestamp" to Clock.systemUTC().instant())))
    )
  }

})
The recording comes back as emptylist
Am I missing something here?
d
It looks strange - why are you passing in the event which then falls back?
Copy code
events(event ?: IncomingHttpRequest(
            httpTransaction.request.toMessage(),
            httpTransaction.response.status.code,
            httpTransaction.duration.toMillis())
          )
r
I think is yout ReportHttpTransactionFilter that is strange We did it this way:
Copy code
val events = EventFilters.AddTimestamp().then(AutoMarshallingEvents(AppJackson))
fun LogIncomingRequests() = ResponseFilters.ReportHttpTransaction {
   events(LogHttpTransaction.fromTransaction(it))
}

val app = LogIncomingRequests().then { response }
๐Ÿ‘ 1
e
@Razvan do you mean to say I will have to use LogHttpTransaction in my filter code instead of events(event)?
@dave if an event is passed, it will be events(event) call as in the test code but if event is not passed, it will use the httpTransaction to create IncomingHttpRequest and use it with events.
r
LogHttpTransaction is just a custom object like IncomingHttpRequest juste a data class with informations you can replace that with
Copy code
fun LogIncomingRequests() = ResponseFilters.ReportHttpTransaction {
   events(
      IncomingHttpRequest(
            itrequest.toMessage(),
            it.response.status.code,
            it.duration.toMillis())
          )
   )
}
if it helps to undersand
๐Ÿ™ 1
๐Ÿ‘ 1
d
@Elizabeth Thomas Yes - and that's exactly what you want to test. ๐Ÿ™ƒ
๐Ÿ‘ 1
e
Okay let me try that!
@Razvan My
events
is configured as
val events = EventFilters.AddTimestamp().then(AutoMarshallingEvents(Jackson)).then(recording)
in my test class. And after running through the filter, when I check the
recording
object, I see it being empty.
@dave ^^
I am missing to see how to validate that events with timestamp were generated.
d
but really you should be testing that your events stack is doing the right thing. assuming that you always want metadata then isolate that part and test it separately to the filter
then you can just test your filter by testing that the correct events (IncomingHttpRequest) were generated, regardless of the metadata
e
Thanks @dave will use this approach!
d
๐Ÿ‘
e
@dave your approach worked. Thanks! But I am failing to understand why my filter defined like this wonโ€™t work
Copy code
object ReportHttpTransactionFilter {
  object Log {
    operator fun invoke(
      rawEvents: Events,
      clock: Clock = Clock.systemUTC()
    ): Filter = Filter { next ->
      { request ->
        val events = AddTimestamp(clock).then(rawEvents)
        next(request).apply {
          ResponseFilters.ReportHttpTransaction(clock = clock) { httpTransaction ->
            events(
              IncomingHttpRequest(
                httpTransaction.request.method,
                httpTransaction.request.uri.path,
                httpTransaction.response.status.code,
                httpTransaction.duration.toMillis()
              )
            )
          }
        }
      }
    }
  }
d
because you're defining a filter within a filter - and that's not how filters work.. ๐Ÿ™‚
Copy code
ResponseFilters.ReportHttpTransaction(clock = clock) { httpTransaction ->
            events(
              IncomingHttpRequest(
                httpTransaction.request.method,
                httpTransaction.request.uri.path,
                httpTransaction.response.status.code,
                httpTransaction.duration.toMillis()
              )
            )
          }
is a filter
you need to do
filter.then(filter).then(handler)
e
Ah, okay - I thought filter within a filter is possible.. ๐Ÿ™‚
When you get a chance, could you share if there is any documentation that outlines this?
d
e
I was following this from ReportHttpTransaction
Copy code
object ReportHttpTransaction {
        operator fun invoke(
            clock: Clock = Clock.systemUTC(),
            transactionLabeler: HttpTransactionLabeler = { it },
            recordFn: (HttpTransaction) -> Unit
        ): Filter = Filter { next ->
            {
                clock.instant().let { start ->
                    next(it).apply {
                        recordFn(transactionLabeler(HttpTransaction(it, this, between(start, clock.instant()))))
                    }
                }
            }
        }
    }
d
yes - but the
apply()
there is actually doing something and not creting another filter
e
Ah, gotcha.. Makes sense. Thanks for explaining it to me!
Also the
LogHttpTransaction.fromTransaction
which @Razvan pointed out, is it in http4k-core? or some other module? I couldnt get the package for it. Again, its probably me doing something wrong.
r
No is just a personal data class with fields I want to log, that has a lot of fields and I donโ€™t want to bother pas then in the constructor.
๐Ÿ‘ 1