stanza-create: ERROR: [031]: invalid option '--exec-id=...'

[natanmedeiros]

Attention, PostgreSQL IP, stanza name and pgbackrest URL were changed to anonymize my info.

pgBackRest version: 2.37 and 2.38

PostgreSQL version: 14.1

Operating system/version - if you have more than one server (for example, a database server, a repository host server, one or more standbys), please specify each: Postgresql server with debian 11, pgbackrest server with debian 11, pgbackrest server with docker using debian bullseye

Did you install pgBackRest from source or from a package? Source

- pgbackrest.conf

[global]
repo-path=/var/lib/pgbackrest
process-max=2
archive-async=y
archive-push-queue-max=1GB
spool-path=/var/spool/pgbackrest
archive-timeout=180
[cliente]
pg1-host=X.X.X.X
pg1-host-port=2233
pg1-path=/var/lib/postgresql/data
pg1-port=5432
repo1-retention-full=1

- postgresql.conf

archive_command = 'pgbackrest --stanza=cliente archive-push %p'
archive_mode = on
listen_addresses = '*'
max_wal_senders = 3
wal_level = replica
port = 5432
hot_standby = on

- postgresql log

DETAIL: The failed archive command was: pgbackrest --stanza=cliente archive-push pg_wal/000000010000000000000001
ERROR: [103]: unable to find a valid repository:
repo1: [FileMissingError] unable to load info file '/var/lib/pgbackrest/archive/cliente/archive.info' or '/var/lib/pgbackrest/archive/cliente/archive.info.copy':
FileMissingError: raised from remote-0 ssh protocol on 'backup237.empresa.com.br': unable to open missing file '/var/lib/pgbackrest/archive/cliente/archive.info' for read
FileMissingError: raised from remote-0 ssh protocol on 'backup237.empresa.com.br': unable to open missing file '/var/lib/pgbackrest/archive/cliente/archive.info.copy' for read
HINT: archive.info cannot be opened but is required to push/get WAL segments.
HINT: is archive_command configured correctly in postgresql.conf?
HINT: has a stanza-create been performed?
HINT: use --no-archive-check to disable archive checks during backup if youhave an alternate archiving scheme.

- pgbackrest log

-------------------PROCESS START-------------------
2022-03-09 17:25:14.076 P00 INFO: stanza-create command begin 2.38: --exec-id=23-f9c9918a --log-level-console=info --pg1-host=X.X.X.X --pg1-host-port=2233 --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --repo1-path=/var/lib/pgbackrest --stanza=cliente
2022-03-09 17:25:17.428 P00 WARN: unable to check pg1: [OptionInvalidError] remote-0 process on 'X.X.X.X' terminated unexpectedly [31]: ERROR: [031]: invalid option '--exec-id=23-f9c9918a'
2022-03-09 17:25:17.428 P00 ERROR: [056]: unable to find primary cluster - cannot proceed
2022-03-09 17:25:17.429 P00 INFO: stanza-create command end: aborted with exception [056]

Describe the issue:

I use an old pgbackrest server to backup my clients, by its not compatible with PostgreSQL 14, so I am build a new server and already tried pgbackrest 2.37 and 2.38, every stanza-create returns invalid option exec-id, even when I dont use it.

Pgbackrest debug log of stanza-create

pgbackrest --stanza="cliente" --log-level-console="debug" stanza-create

2022-03-09 17:36:08.671 P00 DEBUG: common/io/socket/common::sckInit: (block: false, keepAlive: true, tcpKeepAliveCount: 0, tcpKeepAliveIdle: 0, tcpKeepAliveInterval: 0)
2022-03-09 17:36:08.671 P00 DEBUG: common/io/socket/common::sckInit: => void
2022-03-09 17:36:08.671 P00 INFO: stanza-create command begin 2.38: --exec-id=118440-d304760f --log-level-console=debug --pg1-host=X.X.X.X --pg1-host-port=2233 --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --repo1-path=/var/lib/pgbackrest --stanza=cliente
2022-03-09 17:36:08.672 P00 DEBUG: common/lock::lockAcquire: (lockPath: {"/tmp/pgbackrest"}, stanza: {"cliente"}, execId: {"118440-d304760f"}, lockType:2, lockTimeout: 0, failOnNoLock: true)
2022-03-09 17:36:08.672 P00 DEBUG: common/lock::lockAcquire: => true
2022-03-09 17:36:08.672 P00 DEBUG: config/load::cfgLoad: => void
2022-03-09 17:36:08.672 P00 DEBUG: command/stanza/create::cmdStanzaCreate: (void)
2022-03-09 17:36:08.672 P00 DEBUG: command/control/common::lockStopTest: (void)
2022-03-09 17:36:08.672 P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"/tmp/pgbackrest/cliente.stop"}, param.timeout: 0)
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageInfo: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"/tmp/pgbackrest/cliente.stop"}, param.level: 3, param.ignoreMissing: true, param.followLink: true, param.noPathEnforce: false)
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageInfo: => {StorageInfo}
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageExists: => false
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageExists: (this: {type: posix, path: {"/"}, write: false}, pathExp: {"/tmp/pgbackrest/all.stop"}, param.timeout: 0)
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageInfo: (this: {type: posix, path: {"/"}, write: false}, fileExp: {"/tmp/pgbackrest/all.stop"}, param.level: 3, param.ignoreMissing: true, param.followLink: true, param.noPathEnforce: false)
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageInfo: => {StorageInfo}
2022-03-09 17:36:08.673 P00 DEBUG: storage/storage::storageExists: => false
2022-03-09 17:36:08.673 P00 DEBUG: command/control/common::lockStopTest: => void
2022-03-09 17:36:08.673 P00 DEBUG: db/helper::dbGet: (primaryOnly: false, primaryRequired: true, standbyRequired: false)
2022-03-09 17:36:08.673 P00 DEBUG: db/helper::dbGetIdx: (pgIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::pgIsLocal: (pgIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::pgIsLocal: => false
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::pgIsLocal: (pgIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::pgIsLocal: => false
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::protocolRemoteGet: (protocolStorageType: pg, hostIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::protocolRemoteParamSsh: (protocolStorageType: pg, hostIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::protocolRemoteParam: (protocolStorageType: pg, hostIdx: 0)
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::protocolRemoteParam: => {["--exec-id=118440-d304760f", "--log-level-console=off", "--log-level-file=off", "--log-level-stderr=error", "--pg1-path=/var/lib/postgresql/data", "--pg1-port=5432", "--process=0", "--remote-type=pg", "--stanza=cliente", "stanza-create:remote"]}
2022-03-09 17:36:08.673 P00 DEBUG: protocol/helper::protocolRemoteParamSsh: => {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "-p", "2233", "postgres@X.X.X.X", "pgbackrest --exec-id=118440-d304760f --log-level-console=off --log-level-file=off --log-level-stderr=error --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --process=0 --remote-type=pg --stanza=cliente stanza-create:remote"]}
2022-03-09 17:36:08.673 P00 DEBUG: common/exec::execNew: (command: {"ssh"}, param: {["-o", "LogLevel=error", "-o", "Compression=no", "-o", "PasswordAuthentication=no", "-p", "2233", "postgres@X.X.X.X", "pgbackrest --exec-id=118440-d304760f --log-level-console=off --log-level-file=off --log-level-stderr=error --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --process=0 --remote-type=pg --stanza=cliente stanza-create:remote"]}, name: {"remote-0 process on 'X.X.X.X'"}, timeout: 1830000)
2022-03-09 17:36:08.673 P00 DEBUG: common/exec::execNew: => {Exec}
2022-03-09 17:36:08.673 P00 DEBUG: common/exec::execOpen: (this: {Exec})
2022-03-09 17:36:08.675 P00 DEBUG: common/exec::execOpen: => void
WARN: unable to check pg1: [OptionInvalidError] remote-0 process on 'X.X.X.X' terminated unexpectedly [31]: ERROR: [031]: invalid option '--exec-id=118440-d304760f'
2022-03-09 17:36:09.361 P00 DEBUG: common/exit::exitSafe: (result: 0, error: true, signalType: 0)
ERROR: [056]: unable to find primary cluster - cannot proceed
2022-03-09 17:36:09.362 P00 INFO: stanza-create command end: aborted with exception [056]
2022-03-09 17:36:09.362 P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false)
2022-03-09 17:36:09.362 P00 DEBUG: common/lock::lockRelease: => true
2022-03-09 17:36:09.362 P00 DEBUG: common/exit::exitSafe: => 56
2022-03-09 17:36:09.362 P00 DEBUG: main::main: => 56

[dwsteele]

The version of pgBackRest must match on all server. It looks like you have an older version on pg1-host. If it does not recognize exec-id then it must be pretty old.

[natanmedeiros]

I'm very thankful for your answer!

Occurs that I'm using the same version and install procedure, I've tried both 2.37 and 2.38 from source code, and today I tried installing from PostgreSQL Debian repository in both sides using 2.37, but that error keep avoiding me to create my stanza.

There is any additional information that I can send you?

[natanmedeiros]

Please, let me send you more information.

I know that the stanza-create is executed in pgbackrest server, anyway I've tried to execute debug command that pgbackrest server showed me at the pg1-host to see what is its output.

pgbackrest --exec-id=30-701a6536 --log-level-console=debug --log-level-file=off --log-level-stderr=error --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --process=0 --remote-type=pg --stanza=cliente stanza-create:remote

And the output was:

2022-03-10 09:27:35.125 P00 DEBUG: common/io/socket/common::sckInit: (block: false, keepAlive: true, tcpKeepAliveCount: 0, tcpKeepAliveIdle: 0, tcpKeepAliveInterval: 0)
2022-03-10 09:27:35.125 P00 DEBUG: common/io/socket/common::sckInit: => void
2022-03-10 09:27:35.125 P00 INFO: stanza-create:remote command begin 2.37: --exec-id=30-701a6536 --log-level-console=debug --log-level-file=off --log-level-stderr=error --pg1-path=/var/lib/postgresql/data --pg1-port=5432 --process=0 --remote-type=pg --stanza=cliente
2022-03-10 09:27:35.125 P00 DEBUG: config/load::cfgLoad: => void
{"name":"pgBackRest","service":"remote","version":"2.37"}
2022-03-10 09:27:35.126 P00 DEBUG: command/remote/remote::cmdRemote: (void)

8:xinvalid tag typexcommon/type/pack.c:pckReadTagNext:556:(test build required for parameters)
... function(s) omitted ...
protocol/server.c:protocolServerCommandGet:(trace log level required for parameters)
command/remote/remote.c:cmdRemote:(void)
main.c:main:(debug log level required for parameters)2022-03-10 09:27:37.029 P00 DEBUG: command/remote/remote::cmdRemote: => void
2022-03-10 09:27:37.029 P00 DEBUG: common/exit::exitSafe: (result: 0, error: false, signalType: 0)
2022-03-10 09:27:37.029 P00 INFO: stanza-create:remote command end: completed successfully (1905ms)
2022-03-10 09:27:37.029 P00 DEBUG: common/lock::lockRelease: (failOnNoLock: false)
2022-03-10 09:27:37.029 P00 DEBUG: common/lock::lockRelease: => false
2022-03-10 09:27:37.029 P00 DEBUG: common/exit::exitSafe: => 0
2022-03-10 09:27:37.029 P00 DEBUG: main::main: => 0

There is not exec-id error when I do that, so I think that is something at server.

Next is my Dockerfile of pgbackrest server that I'm trying to make it run ok and is where I catch logs that I sent you.

[dwsteele]

8:xinvalid tag typexcommon/type/pack.c:pckReadTagNext:556:(test build required for parameters)

Well, it expects to be able to start a protocol session but it can't do that because of the way you started it.

The only time I have seen invalid option '--exec-id=23-f9c9918a' is when the server is running an older version. Are you sure you are connecting to the correct server?

[natanmedeiros]

Thank you for your time again.

At left is my PostgreSQL client and at right is my new pgbackrest server.

I'm going to continue my search for a solution and if I found something, I will put here.

[natanmedeiros]

Please, look that, even when I try with --no-online option the error occurs.

[dwsteele]

--no-online doesn't prevent it from contacting the remote server. It just means PostgreSQL does not need to be running.

What does this return from your repo host:

ssh postgres@186.251.8.2 pgbackrest version