View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0000958bareos-coreGeneralpublic2018-06-01 16:222023-09-12 16:36
ReporterMarceloRuiz Assigned Tobruno-at-bareos  
PriorityhighSeveritymajorReproducibilityhave not tried
Status closedResolutionunable to reproduce 
PlatformLinuxOSUbuntuOS Version18.04
Product Version17.2.5 
Summary0000958: Always incremental backups always upgraded to full
DescriptionAfter upgrading bareos from 16.2 to version 17.2, each "always incremental" backup job is upgraded to a full backup. This happens all the time and the unmodified configuration used to work fine with 16.2.
Client: Ubuntu 18.04
Server (Director, Storage Daemon): FreeNas 11.1 (Freebsd 11.1-RELEASE-p10)
Steps To ReproduceOn a fresh installation, create an always incremental job. The job will be upgraded to full during the first backup (expected) and subsequent ones (not expected).
Additional InformationI figured maybe the script that upgraded the tables had a problem, so I dropped the whole database and recreated it again and reset bareos to zero (deleting all the stored data and status on every single component including the 2 clients I have). In this way I ruled out problems with the upgrade from one version to another, but the problem remains.
Looking at the logs I see the confirmation the first full backup upgraded from incremental finished with status OK, but the following same job (which should run as incremental) is upgraded "from Full to Full" and the reason is that a prior failed full job was found in the catalog, but the database table has the right information for the OK status.
I am attaching a sanitized version of the log file with the two Job Ids involved. The rest of the logs belong to the second client failing jobs (that on purpose I turned off) to see what was going on more easily.
Tagsalways incremental, freebsd

Activities

MarceloRuiz

MarceloRuiz

2018-06-01 16:22

reporter  

bareos.log (6,342 bytes)    
25-May 17:02 freenas-bareos-dir JobId 1: No prior Full backup Job record found.
25-May 17:02 freenas-bareos-dir JobId 1: No prior or suitable Full backup found in catalog. Doing FULL backup.
25-May 17:02 freenas-bareos-dir JobId 1: Start Backup JobId 1, Job=marcelo-qosmio-backup-data.2018-05-25_17.02.38_04
25-May 17:02 freenas-bareos-dir JobId 1: Created new Volume "marcelo-qosmio-full-data-pool-20180525-1702-1" in catalog.
25-May 17:02 freenas-bareos-dir JobId 1: Using Device "file-device-cons-01" to write.
25-May 17:02 freenas-bareos-dir JobId 1: Using Client Initiated Connection (marcelo-qosmio-fd).
25-May 17:02 freenas-bareos-sd JobId 1: Labeled new Volume "marcelo-qosmio-full-data-pool-20180525-1702-1" on device "file-device-cons-01" (/mnt/bareos-storage-cons-01).
25-May 17:02 freenas-bareos-sd JobId 1: Wrote label to prelabeled Volume "marcelo-qosmio-full-data-pool-20180525-1702-1" on device "file-device-cons-01" (/mnt/bareos-storage-cons-01)
25-May 17:53 freenas-bareos-sd JobId 1: Elapsed time=00:50:43, Transfer rate=7.148 M Bytes/second
25-May 17:53 freenas-bareos-sd JobId 1: Sending spooled attrs to the Director. Despooling 62,200,473 bytes ...
25-May 17:53 freenas-bareos-dir JobId 1: Insert of attributes batch table with 173967 entries start
25-May 17:53 freenas-bareos-dir JobId 1: Insert of attributes batch table done
25-May 17:53 freenas-bareos-dir JobId 1: Bareos freenas-bareos-dir 17.2.5 (14Feb18):
  Build OS:               amd64-portbld-freebsd11.1 freebsd 11.1-RELEASE-p10
  JobId:                  1
  Job:                    marcelo-qosmio-backup-data.2018-05-25_17.02.38_04
  Backup Level:           Full (upgraded from Incremental)
  Client:                 "marcelo-qosmio-fd" 17.2.4 (21Sep17) x86_64-pc-linux-gnu,ubuntu,Ubuntu 16.04 LTS,xUbuntu_16.04,x86_64
  FileSet:                "marcelo-qosmio-data-fileset" 2018-05-25 17:02:38
  Pool:                   "marcelo-qosmio-full-data-pool" (From Job FullPool override)
  Catalog:                "freebird-catalog" (From Client resource)
  Storage:                "freenas-cons-storage-01" (From Pool resource)
  Scheduled time:         25-May-2018 17:02:35
  Start time:             25-May-2018 17:02:41
  End time:               25-May-2018 17:53:39
  Elapsed time:           50 mins 58 secs
  Priority:               20
  FD Files Written:       173,967
  SD Files Written:       173,967
  FD Bytes Written:       21,721,656,142 (21.72 GB)
  SD Bytes Written:       21,754,268,515 (21.75 GB)
  Rate:                   7103.2 KB/s
  Software Compression:   None
  VSS:                    no
  Encryption:             no
  Accurate:               yes
  Volume name(s):         marcelo-qosmio-full-data-pool-20180525-1702-1
  Volume Session Id:      1
  Volume Session Time:    1527282105
  Last Volume Bytes:      21,775,207,249 (21.77 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

25-May 17:53 freenas-bareos-dir JobId 1: Begin pruning Jobs older than 6 months .
25-May 17:53 freenas-bareos-dir JobId 1: No Jobs found to prune.
25-May 17:53 freenas-bareos-dir JobId 1: Begin pruning Files.
25-May 17:53 freenas-bareos-dir JobId 1: No Files found to prune.
25-May 17:53 freenas-bareos-dir JobId 1: End auto prune.
25-May 18:00 freenas-bareos-dir JobId 5: Prior failed job found in catalog. Upgrading to Full.
25-May 18:00 freenas-bareos-dir JobId 5: Start Backup JobId 5, Job=marcelo-qosmio-backup-data.2018-05-25_18.00.00_23
25-May 18:00 freenas-bareos-dir JobId 5: Using Device "file-device-cons-01" to write.
25-May 18:00 freenas-bareos-dir JobId 5: Using Client Initiated Connection (marcelo-qosmio-fd).
25-May 18:00 freenas-bareos-sd JobId 5: Volume "marcelo-qosmio-full-data-pool-20180525-1702-1" previously written, moving to end of data.
25-May 18:00 freenas-bareos-sd JobId 5: Ready to append to end of Volume "marcelo-qosmio-full-data-pool-20180525-1702-1" size=21775207249
25-May 18:45 freenas-bareos-sd JobId 5: Elapsed time=00:45:35, Transfer rate=7.953 M Bytes/second
25-May 18:45 freenas-bareos-sd JobId 5: Sending spooled attrs to the Director. Despooling 62,228,738 bytes ...
25-May 18:45 freenas-bareos-dir JobId 5: Insert of attributes batch table with 174047 entries start
25-May 18:45 freenas-bareos-dir JobId 5: Insert of attributes batch table done
25-May 18:45 freenas-bareos-dir JobId 5: Bareos freenas-bareos-dir 17.2.5 (14Feb18):
  Build OS:               amd64-portbld-freebsd11.1 freebsd 11.1-RELEASE-p10
  JobId:                  5
  Job:                    marcelo-qosmio-backup-data.2018-05-25_18.00.00_23
  Backup Level:           Full (upgraded from Full)
  Client:                 "marcelo-qosmio-fd" 17.2.4 (21Sep17) x86_64-pc-linux-gnu,ubuntu,Ubuntu 16.04 LTS,xUbuntu_16.04,x86_64
  FileSet:                "marcelo-qosmio-data-fileset" 2018-05-25 17:02:38
  Pool:                   "marcelo-qosmio-full-data-pool" (From Job FullPool override)
  Catalog:                "freebird-catalog" (From Client resource)
  Storage:                "freenas-cons-storage-01" (From Pool resource)
  Scheduled time:         25-May-2018 18:00:00
  Start time:             25-May-2018 18:00:01
  End time:               25-May-2018 18:45:50
  Elapsed time:           45 mins 49 secs
  Priority:               20
  FD Files Written:       174,047
  SD Files Written:       174,047
  FD Bytes Written:       21,721,293,131 (21.72 GB)
  SD Bytes Written:       21,753,917,769 (21.75 GB)
  Rate:                   7901.5 KB/s
  Software Compression:   None
  VSS:                    no
  Encryption:             no
  Accurate:               yes
  Volume name(s):         marcelo-qosmio-full-data-pool-20180525-1702-1
  Volume Session Id:      4
  Volume Session Time:    1527282105
  Last Volume Bytes:      43,550,064,986 (43.55 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

25-May 18:45 freenas-bareos-dir JobId 5: Begin pruning Jobs older than 6 months .
25-May 18:45 freenas-bareos-dir JobId 5: No Jobs found to prune.
25-May 18:45 freenas-bareos-dir JobId 5: Begin pruning Files.
25-May 18:45 freenas-bareos-dir JobId 5: No Files found to prune.
25-May 18:45 freenas-bareos-dir JobId 5: End auto prune.
bareos.log (6,342 bytes)   
MarceloRuiz

MarceloRuiz

2020-02-17 04:30

reporter   ~0003818

Problem still present in version 19.2.6 and Postgres 11.
The message: "Prior failed job found in catalog. Upgrading to Full." is not very helpful. At least it should show the previous JobId its referencing to and the job status (in my latest test it will show that the JobID is 1 and the status is T).
Is there any way to debug this behavior?
bruno-at-bareos

bruno-at-bareos

2023-08-22 13:20

manager   ~0005324

Is this is still the case with 22.1.0?
To have a chance to understand and maybe reproduce it (as it is not the case actually) giving the full log between both job, and also output of the list jobs bconsole command will be mandatory.
bruno-at-bareos

bruno-at-bareos

2023-09-12 16:36

manager   ~0005423

No answer, no return with recent version.

Issue History

Date Modified Username Field Change
2018-06-01 16:22 MarceloRuiz New Issue
2018-06-01 16:22 MarceloRuiz File Added: bareos.log
2020-02-17 04:23 MarceloRuiz Tag Attached: always incremental
2020-02-17 04:23 MarceloRuiz Tag Attached: freebsd
2020-02-17 04:30 MarceloRuiz Note Added: 0003818
2023-08-22 13:20 bruno-at-bareos Assigned To => bruno-at-bareos
2023-08-22 13:20 bruno-at-bareos Status new => feedback
2023-08-22 13:20 bruno-at-bareos Note Added: 0005324
2023-09-12 16:36 bruno-at-bareos Status feedback => closed
2023-09-12 16:36 bruno-at-bareos Resolution open => unable to reproduce
2023-09-12 16:36 bruno-at-bareos Note Added: 0005423