.. _observability: Observability ############# Observability allows measuring a system's current state based on the data it generates, such as logs, metrics, and traces. .. contents:: :depth: 1 :local: :backlinks: none .. _pgrst_logging: Logs ==== PostgREST logs basic request information to ``stdout``, including the authenticated user if available, the requesting IP address and user agent, the URL requested, the HTTP response status and the response body size in bytes if available. With :ref:`log-level` set to ``info``, we get: .. code:: 127.0.0.1 - user [26/Jul/2021:01:56:38 -0500] "GET /clients HTTP/1.1" 200 56 "" "curl/7.64.0" 127.0.0.1 - anonymous [26/Jul/2021:01:56:48 -0500] "GET /unexistent HTTP/1.1" 404 162 "" "curl/7.64.0" For diagnostic information about the server itself, PostgREST logs to ``stderr``: - The full version of the connected PostgreSQL database. - :ref:`schema_cache` statistics. - The messages received by the :ref:`listener`. .. code:: 06/May/2024:08:16:11 -0500: Starting PostgREST 12.1... 06/May/2024:08:16:11 -0500: Successfully connected to PostgreSQL 14.10 (Ubuntu 14.10-0ubuntu0.22.04.1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, 64-bit 06/May/2024:08:16:11 -0500: Connection Pool initialized with a maximum size of 10 connections 06/May/2024:08:16:11 -0500: API server listening on port 3000 06/May/2024:08:16:11 -0500: Listening for database notifications on the "pgrst" channel 06/May/2024:08:16:11 -0500: Config reloaded 06/May/2024:08:16:11 -0500: Schema cache queried in 3.8 milliseconds 06/May/2024:08:16:11 -0500: Schema cache loaded 15 Relations, 8 Relationships, 8 Functions, 0 Domain Representations, 4 Media Type Handlers 06/May/2024:14:11:27 -0500: Received a config reload message on the "pgrst" channel 06/May/2024:14:11:27 -0500: Config reloaded .. note:: Logs are based on the ``log-level`` setting. See :ref:`log-level`. .. _sql_query_logs: SQL Query Logs -------------- To log the SQL queries executed for a request, set the :ref:`log-query` to ``true``. It will be logged based on the current :ref:`log-level` setting. .. code-block:: bash log-level = "warn" log-query = "true" The SQL queries will only be logged on ``400`` HTTP errors and up. So, if the user requests a resource without sufficient privileges: .. code-block:: bash curl "localhost:3000/protected_table" This will be logged by PostgREST: .. code:: 17/Feb/2025:17:28:15 -0500: WITH pgrst_source AS ( SELECT "public"."protected_table".* FROM "public"."protected_table" ) SELECT null::bigint AS total_result_set, pg_catalog.count(_postgrest_t) AS page_total, coalesce(json_agg(_postgrest_t), '[]') AS body, nullif(current_setting('response.headers', true), '') AS response_headers, nullif(current_setting('response.status', true), '') AS response_status, '' AS response_inserted FROM ( SELECT * FROM pgrst_source ) _postgrest_t 127.0.0.1 - web_anon [17/Feb/2025:17:28:15 -0500] "GET /protected_table HTTP/1.1" 401 99 "" "curl/8.7.1" Database Logs ------------- Additionally, to find all the SQL operations, you can watch the database logs. By default PostgreSQL does not keep these logs, so you'll need to make the configuration changes below. Find :code:`postgresql.conf` inside your PostgreSQL data directory (to find that, issue the command :code:`show data_directory;`). Either find the settings scattered throughout the file and change them to the following values, or append this block of code to the end of the configuration file. .. code:: sql # send logs where the collector can access them log_destination = "stderr" # collect stderr output to log files logging_collector = on # save logs in pg_log/ under the pg data directory log_directory = "pg_log" # (optional) new log file per day log_filename = "postgresql-%Y-%m-%d.log" # log every kind of SQL statement log_statement = "all" Restart the database and watch the log file in real-time to understand how HTTP requests are being translated into SQL commands. .. note:: On Docker you can enable the logs by using a custom ``init.sh``: .. code:: bash #!/bin/sh echo "log_statement = 'all'" >> /var/lib/postgresql/data/postgresql.conf After that you can start the container and check the logs with ``docker logs``. .. code:: bash docker run -v "$(pwd)/init.sh":"/docker-entrypoint-initdb.d/init.sh" -d postgres docker logs -f .. _metrics: Metrics ======= The ``metrics`` endpoint on the :ref:`admin_server` endpoint provides metrics in `Prometheus text format `_. .. code-block:: bash curl "http://localhost:3001/metrics" .. code-block:: http HTTP/1.1 200 OK Content-Type: text/plain; charset=utf-8 # HELP pgrst_schema_cache_query_time_seconds The query time in seconds of the last schema cache load # TYPE pgrst_schema_cache_query_time_seconds gauge pgrst_schema_cache_query_time_seconds 1.5937927e-2 # HELP pgrst_schema_cache_loads_total The total number of times the schema cache was loaded # TYPE pgrst_schema_cache_loads_total counter pgrst_schema_cache_loads_total 1.0 ... Schema Cache Metrics -------------------- Metrics related to the :ref:`schema_cache`. pgrst_schema_cache_query_time_seconds ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Gauge ======== ======= The query time in seconds of the last schema cache load. pgrst_schema_cache_loads_total ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ========== ========================== **Type** Counter **Labels** ``status``: SUCCESS | FAIL ========== ========================== The total number of times the schema cache was loaded. Connection Pool Metrics ----------------------- Metrics related to the :ref:`connection_pool`. pgrst_db_pool_timeouts_total ~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Counter ======== ======= The total number of pool connection timeouts. pgrst_db_pool_available ~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Gauge ======== ======= Available connections in the pool. pgrst_db_pool_waiting ~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Gauge ======== ======= Requests waiting to acquire a pool connection pgrst_db_pool_max ~~~~~~~~~~~~~~~~~ ======== ======= **Type** Gauge ======== ======= Max pool connections. .. _jwt_cache_metrics: JWT Cache Metrics ----------------- Metrics related to the :ref:`jwt_caching`. pgrst_jwt_cache_requests_total ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Counter ======== ======= The total number of JWT cache lookups. pgrst_jwt_cache_hits_total ~~~~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Counter ======== ======= The total number of JWT cache hits. pgrst_jwt_cache_evictions_total ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ======== ======= **Type** Counter ======== ======= The total number of JWT cache evictions. Traces ====== Server Version Header --------------------- When debugging a problem it's important to verify the running PostgREST version. For this you can look at the :code:`Server` HTTP response header that is returned on every request. .. code:: HEAD /users HTTP/1.1 Server: postgrest/11.0.1 .. _trace_header: Trace Header ------------ You can enable tracing HTTP requests by setting :ref:`server-trace-header`. Specify the set header in the request, and the server will include it in the response. .. code:: bash server-trace-header = "X-Request-Id" .. code-block:: bash curl "http://localhost:3000/users" \ -H "X-Request-Id: 123" .. code:: HTTP/1.1 200 OK X-Request-Id: 123 Proxy-Status Header ------------------- See :ref:`proxy-status_header`. .. _server-timing_header: Server-Timing Header -------------------- You can enable the `Server-Timing `_ header by setting :ref:`server-timing-enabled` on. This header communicates metrics of the different phases in the request-response cycle. .. code-block:: bash curl "http://localhost:3000/users" -i .. code:: HTTP/1.1 200 OK Server-Timing: jwt;dur=14.9, parse;dur=71.1, plan;dur=109.0, transaction;dur=353.2, response;dur=4.4 - All the durations (``dur``) are in milliseconds. - The ``jwt`` stage is when :ref:`jwt_auth` is done. This duration can be lowered with :ref:`jwt_caching`. - On the ``parse`` stage, the :ref:`url_grammar` is parsed. - On the ``plan`` stage, the :ref:`schema_cache` is used to generate the :ref:`main_query` of the transaction. - The ``transaction`` stage corresponds to the database transaction. See :ref:`transactions`. - The ``response`` stage is where the response status and headers are computed. .. note:: We're working on lowering the duration of the ``parse`` and ``plan`` stages on https://github.com/PostgREST/postgrest/issues/2816. .. _content-length_header: Content-Length Header --------------------- You can verify the response body size in bytes in the `Content-Length header `_. .. code-block:: bash curl -i 'localhost:3000/users' .. code-block:: http HTTP/1.1 200 OK Content-Length: 104 Note that this header won't be returned on ``HEAD`` requests for optimization purposes (see :ref:`head_req`). This is in line with `RFC 9110 `_. The body size is also present in the :ref:`PostgREST logs `. .. _explain_plan: Execution plan -------------- You can get the `EXPLAIN execution plan `_ of a request by adding the ``Accept: application/vnd.pgrst.plan`` header. This is enabled by :ref:`db-plan-enabled` (false by default). .. code-block:: bash curl "http://localhost:3000/users?select=name&order=id" \ -H "Accept: application/vnd.pgrst.plan" .. code-block:: postgres Aggregate (cost=73.65..73.68 rows=1 width=112) -> Index Scan using users_pkey on users (cost=0.15..60.90 rows=850 width=36) The output of the plan is generated in ``text`` format by default but you can change it to JSON by using the ``+json`` suffix. .. code-block:: bash curl "http://localhost:3000/users?select=name&order=id" \ -H "Accept: application/vnd.pgrst.plan+json" .. code-block:: json [ { "Plan": { "Node Type": "Aggregate", "Strategy": "Plain", "Partial Mode": "Simple", "Parallel Aware": false, "Async Capable": false, "Startup Cost": 73.65, "Total Cost": 73.68, "Plan Rows": 1, "Plan Width": 112, "Plans": [ { "Node Type": "Index Scan", "Parent Relationship": "Outer", "Parallel Aware": false, "Async Capable": false, "Scan Direction": "Forward", "Index Name": "users_pkey", "Relation Name": "users", "Alias": "users", "Startup Cost": 0.15, "Total Cost": 60.90, "Plan Rows": 850, "Plan Width": 36 } ] } } ] By default the plan is assumed to generate the JSON representation of a resource(``application/json``), but you can obtain the plan for the :ref:`different representations that PostgREST supports ` by adding them to the ``for`` parameter. For instance, to obtain the plan for a ``text/xml``, you would use ``Accept: application/vnd.pgrst.plan; for="text/xml``. The other available parameters are ``analyze``, ``verbose``, ``settings``, ``buffers`` and ``wal``, which correspond to the `EXPLAIN command options `_. To use the ``analyze`` and ``wal`` parameters for example, you would add them like ``Accept: application/vnd.pgrst.plan; options=analyze|wal``. Note that akin to the EXPLAIN command, the changes will be committed when using the ``analyze`` option. To avoid this, you can use the :ref:`db-tx-end` and the ``Prefer: tx=rollback`` header. Securing the Execution Plan ~~~~~~~~~~~~~~~~~~~~~~~~~~~ It's recommended to only activate :ref:`db-plan-enabled` on testing environments since it reveals internal database details. However, if you choose to use it in production you can add a :ref:`db-pre-request` to filter the requests that can use this feature. For example, to only allow requests from an IP address to get the execution plans: .. code-block:: postgres -- Assuming a proxy(Nginx, Cloudflare, etc) passes an "X-Forwarded-For" header(https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/X-Forwarded-For) create or replace function filter_plan_requests() returns void as $$ declare headers json := current_setting('request.headers', true)::json; client_ip text := coalesce(headers->>'x-forwarded-for', ''); accept text := coalesce(headers->>'accept', ''); begin if accept like 'application/vnd.pgrst.plan%' and client_ip != '144.96.121.73' then raise insufficient_privilege using message = 'Not allowed to use application/vnd.pgrst.plan'; end if; end; $$ language plpgsql; -- set this function on your postgrest.conf -- db-pre-request = filter_plan_requests .. raw:: html