archive_command fails but works outside of Postgres

On Fri, Aug 18, 2017 at 12:40 PM, twoflower <standa.kurik@gmail.com> wrote:

I changed my archive_command to the following:

archive_command = 'gsutil cp /storage/postgresql/9.6/main/%p
gs://my_bucket/pg_xlog/'

and it fails, leaving the following in the log:

2017-08-18 18:34:25.057 GMT [1436][0]: [104319] LOG: archive command failed
with exit code 1
2017-08-18 18:34:25.057 GMT [1436][0]: [104320] DETAIL: The failed archive
command was: gsutil cp
/storage/postgresql/9.6/main/000000010000038B000000D8
gs://my_bucket/pg_xlog/
2017-08-18 18:34:25.057 GMT [1436][0]: [104321] WARNING: archiving
transaction log file "000000010000038B000000D8" failed too many times, will
try again later

But the command works when executed manually:

root$ su postgres -c "gsutil cp
/storage/postgresql/9.6/main/000000010000038B000000D8
gs://my_bucket/pg_xlog/"
root$ echo $?
0

The last command verifies that gsutil indeed exited with 0.

How to best debug this issue?

Sounds like it depends on some envvar it doesn't see when run from the
postmaster. If you sudo -u postgres and run it does it work?

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Scott Marlowe wrote:

On Fri, Aug 18, 2017 at 12:40 PM, twoflower <standa.kurik@gmail.com> wrote:

I changed my archive_command to the following:

archive_command = 'gsutil cp /storage/postgresql/9.6/main/%p
gs://my_bucket/pg_xlog/'

2017-08-18 18:34:25.057 GMT [1436][0]: [104321] WARNING: archiving
transaction log file "000000010000038B000000D8" failed too many times, will
try again later

Sounds like it depends on some envvar it doesn't see when run from the
postmaster. If you sudo -u postgres and run it does it work?

I saw one installation with "gsutil cp" in archive_command recently. It
had the CLOUDSDK_PYTHON environment variable set in the archive_command
itself. Maybe that's a problem.

Another possible problem might be the lack of %f (this command seems to
rely on the file being the same name at the other end, which isn't
necessarily so) and the fact that %p is supposed to be the path of the
file, so you shouldn't qualify it with the full path.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

De : pgsql-general-owner@postgresql.org [mailto:pgsql-general-owner@postgresql.org] De la part de twoflower
Envoyé : Friday, August 18, 2017 2:40 PM
À : pgsql-general@postgresql.org
Objet : [GENERAL] archive_command fails but works outside of Postgres

I changed my archive_command to the following:

archive_command = 'gsutil cp /storage/postgresql/9.6/main/%p gs://my_bucket/pg_xlog/'
and it fails, leaving the following in the log:

2017-08-18 18:34:25.057 GMT [1436][0]: [104319] LOG: archive command failed with exit code 1

2017-08-18 18:34:25.057 GMT [1436][0]: [104320] DETAIL: The failed archive command was: gsutil cp /storage/postgresql/9.6/main/000000010000038B000000D8 gs://my_bucket/pg_xlog/

2017-08-18 18:34:25.057 GMT [1436][0]: [104321] WARNING: archiving transaction log file "000000010000038B000000D8" failed too many times, will try again later

But the command works when executed manually:

root$ su postgres -c "gsutil cp /storage/postgresql/9.6/main/000000010000038B000000D8 gs://my_bucket/pg_xlog/"

root$ echo $?

0
The last command verifies that gsutil indeed exited with 0.

How to best debug this issue?

I think the parameter %p contains the complete path of the file and that you may need to specify the file name for the destination. Try this for your archive command :
archive_command = 'gsutil cp "%p" "gs://my_bucket/pg_xlog/%f"'

- Mark Watson

Scott Marlowe-2 wrote

Sounds like it depends on some envvar it doesn't see when run from the
postmaster. If you sudo -u postgres and run it does it work?

Yes, I can do <code>su postgres</code>, execute the command and it works.

--
View this message in context: http://www.postgresql-archive.org/archive-command-fails-but-works-outside-of-Postgres-tp5979040p5979059.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Alvaro Herrera-9 wrote

I saw one installation with "gsutil cp" in archive_command recently.
Ithad the CLOUDSDK_PYTHON environment variable set in the
archive_commanditself. Maybe that's a problem.

That's not the case here, I don't have this variable set anywhere where
gsutil works.
Alvaro Herrera-9 wrote

Another possible problem might be the lack of %f (this command seems
torely on the file being the same name at the other end, which
isn'tnecessarily so) and the fact that %p is supposed to be the path of
thefile, so you shouldn't qualify it with the full path.

%p is not the full path, it is relative to the cluster's data directory (as
described in the documentation
<https://www.postgresql.org/docs/9.6/static/continuous-archiving.html#BACKUP-ARCHIVING-WAL&gt;
).Not using %f is not a problem - gsutil is invoked in the following way:
gsutil &lt;full_path&gt; &lt;storage_dir&gt;
Also, as I mentioned, the command works fine when copied verbatim from the
log error message and executed manually.

--
View this message in context: http://www.postgresql-archive.org/archive-command-fails-but-works-outside-of-Postgres-tp5979040p5979060.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

Mark Watson-12 wrote

I think the parameter %p contains the complete path of the file

It does not, see the link to the official documentation above.

--
View this message in context: http://www.postgresql-archive.org/archive-command-fails-but-works-outside-of-Postgres-tp5979040p5979061.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

Alvaro Herrera-9 wrote

I saw one installation with "gsutil cp" in archive_command recently.
Ithad the CLOUDSDK_PYTHON environment variable set in the
archive_commanditself. Maybe that's a problem.

After all, this was the solution:
archive_command = 'CLOUDSDK_PYTHON=/usr/bin/python gsutil cp
/storage/postgresql/9.6/main/pg_xlog/%p gs://my_bucket/'
as also hinted in https://github.com/GoogleCloudPlatform/gsutil/issues/402
<https://github.com/GoogleCloudPlatform/gsutil/issues/402&gt;

I still don't understand why the environments differ (the context of
archive_command vs. "su postgres -" and executing it there) but I am happy
it's working now.Thank you!

--
View this message in context: http://www.postgresql-archive.org/archive-command-fails-but-works-outside-of-Postgres-tp5979040p5979093.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

On Aug 19, 2017, at 04:05, twoflower <standa.kurik@gmail.com> wrote:

Alvaro Herrera-9 wrote
I saw one installation with "gsutil cp" in archive_command recently. It had the CLOUDSDK_PYTHON environment variable set in the archive_command itself. Maybe that's a problem.
After all, this was the solution:
archive_command = 'CLOUDSDK_PYTHON=/usr/bin/python gsutil cp /storage/postgresql/9.6/main/pg_xlog/%p gs://my_bucket/'
as also hinted in https://github.com/GoogleCloudPlatform/gsutil/issues/402

I still don't understand why the environments differ (the context of archive_command vs. "su postgres -" and executing it there) but I am happy it's working now. Thank you!

If postgres is running under systemd, you'll have a wildly different environment than if you just su to postgres.

--Scott