Add log placeholder for response header values (#135)

* add placeholder for logging response header values

* formatting

README.md

@@ -428,6 +428,7 @@ you may use are:
 - `Message` - A user-supplied message using `logWithMessage`.
 - `ResponseContent` - The response content received. Must implement `ToString` to give meaningful output.
 - `RequestContent` - The request content being sent. Must implement `ToString` to give meaningful output.
+- `ResponseHeader[key]` - The response header received, replace `key` with the name of the header field.
 - `Url` - The URL used for fetching.
 
 **Note:** Oryx will not call `.ToString ()` but will hand it over to the `ILogger` for the actual string interpolation,

src/HttpHandler/Fetch.fs

@@ -59,7 +59,7 @@ module Fetch =
 
         request
 
-    /// Fetch content using the given context. Exposes `{Url}`, `{ResponseContent}`, `{RequestContent}` and `{Elapsed}`
+    /// Fetch content using the given context. Exposes `{Url}`, `{ResponseContent}`, `{ResponseHeader[key]}`, `{RequestContent}` and `{Elapsed}`
     /// to the log format.
     let fetch<'TSource> (source: HttpHandler<'TSource>) : HttpHandler<HttpContent> =
         fun next ->

src/HttpHandler/HttpContext.fs

@@ -47,6 +47,9 @@ module PlaceHolder =
     [<Literal>]
     let ResponseContent = "ResponseContent"
 
+    [<Literal>]
+    let ResponseHeader = "ResponseHeader"
+
     [<Literal>]
     let Message = "Message"
 

src/HttpHandler/Logging.fs

@@ -13,7 +13,14 @@ open FSharp.Control.TaskBuilder
 module Logging =
     // Pre-compiled
     let private reqex =
-        Regex(@"\{(.+?)\}", RegexOptions.Multiline ||| RegexOptions.Compiled)
+        Regex(@"\{(.+?)(\[(.+?)\])?\}", RegexOptions.Multiline ||| RegexOptions.Compiled)
+
+    let private getHeaderValue (headers: Map<string, seq<string>>) (key: string) : string =
+        match headers.TryGetValue(key) with
+        | (true, v) ->
+            match Seq.tryHead v with
+            | first -> if first.IsSome then first.Value else String.Empty
+        | (false, _) -> String.Empty
 
     let private log' logLevel ctx content =
         match ctx.Request.Logger with
@@ -37,6 +44,10 @@ module Logging =
                         |> Option.toObj
                         :> _
                     | PlaceHolder.ResponseContent -> content :> _
+                    | PlaceHolder.ResponseHeader ->
+                        // GroupCollection returns empty string values for indexes beyond what was captured, therefore
+                        // we don't cause an exception here if the optional second group was not captured
+                        getHeaderValue (ctx.Response.Headers) (match'.Groups.[3].Value) :> _
                     | key ->
                         // Look for the key in the extra info. This also enables custom HTTP handlers to add custom
                         // placeholders to the format string.

test/Fetch.fs

@@ -116,6 +116,9 @@ let ``Get with logging is OK`` () =
                 (task {
                     let responseMessage = new HttpResponseMessage(HttpStatusCode.OK)
                     responseMessage.Content <- new PushStreamContent("42")
+                    responseMessage.Headers.Add("test", value = "test-value")
+                    responseMessage.Headers.Add("test2", value = "not-included-in-log")
+                    responseMessage.Headers.Add("X-Request-ID", value = "test-request-id")
                     return responseMessage
                 }))
 
@@ -129,6 +132,10 @@ let ``Get with logging is OK`` () =
             |> withMetrics metrics
             |> withLogger logger
             |> withLogLevel LogLevel.Debug
+            |> withLogFormat (
+                HttpContext.defaultLogFormat
+                + "\n← {ResponseHeader[test]}\n← {ResponseHeader[X-Request-ID]}\n← {ResponseHeader}"
+            )
             |> cache
 
         // Act
@@ -143,6 +150,9 @@ let ``Get with logging is OK`` () =
         // Assert
         test <@ logger.Output.Contains "42" @>
         test <@ logger.Output.Contains "http://test.org" @>
+        test <@ logger.Output.Contains "test-value" @>
+        test <@ logger.Output.Contains "test-request-id" @>
+        test <@ logger.Output.Contains "not-included-in-log" = false @>
         test <@ Result.isOk result @>
         test <@ metrics.Retries = 0L @>
         test <@ metrics.Fetches = 1L @>
@@ -164,6 +174,9 @@ let ``Post with logging is OK`` () =
                     retries <- retries + 1
                     let responseMessage = new HttpResponseMessage(HttpStatusCode.OK)
                     responseMessage.Content <- new PushStreamContent("""{ "pong": 42 }""")
+                    responseMessage.Headers.Add("test", value = "test-value")
+                    responseMessage.Headers.Add("test2", value = "not-included-in-log")
+                    responseMessage.Headers.Add("X-Request-ID", value = "test-request-id")
                     return responseMessage
                 }))
 
@@ -179,6 +192,10 @@ let ``Post with logging is OK`` () =
             |> withHeader ("api-key", "test-key")
             |> withLogger (logger)
             |> withLogLevel LogLevel.Debug
+            |> withLogFormat (
+                HttpContext.defaultLogFormat
+                + "\n← {ResponseHeader[test]}\n← {ResponseHeader[X-Request-ID]}\n← {ResponseHeader}"
+            )
             |> cache
 
         // Act
@@ -190,6 +207,9 @@ let ``Post with logging is OK`` () =
         test <@ logger.Output.Contains json @>
         test <@ logger.Output.Contains msg @>
         test <@ logger.Output.Contains "http://testing.org" @>
+        test <@ logger.Output.Contains "test-value" @>
+        test <@ logger.Output.Contains "test-request-id" @>
+        test <@ logger.Output.Contains "not-included-in-log" = false @>
         test <@ Result.isOk result @>
         test <@ retries' = 1 @>
     }