BUG #18400: logging_collector does not collect messages from postmaster

The following bug has been logged on the website:

Bug reference: 18400
Logged by: George Tarasov
Email address: george(dot)v(dot)tarasov(at)gmail(dot)com
PostgreSQL version: 15.6
Operating system: Windows Server 2019 Datacenter Edition
Description:

Hello!

I found a problem with the logging in the last builds for windows (EDB
builds, available from the main download page:
https://www.postgresql.org/download/windows/)

After default installation (no options were changed, no warnings/errors in
installation log:
C:\Users\Administrator\AppData\Local\Temp\install-postgresql.log) i don't
see messages in Postgres log file from postmaster.

For example, this is the content of the log file after manual restart
installed postgresql service (note: i added only %b to the log_line_prefix
to distinguish backends)

current log file: C:\Program
Files\PostgreSQL\15\data\log\postgresql-2024-03-19_144256.log
2024-03-19 14:42:56.329 GMT [1512 startup] LOG: database system was shut
down at 2024-03-19 14:42:26 GMT

yet another manul service restart (i show ALL messages in the file)

previous log file: C:\Program
Files\PostgreSQL\15\data\log\postgresql-2024-03-19_144256.log
2024-03-19 14:42:56.329 GMT [1512 startup] LOG: database system was shut
down at 2024-03-19 14:42:26 GMT
2024-03-19 14:46:23.068 GMT [6048 checkpointer] LOG: shutting down
2024-03-19 14:46:23.072 GMT [6048 checkpointer] LOG: checkpoint starting:
shutdown immediate
2024-03-19 14:46:23.085 GMT [6048 checkpointer] LOG: checkpoint complete:
wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.005 s, sync=0.002 s, total=0.016 s; sync files=2, longest=0.001 s,
average=0.001 s; distance=0 kB, estimate=0 kB

current log file: C:\Program
Files\PostgreSQL\15\data\log\postgresql-2024-03-19_144624.log
2024-03-19 14:46:24.586 GMT [4796 startup] LOG: database system was shut
down at 2024-03-19 14:46:23 GMT

after shutdown service

current log file: C:\Program
Files\PostgreSQL\15\data\log\postgresql-2024-03-19_144624.log
2024-03-19 14:46:24.586 GMT [4796 startup] LOG: database system was shut
down at 2024-03-19 14:46:23 GMT
2024-03-19 14:50:22.221 GMT [2620 checkpointer] LOG: shutting down
2024-03-19 14:50:22.222 GMT [2620 checkpointer] LOG: checkpoint starting:
shutdown immediate
2024-03-19 14:50:22.232 GMT [2620 checkpointer] LOG: checkpoint complete:
wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.003 s, sync=0.003 s, total=0.011 s; sync files=2, longest=0.002 s,
average=0.002 s; distance=0 kB, estimate=0 kB

Obviously these are not 'all messages' that should be. No messages from
postmaster.

Logging options from my installation.

postgres# select name, setting from pg_settings where category like
'Reporting%';

name | setting
-----------------------------------+--------------------------------
application_name | psql
cluster_name |
debug_pretty_print | on
debug_print_parse | off
debug_print_plan | off
debug_print_rewritten | off
event_source | PostgreSQL
log_autovacuum_min_duration | 600000
log_checkpoints | on
log_connections | off
log_destination | stderr
log_directory | log
log_disconnections | off
log_duration | off
log_error_verbosity | default
log_file_mode | 0640
log_filename | postgresql-%Y-%m-%d_%H%M%S.log
log_hostname | off
log_line_prefix | %m [%p %b]
log_lock_waits | off
log_min_duration_sample | -1
log_min_duration_statement | -1
log_min_error_statement | error
log_min_messages | warning
log_parameter_max_length | -1
log_parameter_max_length_on_error | 0
log_recovery_conflict_waits | off
log_replication_commands | off
log_rotation_age | 1440
log_rotation_size | 10240
log_startup_progress_interval | 10000
log_statement | none
log_statement_sample_rate | 1
log_temp_files | -1
log_timezone | GMT
log_transaction_sample_rate | 0
log_truncate_on_rotation | off
logging_collector | on
syslog_facility | none
syslog_ident | postgres
syslog_sequence_numbers | on
syslog_split_messages | on
update_process_title | off
(43 rows)

Repro steps:
1. download 15.6 postgres windows installer from
https://www.postgresql.org/download/windows
2. run installer under default Administrator account. Don't change any
options (except superuser password). No warnings/errors during
installation.
3. check that logging_collector default is 'on' after installation, and
Postgres service is started.
4. check current log file in the default log directory (C:\Program
Files\PostgreSQL\15\data\log)

Expected: message from postmaster are in the current log file
Actual: no messages from postmaster

Other information:
I also noticed the following behaviour.
1) if disable logging_collector, all messages are correctly put into the
Windows log (includeing from postmaster)
2) if shutdown postgres service, and try manually initialize and start
Postgres through the pg_ctl with logging_collector=on, then everything is
ok. All messages are in the current log file.

> pg_ctl.exe init -D "C:\pgdata"
> ... copy postgresql.conf from the main installation to the pgdata
> pg_ctl.exe -D C:/pgdata -l C:/pgdata/logfile start
waiting for server to start.... done
server started

current log file: C:\pgdata\log\postgresql-2024-03-19_150958.log
2024-03-19 15:09:58.480 GMT [5560 postmaster] LOG: starting PostgreSQL
15.6, compiled by Visual C++ build 1937, 64-bit
2024-03-19 15:09:58.481 GMT [5560 postmaster] LOG: listening on IPv6
address "::", port 5432
2024-03-19 15:09:58.481 GMT [5560 postmaster] LOG: listening on IPv4
address "0.0.0.0", port 5432
2024-03-19 15:09:58.549 GMT [1484 startup] LOG: database system was shut
down at 2024-03-19 15:07:47 GMT
2024-03-19 15:09:58.568 GMT [5560 postmaster] LOG: database system is ready
to accept connections

> pg_ctl.exe -D C:/pgdata -l C:/pgdata/logfile stop
waiting for server to shut down.... done
server stopped

current log file: C:\pgdata\log\postgresql-2024-03-19_150958.log
2024-03-19 15:09:58.480 GMT [5560 postmaster] LOG: starting PostgreSQL
15.6, compiled by Visual C++ build 1937, 64-bit
2024-03-19 15:09:58.481 GMT [5560 postmaster] LOG: listening on IPv6
address "::", port 5432
2024-03-19 15:09:58.481 GMT [5560 postmaster] LOG: listening on IPv4
address "0.0.0.0", port 5432
2024-03-19 15:09:58.549 GMT [1484 startup] LOG: database system was shut
down at 2024-03-19 15:07:47 GMT
2024-03-19 15:09:58.568 GMT [5560 postmaster] LOG: database system is ready
to accept connections
2024-03-19 15:11:50.255 GMT [5560 postmaster] LOG: received fast shutdown
request
2024-03-19 15:11:50.256 GMT [5560 postmaster] LOG: aborting any active
transactions
2024-03-19 15:11:50.267 GMT [5560 postmaster] LOG: background worker
"logical replication launcher" (PID 6008) exited with exit code 1
2024-03-19 15:11:50.269 GMT [1064 checkpointer] LOG: shutting down
2024-03-19 15:11:50.271 GMT [1064 checkpointer] LOG: checkpoint starting:
shutdown immediate
2024-03-19 15:11:50.284 GMT [1064 checkpointer] LOG: checkpoint complete:
wrote 41 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled;
write=0.003 s, sync=0.007 s, total=0.015 s; sync files=11, longest=0.002 s,
average=0.001 s; distance=229 kB, estimate=229 kB
2024-03-19 15:11:50.292 GMT [5560 postmaster] LOG: database system is shut
down

I see that syslogger can't communicate with postmaster (or postmaster with
the logger) when postgres is started as a windows service.
But i can't explain this behaviour and can't suppose why it happens. May be
my windows installation is wrong?! No ideas!
The same on version 16.2.

Thanks,
George Tarasov