View Issue Details

IDProjectCategoryView StatusLast Update
0000745bareos-core[All Projects] directorpublic2017-03-06 11:25
ReporterhostedpowerAssigned Tomaik 
PriorityhighSeveritymajorReproducibilityalways
Status closedResolutionno change required 
PlatformLinuxOSDebianOS Version8
Product Version16.2.4 
Fixed in Version 
Summary0000745: Always incremental consolidate fails when no files are changed
DescriptionHi,


I'm using the always incremental scheme. All works well for most hosts except this one.

I assume this error is caused because the server only backups the /etc/ folder. Most likely zero file changes occur. In this case the virtualfull for the consolidation seems to fail somehow. I only have the problem with this host where I only backup the /etc/


Timestamp

Message


2016-12-26 09:01:25 hostedpower-dir JobId 519: Start Virtual Backup JobId 519, Job=backup-web3.cloud.dynacoonline.com.2016-12-26_09.00.18_45
 
2016-12-26 09:01:25 hostedpower-dir JobId 519: Consolidating JobIds 32,54
 
2016-12-26 09:01:25 hostedpower-dir JobId 519: Unable to get Job record. ERR=sql_get.c:309 No Job found for JobId 0

 
2016-12-26 09:01:25 hostedpower-dir JobId 519: No files found to read. No bootstrap file written.
 
2016-12-26 09:01:25 hostedpower-dir JobId 519: Fatal error: Could not get or create the FileSet record.
 
2016-12-26 09:01:25 hostedpower-dir JobId 519: Error: Bareos hostedpower-dir 16.2.4 (01Jul16):
 Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 8.0 (jessie)
 JobId: 519
 Job: backup-web3.cloud.dynacoonline.com.2016-12-26_09.00.18_45
 Backup Level: Virtual Full
 Client: "web3.cloud.dynacoonline.com" 16.2.4 (01Jul16) x86_64-pc-linux-gnu,debian,Debian GNU/Linux 8.0 (jessie),Debian_8.0,x86_64
 FileSet: "linux-minimal" 2016-12-04 00:15:00
 Pool: "entrematic-cons" (From Job Pool's NextPool resource)
 Catalog: "MyCatalog" (From Client resource)
 Storage: "entrematic-cons" (From Storage from Pool's NextPool resource)
 Scheduled time: 26-Dec-2016 09:00:18
 Start time: 06-Dec-2016 00:35:16
 End time: 06-Dec-2016 00:35:16
 Elapsed time: 0 secs
 Priority: 10
 SD Files Written: 0
 SD Bytes Written: 0 (0 B)
 Rate: 0.0 KB/s
 Volume name(s):
 Volume Session Id: 0
 Volume Session Time: 0
 Last Volume Bytes: 0 (0 B)
 SD Errors: 0
 SD termination status:
 Accurate: yes
 Termination: *** Backup Error ***
 
Tagsalways incremental, configuration, director, support
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

Relationships

related to 0000755 closedmaik Always Incremental "Always Incremental Max Full Age" not working properly 

Activities

joop.martens

joop.martens

2016-12-30 20:05

reporter   ~0002492

Last edited: 2016-12-30 20:05

View 2 revisions

It looks like I'm running into the same issue though for me all consolidation jobs are failing with this error.

In this case all jobs/hosts have changed files on a daily basis, so for me it does not seem to be related to jobs that have no changed files.

These are the first consolidation jobs/attempts that have been executed by Bareos since recently the first full backups expired.
So until now not any consolidation job has ran successfully.

2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: Start Virtual Backup JobId 1025, Job=D_scwsnl01-003_HQS.2016-12-30_09.05.02_05
2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: Consolidating JobIds 22,37
2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: Unable to get Job record. ERR=sql_get.c:309 No Job found for JobId 0

2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: No files found to read. No bootstrap file written.
2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: Fatal error: Could not get or create the FileSet record.
2016-12-30 09:05:02 sclsnl01-009-dir JobId 1025: Error: Bareos sclsnl01-009-dir 16.2.4 (01Jul16):
Build OS: x86_64-redhat-linux-gnu redhat CentOS Linux release 7.0.1406 (Core)
JobId: 1025
Job: D_scwsnl01-003_HQS.2016-12-30_09.05.02_05
Backup Level: Virtual Full
Client: "scwsnl01-003-fd" 15.2.2 (16Nov15) Microsoft Windows Server 2012 Standard Edition (build 9200), 64-bit,Cross-compile,Win64
FileSet: "Windows_Drives_HQS" 2016-09-27 08:25:29
Pool: "AI-Full" (From Job Pool's NextPool resource)
Catalog: "MyCatalog" (From Client resource)
Storage: "File" (From Storage from Pool's NextPool resource)
Scheduled time: 30-Dec-2016 09:05:02
Start time: 30-Sep-2016 03:21:16
End time: 30-Sep-2016 03:38:48
Elapsed time: 17 mins 32 secs
Priority: 10
SD Files Written: 0
SD Bytes Written: 0 (0 B)
Rate: 0.0 KB/s
Volume name(s):
Volume Session Id: 0
Volume Session Time: 0
Last Volume Bytes: 0 (0 B)
SD Errors: 0
SD termination status:
Accurate: yes
Termination: *** Backup Error ***

joop.martens

joop.martens

2017-01-09 14:15

reporter   ~0002502

I have managed to run all my consolidated jobs though there is still an issue with this error. Initially when I reran the consolidation job all VirtualFull jobs executed by the consolidation process immediately failed with the exact same error.

Now a couple of days and backups later I have tried to rerun the consolidation job and found out that the first VirtualFull ran successfully but the other VirtualFull's failed again with the same error message.

Rerunning the consolidation job now resulted in the situation that again the first triggered VirtualFull ran successful while the others failed.

I have repeated this process until all my consolidation jobs had ran successful.

I’m curious what is going to happen with the next consolidation cycle but in my case that will be only in 3 months.
maik

maik

2017-01-20 11:52

administrator   ~0002514

Eventually a consequence of (mis-)configuration in 0000755 - please adjust and check, if behavior still occurs.
joop.martens

joop.martens

2017-01-20 13:46

reporter   ~0002517

These are my job settings:

Always Incremental Job Retention = 91 days
Always Incremental Max Full Age = 98 days

Always Incremental Max Full Age Dir Job is not less or equal of Always Incremental Job Retention Dir Job so this should not be the problem in my case.
hostedpower

hostedpower

2017-02-01 10:49

reporter   ~0002543

Hi,

Same issue again now with proper job settings. Here is job log:


2017-02-01 09:00:13 hostedpower-dir JobId 511: Start Virtual Backup JobId 511, Job=backup-web3.cloud.dynacoonline.com.2017-02-01_09.00.05_02
 
2017-02-01 09:00:13 hostedpower-dir JobId 511: Consolidating JobIds 28,50
 
2017-02-01 09:00:13 hostedpower-dir JobId 511: Unable to get Job record. ERR=sql_get.c:309 No Job found for JobId 0

 
2017-02-01 09:00:13 hostedpower-dir JobId 511: No files found to read. No bootstrap file written.
 
2017-02-01 09:00:13 hostedpower-dir JobId 511: Fatal error: Could not get or create the FileSet record.
 
2017-02-01 09:00:13 hostedpower-dir JobId 511: Error: Bareos hostedpower-dir 16.2.4 (01Jul16):
 Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 8.0 (jessie)
 JobId: 511
 Job: backup-web3.cloud.dynacoonline.com.2017-02-01_09.00.05_02
 Backup Level: Virtual Full
 Client: "web3.cloud.dynacoonline.com" 16.2.4 (01Jul16) x86_64-pc-linux-gnu,debian,Debian GNU/Linux 8.0 (jessie),Debian_8.0,x86_64
 FileSet: "linux-minimal" 2017-01-10 00:15:00
 Pool: "entrematic-cons" (From Job Pool's NextPool resource)
 Catalog: "MyCatalog" (From Client resource)
 Storage: "entrematic-cons" (From Storage from Pool's NextPool resource)
 Scheduled time: 01-Feb-2017 09:00:05
 Start time: 12-Jan-2017 00:55:15
 End time: 12-Jan-2017 00:55:15
 Elapsed time: 0 secs
 Priority: 10
 SD Files Written: 0
 SD Bytes Written: 0 (0 B)
 Rate: 0.0 KB/s
 Volume name(s):
 Volume Session Id: 0
 Volume Session Time: 0
 Last Volume Bytes: 0 (0 B)
 SD Errors: 0
 SD termination status:
 Accurate: yes
 Termination: *** Backup Error ***
maik

maik

2017-02-01 17:19

administrator   ~0002547

Couldn't reproduce: testsetup with full and empty incrementals worked fine:


01-Feb 17:15 bareos-dir JobId 17: Start Virtual Backup JobId 17, Job=aitest.2017-02-01_17.15.03_09
01-Feb 17:15 bareos-dir JobId 17: Consolidating JobIds 5,6,8,9

 JobId Level Files Bytes Status Finished Name
====================================================================
     5 Full 2 4 OK 01-Feb-17 16:34 aitest
     6 Incr 0 0 OK 01-Feb-17 16:34 aitest
     8 Incr 0 0 OK 01-Feb-17 16:47 aitest
     9 Incr 0 0 OK 01-Feb-17 16:47 aitest
joop.martens

joop.martens

2017-02-02 14:11

reporter   ~0002549

I'm afraid that this issue is not always as easy to reproduce.
Also in my setup it happens often but not always.

The odd thing is that like described in my second note: 0002502 rerunning the consolidation job makes one virtual full consolidation job to run successful, that can be repeated until all have been processed.

I could provide you with remote SSH access to my system but preferably arrange this with you outside the bugtracker.

Just use my bugtracker account e-mail address for sending your contact information that I can use to send you the login information.

If there is anything else that I can do to debug this issue and post the results here, please provide instructions.

On my system it is most often reproduce-able. (I have temporarily disabled consolidation because it almost always failing.)
matthijs

matthijs

2017-02-15 13:40

reporter   ~0002569

We had a hard time to reproduce the issue but we managed to find the line of code from where the consolidation (virtual full) fails.

We reduced this problem to the consolidate job not needing to process any files.

In vbackup.c on line 255 you have the message 'Could not get or create the FileSet record.' which we got as a 'Fatal error'. When looking into this we see that the 'create_bootstrap_file' function returns a boolean false.

When running bareos-director in debug mode with '/usr/sbin/bareos-dir -d100 -f' we get also the following messages:
... (100): sql_get.c:1272-15 q=SELECT Path.Path, Filename.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq FROM ( SELECT DISTINCT ON (FilenameId, PathId, DeltaSeq) JobTDate, JobId, FileId, FileIndex, PathId, FilenameId, LStat , DeltaSeq FROM (SELECT FileId, JobId, PathId, FilenameId, FileIndex, LStat ,DeltaSeq FROM File WHERE JobId IN (3,5) UNION ALL SELECT File.FileId, File.JobId, PathId, FilenameId, File.FileIndex, LStat , DeltaSeq FROM BaseFiles JOIN File USING (FileId) WHERE BaseFiles.JobId IN (3,5) ) AS T JOIN Job USING (JobId) ORDER BY FilenameId, PathId, DeltaSeq, JobTDate DESC ) AS T1 JOIN Filename ON (Filename.FilenameId = T1.FilenameId) JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC
... (0): vbackup.c:508-15 Found 0 files to consolidate.
... (100): vbackup.c:373-15 Enter backup_cleanup 69 E
... (100): vbackup.c:458-15 Leave vbackup_cleanup()

The message: 'Found 0 files to consolidate.' can be found in vbackup.c at line 508.

The offending check is on line 510 where it checks the expected files and when the jcr->ExpectedFiles == 0 it returns false.

The query as seen in the output above returns 0 rows in our test.

The solution for us is now to keep the regular jobs running and when there are 'ExpectedFiles' then it will consolidate the jobs.

Hopefully this will help in resolving this issue.
hostedpower

hostedpower

2017-02-15 14:27

reporter   ~0002570

Yeah indeed, I was already thinking the same. It had to do something with 0 changes/files.
maik

maik

2017-03-06 11:25

administrator   ~0002601

Individual configuration problem, solved by support

Issue History

Date Modified Username Field Change
2016-12-28 17:32 hostedpower New Issue
2016-12-30 20:05 joop.martens Note Added: 0002492
2016-12-30 20:05 joop.martens Note Edited: 0002492 View Revisions
2017-01-09 14:15 joop.martens Note Added: 0002502
2017-01-20 11:50 maik Relationship added related to 0000755
2017-01-20 11:52 maik Note Added: 0002514
2017-01-20 11:52 maik Assigned To => maik
2017-01-20 11:52 maik Status new => feedback
2017-01-20 11:57 maik Tag Attached: director
2017-01-20 11:57 maik Tag Attached: support
2017-01-20 11:57 maik Tag Attached: always incremental
2017-01-20 13:46 joop.martens Note Added: 0002517
2017-02-01 10:49 hostedpower Note Added: 0002543
2017-02-01 10:49 hostedpower Status feedback => assigned
2017-02-01 12:52 frank Assigned To maik => frank
2017-02-01 17:19 maik Note Added: 0002547
2017-02-02 14:11 joop.martens Note Added: 0002549
2017-02-15 13:40 matthijs Note Added: 0002569
2017-02-15 14:27 hostedpower Note Added: 0002570
2017-03-02 13:31 frank Assigned To frank => maik
2017-03-06 11:24 maik Tag Attached: configuration
2017-03-06 11:25 maik Note Added: 0002601
2017-03-06 11:25 maik Status assigned => closed
2017-03-06 11:25 maik Resolution open => no change required