NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup

Started by Michael Paquierabout 7 hours ago3 messageshackers
Jump to latest
#1Michael Paquier
michael@paquier.xyz

Hi all,

While doing some tests today for a different patch, I had the surprise
to see the following failure on HEAD (not on REL_18_STABLE or older)
while loading one of the test modules (I was playing with test_slru,
one of the custom pgstats module fails equally). Reproducing this
problem requires the following setup:
- Module loaded by shared_preload_libraries
- logging_collector active, which we don't do in most of the tests run
by the buildfarm.
- -DEXEC_BACKEND.
- Use at least log_min_messages = debug1 to make load_libraries
generate at least one message

Then one is greeted by:
==465718==Using libbacktrace symbolizer. syslogger.c:1118:7: runtime
error: null pointer passed as argument 4, which is declared to never
be null
#0 0x0000012b9331 in write_syslogger_file /home/ioltas/git/postgres/src/backend/postmaster/syslogger.c:1118
#1 0x000001aa353a in send_message_to_server_log /home/ioltas/git/postgres/src/backend/utils/error/elog.c:3889
#2 0x000001a9a3ce in EmitErrorReport /home/ioltas/git/postgres/src/backend/utils/error/elog.c:1924
#3 0x000001a93b8b in errfinish /home/ioltas/git/postgres/src/backend/utils/error/elog.c:555
#4 0x0000015ed3d7 in pgstat_register_kind /home/ioltas/git/postgres/src/backend/utils/activity/pgstat.c:1574
#5 0x7ffff7fb3bcf in _PG_init /home/ioltas/git/postgres/src/test/modules/test_custom_stats/test_custom_fixed_stats.c:80
#6 0x000001aa6fd5 in internal_load_library /home/ioltas/git/postgres/src/backend/utils/fmgr/dfmgr.c:299
#7 0x000001aa653e in load_file /home/ioltas/git/postgres/src/backend/utils/fmgr/dfmgr.c:161
#8 0x000001acbb15 in load_libraries /home/ioltas/git/postgres/src/backend/utils/init/miscinit.c:1838
#9 0x000001acbcb8 in process_shared_preload_libraries /home/ioltas/git/postgres/src/backend/utils/init/miscinit.c:1856
#10 0x0000012a907b in SubPostmasterMain /home/ioltas/git/postgres/src/backend/postmaster/launch_backend.c:678

Looking at a backtrace:
#1 0x00000000012b934d in write_syslogger_file ( buffer=0x2fba5d0
"2026-05-25 16:21:58.516 JST syslogger[465718]: [1-1]
db=,user=,app=,client= LOG: registered custom cumulative statistics
\"test_custom_fixed_stats\" with ID 26\n", count=159, destination=1)
at syslogger.c:1118 1118 rc = fwrite(buffer, 1, count, logfile);
(gdb) p logfile
$1 = (FILE *) 0x0

It is pretty clear that we have the idea to log an entry through the
syslogger but it is too early to do so and its file is not opened, so
my bet is that something in the startup logic has changed.

I did not take the cycles necessary for a bisect, but it looks like
this has been around for a few months at least. I have pinged
f3c9e341cdf1 as a safe startup point for now, so that's a 2026 issue.

Does this ring a bell to somebody?
--
Michael

#2Michael Paquier
michael@paquier.xyz
In reply to: Michael Paquier (#1)
Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup

On Mon, May 25, 2026 at 04:45:41PM +0900, Michael Paquier wrote:

I did not take the cycles necessary for a bisect, but it looks like
this has been around for a few months at least. I have pinged
f3c9e341cdf1 as a safe startup point for now, so that's a 2026 issue.

Well, well:
0c8e082fba8d36434552d3d7800abda54acafd57 is the first bad commit
committer: Álvaro Herrera <alvherre@kurilemu.de>
date: Wed, 4 Feb 2026 16:56:57 +0100
Assign "backend" type earlier during process start-up

I have also checked manually a revert of this commit, and saw that the
problem is gone, so it does not look like I have messed up my bisect.

Alvaro?
--
Michael

#3Ayush Tiwari
ayushtiwari.slg01@gmail.com
In reply to: Michael Paquier (#2)
Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup

Hi,

On Mon, 25 May 2026 at 13:52, Michael Paquier <michael@paquier.xyz> wrote:

On Mon, May 25, 2026 at 04:45:41PM +0900, Michael Paquier wrote:

I did not take the cycles necessary for a bisect, but it looks like
this has been around for a few months at least. I have pinged
f3c9e341cdf1 as a safe startup point for now, so that's a 2026 issue.

Well, well:
0c8e082fba8d36434552d3d7800abda54acafd57 is the first bad commit
committer: Álvaro Herrera <alvherre@kurilemu.de>
date: Wed, 4 Feb 2026 16:56:57 +0100
Assign "backend" type earlier during process start-up

I have also checked manually a revert of this commit, and saw that the
problem is gone, so it does not look like I have messed up my bisect.

I was doing a Binary search to look for commits around those paths.

I also checked 0c8e082fba8 directly: its parent starts clean with the
same setup, while 0c8e082fba8 reports the NULL pointer passed to fwrite().

So this looks to be caused by 0c8e082fba8. After that commit, the
syslogger
child sets MyBackendType = B_LOGGER in SubPostmasterMain(), before
process_shared_preload_libraries(). A message emitted from _PG_init() then
takes the direct write_syslogger_file() path, but the syslogger FILE handles
are not reopened until later in SysLoggerMain().

So I think the bad assumption is that MyBackendType == B_LOGGER means
write_syslogger_file() is ready to use. A fix probably needs to make the
direct syslogger-file path conditional on the FILE handles being ready, and
that should cover stderr, CSV and JSON paths.

Regards,
Ayush