View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001577bareos-coredirectorpublic2023-12-01 09:522023-12-05 09:29
Reportertroloff Assigned Tobruno-at-bareos  
PrioritynormalSeverityminorReproducibilityhave not tried
Status closedResolutionno change required 
PlatformVM (dir)OSDebianOS Version11
Product Version22.1.1 
Summary0001577: Fill Path table Query failed / relation "batch" does not exist
DescriptionDuring backup, a job fails with error message:
2023-11-25 21:31:08 bareos-dir JobId 3455: Insert of attributes batch table with 787949 entries start
 2023-11-25 21:31:58 bareos-dir JobId 3455: Fatal error: cats/sql_create.cc:798 Fill Path table Query failed: INSERT INTO Path (Path) SELECT a.Path FROM ( SELECT DISTINCT Path FROM batch ) AS a WHERE NOT EXISTS ( SELECT Path FROM Path WHERE Path = a.Path ) : ERR=FEHLER: Relation »batch« existiert nicht
ZEILE 1: ...h) SELECT a.Path FROM ( SELECT DISTINCT Path FROM batch ) AS...

(German part reads "ERROR: Relation 'batch' doesn't exist")

Other jobs are working without problems. Joblog attached.
TagsNo tags attached.

Activities

troloff

troloff

2023-12-01 09:52

reporter  

joblog_3455.txt (10,431 bytes)    
Connecting to Director localhost:9101
 Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
1000 OK: bareos-dir Version: 22.1.1 (23 October 2023)
Bareos subscription release.
Support available on https://www.bareos.com/support/
You are connected using the default console

Enter a period (.) to cancel a command.
list joblog jobid=3455
Automatically selected Catalog: MyCatalog
Using Catalog "MyCatalog"
 2023-11-21 21:00:00 bareos-dir JobId 3455: Start Backup JobId 3455, Job=backup-bunker-b1.2023-11-21_21.00.00_55
 2023-11-21 21:00:00 bareos-dir JobId 3455: Connected Storage daemon at bareos-storage-rkp:9103, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-21 21:00:00 bareos-dir JobId 3455:  Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-21 21:00:00 bareos-dir JobId 3455: Connected Client: rbunker2021-fd at rbunker2021:9102, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-21 21:00:00 bareos-dir JobId 3455:  Handshake: Immediate TLS 
 2023-11-21 21:00:00 bareos-dir JobId 3455:  Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-21 21:00:01 bareos-dir JobId 3455: Using Device "tapedrive-1" to write.
 2023-11-21 21:00:01 rbunker2021-fd JobId 3455: Fileset has autoexclude disabled, ignoring FilesNotToBackup Registry key
 2023-11-21 21:00:01 rbunker2021-fd JobId 3455: Connected Storage daemon at bareos-storage-rkp:9103, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-21 21:00:01 rbunker2021-fd JobId 3455:  Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
 2023-11-22 06:12:55 bareos-sd JobId 3455: End of Volume "000189M8" at 188:76917 on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst). Write of 1048576 bytes got -1.
 2023-11-22 06:13:01 bareos-sd JobId 3455: Re-read of last block succeeded.
 2023-11-22 06:13:01 bareos-sd JobId 3455: End of medium on Volume "000189M8" Bytes=14,671,011,604,480 Blocks=13,991,425 at 22-Nov-2023 06:13.
 2023-11-22 06:13:01 bareos-sd JobId 3455: 3307 Issuing autochanger "unload slot 40, drive 1" command.
 2023-11-22 06:15:06 bareos-dir JobId 3455: There are no more Jobs associated with Volume "000003L8". Marking it purged.
 2023-11-22 06:15:06 bareos-dir JobId 3455: All records pruned from Volume "000003L8"; marking it "Purged"
 2023-11-22 06:15:06 bareos-dir JobId 3455: Recycled volume "000003L8"
 2023-11-22 06:15:07 bareos-sd JobId 3455: 3304 Issuing autochanger "load slot 3, drive 1" command.
 2023-11-22 06:15:39 bareos-sd JobId 3455: 3305 Autochanger "load slot 3, drive 1", status is OK.
 2023-11-22 06:15:42 bareos-sd JobId 3455: Recycled volume "000003L8" on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst), all previous data lost.
 2023-11-22 06:15:42 bareos-sd JobId 3455: New volume "000003L8" mounted on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst) at 22-Nov-2023 06:15.
 2023-11-23 03:13:27 bareos-dir JobId 3455: Insert of attributes batch table with 800001 entries start
 2023-11-23 03:13:40 bareos-dir JobId 3455: Insert of attributes batch table done
 2023-11-23 22:58:26 bareos-sd JobId 3455: End of Volume "000004L8" at 164:60553 on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst). Write of 1048576 bytes got -1.
 2023-11-23 22:58:30 bareos-sd JobId 3455: Re-read of last block succeeded.
 2023-11-23 22:58:30 bareos-sd JobId 3455: End of medium on Volume "000004L8" Bytes=16,463,420,592,128 Blocks=15,700,742 at 23-Nov-2023 22:58.
 2023-11-23 22:58:30 bareos-sd JobId 3455: 3307 Issuing autochanger "unload slot 4, drive 1" command.
 2023-11-23 23:00:24 bareos-dir JobId 3455: Volume "000005L8" has Volume Retention of 8380800 sec. and has 1 jobs that will be pruned
 2023-11-23 23:00:24 bareos-dir JobId 3455: Purging the following 1 JobIds: 564
 2023-11-23 23:00:24 bareos-dir JobId 3455: There are no more Jobs associated with Volume "000005L8". Marking it purged.
 2023-11-23 23:00:24 bareos-dir JobId 3455: All records pruned from Volume "000005L8"; marking it "Purged"
 2023-11-23 23:00:24 bareos-dir JobId 3455: Recycled volume "000005L8"
 2023-11-23 23:00:25 bareos-sd JobId 3455: 3304 Issuing autochanger "load slot 5, drive 1" command.
 2023-11-23 23:00:56 bareos-sd JobId 3455: 3305 Autochanger "load slot 5, drive 1", status is OK.
 2023-11-23 23:00:59 bareos-sd JobId 3455: Recycled volume "000005L8" on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst), all previous data lost.
 2023-11-23 23:00:59 bareos-sd JobId 3455: New volume "000005L8" mounted on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst) at 23-Nov-2023 23:00.
 2023-11-24 16:59:19 bareos-sd JobId 3455: End of Volume "000005L8" at 141:29409 on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst). Write of 1048576 bytes got -1.
 2023-11-24 16:59:22 bareos-sd JobId 3455: Re-read of last block succeeded.
 2023-11-24 16:59:22 bareos-sd JobId 3455: End of medium on Volume "000005L8" Bytes=14,130,774,117,376 Blocks=13,476,157 at 24-Nov-2023 16:59.
 2023-11-24 16:59:22 bareos-sd JobId 3455: 3307 Issuing autochanger "unload slot 5, drive 1" command.
 2023-11-24 17:00:55 bareos-dir JobId 3455: Volume "000006L8" has Volume Retention of 8380800 sec. and has 100 jobs that will be pruned
 2023-11-24 17:00:55 bareos-dir JobId 3455: Purging the following 100 JobIds: 584,604,614,624,634,644,654,675,685,695,705,715,725,738,748,758,768,791,801,811,821,831,841,851,861,871,881,902,912,922,932,942,952,962,972,982,992,1015,1025,1035,1045,1055,1065,1075,1085,1095,1105,1171,1191,1201,1211,1221,1244,1254,1264,1274,1284,1294,1304,1314,1324,1334,1355,1365,1375,1385,1395,1405,1415,1425,1435,1445,1468,1478,1536,1537,1560,1561,1635,1636,1656,1657,1677,1678,1698,1699,1733,1734,1754,1755,1775,1776,1796,1797,1817,1818,1850,1851,1871,1872
 2023-11-24 17:01:04 bareos-dir JobId 3455: There are no more Jobs associated with Volume "000006L8". Marking it purged.
 2023-11-24 17:01:04 bareos-dir JobId 3455: All records pruned from Volume "000006L8"; marking it "Purged"
 2023-11-24 17:01:04 bareos-dir JobId 3455: Recycled volume "000006L8"
 2023-11-24 17:01:05 bareos-sd JobId 3455: 3304 Issuing autochanger "load slot 20, drive 1" command.
 2023-11-24 17:01:36 bareos-sd JobId 3455: 3305 Autochanger "load slot 20, drive 1", status is OK.
 2023-11-24 17:01:39 bareos-sd JobId 3455: Recycled volume "000006L8" on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst), all previous data lost.
 2023-11-24 17:01:39 bareos-sd JobId 3455: New volume "000006L8" mounted on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst) at 24-Nov-2023 17:01.
 2023-11-25 19:19:39 bareos-sd JobId 3455: End of Volume "000006L8" at 142:64162 on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst). Write of 1048576 bytes got -1.
 2023-11-25 19:19:44 bareos-sd JobId 3455: Re-read of last block succeeded.
 2023-11-25 19:19:44 bareos-sd JobId 3455: End of medium on Volume "000006L8" Bytes=14,267,214,435,328 Blocks=13,606,276 at 25-Nov-2023 19:19.
 2023-11-25 19:19:44 bareos-sd JobId 3455: 3307 Issuing autochanger "unload slot 20, drive 1" command.
 2023-11-25 19:21:28 bareos-dir JobId 3455: Volume "000189M8" has Volume Retention of 8380800 sec. and has 4 jobs that will be pruned
 2023-11-25 19:21:28 bareos-dir JobId 3455: Purging the following 4 JobIds: 1907,1908,1949,1950
 2023-11-25 19:21:29 bareos-dir JobId 3455: Using Volume "000037L8" from 'Scratch' pool.
 2023-11-25 19:21:29 bareos-sd JobId 3455: 3304 Issuing autochanger "load slot 2, drive 1" command.
 2023-11-25 19:22:03 bareos-sd JobId 3455: 3305 Autochanger "load slot 2, drive 1", status is OK.
 2023-11-25 19:22:06 bareos-sd JobId 3455: Wrote label to prelabeled Volume "000037L8" on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst)
 2023-11-25 19:22:06 bareos-sd JobId 3455: New volume "000037L8" mounted on device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst) at 25-Nov-2023 19:22.
 2023-11-25 21:31:08 bareos-sd JobId 3455: Releasing device "tapedrive-1" (/dev/tape/by-id/scsi-35000e111511ce065-nst).
 2023-11-25 21:31:08 bareos-sd JobId 3455: Elapsed time=96:21:18, Transfer rate=172.9 M Bytes/second
 2023-11-25 21:31:08 bareos-dir JobId 3455: Insert of attributes batch table with 787949 entries start
 2023-11-25 21:31:58 bareos-dir JobId 3455: Fatal error: cats/sql_create.cc:798 Fill Path table Query failed: INSERT INTO Path (Path) SELECT a.Path FROM ( SELECT DISTINCT Path FROM batch ) AS a WHERE NOT EXISTS ( SELECT Path FROM Path WHERE Path = a.Path ) : ERR=FEHLER:  Relation »batch« existiert nicht
ZEILE 1: ...h) SELECT a.Path FROM ( SELECT DISTINCT Path FROM batch ) AS...
                                                              ^


 2023-11-25 21:31:58 bareos-dir JobId 3455: Error: Bareos bareos-dir 22.1.1 (23Oct23):
  Build OS:               Debian GNU/Linux 11 (bullseye)
  JobId:                  3455
  Job:                    backup-bunker-b1.2023-11-21_21.00.00_55
  Backup Level:           Incremental, since=2023-11-20 21:00:00
  Client:                 "rbunker2021-fd" 23.0.0~pre870.ee085db55 (06Jul23) Microsoft Windows Server 2012  (build 9200), 64-bit,Cross-compile
  FileSet:                "bunker-b1" 2023-04-04 17:49:04
  Pool:                   "Tape-RKP-Incr-B" (From Job IncPool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "tape-storage-rkp" (From Job resource)
  Scheduled time:         21-Nov-2023 21:00:00
  Start time:             21-Nov-2023 21:00:01
  End time:               25-Nov-2023 21:31:58
  Elapsed time:           4 days 31 mins 57 secs
  Priority:               10
  FD Files Written:       1,587,951
  SD Files Written:       1,587,951
  FD Bytes Written:       59,989,908,457,917 (59.98 TB)
  SD Bytes Written:       59,990,522,488,132 (59.99 TB)
  Rate:                   172624.4 KB/s
  Software Compression:   None
  VSS:                    no
  Encryption:             no
  Accurate:               no
  Volume name(s):         000189M8|000003L8|000004L8|000005L8|000006L8|000037L8
  Volume Session Id:      279
  Volume Session Time:    1696820621
  Last Volume Bytes:      1,351,483,507,712 (1.351 TB)
  Non-fatal FD errors:    1
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Bareos binary info:     Bareos subscription release
  Job triggered by:       Scheduler
  Termination:            *** Backup Error ***

You have messages.
joblog_3455.txt (10,431 bytes)   
bruno-at-bareos

bruno-at-bareos

2023-12-04 17:11

manager   ~0005565

You should open a new ticket in the support portal https://servicedesk.bareos.com

Mainly look suspicious, like if PostgreSQL at that precise time has missed free temporary space.
troloff

troloff

2023-12-05 08:11

reporter   ~0005567

Indeed seems to be a postgres / free space issue. Will investigate further - feel free to close this issue.
bruno-at-bareos

bruno-at-bareos

2023-12-05 09:28

manager   ~0005568

If you have trouble to plan correctly the db please review again also the documentation
https://docs.bareos.org/TasksAndConcepts/CatalogMaintenance.html#postgresql-database

There's a number of tricks there to calculate and check the size.
Also you may want to rerun the bareos-support tool script, at the end it gives numerous interesting data about the catalog and postgresql configuration.

The big advise, is to have at least the size of table file as free temp space + 20%
bruno-at-bareos

bruno-at-bareos

2023-12-05 09:29

manager   ~0005569

Pg temp space trouble.

Issue History

Date Modified Username Field Change
2023-12-01 09:52 troloff New Issue
2023-12-01 09:52 troloff File Added: joblog_3455.txt
2023-12-04 17:11 bruno-at-bareos Note Added: 0005565
2023-12-05 08:11 troloff Note Added: 0005567
2023-12-05 09:28 bruno-at-bareos Note Added: 0005568
2023-12-05 09:29 bruno-at-bareos Assigned To => bruno-at-bareos
2023-12-05 09:29 bruno-at-bareos Status new => closed
2023-12-05 09:29 bruno-at-bareos Resolution open => no change required
2023-12-05 09:29 bruno-at-bareos Note Added: 0005569