View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0000933bareos-coredirectorpublic2018-03-22 12:442023-08-22 15:36
Reporterhostedpower Assigned Tobruno-at-bareos  
PriorityhighSeveritymajorReproducibilityalways
Status closedResolutionno change required 
PlatformLinuxOSDebianOS Version9
Product Version16.2.7 
Summary0000933: Fatal error: fd_plugins.c:1237 Unbalanced call to createFile=0 0
Description2018-03-22 12:27:28 example-dir JobId 15968: Error: Bareos example-dir 16.2.7 (09Oct17):
 Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 8.0 (jessie)
 JobId: 15968
 Job: RestoreFiles.2018-03-22_12.26.32_04
 Restore Client: customer.xxx.com
 Start time: 22-Mar-2018 12:26:34
 End time: 22-Mar-2018 12:27:28
 Elapsed time: 54 secs
 Files Expected: 126,634
 Files Restored: 126,601
 Bytes Restored: 4,869,318,236
 Rate: 90172.6 KB/s
 FD Errors: 1
 FD termination status: Fatal Error
 SD termination status: OK
 Termination: *** Restore Error ***

 
2018-03-22 12:27:28 example-dir JobId 15968: Begin pruning Files.
 
2018-03-22 12:27:28 example-dir JobId 15968: No Files found to prune.
 
2018-03-22 12:27:28 example-dir JobId 15968: End auto prune.

 
2018-03-22 12:27:27 bareos-sd JobId 15968: End of Volume at file 2 on device "example-incr" (/home/example/bareos), Volume "vol-incr-0447"
 
2018-03-22 12:27:27 bareos-sd JobId 15968: Ready to read from volume "vol-cons-0486" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:27:27 bareos-sd JobId 15968: Forward spacing Volume "vol-cons-0486" to file:block 0:218.
 
2018-03-22 12:27:27 customer.xxx.com JobId 15968: Fatal error: fd_plugins.c:1237 Unbalanced call to createFile=0 0
 
2018-03-22 12:27:26 bareos-sd JobId 15968: End of Volume at file 8 on device "example-incr" (/home/example/bareos), Volume "vol-cons-0513"
 
2018-03-22 12:27:26 bareos-sd JobId 15968: Ready to read from volume "vol-incr-0447" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:27:26 bareos-sd JobId 15968: Forward spacing Volume "vol-incr-0447" to file:block 2:769145852.
 
2018-03-22 12:26:38 bareos-sd JobId 15968: End of Volume at file 2 on device "example-incr" (/home/example/bareos), Volume "vol-incr-0446"
 
2018-03-22 12:26:38 bareos-sd JobId 15968: Ready to read from volume "vol-cons-0513" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:26:38 bareos-sd JobId 15968: Forward spacing Volume "vol-cons-0513" to file:block 7:417218068.
 
2018-03-22 12:26:37 bareos-sd JobId 15968: End of Volume at file 2 on device "example-incr" (/home/example/bareos), Volume "vol-incr-0456"
 
2018-03-22 12:26:37 bareos-sd JobId 15968: Ready to read from volume "vol-incr-0446" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:26:37 bareos-sd JobId 15968: Forward spacing Volume "vol-incr-0446" to file:block 2:786923100.
 
2018-03-22 12:26:36 bareos-sd JobId 15968: End of Volume at file 2 on device "example-incr" (/home/example/bareos), Volume "vol-incr-0423"
 
2018-03-22 12:26:36 bareos-sd JobId 15968: Ready to read from volume "vol-incr-0456" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:26:36 bareos-sd JobId 15968: Forward spacing Volume "vol-incr-0456" to file:block 2:691729567.
 
2018-03-22 12:26:35 bareos-sd JobId 15968: Ready to read from volume "vol-incr-0423" on device "example-incr" (/home/example/bareos).
 
2018-03-22 12:26:35 bareos-sd JobId 15968: Forward spacing Volume "vol-incr-0423" to file:block 2:606078578.
 
2018-03-22 12:26:34 example-dir JobId 15968: Start Restore Job RestoreFiles.2018-03-22_12.26.32_04
 
2018-03-22 12:26:34 example-dir JobId 15968: Using Device "example-incr" to read.
Steps To ReproduceRestore files from an always incremental schedule, including a mysql backup

We tried separate restore afterwards and this works without errors (so first restore of files and than a separate restore job for the database)
TagsNo tags attached.

Activities

joergs

joergs

2018-04-05 12:54

developer   ~0002960

So, what plugings have you configured? This error should only occur, if a plugin is used.
hostedpower

hostedpower

2018-04-05 13:44

reporter   ~0002964

Hello Joergs,

We use the MySQL plugin of course :)
joergs

joergs

2018-04-05 16:47

developer   ~0002965

Well, there are still multiple MySQL plugins and different possible configurations.
hostedpower

hostedpower

2018-04-05 16:50

reporter   ~0002966

We used this install procedure:


cd /tmp
git clone https://github.com/bareos/bareos-contrib
cp -R ./bareos-contrib/fd-plugins/mysql-python/*.py /usr/lib/bareos/plugins/
rm -rf bareos-contrib/
service bareos-fd restart

It's strange that seperate restores work perfectly, it's only when we combine SQL dump file restore & regular files we run into issues.

Please let me know which info exactly you need if you need anything else!
hostedpower

hostedpower

2019-07-29 12:03

reporter   ~0003530

Today this is still an issue..

If we restore MySQL database and files together it goes wrong :(



2019-07-29 11:59:57 xxxx JobId 88755: Fatal error: filed/fd_plugins.cc:1247 Unbalanced call to createFile=0 0
 
2019-07-29 11:59:57 backupxxx JobId 88755: Error: lib/bsock_tcp.cc:417 Wrote 29242 bytes to client:94.237.42.21:9103, but only 0 accepted.
 
2019-07-29 11:59:57 backupxxx JobId 88755: Fatal error: stored/read.cc:164 Error sending to File daemon. ERR=Connection reset by peer
 
2019-07-29 11:59:57 backupxxx JobId 88755: Error: lib/bsock_tcp.cc:457 Socket has errors=1 on call to client:94.237.42.21:9103
 
2019-07-29 11:59:57 backupxxx JobId 88755: Releasing device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:57 director JobId 88755: Max configured use duration=82,800 sec. exceeded. Marking Volume "vol-cons-3373" as Used.
 
2019-07-29 11:59:57 director JobId 88755: Error: Bareos director 18.2.6 (13Feb19):
 Build OS: Linux-4.4.92-6.18-default debian Debian GNU/Linux 9.7 (stretch)
 JobId: 88755
 Job: RestoreFiles.2019-07-29_11.09.05_18
 Restore Client: xxxxx
 Start time: 29-Jul-2019 11:58:44
 End time: 29-Jul-2019 11:59:57
 Elapsed time: 1 min 13 secs
 Files Expected: 186,501
 Files Restored: 15,767
 Bytes Restored: 5,625,032,491
 Rate: 77055.2 KB/s
 FD Errors: 1
 FD termination status: Fatal Error
 SD termination status: Fatal Error
 Bareos binary info: official Bareos subscription
 Termination: *** Restore Error ***

 
2019-07-29 11:59:57 director JobId 88755: Begin pruning Files.
 
2019-07-29 11:59:57 director JobId 88755: No Files found to prune.
 
2019-07-29 11:59:57 director JobId 88755: End auto prune.

 
2019-07-29 11:59:56 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3338"
 
2019-07-29 11:59:56 backupxxx JobId 88755: Ready to read from volume "vol-cons-3373" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:56 backupxxx JobId 88755: Forward spacing Volume "vol-cons-3373" to file:block 0:241.
 
2019-07-29 11:59:53 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3325"
 
2019-07-29 11:59:53 backupxxx JobId 88755: Ready to read from volume "vol-incr-3338" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:53 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3338" to file:block 0:241.
 
2019-07-29 11:59:51 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3314"
 
2019-07-29 11:59:51 backupxxx JobId 88755: Ready to read from volume "vol-incr-3325" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:51 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3325" to file:block 0:241.
 
2019-07-29 11:59:49 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3307"
 
2019-07-29 11:59:49 backupxxx JobId 88755: Ready to read from volume "vol-incr-3314" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:49 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3314" to file:block 0:241.
 
2019-07-29 11:59:40 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3283"
 
2019-07-29 11:59:40 backupxxx JobId 88755: Ready to read from volume "vol-incr-3295" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:40 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3295" to file:block 0:241.
 
2019-07-29 11:59:40 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3295"
 
2019-07-29 11:59:40 backupxxx JobId 88755: Ready to read from volume "vol-incr-3307" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:40 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3307" to file:block 0:241.
 
2019-07-29 11:59:30 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3276"
 
2019-07-29 11:59:30 backupxxx JobId 88755: Ready to read from volume "vol-incr-3283" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:30 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3283" to file:block 0:241.
 
2019-07-29 11:59:02 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3265"
 
2019-07-29 11:59:02 backupxxx JobId 88755: Ready to read from volume "vol-incr-3276" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:02 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3276" to file:block 0:241.
 
2019-07-29 11:59:01 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3258"
 
2019-07-29 11:59:01 backupxxx JobId 88755: Ready to read from volume "vol-incr-3265" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:01 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3265" to file:block 0:241.
 
2019-07-29 11:59:00 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3252"
 
2019-07-29 11:59:00 backupxxx JobId 88755: Ready to read from volume "vol-incr-3258" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:59:00 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3258" to file:block 0:241.
 
2019-07-29 11:58:57 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3244"
 
2019-07-29 11:58:57 backupxxx JobId 88755: Ready to read from volume "vol-incr-3252" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:57 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3252" to file:block 0:241.
 
2019-07-29 11:58:56 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3230"
 
2019-07-29 11:58:56 backupxxx JobId 88755: Ready to read from volume "vol-incr-3244" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:56 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3244" to file:block 0:241.
 
2019-07-29 11:58:54 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3224"
 
2019-07-29 11:58:54 backupxxx JobId 88755: Ready to read from volume "vol-incr-3230" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:54 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3230" to file:block 0:241.
 
2019-07-29 11:58:51 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3218"
 
2019-07-29 11:58:51 backupxxx JobId 88755: Ready to read from volume "vol-incr-3224" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:51 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3224" to file:block 0:241.
 
2019-07-29 11:58:49 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3212"
 
2019-07-29 11:58:49 backupxxx JobId 88755: Ready to read from volume "vol-incr-3218" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:49 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3218" to file:block 0:241.
 
2019-07-29 11:58:48 backupxxx JobId 88755: End of Volume at file 0 on device "serverxx-incr" (/home/serverxx/bareos), Volume "vol-incr-3364"
 
2019-07-29 11:58:48 backupxxx JobId 88755: Ready to read from volume "vol-incr-3212" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:48 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3212" to file:block 0:241.
 
2019-07-29 11:58:47 backupxxx JobId 88755: Ready to read from volume "vol-incr-3364" on device "serverxx-incr" (/home/serverxx/bareos).
 
2019-07-29 11:58:47 backupxxx JobId 88755: Forward spacing Volume "vol-incr-3364" to file:block 0:241.
 
2019-07-29 11:58:46 xxxx JobId 88755: Connected Storage daemon at backupxxx:9103, encryption: PSK-AES256-CBC-SHA
 
2019-07-29 11:58:44 director JobId 88755: Start Restore Job RestoreFiles.2019-07-29_11.09.05_18
 
2019-07-29 11:58:44 director JobId 88755: Connected Storage daemon at backupxxx:9103, encryption: ECDHE-PSK-CHACHA20-POLY1305
 
2019-07-29 11:58:44 director JobId 88755: Using Device "serverxx-incr" to read.
 
2019-07-29 11:58:44 director JobId 88755: Connected Client: xxxx at xxxx:9102, encryption: PSK-AES256-CBC-SHA
 
2019-07-29 11:58:44 director JobId 88755: Handshake: Immediate TLS
2019-07-29 11:58:44 director JobId 88755: Encryption: PSK-AES256-CBC-SHA
hostedpower

hostedpower

2019-07-29 17:31

reporter   ~0003532

to be clear.

Restore together, result:

Files: Not complete
MySQL db: restore looks ok

Restore Files and db , both in seperate job:

Files: OK
MySQL db: OK
hostedpower

hostedpower

2019-12-24 15:57

reporter   ~0003715

Still an issue, we're not able to restore AND files AND mysql database at the same time without this weird error... :)

Any idea?
sipgate

sipgate

2020-09-30 08:49

reporter   ~0004044

This is still an issue in 19.2.7

We can successfully restore
* a single full database backup
* a single full database backup plus some flat files
* a full database backup plus (1 or more) incremental database backups

We are not able to successfully restore
* a full database backup plus (1 or more) incremental database backups plus some flat files

Here's the log when trying full + incremental + files:

30-Sep 08:47 backup-storage02 JobId 567: Ready to read from volume "Full-db14-buster-0139" on device "backup-storage02" (/data/bareos/storage).
30-Sep 08:47 backup-storage02 JobId 567: Forward spacing Volume "Full-db14-buster-0139" to file:block 0:319522951.
30-Sep 08:47 backup-storage02 JobId 567: End of Volume at file 0 on device "backup-storage02" (/data/bareos/storage), Volume "Full-db14-buster-0139"
30-Sep 08:47 backup-storage02 JobId 567: Ready to read from volume "Incremental-db14-buster-0144" on device "backup-storage02" (/data/bareos/storage).
30-Sep 08:47 backup-storage02 JobId 567: Forward spacing Volume "Incremental-db14-buster-0144" to file:block 0:13528970.
30-Sep 08:47 backup-storage02 JobId 567: End of Volume at file 0 on device "backup-storage02" (/data/bareos/storage), Volume "Incremental-db14-buster-0144"
30-Sep 08:47 backup-storage02 JobId 567: Ready to read from volume "Incremental-db14-buster-0148" on device "backup-storage02" (/data/bareos/storage).
30-Sep 08:47 backup-storage02 JobId 567: Forward spacing Volume "Incremental-db14-buster-0148" to file:block 0:311.
30-Sep 08:47 db14-buster JobId 567: Fatal error: filed/fd_plugins.cc:1279 Unbalanced call to createFile=0 0
30-Sep 08:47 backup-storage02 JobId 567: Error: lib/bsock_tcp.cc:435 Wrote 65536 bytes to client:$client_ip:9103, but only 32768 accepted.
30-Sep 08:47 backup-storage02 JobId 567: Fatal error: stored/read.cc:159 Error sending to File daemon. ERR=Connection reset by peer
30-Sep 08:47 backup-storage02 JobId 567: Error: lib/bsock_tcp.cc:475 Socket has errors=1 on call to client:$client_ip:9103
30-Sep 08:47 backup-storage02 JobId 567: Releasing device "backup-storage02" (/data/bareos/storage).
30-Sep 08:47 backup-director01 JobId 567: Error: Bareos backup-director01 19.2.7 (16Apr20):
  Build OS: Linux-3.10.0-1062.18.1.el7.x86_64 debian Debian GNU/Linux 10 (buster)
  JobId: 567
  Job: RestoreFiles.2020-09-30_08.47.15_22
  Restore Client: db14-buster
  Start time: 30-Sep-2020 08:47:17
  End time: 30-Sep-2020 08:47:22
  Elapsed time: 5 secs
  Files Expected: 28
  Files Restored: 23
  Bytes Restored: 108,650,330
  Rate: 21730.1 KB/s
  FD Errors: 1
  FD termination status: Fatal Error
  SD termination status: Fatal Error
  Bareos binary info: bareos.org build: Get official binaries and vendor support on bareos.com
  Termination: *** Restore Error ***
bruno-at-bareos

bruno-at-bareos

2023-08-22 15:36

manager   ~0005335

It has been documented in the meantime to not mix normal File and Plugin fileset.

Issue History

Date Modified Username Field Change
2018-03-22 12:44 hostedpower New Issue
2018-04-05 12:54 joergs Note Added: 0002960
2018-04-05 12:54 joergs Status new => feedback
2018-04-05 13:44 hostedpower Note Added: 0002964
2018-04-05 13:44 hostedpower Status feedback => new
2018-04-05 16:47 joergs Note Added: 0002965
2018-04-05 16:47 joergs Status new => feedback
2018-04-05 16:50 hostedpower Note Added: 0002966
2018-04-05 16:50 hostedpower Status feedback => new
2019-07-29 12:03 hostedpower Note Added: 0003530
2019-07-29 17:30 arogge Status new => acknowledged
2019-07-29 17:31 hostedpower Note Added: 0003532
2019-12-24 15:57 hostedpower Note Added: 0003715
2020-09-30 08:49 sipgate Note Added: 0004044
2023-08-22 15:36 bruno-at-bareos Assigned To => bruno-at-bareos
2023-08-22 15:36 bruno-at-bareos Status acknowledged => closed
2023-08-22 15:36 bruno-at-bareos Resolution open => no change required
2023-08-22 15:36 bruno-at-bareos Note Added: 0005335