BUG #14839: failed archive log messages are merged as 1 message

From: evan(dot)r(dot)rempel(at)gmail(dot)com
To: pgsql-bugs(at)postgresql(dot)org
Cc: evan(dot)r(dot)rempel(at)gmail(dot)com
Subject: BUG #14839: failed archive log messages are merged as 1 message
Date: 2017-09-30 22:44:44
Message-ID: 20170930224444.28566.27031@wrigleys.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 14839
Logged by: Evan Rempel
Email address: evan(dot)r(dot)rempel(at)gmail(dot)com
PostgreSQL version: 9.6.5
Operating system: Redhat EL6.9
Description:

A description of what you are trying to achieve and what results you
expect.:

Just letting the server run with a failing archive command. The messages
logged by the postgresql process get merged together.

PostgreSQL version number you are running:

9.6.5

How you installed PostgreSQL:

Installed from pgdb RPM repository.

Changes made to the settings in the postgresql.conf file: see Server
Configuration for a quick way to list them all.

max_connections = 500 # (change requires restart)
listen_addresses = '*,localhost' # what IP address(es) to listen on;
shared_buffers = '3996MB'
work_mem = '8MB'
wal_level = replica # minimal, replica, or logical
max_wal_size = 10GB
min_wal_size = 80MB
archive_mode = on # enables archiving; off, on, or always
archive_command =
'/home1l/postgres/UVIC/common/scripts/postgres/pg_backup.sh PGPOOL2
walBackup "%p"'
log_destination = 'syslog'
syslog_facility = 'LOCAL0'
syslog_ident = 'postgres'
syslog_sequence_numbers = on
syslog_split_messages = off
client_min_messages = log
log_min_messages = info
log_min_error_statement = info
log_min_duration_statement = 10000
log_checkpoints = on
log_connections = on
log_disconnections = on
log_line_prefix = 'PGPOOL2:%d:%u:%h ' # special
values:
cluster_name = 'PGPOOL2'

Operating system and version:

Redhat EL6.9
Linux myhost 2.6.32-696.el6.x86_64 #1 SMP Tue Feb 21 00:53:17 EST 2017
x86_64 x86_64 x86_64 GNU/Linux

What program you're using to connect to PostgreSQL:

No program connecting. Strictly a PostgreSQL server bug.

Is there anything relevant or unusual in the PostgreSQL server logs?:

Server syslog is the bug and shows:

2017-09-28T08:59:48.097 myhostname local0.err postgres[33550]: [5]
PGPOOL2::: FATAL: archive command was terminated by signal 9: Killed
PGPOOL2::: DETAIL: The failed archive command was:
/home1l/postgres/UVIC/common/scripts/postgres/pg_backup.sh PGPOOL2 walBackup
"pg_xlog/000000010000000000000001"


For questions about any kind of error:

no questions

What you were doing when the error happened / how to cause the error:

A misconfigured archive command.

The EXACT TEXT of the error message you're getting, if there is one: (Copy
and paste the message to the email, do not send a screenshot)

The bug I am reporting is that the logged messages includes two messages.
The above log message should have been logged as:

2017-09-28T08:59:48.097 myhostname local0.err postgres[33550]: [5]
PGPOOL2::: FATAL: archive command was terminated by signal 9: Killed

2017-09-28T08:59:48.097 myhostname local0.err postgres[33550]: [6]
PGPOOL2::: DETAIL: The failed archive command was:
/home1l/postgres/UVIC/common/scripts/postgres/pg_backup.sh PGPOOL2 walBackup
"pg_xlog/000000010000000000000001"

Browse pgsql-bugs by date

  From Date Subject
Next Message Tomas Vondra 2017-10-01 22:03:29 Re: Query planner skipping index depending on DISTINCT parameter order (2)
Previous Message Tom Lane 2017-09-30 18:16:50 Re: bug report