NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup
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
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
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-upI 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
On Mon, May 25, 2026 at 01:54:28PM +0530, Ayush Tiwari wrote:
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.
I am not sure. We are attempting to write to the syslogger file but
we should not do so yet. This code path should not be taken and
properly redirected to stderr, we should not use a shortcut based on
the FILE existing or not.
I have forgotten to add Alvaro in CC yesterday, done now.
--
Michael
On Mon, May 25, 2026, at 5:21 AM, Michael Paquier 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-upI 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.
It seems I was too optimistic about this patch. Since the commit 0c8e082fba8
sets MyBackendType to B_LOGGER earlier, it breaks the following assumption in
syslogger.c.
/*
* If we're told to write to a structured log file, but it's not open,
* dump the data to syslogFile (which is always open) instead. This can
* happen if structured output is enabled after postmaster start and we've
* been unable to open logFile. There are also race conditions during a
* parameter change whereby backends might send us structured output
* before we open the logFile or after we close it. Writing formatted
* output to the regular log file isn't great, but it beats dropping log
* output on the floor.
It shouldn't assume syslogFile is always open. The send_message_to_server_log()
shouldn't be executing the following code path in this case.
/* If in the syslogger process, try to write messages direct to file */
if (MyBackendType == B_LOGGER)
write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_STDERR);
It could set MyBackendType only if child_type != B_LOGGER during
launch_backend.c and set it at the same code path as in the past. However, I
consider this solution ugly and hackish.
--
Euler Taveira
EDB https://www.enterprisedb.com/
On Mon, May 25, 2026 at 11:39:54PM -0300, Euler Taveira wrote:
It seems I was too optimistic about this patch. Since the commit 0c8e082fba8
sets MyBackendType to B_LOGGER earlier, it breaks the following assumption in
syslogger.c./*
* If we're told to write to a structured log file, but it's not open,
* dump the data to syslogFile (which is always open) instead. This can
* happen if structured output is enabled after postmaster start and we've
* been unable to open logFile. There are also race conditions during a
* parameter change whereby backends might send us structured output
* before we open the logFile or after we close it. Writing formatted
* output to the regular log file isn't great, but it beats dropping log
* output on the floor.It shouldn't assume syslogFile is always open. The send_message_to_server_log()
shouldn't be executing the following code path in this case.
This comment has been rewritten in 2022 when jsonlog was added in
dc686681e079, but this assumption is much older than that:
bff84a547d71, where the syslogger has been made more robust. And we
assume that the log file is always open, so this change is breaking
an old assumption.
It could set MyBackendType only if child_type != B_LOGGER during
launch_backend.c and set it at the same code path as in the past. However, I
consider this solution ugly and hackish.
While thinking about an approach that could allow to keep
0c8e082fba8d, I was wondering whether we should have a boolean flag
that tracks if the log file is opened or not that gets set (we should
not care about the reset) when we are done with its creation, but I'm
feeling that this makes the logic feeble. We know only rely on
MyBackendType for the job which means to complicate all these checks.
The part that makes me uneasy is that the logging facility should be
robust by design, and simpler is always better IMO.
An exception where we don't set MyBackendType and have an exception
for this corresponding child_type value does not really feel right to
me either.. As a whole, I am not sure to like what has been done
here.
--
Michael
At Tue, 26 May 2026 14:20:52 +0900, Michael Paquier <michael@paquier.xyz> wrote in
While thinking about an approach that could allow to keep
0c8e082fba8d, I was wondering whether we should have a boolean flag
that tracks if the log file is opened or not that gets set (we should
not care about the reset) when we are done with its creation, but I'm
feeling that this makes the logic feeble. We know only rely on
In write_syslogger_file, there's already a fallback path to
write_stderr() when fwrite fails. Would it make sense to treat logfile
== NULL as an error case as well?
MyBackendType for the job which means to complicate all these checks.
The part that makes me uneasy is that the logging facility should be
robust by design, and simpler is always better IMO.An exception where we don't set MyBackendType and have an exception
for this corresponding child_type value does not really feel right to
me either.. As a whole, I am not sure to like what has been done
here.
Agreed.
Regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
On Tue, May 26, 2026 at 02:39:12PM +0900, Kyotaro Horiguchi wrote:
In write_syslogger_file, there's already a fallback path to
write_stderr() when fwrite fails. Would it make sense to treat logfile
== NULL as an error case as well?
It does not make much sense to me. A write failure is based on the
fact that something went wrong in the underlying OS, most likely in
the file system, and that's not something Postgres has any idea about.
This issue is different, it is a Postgres logic bug, so adding an
exception like the one you are suggesting is just a shortcut hiding
the real issue: the log file is not ready yet, but the syslogger is
invoked at a point when it thinks the log file exists.
--
Michael
On 2026-May-26, Michael Paquier wrote:
This issue is different, it is a Postgres logic bug, so adding an
exception like the one you are suggesting is just a shortcut hiding
the real issue: the log file is not ready yet, but the syslogger is
invoked at a point when it thinks the log file exists.
I think we can solve this easily by flipping a new Boolean value at the
same point were MyBackendType was previously set. The attached POC
fixes the scenario you described; can you confirm? It needs some
additional comments, of course.
(There is one more place in elog.c where we check that MyBackendType is
_not_ B_LOGGER, but I think that one is correct as-is; and I'm wondering
if that would behave correctly before 0c8e082fba8d.)
--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
“Cuando no hay humildad las personas se degradan” (A. Christie)
Attachments:
0001-POC-syslogger-add-Boolean-state-indicating-readiness.patchtext/x-diff; charset=utf-8Download+9-4
On Tue, May 26, 2026, at 8:09 AM, Alvaro Herrera wrote:
On 2026-May-26, Michael Paquier wrote:
This issue is different, it is a Postgres logic bug, so adding an
exception like the one you are suggesting is just a shortcut hiding
the real issue: the log file is not ready yet, but the syslogger is
invoked at a point when it thinks the log file exists.I think we can solve this easily by flipping a new Boolean value at the
same point were MyBackendType was previously set. The attached POC
fixes the scenario you described; can you confirm? It needs some
additional comments, of course.
It fixes the issue for me. However, I'm wondering if we can avoid adding a new
boolean for it. We already have redirection_done that guarantees the syslogger
is working properly. Couldn't we use it? (SysLogger_Start() opens the file --
logfile_open -- and a few lines below it sets the redirection_done. If we adopt
this approach, a comment should be added to avoid breaking it in the future.)
(There is one more place in elog.c where we check that MyBackendType is
_not_ B_LOGGER, but I think that one is correct as-is; and I'm wondering
if that would behave correctly before 0c8e082fba8d.)
Yes. The redirection_done guarantees that the file is open.
PS> this patch does not allow writes to syslogger as soon as possible like your
patch but it seems acceptable to me.
--
Euler Taveira
EDB https://www.enterprisedb.com/
Attachments:
0001-syslogger-try-to-write-messages-only-after-setup.patchtext/x-patch; name="=?UTF-8?Q?0001-syslogger-try-to-write-messages-only-after-setup.patch?="Download+5-3
On 2026-May-26, Euler Taveira wrote:
It fixes the issue for me. However, I'm wondering if we can avoid adding a new
boolean for it. We already have redirection_done that guarantees the syslogger
is working properly.
Yeah, that was my first thought as well, but after looking at it, I
thought it may be better not to mess with that, since it was almost
surgical in how it was designed; furthermore, it is written to be
transmitted from postmaster to its children, whereas this new state
variable is local to the syslogger process.
Also, consider the case where you have postmaster running for a while
(so redirection_done has been set already), and for whatever reason
syslogger restarts. Will it inherit the correct value? I don't know (I
think it won't), and it seems error-prone to assume it will work
correctly. I think this would only fail if for whatever reason the
syslogger itself wanted to print an error before setting up the file
descriptors, but I don't think this is impossible: for example, if
postmaster_child_launch() runs into an OOM during internal_forkexec().
Plus, redirection_done means something completely different: it is used
to say that syslogPipe[] has been set up for message chunk transmission.
The new variable indicates that the logging file descriptors for the
various output files (syslogFile etc) have been set up in the syslogger
process.
All in all, I don't think we should cut corners here just to save one
boolean variable.
--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
"No hay ausente sin culpa ni presente sin disculpa" (Prov. francés)
On Tue, May 26, 2026, at 2:21 PM, Álvaro Herrera wrote:
All in all, I don't think we should cut corners here just to save one
boolean variable.
As I said I'm fine with your proposed patch.
--
Euler Taveira
EDB https://www.enterprisedb.com/
On Tue, May 26, 2026 at 09:13:30PM -0300, Euler Taveira wrote:
As I said I'm fine with your proposed patch.
With the patch posted at [1]/messages/by-id/ahV9KzLOqvOw78C3@alvherre.pgsql -- Michael in place, the problem is indeed gone.
My first reaction is that we may want to update the two code paths of
csvlog.c and jsonlog.c with a similar check, switching away from
MyBackendType to your new syslogger_setup_done. That would be more
defensive in the long-term if someone has the idea to refactor or
reshape this code.
It also looks important to me to plant a few comments to document the
purpose of the flag (which is I'm sure something you were going to
do). It is not complicated to see what's the purpose by grepping for
syslogger_setup_done, but it would be less guessing for the reader.
Keeping redirection_done out of this decision-making logic sounds
indeed wiser, the flag serves a different purpose..
As a whole, I'm fine with this idea.
[1]: /messages/by-id/ahV9KzLOqvOw78C3@alvherre.pgsql -- Michael
--
Michael
On 2026-May-27, Michael Paquier wrote:
My first reaction is that we may want to update the two code paths of
csvlog.c and jsonlog.c with a similar check, switching away from
MyBackendType to your new syslogger_setup_done. That would be more
defensive in the long-term if someone has the idea to refactor or
reshape this code.
Right, done, thanks. I tested this by messing with pg_ctl's
004_logrotate.pl; as far as I can tell, it's all working fine.
I did notice that if you have an elog(WARNING) very early in syslogger,
it appears in postmaster's stderr only and not in the log files. I'm
not fussed about this ... as long as nothing crashes, it's fine.
It also looks important to me to plant a few comments to document the
purpose of the flag (which is I'm sure something you were going to
do). It is not complicated to see what's the purpose by grepping for
syslogger_setup_done, but it would be less guessing for the reader.
Yep, done and pushed.
I wondered if the MyBackendType changes could have an effect on
early-startup of other process types, but I couldn't find anything
actionable.
--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
On Mon, Jun 08, 2026 at 08:03:35PM +0200, Alvaro Herrera wrote:
On 2026-May-27, Michael Paquier wrote:
It also looks important to me to plant a few comments to document the
purpose of the flag (which is I'm sure something you were going to
do). It is not complicated to see what's the purpose by grepping for
syslogger_setup_done, but it would be less guessing for the reader.Yep, done and pushed.
Thanks for the fix.
--
Michael