Process Log Format String for Logger Compatibility (#137)

* format string logger compatibility fix

* refactor

* discard unused argument

* set access to private on added properties

* use Interlocked.Increment for counter

Author: ozangoktan

src/HttpHandler/Logging.fs

@@ -5,6 +5,7 @@ namespace Oryx
 
 open System
 open System.Text.RegularExpressions
+open System.Threading
 
 open Microsoft.Extensions.Logging
 open FSharp.Control.TaskBuilder
@@ -15,6 +16,14 @@ module Logging =
     let private reqex =
         Regex(@"\{(.+?)(\[(.+?)\])?\}", RegexOptions.Multiline ||| RegexOptions.Compiled)
 
+    let private loggerFormatRegex =
+        Regex($@"{{{PlaceHolder.ResponseHeader}\[(.+?)\]}}", RegexOptions.Multiline ||| RegexOptions.Compiled)
+
+    let mutable private placeholderCounter = 0
+
+    let private replacer (_: Match) : string =
+        $"{{{PlaceHolder.ResponseHeader}__{Interlocked.Increment(&placeholderCounter)}}}"
+
     let private getHeaderValue (headers: Map<string, seq<string>>) (key: string) : string =
         match headers.TryGetValue(key) with
         | (true, v) ->
@@ -57,7 +66,10 @@ module Logging =
                 |> Array.ofSeq
 
             let level, values = logLevel, getValues content
-            logger.Log(level, format, values)
+
+            let formatCompatibilityString = loggerFormatRegex.Replace(format, replacer)
+
+            logger.Log(level, formatCompatibilityString, values)
         | _ -> ()
 
     /// Set the logger (ILogger) to use. Usually you would use `HttpContext.withLogger` instead to set the logger for

test/Fetch.fs

@@ -110,6 +110,7 @@ let ``Get with logging is OK`` () =
         // Arrange
         let metrics = TestMetrics()
         let logger = new TestLogger<string>()
+        let msg = "custom message"
 
         let stub =
             Func<HttpRequestMessage, CancellationToken, Task<HttpResponseMessage>>(fun request token ->
@@ -124,18 +125,30 @@ let ``Get with logging is OK`` () =
 
         let client = new HttpClient(new HttpMessageHandlerStub(stub))
 
+        let logPlaceholders =
+            String.Join(
+                "\n← ",
+                [| "ResponseHeader[test]"
+                   "Message"
+                   "ResponseHeader[missing-key]"
+                   "ResponseHeader[X-Request-ID]"
+                   "ResponseHeader"
+                   "ResponseHeader["
+                   "ResponseHeader]"
+                   "ResponseHeader[[]]" |]
+                |> Array.map (fun x -> $"{{{x}}}")
+            )
+
         let ctx =
             httpRequest
             |> withHttpClient client
             |> withUrlBuilder (fun _ -> "http://test.org/")
             |> withHeader ("api-key", "test-key")
+            |> withLogMessage (msg)
             |> withMetrics metrics
             |> withLogger logger
             |> withLogLevel LogLevel.Debug
-            |> withLogFormat (
-                HttpContext.defaultLogFormat
-                + "\n← {ResponseHeader[test]}\n← {ResponseHeader[X-Request-ID]}\n← {ResponseHeader}"
-            )
+            |> withLogFormat (HttpContext.defaultLogFormat + $"\n← {logPlaceholders}\n← end")
             |> cache
 
         // Act
@@ -150,8 +163,7 @@ 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 $"test-value\n← {msg}\n← \n← test-request-id\n← \n← \n← \n← \n← end" @>
         test <@ logger.Output.Contains "not-included-in-log" = false @>
         test <@ Result.isOk result @>
         test <@ metrics.Retries = 0L @>
@@ -185,17 +197,28 @@ let ``Post with logging is OK`` () =
         let content () =
             new StringableContent(json) :> HttpContent
 
+        let logPlaceholders =
+            String.Join(
+                "\n← ",
+                [| "ResponseHeader[test]"
+                   "Message"
+                   "ResponseHeader[missing-key]"
+                   "ResponseHeader[X-Request-ID]"
+                   "ResponseHeader"
+                   "ResponseHeader["
+                   "ResponseHeader]"
+                   "ResponseHeader[[]]" |]
+                |> Array.map (fun x -> $"{{{x}}}")
+            )
+
         let ctx =
             httpRequest
             |> withHttpClientFactory (fun () -> client)
             |> withUrlBuilder (fun _ -> "http://testing.org/")
             |> withHeader ("api-key", "test-key")
             |> withLogger (logger)
             |> withLogLevel LogLevel.Debug
-            |> withLogFormat (
-                HttpContext.defaultLogFormat
-                + "\n← {ResponseHeader[test]}\n← {ResponseHeader[X-Request-ID]}\n← {ResponseHeader}"
-            )
+            |> withLogFormat (HttpContext.defaultLogFormat + $"\n← {logPlaceholders}\n← end")
             |> cache
 
         // Act
@@ -207,8 +230,7 @@ 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 $"test-value\n← {msg}\n← \n← test-request-id\n← \n← \n← \n← \n← end" @>
         test <@ logger.Output.Contains "not-included-in-log" = false @>
         test <@ Result.isOk result @>
         test <@ retries' = 1 @>

version

@@ -1 +1 @@
-5.4.1
+5.4.2