View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0001449 | bareos-core | file daemon | public | 2022-04-19 14:58 | 2022-06-27 14:16 |
Reporter | mdc | Assigned To | bruno-at-bareos | ||
Priority | normal | Severity | minor | Reproducibility | always |
Status | closed | Resolution | fixed | ||
Platform | x86_64 | OS | CentOS | OS Version | stream 8 |
Product Version | 21.1.2 | ||||
Summary | 0001449: MariaDB mariabackup plugin will work, but reports an error on | ||||
Description | Every incremental/full run will produce an warning log and so an mail will be generated. But the restore will work. Log: 19-Apr 14:00 <Client> JobId 268: Warning: Cannot stat file /_mariabackup/xbstream.0000000268: ERR=No such file or directory But the file was saved: *list files jobid=268 Automatically selected Catalog: Datenbank Using Catalog "Datenbank" /_mariabackup/xbstream.0000000268 And on an restore the directory is created: ll /var/tmp/bareos/_mariabackup/269/ total 36 drwxr-xr-x. 9 root bareos 4096 Apr 19 14:52 . drwxr-xr-x. 3 root bareos 4096 Apr 19 14:51 .. drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000000000000000000_00000001142240887624_0000000250 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142240887624_00000001142285408394_0000000253 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142285408394_00000001142285413099_0000000255 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142285413099_00000001142285422884_0000000256 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142285422884_00000001142286573928_0000000262 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142286573928_00000001142332777524_0000000267 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 00000001142332777524_00000001142333405715_0000000268 ll /var/tmp/bareos/_mariabackup/269/00000001142332777524_00000001142333405715_0000000268 total 6736 drwxr-xr-x. 7 root bareos 4096 Apr 19 14:52 . drwxr-xr-x. 9 root bareos 4096 Apr 19 14:52 .. -rw-r-----. 1 root bareos 598016 Apr 19 14:52 aria_log.00000001 -rw-r-----. 1 root bareos 52 Apr 19 14:52 aria_log_control -rw-r-----. 1 root bareos 324 Apr 19 14:52 backup-my.cnf -rw-r-----. 1 root bareos 925417 Apr 19 14:52 ib_buffer_pool -rw-r-----. 1 root bareos 5275648 Apr 19 14:52 ibdata1.delta -rw-r-----. 1 root bareos 45 Apr 19 14:52 ibdata1.meta -rw-r-----. 1 root bareos 2560 Apr 19 14:52 ib_logfile0 drwx------. 2 root bareos 4096 Apr 19 14:52 <FOO_DB> drwx------. 2 root bareos 4096 Apr 19 14:52 mysql drwx------. 2 root bareos 4096 Apr 19 14:52 performance_schema drwx------. 2 root bareos 49152 Apr 19 14:52 <FOO2_DB> drwx------. 2 root bareos 4096 Apr 19 14:52 sys -rw-r-----. 1 root bareos 99 Apr 19 14:52 xtrabackup_checkpoints -rw-r-----. 1 root bareos 537 Apr 19 14:52 xtrabackup_info | ||||
Tags | No tags attached. | ||||
It will happens on active and passive clients. | |
When the fd run's in debug mode, I will see for the xbstream file an log, which, don't occurs for the other files: module/bareosfd.cc:1392-299 python3-fd-mod: get_acl() entry point in Python called with AclPacket(fname="/_mariabackup/xbstream.0000000299", content="") module/bareosfd.cc:1392-299 python3-fd-mod: get_xattr() entry point in Python called with XattrPacket(fname="/_mariabackup/xbstream.0000000299", name="", value="") Can this be the source of the message? |
|
Using debug mode 999 give me another hint: module/bareosfd.cc:1392-304 python3-fd-mod: plugin_io called with 2 findlib/find_one.cc:259-304 HasFileChanged fname=/_mariabackup/xbstream.0000000304 lib/message.cc:1252-304 Enter Jmsg type=5 lib/message.cc:614-304 Enter DispatchMessage type=5 msg=<CLIENT> JobId 304: Warning: Cannot stat file /_mariabackup/xbstream.0000000304: ERR=No such file or directory As an work around, set "Check File Changes = no" in the FileSet for the job. I think it will be better to handle this call in the AddOn, as the documentation says: "In general, it is recommended to use this option." |
|
Hello, our priority is to be able to reproduce the problem. To understand your configuration and installation we need more information. Maybe you will be able to run our support tool which will grab those for you. curl -O https://support.bareos.com/tools/bareos-support-info.sh chmod 750 bareos-support-info.sh ./bareos-support-info.sh The support tool will gather the following information. - Installed Bareos packages - Logfiles - Bactraces - Tracebacks - Status information - Information about pools, media, jobs - Configuration with anonymized passwords and cipher keys - System information like space, packages related to bareos - Database information You can attach the resulting tar.gz to this ticket (if small enough). Otherwise you can report a link to download it or ask I will communicate a way to transfer it to us. You can also add here the output of bconsole command list joblog jobid=268 |
|
Here are the log output (internal infos re removed): *list joblog jobid=268 Automatically selected Catalog: Datenbank Using Catalog "Datenbank" 2022-04-19 14:00:02 Bareos Director JobId 268: Start Backup JobId 268, Job=MariaDB_client-foo.2022-04-19_14.00.00_34 2022-04-19 14:00:02 Bareos Director JobId 268: Connected Storage daemon at storage.foo.foo:9103, encryption: PSK-AES256-CBC-SHA SSLv3 2022-04-19 14:00:02 Bareos Director JobId 268: Using Device "MariaDBInc" to write. 2022-04-19 14:00:02 Bareos Director JobId 268: Connected Client: client-foo at client-foo.foo.foo:9102, encryption: PSK-AES256-CBC-SHA SSLv3 2022-04-19 14:00:02 Bareos Director JobId 268: Handshake: Immediate TLS 2022-04-19 14:00:02 Bareos Director JobId 268: Encryption: PSK-AES256-CBC-SHA SSLv3 2022-04-19 14:00:03 client-foo.foo.foo JobId 268: python3-fd-mod: Got to_lsn 1142332777524 from restore object of job 267 2022-04-19 14:00:05 client-foo.foo.foo JobId 268: Extended attribute support is enabled 2022-04-19 14:00:05 client-foo.foo.foo JobId 268: ACL support is enabled 2022-04-19 14:00:03 storage.foo.foo JobId 268: Connected File Daemon at client-foo.foo.foo:9102, encryption: PSK-AES256-CBC-SHA TLSv1/SSLv3 2022-04-19 14:00:05 storage.foo.foo JobId 268: Volume "Inc-MariaDB-0022" previously written, moving to end of data. 2022-04-19 14:00:05 storage.foo.foo JobId 268: Ready to append to end of Volume "Inc-MariaDB-0022" size=128567781 2022-04-19 14:00:05 client-foo.foo.foo JobId 268: python3-fd-mod: Backup until LSN: 1142333405724 2022-04-19 14:00:05 client-foo.foo.foo JobId 268: python3-fd-mod: Starting backup of /_mariabackup/xbstream.0000000268 2022-04-19 14:00:19 client-foo.foo.foo JobId 268: Warning: Cannot stat file /_mariabackup/xbstream.0000000268: ERR=No such file or directory 2022-04-19 14:00:19 client-foo.foo.foo JobId 268: python3-fd-mod: Starting backup of /_mariabackup/xtrabackup_checkpoints 2022-04-19 14:00:19 storage.foo.foo JobId 268: Releasing device "MariaDB Inc" (/mnt/backup/bareos/MariaDB/Inc). 2022-04-19 14:00:19 storage.foo.foo JobId 268: Elapsed time=00:00:14, Transfer rate=207.5 K Bytes/second 2022-04-19 14:00:19 Bareos Director JobId 268: Insert of attributes batch table with 1 entries start 2022-04-19 14:00:19 Bareos Director JobId 268: Insert of attributes batch table done 2022-04-19 14:00:19 Bareos Director JobId 268: Bareos Bareos Director 21.1.2 (17Mar22): Build OS: CentOS Stream release 8 JobId: 268 Job: MariaDB_client-foo.2022-04-19_14.00.00_34 Backup Level: Incremental, since=2022-04-19 13:00:05 Client: "client-foo" 21.1.2 (17Mar22) CentOS Linux release 7.9.2009 (Core),redhat FileSet: "MariaDB" 2022-04-19 09:36:32 Pool: "Inc MariaDB" (From Run Pool override) Catalog: "Datenbank" (From Client resource) Storage: "MariaDB Inc" (From Pool resource) Scheduled time: 19-Apr-2022 14:00:00 Start time: 19-Apr-2022 14:00:05 End time: 19-Apr-2022 14:00:19 Elapsed time: 14 secs Priority: 10 FD Files Written: 2 SD Files Written: 2 FD Bytes Written: 2,904,802 (2.904 MB) SD Bytes Written: 2,905,484 (2.905 MB) Rate: 207.5 KB/s Software Compression: 84.2 % (gzip9) VSS: no Encryption: no Accurate: no Volume name(s): Inc-MariaDB-0022 Volume Session Id: 29 Volume Session Time: 1650350336 Last Volume Bytes: 131,478,793 (131.4 MB) Non-fatal FD errors: 0 SD Errors: 0 FD termination status: OK SD termination status: OK Bareos binary info: self-compiled: Get official binaries and vendor support on bareos.com Job triggered by: Scheduler Termination: Backup OK 2022-04-19 14:00:19 Bareos Director JobId 268: Begin pruning Jobs older than 7 days . 2022-04-19 14:00:19 Bareos Director JobId 268: No Jobs found to prune. 2022-04-19 14:00:19 Bareos Director JobId 268: Begin pruning Files. 2022-04-19 14:00:19 Bareos Director JobId 268: No Files found to prune. 2022-04-19 14:00:19 Bareos Director JobId 268: End auto prune. |
|
Thanks for the report. After analyzing the content, we are not able to detect any problem like the one you describe before. We also aren't able to reproduce this problem for the moment (Full and incremental backups are done each time we build the software in our systemtests). Maybe this instance was failing with incomplete or interrupted backup at that time ? Are you still able to reproduce this ? |
|
Yes I can reproduce it every time. "Check File Changes = no" -> all ok "Check File Changes = yes" -> the backups will work, but the error is logged and the backups are marked as "Warning" |
|
(Same conclusion than for bug 1452) After a review today with developer here's the conclusion and next step that will be done. We will change the documentation for master and other release to clarify the situation of this parameter CheckFileChanges is not intended to be run with plugin, and its usage should be reserved for File exclusively. Now if you would like to run one job with a debug level set at 1000 and report the trace here, this will be really appreciated as it can serve for an eventually future development about make CheckFileChanges supported on plugin. Thanks. |
|
Thanks for the report, we open internally a task for that, but there's no eta when it will be done nor if it will be. Maybe a first check will be to see if CheckFileChanges can be used in Plugin backup context. At least now the documentation will be changed to reflect this statement. See PR-1180 https://github.com/bareos/bareos/pull/1180 if you want comment. |
|
Thanks for the information. | |
PR1180 merged | |
Date Modified | Username | Field | Change |
---|---|---|---|
2022-04-19 14:58 | mdc | New Issue | |
2022-04-20 07:06 | mdc | Note Added: 0004569 | |
2022-04-20 08:39 | mdc | Note Added: 0004570 | |
2022-04-20 10:04 | mdc | Note Added: 0004571 | |
2022-04-21 11:38 | bruno-at-bareos | Note Added: 0004575 | |
2022-04-21 14:08 | bruno-at-bareos | Assigned To | => bruno-at-bareos |
2022-04-21 14:08 | bruno-at-bareos | Status | new => assigned |
2022-04-26 10:07 | mdc | Note Added: 0004578 | |
2022-05-03 10:57 | bruno-at-bareos | Note Added: 0004587 | |
2022-05-05 11:47 | mdc | Note Added: 0004592 | |
2022-05-10 17:26 | bruno-at-bareos | Note Added: 0004609 | |
2022-05-12 09:47 | bruno-at-bareos | Note Added: 0004619 | |
2022-05-12 10:38 | mdc | Note Added: 0004620 | |
2022-06-27 14:16 | bruno-at-bareos | Status | assigned => closed |
2022-06-27 14:16 | bruno-at-bareos | Resolution | open => fixed |
2022-06-27 14:16 | bruno-at-bareos | Note Added: 0004645 |