PBM-1442 PBM-1443: improve pbm diagnostic #1111
Annotations
28 errors and 2 warnings
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[indexes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f51a25b1b10>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[indexes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f21e0346f50>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_crud_PBM_T270[indexes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L75
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[inserts]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[replaces]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[updates]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L107
AssertionError: Backup failed{"Error":"get backup metadata: get: context deadline exceeded"}
2024-11-14T13:27:22Z I [rs1/rs102:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 7cc283145a6cba5b11003337f647911514c5473c
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_12:02_UTC
GoVersion: go1.22.9
2024-11-14T13:27:22Z I [rs1/rs102:27017] starting PITR routine
2024-11-14T13:27:22Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:22Z I [rs1/rs103:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 7cc283145a6cba5b11003337f647911514c5473c
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_12:02_UTC
GoVersion: go1.22.9
2024-11-14T13:27:22Z I [rs1/rs103:27017] starting PITR routine
2024-11-14T13:27:22Z I [rs1/rs102:27017] node: rs1/rs102:27017
2024-11-14T13:27:22Z I [rs1/rs101:27017] starting PITR routine
2024-11-14T13:27:22Z I [rs1/rs101:27017] pbm-agent:
Version: 2.7.0
Platform: linux/amd64
GitCommit: 7cc283145a6cba5b11003337f647911514c5473c
GitBranch: CURRENT_PR
BuildTime: 2024-11-14_12:02_UTC
GoVersion: go1.22.9
2024-11-14T13:27:22Z I [rs1/rs103:27017] node: rs1/rs103:27017
2024-11-14T13:27:22Z I [rs1/rs102:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T13:27:22Z I [rs1/rs101:27017] node: rs1/rs101:27017
2024-11-14T13:27:22Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:22Z I [rs1/rs102:27017] listening for the commands
2024-11-14T13:27:22Z I [rs1/rs101:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T13:27:22Z I [rs1/rs103:27017] conn level ReadConcern: majority; WriteConcern: majority
2024-11-14T13:27:22Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:22Z I [rs1/rs101:27017] listening for the commands
2024-11-14T13:27:22Z I [rs1/rs103:27017] listening for the commands
2024-11-14T13:27:27Z E [rs1/rs102:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:27Z E [rs1/rs101:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:27Z E [rs1/rs103:27017] [agentCheckup] check storage connection: unable to get storage: get config: get: mongo: no documents in result
2024-11-14T13:27:29Z I [rs1/rs102:27017] got command resync <ts: 1731590848>, opid: 6735fac0ed6f7aec5718d914
2024-11-14T13:27:29Z I [rs1/rs102:27017] got epoch {1731590847 6}
2024-11-14T13:27:29Z I [rs1/rs103:27017] got command resync <ts: 1731590848>, opid: 6735fac0ed6f7aec5718d914
2024-11-14T13:27:29Z I [rs1/rs101:27017] got command resync <ts: 1731590848>, opid: 6735fac0ed6f7aec5718d914
2024-11-14T13:27:29Z I [rs1/rs102:27017] [resync] started
2024-11-14T13:27:29Z I [rs1/rs101:27017] got epoch {1731590847 6}
2024-11-14T13:27:29Z I [rs1/rs103:27017] got epoch {1731590847 6}
2024-11-14T13:27:29Z D [rs1/rs101:27017] [resync] lock not acquired
2024-11-14T13:27:29Z D [rs1/rs103:27017] [resync] lock not acquired
2024-11-14T13:27:29Z D [rs1/rs102:27017] [resync] uploading ".pbm.init" [size hint: 5 (5.00B); part size: 10485760 (10.00MB)]
2024-11-14T13:27:29Z D [rs1/rs102:27017] [resync] got backups list: 0
2024-11-14T13:27:29Z D [rs1/rs102:27017] [resync] got physical restores list: 0
2024-11-14T13:27:29Z D [rs1/rs102:27017] [resync] epoch set to {1731590849 14}
2024-11-14T13:27:29Z I [rs1/rs102:27017] [resync] succeed
2024-11-14T13:27:34Z I [rs1/rs102:27017] got command resync <ts: 1731590853>, opid: 6735fac55e1f9f130ae74b09
2024-11-14T13:27:34Z I [rs1/rs102:27017] got epoch {1731590849 14}
2024-11-14T13:27:34Z I [rs1/rs103:27017] got command resync <ts: 1731590853>, opid: 6735fac55e1f9f130ae74b09
2024-11-14T13:27:34Z I [rs1/rs101:27017] got command resync <ts: 1731590853>, opid: 6735fac55e1f9f130ae74b09
2024-11-14T13:27:34Z I [rs1/rs103:27017] got epoch {1731590849 14}
2024-11-14T13:27:34Z I [rs1/rs101:27017] got epoch {1731590849 14}
2024-11-14T13:27:34Z I [rs1/rs102:27017] [resync] started
2024-11-14T13:27:34Z D [rs1/rs101:27017] [resync] lock not acquired
2024-11-14T13:27:34Z I [rs1/rs101:27017] got command backup [name: 2024-11-14T13:27:34Z, compression: none (level: default)] <ts: 1731590854>, opid: 6735fac676e76df95c35f742
2024-11-14T13:27:34Z D [rs1/rs102:27017] [resync] got backups list: 0
2024-11-14T13:27:34Z D [rs1/rs103:27017] [resync] lock not acquired
2024-11-14T13:27:34Z I [rs1/rs101:27017] got epoch {1731590849 14}
2024-11-14T13:27:34Z D [rs1/rs102:27017] [resync] got physical restores list: 0
2024-11-14T13:27:34Z E [rs1/rs101:27017] [backup/2024-11-14T13:27:34Z] unable to proceed with the backup, active lock is present
2024-11-14T13:27:34Z D [rs1/rs102:27017] [resync] epoch set to {1731590854 17}
2024-11-14T13:27:34Z I [rs1/rs102:27017] [resync] succeed
2024-11-14T13:27:35Z I [rs1/rs102:27017] got command backup [name: 2024-11-14T13:27:34Z, compression: none (level: default)] <ts: 1731590854>, opid: 6735fac676e76df95c35f742
2024-11-14T13:27:35Z I [rs1/rs102:27017] got epoch {1731590854 17}
2024-11-14T13:27:35Z I [rs1/rs103:27017] got command backup [name: 2024-11-14T13:27:34Z, compression: none (level: default)] <ts: 1731590854>, opid: 6735fac676e76df95c35f742
2024-11-14T13:27:35Z I [rs1/rs103:27017] got epoch {1731590854 17}
2024-11-14T13:27:50Z D [rs1/rs102:27017] [backup/2024-11-14T13:27:34Z] nomination timeout
2024-11-14T13:27:50Z D [rs1/rs102:27017] [backup/2024-11-14T13:27:34Z] skip after nomination, probably started by another node
2024-11-14T13:27:50Z D [rs1/rs103:27017] [backup/2024-11-14T13:27:34Z] nomination timeout
2024-11-14T13:27:50Z D [rs1/rs103:27017] [backup/2024-11-14T13:27:34Z] skip after nomination, probably started by another node
|
test_rename_replicaset.test_logical_pitr_with_txn_PBM_T271[deletes]:
psmdb-testing/pbm-functional/pytest/test_rename_replicaset.py#L129
AssertionError: assert 'cloning namespace (--ns-to) is already in use' in 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n'
+ where 'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n' = CommandResult(backend=<testinfra.backend.docker.DockerBackend object at 0x7f67ffdbfad0>, exit_status=1, command=b'pbm ...'', _stderr=b'Error: parse --ns-from and --ns-to options: cloning with restore to the point-in-time is not possible\n').stderr
|
test_PBM-1211.test_pitr_PBM_T268[physical]:
psmdb-testing/pbm-functional/pytest/test_PBM-1211.py#L79
AssertionError: Starting restore 2024-11-14T12:20:22.242493525Z to point-in-time 2024-11-14T12:18:59 from '2024-11-14T12:15:19Z'..........................Started physical restore.
Waiting to finish.....................Error: operation failed with: replay pitr oplog: reply oplog: replay chunk 1731586521.1731586585: apply oplog for chunk: applying an entry: op: {"Timestamp":{"T":1731586532,"I":9},"Term":1,"Hash":null,"Version":2,"Operation":"u","Namespace":"config.settings","Object":[{"Key":"$v","Value":2},{"Key":"diff","Value":[{"Key":"u","Value":[{"Key":"mode","Value":"full"},{"Key":"stopped","Value":false}]}]}],"Query":[{"Key":"_id","Value":"balancer"}],"UI":{"Subtype":4,"Data":"NtLY8eG3QJ2saReFA57XyA=="},"LSID":null,"TxnNumber":null,"PrevOpTime":null,"MultiOpType":null} | merr <nil>: applyOps: (NotWritablePrimary) not primary
{"t":{"$date":"2024-11-14T12:21:08.120+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2024-11-14T12:21:08.124+00:00"},"s":"I", "c":"CONTROL", "id":5945603, "svc":"-", "ctx":"main","msg":"Multi threading initialized"}
{"t":{"$date":"2024-11-14T12:21:08.124+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "svc":"-", "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set at least one of the related parameters","attr":{"relatedParameters":["tcpFastOpenServer","tcpFastOpenClient","tcpFastOpenQueueSize"]}}
{"t":{"$date":"2024-11-14T12:21:08.125+00:00"},"s":"I", "c":"NETWORK", "id":4915701, "svc":"-", "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":25},"outgoing":{"minWireVersion":6,"maxWireVersion":25},"isInternalClient":true}}}
{"t":{"$date":"2024-11-14T12:21:08.125+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingCoordinatorService","namespace":"config.reshardingOperations"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ConfigsvrCoordinatorService","namespace":"config.sharding_configsvr_coordinators"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"RenameCollectionParticipantService","namespace":"config.localRenameParticipants"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ShardingDDLCoordinator","namespace":"config.system.sharding_ddl_coordinators"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingDonorService","namespace":"config.localReshardingOperations.donor"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"ReshardingRecipientService","namespace":"config.localReshardingOperations.recipient"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"REPL", "id":5123008, "svc":"-", "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"MultiUpdateCoordinatorService","namespace":"config.localMigrationBlockingOperations.multiUpdateCoordinators"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"TENANT_M", "id":7091600, "svc":"-", "ctx":"main","msg":"Starting TenantMigrationAccessBlockerRegistry"}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"CONTROL", "id":4615611, "svc":"S", "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1960,"port":27550,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"rscfg01"}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"CONTROL", "id":23403, "svc":"S", "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"8.0.1-1","gitVersion":"88788b464f844b9120ed4a22ebe72cbfa873626c","openSSLVersion":"OpenSSL 1.1.1k FIPS 25 Mar 2021","modules":[],"proFeatures":[],"allocator":"tcmalloc-google","environment":{"distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"CONTROL", "id":51765, "svc":"S", "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Oracle Linux Server release 8.10","version":"Kernel 6.5.0-1025-azure"}}}
{"t":{"$date":"2024-11-14T12:21:08.126+00:00"},"s":"I", "c":"CONTROL", "id":21951, "svc":"S", "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"/tmp/pbmMongdTmpConf263978617","net":{"bindIp":"localhost","port":27550},"replication":{"replSet":"rscfg"},"setParameter":{"disableLogicalSessionCacheRefresh":"true","takeUnstableCheckpointOnShutdown":"true"},"sharding":{"clusterRole":"configsvr"},"storage":{"dbPath":"/var/lib/mongo","directoryPerDB":false,"wiredTiger":{"collectionConfig":{"blockCompressor":"snappy"},"engineConfig":{"directoryForIndexes":false,"journalCompressor":"snappy"},"indexConfig":{"prefixCompression":true}}},"systemLog":{"destination":"file","path":"/var/lib/mongo/pbm.restore.log"}}}}
{"t":{"$date":"2024-11-14T12:21:08.127+00:00"},"s":"I", "c":"STORAGE", "id":22270, "svc":"S", "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/var/lib/mongo","storageEngine":"wiredTiger"}}
{"t":{"$date":"2024-11-14T12:21:08.127+00:00"},"s":"I", "c":"STORAGE", "id":22315, "svc":"S", "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=7478M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,remove=true,path=journal,compressor=snappy),builtin_extension_config=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=2000),statistics_log=(wait=0),json_output=(error,message),verbose=[recovery_progress:1,checkpoint_progress:1,compact_progress:1,backup:0,checkpoint:0,compact:0,evict:0,history_store:0,recovery:0,rts:0,salvage:0,tiered:0,timestamp:0,transaction:0,verify:0,log:0],prefetch=(available=true,default=false),"}}
{"t":{"$date":"2024-11-14T12:21:08.260+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":260615,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}}
{"t":{"$date":"2024-11-14T12:21:08.286+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":286160,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}}
{"t":{"$date":"2024-11-14T12:21:08.353+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":353267,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Main recovery loop: starting at 5/176768 to 6/256"}}}
{"t":{"$date":"2024-11-14T12:21:08.405+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":404986,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 5 through 6"}}}
{"t":{"$date":"2024-11-14T12:21:08.439+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":439230,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Recovering log 6 through 6"}}}
{"t":{"$date":"2024-11-14T12:21:08.467+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":467159,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery log replay has successfully finished and ran for 206 milliseconds"}}}
{"t":{"$date":"2024-11-14T12:21:08.467+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":467284,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global recovery timestamp: (0, 0)"}}}
{"t":{"$date":"2024-11-14T12:21:08.467+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":467325,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"Set global oldest timestamp: (0, 0)"}}}
{"t":{"$date":"2024-11-14T12:21:08.469+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":469539,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery rollback to stable has successfully finished and ran for 2 milliseconds"}}}
{"t":{"$date":"2024-11-14T12:21:08.472+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":472371,"thread":"1960:0x7f874710c180","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":7,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 69"}}}
{"t":{"$date":"2024-11-14T12:21:08.474+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":474064,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery checkpoint has successfully finished and ran for 4 milliseconds"}}}
{"t":{"$date":"2024-11-14T12:21:08.474+00:00"},"s":"I", "c":"WTRECOV", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":474119,"thread":"1960:0x7f874710c180","session_name":"txn-recover","category":"WT_VERB_RECOVERY_PROGRESS","category_id":34,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"recovery was completed successfully and took 213ms, including 206ms for the log replay, 2ms for the rollback to stable, and 4ms for the checkpoint."}}}
{"t":{"$date":"2024-11-14T12:21:08.476+00:00"},"s":"I", "c":"STORAGE", "id":4795906, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":349}}
{"t":{"$date":"2024-11-14T12:21:08.476+00:00"},"s":"I", "c":"RECOVERY", "id":23987, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}}
{"t":{"$date":"2024-11-14T12:21:08.484+00:00"},"s":"I", "c":"STORAGE", "id":7393203, "svc":"S", "ctx":"initandlisten","msg":"The size storer reports that the collection contains","attr":{"numRecords":221,"dataSize":85151}}
{"t":{"$date":"2024-11-14T12:21:08.484+00:00"},"s":"I", "c":"STORAGE", "id":7393212, "svc":"S", "ctx":"initandlisten","msg":"Scanning collection to determine where to place markers for truncation","attr":{"namespace":"local.oplog.rs"}}
{"t":{"$date":"2024-11-14T12:21:08.484+00:00"},"s":"I", "c":"STORAGE", "id":22382, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger record store oplog processing finished","attr":{"durationMillis":0}}
{"t":{"$date":"2024-11-14T12:21:08.515+00:00"},"s":"W", "c":"CONTROL", "id":22120, "svc":"S", "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted. You can use percona-server-mongodb-enable-auth.sh to fix it","tags":["startupWarnings"]}
{"t":{"$date":"2024-11-14T12:21:08.515+00:00"},"s":"W", "c":"CONTROL", "id":9068900, "svc":"S", "ctx":"initandlisten","msg":"For customers running the current memory allocator, we suggest changing the contents of the following sysfsFile","attr":{"allocator":"tcmalloc-google","sysfsFile":"/sys/kernel/mm/transparent_hugepage/defrag","currentValue":"madvise","desiredValue":"defer+madvise"},"tags":["startupWarnings"]}
{"t":{"$date":"2024-11-14T12:21:08.515+00:00"},"s":"W", "c":"CONTROL", "id":8640302, "svc":"S", "ctx":"initandlisten","msg":"We suggest setting the contents of sysfsFile to 0.","attr":{"sysfsFile":"/sys/kernel/mm/transparent_hugepage/khugepaged/max_ptes_none","currentValue":511},"tags":["startupWarnings"]}
{"t":{"$date":"2024-11-14T12:21:08.515+00:00"},"s":"W", "c":"NETWORK", "id":5123300, "svc":"S", "ctx":"initandlisten","msg":"vm.max_map_count is too low","attr":{"currentValue":262144,"recommendedMinimum":1677720,"maxConns":838860},"tags":["startupWarnings"]}
{"t":{"$date":"2024-11-14T12:21:08.515+00:00"},"s":"W", "c":"CONTROL", "id":8386700, "svc":"S", "ctx":"initandlisten","msg":"We suggest setting swappiness to 0 or 1, as swapping can cause performance problems.","attr":{"sysfsFile":"/proc/sys/vm/swappiness","currentValue":60},"tags":["startupWarnings"]}
{"t":{"$date":"2024-11-14T12:21:08.536+00:00"},"s":"I", "c":"NETWORK", "id":4915702, "svc":"S", "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":25},"outgoing":{"minWireVersion":6,"maxWireVersion":25},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":25},"incomingInternalClient":{"minWireVersion":25,"maxWireVersion":25},"outgoing":{"minWireVersion":25,"maxWireVersion":25},"isInternalClient":true}}}
{"t":{"$date":"2024-11-14T12:21:08.536+00:00"},"s":"I", "c":"REPL", "id":5853300, "svc":"S", "ctx":"initandlisten","msg":"current featureCompatibilityVersion value","attr":{"featureCompatibilityVersion":"8.0","context":"startup"}}
{"t":{"$date":"2024-11-14T12:21:08.536+00:00"},"s":"I", "c":"STORAGE", "id":5071100, "svc":"S", "ctx":"initandlisten","msg":"Clearing temp directory"}
{"t":{"$date":"2024-11-14T12:21:08.543+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"initandlisten","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.543+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"initandlisten","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.568+00:00"},"s":"I", "c":"CONTROL", "id":20536, "svc":"S", "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2024-11-14T12:21:08.568+00:00"},"s":"I", "c":"FTDC", "id":20625, "svc":"S", "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"/var/lib/mongo/diagnostic.data"}}
{"t":{"$date":"2024-11-14T12:21:08.571+00:00"},"s":"I", "c":"REPL", "id":40440, "svc":"S", "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
{"t":{"$date":"2024-11-14T12:21:08.571+00:00"},"s":"I", "c":"REPL", "id":40445, "svc":"S", "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"I", "c":"SHARDING", "id":22727, "svc":"-", "ctx":"ShardRegistryUpdater","msg":"Error running periodic reload of shard registry","attr":{"error":"NotYetInitialized: Config shard has not been set up yet","shardRegistryReloadIntervalSeconds":30}}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"I", "c":"SHARDING", "id":22072, "svc":"S", "ctx":"initandlisten","msg":"Initializing sharding state","attr":{"initialShardIdentity":{"shardName":"config","clusterId":{"$oid":"6735e9c5e890c2d6b11e2966"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"W", "c":"SHARDING", "id":7012500, "svc":"S", "ctx":"QueryAnalysisConfigurationsRefresher","msg":"Failed to refresh query analysis configurations, will try again at the next interval","attr":{"error":"NotYetInitialized: Config shard has not been set up yet"}}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"I", "c":"-", "id":4939300, "svc":"S", "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"ReadConcernMajorityNotAvailableYet: Read concern majority reads are currently not possible.","nextWakeupMillis":200}}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"I", "c":"SHARDING", "id":22071, "svc":"S", "ctx":"initandlisten","msg":"Finished initializing sharding components","attr":{"memberState":"secondary"}}
{"t":{"$date":"2024-11-14T12:21:08.573+00:00"},"s":"I", "c":"SHARDING", "id":22081, "svc":"S", "ctx":"initandlisten","msg":"Sharding status of the node recovered successfully","attr":{"role":"6735e9c5e890c2d6b11e2966 : ClusterRole{shard|config|router} : rscfg/rscfg01:27017 : config"}}
{"t":{"$date":"2024-11-14T12:21:08.574+00:00"},"s":"I", "c":"REPL", "id":6015317, "svc":"S", "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigStartingUp","oldState":"ConfigPreStart"}}
{"t":{"$date":"2024-11-14T12:21:08.574+00:00"},"s":"I", "c":"REPL", "id":6005300, "svc":"S", "ctx":"initandlisten","msg":"Starting up replica set aware services"}
{"t":{"$date":"2024-11-14T12:21:08.575+00:00"},"s":"I", "c":"REPL", "id":4280500, "svc":"S", "ctx":"initandlisten","msg":"Attempting to create internal replication collections"}
{"t":{"$date":"2024-11-14T12:21:08.577+00:00"},"s":"I", "c":"REPL", "id":4280501, "svc":"S", "ctx":"initandlisten","msg":"Attempting to load local voted for document"}
{"t":{"$date":"2024-11-14T12:21:08.577+00:00"},"s":"I", "c":"REPL", "id":21311, "svc":"S", "ctx":"initandlisten","msg":"Did not find local initialized voted for document at startup"}
{"t":{"$date":"2024-11-14T12:21:08.577+00:00"},"s":"I", "c":"REPL", "id":4280502, "svc":"S", "ctx":"initandlisten","msg":"Searching for local Rollback ID document"}
{"t":{"$date":"2024-11-14T12:21:08.579+00:00"},"s":"I", "c":"REPL", "id":21529, "svc":"S", "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":1}}
{"t":{"$date":"2024-11-14T12:21:08.579+00:00"},"s":"I", "c":"REPL", "id":4280504, "svc":"S", "ctx":"initandlisten","msg":"Cleaning up any partially applied oplog batches & reading last op from oplog"}
{"t":{"$date":"2024-11-14T12:21:08.579+00:00"},"s":"I", "c":"SHARDING", "id":22072, "svc":"S", "ctx":"initandlisten","msg":"Initializing sharding state","attr":{"initialShardIdentity":{"shardName":"config","clusterId":{"$oid":"6735e9c5e890c2d6b11e2966"},"configsvrConnectionString":"rscfg/rscfg01:27017"}}}
{"t":{"$date":"2024-11-14T12:21:08.580+00:00"},"s":"I", "c":"CONTROL", "id":6608200, "svc":"S", "ctx":"initandlisten","msg":"Initializing cluster server parameters from disk"}
{"t":{"$date":"2024-11-14T12:21:08.581+00:00"},"s":"I", "c":"REPL", "id":21546, "svc":"S", "ctx":"initandlisten","msg":"Recovering from an unstable checkpoint","attr":{"topOfOplog":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"appliedThrough":{"ts":{"$timestamp":{"t":0,"i":0}},"t":-1}}}
{"t":{"$date":"2024-11-14T12:21:08.581+00:00"},"s":"I", "c":"REPL", "id":21547, "svc":"S", "ctx":"initandlisten","msg":"No oplog entries to apply for recovery. appliedThrough is null"}
{"t":{"$date":"2024-11-14T12:21:08.583+00:00"},"s":"I", "c":"WTCHKPT", "id":22430, "svc":"S", "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":{"ts_sec":1731586868,"ts_usec":582999,"thread":"1960:0x7f874710c180","session_name":"WT_SESSION.checkpoint","category":"WT_VERB_CHECKPOINT_PROGRESS","category_id":7,"verbose_level":"DEBUG_1","verbose_level_id":1,"msg":"saving checkpoint snapshot min: 103, snapshot max: 103 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 69"}}}
{"t":{"$date":"2024-11-14T12:21:08.585+00:00"},"s":"I", "c":"REPL", "id":4280505, "svc":"S", "ctx":"initandlisten","msg":"Creating any necessary TenantMigrationAccessBlockers for unfinished migrations"}
{"t":{"$date":"2024-11-14T12:21:08.585+00:00"},"s":"I", "c":"TENANT_M", "id":6531504, "svc":"S", "ctx":"initandlisten","msg":"Clearing serverless operation lock registry on shutdown","attr":{"ns":null}}
{"t":{"$date":"2024-11-14T12:21:08.586+00:00"},"s":"I", "c":"REPL", "id":4280506, "svc":"S", "ctx":"initandlisten","msg":"Reconstructing prepared transactions"}
{"t":{"$date":"2024-11-14T12:21:08.586+00:00"},"s":"I", "c":"REPL", "id":4280507, "svc":"S", "ctx":"initandlisten","msg":"Loaded replica set config, scheduled callback to set local config"}
{"t":{"$date":"2024-11-14T12:21:08.586+00:00"},"s":"I", "c":"REPL", "id":4280508, "svc":"S", "ctx":"ReplCoord-0","msg":"Attempting to set local replica set config; validating config for startup"}
{"t":{"$date":"2024-11-14T12:21:08.586+00:00"},"s":"I", "c":"STORAGE", "id":22262, "svc":"S", "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"STORAGE", "id":7333401, "svc":"S", "ctx":"initandlisten","msg":"Starting the DiskSpaceMonitor"}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"QUERY", "id":7080100, "svc":"-", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Starting Change Stream Expired Pre-images Remover thread"}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"-", "id":7658604, "svc":"S", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Decided on initial creation method for pre-images truncate markers initialization","attr":{"initialCreationMethod":"emptyCollection","dataSize":0,"numRecords":0,"preImagesCollectionUUID":{"uuid":{"$uuid":"1b4941b8-a5d0-4e08-89e5-954413332dfc"}},"tenantId":null}}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"NETWORK", "id":23015, "svc":"-", "ctx":"listener","msg":"Listening on","attr":{"address":"/tmp/mongodb-27550.sock"}}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"NETWORK", "id":23015, "svc":"-", "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"NETWORK", "id":23016, "svc":"-", "ctx":"listener","msg":"Waiting for connections","attr":{"port":27550,"ssl":"off"}}
{"t":{"$date":"2024-11-14T12:21:08.587+00:00"},"s":"I", "c":"CONTROL", "id":8423403, "svc":"S", "ctx":"initandlisten","msg":"mongod startup complete","attr":{"Summary of time elapsed":{"Startup from clean shutdown?":true,"Statistics":{"Set up periodic runner":"0 ms","Set up online certificate status protocol manager":"0 ms","Transport layer setup":"0 ms","Run initial syncer crash recovery":"0 ms","Create storage engine lock file in the data directory":"0 ms","Get metadata describing storage engine":"0 ms","Validate options in metadata against current startup options":"0 ms","Create storage engine":"379 ms","Write current PID to file":"0 ms","Write a new metadata for storage engine":"0 ms","Initialize FCV before rebuilding indexes":"21 ms","Drop abandoned idents and get back indexes that need to be rebuilt or builds that need to be restarted":"0 ms","Rebuild indexes for collections":"0 ms","Build user and roles graph":"0 ms","Verify indexes for admin.system.users collection":"0 ms","Verify indexes for admin.system.roles collection":"0 ms","Set up the background thread pool responsible for waiting for opTimes to be majority committed":"0 ms","Initialize the sharding components for a config server":"2 ms","Initialize information needed to make a mongod instance shard aware":"0 ms","Load global settings from config server":"0 ms","Start up the replication coordinator":"13 ms","Create an oplog view for tenant migrations":"0 ms","Ensure the change stream collections on startup contain consistent data":"0 ms","Write startup options to the audit log":"0 ms","Start transport layer":"0 ms","_initAndListen total elapsed time":"461 ms"}}}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47878","uuid":{"uuid":{"$uuid":"0a38778e-2ee9-4fdb-b398-4e928d719c22"}},"connectionId":2,"connectionCount":1}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn2","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"-", "id":9023600, "svc":"S", "ctx":"ChangeStreamExpiredPreImagesRemover","msg":"Completed initialization of pre-image tenant truncate markers","attr":{"preImagesCollectionUUID":{"uuid":{"$uuid":"1b4941b8-a5d0-4e08-89e5-954413332dfc"}},"tenantId":null}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":4280509, "svc":"S", "ctx":"ReplCoord-0","msg":"Local configuration validated for startup"}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":6015317, "svc":"S", "ctx":"ReplCoord-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigStartingUp"}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"SHARDING", "id":7063400, "svc":"S", "ctx":"ReplCoord-0","msg":"Updating implicit default writeConcern majority","attr":{"newImplicitDefaultWCMajority":true}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"NETWORK", "id":22944, "svc":"S", "ctx":"conn2","msg":"Connection ended","attr":{"remote":"127.0.0.1:47878","uuid":{"uuid":{"$uuid":"0a38778e-2ee9-4fdb-b398-4e928d719c22"}},"connectionId":2,"connectionCount":0}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21392, "svc":"S", "ctx":"ReplCoord-0","msg":"New replica set config in use","attr":{"config":{"_id":"rscfg","version":1,"members":[{"_id":0,"host":"localhost:27550","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1,"tags":{},"secondaryDelaySecs":0,"votes":1}],"configsvr":true,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0}}}}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21393, "svc":"S", "ctx":"ReplCoord-0","msg":"Found self in config","attr":{"hostAndPort":"localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"STARTUP2","oldState":"STARTUP"}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21827, "svc":"S", "ctx":"ReplCoord-0","msg":"Updating term","attr":{"oldTerm":0,"newTerm":1}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21320, "svc":"S", "ctx":"ReplCoord-0","msg":"Updated term","attr":{"term":1}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"NETWORK", "id":4603701, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting Replica Set Monitor","attr":{"protocol":"streamable","uri":"rscfg/localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"-", "id":4333223, "svc":"S", "ctx":"ReplCoord-0","msg":"RSM now monitoring replica set","attr":{"replicaSet":"rscfg","nReplicaSetMembers":1}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"-", "id":4333226, "svc":"S", "ctx":"ReplCoord-0","msg":"RSM host was added to the topology","attr":{"replicaSet":"rscfg","host":"localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"REPL", "id":21306, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication storage threads"}
{"t":{"$date":"2024-11-14T12:21:08.588+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Connecting","attr":{"hostAndPort":"localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47890","uuid":{"uuid":{"$uuid":"2a0b8eac-70e1-469d-9297-2f927823d949"}},"connectionId":4,"connectionCount":1}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"REPL", "id":4280512, "svc":"S", "ctx":"ReplCoord-0","msg":"No initial sync required. Attempting to begin steady replication","attr":{"lastOpTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"isInitialSyncFlagSet":false}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"STARTUP2"}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"STORAGE", "id":20320, "svc":"S", "ctx":"ReplCoord-0","msg":"createCollection","attr":{"namespace":"local.replset.initialSyncId","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"87132261-cbef-4203-b060-8507d81031f3"}},"options":{}}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn4","msg":"client metadata","attr":{"remote":"127.0.0.1:47890","client":"conn4","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ReplicaSetMonitor-TaskExecutor","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"NETWORK", "id":23729, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"ServerPingMonitor is now monitoring host","attr":{"host":"localhost:27550","replicaSet":"rscfg"}}
{"t":{"$date":"2024-11-14T12:21:08.589+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"b2d810b9-9bd9-44c9-8fe8-187299ac0eb4","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":2},"roundTripTime":398,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSOther","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-14T12:21:08.589Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"5bbc0429-0ed9-4234-ae1e-b5c06014d22e","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","type":"Unknown","minWireVersion":0,"maxWireVersion":0,"lastUpdateTime":{"$date":{"$numberLong":"-9223372036854775808"}},"hosts":{},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true}}}
{"t":{"$date":"2024-11-14T12:21:08.590+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47902","uuid":{"uuid":{"$uuid":"344dbce1-095a-4664-a5fd-c2b05c25a4b4"}},"connectionId":5,"connectionCount":2}}
{"t":{"$date":"2024-11-14T12:21:08.590+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn5","msg":"client metadata","attr":{"remote":"127.0.0.1:47902","client":"conn5","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ReplicaSetMonitor-TaskExecutor","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}}
{"t":{"$date":"2024-11-14T12:21:08.590+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn4","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}}
{"t":{"$date":"2024-11-14T12:21:08.592+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47916","uuid":{"uuid":{"$uuid":"d93d14a3-fcb2-4398-b5cf-83bf58b4f93d"}},"connectionId":7,"connectionCount":3}}
{"t":{"$date":"2024-11-14T12:21:08.592+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn7","msg":"client metadata","attr":{"remote":"127.0.0.1:47916","client":"conn7","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.22.9","env":{"container":{"runtime":"docker"}}}}}
{"t":{"$date":"2024-11-14T12:21:08.592+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47918","uuid":{"uuid":{"$uuid":"61e882cc-b382-49bc-a5a2-d1307e0214df"}},"connectionId":8,"connectionCount":4}}
{"t":{"$date":"2024-11-14T12:21:08.593+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47924","uuid":{"uuid":{"$uuid":"effff6f2-a43b-4346-8d12-1243f0dbfa84"}},"connectionId":9,"connectionCount":5}}
{"t":{"$date":"2024-11-14T12:21:08.593+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn8","msg":"client metadata","attr":{"remote":"127.0.0.1:47918","client":"conn8","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.22.9","env":{"container":{"runtime":"docker"}}}}}
{"t":{"$date":"2024-11-14T12:21:08.593+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn9","msg":"client metadata","attr":{"remote":"127.0.0.1:47924","client":"conn9","negotiatedCompressors":[],"doc":{"application":{"name":"pbm-physical-restore"},"driver":{"name":"mongo-go-driver","version":"1.16.0"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.22.9","env":{"container":{"runtime":"docker"}}}}}
{"t":{"$date":"2024-11-14T12:21:08.593+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn9","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"INDEX", "id":20345, "svc":"S", "ctx":"ReplCoord-0","msg":"Index build: done building","attr":{"buildUUID":null,"collectionUUID":{"uuid":{"$uuid":"87132261-cbef-4203-b060-8507d81031f3"}},"namespace":"local.replset.initialSyncId","index":"_id_","ident":"index-1-3359315161501178204","collectionIdent":"collection-0-3359315161501178204","commitTimestamp":null}}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":21299, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication fetcher thread"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":8569800, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication writer thread"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":21300, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication applier thread"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":21301, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting replication reporter thread"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":8543100, "svc":"S", "ctx":"OplogWriter-0","msg":"Starting oplog write"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":8423402, "svc":"S", "ctx":"BackgroundSync","msg":"Failed to select a sync source on the first attempt. Starting second attempt"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":21224, "svc":"S", "ctx":"OplogApplier-0","msg":"Starting oplog application"}
{"t":{"$date":"2024-11-14T12:21:08.594+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-0","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"RECOVERING"}}
{"t":{"$date":"2024-11-14T12:21:08.618+00:00"},"s":"I", "c":"ELECTION", "id":4615652, "svc":"S", "ctx":"ReplCoord-0","msg":"Starting an election, since we've seen no PRIMARY in election timeout period","attr":{"electionTimeoutPeriodMillis":10000}}
{"t":{"$date":"2024-11-14T12:21:08.618+00:00"},"s":"I", "c":"ELECTION", "id":21438, "svc":"S", "ctx":"ReplCoord-0","msg":"Conducting a dry run election to see if we could be elected","attr":{"currentTerm":1}}
{"t":{"$date":"2024-11-14T12:21:08.619+00:00"},"s":"I", "c":"REPL", "id":4280511, "svc":"S", "ctx":"ReplCoord-0","msg":"Set local replica set config"}
{"t":{"$date":"2024-11-14T12:21:08.619+00:00"},"s":"I", "c":"ELECTION", "id":21444, "svc":"S", "ctx":"ReplCoord-1","msg":"Dry election run succeeded, running for election","attr":{"newTerm":2}}
{"t":{"$date":"2024-11-14T12:21:08.619+00:00"},"s":"I", "c":"REPL", "id":21827, "svc":"S", "ctx":"ReplCoord-1","msg":"Updating term","attr":{"oldTerm":1,"newTerm":2}}
{"t":{"$date":"2024-11-14T12:21:08.619+00:00"},"s":"I", "c":"ELECTION", "id":6015300, "svc":"S", "ctx":"ReplCoord-1","msg":"Storing last vote document in local storage for my election","attr":{"lastVote":{"term":2,"candidateIndex":0}}}
{"t":{"$date":"2024-11-14T12:21:08.619+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"cc3b04a2-c3d3-4e47-9866-3560a1000e96","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":3},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-14T12:21:08.619Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"5215ec59-a963-4492-8f6e-8aa90dd6f239","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":2},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSOther","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-14T12:21:08.590Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"setName":"rscfg","compatible":true}}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"ELECTION", "id":21450, "svc":"S", "ctx":"ReplCoord-1","msg":"Election succeeded, assuming primary role","attr":{"term":2}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21358, "svc":"S", "ctx":"ReplCoord-1","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47928","uuid":{"uuid":{"$uuid":"600554f1-3898-4c1d-ac67-044b555c01fb"}},"connectionId":11,"connectionCount":6}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21106, "svc":"S", "ctx":"ReplCoord-1","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21359, "svc":"S", "ctx":"ReplCoord-1","msg":"Entering primary catch-up mode"}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":6015304, "svc":"S", "ctx":"ReplCoord-1","msg":"Skipping primary catchup since we are the only node in the replica set."}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21363, "svc":"S", "ctx":"ReplCoord-1","msg":"Exited primary catch-up mode"}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21107, "svc":"S", "ctx":"ReplCoord-1","msg":"Stopping replication producer"}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn11","msg":"client metadata","attr":{"remote":"127.0.0.1:47928","client":"conn11","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ShardRegistry","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"8f81ea80-468c-4145-a092-490f60837118","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":4},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:27550","lastUpdateTime":{"$date":"2024-11-14T12:21:08.620Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true},"previousTopologyDescription":{"id":"cc3b04a2-c3d3-4e47-9866-3560a1000e96","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":3},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"lastUpdateTime":{"$date":"2024-11-14T12:21:08.619Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true}}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":8938402, "svc":"S", "ctx":"OplogWriter-0","msg":"Oplog writer buffer has been drained","attr":{"term":2}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21239, "svc":"S", "ctx":"ReplBatcher","msg":"Oplog applier buffer has been drained","attr":{"term":2}}
{"t":{"$date":"2024-11-14T12:21:08.620+00:00"},"s":"I", "c":"REPL", "id":21239, "svc":"S", "ctx":"ReplBatcher","msg":"Oplog applier buffer has been drained","attr":{"term":2}}
{"t":{"$date":"2024-11-14T12:21:08.621+00:00"},"s":"I", "c":"REPL", "id":21343, "svc":"S", "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"}
{"t":{"$date":"2024-11-14T12:21:08.621+00:00"},"s":"I", "c":"REPL", "id":21344, "svc":"S", "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"}
{"t":{"$date":"2024-11-14T12:21:08.621+00:00"},"s":"I", "c":"REPL", "id":21340, "svc":"S", "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","totalOpsKilled":0,"totalOpsRunning":6}}}
{"t":{"$date":"2024-11-14T12:21:08.621+00:00"},"s":"I", "c":"REPL", "id":6015310, "svc":"S", "ctx":"OplogApplier-0","msg":"Starting to transition to primary."}
{"t":{"$date":"2024-11-14T12:21:08.621+00:00"},"s":"I", "c":"REPL", "id":6015309, "svc":"S", "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"I", "c":"COMMAND", "id":5324200, "svc":"S", "ctx":"OplogApplier-0","msg":"CMD: collMod","attr":{"cmdObj":{"collMod":"settings","validator":{"$jsonSchema":{"oneOf":[{"properties":{"_id":{"enum":["balancer"]},"mode":{"enum":["full","off"]},"stopped":{"bsonType":"bool"},"activeWindow":{"bsonType":"object","required":["start","stop"]},"_secondaryThrottle":{"oneOf":[{"bsonType":"bool"},{"bsonType":"object"}]},"_waitForDelete":{"bsonType":"bool"},"attemptToBalanceJumboChunks":{"bsonType":"bool"}},"additionalProperties":false},{"properties":{"_id":{"enum":["chunksize"]},"value":{"bsonType":"number","minimum":1,"maximum":1024}},"additionalProperties":false},{"properties":{"_id":{"enum":["automerge","ReadWriteConcernDefaults","audit"]}}}]}},"validationLevel":"strict"}}}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"W", "c":"QUERY", "id":3216000, "svc":"S", "ctx":"OplogApplier-0","msg":"$jsonSchema validator does not allow '_id' field. This validator will reject all documents, consider adding '_id' to the allowed fields."}
{"t":{"$date":"2024-11-14T12:21:08.622+00:00"},"s":"I", "c":"REPL", "id":7360104, "svc":"S", "ctx":"OplogApplier-0","msg":"Wrote oplog entry for collMod","attr":{"namespace":"config.$cmd","uuid":{"uuid":{"$uuid":"36d2d8f1-e1b7-409d-ac69-1785039ed7c8"}},"opTime":{"ts":{"$timestamp":{"t":1731586868,"i":3}},"t":2},"object":{"collMod":"settings","validator":{"$jsonSchema":{"oneOf":[{"properties":{"_id":{"enum":["balancer"]},"mode":{"enum":["full","off"]},"stopped":{"bsonType":"bool"},"activeWindow":{"bsonType":"object","required":["start","stop"]},"_secondaryThrottle":{"oneOf":[{"bsonType":"bool"},{"bsonType":"object"}]},"_waitForDelete":{"bsonType":"bool"},"attemptToBalanceJumboChunks":{"bsonType":"bool"}},"additionalProperties":false},{"properties":{"_id":{"enum":["chunksize"]},"value":{"bsonType":"number","minimum":1,"maximum":1024}},"additionalProperties":false},{"properties":{"_id":{"enum":["automerge","ReadWriteConcernDefaults","audit"]}}}]}},"validationLevel":"strict"}}}
{"t":{"$date":"2024-11-14T12:21:08.624+00:00"},"s":"I", "c":"SHARDING", "id":22049, "svc":"S", "ctx":"PeriodicShardedIndexConsistencyChecker","msg":"Checking consistency of sharded collection indexes across the cluster"}
{"t":{"$date":"2024-11-14T12:21:08.625+00:00"},"s":"I", "c":"STORAGE", "id":20657, "svc":"S", "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"}
{"t":{"$date":"2024-11-14T12:21:08.626+00:00"},"s":"I", "c":"-", "id":4939300, "svc":"S", "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"ReadConcernMajorityNotAvailableYet: Read concern majority reads are currently not possible.","nextWakeupMillis":400}}
{"t":{"$date":"2024-11-14T12:21:08.626+00:00"},"s":"I", "c":"-", "id":8025900, "svc":"S", "ctx":"OplogApplier-0","msg":"ReplicaSetAwareServiceRegistry::onStepUpComplete stepping up all services"}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"STORAGE", "id":7508300, "svc":"S", "ctx":"IndexBuildsCoordinator-StepUp","msg":"Finished performing asynchronous step-up checks on index builds"}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"SHARDING", "id":21856, "svc":"S", "ctx":"Balancer","msg":"CSRS balancer is starting"}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"RDELETER", "id":6834800, "svc":"S", "ctx":"ResubmitRangeDeletionsOnStepUp","msg":"Resubmitting range deletion tasks"}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"REPL", "id":21331, "svc":"S", "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted","attr":{"term":2}}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"REPL", "id":6015306, "svc":"S", "ctx":"OplogApplier-0","msg":"Applier already left draining state, exiting."}
{"t":{"$date":"2024-11-14T12:21:08.627+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47944","uuid":{"uuid":{"$uuid":"2c509f47-e06d-4819-b3be-e2a2e5baca4c"}},"connectionId":13,"connectionCount":7}}
{"t":{"$date":"2024-11-14T12:21:08.628+00:00"},"s":"I", "c":"NETWORK", "id":4333213, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM Topology Change","attr":{"replicaSet":"rscfg","newTopologyDescription":{"id":"4565e91d-a42e-4bb6-a4c5-90c43af4ac5c","topologyType":"ReplicaSetWithPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":5},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:21:08.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586868,"i":4}},"t":2},"type":"RSPrimary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:27550","lastUpdateTime":{"$date":"2024-11-14T12:21:08.628Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true,"maxElectionIdSetVersion":{"electionId":{"$oid":"7fffffff0000000000000002"},"setVersion":1}},"previousTopologyDescription":{"id":"8f81ea80-468c-4145-a092-490f60837118","topologyType":"ReplicaSetNoPrimary","servers":{"localhost:27550":{"address":"localhost:27550","topologyVersion":{"processId":{"$oid":"6735eb3490d973a4ff1d9019"},"counter":4},"roundTripTime":453,"lastWriteDate":{"$date":"2024-11-14T12:15:21.000Z"},"opTime":{"ts":{"$timestamp":{"t":1731586521,"i":5}},"t":1},"type":"RSSecondary","minWireVersion":25,"maxWireVersion":25,"me":"localhost:27550","setName":"rscfg","setVersion":1,"electionId":{"$oid":"7fffffff0000000000000002"},"primary":"localhost:27550","lastUpdateTime":{"$date":"2024-11-14T12:21:08.620Z"},"logicalSessionTimeoutMinutes":30,"hosts":{"0":"localhost:27550"},"arbiters":{},"passives":{}}},"logicalSessionTimeoutMinutes":30,"setName":"rscfg","compatible":true}}}
{"t":{"$date":"2024-11-14T12:21:08.628+00:00"},"s":"I", "c":"SHARDING", "id":471691, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Updating the shard registry with confirmed replica set","attr":{"connectionString":"rscfg/localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.628+00:00"},"s":"I", "c":"NETWORK", "id":6006301, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Replica set primary server change detected","attr":{"replicaSet":"rscfg","topologyType":"ReplicaSetWithPrimary","primary":"localhost:27550","durationMillis":39}}
{"t":{"$date":"2024-11-14T12:21:08.628+00:00"},"s":"I", "c":"SHARDING", "id":22068, "svc":"-", "ctx":"Sharding-Fixed-3","msg":"Updating shard identity config string with confirmed replica set","attr":{"connectionString":"rscfg/localhost:27550"}}
{"t":{"$date":"2024-11-14T12:21:08.629+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn13","msg":"client metadata","attr":{"remote":"127.0.0.1:47944","client":"conn13","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ShardRegistry","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}}
{"t":{"$date":"2024-11-14T12:21:08.629+00:00"},"s":"I", "c":"REPL", "id":6795400, "svc":"S", "ctx":"JournalFlusher","msg":"Advancing committed opTime to a new term","attr":{"newCommittedOpTime":{"ts":{"$timestamp":{"t":1731586868,"i":4}},"t":2},"newCommittedWallime":{"$date":"2024-11-14T12:21:08.624Z"},"oldTerm":-1}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"STORAGE", "id":22310, "svc":"S", "ctx":"JournalFlusher","msg":"Triggering the first stable checkpoint","attr":{"initialDataTimestamp":{"$timestamp":{"t":1731586521,"i":5}},"prevStableTimestamp":{"$timestamp":{"t":0,"i":0}},"currStableTimestamp":{"$timestamp":{"t":1731586868,"i":4}}}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"NETWORK", "id":22943, "svc":"-", "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:47960","uuid":{"uuid":{"$uuid":"4df275dd-55d1-47f1-bea2-733e9359e1cb"}},"connectionId":14,"connectionCount":8}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn11","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":9}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"REPL", "id":5123005, "svc":"S", "ctx":"ConfigsvrCoordinatorService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"ConfigsvrCoordinatorService"}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"TXN", "id":22452, "svc":"S", "ctx":"TransactionCoordinator","msg":"Need to resume coordinating commit for transactions with an in-progress two-phase commit/abort","attr":{"numPendingTransactions":0}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "svc":"S", "ctx":"conn13","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":1}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"REPL", "id":5123005, "svc":"S", "ctx":"MultiUpdateCoordinatorService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"MultiUpdateCoordinatorService"}}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"TXN", "id":22438, "svc":"-", "ctx":"Sharding-Fixed-2","msg":"Incoming coordinateCommit requests are now enabled"}
{"t":{"$date":"2024-11-14T12:21:08.630+00:00"},"s":"I", "c":"REPL", "id":5123005, "svc":"S", "ctx":"ReshardingDonorService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"ReshardingDonorService"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"NETWORK", "id":51800, "svc":"S", "ctx":"conn14","msg":"client metadata","attr":{"remote":"127.0.0.1:47960","client":"conn14","negotiatedCompressors":["snappy","zstd","zlib"],"doc":{"driver":{"name":"NetworkInterfaceTL-ShardRegistry","version":"8.0.1-1"},"os":{"type":"Linux","name":"Oracle Linux Server release 8.10","architecture":"x86_64","version":"Kernel 6.5.0-1025-azure"}}}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"REPL", "id":5123005, "svc":"S", "ctx":"RenameCollectionParticipantService-0","msg":"Rebuilding PrimaryOnlyService due to stepUp","attr":{"service":"RenameCollectionParticipantService"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"NETWORK", "id":4603701, "svc":"S", "ctx":"ShardRegistry-0","msg":"Starting Replica Set Monitor","attr":{"protocol":"streamable","uri":"rs1/rs101:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"-", "id":4333223, "svc":"S", "ctx":"ShardRegistry-0","msg":"RSM now monitoring replica set","attr":{"replicaSet":"rs1","nReplicaSetMembers":1}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"-", "id":4333226, "svc":"S", "ctx":"ShardRegistry-0","msg":"RSM host was added to the topology","attr":{"replicaSet":"rs1","host":"rs101:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.629+00:00"},"s":"E", "c":"WT", "id":22435, "svc":"S", "ctx":"BalancerStatsRegistry::asynchronousInitialization","msg":"WiredTiger error message","attr":{"error":2,"message":{"ts_sec":1731586868,"ts_usec":629905,"thread":"1960:0x7f86d3479700","session_name":"WT_SESSION.open_cursor","category":"WT_VERB_DEFAULT","category_id":12,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__posix_fs_size:422:/var/lib/mongo/collection-29-5060147328105201007.wt: file-size: stat","error_str":"No such file or directory","error_code":2}}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Connecting","attr":{"hostAndPort":"rs101:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"NETWORK", "id":4603701, "svc":"S", "ctx":"ShardRegistry-0","msg":"Starting Replica Set Monitor","attr":{"protocol":"streamable","uri":"rs2/rs201:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"-", "id":4333223, "svc":"S", "ctx":"ShardRegistry-0","msg":"RSM now monitoring replica set","attr":{"replicaSet":"rs2","nReplicaSetMembers":1}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"-", "id":4333226, "svc":"S", "ctx":"ShardRegistry-0","msg":"RSM host was added to the topology","attr":{"replicaSet":"rs2","host":"rs201:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"E", "c":"WT", "id":22435, "svc":"S", "ctx":"ResubmitRangeDeletionsOnStepUp","msg":"WiredTiger error message","attr":{"error":2,"message":{"ts_sec":1731586868,"ts_usec":631599,"thread":"1960:0x7f86d847e700","session_dhandle_name":"file:collection-29-5060147328105201007.wt","session_name":"WT_SESSION.open_cursor","category":"WT_VERB_DEFAULT","category_id":12,"verbose_level":"ERROR","verbose_level_id":-3,"msg":"__posix_open_file:924:/var/lib/mongo/collection-29-5060147328105201007.wt: handle-open: open","error_str":"No such file or directory","error_code":2}}}
{"t":{"$date":"2024-11-14T12:21:08.631+00:00"},"s":"I", "c":"CONNPOOL", "id":22576, "svc":"-", "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Connecting","attr":{"hostAndPort":"rs201:27017"}}
{"t":{"$date":"2024-11-14T12:21:08.632+00:00"},"s":"E", "c":"SHARDING", "id":6419600, "svc":"S", "ctx":"BalancerStatsRegistry::asynchronousInitialization","msg":"Failed to initialize BalancerStatsRegistry after stepUp","attr":{"error":"CursorNotFound: unable to open cursor at URI statistics:table:collection-29-5060147328105201007 for statistic: 2024. reason: No such file or directory"}}
{"t":{"$date":"2024-11-14T12:21:08.632+00:00"},"s":"F", "c":"STORAGE", "id":50883, "svc":"S", "ctx":"ResubmitRangeDeletionsOnStepUp","msg":"Cursor not found","attr":{"error":{"code":43,"codeName":"CursorNotFound","errmsg":"Failed to open a WiredTiger cursor. Reason: UnknownError: 2: No such file or directory, uri: table:collection-29-5060147328105201007, config: "}}}
{"t":{"$date":"2024-11-14T12:21:08.632+00:00"},"s":"F", "c":"ASSERT", "id":23091, "svc":"S", "ctx":"ResubmitRangeDeletionsOnStepUp","msg":"Fatal assertion","attr":{"msgid":50883,"file":"src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp","line":111}}
{"t":{"$date":"2024-11-14T12:21:08.632+00:00"},"s":"F", "c":"ASSERT", "id":23092, "svc":"S", "ctx":"ResubmitRangeDeletionsOnStepUp","msg":"\n\n***aborting after fassert() failure\n\n"}
|
Trivy
The following actions use a deprecated Node.js version and will be forced to run on node20: github/codeql-action/upload-sarif@v2. For more info: https://github.blog/changelog/2024-03-07-github-actions-all-actions-will-run-on-node20-instead-of-node16-by-default/
|
Trivy
CodeQL Action v2 will be deprecated on December 5th, 2024. Please update all occurrences of the CodeQL Action in your workflow files to v3. For more information, see https://github.blog/changelog/2024-01-12-code-scanning-deprecation-of-codeql-action-v2/
|