Bacula-users

Re: [Bacula-users] Checksum warnings during backup?

2010-07-08 12:22:59
Subject: Re: [Bacula-users] Checksum warnings during backup?
From: Andreas Koch <koch AT esa.informatik.tu-darmstadt DOT de>
To: Martin Simmons <martin AT lispworks DOT com>
Date: Thu, 08 Jul 2010 18:19:49 +0200
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 07/05/2010 09:19 PM, Martin Simmons wrote:
>>>>>> On Mon, 05 Jul 2010 17:54:29 +0200, Andreas Koch said:
>>
>> I used the wrong JobID, those were indeed the rows for the differential
>> backup. The data for the underlying full is attached below. It does lack a
>> checksum for table.7.bz2.
> 
> OK, so that explains the warning.
> 
> Now the mystery is why it doesn't have a checksum, which is presumably a
> problem with the Full backup.
> 
> Which database backend are you using (I could guess postgresql from the man
> pages!)?

Yes, postgresql-8.4.

> 
> Is your Bacula built with batch insert?

Yes.

> 
> Running bacula-dir with debug level 400 and doing a new FULL backup should
> print messages about what the Director receives from the SD for each file.

OK, here's an excerpt of the data:

For the broken file ``table.7.bz2´´, the following lines appear to be relevant:

gundabad-dir: catreq.c:405-25 UpdCat msg=UpdCat
Job=DefaultBackup.2010-07-08_17.49.28_03 FileAttributes
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=138
Strm=1 data_len=157
gundabad-dir: catreq.c:429-25 dird<stored: stream=1
/usr/share/postgresql-8.4/man/man7/table.7.bz2
gundabad-dir: catreq.c:430-25 dird<stored: attr=PwA Dky9 IGk C A A A 6 BAA I
BMBmj+ BMBmj+ BMBmkF BW A C
gundabad-dir: catreq.c:449-25 dird<filed: stream=1
/usr/share/postgresql-8.4/man/man7/table.7.bz2
gundabad-dir: catreq.c:450-25 dird<filed: attr=PwA Dky9 IGk C A A A 6 BAA I
BMBmj+ BMBmj+ BMBmkF BW A C
gundabad-dir: catreq.c:405-25 UpdCat msg=UpdCat
Job=DefaultBackup.2010-07-08_17.49.28_03 FileAttributes
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=139
Strm=1 data_len=117
gundabad-dir: catreq.c:411-25 Cached attr. Stream=1
fname=/usr/share/postgresql-8.4/man/man7/table.7.bz2
gundabad-dir: sql_create.c:921-25
Fname=/usr/share/postgresql-8.4/man/man7/table.7.bz2
gundabad-dir: sql_create.c:922-25 put_file_into_catalog

What is missing here are any lines dealing with the checksum (which appear to
be called Digest in this log). As an example, for the next file, the log shown
above directly continues:

gundabad-dir: catreq.c:429-25 dird<stored: stream=1
/usr/share/postgresql-8.4/man/man7/alter_view.7.bz2
gundabad-dir: catreq.c:430-25 dird<stored: attr=PwA Dkxs IGk B A A A Q2 BAA I
BMBmj8 BMBmj8 BMBmkF A A C
gundabad-dir: catreq.c:449-25 dird<filed: stream=1
/usr/share/postgresql-8.4/man/man7/alter_view.7.bz2
gundabad-dir: catreq.c:450-25 dird<filed: attr=PwA Dkxs IGk B A A A Q2 BAA I
BMBmj8 BMBmj8 BMBmkF A A C
gundabad-dir: catreq.c:405-25 UpdCat msg=UpdCat
Job=DefaultBackup.2010-07-08_17.49.28_03 FileAttributes
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=139
Strm=10 data_len=20
gundabad-dir: catreq.c:487-25 DigestLen=27 Digest=dmOnNO8HFwkl4ZdkvcLMOCBjg+A
type=10
gundabad-dir: catreq.c:492-25 Cached attr with digest. Stream=1
fname=/usr/share/postgresql-8.4/man/man7/alter_view.7.bz2
gundabad-dir: sql_create.c:921-25
Fname=/usr/share/postgresql-8.4/man/man7/alter_view.7.bz2
gundabad-dir: sql_create.c:922-25 put_file_into_catalog

Note that there is a DigestLen... line between the UpdCat.../Cached attr...
lines, which was missing from the prior log output. Also, a normal file
reports ``Cached attr with digest ...´´, while the broken file just has
``Cached attr.´´

There's another discrepancy. Normally, each file index (here abbreviated as
FI) occurs in _two_ lines. For a non-broken file (here with FI=137), this
would be

gundabad-dir: catreq.c:405-25 UpdCat msg=UpdCat
Job=DefaultBackup.2010-07-08_17.49.28_03 FileAttributes
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=137
Strm=1 data_len=123
gundabad-dir: catreq.c:429-25 dird<stored: stream=1
/usr/share/postgresql-8.4/man/man7/alter_tablespace.7.bz2
gundabad-dir: catreq.c:430-25 dird<stored: attr=PwA Dkxm IGk B A A A Kz BAA I
BMBmj8 BMBmj8 BMBmkF A A C
gundabad-dir: catreq.c:449-25 dird<filed: stream=1
/usr/share/postgresql-8.4/man/man7/alter_tablespace.7.bz2
gundabad-dir: catreq.c:450-25 dird<filed: attr=PwA Dkxm IGk B A A A Kz BAA I
BMBmj8 BMBmj8 BMBmkF A A C
gundabad-dir: catreq.c:405-25 UpdCat msg=UpdCat
Job=DefaultBackup.2010-07-08_17.49.28_03 FileAttributes
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=137
Strm=10 data_len=20
gundabad-dir: catreq.c:487-25 DigestLen=27 Digest=vJvtTQ9F2sguOypX9ThR7u5IJi8
type=10
gundabad-dir: catreq.c:492-25 Cached attr with digest. Stream=1
fname=/usr/share/postgresql-8.4/man/man7/alter_tablespace.7.bz2
gundabad-dir: sql_create.c:921-25
Fname=/usr/share/postgresql-8.4/man/man7/alter_tablespace.7.bz2
gundabad-dir: sql_create.c:922-25 put_file_into_catalog

with FI=137 occuring in the two log lines

gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=137
Strm=1 data_len=123
...
gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=137
Strm=10 data_len=20

The broken file table.7.bz2 has FI=138, which shows up only _once_ in the log
(excerpt from first log fragment in this mail)

gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=138
Strm=1 data_len=157

Nowhere does a line mentioning FI=138 and Strm=10 occur. Instead, at the usual
position (after the missing Digest line), the Cached ... line already mentions
FI=139 and Strm=1:

gundabad-dir: catreq.c:407-25 UpdCat VolSessId=12 VolSessT=1277829932 FI=139
Strm=1 data_len=117

I hope this info and my attempts at interpretation are helpful!

Best,
  Andreas
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkw1+qEACgkQk5ta2EV7DoxjrgCfVfWnCT46xGppBRQL9IB8Ltg0
sHcAn3rac9C4W0niMl0R3QXMU92EFf9C
=rEQx
-----END PGP SIGNATURE-----

------------------------------------------------------------------------------
This SF.net email is sponsored by Sprint
What will you do first with EVO, the first 4G phone?
Visit sprint.com/first -- http://p.sf.net/sfu/sprint-com-first
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users