Skip to content

PBM-887: add diagnostic command #1072

PBM-887: add diagnostic command

PBM-887: add diagnostic command #1072

GitHub Actions / JUnit Test Report failed Nov 2, 2024 in 0s

28 tests run, 23 passed, 4 skipped, 1 failed.

Annotations

Check failure on line 69 in psmdb-testing/pbm-functional/pytest/test_azurite.py

See this annotation in the file changed.

@github-actions github-actions / JUnit Test Report

test_azurite.test_logical

AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}

2024-11-02T17:40:07Z I [rs1/rs103:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:07Z I [rs1/rs103:27017] starting PITR routine
2024-11-02T17:40:07Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:07Z I [rs2/rs201:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:07Z I [rs2/rs201:27017] starting PITR routine
2024-11-02T17:40:08Z I [rs1/rs102:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:08Z I [rs1/rs102:27017] starting PITR routine
2024-11-02T17:40:08Z I [rs1/rs103:27017] node: rs1/rs103:27017
2024-11-02T17:40:08Z I [rs1/rs101:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:08Z I [rs1/rs101:27017] starting PITR routine
2024-11-02T17:40:08Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:08Z I [rs1/rs102:27017] node: rs1/rs102:27017
2024-11-02T17:40:08Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:08Z I [rs1/rs101:27017] node: rs1/rs101:27017
2024-11-02T17:40:08Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:08Z I [rs1/rs103:27017] listening for the commands
2024-11-02T17:40:08Z I [rs2/rs201:27017] node: rs2/rs201:27017
2024-11-02T17:40:08Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:08Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:08Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:08Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:08Z I [rs2/rs201:27017] listening for the commands
2024-11-02T17:40:08Z I [rs1/rs102:27017] listening for the commands
2024-11-02T17:40:08Z I [rs1/rs101:27017] listening for the commands
2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] starting PITR routine
2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
2024-11-02T17:40:09Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] starting PITR routine
2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] listening for the commands
2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
2024-11-02T17:40:09Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] listening for the commands
2024-11-02T17:40:09Z I [rs2/rs202:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:09Z I [rs2/rs202:27017] starting PITR routine
2024-11-02T17:40:09Z I [rs2/rs202:27017] node: rs2/rs202:27017
2024-11-02T17:40:09Z I [rs2/rs203:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:09Z I [rs2/rs203:27017] starting PITR routine
2024-11-02T17:40:09Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:09Z I [rs2/rs203:27017] node: rs2/rs203:27017
2024-11-02T17:40:09Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:09Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:09Z I [rs2/rs202:27017] listening for the commands
2024-11-02T17:40:09Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:09Z I [rs2/rs203:27017] listening for the commands
2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] pbm-agent:
Version:   2.7.0
Platform:  linux/amd64
GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
GitBranch: CURRENT_PR
BuildTime: 2024-11-02_16:54_UTC
GoVersion: go1.22.8
2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] starting PITR routine
2024-11-02T17:40:11Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] listening for the commands
2024-11-02T17:40:13Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:13Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:13Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:13Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:14Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:14Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:14Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:14Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:16Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] got epoch {1730569216 2}
2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] [resync] started
2024-11-02T17:40:17Z I [rscfg/rscfg02:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:17Z I [rscfg/rscfg02:27017] got epoch {1730569216 2}
2024-11-02T17:40:17Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 0
2024-11-02T17:40:17Z I [rs2/rs202:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:17Z I [rs2/rs202:27017] got epoch {1730569216 2}
2024-11-02T17:40:17Z I [rs2/rs203:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] epoch set to {1730569217 16}
2024-11-02T17:40:17Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-11-02T17:40:17Z I [rs2/rs203:27017] got epoch {1730569217 16}
2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] [resync] succeed
2024-11-02T17:40:17Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-11-02T17:40:18Z I [rs1/rs103:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:18Z I [rs1/rs103:27017] got epoch {1730569217 16}
2024-11-02T17:40:18Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-11-02T17:40:18Z I [rs2/rs201:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:18Z I [rs1/rs101:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:18Z I [rs1/rs102:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:18Z I [rs2/rs201:27017] got epoch {1730569217 16}
2024-11-02T17:40:18Z I [rs1/rs101:27017] got epoch {1730569217 16}
2024-11-02T17:40:18Z I [rs1/rs102:27017] got epoch {1730569217 16}
2024-11-02T17:40:18Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-11-02T17:40:18Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-11-02T17:40:18Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-11-02T17:40:18Z I [rscfg/rscfg03:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
2024-11-02T17:40:18Z I [rscfg/rscfg03:27017] got epoch {1730569217 16}
2024-11-02T17:40:18Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 67266401246825df5ed0a03b [Resync storage]
2024-11-02T17:40:18Z D [rscfg/rscfg03:27017] [resync] lock not acquired
2024-11-02T17:40:22Z I [rs2/rs202:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:22Z I [rs2/rs202:27017] got epoch {1730569217 16}
2024-11-02T17:40:22Z I [rs2/rs203:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:22Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-11-02T17:40:22Z I [rs2/rs203:27017] got epoch {1730569217 16}
2024-11-02T17:40:22Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-11-02T17:40:23Z I [rs1/rs103:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rs1/rs103:27017] got epoch {1730569217 16}
2024-11-02T17:40:23Z I [rs2/rs201:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rs1/rs102:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rs1/rs101:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-11-02T17:40:23Z I [rs1/rs101:27017] got epoch {1730569217 16}
2024-11-02T17:40:23Z I [rs2/rs201:27017] got epoch {1730569217 16}
2024-11-02T17:40:23Z I [rs1/rs102:27017] got epoch {1730569217 16}
2024-11-02T17:40:23Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-11-02T17:40:23Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-11-02T17:40:23Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-11-02T17:40:23Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
2024-11-02T17:40:23Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
2024-11-02T17:40:23Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
2024-11-02T17:40:23Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] got epoch {1730569217 16}
2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] [resync] started
2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] epoch set to {1730569223 110}
2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] [resync] succeed
2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got epoch {1730569223 110}
2024-11-02T17:40:23Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 67266406fe450ef5ac049f27 [Resync storage]
2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
2024-11-02T17:40:23Z D [rscfg/rscfg01:27017] [resync] lock not acquired
2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got epoch {1730569223 110}
2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got epoch {1730569223 110}
2024-11-02T17:40:23Z E [rscfg/rscfg01:27017] [backup/2024-11-02T17:40:23Z] unable to proceed with the backup, active lock is present
2024-11-02T17:40:23Z D [rscfg/rscfg02:27017] [resync] get lock: duplicate operation: 67266406fe450ef5ac049f27 [Resync storage]
2024-11-02T17:40:23Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got epoch {1730569223 110}
2024-11-02T17:40:23Z I [rs2/rs202:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:23Z I [rs2/rs203:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:23Z I [rs2/rs202:27017] got epoch {1730569223 110}
2024-11-02T17:40:23Z I [rs2/rs203:27017] got epoch {1730569223 110}
2024-11-02T17:40:24Z I [rs1/rs103:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:24Z I [rs1/rs103:27017] got epoch {1730569223 110}
2024-11-02T17:40:24Z I [rs2/rs201:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:24Z I [rs1/rs102:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:24Z I [rs1/rs101:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:24Z I [rs2/rs201:27017] got epoch {1730569223 110}
2024-11-02T17:40:24Z I [rs1/rs101:27017] got epoch {1730569223 110}
2024-11-02T17:40:24Z I [rs1/rs102:27017] got epoch {1730569223 110}
2024-11-02T17:40:24Z I [rscfg/rscfg03:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
2024-11-02T17:40:24Z I [rscfg/rscfg03:27017] got epoch {1730569223 110}
2024-11-02T17:40:38Z D [rscfg/rscfg02:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:38Z D [rscfg/rscfg02:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:38Z D [rs2/rs202:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:38Z D [rs2/rs203:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:38Z D [rs2/rs202:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:38Z D [rs2/rs203:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:39Z D [rs1/rs103:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:39Z D [rs1/rs103:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:39Z D [rs1/rs101:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:39Z D [rs2/rs201:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:39Z D [rs1/rs102:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:39Z D [rs1/rs101:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:39Z D [rs2/rs201:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:39Z D [rs1/rs102:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
2024-11-02T17:40:39Z D [rscfg/rscfg03:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
2024-11-02T17:40:39Z D [rscfg/rscfg03:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
Raw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7fb60cd1f990>

    @pytest.mark.timeout(300, func_only=True)
    def test_logical(start_cluster, cluster):
        cluster.check_pbm_status()
        pymongo.MongoClient(cluster.connection)["test"]["test"].insert_many(documents)
>       backup = cluster.make_backup("logical")

test_azurite.py:69: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <cluster.Cluster object at 0x7fb60cd1f990>, type = 'logical'

    def make_backup(self, type):
        n = testinfra.get_host("docker://" + self.pbm_cli)
        timeout = time.time() + 120
        while True:
            running = self.get_status()['running']
            Cluster.log("Current operation: " + str(running))
            if not running:
                if type:
                    start = n.run(
                        'pbm backup --out=json --type=' + type)
                else:
                    start = n.run('pbm backup --out=json')
                if start.rc == 0:
                    name = json.loads(start.stdout)['name']
                    Cluster.log("Backup started")
                    break
                elif "resync" in start.stdout:
                    Cluster.log("Resync in progress, retrying: " + start.stdout)
                else:
                    logs = n.check_output("pbm logs -sD -t0")
>                   assert False, "Backup failed" + start.stdout + start.stderr + '\n' + logs
E                   AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}
E                   
E                   2024-11-02T17:40:07Z I [rs1/rs103:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:07Z I [rs1/rs103:27017] starting PITR routine
E                   2024-11-02T17:40:07Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:07Z I [rs2/rs201:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:07Z I [rs2/rs201:27017] starting PITR routine
E                   2024-11-02T17:40:08Z I [rs1/rs102:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:08Z I [rs1/rs102:27017] starting PITR routine
E                   2024-11-02T17:40:08Z I [rs1/rs103:27017] node: rs1/rs103:27017
E                   2024-11-02T17:40:08Z I [rs1/rs101:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:08Z I [rs1/rs101:27017] starting PITR routine
E                   2024-11-02T17:40:08Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:08Z I [rs1/rs102:27017] node: rs1/rs102:27017
E                   2024-11-02T17:40:08Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:08Z I [rs1/rs101:27017] node: rs1/rs101:27017
E                   2024-11-02T17:40:08Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:08Z I [rs1/rs103:27017] listening for the commands
E                   2024-11-02T17:40:08Z I [rs2/rs201:27017] node: rs2/rs201:27017
E                   2024-11-02T17:40:08Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:08Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:08Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:08Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:08Z I [rs2/rs201:27017] listening for the commands
E                   2024-11-02T17:40:08Z I [rs1/rs102:27017] listening for the commands
E                   2024-11-02T17:40:08Z I [rs1/rs101:27017] listening for the commands
E                   2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] starting PITR routine
E                   2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
E                   2024-11-02T17:40:09Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] starting PITR routine
E                   2024-11-02T17:40:09Z I [rscfg/rscfg01:27017] listening for the commands
E                   2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
E                   2024-11-02T17:40:09Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:09Z I [rscfg/rscfg02:27017] listening for the commands
E                   2024-11-02T17:40:09Z I [rs2/rs202:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:09Z I [rs2/rs202:27017] starting PITR routine
E                   2024-11-02T17:40:09Z I [rs2/rs202:27017] node: rs2/rs202:27017
E                   2024-11-02T17:40:09Z I [rs2/rs203:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:09Z I [rs2/rs203:27017] starting PITR routine
E                   2024-11-02T17:40:09Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:09Z I [rs2/rs203:27017] node: rs2/rs203:27017
E                   2024-11-02T17:40:09Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:09Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:09Z I [rs2/rs202:27017] listening for the commands
E                   2024-11-02T17:40:09Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:09Z I [rs2/rs203:27017] listening for the commands
E                   2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] pbm-agent:
E                   Version:   2.7.0
E                   Platform:  linux/amd64
E                   GitCommit: 652a686ac7e3b42b088697f4d85e612d4771807b
E                   GitBranch: CURRENT_PR
E                   BuildTime: 2024-11-02_16:54_UTC
E                   GoVersion: go1.22.8
E                   2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] starting PITR routine
E                   2024-11-02T17:40:11Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
E                   2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
E                   2024-11-02T17:40:11Z I [rscfg/rscfg03:27017] listening for the commands
E                   2024-11-02T17:40:13Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:13Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:13Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:13Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:14Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:14Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:14Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:14Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:16Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E                   2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] got epoch {1730569216 2}
E                   2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] [resync] started
E                   2024-11-02T17:40:17Z I [rscfg/rscfg02:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:17Z I [rscfg/rscfg02:27017] got epoch {1730569216 2}
E                   2024-11-02T17:40:17Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E                   2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
E                   2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
E                   2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 0
E                   2024-11-02T17:40:17Z I [rs2/rs202:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:17Z I [rs2/rs202:27017] got epoch {1730569216 2}
E                   2024-11-02T17:40:17Z I [rs2/rs203:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:17Z D [rscfg/rscfg01:27017] [resync] epoch set to {1730569217 16}
E                   2024-11-02T17:40:17Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:17Z I [rs2/rs203:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:17Z I [rscfg/rscfg01:27017] [resync] succeed
E                   2024-11-02T17:40:17Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:18Z I [rs1/rs103:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:18Z I [rs1/rs103:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:18Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:18Z I [rs2/rs201:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:18Z I [rs1/rs101:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:18Z I [rs1/rs102:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:18Z I [rs2/rs201:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:18Z I [rs1/rs101:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:18Z I [rs1/rs102:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:18Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:18Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:18Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:18Z I [rscfg/rscfg03:27017] got command resync <ts: 1730569217>, opid: 67266401246825df5ed0a03b
E                   2024-11-02T17:40:18Z I [rscfg/rscfg03:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:18Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 67266401246825df5ed0a03b [Resync storage]
E                   2024-11-02T17:40:18Z D [rscfg/rscfg03:27017] [resync] lock not acquired
E                   2024-11-02T17:40:22Z I [rs2/rs202:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:22Z I [rs2/rs202:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:22Z I [rs2/rs203:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:22Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:22Z I [rs2/rs203:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:22Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:23Z I [rs1/rs103:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rs1/rs103:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:23Z I [rs2/rs201:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rs1/rs102:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rs1/rs101:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:23Z I [rs1/rs101:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:23Z I [rs2/rs201:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:23Z I [rs1/rs102:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:23Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:23Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:23Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E                   2024-11-02T17:40:23Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
E                   2024-11-02T17:40:23Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
E                   2024-11-02T17:40:23Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
E                   2024-11-02T17:40:23Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
E                   2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] got epoch {1730569217 16}
E                   2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] [resync] started
E                   2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
E                   2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
E                   2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
E                   2024-11-02T17:40:23Z D [rscfg/rscfg03:27017] [resync] epoch set to {1730569223 110}
E                   2024-11-02T17:40:23Z I [rscfg/rscfg03:27017] [resync] succeed
E                   2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:23Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 67266406fe450ef5ac049f27 [Resync storage]
E                   2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got command resync <ts: 1730569222>, opid: 67266406fe450ef5ac049f27
E                   2024-11-02T17:40:23Z D [rscfg/rscfg01:27017] [resync] lock not acquired
E                   2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:23Z I [rscfg/rscfg01:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:23Z E [rscfg/rscfg01:27017] [backup/2024-11-02T17:40:23Z] unable to proceed with the backup, active lock is present
E                   2024-11-02T17:40:23Z D [rscfg/rscfg02:27017] [resync] get lock: duplicate operation: 67266406fe450ef5ac049f27 [Resync storage]
E                   2024-11-02T17:40:23Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E                   2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:23Z I [rscfg/rscfg02:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:23Z I [rs2/rs202:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:23Z I [rs2/rs203:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:23Z I [rs2/rs202:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:23Z I [rs2/rs203:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:24Z I [rs1/rs103:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:24Z I [rs1/rs103:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:24Z I [rs2/rs201:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:24Z I [rs1/rs102:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:24Z I [rs1/rs101:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:24Z I [rs2/rs201:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:24Z I [rs1/rs101:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:24Z I [rs1/rs102:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:24Z I [rscfg/rscfg03:27017] got command backup [name: 2024-11-02T17:40:23Z, compression: s2 (level: default)] <ts: 1730569223>, opid: 672664073819acb64f5ec860
E                   2024-11-02T17:40:24Z I [rscfg/rscfg03:27017] got epoch {1730569223 110}
E                   2024-11-02T17:40:38Z D [rscfg/rscfg02:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:38Z D [rscfg/rscfg02:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:38Z D [rs2/rs202:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:38Z D [rs2/rs203:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:38Z D [rs2/rs202:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:38Z D [rs2/rs203:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:39Z D [rs1/rs103:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:39Z D [rs1/rs103:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:39Z D [rs1/rs101:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:39Z D [rs2/rs201:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:39Z D [rs1/rs102:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:39Z D [rs1/rs101:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:39Z D [rs2/rs201:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:39Z D [rs1/rs102:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node
E                   2024-11-02T17:40:39Z D [rscfg/rscfg03:27017] [backup/2024-11-02T17:40:23Z] nomination timeout
E                   2024-11-02T17:40:39Z D [rscfg/rscfg03:27017] [backup/2024-11-02T17:40:23Z] skip after nomination, probably started by another node

cluster.py:393: AssertionError