Problem with always incremental job 2 years of running

[Silvio Schloeffel]

Hi,


I'm not really sure how to describe my problem, so please ask if you
miss something.

I have multiple always incr jobs running and it worked as expected.
BUT
Since ~ one week I have a problem with one of the jobs. The strange
thing is that the problem started after the latest upgrade.
The system tried to create a virtual full and failed but the incremental
backup is running..



6 2024-10-12 21:28:21 bareos-dir JobId 18885: Error: Bareos bareos-dir
23.0.4~pre219.fcc1a62ef (30Aug24):
Build OS: Red Hat Enterprise Linux release 8.10 (Ootpa)
JobId: 18885
Job: bachserv17-bach_operation-backup.2024-10-12_21.00.01_59
Backup Level: Virtual Full
Client: "bachserv17" 23.0.4~pre131.d9aa41d53 (08Aug24) Red Hat
Enterprise Linux Server release 7.9 (Maipo),redhat
FileSet: "BachOperation" 2022-09-28 09:45:55
Pool: "AI-Consolidated" (From Job Pool's NextPool resource)
Catalog: "MyCatalog" (From Client resource)
Storage: "File" (From Storage from Pool's NextPool resource)
Scheduled time: 12-Okt-2024 21:00:01
Start time: 13-Aug-2024 20:10:05
End time: 13-Aug-2024 20:12:26
Elapsed time: 2 mins 21 secs
Priority: 10
Allow Mixed Priority: no
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
Bareos binary info: Bareos community build (UNSUPPORTED): Get
professional support from https://www.bareos.com
Job triggered by: User
Termination: *** Backup Error ***

5 2024-10-12 21:28:21 bareos-dir JobId 18885: Replicating deleted files
from jobids 18850,17153 to jobid 18885
4 2024-10-12 21:28:21 bareos-dir JobId 18885: Fatal error: Could not
create bootstrap file
3 2024-10-12 21:28:21 bareos-dir JobId 18885: No files found to read. No
bootstrap file written.
2 2024-10-12 21:28:21 bareos-dir JobId 18885: Unable to get Job record.
ERR=cats/sql_get.cc:266 No Job found for JobName

1 2024-10-12 21:28:21 bareos-dir JobId 18885: Start Virtual Backup JobId
18885, Job=bachserv17-bach_operation-backup.2024-10-12_21.00.01_59
Zeige Zeile 1 bis 6 von 6 Zeilen.


The message "No Job found for JobName" ist strange for me because the
Job exists unchanged since Sep 2022.

The console also showed me old virt full backups created by this job.

Choose a query (1-22): 20
bachserv17-bach_operation-backup
+----------------------------------+-------+----------------------+---------------------+--------+---------+
| jobname | jobid | volumename |
start | files | bytes |
+----------------------------------+-------+----------------------+---------------------+--------+---------+
| bachserv17-bach_operation-backup | 18448 | AI-Consolidated-0033 |
2024-07-29 20:10:05 | 25,387 | 124.505 |
| bachserv17-bach_operation-backup | 18448 | AI-Consolidated-0318 |
2024-07-29 20:10:05 | 25,387 | 124.505 |
| bachserv17-bach_operation-backup | 18448 | AI-Consolidated-0319 |
2024-07-29 20:10:05 | 25,387 | 124.505 |
| bachserv17-bach_operation-backup | 18955 | AI-Consolidated-0316 |
2024-08-16 20:10:03 | 25,446 | 126.081 |
| bachserv17-bach_operation-backup | 18955 | AI-Consolidated-0021 |
2024-08-16 20:10:03 | 25,446 | 126.081 |
| bachserv17-bach_operation-backup | 18955 | AI-Consolidated-0030 |
2024-08-16 20:10:03 | 25,446 | 126.081 |
| bachserv17-bach_operation-backup | 17283 | AI-Incremental-0060 |
2024-08-17 20:10:03 | 25,446 | 0.000 |
| bachserv17-bach_operation-backup | 17315 | AI-Incremental-0321 |
2024-08-19 20:10:04 | 25,446 | 126.077 |
| bachserv17-bach_operation-backup | 17315 | AI-Incremental-0071 |
2024-08-19 20:10:04 | 25,446 | 126.077 |
| bachserv17-bach_operation-backup | 17315 | AI-Incremental-0061 |
2024-08-19 20:10:04 | 25,446 | 126.077 |
| bachserv17-bach_operation-backup | 17384 | AI-Incremental-0117 |
2024-08-21 20:10:03 | 4 | 0.000 |
| bachserv17-bach_operation-backup | 17513 | AI-Incremental-0084 |
2024-08-26 20:10:03 | 2 | 0.000 |
| bachserv17-bach_operation-backup | 17615 | AI-Incremental-0331 |
2024-08-29 20:10:03 | 3 | 0.000 |
| bachserv17-bach_operation-backup | 17650 | AI-Incremental-0151 |
2024-08-30 20:10:03 | 3 | 0.000 |
| bachserv17-bach_operation-backup | 17712 | AI-Incremental-0096 |
2024-09-01 20:10:04 | 54 | 106.028 |
| bachserv17-bach_operation-backup | 17712 | AI-Incremental-0101 |
2024-09-01 20:10:04 | 54 | 106.028 |
| bachserv17-bach_operation-backup | 17712 | AI-Incremental-0155 |
2024-09-01 20:10:04 | 54 | 106.028 |
| bachserv17-bach_operation-backup | 17717 | AI-Incremental-0295 |
2024-09-02 20:10:03 | 26 | 0.003 |
| bachserv17-bach_operation-backup | 17917 | AI-Incremental-0135 |
2024-09-09 20:10:03 | 49 | 0.013 |
| bachserv17-bach_operation-backup | 17952 | AI-Incremental-0132 |
2024-09-10 20:10:03 | 41 | 0.002 |
| bachserv17-bach_operation-backup | 17986 | AI-Incremental-0131 |
2024-09-11 20:10:03 | 7 | 0.001 |
| bachserv17-bach_operation-backup | 18054 | AI-Incremental-0143 |
2024-09-13 20:10:03 | 3 | 0.000 |
| bachserv17-bach_operation-backup | 18308 | AI-Incremental-0176 |
2024-09-23 20:10:03 | 6 | 0.000 |
| bachserv17-bach_operation-backup | 18375 | AI-Incremental-0197 |
2024-09-25 20:10:03 | 8 | 0.000 |
| bachserv17-bach_operation-backup | 18409 | AI-Incremental-0183 |
2024-09-26 20:10:03 | 152 | 0.006 |
| bachserv17-bach_operation-backup | 18441 | AI-Incremental-0187 |
2024-09-27 20:10:03 | 313 | 0.007 |
| bachserv17-bach_operation-backup | 18497 | AI-Incremental-0191 |
2024-09-30 20:10:04 | 2 | 0.000 |
| bachserv17-bach_operation-backup | 18533 | AI-Incremental-0294 |
2024-10-01 20:10:04 | 68 | 107.830 |
| bachserv17-bach_operation-backup | 18533 | AI-Incremental-0205 |
2024-10-01 20:10:04 | 68 | 107.830 |
| bachserv17-bach_operation-backup | 18533 | AI-Incremental-0291 |
2024-10-01 20:10:04 | 68 | 107.830 |
| bachserv17-bach_operation-backup | 18568 | AI-Incremental-0211 |
2024-10-02 20:10:03 | 54 | 0.009 |
| bachserv17-bach_operation-backup | 18703 | AI-Incremental-0219 |
2024-10-07 20:10:03 | 3 | 0.000 |
| bachserv17-bach_operation-backup | 18739 | AI-Incremental-0220 |
2024-10-08 20:10:03 | 2 | 0.000 |
| bachserv17-bach_operation-backup | 18775 | AI-Incremental-0225 |
2024-10-09 20:10:03 | 8 | 0.000 |
| bachserv17-bach_operation-backup | 18809 | AI-Incremental-0229 |
2024-10-10 20:10:03 | 2 | 0.000 |
| bachserv17-bach_operation-backup | 18843 | AI-Incremental-0234 |
2024-10-11 20:10:03 | 11 | 0.000 |
| bachserv17-bach_operation-backup | 18905 | AI-Incremental-0238 |
2024-10-14 20:10:03 | 19 | 0.001 |
| bachserv17-bach_operation-backup | 18976 | AI-Incremental-0307 |
2024-10-16 20:10:03 | 46 | 0.016 |What also
| bachserv17-bach_operation-backup | 19010 | AI-Incremental-0053 |
2024-10-17 20:10:03 | 12 | 0.000 |
+----------------------------------+-------+----------------------+---------------------+--------+---------

What also wonders me is the change of the job level:

*list jobid=18955
Automatically selected Catalog: MyCatalog
Using Catalog "MyCatalog"
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+-----------------+-----------+
| jobid | name | client | starttime
| duration | type | level | jobfiles | jobbytes | jobstatus |
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+-----------------+-----------+
| 18955 | bachserv17-bach_operation-backup | bachserv17 | 2024-08-16
20:10:03 | 00:00:29 | B | I | 25,446 | 135,378,736,321 | T
|
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+-----------------+-----------+
*list jobid=18885
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+----------+-----------+
| jobid | name | client | starttime
| duration | type | level | jobfiles | jobbytes | jobstatus |
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+----------+-----------+
| 18885 | bachserv17-bach_operation-backup | bachserv17 | 2024-08-13
20:10:05 | 00:02:21 | B | f | 0 | 0 | f |
+-------+----------------------------------+------------+---------------------+----------+------+-------+----------+----------+-----------+


Can someone explain me what happens here.

File and job definition has not been changed:
fileset:
-rw-r--r--. 1 bareos bareos 1208 15. Okt 2020 bach_operation.conf
job:
-rw-r--r--. 1 bareos bareos 424 27. Sep 2022
bachserv17-bach_operation-backup.conf
jobdef:
-rw-r--r--. 1 bareos bareos 1393 27. Sep 2022 backupOperation.conf


Best

Silvio

[Sebastian Sura]

Hi Silvio,

What change in joblevel are you talking about ? Its not clear to me what
job 18955 and 18885 have to do with each other.
The 'no job found for jobname' error message is really weird. This is
not talking about the jobs in the configuration but the jobs that were
actually run.
Somehow it tried to look up a job with jobid=0 which is why it got
confused.  Did this happen only once or can you easily reproduce it ?
If you can reproduce it, could you try to grab a debug trace on the
director when you run this job ?  You can do so by running

```
setdebug level=200 trace=1 director
```

in bconsole.  This should also tell you where the file is getting
saved.  Dont forget to disable it again after you reproduced it, e.g.
with setdebug level=10 trace=0.

If they are still available, could you post the joblogs for 18850 and
17153 ?

Kind Regards
Sebastian Sura

Am 18.10.24 um 10:19 schrieb Silvio Schloeffel:

--
Sebastian Sura sebasti...@bareos.com
Bareos GmbH & Co. KG Phone: +49 221 630693-0
https://www.bareos.com
Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
Komplementär: Bareos Verwaltungs-GmbH
Geschäftsführer: Stephan Dühr, Jörg Steffens, Philipp Storz