refactor: simplify logger middleware

PostgREST · Jan 5, 2022 · 826ae74 · 826ae74
1 parent cde9cd4
commit 826ae74
Show file tree

Hide file tree

Showing 7 changed files with 73 additions and 54 deletions.
diff --git a/nix/overlays/haskell-packages.nix b/nix/overlays/haskell-packages.nix
@@ -20,6 +20,36 @@ let
       # To get the sha256:
       #   nix-prefetch-url --unpack https://hackage.haskell.org/package/protolude-0.3.0/protolude-0.3.0.tar.gz
 
+      # To temporarily pin unreleased versions from GitHub:
+      #   <name> =
+      #     prev.callCabal2nixWithOptions "<name>" (super.fetchFromGitHub {
+      #       owner = "<owner>";
+      #       repo  = "<repo>";
+      #       rev = "<commit>";
+      #       sha256 = "<sha256>";
+      #    }) "--subpath=<subpath>" {};
+      #
+      # To get the sha256:
+      #   nix-prefetch-url --unpack https://github.com/<owner>/<repo>/archive/<commit>.tar.gz
+
+      wai-extra =
+        prev.callHackageDirect
+          {
+            pkg = "wai-extra";
+            ver = "3.1.8";
+            sha256 = "1ha8sxc2ii7k7xs5nm06wfwqmf4f1p2acp4ya0jnx6yn6551qps4";
+          }
+          { };
+
+      wai-logger =
+        prev.callHackageDirect
+          {
+            pkg = "wai-logger";
+            ver = "2.3.7";
+            sha256 = "1d23fdbwbahr3y1vdyn57m1qhljy22pm5cpgb20dy6mlxzdb30xd";
+          }
+          { };
+
       hasql-dynamic-statements =
         lib.dontCheck (lib.unmarkBroken prev.hasql-dynamic-statements);
 

diff --git a/postgrest.cabal b/postgrest.cabal
@@ -82,7 +82,6 @@ library
                     , contravariant-extras      >= 0.3.3 && < 0.4
                     , cookie                    >= 0.4.2 && < 0.5
                     , either                    >= 4.4.1 && < 5.1
-                    , fast-logger               >= 2.4.5
                     , gitrev                    >= 1.2 && < 1.4
                     , hasql                     >= 1.4 && < 1.5
                     , hasql-dynamic-statements  == 0.3.1
@@ -112,8 +111,7 @@ library
                     , vector                    >= 0.11 && < 0.13
                     , wai                       >= 3.2.1 && < 3.3
                     , wai-cors                  >= 0.2.5 && < 0.3
-                    , wai-extra                 >= 3.0.19 && < 3.2
-                    , wai-logger                >= 2.3.2
+                    , wai-extra                 >= 3.1.8 && < 3.2
                     , warp                      >= 3.2.12 && < 3.4
                       -- -fno-spec-constr may help keep compile time memory use in check,
                       --   see https://gitlab.haskell.org/ghc/ghc/issues/16017#note_219304

diff --git a/src/PostgREST/Middleware.hs b/src/PostgREST/Middleware.hs
@@ -6,7 +6,6 @@ Description : Sets CORS policy. Also the PostgreSQL GUCs, role, search_path and
 {-# LANGUAGE RecordWildCards #-}
 module PostgREST.Middleware
   ( runPgLocals
-  , pgrstFormat
   , pgrstMiddleware
   , optionalRollback
   ) where
@@ -24,21 +23,16 @@ import qualified Hasql.DynamicStatements.Snippet      as SQL hiding
 import qualified Hasql.DynamicStatements.Statement    as SQL
 import qualified Hasql.Transaction                    as SQL
 import qualified Network.Wai                          as Wai
-import qualified Network.Wai.Logger                   as Wai
 import qualified Network.Wai.Middleware.Cors          as Wai
-import qualified Network.Wai.Middleware.Gzip          as Wai
 import qualified Network.Wai.Middleware.RequestLogger as Wai
 
 import Control.Arrow ((***))
 
-import Data.Function             (id)
 import Data.List                 (lookup)
 import Data.Scientific           (FPFormat (..), formatScientific,
                                   isInteger)
-import Network.HTTP.Types.Status (Status, status400, status500,
-                                  statusCode)
+import Network.HTTP.Types.Status (status400, status500)
 import System.IO.Unsafe          (unsafePerformIO)
-import System.Log.FastLogger     (toLogStr)
 
 import PostgREST.Config             (AppConfig (..), LogLevel (..))
 import PostgREST.Config.PgVersion   (PgVersion (..), pgVersion140)
@@ -95,45 +89,23 @@ runPgLocals conf claims app req jsonDbS actualPgVersion = do
     unquoted (JSON.Bool b) = show b
     unquoted v = T.decodeUtf8 . LBS.toStrict $ JSON.encode v
 
--- | Log in apache format. Only requests that have a status greater than minStatus are logged.
--- | There's no way to filter logs in the apache format on wai-extra: https://hackage.haskell.org/package/wai-extra-3.0.29.2/docs/Network-Wai-Middleware-RequestLogger.html#t:OutputFormat.
--- | So here we copy wai-logger apacheLogStr function: https://github.com/kazu-yamamoto/logger/blob/a4f51b909a099c51af7a3f75cf16e19a06f9e257/wai-logger/Network/Wai/Logger/Apache.hs#L45
--- | TODO: Add the ability to filter apache logs on wai-extra and remove this function.
-pgrstFormat :: Status -> Wai.OutputFormatter
-pgrstFormat minStatus date req status responseSize =
-  if status < minStatus
-    then mempty
-  else toLogStr (getSourceFromSocket req)
-    <> " - - ["
-    <> toLogStr date
-    <> "] \""
-    <> toLogStr (Wai.requestMethod req)
-    <> " "
-    <> toLogStr (Wai.rawPathInfo req <> Wai.rawQueryString req)
-    <> " "
-    <> toLogStr (show (Wai.httpVersion req)::Text)
-    <> "\" "
-    <> toLogStr (show (statusCode status)::Text)
-    <> " "
-    <> toLogStr (maybe "-" show responseSize::Text)
-    <> " \""
-    <> toLogStr (fromMaybe mempty $ Wai.requestHeaderReferer req)
-    <> "\" \""
-    <> toLogStr (fromMaybe mempty $ Wai.requestHeaderUserAgent req)
-    <> "\"\n"
-  where
-    getSourceFromSocket = BS.pack . Wai.showSockAddr . Wai.remoteHost
-
-pgrstMiddleware :: LogLevel -> Wai.Application -> Wai.Application
+pgrstMiddleware :: LogLevel -> Wai.Middleware
 pgrstMiddleware logLevel =
-    logger
+    logger logLevel
   . Wai.cors corsPolicy
+
+logger :: LogLevel -> Wai.Middleware
+logger logLevel = case logLevel of
+  LogInfo  -> requestLogger (const True)
+  LogWarn  -> requestLogger (>= status400)
+  LogError -> requestLogger (>= status500)
+  LogCrit  -> requestLogger (const False)
   where
-    logger = case logLevel of
-      LogCrit  -> id
-      LogError -> unsafePerformIO $ Wai.mkRequestLogger Wai.def { Wai.outputFormat = Wai.CustomOutputFormat $ pgrstFormat status500}
-      LogWarn  -> unsafePerformIO $ Wai.mkRequestLogger Wai.def { Wai.outputFormat = Wai.CustomOutputFormat $ pgrstFormat status400}
-      LogInfo  -> Wai.logStdout
+    requestLogger filterStatus = unsafePerformIO $ Wai.mkRequestLogger Wai.defaultRequestLoggerSettings
+      { Wai.outputFormat = Wai.ApacheWithSettings $
+          Wai.defaultApacheSettings
+            & Wai.setApacheRequestFilter (\_ res -> filterStatus $ Wai.responseStatus res)
+      }
 
 -- | CORS policy to be used in by Wai Cors middleware
 corsPolicy :: Wai.Request -> Maybe Wai.CorsResourcePolicy

diff --git a/stack.yaml b/stack.yaml
@@ -13,3 +13,5 @@ extra-deps:
   - hasql-dynamic-statements-0.3.1@sha256:c3a2c89c4a8b3711368dbd33f0ccfe46a493faa7efc2c85d3e354c56a01dfc48,2673
   - hasql-implicits-0.1.0.2@sha256:5d54e09cb779a209681b139fb3cc726bae75134557932156340cc0a56dd834a8,1361
   - ptr-0.16.8.1@sha256:525219ec5f5da5c699725f7efcef91b00a7d44120fc019878b85c09440bf51d6,2686
+  - wai-extra-3.1.8@sha256:bf3dbe8f4c707b502b2a88262ed71c807220651597b76b56983f864af6197890,7280
+  - wai-logger-2.3.7@sha256:19a0dc5122e22d274776d80786fb9501956f5e75b8f82464bbdad5604d154d82,1671
diff --git a/stack.yaml.lock b/stack.yaml.lock
@@ -7,27 +7,41 @@ packages:
 - completed:
     hackage: hasql-dynamic-statements-0.3.1@sha256:c3a2c89c4a8b3711368dbd33f0ccfe46a493faa7efc2c85d3e354c56a01dfc48,2673
     pantry-tree:
-      size: 641
       sha256: b1b9a6a26ec765e5fe29f9a670a5c9ec7067ea00dee8491f0819284ff0201b6f
+      size: 641
   original:
     hackage: hasql-dynamic-statements-0.3.1@sha256:c3a2c89c4a8b3711368dbd33f0ccfe46a493faa7efc2c85d3e354c56a01dfc48,2673
 - completed:
     hackage: hasql-implicits-0.1.0.2@sha256:5d54e09cb779a209681b139fb3cc726bae75134557932156340cc0a56dd834a8,1361
     pantry-tree:
-      size: 310
       sha256: 2f00d1467d0e226b966c2cd7bac433c8948e2f7bbdf8a44936029f66fc20b5f3
+      size: 310
   original:
     hackage: hasql-implicits-0.1.0.2@sha256:5d54e09cb779a209681b139fb3cc726bae75134557932156340cc0a56dd834a8,1361
 - completed:
     hackage: ptr-0.16.8.1@sha256:525219ec5f5da5c699725f7efcef91b00a7d44120fc019878b85c09440bf51d6,2686
     pantry-tree:
-      size: 1089
       sha256: d2b8440a738719ef8430ec38fe33b129e3940e4ccf2c016a727a1110a43656bb
+      size: 1089
   original:
     hackage: ptr-0.16.8.1@sha256:525219ec5f5da5c699725f7efcef91b00a7d44120fc019878b85c09440bf51d6,2686
+- completed:
+    hackage: wai-extra-3.1.8@sha256:bf3dbe8f4c707b502b2a88262ed71c807220651597b76b56983f864af6197890,7280
+    pantry-tree:
+      sha256: a544ea95288d188e893322a8e6d68f2b1f844f772dbea1f26e5c0c1a74694f56
+      size: 4053
+  original:
+    hackage: wai-extra-3.1.8@sha256:bf3dbe8f4c707b502b2a88262ed71c807220651597b76b56983f864af6197890,7280
+- completed:
+    hackage: wai-logger-2.3.7@sha256:19a0dc5122e22d274776d80786fb9501956f5e75b8f82464bbdad5604d154d82,1671
+    pantry-tree:
+      sha256: 52b5abf5c4c09bcfbc06e01f761a75c32cbd3e6ba23c8843981933fcc31ed53c
+      size: 474
+  original:
+    hackage: wai-logger-2.3.7@sha256:19a0dc5122e22d274776d80786fb9501956f5e75b8f82464bbdad5604d154d82,1671
 snapshots:
 - completed:
+    sha256: 87842ecbaa8ca9cee59a7e6be52369dbed82ed075cb4e0d152614a627e8fd488
     size: 586069
     url: https://raw.githubusercontent.com/commercialhaskell/stackage-snapshots/master/lts/18/14.yaml
-    sha256: 87842ecbaa8ca9cee59a7e6be52369dbed82ed075cb4e0d152614a627e8fd488
   original: lts-18.14
diff --git a/test/io-tests/fixtures.sql b/test/io-tests/fixtures.sql
@@ -73,3 +73,9 @@ create function reload_pgrst_config() returns void as $_$
 begin
   perform pg_notify('pgrst', 'reload config');
 end $_$ language plpgsql ;
+
+create or replace function raise_bad_pt() returns void as $$
+begin
+  raise sqlstate 'PT40A' using message = 'Wrong';
+end;
+$$ language plpgsql;
diff --git a/test/io-tests/test_io.py b/test/io-tests/test_io.py
@@ -816,10 +816,7 @@ def test_admin_live_dependent_on_main_app(defaultenv):
 def test_log_level(level, has_output, defaultenv):
     "log_level should filter request logging"
 
-    env = {
-        **defaultenv,
-        "PGRST_LOG_LEVEL": level
-    }
+    env = {**defaultenv, "PGRST_LOG_LEVEL": level}
 
     with run(env=env) as postgrest:
         response = postgrest.session.get("/")