Merge pull request #125 from NoRedInk/log-when-changing-query-timeout

add a tracing span when modifying the query timeout

nri-redis/src/Redis/Handler.hs

@@ -18,6 +18,7 @@ import qualified Data.Text.Encoding
 import qualified Database.Redis
 import qualified Dict
 import qualified GHC.Stack as Stack
+import qualified Log
 import qualified Platform
 import qualified Redis.Internal as Internal
 import qualified Redis.Script as Script
@@ -60,14 +61,18 @@ handlerAutoExtendExpire namespace settings = do
     |> liftIO
 
 -- | Sets a timeout for the query in milliseconds.
-withQueryTimeoutMilliseconds :: Int -> Internal.Handler' x -> Internal.Handler' x
+withQueryTimeoutMilliseconds :: Int -> Internal.Handler' x -> Task () (Internal.Handler' x)
 withQueryTimeoutMilliseconds timeoutMs handler' =
-  handler' {Internal.queryTimeout = Settings.TimeoutQueryAfterMilliseconds timeoutMs}
+  (handler' {Internal.queryTimeout = Settings.TimeoutQueryAfterMilliseconds timeoutMs})
+    |> Task.succeed
+    |> Log.withContext "setting redis query timeout" [Log.context "timeoutMilliseconds" (Text.fromInt timeoutMs)]
 
 -- | Disables timeout for query in milliseconds
-withoutQueryTimeout :: Internal.Handler' x -> Internal.Handler' x
+withoutQueryTimeout :: Internal.Handler' x -> Task () (Internal.Handler' x)
 withoutQueryTimeout handler' =
-  handler' {Internal.queryTimeout = Settings.NoQueryTimeout}
+  (handler' {Internal.queryTimeout = Settings.NoQueryTimeout})
+    |> Task.succeed
+    |> Log.withContext "setting no redis query timeout" []
 
 defaultExpiryKeysAfterSeconds :: Int -> Internal.HandlerAutoExtendExpire -> Internal.HandlerAutoExtendExpire
 defaultExpiryKeysAfterSeconds secs handler' =

nri-redis/test/Spec/Redis.hs

@@ -23,7 +23,7 @@ import qualified Prelude
 -- put this at the top of the file so that adding tests doesn't push
 -- the line number of the source location of this file down, which would
 -- change golden test results
-spanForTask :: (Show e) => Task e () -> Expect.Expectation' Platform.TracingSpan
+spanForTask :: (Show e) => Task e a -> Expect.Expectation' Platform.TracingSpan
 spanForTask task =
   Expect.fromIO <| do
     spanVar <- MVar.newEmptyMVar
@@ -134,15 +134,30 @@ observabilityTests handler =
     Test.describe
       "with 0 ms timeout"
       [ Test.test "Redis.query reports the span data we expect" <| \() -> do
+          handlerThatExpiresImmediately <- Expect.succeeds (Redis.withQueryTimeoutMilliseconds 0 handler)
           span <-
-            Redis.query (Redis.withQueryTimeoutMilliseconds 0 handler) (Redis.ping api)
+            Redis.query handlerThatExpiresImmediately (Redis.ping api)
               |> spanForFailingTask
           span
             |> Debug.toString
             |> Expect.all
-              [ Expect.equalToContentsOf (goldenResultsDir ++ "/observability-spec-timeout-reporting-redis-query"),
+              [ Expect.equalToContentsOf (goldenResultsDir ++ "/observability-spec-reporting-redis-query-timeout"),
                 \spanText -> Expect.true (Text.contains "Redis Query" spanText)
-              ]
+              ],
+        Test.test "Redis.withQueryTimeoutMilliseconds reports the span data we expect" <| \() -> do
+          span <-
+            Redis.withQueryTimeoutMilliseconds 0 handler
+              |> spanForTask
+          span
+            |> Debug.toString
+            |> Expect.equalToContentsOf (goldenResultsDir ++ "/observability-spec-reporting-with-query-timout"),
+        Test.test "Redis.withoutQueryTimeout reports the span data we expect" <| \() -> do
+          spanSettingTimeout <-
+            Redis.withoutQueryTimeout handler
+              |> spanForTask
+          spanSettingTimeout
+            |> Debug.toString
+            |> Expect.equalToContentsOf (goldenResultsDir ++ "/observability-spec-reporting-without-query-timout")
       ]
   ]
 

nri-redis/test/golden-results-9.2/observability-spec-timeout-reporting-redis-query → nri-redis/test/golden-results-9.2/observability-spec-reporting-redis-query-timeout

@@ -32,9 +32,9 @@ TracingSpan
                     { srcLocPackage = "main"
                     , srcLocModule = "Spec.Redis"
                     , srcLocFile = "test/Spec/Redis.hs"
-                    , srcLocStartLine = 138
+                    , srcLocStartLine = 139
                     , srcLocStartCol = 13
-                    , srcLocEndLine = 138
+                    , srcLocEndLine = 139
                     , srcLocEndCol = 24
                     }
                 )

nri-redis/test/golden-results-9.2/observability-spec-reporting-with-query-timout

@@ -0,0 +1,49 @@
+TracingSpan
+  { name = "test-root"
+  , started = MonotonicTime { inMicroseconds = 0 }
+  , finished = MonotonicTime { inMicroseconds = 0 }
+  , frame =
+      Just
+        ( "rootTracingSpanIO"
+        , SrcLoc
+            { srcLocPackage = "main"
+            , srcLocModule = "Spec.Redis"
+            , srcLocFile = "test/Spec/Redis.hs"
+            , srcLocStartLine = 31
+            , srcLocStartCol = 7
+            , srcLocEndLine = 31
+            , srcLocEndCol = 33
+            }
+        )
+  , details = Nothing
+  , summary = Nothing
+  , succeeded = Succeeded
+  , containsFailures = False
+  , allocated = 0
+  , children =
+      [ TracingSpan
+          { name = "setting redis query timeout"
+          , started = MonotonicTime { inMicroseconds = 0 }
+          , finished = MonotonicTime { inMicroseconds = 0 }
+          , frame =
+              Just
+                ( "withContext"
+                , SrcLoc
+                    { srcLocPackage = "main"
+                    , srcLocModule = "Redis.Handler"
+                    , srcLocFile = "src/Redis/Handler.hs"
+                    , srcLocStartLine = 68
+                    , srcLocStartCol = 8
+                    , srcLocEndLine = 68
+                    , srcLocEndCol = 23
+                    }
+                )
+          , details = Just "{\"timeoutMilliseconds\":\"0\"}"
+          , summary = Just "setting redis query timeout"
+          , succeeded = Succeeded
+          , containsFailures = False
+          , allocated = 0
+          , children = []
+          }
+      ]
+  }

nri-redis/test/golden-results-9.2/observability-spec-reporting-without-query-timout

@@ -0,0 +1,49 @@
+TracingSpan
+  { name = "test-root"
+  , started = MonotonicTime { inMicroseconds = 0 }
+  , finished = MonotonicTime { inMicroseconds = 0 }
+  , frame =
+      Just
+        ( "rootTracingSpanIO"
+        , SrcLoc
+            { srcLocPackage = "main"
+            , srcLocModule = "Spec.Redis"
+            , srcLocFile = "test/Spec/Redis.hs"
+            , srcLocStartLine = 31
+            , srcLocStartCol = 7
+            , srcLocEndLine = 31
+            , srcLocEndCol = 33
+            }
+        )
+  , details = Nothing
+  , summary = Nothing
+  , succeeded = Succeeded
+  , containsFailures = False
+  , allocated = 0
+  , children =
+      [ TracingSpan
+          { name = "setting no redis query timeout"
+          , started = MonotonicTime { inMicroseconds = 0 }
+          , finished = MonotonicTime { inMicroseconds = 0 }
+          , frame =
+              Just
+                ( "withContext"
+                , SrcLoc
+                    { srcLocPackage = "main"
+                    , srcLocModule = "Redis.Handler"
+                    , srcLocFile = "src/Redis/Handler.hs"
+                    , srcLocStartLine = 75
+                    , srcLocStartCol = 8
+                    , srcLocEndLine = 75
+                    , srcLocEndCol = 23
+                    }
+                )
+          , details = Just "{}"
+          , summary = Just "setting no redis query timeout"
+          , succeeded = Succeeded
+          , containsFailures = False
+          , allocated = 0
+          , children = []
+          }
+      ]
+  }