Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Automated dumps include generated column values #164

Open
dabico opened this issue Aug 15, 2023 · 2 comments · May be fixed by #271
Open

Automated dumps include generated column values #164

dabico opened this issue Aug 15, 2023 · 2 comments · May be fixed by #271
Assignees
@dabico
Labels
bug Something isn't working dumps Hosting and distribution of database dumps

Comments

@dabico
Copy link
Member

dabico commented Aug 15, 2023 •
edited
Loading

First observed in #124

The backups we automate through a dedicated service create dumps including the values of generated columns. Since we only use these types of columns in git_repo_metric, the dump will work up until those values need to be inserted, at which point the import process will raise an error. Not sure what exactly is causing this, since using the same configurations to dump manually does not lead to such an outcome. I'll take a look at the debug log of the backup service and see if that yields any insights.
@dabico dabico added the bug Something isn't working label Aug 15, 2023
@dabico dabico self-assigned this Aug 15, 2023
@dabico
Copy link
Member Author

dabico commented Aug 15, 2023

Log of the last backup run:

2023-08-15.00:00:00 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] Backup routines started time: 2023-08-15 00:00:00 UTC
+ case "${dbtype,,}" in
+ check_availability
+ var_false FALSE
+ '[' false = false ']'
+ case "$dbtype" in
+ counter=0
+ transform_file_var DB_PASS
+ local variables
++ echo DB_PASS
++ tr ' ' '\n'
+ variables=DB_PASS
+ for variable in $variables
+ '[' -v DB_PASS_FILE ']'
+ unset file_variable
+ unset variables
+ export MYSQL_PWD=Lugano2020
+ MYSQL_PWD=Lugano2020
+ mysqladmin -ugseadmin -P3306 -hgse-database status
+ backup_mysql
+ var_true TRUE
+ '[' true = true ']'
+ single_transaction=--single-transaction
+ var_true TRUE
+ '[' true = true ']'
+ stored_procedures=--routines
+ '[' gse = all ']'
++ echo gse
++ tr , '\n'
+ db_names=gse
++ echo gse
++ xargs
++ tr ' ' ,
+ print_debug 'Databases Found: gse'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:00 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] Databases Found: gse
+ var_true false
+ '[' false = true ']'
+ '[' false = yes ']'
+ print_debug 'Not splitting database dumps into their own files'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:00 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] Not splitting database dumps into their own files
+ prepare_dbbackup
++ date +%s
+ dbbackup_start_time=1692057600
++ date +%Y%m%d-%H%M%S
+ now=20230815-000000
++ date +%H:%M:%S
+ now_time=00:00:00
++ date +%Y-%m-%d
+ now_date=2023-08-15
+ ltarget=mysql_gse_gse-database
+ target=mysql_gse_gse-database_20230815-000000.sql
+ target=mysql_all_gse-database_20230815-000000.sql
+ ltarget=mysql_all_gse-database
+ compression
+ var_false TRUE
+ '[' true = false ']'
+ '[' true = no ']'
+ var_true ''
+ '[' '' = true ']'
+ '[' '' = yes ']'
+ case "${COMPRESSION,,}" in
+ compress_cmd='pigz -q -3 -p 256 '
+ compression_type=gzip
+ extension=.gz
+ dir_compress_cmd='pigz -q -3 -p 256 '
+ target_dir=mysql_all_gse-database_20230815-000000.sql
+ target=mysql_all_gse-database_20230815-000000.sql.gz
+ case "${CONTAINER_LOG_LEVEL,,}" in
+ '[' gzip = none ']'
+ compression_string='and compressing with '\''gzip:3'\'' with '\''256'\'' threads'
+ pre_dbbackup all
+ '[' -n '' ']'
+ '[' -d /assets/custom-scripts/pre ']'
+ '[' -d /assets/scripts/pre/ ']'
++ echo gse
++ xargs
++ tr ' ' ,
+ print_notice 'Dumping all MySQL / MariaDB databases: '\''gse'\'' and compressing with '\''gzip:3'\'' with '\''256'\'' threads'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:00 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Dumping all MySQL / MariaDB databases: 'gse' and compressing with 'gzip:3' with '256' threads
+ pigz -q -3 -p 256
++ echo gse
++ xargs
+ mysqldump --max-allowed-packet=512M -h gse-database -P 3306 -ugseadmin --single-transaction --routines --databases gse
mysqldump: Error: 'Access denied; you need (at least one of) the PROCESS privilege(s) for this operation' when trying to dump tablespaces
+ exit_code=0
+ check_exit_code mysql_all_gse-database_20230815-000000.sql.gz
+ print_debug 'DB Backup Exit Code is 0'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:47 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] DB Backup Exit Code is 0
+ case "${1}" in
+ case "${exit_code}" in
+ print_info 'DB Backup of '\''mysql_all_gse-database_20230815-000000.sql.gz'\'' completed successfully'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:47 [INFO] /etc/services.available/10-db-backup/run ** [db-backup] DB Backup of 'mysql_all_gse-database_20230815-000000.sql.gz' completed successfully
+ generate_checksum
+ var_true TRUE
+ '[' true = true ']'
+ '[' 0 = 0 ']'
+ case "${CHECKSUM,,}" in
+ checksum_command=sha1sum
+ checksum_extension=sha1
+ print_notice 'Generating SHA1 for '\''mysql_all_gse-database_20230815-000000.sql.gz'\'''
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:47 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Generating SHA1 for 'mysql_all_gse-database_20230815-000000.sql.gz'
+ cd /tmp/backups
+ sha1sum mysql_all_gse-database_20230815-000000.sql.gz
++ sha1sum mysql_all_gse-database_20230815-000000.sql.gz
++ awk ' { print $1}'
+ checksum_value=be21170bc111b1a94deecd6b7323a49e55ba068e
+ print_debug 'SHA1: be21170bc111b1a94deecd6b7323a49e55ba068e - mysql_all_gse-database_20230815-000000.sql.gz'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] SHA1: be21170bc111b1a94deecd6b7323a49e55ba068e - mysql_all_gse-database_20230815-000000.sql.gz
+ move_dbbackup
+ '[' 0 = 0 ']'
++ stat -c%s /tmp/backups/mysql_all_gse-database_20230815-000000.sql.gz
+ dbbackup_size=310764108
++ date -r /tmp/backups/mysql_all_gse-database_20230815-000000.sql.gz +%s
+ dbbackup_date=1692057647
+ case "${SIZE_VALUE,,}" in
+ SIZE_VALUE=1
+ '[' 1 = 1 ']'
++ stat -c%s /tmp/backups/mysql_all_gse-database_20230815-000000.sql.gz
+ filesize=310764108
+ print_notice 'Backup of mysql_all_gse-database_20230815-000000.sql.gz created with the size of 310764108 bytes'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Backup of mysql_all_gse-database_20230815-000000.sql.gz created with the size of 310764108 bytes
+ case "${BACKUP_LOCATION,,}" in
+ print_debug 'Moving backup to filesystem'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] Moving backup to filesystem
+ mkdir -p /backup
+ mv /tmp/backups/mysql_all_gse-database_20230815-000000.sql.gz.sha1 /backup/
+ mv /tmp/backups/mysql_all_gse-database_20230815-000000.sql.gz /backup/mysql_all_gse-database_20230815-000000.sql.gz
+ move_exit_code=0
+ var_true TRUE
+ '[' true = true ']'
+ ln -sf /backup/mysql_all_gse-database_20230815-000000.sql.gz /backup/latest-mysql_all_gse-database
+ '[' -n '' ']'
+ rm -rf /tmp/backups/-transfer.log
+ check_exit_code move mysql_all_gse-database_20230815-000000.sql.gz
+ print_debug 'DB Backup Exit Code is 0'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] DB Backup Exit Code is 0
+ case "${1}" in
+ case "${move_exit_code}" in
+ print_debug 'Moving of backup '\''mysql_all_gse-database_20230815-000000.sql.gz'\'' completed successfully'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [DEBUG] /etc/services.available/10-db-backup/run ** [db-backup] Moving of backup 'mysql_all_gse-database_20230815-000000.sql.gz' completed successfully
+ case "${exit_code}" in
+ print_info 'DB Backup of '\''move'\'' completed successfully'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [INFO] /etc/services.available/10-db-backup/run ** [db-backup] DB Backup of 'move' completed successfully
+ post_dbbackup all
++ date +%s
+ dbbackup_finish_time=1692057649
++ echo 49
+ dbbackup_total_time=49
+ var_true false
+ '[' false = true ']'
+ '[' false = yes ']'
+ '[' -n '' ']'
+ '[' -d /assets/custom-scripts/ ']'
+ '[' -d /assets/scripts/post/ ']'
+ dir_notempty /assets/scripts/post/
++ ls -A /assets/scripts/post/
+ '[' -n '.keep
.upload-dump.sh' ']'
++ find /assets/scripts/post/ -name '*.sh' -type f
+ for f in $(find ${SCRIPT_LOCATION_POST} -name \*.sh -type f)
+ var_true ''
+ '[' '' = true ']'
+ '[' '' = yes ']'
+ '[' -x /assets/scripts/post/.upload-dump.sh ']'
+ print_notice 'Executing post backup custom script : '\''/assets/scripts/post/.upload-dump.sh'\'''
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:00:49 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Executing post backup custom script : '/assets/scripts/post/.upload-dump.sh'
+ /assets/scripts/post/.upload-dump.sh 0 mysql gse-database all 1692057600 1692057649 49 mysql_all_gse-database_20230815-000000.sql.gz 310764108 be21170bc111b1a94deecd6b7323a49e55ba068e 0
Compressing database backups into single archive...
tar: removing leading '/' from member names
backup/latest-mysql_all_gse-database
backup/mysql_all_gse-database_20230808-000001.sql.gz
backup/mysql_all_gse-database_20230808-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230809-000001.sql.gz
backup/mysql_all_gse-database_20230809-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230810-000001.sql.gz
backup/mysql_all_gse-database_20230810-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230811-000001.sql.gz
backup/mysql_all_gse-database_20230811-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230812-000001.sql.gz
backup/mysql_all_gse-database_20230812-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230813-000000.sql.gz
backup/mysql_all_gse-database_20230813-000000.sql.gz.sha1
backup/mysql_all_gse-database_20230814-000001.sql.gz
backup/mysql_all_gse-database_20230814-000001.sql.gz.sha1
backup/mysql_all_gse-database_20230815-000000.sql.gz
backup/mysql_all_gse-database_20230815-000000.sql.gz.sha1
Uploading database backups to bar.si.usi.ch... Done!
Performing post-transfer cleanup... Done!
++ echo 49
++ awk '{printf "Hours: %d Minutes: %02d Seconds: %02d", $1/3600, ($1/60)%60, $1%60}'
+ print_notice 'DB Backup for '\''all'\'' time taken: Hours: 0 Minutes: 00 Seconds: 49'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:02:43 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] DB Backup for 'all' time taken: Hours: 0 Minutes: 00 Seconds: 49
+ unset s3_ssl
+ unset s3_ca_cert
++ date +%s
+ backup_finish_time=1692057763
++ echo 163
+ backup_total_time=163
+ '[' -z 0 ']'
++ date -d @1692057763 '+%Y-%m-%d %T %Z'
+ print_info 'Backup routines finish time: 2023-08-15 00:02:43 UTC with overall exit code 0'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:02:43 [INFO] /etc/services.available/10-db-backup/run ** [db-backup] Backup routines finish time: 2023-08-15 00:02:43 UTC with overall exit code 0
++ echo 163
++ awk '{printf "Hours: %d Minutes: %02d Seconds: %02d", $1/3600, ($1/60)%60, $1%60}'
+ print_notice 'Backup routines time taken: Hours: 0 Minutes: 02 Seconds: 43'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:02:43 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Backup routines time taken: Hours: 0 Minutes: 02 Seconds: 43
+ cleanup_old_data
+ '[' -n 10080 ']'
+ '[' 0 '!=' 1 ']'
+ case "${BACKUP_LOCATION,,}" in
+ print_info 'Cleaning up old backups on filesystem'
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:02:43 [INFO] /etc/services.available/10-db-backup/run ** [db-backup] Cleaning up old backups on filesystem
+ mkdir -p /backup
+ find /backup/ -mmin +10080 -iname '*' -exec rm '{}' ';'
+ var_true ''
+ '[' '' = true ']'
+ '[' '' = yes ']'
+++ date +%s
++ date -d@1692144000 '+%Y-%m-%d %T %Z'
+ print_notice 'Sleeping for another 86237 seconds. Waking up at 2023-08-16 00:00:00 UTC '
+ output_off
+ '[' true = true ']'
+ set +x
2023-08-15.00:02:43 [NOTICE] /etc/services.available/10-db-backup/run ** [db-backup] Sleeping for another 86237 seconds. Waking up at 2023-08-16 00:00:00 UTC 
+ sleep 86237

Still not exactly sure where the problem is.

@dabico
Copy link
Member Author

dabico commented Dec 30, 2023

I've just now confirmed that this is an issue with MariaDB, which a lot of these automated database backup images use. See: databacker/mysql-backup#105

@dabico dabico linked a pull request Jan 2, 2024 that will close this issue
Draft
@dabico dabico added the dumps Hosting and distribution of database dumps label Jan 3, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@dabico dabico

Labels
bug Something isn't working dumps Hosting and distribution of database dumps
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Change Docker image for performing backups seart-group/ghs
1 participant
@dabico