public inbox for [email protected]help / color / mirror / Atom feed
NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup 8+ messages / 4 participants [nested] [flat]
* NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-25 07:45 Michael Paquier <[email protected]> 0 siblings, 1 reply; 8+ messages in thread From: Michael Paquier @ 2026-05-25 07:45 UTC (permalink / raw) To: Postgres hackers <[email protected]> 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 Attachments: [application/pgp-signature] signature.asc (833B, 2-signature.asc) download ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-25 08:21 Michael Paquier <[email protected]> parent: Michael Paquier <[email protected]> 0 siblings, 2 replies; 8+ messages in thread From: Michael Paquier @ 2026-05-25 08:21 UTC (permalink / raw) To: Postgres hackers <[email protected]> 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 <[email protected]> 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 Attachments: [application/pgp-signature] signature.asc (833B, 2-signature.asc) download ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-25 08:24 Ayush Tiwari <[email protected]> parent: Michael Paquier <[email protected]> 1 sibling, 1 reply; 8+ messages in thread From: Ayush Tiwari @ 2026-05-25 08:24 UTC (permalink / raw) To: Michael Paquier <[email protected]>; +Cc: Postgres hackers <[email protected]> Hi, On Mon, 25 May 2026 at 13:52, Michael Paquier <[email protected]> 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 <[email protected]> > 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 ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-25 23:06 Michael Paquier <[email protected]> parent: Ayush Tiwari <[email protected]> 0 siblings, 0 replies; 8+ messages in thread From: Michael Paquier @ 2026-05-25 23:06 UTC (permalink / raw) To: Ayush Tiwari <[email protected]>; +Cc: Postgres hackers <[email protected]>; Alvaro Herrera <[email protected]> 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 Attachments: [application/pgp-signature] signature.asc (833B, 2-signature.asc) download ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-26 02:39 Euler Taveira <[email protected]> parent: Michael Paquier <[email protected]> 1 sibling, 1 reply; 8+ messages in thread From: Euler Taveira @ 2026-05-26 02:39 UTC (permalink / raw) To: Michael Paquier <[email protected]>; Postgres hackers <[email protected]>; +Cc: Álvaro Herrera <[email protected]> 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 <[email protected]> > 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. > 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/ ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-26 05:20 Michael Paquier <[email protected]> parent: Euler Taveira <[email protected]> 0 siblings, 1 reply; 8+ messages in thread From: Michael Paquier @ 2026-05-26 05:20 UTC (permalink / raw) To: Euler Taveira <[email protected]>; +Cc: Postgres hackers <[email protected]>; Álvaro Herrera <[email protected]> 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 Attachments: [application/pgp-signature] signature.asc (833B, 2-signature.asc) download ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-26 05:39 Kyotaro Horiguchi <[email protected]> parent: Michael Paquier <[email protected]> 0 siblings, 1 reply; 8+ messages in thread From: Kyotaro Horiguchi @ 2026-05-26 05:39 UTC (permalink / raw) To: [email protected]; +Cc: [email protected]; [email protected]; [email protected] At Tue, 26 May 2026 14:20:52 +0900, Michael Paquier <[email protected]> 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 ^ permalink raw reply [nested|flat] 8+ messages in thread
* Re: NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup @ 2026-05-26 05:52 Michael Paquier <[email protected]> parent: Kyotaro Horiguchi <[email protected]> 0 siblings, 0 replies; 8+ messages in thread From: Michael Paquier @ 2026-05-26 05:52 UTC (permalink / raw) To: Kyotaro Horiguchi <[email protected]>; +Cc: [email protected]; [email protected]; [email protected] 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 Attachments: [application/pgp-signature] signature.asc (833B, 2-signature.asc) download ^ permalink raw reply [nested|flat] 8+ messages in thread
end of thread, other threads:[~2026-05-26 05:52 UTC | newest] Thread overview: 8+ messages (download: mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2026-05-25 07:45 NULL pointer dereference in syslogger with load_libraries() and -DEXEC_BACKEND at startup Michael Paquier <[email protected]> 2026-05-25 08:21 ` Michael Paquier <[email protected]> 2026-05-25 08:24 ` Ayush Tiwari <[email protected]> 2026-05-25 23:06 ` Michael Paquier <[email protected]> 2026-05-26 02:39 ` Euler Taveira <[email protected]> 2026-05-26 05:20 ` Michael Paquier <[email protected]> 2026-05-26 05:39 ` Kyotaro Horiguchi <[email protected]> 2026-05-26 05:52 ` Michael Paquier <[email protected]>
This inbox is served by agora; see mirroring instructions for how to clone and mirror all data and code used for this inbox