Description
Affected Builds:
Observed consistently in builds onwards and including 3444 to 3468.
The issue is not observed in builds <= 3435
Description (Testing on build 3466):
It appears as if some stderr output is not being redirected to the logs.
(Pdb) p error
|
['2020-10-22T10:40:39.776+00:00 (Gocbcore) Attempted to start tracing on traced request']
|
The error is written to stderr and is not present in the logs (see attached backup-0.log).
Steps to reproduce:
Observed in testrunner in a test where a rebalance is started asynchronously followed by a 'cbbackupmgr backup' to s3.
2020-10-22 11:40:36,336 - root - INFO - running command.raw on 10.112.210.104: /opt/couchbase/bin//cbbackupmgr backup --archive s3://fce1af28-1452-11eb-9fa8-acde48001122/archive-10.112.210.101 --repo backup --cluster http://10.112.210.101:8091 --username Administrator --password password --obj-access-key-id asdf --obj-endpoint http://10.112.202.104:4572 --obj-region asdf --obj-secret-access-key asdf --obj-staging-dir /tmp/cbbackupmgr-staging --s3-force-path-style --no-progress-bar
|
|
(Pdb) p output
|
['Backed up to 2020-10-22T10_40_36.420585143Z', 'Copied all data in 44.782281852s (Avg. 4.30KB/Sec)', '1 buckets, 1000 items / 192.73KB', 'Backup successfully completed', 'Backed up bucket "default" succeeded', 'Mutations backed up: 1000, Mutations failed to backup: 0', 'Deletions backed up: 0, Deletions failed to backup: 0', 'Skipped due to purge number or conflict resolution: Mutations: 0 Deletions: 0']
|
(Pdb) p error
|
['2020-10-22T10:40:39.776+00:00 (Gocbcore) Attempted to start tracing on traced request']
|
(Pdb)
|
Additional testrunner stack traces from testrunner on 7.0.0-3455:
Traceback (most recent call last):
|
File "pytests/ent_backup_restore/enterprise_backup_restore_test.py", line 197, in test_backup_restore_with_rebalance
|
self.backup_cluster_validate()
|
File "pytests/ent_backup_restore/enterprise_backup_restore_base.py", line 638, in backup_cluster_validate
|
"\nErrors: {0} \nOutput: {1}".format(error, output))
|
AssertionError: Taking cluster backup failed. Check printout below.
|
Errors: ['2020-10-20T00:01:42.255-07:00 (Gocbcore) Attempted to start tracing on traced request', '2020-10-20T00:02:04.356-07:00 (Gocbcore) memdClient read failure: EOF']
|
Output: ['Backed up to 2020-10-20T00_01_40.29830585-07_00', 'Copied all data in 51.993788499s (Avg. 3.71KB/Sec)', '1 buckets, 1000 items / 192.82KB', 'Backup successfully completed', 'Backed up bucket "default" succeeded', 'Mutations backed up: 1000, Mutations failed to backup: 0', 'Deletions backed up: 0, Deletions failed to backup: 0', 'Skipped due to purge number or conflict resolution: Mutations: 0 Deletions: 0']
|
Traceback (most recent call last):
|
File "pytests/ent_backup_restore/enterprise_backup_restore_test.py", line 197, in test_backup_restore_with_rebalance
|
self.backup_cluster_validate()
|
File "pytests/ent_backup_restore/enterprise_backup_restore_base.py", line 638, in backup_cluster_validate
|
"\nErrors: {0} \nOutput: {1}".format(error, output))
|
AssertionError: Taking cluster backup failed. Check printout below.
|
Errors: ['2020-10-19T23:51:43.254-07:00 (Gocbcore) Attempted to start tracing on traced request']
|
Output: ['Backed up to 2020-10-19T23_51_41.665133572-07_00', 'Copied all data in 38.2248715s (Avg. 5.04KB/Sec)', '1 buckets, 1000 items / 192.83KB', 'Backup successfully completed', 'Backed up bucket "default" succeeded', 'Mutations backed up: 1000, Mutations failed to backup: 0', 'Deletions backed up: 0, Deletions failed to backup: 0', 'Skipped due to purge number or conflict resolution: Mutations: 0 Deletions: 0']
|