View Issue Details

IDProjectCategoryView StatusLast Update
0001449bareos-corefile daemonpublic2022-05-12 10:38
Reportermdc Assigned Tobruno-at-bareos  
PrioritynormalSeverityminorReproducibilityalways
Status assignedResolutionopen 
Platformx86_64OSCentOSOS Versionstream 8
Product Version21.1.2 
Summary0001449: MariaDB mariabackup plugin will work, but reports an error on
DescriptionEvery 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
TagsNo tags attached.
bareos-master: impact
bareos-master: action
bareos-19.2: impact
bareos-19.2: action
bareos-18.2: impact
bareos-18.2: action
bareos-17.2: impact
bareos-17.2: action
bareos-16.2: impact
bareos-16.2: action
bareos-15.2: impact
bareos-15.2: action
bareos-14.2: impact
bareos-14.2: action
bareos-13.2: impact
bareos-13.2: action
bareos-12.4: impact
bareos-12.4: action

Activities

mdc

mdc

2022-04-20 07:06

reporter   ~0004569

It will happens on active and passive clients.
mdc

mdc

2022-04-20 08:39

reporter   ~0004570

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?
mdc

mdc

2022-04-20 10:04

reporter   ~0004571

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."
bruno-at-bareos

bruno-at-bareos

2022-04-21 11:38

developer   ~0004575

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
mdc

mdc

2022-04-26 10:07

reporter   ~0004578

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.
bruno-at-bareos

bruno-at-bareos

2022-05-03 10:57

developer   ~0004587

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 ?
mdc

mdc

2022-05-05 11:47

reporter   ~0004592

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"
bruno-at-bareos

bruno-at-bareos

2022-05-10 17:26

developer   ~0004609

(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.
bruno-at-bareos

bruno-at-bareos

2022-05-12 09:47

developer   ~0004619

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.
mdc

mdc

2022-05-12 10:38

reporter   ~0004620

Thanks for the information.

Issue History

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