store: log web handler exceptions as records

apps/simplex-store-service/src/StoreService/Web/Server.hs

@@ -543,9 +543,14 @@ eventTypeOf body = case J.decode body of
 webSettings :: ListenerConfig -> Warp.Settings
 webSettings ListenerConfig {lHost} =
   Warp.setHost (fromString (T.unpack lHost))
+    . Warp.setOnException logRequestException
     . Warp.setOnExceptionResponse (const internalError)
     $ Warp.defaultSettings
 
+-- | Warp's default writes the text and its newline apart, splitting a record another thread logs between them.
+logRequestException :: Maybe Request -> E.SomeException -> IO ()
+logRequestException _ e = when (Warp.defaultShouldDisplayException e) $ logError ("store service: a web request failed: " <> tshow e)
+
 -- | Each port with its app: the badges site's, and the names site's when it is served.
 webListeners :: WebEnv -> [(Int, Application)]
 webListeners env@WebEnv {weNamesSite} = (lBadgesPort, webApp env) : [(port, siteApp env weNamesSite) | Just port <- [lNamesPort]]

tests/Bots/StoreService/WebTests.hs

@@ -244,6 +244,7 @@ badgeWebTests = do
     it "answers a hold from the row it read, not from the status it woke on" testHoldReportsTheRowNotTheWake
     it "answers a hold that timed out with a change nothing published" testHoldTimeoutReportsAnUnpublishedChange
     it "answers a handler exception with 500 internal, and keeps serving" testHandlerExceptionIsContained
+    it "logs a handler exception as one service log record, never a bare line" testHandlerExceptionIsLogged
   describe "StoreService names: sites" $ do
     it "exports both sites, each with the publishable key" testExportsBothSites
     it "serves each site on its own port only, whatever the Host, and the API on both" testEachPortServesItsSite
@@ -1709,6 +1710,17 @@ testHandlerExceptionIsContained = bounded "handler exception" $ withWebAppExpect
   statusOf shell `shouldBe` 200
   responseBody shell `shouldBe` shellHtml
 
+-- | Warp reports an exception after sending the 500, and serves the connection's next request only after that report.
+testHandlerExceptionIsLogged :: IO ()
+testHandlerExceptionIsLogged = bounded "handler exception logged" $ withWebAppExpectingThrow $ \env client -> do
+  iid <- seedOpenInvoice env
+  breakStore (weStore env)
+  logs <- capturingStderr $ do
+    statusOf <$> webGet client (invoicePath iid) >>= (`shouldBe` 500)
+    statusOf <$> webGet client "/" >>= (`shouldBe` 200)
+  logs `shouldSatisfy` loggedError "store service: a web request failed: "
+  filter (not . ("[ERROR " `T.isPrefixOf`)) (filter ("badge_code_invoices" `T.isInfixOf`) (T.lines logs)) `shouldBe` []
+
 createsPerMinute :: Int
 createsPerMinute = 5