Asrestore issue while restoring data

Tools asbackup & asrestore
1

Hi team,

we are facing some issue while restoring data to a 3 node cluster. 2022-10-12 22:46:35 GMT [INF] [10272] Restoring s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00094.asb

2022-10-12 22:46:35 GMT [INF] [10272] Opened backup file s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00094.asb

2022-10-12 22:46:36 GMT [INF] [10270] Restoring s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00095.asb

2022-10-12 22:46:36 GMT [INF] [10270] Opened backup file s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00095.asb

2022-10-12 22:46:37 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 178632126 record(s) (10605 rec/s, 5006 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:46:37 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 178631312: failed 0 (existed 0 , fresher 0)

2022-10-12 22:46:37 GMT [INF] [10261] 59% complete, ~3h14m15s remaining

2022-10-12 22:46:42 GMT [INF] [10284] Restoring s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00096.asb

2022-10-12 22:46:42 GMT [INF] [10284] Opened backup file s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00096.asb

2022-10-12 22:46:47 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 178788704 record(s) (15632 rec/s, 7384 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:46:47 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 178787904: failed 0 (existed 0 , fresher 0)

2022-10-12 22:46:47 GMT [INF] [10261] 59% complete, ~2h11m32s remaining

2022-10-12 22:46:57 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 178890528 record(s) (10168 rec/s, 4798 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:46:57 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 178889696: failed 0 (existed 0 , fresher 0)

2022-10-12 22:46:57 GMT [INF] [10261] 59% complete, ~3h22m14s remaining

2022-10-12 22:47:07 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 178997402 record(s) (10653 rec/s, 5033 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:47:07 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 178996624: failed 0 (existed 0 , fresher 0)

2022-10-12 22:47:07 GMT [INF] [10261] 59% complete, ~3h12m38s remaining

2022-10-12 22:47:11 GMT [INF] [10276] Restoring s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00097.asb

2022-10-12 22:47:11 GMT [INF] [10276] Opened backup file s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00097.asb

2022-10-12 22:47:16 GMT [INF] [10277] Restoring s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00098.asb

2022-10-12 22:47:16 GMT [INF] [10277] Opened backup file s3://indus-staging-aerospike-backup/user-personas/2022/10/11/user-personas_00098.asb

2022-10-12 22:47:17 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179109815 record(s) (11218 rec/s, 5296 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:47:17 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179109024: failed 0 (existed 0 , fresher 0)

2022-10-12 22:47:17 GMT [INF] [10261] 59% complete, ~3h2m55s remaining

2022-10-12 22:47:27 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (6042 rec/s, 2855 KiB/s, 483 B/rec, retries: 0)

2022-10-12 22:47:27 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:47:27 GMT [INF] [10261] 59% complete, ~5h39m8s remaining

2022-10-12 22:47:37 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:47:37 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:47:47 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:47:47 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:47:57 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:47:57 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:07 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:07 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:17 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:17 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:27 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:27 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:37 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:37 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:47 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:47 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:48:57 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:48:57 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:49:07 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

2022-10-12 22:49:07 GMT [INF] [10261] Expired 0 : skipped 0 : err_ignored 0 : inserted 179170080: failed 0 (existed 0 , fresher 0)

2022-10-12 22:49:17 GMT [INF] [10261] 2 UDF file(s), 0 secondary index(es), 179170236 record(s) (0 rec/s, 0 KiB/s, 0 B/rec, retries: 0)

After 59% it stops restoring data and only these logs are available till end while restoring command still running

2

Does asbackup support restoring directly from S3? I didn’t know this was a feature! I wonder if it would change anything if you pulled them locally first? Do you know how many records are in the backup?

3

Hi albot, yes asbackup support restore directly from s3. The records was around 600M.

4

Have you tried pulling the file down to a machine before restoring instead of straight from s3? Could be that the connectivity gets dropped or there is some bug? Can you verify the file isn’t truncated or missing some data? You can count the number of records in a file by using something like grep -c '^+ d' myfiles*.asb which counts the number of digests in the file. What version is the server and asbackup? Are they the same versions as when the backup was taken?