borgmatic restore fails with "Error running actions for repository 'utf-8' codec can't decode byte 0xff in position 61: invalid start byte" #476

Closed
opened 2021-12-06 17:10:39 +00:00 by qupfer · 9 comments

What I'm trying to do and why

Hi all,

I have an docker-compose file for an wordpress setup, including borgmatic.
If I try to restore the database, it fails during the restore.

Somebody any Idea if I make an mistake or is their an bug in the sql-hook?

Thanks
Henning

docker-compose.yml

version: "3.9"
    
services:

  borgmatic:
    depends_on:
      - db
      - wordpress
    image: b3vis/borgmatic
    restart: always
    volumes:
      - /opt/wordpress:/mnt/source/wordpress:ro
      - mysql-socket-vol-1:/var/run/mysqld/:z
      - ./borgmatic/etc:/etc/borgmatic.d:Z
      - ./borgmatic/state:/root/.config/borg:Z
      - ./borgmatic/ssh:/root/.ssh:Z
    environment:
      - TZ=Europe/Berlin
      - BORG_PASSPHRASE=abcdefghijklmnopqrstuvwxyz
    networks:
      wordpress-network: 
      
  db:
    image: mariadb:latest
    volumes:
      - mysql-socket-vol-1:/var/run/mysqld/:z
      - ./db_data:/var/lib/mysql
    restart: always
    networks:
      wordpresss-network:
    environment:
      MYSQL_ROOT_PASSWORD: VerySecure
      MYSQL_DATABASE: wordpress
      MYSQL_USER: wordpress
      MYSQL_PASSWORD: VerySecureToo
[...]

config.yml

location:
    source_directories:
        - /mnt/source
    repositories:
        - username@borghost:./wordpress

storage:
    ssh_command: ssh -p12345
    archive_name_format: 'wordpres-{now:%Y-%m-%dT%H:%M:%S}'

consistency:
    prefix: "wordpres"

retention:
    keep_hourly: 24
    keep_daily: 7
    keep_weekly: 4
    keep_monthly: 6
    prefix: "wordpres"

hooks:
    mysql_databases:
        - name: wordpress
          username: wordpress
          password: VerySecure
          options: --default-character-set=utf8mb4

Steps to reproduce (if a bug)

running:

docker-compose exec borgmatic borgmatic  -v2 restore --archive latest  

Actual behavior (if a bug)

After some parts of the databse are restore, it fails with this error:

--------------
/*!40101 SET character_set_client = @saved_cs_client */
--------------
--------------
LOCK TABLES `wp_wfblockediplog` WRITE
--------------
--------------
/*!40000 ALTER TABLE `wp_wfblockediplog` DISABLE KEYS */
--------------
--------------
username@borghost:./wordpress: Error running actions for repository
'utf-8' codec can't decode byte 0xff in position 61: invalid start byte
/etc/borgmatic.d/config.yaml: Error running configuration file

summary:
/etc/borgmatic.d/config.yaml: Error running configuration file
username@borghost:./wordpress: Error running actions for repository
'utf-8' codec can't decode byte 0xff in position 61: invalid start byte

Need some help? https://torsion.org/borgmatic/#issues

Expected behavior (if a bug)

The borgmatic command works and return 0.

Other notes / implementation ideas

Coping the sql dump from the repo, and importing it on the db container via mysql -u root -pabcde < database.sql works.

Environment

borgmatic version: 1.5.18

borgmatic installation method: docker-compose

Borg version: borg 1.1.17
Python version: Python 3.8.10
Database version (if applicable): mysql Ver 15.1 Distrib 10.5.12-MariaDB, for Linux (x86_64) using readline 5.1
operating system and version:
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.13.6
PRETTY_NAME="Alpine Linux v3.13"
HOME_URL="https://alpinelinux.org/"
BUG_REPORT_URL="https://bugs.alpinelinux.org/"

#### What I'm trying to do and why Hi all, I have an docker-compose file for an wordpress setup, including borgmatic. If I try to restore the database, it fails during the restore. Somebody any Idea if I make an mistake or is their an bug in the sql-hook? Thanks Henning docker-compose.yml ``` version: "3.9" services: borgmatic: depends_on: - db - wordpress image: b3vis/borgmatic restart: always volumes: - /opt/wordpress:/mnt/source/wordpress:ro - mysql-socket-vol-1:/var/run/mysqld/:z - ./borgmatic/etc:/etc/borgmatic.d:Z - ./borgmatic/state:/root/.config/borg:Z - ./borgmatic/ssh:/root/.ssh:Z environment: - TZ=Europe/Berlin - BORG_PASSPHRASE=abcdefghijklmnopqrstuvwxyz networks: wordpress-network: db: image: mariadb:latest volumes: - mysql-socket-vol-1:/var/run/mysqld/:z - ./db_data:/var/lib/mysql restart: always networks: wordpresss-network: environment: MYSQL_ROOT_PASSWORD: VerySecure MYSQL_DATABASE: wordpress MYSQL_USER: wordpress MYSQL_PASSWORD: VerySecureToo [...] ``` config.yml ``` location: source_directories: - /mnt/source repositories: - username@borghost:./wordpress storage: ssh_command: ssh -p12345 archive_name_format: 'wordpres-{now:%Y-%m-%dT%H:%M:%S}' consistency: prefix: "wordpres" retention: keep_hourly: 24 keep_daily: 7 keep_weekly: 4 keep_monthly: 6 prefix: "wordpres" hooks: mysql_databases: - name: wordpress username: wordpress password: VerySecure options: --default-character-set=utf8mb4 ``` #### Steps to reproduce (if a bug) running: ``` docker-compose exec borgmatic borgmatic -v2 restore --archive latest ``` #### Actual behavior (if a bug) After some parts of the databse are restore, it fails with this error: ``` -------------- /*!40101 SET character_set_client = @saved_cs_client */ -------------- -------------- LOCK TABLES `wp_wfblockediplog` WRITE -------------- -------------- /*!40000 ALTER TABLE `wp_wfblockediplog` DISABLE KEYS */ -------------- -------------- username@borghost:./wordpress: Error running actions for repository 'utf-8' codec can't decode byte 0xff in position 61: invalid start byte /etc/borgmatic.d/config.yaml: Error running configuration file summary: /etc/borgmatic.d/config.yaml: Error running configuration file username@borghost:./wordpress: Error running actions for repository 'utf-8' codec can't decode byte 0xff in position 61: invalid start byte Need some help? https://torsion.org/borgmatic/#issues ``` #### Expected behavior (if a bug) The borgmatic command works and return 0. #### Other notes / implementation ideas Coping the sql dump from the repo, and importing it on the db container via `mysql -u root -pabcde < database.sql` works. #### Environment **borgmatic version:** 1.5.18 **borgmatic installation method:** docker-compose **Borg version:** borg 1.1.17 **Python version:** Python 3.8.10 **Database version (if applicable):** mysql Ver 15.1 Distrib 10.5.12-MariaDB, for Linux (x86_64) using readline 5.1 **operating system and version:** NAME="Alpine Linux" ID=alpine VERSION_ID=3.13.6 PRETTY_NAME="Alpine Linux v3.13" HOME_URL="https://alpinelinux.org/" BUG_REPORT_URL="https://bugs.alpinelinux.org/"
Owner

Thank you for taking the time to report this! The error message has the look of a Python unicode error, but based on this output, I can't currently pinpoint where it's occurring or reproduce the issue. My guess, based on your MySQL options (--default-character-set=utf8mb4), is that MariaDB is outputting some text in a character encoding that borgmatic is misinterpreting.

Would it be possible for you to provide a santized version of your database in which this issue is occurring? Even something with all or most of the values removed, assuming that still produces the same issue with borgmatic. Thanks!

Thank you for taking the time to report this! The error message has the look of a Python unicode error, but based on this output, I can't currently pinpoint where it's occurring or reproduce the issue. My guess, based on your MySQL options (`--default-character-set=utf8mb4`), is that MariaDB is outputting some text in a character encoding that borgmatic is misinterpreting. Would it be possible for you to provide a santized version of your database in which this issue is occurring? Even something with all or most of the values removed, assuming that still produces the same issue with borgmatic. Thanks!
witten added the
bug
label 2021-12-06 18:55:57 +00:00
Author

Thanks for your quick response. I will try tomorrow to create a sanitized version of the sql database.

Thanks for your quick response. I will try tomorrow to create a sanitized version of the sql database.
Author

I'm new to databases, so if I do something wrong (reomove to mutch, make in invalid or stuff like that) please tell and give me a hint :-)

I removed all before and after the position there it fails.

It looks like the "bad" part is this

INSERT INTO `wp_wfblockediplog` VALUES ('\0\0\0\0\0\0\0\0\0\0ÿÿl˜y','GB',2,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ–Â7','US',1,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ\"{},','US',1,18968,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ#ÇC','BE',2,18965,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ.¡Ž','RU',5,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ.¡Ž','RU',1,18968,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ6úg»','JP',1,18968,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿBs­','US',1,18962,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿCÍ2','US',1,18962,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿl£éj','US',4,18965,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ‹¢ý','SG',1,18963,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ°¥\"	','FR',3,18967,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ¯×','IR',1,18962,'waf'),('*øÀt9\0\0\0\0\0\0\0','DE',4,18965,'waf'),('*  \'D\0\0\0\0\0\0\0','DE',1,18968,'waf');
I'm new to databases, so if I do something wrong (reomove to mutch, make in invalid or stuff like that) please tell and give me a hint :-) I removed all before and after the position there it fails. It looks like the "bad" part is this ``` INSERT INTO `wp_wfblockediplog` VALUES ('\0\0\0\0\0\0\0\0\0\0ÿÿl˜y','GB',2,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ–Â7','US',1,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ\"{},','US',1,18968,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ#ÇC','BE',2,18965,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ.¡Ž','RU',5,18964,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ.¡Ž','RU',1,18968,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ6úg»','JP',1,18968,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿBs­','US',1,18962,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿCÍ2','US',1,18962,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿl£éj','US',4,18965,'waf'),('\0\0\0\0\0\0\0\0\0\0ÿÿ‹¢ý','SG',1,18963,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ°¥\" ','FR',3,18967,'brute'),('\0\0\0\0\0\0\0\0\0\0ÿÿ¯×','IR',1,18962,'waf'),('*øÀt9\0\0\0\0\0\0\0','DE',4,18965,'waf'),('* \'D\0\0\0\0\0\0\0','DE',1,18968,'waf'); ```
Owner

Thank you! I've been trying to reproduce this, and thus far I've gotten no repro when running MariaDB via Docker (with the restored "problem" data) and borgmatic running on my host. So now I'm trying to run everything in Compose as per your example. Can I get a look at the portions of your Compose file that define both the wordpress_network and the mysql-socket-vol-1? Appreciate it.

Thank you! I've been trying to reproduce this, and thus far I've gotten no repro when running MariaDB via Docker (with the restored "problem" data) and borgmatic running on my host. So now I'm trying to run everything in Compose as per your example. Can I get a look at the portions of your Compose file that define both the `wordpress_network` and the `mysql-socket-vol-1`? Appreciate it.
Author

Hi, both things are only for nicer naming :-)

volumes:
  mysql-socket-vol-1:

networks:
  wordpresss-network:
    driver: bridge                                                                                      
    driver_opts:
      com.docker.network.bridge.name: br-wordpress

However, it looks I used the "wrong" backup for posting. Sorry :-(
I add a new "dump" and also an full docker-compose project, including an repo which fails.
Due the "large" db_data part, it can not be uploaded here, but you can find download it: https://07q.de/data/borg.tar.xz (a bit slow, but should work)

Extract and just run (I hope, I removed all absolute paths):
docker-compose up -d
docker-compose exec borgmatic borgmatic restore -v2 --archive latest

Passwords are in the docker-compose.yml or config.yml files.

Hi, both things are only for nicer naming :-) ``` volumes: mysql-socket-vol-1: networks: wordpresss-network: driver: bridge driver_opts: com.docker.network.bridge.name: br-wordpress ``` However, it looks I used the "wrong" backup for posting. Sorry :-( I add a new "dump" and also an full docker-compose project, including an repo which fails. Due the "large" db_data part, it can not be uploaded here, but you can find download it: https://07q.de/data/borg.tar.xz (a bit slow, but should work) Extract and just run (I hope, I removed all absolute paths): `docker-compose up -d` `docker-compose exec borgmatic borgmatic restore -v2 --archive latest` Passwords are in the docker-compose.yml or config.yml files.
Owner

Thank you so much for including a full repro environment. I had to change the MariaDB image version to 10.6.5 to get it to start, but now it's running and I have a full repro of the problem! Now, to figure out what's going on...

Thank you so much for including a full repro environment. I had to change the MariaDB image version to 10.6.5 to get it to start, but now it's running and I have a full repro of the problem! Now, to figure out what's going on...
Owner

I have a fix! So the problem was that borgmatic was calling mysql --verbose as part of doing a database restore, which caused MySQL to spew every single database statement to stdout, which caused borgmatic to try to decode them all so it could stuff them into logs. But if the database contained any non-UTF-8 values, this blew up! The fix was to remove the --verbose flag to mysql. After all, there's no good reason to log the entire contents of the database when doing a restore.

Thanks again for your patience and help here. Wouldn't have been able to do it without your repro environment. This fix will be part of the next release.

I have a fix! So the problem was that borgmatic was calling `mysql --verbose` as part of doing a database restore, which caused MySQL to spew every single database statement to stdout, which caused borgmatic to try to decode them all so it could stuff them into logs. But if the database contained any non-UTF-8 values, this blew up! The fix was to remove the `--verbose` flag to `mysql`. After all, there's no good reason to *log* the entire contents of the database when doing a restore. Thanks again for your patience and help here. Wouldn't have been able to do it without your repro environment. This fix will be part of the next release.
Author

Thanks a lot for your quick bugfix.
I'm happy I can continue using borgmativ without any bad feeling. :-D

Thanks a lot for your quick bugfix. I'm happy I can continue using borgmativ without any bad feeling. :-D
Owner

Just released in borgmatic 1.5.22!

Just released in borgmatic 1.5.22!
Sign in to join this conversation.
No Milestone
No Assignees
2 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: borgmatic-collective/borgmatic#476
No description provided.