Re: [Bacula-users] scheduled job different that manually initiated job? --WAS: Re: Backup problem with 1 of 2 Raspberry PI using Raspbian (Debian)

Johannsen, Thorsten Tue, 10 Apr 2018 04:00:57 -0700

Hi Martin,

On 09.04.2018 13:56, Martin Simmons wrote:

Are you setting accurate=yes only in the schedule?  If so, you need to also
pass accurate=yes in the bconsole run command.  Alternatively, add it to the
job definition.


Heureka!

I was actually starting to believe there was a bug in bacula. As itturns out, I've set "Accurate = no" in the Job config but "Accurate =yes" in the Schedule.


This of course explains the behavior!


Note: Backup works when accurate=no is specified, and failes after

---------------------------------------------------------------------------

2018-04-10 12:46:08heBacula-dir JobId 1738: Sending Accurate informationto the FD.

---------------------------------------------------------------------------

if accurate=yes is given.

To debug the client problem, try

setdebug level=100 trace=1 client=heRPI02-fd


if I do this in bconsole having the client debug turned on, I see

---------------------------------------------------------------------------

heRPI02-fd: job.c:608-0 setdebug_cmd: setdebug=100 trace=1 hangup=-1blowup=-1 options= tags=

---------------------------------------------------------------------------

but find / |grep bacula.trace on bacula-dir and heRPI02 does not yieldany files.


to make it create a bacula.trace file or run the bacula-fd with -f -d 100.

If level 100 does not show enough, then increase it.


This one was done with "-d999"

---------------------------------------------------------------------------

heRPI02-fd: message.c:788-1738 Enter dispatch_msg type=6 msg=heRPI02-fdJobId 1738: ClientBeforeJob: exiting...heRPI02-fd: message.c:991-1738 DIRECTOR for following msg: heRPI02-fdJobId 1738: ClientBeforeJob: exiting...

heRPI02-fd: bpipe.c:240-1738 Wait for 15341 opt=0
heRPI02-fd: bpipe.c:248-1738 Got break wpid=15341 status=0 ERR=none
heRPI02-fd: bpipe.c:269-1738 child status=0
heRPI02-fd: bpipe.c:284-1738 returning stat=0,0
heRPI02-fd: runscript.c:254-1738 runscript OK
heRPI02-fd: job.c:752-1738 Back from run_scripts ClientBeforeJob now: OK
heRPI02-fd: job.c:288-1738 <dird: accurate files=53201
heRPI02-fd: job.c:311-1738 Executing Dir accurate files=53201
 command.
heRPI02-fd: htable.c:67-1738 malloc buf=7520b020 size=1000000 rem=27544016
Bacula interrupted by signal 11: Segmentation violation

Kaboom! bacula-fd, heRPI02-fd got signal 11 - Segmentation violation at10-Apr-2018 12:46:18. Attempting traceback.

Kaboom! exepath=/usr/sbin/

heRPI02-fd: htable.c:130-1738 Leave hash_index hash=0x7520b068index=59779085

heRPI02-fd: htable.c:283-1738 Insert: hash=0 index=59779085

heRPI02-fd: htable.c:286-1738 Insert hp=7520b030 index=1507item=7520b030 offset=0heRPI02-fd: htable.c:293-1738 Insert hp->next=0 hp->hash=0x390280dhp->key=<NULL>

heRPI02-fd: htable.c:299-1738 Leave insert index=1507 num_items=1 key=/mnt/

heRPI02-fd: accurate.c:230-1738 add fname=</mnt/> lstat=LMC HtB EHt C AA A BAA BAA I BaqFXr BaqEVw BaqFXr A A d delta_seq=0 chksum=heRPI02-fd: htable.c:130-1738 Leave hash_index hash=0x1a45d18index=-1036830508

heRPI02-fd: htable.c:283-1738 Insert: hash=3b2ac index=-1036830508

heRPI02-fd: htable.c:286-1738 Insert hp=7520b0b0 index=7140item=7520b0b0 offset=0

heRPI02-fd: signal.c:135-1738 sig=11 Segmentation violation
heRPI02-fd: signal.c:205-1738 Working=/var/lib/bacula
heRPI02-fd: signal.c:206-1738 btpath=/usr/sbin/btraceback
heRPI02-fd: signal.c:207-1738 exepath=/usr/sbin/bacula-fd
heRPI02-fd: signal.c:236-1738 Doing waitpid
Calling: /usr/sbin/btraceback /usr/sbin/bacula-fd 15336 /var/lib/bacula
bsmtp: bsmtp.c:488-0 Failed to connect to mailhost localhost
The btraceback call returned 1
Dumping: /var/lib/bacula/heRPI02-fd.15336.lockdump
heRPI02-fd: signal.c:238-1738 Done waitpid
heRPI02-fd: lockmgr.c:1157-1738 lockmgr disabled
------------------------------------------------------------------------


Thanks in advance,

kind regards,

Thorsten

__Martin

On Sat, 7 Apr 2018 21:57:25 +0200, Johannsen, Thorsten said:


Hello list,

I'm still struggeling with my Raspberry PIs of which one (heRPI01) is
backing up fine and the other one (heRPI02) isn't.

The one that has problems during backup always terminates after "sending
accurate information to the FD".


-----------------------------------------------------------------------------------------------------------------------------------------------------------------
2018-04-07 21:00:38heRPI02-fd JobId 1692: ClientBeforeJob: exiting...
2018-04-07 21:00:38heBacula-dir JobId 1692: Sending Accurate information to the 
FD.
2018-04-07 21:00:50heBacula-dir JobId 1692: Error: bsock.c:721 Write error 
sending 97 bytes to Client: heRPI02-fd:heRPI02:9102: ERR=Connection reset by 
peer
2018-04-07 21:00:51heBacula-dir JobId 1692: Error: bsock.c:609 Socket has 
errors=1 on call to Client: heRPI02-fd:heRPI02:9102
2018-04-07 21:00:51heBacula-dir JobId 1692: Fatal error: Network error with FD 
during Backup: ERR=Connection reset by peer
2018-04-07 21:01:51heBacula-dir JobId 1692: Fatal error: No Job status returned 
from FD.
-----------------------------------------------------------------------------------------------------------------------------------------------------------------


What *really* surprises me is that the jobs exits OK when I manually run it from bconsole 
via "run". And that time I do not see the Accurate message in the job log.

-----------------------------------------------------------------------------------------------------------------------------------------------------------------
2018-04-07 21:45:04heRPI02-fd JobId 1693: ClientBeforeJob: exiting...
2018-04-07 21:45:05heBacula-sd JobId 1693: Labeled new Volume 
"IncBackup__heRPI02-fd__1692__2018-04-07T21.00.03" on File device 
"AC-IncBackup-Dev03" (/srv/bacula-sd/AC-IncBackup).
2018-04-07 21:45:05heBacula-sd JobId 1693: Wrote label to prelabeled Volume 
"IncBackup__heRPI02-fd__1692__2018-04-07T21.00.03" on File device 
"AC-IncBackup-Dev03" (/srv/bacula-sd/AC-IncBackup)
2018-04-07 21:45:05heBacula-dir JobId 1693: Max Volume jobs=1 exceeded. Marking Volume 
"IncBackup__heRPI02-fd__1692__2018-04-07T21.00.03" as Used.
2018-04-07 21:45:06heRPI02-fd JobId 1693:      Disallowed filesystem. Will not 
descend from / into /dev
2018-04-07 21:45:09heRPI02-fd JobId 1693:      Disallowed filesystem. Will not 
descend from / into /sys
2018-04-07 21:45:12heRPI02-fd JobId 1693: Error: /var/lib/mysql/ib_logfile0 
mtime changed during backup.
2018-04-07 21:45:16heRPI02-fd JobId 1693: Error: /var/lib/mysql/ibdata1 mtime 
changed during backup.
2018-04-07 21:45:20heRPI02-fd JobId 1693: Error: /var/lib/mysql/ib_logfile1 
mtime changed during backup.
2018-04-07 21:45:23heRPI02-fd JobId 1693:      Disallowed filesystem. Will not 
descend from / into /run
2018-04-07 21:45:24heRPI02-fd JobId 1693:      Disallowed filesystem. Will not 
descend from / into /proc
2018-04-07 21:45:30heBacula-sd JobId 1693: Elapsed time=00:00:25, Transfer 
rate=4.195 M Bytes/second
2018-04-07 21:45:30heBacula-dir JobId 1693: Max Volume jobs=1 exceeded. Marking Volume 
"IncBackup__heRPI02-fd__1692__2018-04-07T21.00.03" as Used.
2018-04-07 21:45:30heBacula-sd JobId 1693: Sending spooled attrs to the 
Director. Despooling 44,303 bytes ...
2018-04-07 21:45:30heBacula-dir JobId 1693: Bacula Enterprise heBacula-dir 
8.8.1 (01Mar17):
-----------------------------------------------------------------------------------------------------------------------------------------------------------------


How is this possible?


best regards

Thorsten





On 05.04.2018 15:17, Johannsen, Thorsten wrote:

On 05.04.2018 13:35, Johannsen, Thorsten wrote:

On 05.04.2018 00:01, Jari Fredriksson wrote:

Hi Jari,


[...]

Do you have Raspbian installed? Do you use the bacula-fd version from
the repository or did you compile your own?


Moreover: could you please check the free memory on your 5 RPI's?

Currently I have:

heRPI01:~ $ free -h
              total       used       free     shared buffers cached
Mem:          923M       447M       476M        11M 100M 139M
-/+ buffers/cache:       207M       716M
Swap:          99M         0B        99M

(this is the RPI where backup works)


heRPI02:~ $ free -h
               total        used        free      shared buff/cache
available
Mem:           927M        176M        371M         23M 379M        663M
Swap:           99M          0B         99M

(this is the RPI where backup does not (always) work. With Accurate=no
the success/failure
ratio has improved, but I'm still getting failed backups.

Thanks in advance,

Cheers,

Thorsten


------------------------------------------------------------------------------

Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users




------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users



------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Re: [Bacula-users] scheduled job different that manually initiated job? --WAS: Re: Backup problem with 1 of 2 Raspberry PI using Raspbian (Debian)

Reply via email to