SQL vs PL/pgSQL in PostgreSQL: Plan Caching

During recent load testing of a reporting workload on PostgreSQL 16, we found something interesting.

A very simple SQL function, one line with a regular expression, was called 10 million times by a job that runs every hour. Each run kept a CPU core fully busy for about 47 seconds. We fixed it by converting that one function from LANGUAGE sql to LANGUAGE plpgsql. The query inside the function did not change, the job did not change, and the job returned the same result with about half the CPU.

The behaviour behind this case is already fixed in PostgreSQL 18. Many production systems still run PostgreSQL 16 or 17, though, and there the question is worth answering: how does changing the language of a function, without changing its query, cut its CPU cost in half?

The workload: an hourly error dashboard#

The application writes its logs to PostgreSQL: debug messages, request logs, warnings, and errors with full stack traces. About 10 million lines arrive every day.

CREATE TABLE app_logs (
    id        bigint PRIMARY KEY,
    logged_at timestamptz NOT NULL,
    app       text NOT NULL,
    level     text NOT NULL,
    message   text NOT NULL
);

For the load test we loaded 24 hours of logs: 10 million rows, 1.2 GB.

Level	Rows	Example message
DEBUG	6,000,000	cache lookup key=user:4200 hit=t
INFO	2,500,000	GET /api/orders/4260 status=200 duration_ms=60
WARN	500,000	slow query detected duration_ms=1785
ERROR	1,000,000	[ERR-1040] payment gateway call failed: ... and a stack trace

An error line looks like this:

[ERR-1040] payment gateway call failed: timeout after 3000 ms
    at com.shop.pay.GatewayClient.call(GatewayClient.java:88)
    at com.shop.pay.PaymentService.charge(PaymentService.java:142)
    at com.shop.api.CheckoutController.submit(CheckoutController.java:57)

The error code is always ERR- followed by four digits, so the regular expression ERR-[0-9]{4} finds it.

Every hour, a job refreshes an “errors in the last 24 hours” dashboard. It reads the last 24 hours of logs, pulls the error code out of each line, and counts the errors per code. That is 10 million function calls per run.

The function behind the CPU spike#

The error code is extracted by a small helper function, the kind found in many codebases:

CREATE FUNCTION get_error_code(p_message text) RETURNS text
LANGUAGE sql AS $$
    SELECT (regexp_matches(p_message, 'ERR-[0-9]{4}'))[1]
$$;

The hourly job calls it once for every log line:

DO $$
DECLARE
    r        record;
    v_code   text;
    v_errors bigint := 0;
BEGIN
    FOR r IN
        SELECT message FROM app_logs
        WHERE logged_at >= now() - interval '24 hours'
    LOOP
        SELECT get_error_code(r.message) INTO v_code;

        IF v_code IS NOT NULL THEN
            v_errors := v_errors + 1;    -- the real job counts per error code here
        END IF;
    END LOOP;

    RAISE NOTICE 'error lines found: %', v_errors;
END
$$;

The loop visits all 10 million lines and reports error lines found: 1000000.

The fix: the same function in PL/pgSQL, which fixed the CPU spike#

CREATE OR REPLACE FUNCTION get_error_code(p_message text) RETURNS text
LANGUAGE plpgsql AS $$
DECLARE
    v_code text;
BEGIN
    SELECT (regexp_matches(p_message, 'ERR-[0-9]{4}'))[1] INTO v_code;
    RETURN v_code;
END
$$;

CREATE OR REPLACE keeps the function’s name and arguments, so the hourly job did not change at all. The query inside the function did not change either, and both versions return the same result. Row 1 is a debug line with no error code, and row 90 is an error line:

SELECT id, level, get_error_code(message) AS error_code
FROM app_logs
WHERE id IN (1, 90);

--  id | level | error_code
-- ----+-------+------------
--   1 | DEBUG |
--  90 | ERROR | ERR-1040

The result#

Our load-test environment was PostgreSQL 16.15 with default settings. We ran the hourly job three times with each version of the function:

Version of get_error_code	CPU time per run (three runs)	Error lines found
LANGUAGE sql	47.7 s, 45.8 s, 48.3 s	1,000,000
LANGUAGE plpgsql	24.5 s, 24.4 s, 24.3 s	1,000,000

CPU time is the user plus system time that PostgreSQL reported for the job, with log_statement_stats = on. The run time was the same as the CPU time: the database process used one CPU core at 100% from start to finish.

Why a language change fixed it#

Before PostgreSQL runs a query, it makes a plan: the steps it will follow to compute the result. Even a one-line query has a plan, and making it is pure CPU work. For a query like ours it takes about a microsecond. Done once, that is nothing. Done ten million times, every hour, it adds up.

Before PostgreSQL 18, that is in versions 16 and 17, PostgreSQL handles plans differently for the two languages.

PL/pgSQL keeps its plans. When a PL/pgSQL function runs a query for the first time in a session, PostgreSQL saves it in a plan cache. For the first five calls, it plans with the real message text. On the sixth call, it makes one general plan that works for any message. If the general plan is not more expensive, PostgreSQL uses it for every call after that. That is six plans in total, however many rows the loop visits.

A SQL function on PostgreSQL 16 does not. It has no plan cache. It keeps its plan only until the statement that called it finishes. In the hourly job, SELECT get_error_code(r.message) INTO v_code is a new statement for every row. So for every row, PostgreSQL parses the function body, plans its query, runs it once, and throws all of that away.

How the loop calls the function matters. A plain assignment, v_code := get_error_code(r.message);, keeps the call alive for the whole run, so the SQL function is planned once. SELECT ... INTO, PERFORM and EXECUTE start a new query every time.

Why is such a simple function planned at all?#

PostgreSQL usually does not plan a one-line SQL function on its own. It copies the function body into the calling query, which is called inlining, and the function disappears. That did not happen here, and the reason is regexp_matches. It is a set-returning function (it returns zero or more rows), and PostgreSQL does not inline a SQL function whose body calls one. EXPLAIN shows the function call staying in the plan:

EXPLAIN (VERBOSE, COSTS OFF)
SELECT get_error_code(message) FROM app_logs WHERE id = 90;

--  Index Scan using app_logs_pkey on public.app_logs
--    Output: get_error_code(message)
--    Index Cond: (app_logs.id = 90)

Now change regexp_matches to regexp_match, which returns a single result instead of a set (available since PostgreSQL 10):

CREATE OR REPLACE FUNCTION get_error_code(p_message text) RETURNS text
LANGUAGE sql AS $$
    SELECT (regexp_match(p_message, 'ERR-[0-9]{4}'))[1]
$$;

-- the same EXPLAIN now shows:
--  Index Scan using app_logs_pkey on public.app_logs
--    Output: (regexp_match(message, 'ERR-[0-9]{4}'::text))[1]
--    Index Cond: (app_logs.id = 90)

The function is now inlined, so there is no function plan left to repeat. With this version, the same hourly job used 11.9 seconds of CPU, half of the PL/pgSQL version. When a function can be written so that PostgreSQL inlines it, that is the better fix.

Seeing it with pg_stat_statements#

You do not have to take this on trust. pg_stat_statements counts how many times each statement was executed and how many times it was planned. Two settings make it include the queries inside functions:

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.track = all            # include statements inside functions
pg_stat_statements.track_planning = on    # count plans as well as executions

Reset the counters, run the hourly job, and then look at the statements:

SELECT pg_stat_statements_reset();

-- run the hourly job here

SELECT calls, plans, query
FROM pg_stat_statements
WHERE query LIKE 'SELECT (regexp_matches%';

This is what we saw on PostgreSQL 16, once for each version of the function (pg_stat_statements shows constants as $2 and $3):

Statement	Version	Executed	Planned
SELECT (regexp_matches(p_message, $2))[$3] (inside the function)	sql	10,000,000	10,000,000
SELECT (regexp_matches(p_message, $2))[$3] (inside the function)	plpgsql	10,000,000	6

As the results show, the PL/pgSQL version planned the query just 6 times, whereas the SQL version generated an execution plan 10,000,000 times, once for every row. That is where the CPU was busy: generating a new plan for each statement.

Summary#

• On PostgreSQL 16, a SQL function that cannot be inlined keeps its plan only until the statement that called it finishes.
• The hourly job called it with SELECT ... INTO, a new statement for every row: 10,000,000 plans per run.
• PL/pgSQL keeps its plans in a cache and planned the same query six times.
• Converting the function to PL/pgSQL cut the CPU time per run from about 47 seconds to about 24 seconds, with the same result.

References#

• PostgreSQL 18.0 release notes, “Improve SQL-language function plan caching”: https://www.postgresql.org/docs/release/18.0/
• The commit behind it, “Change SQL-language functions to use the plan cache”: https://www.postgresql.org/message-id/[email protected]
• PostgreSQL 16 documentation, PL/pgSQL plan caching: https://www.postgresql.org/docs/16/plpgsql-implementation.html
• PostgreSQL 16 documentation, regexp_match and regexp_matches: https://www.postgresql.org/docs/16/functions-matching.html
• PostgreSQL 16 documentation, pg_stat_statements: https://www.postgresql.org/docs/16/pgstatstatements.html