View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001122bareos-coreGeneralpublic2019-10-18 19:322023-09-04 16:40
Reporterxyros Assigned Tobruno-at-bareos  
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionno change required 
PlatformLinuxOSUbuntuOS Version16.04
Product Version18.2.6 
Summary0001122: Consolidate queues and indefinitely orphans jobs but falsely reports status as "Consolidate OK" for last queued
DescriptionMy Consolidate job never succeeds -- quickly terminating with "Consolidate OK" while leaving all the VirtualFull jobs it started queued and orphaned.

In the WebUI listing for the allegedly successful Consolidate run, it always list the sequentially last (by job ID) client it queued as being the successful run; however, the level is "Incremental," nothing is actually done, and the client's VirtualFull job is actually still queued up with all the other clients.

In bconsole the status is similar to this:

Running Jobs:
Console connected at 15-Oct-19 15:06
 JobId Level Name Status
======================================================================
   636 Virtual PandoraFMS.2019-10-15_14.33.02_06 is waiting on max Storage jobs
   637 Virtual MongoDB.2019-10-15_14.33.03_09 is waiting on max Storage jobs
   638 Virtual DNS-DHCP.2019-10-15_14.33.04_11 is waiting on max Storage jobs
   639 Virtual Desktop_1.2019-10-15_14.33.05_19 is waiting on max Storage jobs
   640 Virtual Desktop_2.2019-10-15_14.33.05_20 is waiting on max Storage jobs
   641 Virtual Desktop_3.2019-10-15_14.33.06_21 is waiting on max Storage jobs
====


Given that above output, for example the WebUI would show the following:

    642 Consolidate desktop3-fd.hq Consolidate Incremental 0 0.00 B 0 Success
    641 Desktop_3 desktop3-fd.hq Backup VirtualFull 0 0.00 B 0 Queued
    640 Desktop_2 desktop2-fd.hq Backup VirtualFull 0 0.00 B 0 Queued
    639 Desktop_1 desktop1-fd.hq Backup VirtualFull 0 0.00 B 0 Queued
    638 DNS-DHCP dns-dhcp-fd.hq Backup VirtualFull 0 0.00 B 0 Queued
    637 MongoDB mongodb-fd.hq Backup VirtualFull 0 0.00 B 0 Queued
    636 PandoraFMS pandorafms-fd.hq Backup VirtualFull 0 0.00 B 0 Queued


I don't know if this has anything to do with the fact that I have multiple storage definitions, for each VLAN the server is on, and an additional one dedicated for the storage addressable on the default IP (see bareos-dir/storage/File.conf in attached bareos.zip file). Technically this should not matter, but I get the impression Bareos nas not been designed/tested to elegantly work in an environment where the server participates in VLANs.

The reason I'm using VLANs is so that connections do not have to go through a router to reach the clients. Therefore, the full network bandwidth of each LAN segment is available to the Bareos client/server data transfer.

I've tried debugging the Consolidate backup process, using "bareos-dir -d 400 >> /var/log/bareos-dir.log;" however, I get nothing that particularly identifies the issue. I have attached a truncated log file that contains activity starting with queuing the second-to-last. I've cut off the log at the point where it is stuck in the endless cycling with output of:

bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
etc...

For convenience, I have attached all the most relevant excerpts of my configuration files (sanitized for privacy/security reasons).

I suspect there's a bug that is responsible for this; however, I'm unable to make heads or tails of what's going on.

Could someone please take a look?

Thanks
Steps To Reproduce1. Place Bareos on a network switch (virtual or actual) with tagged VLANS
2. Configure Bareos host to have connectivity on three or more VLANs
3. Make sure you have clients you can backup, on each of the VLANs
4. Use the attached config files as reference for setting up storages and jobs for testing.
Tagsalways incremental, consolidate

Activities

xyros

xyros

2019-10-18 19:32

reporter  

bareos.zip (9,113 bytes)
bareos-dir.log (41,361 bytes)    
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Job queued. JobId=662
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Consolidating JobId 662 started.
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Looking at always incremental job Desktop_2
')
bareos-dir (200): dird/dird_conf.cc:1950-0 FilesetResource::PrintConfig
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='Windows Desktop' AND MD5='Zm/Nd/lpVk+ee++ddQ/H2B'
bareos-dir (119): dird/job.cc:1424-0 Created FileSet Windows Desktop record 7
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT ClientId,Uname FROM Client WHERE Name='desktop_2-fd.hq'
bareos-dir (100): dird/job.cc:1380-0 Created Client desktop_2-fd.hq record 17
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=14,31,49,66,83,100,117,135,152,169,200,231,471
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:154-0 unlimited jobids list:  14,31,49,66,83,100,117,135,152,169,200,231,471.
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Desktop_2: considering jobs older than 08-Oct-2019 15:58:02 for consolidation.
')
bareos-dir (10): dird/consolidate.cc:167-0 Desktop_2: considering jobs with ClientId 17 and FilesetId 7 older than 08-Oct-2019 15:58:02 for consolidation.
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=14,31,49,66,83,100,117,135,152,169,200,231
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:171-0 consolidate candidates:  14,31,49,66,83,100,117,135,152,169,200,231.
bareos-dir (10): dird/consolidate.cc:187-0 Incrementals found/required. (12/0).
bareos-dir (10): dird/consolidate.cc:190-0 total: 12, to_consolidate: 12, limit: 13.
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 17 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=14,31,49,66,83,100,117,135,152,169,200,231
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:194-0 12 consolidate ids after limit: 14,31,49,66,83,100,117,135,152,169,200,231.
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: before ConsolidateFull: jobids: 14,31,49,66,83,100,117,135,152,169,200,231
')
bareos-dir (10): dird/consolidate.cc:237-0 Previous JobId=14
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=14
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: check full age: full is 19-Sep-2019 20:50:13, allowed is 01-Oct-2019 15:58:02
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: 1 AlwaysIncrementalFullConsolidations reached -> skipping first jobid 14 independent of age
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: after ConsolidateFull: jobids: 31,49,66,83,100,117,135,152,169,200,231
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Desktop_2: Start new consolidation
')
bareos-dir (100): dird/consolidate.cc:71-0 =============== consolidate cmd=run job="Desktop_2" jobid=31,49,66,83,100,117,135,152,169,200,231 level=VirtualFull accurate=yes
bareos-dir (100): dird/ua_db.cc:155-0 UA Open database
bareos-dir (100): cats/sql_pooling.cc:61-0 DbSqlGetNonPooledConnection allocating 1 new non pooled database connection to database bareos, backend type postgresql
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false
bareos-dir (100): cats/postgresql.cc:1249-0 DB REopen bareos
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Using Catalog "MyCatalog"
')
bareos-dir (150): dird/ua_db.cc:188-0 DB bareos opened
bareos-dir (100): dird/ua_run.cc:2124-0 Using pool AI-Incremental-VLAN107
bareos-dir (100): dird/ua_run.cc:2138-0 Using next pool AI-Consolidated-VLAN107
bareos-dir (100): include/jcr.h:320-0 Construct JobControlRecord
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Job resource
bareos-dir (50): dird/storage.cc:193-0 write_storage=File-AI-VLAN107 where=Pool resource
bareos-dir (100): dird/ua_run.cc:521-0 JobId=0 using pool AI-Incremental-VLAN107 priority=10
bareos-dir (250): lib/message.cc:350-0 Copy message resource 8014018e8 to 801d0fb28
bareos-dir (100): dird/job.cc:1519-0 JobId=0 created Job=Desktop_2.2019-10-15_15.58.06_16
bareos-dir (100): dird/job.cc:178-0 Open database
bareos-dir (100): cats/sql_pooling.cc:61-0 DbSqlGetNonPooledConnection allocating 1 new non pooled database connection to database bareos, backend type postgresql
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false
bareos-dir (100): cats/postgresql.cc:1249-0 DB REopen bareos
bareos-dir (150): dird/job.cc:195-0 DB opened
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT ClientId,Uname FROM Client WHERE Name='desktop_2-fd.hq'
bareos-dir (100): dird/job.cc:1380-0 Created Client desktop_2-fd.hq record 17
bareos-dir (100): dird/job.cc:235-0 Created job record JobId=663 Name=Desktop_2.2019-10-15_15.58.06_16 Type=B Level=f
bareos-dir (150): dird/dir_plugins.cc:525-0 === enter NewPlugins ===
bareos-dir (150): dird/dir_plugins.cc:527-0 No dir plugin list!
bareos-dir (150): dird/dir_plugins.cc:215-0 No bplugin_list: GeneratePluginEvent ignored.
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Job resource
bareos-dir (200): dird/dird_conf.cc:1950-0 FilesetResource::PrintConfig
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='Windows Desktop' AND MD5='Zm/Nd/lpVk+ee++ddQ/H2B'
bareos-dir (119): dird/job.cc:1424-0 Created FileSet Windows Desktop record 7
bareos-dir (100): dird/job.cc:1247-0 entering ApplyPoolOverrides()
bareos-dir (110): dird/job.cc:917-0 get_or_create_pool=AI-Incremental-VLAN107
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='AI-Incremental-VLAN107'
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT count(*) from Media WHERE PoolId=13
bareos-dir (400): cats/sql_get.cc:671-0 Actual NumVols=12 Pool NumVols=12
bareos-dir (10): dird/vbackup.cc:98-0 Read pool=AI-Incremental-VLAN107 (From Job resource)
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query UPDATE Job SET JobStatus='C',Level='f',StartTime='2019-10-15 15:58:06',ClientId=17,JobTDate=1571180286,PoolId=13,FileSetId=7 WHERE JobId=663
bareos-dir (110): dird/job.cc:917-0 get_or_create_pool=AI-Consolidated-VLAN107
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='AI-Consolidated-VLAN107'
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT count(*) from Media WHERE PoolId=18
bareos-dir (400): cats/sql_get.cc:671-0 Actual NumVols=1 Pool NumVols=1
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Storage from Pool's NextPool resource
bareos-dir (10): dird/vbackup.cc:151-0 Write pool=AI-Consolidated-VLAN107 read rpool=AI-Incremental-VLAN107
bareos-dir (150): dird/dir_plugins.cc:215-0 No bplugin_list: GeneratePluginEvent ignored.
bareos-dir (200): dird/job.cc:118-0 Add jrc to work queue
bareos-dir (100): dird/ua_run.cc:527-0 JobId=663 NewJobId=663 using pool AI-Consolidated-VLAN107 priority=10
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Job queued. JobId=663
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Consolidating JobId 663 started.
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Looking at always incremental job Desktop_3
')
bareos-dir (200): dird/dird_conf.cc:1950-0 FilesetResource::PrintConfig
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='Windows Desktop' AND MD5='Zm/Nd/lpVk+ee++ddQ/H2B'
bareos-dir (119): dird/job.cc:1424-0 Created FileSet Windows Desktop record 7
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT ClientId,Uname FROM Client WHERE Name='desktop_3-fd.hq'
bareos-dir (100): dird/job.cc:1380-0 Created Client desktop_3-fd.hq record 18
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-15 15:58:07' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=15,32,50,67,84,101,118,136,153,170,201,232,472
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:154-0 unlimited jobids list:  15,32,50,67,84,101,118,136,153,170,201,232,472.
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Desktop_3: considering jobs older than 08-Oct-2019 15:58:02 for consolidation.
')
bareos-dir (10): dird/consolidate.cc:167-0 Desktop_3: considering jobs with ClientId 18 and FilesetId 7 older than 08-Oct-2019 15:58:02 for consolidation.
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=15,32,50,67,84,101,118,136,153,170,201,232
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:171-0 consolidate candidates:  15,32,50,67,84,101,118,136,153,170,201,232.
bareos-dir (10): dird/consolidate.cc:187-0 Incrementals found/required. (12/0).
bareos-dir (10): dird/consolidate.cc:190-0 total: 12, to_consolidate: 12, limit: 13.
bareos-dir (100): cats/sql_query.cc:96-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) with query name create_temp_accurate_jobids (36)
bareos-dir (100): cats/sql_query.cc:102-0 called: void BareosDb::FillQueryVaList(PoolMem &, BareosDb::SQL_QUERY_ENUM, __va_list_tag *) query is now CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query CREATE TABLE btemp3650 AS SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND Level = 'F' AND JobStatus IN ('T', 'W') AND Type = 'B' AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSetId = 7 ORDER BY Job.JobId DESC, Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='D' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC LIMIT 1 
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO btemp3650 (JobId, StartTime, EndTime, JobTDate, PurgedFiles) SELECT JobId, StartTime, EndTime, JobTDate, PurgedFiles FROM Job JOIN FileSet USING (FileSetId) WHERE ClientId = 18 AND JobFiles > 0 AND Level='I' AND JobStatus IN ('T','W') AND Type='B' AND StartTime > (SELECT EndTime FROM btemp3650 ORDER BY EndTime DESC LIMIT 1) AND StartTime < '2019-10-08 15:58:03' AND FileSet.FileSet= (SELECT FileSet FROM FileSet WHERE FileSetId = 7) ORDER BY Job.JobTDate DESC 
bareos-dir (1): cats/sql_get.cc:1360-0 db_accurate_get_jobids=15,32,50,67,84,101,118,136,153,170,201,232
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query DROP TABLE btemp3650
bareos-dir (10): dird/consolidate.cc:194-0 12 consolidate ids after limit: 15,32,50,67,84,101,118,136,153,170,201,232.
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: before ConsolidateFull: jobids: 15,32,50,67,84,101,118,136,153,170,201,232
')
bareos-dir (10): dird/consolidate.cc:237-0 Previous JobId=15
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=15
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: check full age: full is 19-Sep-2019 20:52:25, allowed is 01-Oct-2019 15:58:02
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: 1 AlwaysIncrementalFullConsolidations reached -> skipping first jobid 15 independent of age
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: after ConsolidateFull: jobids: 32,50,67,84,101,118,136,153,170,201,232
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Desktop_3: Start new consolidation
')
bareos-dir (100): dird/consolidate.cc:71-0 =============== consolidate cmd=run job="Desktop_3" jobid=32,50,67,84,101,118,136,153,170,201,232 level=VirtualFull accurate=yes
bareos-dir (100): dird/ua_db.cc:155-0 UA Open database
bareos-dir (100): cats/sql_pooling.cc:61-0 DbSqlGetNonPooledConnection allocating 1 new non pooled database connection to database bareos, backend type postgresql
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false
bareos-dir (100): cats/postgresql.cc:1249-0 DB REopen bareos
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Using Catalog "MyCatalog"
')
bareos-dir (150): dird/ua_db.cc:188-0 DB bareos opened
bareos-dir (100): dird/ua_run.cc:2124-0 Using pool AI-Incremental-VLAN107
bareos-dir (100): dird/ua_run.cc:2138-0 Using next pool AI-Consolidated-VLAN107
bareos-dir (100): include/jcr.h:320-0 Construct JobControlRecord
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Job resource
bareos-dir (50): dird/storage.cc:193-0 write_storage=File-AI-VLAN107 where=Pool resource
bareos-dir (100): dird/ua_run.cc:521-0 JobId=0 using pool AI-Incremental-VLAN107 priority=10
bareos-dir (250): lib/message.cc:350-0 Copy message resource 8014018e8 to 801d0fd28
bareos-dir (100): dird/job.cc:1519-0 JobId=0 created Job=Desktop_3.2019-10-15_15.58.06_17
bareos-dir (100): dird/job.cc:178-0 Open database
bareos-dir (100): cats/sql_pooling.cc:61-0 DbSqlGetNonPooledConnection allocating 1 new non pooled database connection to database bareos, backend type postgresql
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false
bareos-dir (100): cats/cats_backends.cc:81-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false
bareos-dir (100): cats/postgresql.cc:1249-0 DB REopen bareos
bareos-dir (150): dird/job.cc:195-0 DB opened
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT ClientId,Uname FROM Client WHERE Name='desktop_3-fd.hq'
bareos-dir (100): dird/job.cc:1380-0 Created Client desktop_3-fd.hq record 18
bareos-dir (100): dird/job.cc:235-0 Created job record JobId=664 Name=Desktop_3.2019-10-15_15.58.06_17 Type=B Level=f
bareos-dir (150): dird/dir_plugins.cc:525-0 === enter NewPlugins ===
bareos-dir (150): dird/dir_plugins.cc:527-0 No dir plugin list!
bareos-dir (150): dird/dir_plugins.cc:215-0 No bplugin_list: GeneratePluginEvent ignored.
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Job resource
bareos-dir (200): dird/dird_conf.cc:1950-0 FilesetResource::PrintConfig
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='Windows Desktop' AND MD5='Zm/Nd/lpVk+ee++ddQ/H2B'
bareos-dir (119): dird/job.cc:1424-0 Created FileSet Windows Desktop record 7
bareos-dir (100): dird/job.cc:1247-0 entering ApplyPoolOverrides()
bareos-dir (110): dird/job.cc:917-0 get_or_create_pool=AI-Incremental-VLAN107
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='AI-Incremental-VLAN107'
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT count(*) from Media WHERE PoolId=13
bareos-dir (400): cats/sql_get.cc:671-0 Actual NumVols=12 Pool NumVols=12
bareos-dir (10): dird/vbackup.cc:98-0 Read pool=AI-Incremental-VLAN107 (From Job resource)
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query UPDATE Job SET JobStatus='C',Level='f',StartTime='2019-10-15 15:58:06',ClientId=18,JobTDate=1571180286,PoolId=13,FileSetId=7 WHERE JobId=664
bareos-dir (110): dird/job.cc:917-0 get_or_create_pool=AI-Consolidated-VLAN107
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='AI-Consolidated-VLAN107'
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT count(*) from Media WHERE PoolId=18
bareos-dir (400): cats/sql_get.cc:671-0 Actual NumVols=1 Pool NumVols=1
bareos-dir (100): dird/storage.cc:157-0 write_storage_list=File-AI-VLAN107
bareos-dir (100): dird/storage.cc:166-0 write_storage=File-AI-VLAN107 where=Storage from Pool's NextPool resource
bareos-dir (10): dird/vbackup.cc:151-0 Write pool=AI-Consolidated-VLAN107 read rpool=AI-Incremental-VLAN107
bareos-dir (150): dird/dir_plugins.cc:215-0 No bplugin_list: GeneratePluginEvent ignored.
bareos-dir (200): dird/job.cc:118-0 Add jrc to work queue
bareos-dir (100): dird/ua_run.cc:527-0 JobId=664 NewJobId=664 using pool AI-Consolidated-VLAN107 priority=10
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Job queued. JobId=664
')
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: Consolidating JobId 664 started.
')
bareos-dir (100): dird/consolidate.cc:316-0 Enter backup_cleanup()
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query UPDATE Job SET JobStatus='T',Level='I',EndTime='2019-10-15 15:58:06',ClientId=18,JobBytes=0,ReadBytes=0,JobFiles=0,JobErrors=0,VolSessionId=0,VolSessionTime=0,PoolId=0,FileSetId=7,JobTDate=1571180286,RealEndTime='2019-10-15 15:58:06',PriorJobId=0,HasBase=0,PurgedFiles=0 WHERE JobId=650
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=650
bareos-dir (100): cats/sql_query.cc:124-0 called: bool BareosDb::SqlQuery(const char *, int) with query INSERT INTO Log (JobId, Time, LogText) VALUES (650,'2019-10-15 15:58:06','bareos-dir JobId 650: BAREOS 18.2.6 (13Feb19): 15-Oct-2019 15:58:06
  JobId:                  650
  Job:                    Consolidate.2019-10-15_15.58.00_03
  Scheduled time:         15-Oct-2019 15:58:00
  Start time:             15-Oct-2019 15:58:02
  End time:               15-Oct-2019 15:58:06
  Bareos binary info:     self-compiled: Get official binaries and vendor support on bareos.com
  Termination:            Consolidate OK

')
bareos-dir (100): dird/consolidate.cc:364-0 Leave ConsolidateCleanup()
bareos-dir (200): lib/runscript.cc:150-0 runscript: running all RunScript object (AfterJob) JobStatus=T
bareos-dir (150): dird/dir_plugins.cc:215-0 No bplugin_list: GeneratePluginEvent ignored.
bareos-dir (50): dird/job.cc:682-0 ======== End Job stat=T ==========
bareos-dir (200): dird/jobq.cc:479-0 Done lock mutex after running job. Release locks.
bareos-dir (50): dird/jobq.cc:932-0 Dec Job=Consolidate rncj=0
bareos-dir (200): dird/job.cc:1560-0 Start dird FreeJcr
bareos-dir (100): lib/jcr.cc:170-0 write_last_jobs seek to 192
bareos-dir (200): dird/job.cc:1624-0 End dird FreeJcr
bareos-dir (100): lib/jcr.cc:446-0 FreeCommonJcr: 801561c28 
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN105 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN105 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN105 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN108 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN108 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN108 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir (50): dird/jobq.cc:1004-0 Fail to acquire Wstore=File-AI-VLAN107 wncj=1
bareos-dir (50): dird/jobq.cc:971-0 Dec Rstore=File-AI-VLAN107 rncj=0
bareos-dir (50): dird/jobq.cc:951-0 Inc Rstore=File-AI-VLAN107 rncj=1
bareos-dir.log (41,361 bytes)   
xyros

xyros

2020-06-11 10:11

reporter   ~0004008

Figured it out myself. The official documentation needs a full working example, as the always incremental backup configuration is very finicky and the error message provide insufficient guidance for resolution.
bruno-at-bareos

bruno-at-bareos

2023-09-04 16:40

manager   ~0005367

Fixed by user adapted configuration

Issue History

Date Modified Username Field Change
2019-10-18 19:32 xyros New Issue
2019-10-18 19:32 xyros Tag Attached: always incremental
2019-10-18 19:32 xyros Tag Attached: consolidate
2019-10-18 19:32 xyros File Added: bareos.zip
2019-10-18 19:32 xyros File Added: bareos-dir.log
2020-06-11 10:11 xyros Note Added: 0004008
2023-09-04 16:40 bruno-at-bareos Assigned To => bruno-at-bareos
2023-09-04 16:40 bruno-at-bareos Status new => resolved
2023-09-04 16:40 bruno-at-bareos Resolution open => no change required
2023-09-04 16:40 bruno-at-bareos Note Added: 0005367