diff --git a/CHANGELOG.md b/CHANGELOG.md index 2f6862480d..c1637d3fbe 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,7 @@ This project adheres to [Semantic Versioning](http://semver.org/). - #2887, Add Preference `max-affected` to limit affected resources - @taimoorzaeem - #3171, Add an ability to dump config via admin API - @skywriter - #3061, Apply all function settings as transaction-scoped settings - @taimoorzaeem + - #3171, Log schema cache stats to stderr - @steve-chavez ### Fixed diff --git a/src/PostgREST/AppState.hs b/src/PostgREST/AppState.hs index 71903d8399..8b577efbb1 100644 --- a/src/PostgREST/AppState.hs +++ b/src/PostgREST/AppState.hs @@ -46,6 +46,7 @@ import qualified Network.HTTP.Types.Status as HTTP import qualified Network.Socket as NS import qualified PostgREST.Error as Error import PostgREST.Version (prettyVersion) +import System.TimeIt (timeItT) import Control.AutoUpdate (defaultUpdateSettings, mkAutoUpdate, updateAction) @@ -58,6 +59,8 @@ import Data.Time (ZonedTime, defaultTimeLocale, formatTime, getZonedTime) import Data.Time.Clock (UTCTime, getCurrentTime) +import Numeric (showFFloat) + import PostgREST.Config (AppConfig (..), LogLevel (..), addFallbackAppName, @@ -67,8 +70,9 @@ import PostgREST.Config.Database (queryDbSettings, queryRoleSettings) import PostgREST.Config.PgVersion (PgVersion (..), minimumPgVersion) -import PostgREST.SchemaCache (SchemaCache, - querySchemaCache) +import PostgREST.SchemaCache (SchemaCache (..), + querySchemaCache, + showSummary) import PostgREST.SchemaCache.Identifiers (dumpQi) import PostgREST.Unix (createAndBindDomainSocket) @@ -307,9 +311,9 @@ data SCacheStatus loadSchemaCache :: AppState -> IO SCacheStatus loadSchemaCache appState = do conf@AppConfig{..} <- getConfig appState - result <- + (resultTime, result) <- let transaction = if configDbPreparedStatements then SQL.transaction else SQL.unpreparedTransaction in - usePool appState conf . transaction SQL.ReadCommitted SQL.Read $ + timeItT $ usePool appState conf . transaction SQL.ReadCommitted SQL.Read $ querySchemaCache conf case result of Left e -> do @@ -326,9 +330,13 @@ loadSchemaCache appState = do return SCOnRetry Right sCache -> do - putSchemaCache appState (Just sCache) - logWithZTime appState "Schema cache loaded" + putSchemaCache appState $ Just sCache + logWithZTime appState $ "Schema cache queried in " <> showMillis resultTime <> " milliseconds" + logWithZTime appState $ "Schema cache loaded " <> showSummary sCache return SCLoaded + where + showMillis :: Double -> Text + showMillis x = toS $ showFFloat (Just 1) (x * 1000) "" -- | Current database connection status data ConnectionStatus data ConnectionStatus diff --git a/src/PostgREST/SchemaCache.hs b/src/PostgREST/SchemaCache.hs index 2bfe801a43..34a8d60f6e 100644 --- a/src/PostgREST/SchemaCache.hs +++ b/src/PostgREST/SchemaCache.hs @@ -24,6 +24,7 @@ module PostgREST.SchemaCache , accessibleTables , accessibleFuncs , schemaDescription + , showSummary ) where import Control.Monad.Extra (whenJust) @@ -34,6 +35,7 @@ import qualified Data.Aeson.Types as JSON import qualified Data.HashMap.Strict as HM import qualified Data.HashMap.Strict.InsOrd as HMI import qualified Data.Set as S +import qualified Data.Text as T import qualified Hasql.Decoders as HD import qualified Hasql.Encoders as HE import qualified Hasql.Statement as SQL @@ -93,6 +95,16 @@ instance JSON.ToJSON SchemaCache where , "dbTimezones" .= JSON.emptyArray ] +showSummary :: SchemaCache -> Text +showSummary (SchemaCache tbls rels routs reps mediaHdlrs _) = + T.intercalate ", " + [ show (HM.size tbls) <> " Relations" + , show (HM.size rels) <> " Relationships" + , show (HM.size routs) <> " Functions" + , show (HM.size reps) <> " Domain Representations" + , show (HM.size mediaHdlrs) <> " Media Type Handlers" + ] + -- | A view foreign key or primary key dependency detected on its source table -- Each column of the key could be referenced multiple times in the view, e.g. -- diff --git a/test/memory/memory-tests.sh b/test/memory/memory-tests.sh index 20967082d9..28f8088c4b 100755 --- a/test/memory/memory-tests.sh +++ b/test/memory/memory-tests.sh @@ -103,8 +103,8 @@ postJsonArrayTest(){ echo "Running memory usage tests.." jsonKeyTest "1M" "POST" "/rpc/leak?columns=blob" "27M" -jsonKeyTest "1M" "POST" "/leak?columns=blob" "16M" -jsonKeyTest "1M" "PATCH" "/leak?id=eq.1&columns=blob" "16M" +jsonKeyTest "1M" "POST" "/leak?columns=blob" "20M" +jsonKeyTest "1M" "PATCH" "/leak?id=eq.1&columns=blob" "20M" jsonKeyTest "10M" "POST" "/rpc/leak?columns=blob" "44M" jsonKeyTest "10M" "POST" "/leak?columns=blob" "44M" @@ -114,8 +114,8 @@ jsonKeyTest "50M" "POST" "/rpc/leak?columns=blob" "172M" jsonKeyTest "50M" "POST" "/leak?columns=blob" "172M" jsonKeyTest "50M" "PATCH" "/leak?id=eq.1&columns=blob" "172M" -postJsonArrayTest "1000" "/perf_articles?columns=id,body" "15M" -postJsonArrayTest "10000" "/perf_articles?columns=id,body" "15M" +postJsonArrayTest "1000" "/perf_articles?columns=id,body" "20M" +postJsonArrayTest "10000" "/perf_articles?columns=id,body" "20M" postJsonArrayTest "100000" "/perf_articles?columns=id,body" "24M" trap - int term exit