Thread: Logging queries executed by SPI_execute

Hi there,

I have been trying to debug what queries an extension is firing. After reading
the code for the extension, I noticed that all the statements are fired via the
SPI interface, most specifically, using the SPI_execute* family of functions.

However, the problem is that these statements don't seem to feature in the
logfile. It has become a bit of a "dead end" for me to fully analyse what
queries are fired in the end.

My postgresql.conf is fairly simple, but I have added "log_statement = 'all'"
and thus was expecting to see information for these statements too.

Is there anything I am missing? Some configuration or perhaps another way to
find out about these statements?

It may not be relevant, but the extension I am having a look at is pg_repack if
anyone is interested. I am trying to get a deeper understanding of what the
function repack_apply does.

Thanks,
Marcelo.

On Mon, Feb 3, 2025 at 6:46 PM Pavel Stehule <pavel.stehule@gmail.com> wrote:
> The queries executed by SPI are never executed on the top level. These queries are marked as nested.
>
> So you need to use auto_explain https://www.postgresql.org/docs/current/auto-explain.html with active
auto_explain.log_nested_statements

Thanks Pavel, I have tried that but however couldn't succeed.

I have added this to my postgres.conf file:

    session_preload_libraries = 'auto_explain'
    auto_explain.log_nested_statements = true

After running pg_repack, which calls SPI_execute* functions, I can't really see
those functions being propagated to the logs.

I have a workaround in place, which is to add elog calls such as

    elog(LOG, "...")

to capture the queries. But of course, ideally a postgres.conf setting would be
more handy.

Best,
Marcelo