PBM-1444. Test selective PITR restore with DDL operations in oplog #186
GitHub Actions / JUnit Test Report
failed
Dec 2, 2024 in 0s
42 tests run, 32 passed, 8 skipped, 2 failed.
Annotations
Check failure on line 69 in pbm-functional/pytest/test_azurite.py
github-actions / JUnit Test Report
test_azurite.test_logical
AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}
2024-12-02T12:03:59Z I [rs2/rs201:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:03:59Z I [rs2/rs201:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:03:59Z I [rs1/rs101:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:03:59Z I [rs2/rs201:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:03:59Z I [rs2/rs201:27017] starting PITR routine
2024-12-02T12:03:59Z I [rs1/rs101:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:03:59Z I [rs1/rs103:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:03:59Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:03:59Z I [rs2/rs201:27017] node: rs2/rs201:27017
2024-12-02T12:03:59Z I [rs1/rs102:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:03:59Z I [rs1/rs101:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:03:59Z I [rs1/rs101:27017] starting PITR routine
2024-12-02T12:03:59Z I [rs1/rs103:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:03:59Z I [rs1/rs102:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:03:59Z I [rs1/rs101:27017] node: rs1/rs101:27017
2024-12-02T12:03:59Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:03:59Z I [rs1/rs103:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:03:59Z I [rs1/rs103:27017] starting PITR routine
2024-12-02T12:03:59Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:03:59Z I [rs2/rs201:27017] listening for the commands
2024-12-02T12:03:59Z I [rs1/rs102:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:03:59Z I [rs1/rs102:27017] starting PITR routine
2024-12-02T12:03:59Z I [rs1/rs103:27017] node: rs1/rs103:27017
2024-12-02T12:03:59Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:03:59Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:03:59Z I [rs1/rs102:27017] node: rs1/rs102:27017
2024-12-02T12:03:59Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:03:59Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:03:59Z I [rs1/rs101:27017] listening for the commands
2024-12-02T12:03:59Z I [rs1/rs103:27017] listening for the commands
2024-12-02T12:03:59Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:03:59Z I [rs1/rs102:27017] listening for the commands
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] starting PITR routine
2024-12-02T12:04:00Z I [rs2/rs203:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:04:00Z I [rs2/rs202:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] starting PITR routine
2024-12-02T12:04:00Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
2024-12-02T12:04:00Z I [rs2/rs202:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:04:00Z I [rs2/rs203:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:04:00Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:00Z I [rs2/rs202:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:04:00Z I [rs2/rs202:27017] starting PITR routine
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] listening for the commands
2024-12-02T12:04:00Z I [rs2/rs203:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:04:00Z I [rs2/rs203:27017] starting PITR routine
2024-12-02T12:04:00Z I [rs2/rs202:27017] node: rs2/rs202:27017
2024-12-02T12:04:00Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] listening for the commands
2024-12-02T12:04:00Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:04:00Z I [rs2/rs203:27017] node: rs2/rs203:27017
2024-12-02T12:04:00Z I [rs2/rs202:27017] listening for the commands
2024-12-02T12:04:00Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:01Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:04:01Z I [rs2/rs203:27017] listening for the commands
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017]
% _____
%%% | __ \
###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
#### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
,((### ### %%% _____ _
(((( (### #### %%%% / ____| | |
((( ((# ###### | (___ __ _ _ _ __ _ __| |
(((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
/(( ,((( *### ____) | (_| | |_| | (_| | (_| |
//// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
/// (((( #### | |
/////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
** Join Percona Squad! **
Participate in monthly SWAG raffles, get early access to new product features,
invite-only ”ask me anything” sessions with database performance experts.
Interested? Fill in the form at squad.percona.com/mongodb
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
GitBranch: dev
BuildTime: 2024-12-02_11:18_UTC
GoVersion: go1.23.3
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] starting PITR routine
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
2024-12-02T12:04:02Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] listening for the commands
2024-12-02T12:04:04Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:04Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:04Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:04Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:05Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:05Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:06Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:06Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:07Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-12-02T12:04:08Z I [rscfg/rscfg01:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:08Z I [rscfg/rscfg01:27017] got epoch {1733141047 3}
2024-12-02T12:04:08Z I [rscfg/rscfg02:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs2/rs202:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rscfg/rscfg02:27017] got epoch {1733141047 3}
2024-12-02T12:04:09Z I [rs2/rs203:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs2/rs202:27017] got epoch {1733141047 3}
2024-12-02T12:04:09Z I [rscfg/rscfg01:27017] [resync] started
2024-12-02T12:04:09Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z I [rs2/rs203:27017] got epoch {1733141047 3}
2024-12-02T12:04:09Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 0
2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] epoch set to {1733141049 15}
2024-12-02T12:04:09Z I [rscfg/rscfg01:27017] [resync] succeed
2024-12-02T12:04:09Z I [rs2/rs201:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs2/rs201:27017] got epoch {1733141049 15}
2024-12-02T12:04:09Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z I [rs1/rs101:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs1/rs101:27017] got epoch {1733141049 15}
2024-12-02T12:04:09Z I [rs1/rs103:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z I [rs1/rs102:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rs1/rs103:27017] got epoch {1733141049 15}
2024-12-02T12:04:09Z I [rs1/rs102:27017] got epoch {1733141049 15}
2024-12-02T12:04:09Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-12-02T12:04:09Z I [rscfg/rscfg03:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
2024-12-02T12:04:09Z I [rscfg/rscfg03:27017] got epoch {1733141049 15}
2024-12-02T12:04:09Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 674da238b59b69e927b15c90 [Resync storage]
2024-12-02T12:04:09Z D [rscfg/rscfg03:27017] [resync] lock not acquired
2024-12-02T12:04:14Z I [rs2/rs201:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:14Z I [rs2/rs201:27017] got epoch {1733141049 15}
2024-12-02T12:04:14Z I [rs1/rs101:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:14Z I [rs1/rs101:27017] got epoch {1733141049 15}
2024-12-02T12:04:14Z I [rs1/rs103:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:14Z I [rs1/rs101:27017] [resync] not a member of the leader rs
2024-12-02T12:04:14Z I [rs2/rs201:27017] [resync] not a member of the leader rs
2024-12-02T12:04:14Z I [rs1/rs102:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:14Z I [rs1/rs103:27017] got epoch {1733141049 15}
2024-12-02T12:04:14Z I [rs1/rs102:27017] got epoch {1733141049 15}
2024-12-02T12:04:14Z I [rs1/rs103:27017] [resync] not a member of the leader rs
2024-12-02T12:04:14Z I [rs1/rs102:27017] [resync] not a member of the leader rs
2024-12-02T12:04:14Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
2024-12-02T12:04:14Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
2024-12-02T12:04:14Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
2024-12-02T12:04:14Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] got epoch {1733141049 15}
2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] [resync] started
2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] epoch set to {1733141054 157}
2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] [resync] succeed
2024-12-02T12:04:15Z I [rscfg/rscfg01:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:15Z I [rscfg/rscfg01:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z D [rscfg/rscfg02:27017] [resync] lock not acquired
2024-12-02T12:04:15Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 674da23e44e0b8d071d84a72 [Resync storage]
2024-12-02T12:04:15Z I [rs2/rs202:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs2/rs203:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
2024-12-02T12:04:15Z I [rs2/rs202:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z D [rscfg/rscfg01:27017] [resync] lock not acquired
2024-12-02T12:04:15Z I [rs2/rs203:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs2/rs202:27017] [resync] not a member of the leader rs
2024-12-02T12:04:15Z I [rs2/rs203:27017] [resync] not a member of the leader rs
2024-12-02T12:04:15Z I [rs2/rs202:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs2/rs203:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs2/rs203:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs2/rs202:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs2/rs201:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs2/rs201:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs1/rs101:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs1/rs101:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs1/rs103:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs1/rs103:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rs1/rs102:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rs1/rs102:27017] got epoch {1733141054 157}
2024-12-02T12:04:15Z I [rscfg/rscfg03:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
2024-12-02T12:04:15Z I [rscfg/rscfg03:27017] got epoch {1733141054 157}
2024-12-02T12:04:30Z D [rscfg/rscfg02:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rscfg/rscfg02:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs2/rs202:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs2/rs203:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs2/rs202:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs2/rs203:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs2/rs201:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs2/rs201:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs1/rs101:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs1/rs101:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs1/rs103:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs1/rs103:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rs1/rs102:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rs1/rs102:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
2024-12-02T12:04:30Z D [rscfg/rscfg03:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
2024-12-02T12:04:30Z D [rscfg/rscfg03:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another nodeRaw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7f52593af9d0>
@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 0x7f52593af9d0>, 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-12-02T12:03:59Z I [rs2/rs201:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:03:59Z I [rs1/rs101:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] starting PITR routine
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:03:59Z I [rs1/rs103:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:03:59Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] node: rs2/rs201:27017
E 2024-12-02T12:03:59Z I [rs1/rs102:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] starting PITR routine
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] node: rs1/rs101:27017
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] starting PITR routine
E 2024-12-02T12:03:59Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:03:59Z I [rs2/rs201:27017] listening for the commands
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] starting PITR routine
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] node: rs1/rs103:27017
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:03:59Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] node: rs1/rs102:27017
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:03:59Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:03:59Z I [rs1/rs101:27017] listening for the commands
E 2024-12-02T12:03:59Z I [rs1/rs103:27017] listening for the commands
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:03:59Z I [rs1/rs102:27017] listening for the commands
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] starting PITR routine
E 2024-12-02T12:04:00Z I [rs2/rs203:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:04:00Z I [rs2/rs202:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] starting PITR routine
E 2024-12-02T12:04:00Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] node: rscfg/rscfg01:27017
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] node: rscfg/rscfg02:27017
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:04:00Z I [rs2/rs203:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:04:00Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] starting PITR routine
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:04:00Z I [rscfg/rscfg01:27017] listening for the commands
E 2024-12-02T12:04:00Z I [rs2/rs203:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:04:00Z I [rs2/rs203:27017] starting PITR routine
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] node: rs2/rs202:27017
E 2024-12-02T12:04:00Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:00Z I [rscfg/rscfg02:27017] listening for the commands
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:04:00Z I [rs2/rs203:27017] node: rs2/rs203:27017
E 2024-12-02T12:04:00Z I [rs2/rs202:27017] listening for the commands
E 2024-12-02T12:04:00Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:01Z I [rs2/rs203:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:04:01Z I [rs2/rs203:27017] listening for the commands
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017]
E % _____
E %%% | __ \
E ###%%%%%%%%%%%%* | |__) |__ _ __ ___ ___ _ __ __ _
E ### ##%% %%%% | ___/ _ \ '__/ __/ _ \| '_ \ / _` |
E #### ##% %%%% | | | __/ | | (_| (_) | | | | (_| |
E ### #### %%% |_| \___|_| \___\___/|_| |_|\__,_|
E ,((### ### %%% _____ _
E (((( (### #### %%%% / ____| | |
E ((( ((# ###### | (___ __ _ _ _ __ _ __| |
E (((( (((# #### \___ \ / _` | | | |/ _` |/ _` |
E /(( ,((( *### ____) | (_| | |_| | (_| | (_| |
E //// ((( #### |_____/ \__, |\__,_|\__,_|\__,_|
E /// (((( #### | |
E /////////////(((((((((((((((((######## |_| Join @ squad.percona.com/mongodb
E
E ** Join Percona Squad! **
E Participate in monthly SWAG raffles, get early access to new product features,
E invite-only ”ask me anything” sessions with database performance experts.
E
E Interested? Fill in the form at squad.percona.com/mongodb
E
E
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] log options: log-path=/dev/stderr, log-level:D, log-json:false
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] pbm-agent:
E Version: 2.7.0
E Platform: linux/amd64
E GitCommit: 44b7141b76d5e4a1c87ecf4878102eaceb7e8c0f
E GitBranch: dev
E BuildTime: 2024-12-02_11:18_UTC
E GoVersion: go1.23.3
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] starting PITR routine
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] node: rscfg/rscfg03:27017
E 2024-12-02T12:04:02Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] conn level ReadConcern: majority; WriteConcern: majority
E 2024-12-02T12:04:02Z I [rscfg/rscfg03:27017] listening for the commands
E 2024-12-02T12:04:04Z E [rs2/rs201:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:04Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:04Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:04Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:05Z E [rscfg/rscfg01:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:05Z E [rscfg/rscfg02:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:06Z E [rs2/rs202:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:06Z E [rs2/rs203:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:07Z E [rscfg/rscfg03:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
E 2024-12-02T12:04:08Z I [rscfg/rscfg01:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:08Z I [rscfg/rscfg01:27017] got epoch {1733141047 3}
E 2024-12-02T12:04:08Z I [rscfg/rscfg02:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs2/rs202:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rscfg/rscfg02:27017] got epoch {1733141047 3}
E 2024-12-02T12:04:09Z I [rs2/rs203:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs2/rs202:27017] got epoch {1733141047 3}
E 2024-12-02T12:04:09Z I [rscfg/rscfg01:27017] [resync] started
E 2024-12-02T12:04:09Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z I [rs2/rs203:27017] got epoch {1733141047 3}
E 2024-12-02T12:04:09Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E 2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
E 2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] got backups list: 0
E 2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] got physical restores list: 0
E 2024-12-02T12:04:09Z D [rscfg/rscfg01:27017] [resync] epoch set to {1733141049 15}
E 2024-12-02T12:04:09Z I [rscfg/rscfg01:27017] [resync] succeed
E 2024-12-02T12:04:09Z I [rs2/rs201:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs2/rs201:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:09Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z I [rs1/rs101:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs1/rs101:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:09Z I [rs1/rs103:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z I [rs1/rs102:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rs1/rs103:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:09Z I [rs1/rs102:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:09Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:09Z I [rscfg/rscfg03:27017] got command resync <ts: 1733141048>, opid: 674da238b59b69e927b15c90
E 2024-12-02T12:04:09Z I [rscfg/rscfg03:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:09Z D [rscfg/rscfg03:27017] [resync] get lock: duplicate operation: 674da238b59b69e927b15c90 [Resync storage]
E 2024-12-02T12:04:09Z D [rscfg/rscfg03:27017] [resync] lock not acquired
E 2024-12-02T12:04:14Z I [rs2/rs201:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:14Z I [rs2/rs201:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:14Z I [rs1/rs101:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:14Z I [rs1/rs101:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:14Z I [rs1/rs103:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:14Z I [rs1/rs101:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:14Z I [rs2/rs201:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:14Z I [rs1/rs102:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:14Z I [rs1/rs103:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:14Z I [rs1/rs102:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:14Z I [rs1/rs103:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:14Z I [rs1/rs102:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:14Z W [rs2/rs201:27017] [agentCheckup] storage is not initialized
E 2024-12-02T12:04:14Z W [rs1/rs101:27017] [agentCheckup] storage is not initialized
E 2024-12-02T12:04:14Z W [rs1/rs103:27017] [agentCheckup] storage is not initialized
E 2024-12-02T12:04:14Z W [rs1/rs102:27017] [agentCheckup] storage is not initialized
E 2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] got epoch {1733141049 15}
E 2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] [resync] started
E 2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] BufferSize is set to 10485760 (~10Mb) | 5
E 2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] got backups list: 0
E 2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] got physical restores list: 0
E 2024-12-02T12:04:14Z D [rscfg/rscfg03:27017] [resync] epoch set to {1733141054 157}
E 2024-12-02T12:04:14Z I [rscfg/rscfg03:27017] [resync] succeed
E 2024-12-02T12:04:15Z I [rscfg/rscfg01:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:15Z I [rscfg/rscfg01:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z D [rscfg/rscfg02:27017] [resync] lock not acquired
E 2024-12-02T12:04:15Z D [rscfg/rscfg01:27017] [resync] get lock: duplicate operation: 674da23e44e0b8d071d84a72 [Resync storage]
E 2024-12-02T12:04:15Z I [rs2/rs202:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs2/rs203:27017] got command resync <ts: 1733141054>, opid: 674da23e44e0b8d071d84a72
E 2024-12-02T12:04:15Z I [rs2/rs202:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z D [rscfg/rscfg01:27017] [resync] lock not acquired
E 2024-12-02T12:04:15Z I [rs2/rs203:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rscfg/rscfg02:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs2/rs202:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:15Z I [rs2/rs203:27017] [resync] not a member of the leader rs
E 2024-12-02T12:04:15Z I [rs2/rs202:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs2/rs203:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs2/rs203:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs2/rs202:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs2/rs201:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs2/rs201:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs1/rs101:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs1/rs101:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs1/rs103:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs1/rs103:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rs1/rs102:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rs1/rs102:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:15Z I [rscfg/rscfg03:27017] got command backup [name: 2024-12-02T12:04:14Z, compression: s2 (level: default)] <ts: 1733141054>, opid: 674da23e3be4e88f45cdd8cf
E 2024-12-02T12:04:15Z I [rscfg/rscfg03:27017] got epoch {1733141054 157}
E 2024-12-02T12:04:30Z D [rscfg/rscfg02:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rscfg/rscfg02:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs2/rs202:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs2/rs203:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs2/rs202:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs2/rs203:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs2/rs201:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs2/rs201:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs1/rs101:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs1/rs101:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs1/rs103:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs1/rs103:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rs1/rs102:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rs1/rs102:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
E 2024-12-02T12:04:30Z D [rscfg/rscfg03:27017] [backup/2024-12-02T12:04:14Z] nomination timeout
E 2024-12-02T12:04:30Z D [rscfg/rscfg03:27017] [backup/2024-12-02T12:04:14Z] skip after nomination, probably started by another node
cluster.py:393: AssertionError
Check failure on line 178 in pbm-functional/pytest/test_rename_replicaset.py
github-actions / JUnit Test Report
test_rename_replicaset.test_logical_pitr_ddl_PBM_T273
AssertionError: assert 'old_index' not in {'_id_': {'key': [('_id', 1)], 'v': 2}, 'new_index': {'key': [('data', 1)], 'v': 2}, 'old_index': {'key': [('key', 1)], 'v': 2}}
+ where {'_id_': {'key': [('_id', 1)], 'v': 2}, 'new_index': {'key': [('data', 1)], 'v': 2}, 'old_index': {'key': [('key', 1)], 'v': 2}} = index_information()
+ where index_information = Collection(Database(MongoClient(host=['rs101:27017'], document_class=dict, tz_aware=False, connect=True), 'restored'), 'indexes').index_informationRaw output
start_cluster = True, cluster = <cluster.Cluster object at 0x7f5259397f10>
@pytest.mark.timeout(300,func_only=True)
def test_logical_pitr_ddl_PBM_T273(start_cluster,cluster):
cluster.check_pbm_status()
cluster.make_backup("logical")
cluster.enable_pitr(pitr_extra_args="--set pitr.oplogSpanMin=0.1")
time.sleep(5)
client = pymongo.MongoClient(cluster.connection)
client.drop_database('test')
for i in range(10):
client["test"]["indexes"].insert_one({"key": i+10, "data": i+10})
client["test"]["indexes"].create_index("data",name="new_index")
time.sleep(5)
pitr = datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%S")
pitr=" --time=" + pitr
Cluster.log("Time for PITR is: " + pitr)
time.sleep(10)
cluster.disable_pitr()
time.sleep(5)
backup=pitr + " --ns-from=test.indexes --ns-to=restored.indexes"
cluster.make_restore(backup)
client = pymongo.MongoClient(cluster.connection)
assert client["restored"]["indexes"].count_documents({})==10
for i in range(10):
assert client["restored"]["indexes"].find_one({"key": i+10, "data": i+10})
assert 'new_index' in client["restored"]["indexes"].index_information()
> assert 'old_index' not in client["restored"]["indexes"].index_information()
E AssertionError: assert 'old_index' not in {'_id_': {'key': [('_id', 1)], 'v': 2}, 'new_index': {'key': [('data', 1)], 'v': 2}, 'old_index': {'key': [('key', 1)], 'v': 2}}
E + where {'_id_': {'key': [('_id', 1)], 'v': 2}, 'new_index': {'key': [('data', 1)], 'v': 2}, 'old_index': {'key': [('key', 1)], 'v': 2}} = index_information()
E + where index_information = Collection(Database(MongoClient(host=['rs101:27017'], document_class=dict, tz_aware=False, connect=True), 'restored'), 'indexes').index_information
test_rename_replicaset.py:178: AssertionError
Loading