View Issue Details

IDProjectCategoryView StatusLast Update
0001452bareos-corefile daemonpublic2022-06-27 14:16
Reportermdc Assigned Tobruno-at-bareos  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
Platformx86_64OSCentOSOS Versionstream 8
Product Version21.1.2 
Summary0001452: PostgreSQL backup plugin works only with "Check File Changes = no"
DescriptionWhen using Check File Changes = yes like it is recommend in the documentation, the backups will end with an warning about changed files.
It looks like the same problem like in 0001449. But I am not sure.
Additional InformationSee the attachments for job logs.
TagsNo tags attached.
bareos-master: impactyes
bareos-master: actionfixed
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

Activities

mdc

mdc

2022-05-02 14:07

reporter  

full.txt (741,737 bytes)
inc.txt (4,699 bytes)   
Automatically selected Catalog: Datenbank
Using Catalog "Datenbank"
 2022-05-02 12:52:47 Bareos Director JobId 1124: Start Backup JobId 1124, Job=PostgreSQL_sl-it-t-pgsql2.2022-05-02_12.52.45_31
 2022-05-02 12:52:47 Bareos Director JobId 1124: Connected Storage daemon at sl-it-p-bck3.mdc-berlin.net:9103, encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 Bareos Director JobId 1124: Created new Volume "Inc-PostgreSQL-0047" in catalog.
 2022-05-02 12:52:47 Bareos Director JobId 1124: Using Device "PostgreSQLInc" to write.
 2022-05-02 12:52:47 Bareos Director JobId 1124: Connected Client: sl-it-t-pgsql2 at sl-it-t-pgsql2.mdc-berlin.net:9102, encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 Bareos Director JobId 1124:  Handshake: Immediate TLS  2022-05-02 12:52:47 Bareos Director JobId 1124:  Encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: python3-fd-mod: Got lastBackupStopTime 1651488681 from restore object of job 1123
 2022-05-02 12:52:47 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: python3-fd-mod: Got lastLSN 00000000/6A000138 from restore object of job 1123
 2022-05-02 12:52:47 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: Connected Storage daemon at sl-it-p-bck3.mdc-berlin.net:9103, encryption: PSK-AES256-CBC-SHA TLSv1/SSLv3
 2022-05-02 12:52:47 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: Extended attribute support is enabled
 2022-05-02 12:52:47 sl-it-p-bck3.mdc-berlin.net JobId 1124: Labeled new Volume "Inc-PostgreSQL-0047" on device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc).
 2022-05-02 12:52:47 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: ACL support is enabled
 2022-05-02 12:52:48 sl-it-p-bck3.mdc-berlin.net JobId 1124: Wrote label to prelabeled Volume "Inc-PostgreSQL-0047" on device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc)
 2022-05-02 12:52:48 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: python3-fd-mod: Connected to Postgres version 120010
 2022-05-02 12:52:48 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: python3-fd-mod: Current LSN 00000000/6B000060, last LSN: 00000000/6A000138
 2022-05-02 12:52:48 sl-it-t-pgsql2.mdc-berlin.net JobId 1124: Error: /var/lib/pgsql/wal_archive/00000001000000000000006B: size changed during backup.
 2022-05-02 12:52:48 sl-it-p-bck3.mdc-berlin.net JobId 1124: Releasing device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc).
 2022-05-02 12:52:48 sl-it-p-bck3.mdc-berlin.net JobId 1124: Elapsed time=00:00:01, Transfer rate=25.62 K Bytes/second
 2022-05-02 12:52:48 Bareos Director JobId 1124: Insert of attributes batch table with 1 entries start
 2022-05-02 12:52:48 Bareos Director JobId 1124: Insert of attributes batch table done
 2022-05-02 12:52:48 Bareos Director JobId 1124: Bareos Bareos Director 21.1.2 (17Mar22):
  Build OS:               CentOS Stream release 8
  JobId:                  1124
  Job:                    PostgreSQL_sl-it-t-pgsql2.2022-05-02_12.52.45_31
  Backup Level:           Incremental, since=2022-05-02 12:50:55
  Client:                 "sl-it-t-pgsql2" 21.1.2 (17Mar22) CentOS Linux release 7.9.2009 (Core),redhat
  FileSet:                "PostgreSQL" 2022-05-02 09:26:30
  Pool:                   "Inc PostgreSQL" (From Job resource)
  Catalog:                "Datenbank" (From Client resource)
  Storage:                "PostgreSQL Inc" (From Pool resource)
  Scheduled time:         02-May-2022 12:52:42
  Start time:             02-May-2022 12:52:47
  End time:               02-May-2022 12:52:48
  Elapsed time:           1 sec
  Priority:               10
  FD Files Written:       2
  SD Files Written:       2
  FD Bytes Written:       24,669 (24.66 KB)
  SD Bytes Written:       25,628 (25.62 KB)
  Rate:                   24.7 KB/s
  Software Compression:   99.9 % (gzip9)
  VSS:                    no
  Encryption:             no
  Accurate:               no
  Volume name(s):         Inc-PostgreSQL-0047
  Volume Session Id:      29
  Volume Session Time:    1651473422
  Last Volume Bytes:      29,516 (29.51 KB)
  Non-fatal FD errors:    1
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Bareos binary info:     self-compiled: Get official binaries and vendor support on bareos.com
  Job triggered by:       User
  Termination:            Backup OK -- with warnings

 2022-05-02 12:52:48 Bareos Director JobId 1124: Begin pruning Jobs older than 7 days .
 2022-05-02 12:52:48 Bareos Director JobId 1124: No Jobs found to prune.
 2022-05-02 12:52:48 Bareos Director JobId 1124: Begin pruning Files.
 2022-05-02 12:52:48 Bareos Director JobId 1124: No Files found to prune.
 2022-05-02 12:52:48 Bareos Director JobId 1124: End auto prune.

You have messages.
inc.txt (4,699 bytes)   
mdc

mdc

2022-05-03 06:24

reporter   ~0004583

inc-2.txt (4,555 bytes)   
Automatically selected Catalog: Datenbank
Using Catalog "Datenbank"
 2022-05-02 12:52:47 Bareos Director JobId 1124: Start Backup JobId 1124, Job=PostgreSQL_demo-server.2022-05-02_12.52.45_31
 2022-05-02 12:52:47 Bareos Director JobId 1124: Connected Storage daemon at storage-demo.foo.foo:9103, encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 Bareos Director JobId 1124: Created new Volume "Inc-PostgreSQL-0047" in catalog.
 2022-05-02 12:52:47 Bareos Director JobId 1124: Using Device "PostgreSQLInc" to write.
 2022-05-02 12:52:47 Bareos Director JobId 1124: Connected Client: demo-server at demo-server.foo.foo:9102, encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 Bareos Director JobId 1124:  Handshake: Immediate TLS  2022-05-02 12:52:47 Bareos Director JobId 1124:  Encryption: PSK-AES256-CBC-SHA SSLv3
 2022-05-02 12:52:47 demo-server.foo.foo JobId 1124: python3-fd-mod: Got lastBackupStopTime 1651488681 from restore object of job 1123
 2022-05-02 12:52:47 demo-server.foo.foo JobId 1124: python3-fd-mod: Got lastLSN 00000000/6A000138 from restore object of job 1123
 2022-05-02 12:52:47 demo-server.foo.foo JobId 1124: Connected Storage daemon at storage-demo.foo.foo:9103, encryption: PSK-AES256-CBC-SHA TLSv1/SSLv3
 2022-05-02 12:52:47 demo-server.foo.foo JobId 1124: Extended attribute support is enabled
 2022-05-02 12:52:47 storage-demo.foo.foo JobId 1124: Labeled new Volume "Inc-PostgreSQL-0047" on device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc).
 2022-05-02 12:52:47 demo-server.foo.foo JobId 1124: ACL support is enabled
 2022-05-02 12:52:48 storage-demo.foo.foo JobId 1124: Wrote label to prelabeled Volume "Inc-PostgreSQL-0047" on device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc)
 2022-05-02 12:52:48 demo-server.foo.foo JobId 1124: python3-fd-mod: Connected to Postgres version 120010
 2022-05-02 12:52:48 demo-server.foo.foo JobId 1124: python3-fd-mod: Current LSN 00000000/6B000060, last LSN: 00000000/6A000138
 2022-05-02 12:52:48 demo-server.foo.foo JobId 1124: Error: /var/lib/pgsql/wal_archive/00000001000000000000006B: size changed during backup.
 2022-05-02 12:52:48 storage-demo.foo.foo JobId 1124: Releasing device "PostgreSQL Inc" (/mnt/backup/bareos/PostgreSQL/Inc).
 2022-05-02 12:52:48 storage-demo.foo.foo JobId 1124: Elapsed time=00:00:01, Transfer rate=25.62 K Bytes/second
 2022-05-02 12:52:48 Bareos Director JobId 1124: Insert of attributes batch table with 1 entries start
 2022-05-02 12:52:48 Bareos Director JobId 1124: Insert of attributes batch table done
 2022-05-02 12:52:48 Bareos Director JobId 1124: Bareos Bareos Director 21.1.2 (17Mar22):
  Build OS:               CentOS Stream release 8
  JobId:                  1124
  Job:                    PostgreSQL_demo-server.2022-05-02_12.52.45_31
  Backup Level:           Incremental, since=2022-05-02 12:50:55
  Client:                 "demo-server" 21.1.2 (17Mar22) CentOS Linux release 7.9.2009 (Core),redhat
  FileSet:                "PostgreSQL" 2022-05-02 09:26:30
  Pool:                   "Inc PostgreSQL" (From Job resource)
  Catalog:                "Datenbank" (From Client resource)
  Storage:                "PostgreSQL Inc" (From Pool resource)
  Scheduled time:         02-May-2022 12:52:42
  Start time:             02-May-2022 12:52:47
  End time:               02-May-2022 12:52:48
  Elapsed time:           1 sec
  Priority:               10
  FD Files Written:       2
  SD Files Written:       2
  FD Bytes Written:       24,669 (24.66 KB)
  SD Bytes Written:       25,628 (25.62 KB)
  Rate:                   24.7 KB/s
  Software Compression:   99.9 % (gzip9)
  VSS:                    no
  Encryption:             no
  Accurate:               no
  Volume name(s):         Inc-PostgreSQL-0047
  Volume Session Id:      29
  Volume Session Time:    1651473422
  Last Volume Bytes:      29,516 (29.51 KB)
  Non-fatal FD errors:    1
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Bareos binary info:     self-compiled: Get official binaries and vendor support on bareos.com
  Job triggered by:       User
  Termination:            Backup OK -- with warnings

 2022-05-02 12:52:48 Bareos Director JobId 1124: Begin pruning Jobs older than 7 days .
 2022-05-02 12:52:48 Bareos Director JobId 1124: No Jobs found to prune.
 2022-05-02 12:52:48 Bareos Director JobId 1124: Begin pruning Files.
 2022-05-02 12:52:48 Bareos Director JobId 1124: No Files found to prune.
 2022-05-02 12:52:48 Bareos Director JobId 1124: End auto prune.

You have messages.
inc-2.txt (4,555 bytes)   
bruno-at-bareos

bruno-at-bareos

2022-05-04 17:08

developer   ~0004589

Can you attach Job & fileset configuration file please.
mdc

mdc

2022-05-05 11:54

reporter   ~0004593

Yes of course:
File set:
Fileset {
  Name = "PostgreSQL"
  Description = "Sichert alle PostgreSQL Datenbanken"
  Include {
    Options {
      Signature = SHA512
      Compression = GZIP9
      Accurate = pugsmc1n
      No Atime = yes
      # Bug https://bugs.bareos.org/view.php?id=1452
      Check File Changes = yes
    }
    File = "\\|sh -c 'ls /etc/psql_*'"
    Plugin = "python"
             ":module_path=/usr/lib64/bareos/plugins"
             ":module_name=bareos-fd-postgres"
             ":postgresDataDir=/var/lib/pgsql/current/data"
             ":walArchive=/var/lib/pgsql/wal_archive"
             ":dbHost=/var/run/postgresql"
             ":role=backup"
  }
}

JobDef:
JobDefs {
  Name = "Backup PostgreSQL"
  Type = Backup
  Level = Incremental
  FileSet = "PostgreSQL"
  Job Defs = "WebUI"
  Schedule = "PostgreSQL"
  Pool = "Inc PostgreSQL"
  Run Script {
    Command = "/etc/bareos/scripts/pgsql_wal_archive_clean_up %l"
    Runs When = Before
    Fail Job On Error = No
  }
}

JobDef WebUI:
JobDefs {
        Name = "WebUI"
        Description = "Damit Restore aus dem WebUI geht."
        Run Script {
                Console = ".bvfs_update"
                RunsWhen = After
                RunsOnClient = No
        }
        Job Defs =Meldungen
}

JobDef:
JobDefs {
  Name = "Meldungen"
  Description = "Wie die Meldungen von Bareos behandelt werden."
  Messages = FOO
}

Hint:
":role=backup
is an extension to the add-on, needed at our side. See 0001456 here, for the details.
posgresql-addon-role.patch (977 bytes)   
diff -Nuar bareos-Release-21.1.2.org/core/src/plugins/filed/python/postgres/BareosFdPluginPostgres.py bareos-Release-21.1.2/core/src/plugins/filed/python/postgres/BareosFdPluginPostgres.py
--- bareos-Release-21.1.2.org/core/src/plugins/filed/python/postgres/BareosFdPluginPostgres.py	2022-05-05 10:51:57.293098759 +0200
+++ bareos-Release-21.1.2/core/src/plugins/filed/python/postgres/BareosFdPluginPostgres.py	2022-05-05 10:54:34.070777307 +0200
@@ -183,6 +183,9 @@
                     self.dbuser, database=self.dbname, host=self.dbHost
                 )
 
+            if self.options["role"]:
+              self.dbCon.run("SET ROLE {0}".format(self.options["role"]))
+              bareosfd.DebugMessage(100, "SQL role switched to {0}\n".format(self.options["role"]))
             result = self.dbCon.run("SELECT current_setting('server_version_num')")
             self.pgVersion = int(result[0][0])
             # WARNING: JobMessages cause fatal errors at this stage
posgresql-addon-role.patch (977 bytes)   
bruno-at-bareos

bruno-at-bareos

2022-05-05 13:43

developer   ~0004594

I'll give you the result of actual test of the plugin and its configuration used (see in source systemtest/tests/py3plug

PRETEST: running /bareos/git/build/systemtests/ctest_custom_pretest.sh script
PRETEST: running system tests on the sourcetree
PRETEST: checking for executable /bareos/git/build/core/src/dird/bareos-dir
PRETEST: checking configured hostname (25186cca9a4f) ... OK
    Start 341: system:py3plug-fd-postgres
1/3 Test 0000341: system:py3plug-fd-postgres ....... Passed 36.57 sec

cat systemtests/tests/py3plug-fd-postgres/etc/bareos/bareos-dir.d/fileset/PluginTest.conf
FileSet {
  Name = "PluginTest"
  Description = "Test the Plugin functionality with a Python Plugin."
  Include {
    Options {
      signature = MD5
      CheckFileChanges = Yes
    }
    Plugin = "python3"
             ":module_path=/bareos/git/build/systemtests/tests/py3plug-fd-postgres/python-modules"
             ":module_name=bareos-fd-postgres"
             ":dbHost=/bareos/git/build/systemtests/tests/py3plug-fd-postgres/tmp"
             ":postgresDataDir=/bareos/git/build/systemtests/tests/py3plug-fd-postgres/database/data/"
             ":walArchive=/bareos/git/build/systemtests/tests/py3plug-fd-postgres/database/wal_archive/"
  }
}

Even if we have the checkfilechanges. of course as recommend we don't mix plugin and file job.
mdc

mdc

2022-05-05 14:19

reporter   ~0004597

Hi,
I have disabled the file part for testing(So that only the plug in is used.), but the result is the same.
with CheckFileChanges = Yes, many warnings about altered files.
If it helps, I can let the client the fd in debug mode, to get more informations.
bruno-at-bareos

bruno-at-bareos

2022-05-10 17:25

developer   ~0004608

After a review today with developer here's the conclusion and next step that will be done.

We will change the documentation for master and other release to clarify the situation of this parameter
CheckFileChanges is not intended to be run with plugin, and its usage should be reserved for File exclusively.

Now if you would like to run one job with a debug level set at 1000 and report the trace here, this will be really appreciated
as it can serve for an eventually future development about make CheckFileChanges supported on plugin.

Thanks.
bruno-at-bareos

bruno-at-bareos

2022-05-12 09:47

developer   ~0004618

Thanks for the report, we open internally a task for that, but there's no eta when it will be done nor if it will be.
Maybe a first check will be to see if CheckFileChanges can be used in Plugin backup context.

At least now the documentation will be changed to reflect this statement.
See PR-1180 https://github.com/bareos/bareos/pull/1180 if you want comment.
mdc

mdc

2022-05-12 10:39

reporter   ~0004621

Thanks for the information.
bruno-at-bareos

bruno-at-bareos

2022-06-27 14:16

developer   ~0004646

PR1180 merged

Issue History

Date Modified Username Field Change
2022-05-02 14:07 mdc New Issue
2022-05-02 14:07 mdc File Added: full.txt
2022-05-02 14:07 mdc File Added: inc.txt
2022-05-03 06:24 mdc Note Added: 0004583
2022-05-03 06:24 mdc File Added: inc-2.txt
2022-05-04 17:08 bruno-at-bareos Note Added: 0004589
2022-05-05 11:54 mdc Note Added: 0004593
2022-05-05 11:54 mdc File Added: posgresql-addon-role.patch
2022-05-05 13:43 bruno-at-bareos Note Added: 0004594
2022-05-05 14:19 mdc Note Added: 0004597
2022-05-10 13:03 bruno-at-bareos Assigned To => bruno-at-bareos
2022-05-10 13:03 bruno-at-bareos Status new => assigned
2022-05-10 17:25 bruno-at-bareos Note Added: 0004608
2022-05-12 09:47 bruno-at-bareos Note Added: 0004618
2022-05-12 10:39 mdc Note Added: 0004621
2022-06-27 14:16 bruno-at-bareos Status assigned => closed
2022-06-27 14:16 bruno-at-bareos Resolution open => fixed
2022-06-27 14:16 bruno-at-bareos bareos-master: impact => yes
2022-06-27 14:16 bruno-at-bareos bareos-master: action => fixed
2022-06-27 14:16 bruno-at-bareos Note Added: 0004646