John Drescher <dresche...@gmail.com> wrote on 28.05.2010 13:53:46:
> John Drescher <dresche...@gmail.com>
> 28.05.2010 13:53
>
> An
>
> c.kesch...@internet-mit-iq.de
>
> Kopie
>
> bacula-users@lists.sourceforge.net
>
> Thema
>
> Re: [Bacula-users] backup failed, network problems, vchanger or bacula?
>
> 2010/5/28 <c.kesch...@internet-mit-iq.de>:
> > Today our backups failed. It seemed to run fine until some point, then
it
> > stopped with a changer error. There was also this error:
> > ptrace: Operation not permitted.
> > /home/bacula/working/19031: No such file or directory.
> > $1 = 0
> > /home/bacula/etc/btraceback.gdb:2: Error in sourced command file:
> > No symbol "exename" in current context.
> >
> > But I don't know if that is related.
> >
> > All the Joboutputs have these lines in them:
> > 28-Mai 02:53 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:53 bacula-sd JobId 9147: 3991 Bad autochanger "loaded? drive
0"
> > command: ERR=Child exited with code 1.
> > Results=Could not write loaded0 file on /mnt/usbchanger1/mag
> >
> > The first job wrote some data and also had this lines in the output:
> > 28-Mai 02:53 iq-fd JobId 9147: Fatal error: backup.c:944 Network send
error
> > to SD. ERR=Connection reset by peer
> >
> > Seems like there was a problem with the network. The external HDD is
mounted
> > through iSCSI on the server. When I came to work this morning though I
could
> > touch and delete files without problems so the iSCSI connection was
still
> > there. Could small network problems cause vchanger/bacula to stop
working?
> > I'd like to find out if the problem is bacula or vchanger related. I
know
> > that probably noone is using vchanger with iSCSI but I hope someone
might
> > have an idea on how to solve this (it is not the first time we hadthis
kind
> > of problem).
> > This is bacula 5.0.1 (clients 3.0.0) and vchanger 0.8.2.
> >
> > Here is the full output of the first job that ran:
> >
> > 28-Mai 02:05 bacula-dir JobId 9147: Start Backup JobId 9147,
> > Job=iq.2010-05-28_02.05.00_47
> > 28-Mai 02:05 bacula-dir JobId 9147: Using Device
"usb-changer-1-drive-0"
> > 28-Mai 02:05 iq-fd JobId 9147: shell command: run ClientBeforeJob
> > "/etc/init.d/rc_domino stop"
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: Switching to notes
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: Stopping Domino for
xLinux
> > (notes)
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting for
shutdown to
> > complete
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting 10
seconds
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting 20
seconds
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting 30
seconds
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting 40
seconds
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ... waiting 50
seconds
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: ..done
> > 28-Mai 02:05 iq-fd JobId 9147: ClientBeforeJob: Domino for xLinux
(notes)
> > shutdown completed
> > 28-Mai 02:05 bacula-sd JobId 9147: 3307 Issuing autochanger "unload
slot 15,
> > drive 0" command.
> > 28-Mai 02:05 bacula-sd JobId 9147: 3304 Issuing autochanger "load slot
16,
> > drive 0" command.
> > 28-Mai 02:05 bacula-sd JobId 9147: 3305 Autochanger "load slot
16,drive 0",
> > status is OK.
> > 28-Mai 02:05 bacula-sd JobId 9147: Volume "usbchanger1_0005_0016"
previously
> > written, moving to end of data.
> > 28-Mai 02:05 bacula-sd JobId 9147: Ready to append to end of Volume
> > "usbchanger1_0005_0016" size=2781850256
> > 28-Mai 02:12 bacula-sd JobId 9147: User defined maximum volume
capacity
> > 4,831,838,208 exceeded on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0).
> > 28-Mai 02:12 bacula-sd JobId 9147: End of medium on Volume
> > "usbchanger1_0005_0016" Bytes=4,831,783,484 Blocks=74,900 at
28-Mai-2010
> > 02:12.
> > 28-Mai 02:12 bacula-sd JobId 9147: 3307 Issuing autochanger "unload
slot 16,
> > drive 0" command.
> > 28-Mai 02:12 bacula-dir JobId 9147: There are no more Jobs associated
with
> > Volume "usbchanger1_0005_0032". Marking it purged.
> > 28-Mai 02:12 bacula-dir JobId 9147: All records pruned from Volume
> > "usbchanger1_0005_0032"; marking it "Purged"
> > 28-Mai 02:12 bacula-dir JobId 9147: Recycled volume
"usbchanger1_0005_0032"
> > 28-Mai 02:12 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:12 bacula-sd JobId 9147: 3302 Autochanger "loaded? drive 0",
> > result: nothing loaded.
> > 28-Mai 02:12 bacula-sd JobId 9147: 3304 Issuing autochanger "load slot
32,
> > drive 0" command.
> > 28-Mai 02:12 bacula-sd JobId 9147: 3305 Autochanger "load slot
32,drive 0",
> > status is OK.
> > 28-Mai 02:12 bacula-sd JobId 9147: Recycled volume
"usbchanger1_0005_0032"
> > on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0), all previous data lost.
> > 28-Mai 02:12 bacula-sd JobId 9147: New volume "usbchanger1_0005_0032"
> > mounted on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0) at 28-Mai-2010 02:12.
> > 28-Mai 02:27 bacula-sd JobId 9147: User defined maximum volume
capacity
> > 4,831,838,208 exceeded on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0).
> > 28-Mai 02:27 bacula-sd JobId 9147: End of medium on Volume
> > "usbchanger1_0005_0032" Bytes=4,831,819,893 Blocks=74,898 at
28-Mai-2010
> > 02:27.
> > 28-Mai 02:27 bacula-sd JobId 9147: 3307 Issuing autochanger "unload
slot 32,
> > drive 0" command.
> > 28-Mai 02:27 bacula-dir JobId 9147: There are no more Jobs associated
with
> > Volume "usbchanger1_0005_0033". Marking it purged.
> > 28-Mai 02:27 bacula-dir JobId 9147: All records pruned from Volume
> > "usbchanger1_0005_0033"; marking it "Purged"
> > 28-Mai 02:27 bacula-dir JobId 9147: Recycled volume
"usbchanger1_0005_0033"
> > 28-Mai 02:27 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:27 bacula-sd JobId 9147: 3302 Autochanger "loaded? drive 0",
> > result: nothing loaded.
> > 28-Mai 02:27 bacula-sd JobId 9147: 3304 Issuing autochanger "load slot
33,
> > drive 0" command.
> > 28-Mai 02:27 bacula-sd JobId 9147: 3305 Autochanger "load slot
33,drive 0",
> > status is OK.
> > 28-Mai 02:27 bacula-sd JobId 9147: Recycled volume
"usbchanger1_0005_0033"
> > on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0), all previous data lost.
> > 28-Mai 02:27 bacula-sd JobId 9147: New volume "usbchanger1_0005_0033"
> > mounted on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0) at 28-Mai-2010 02:27.
> > 28-Mai 02:40 bacula-sd JobId 9147: End of Volume
"usbchanger1_0005_0033" at
> > 0:4120639609 on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0). Write of 64512 bytes got
55174.
> > 28-Mai 02:40 bacula-sd JobId 9147: End of medium on Volume
> > "usbchanger1_0005_0033" Bytes=4,120,639,610 Blocks=63,874 at
28-Mai-2010
> > 02:40.
> > 28-Mai 02:40 bacula-sd JobId 9147: 3307 Issuing autochanger "unload
slot 33,
> > drive 0" command.
> > 28-Mai 02:40 bacula-dir JobId 9147: There are no more Jobs associated
with
> > Volume "usbchanger1_0005_0017". Marking it purged.
> > 28-Mai 02:40 bacula-dir JobId 9147: All records pruned from Volume
> > "usbchanger1_0005_0017"; marking it "Purged"
> > 28-Mai 02:40 bacula-dir JobId 9147: Recycled volume
"usbchanger1_0005_0017"
> > 28-Mai 02:40 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:40 bacula-sd JobId 9147: 3302 Autochanger "loaded? drive 0",
> > result: nothing loaded.
> > 28-Mai 02:40 bacula-sd JobId 9147: 3304 Issuing autochanger "load slot
17,
> > drive 0" command.
> > 28-Mai 02:40 bacula-sd JobId 9147: 3305 Autochanger "load slot
17,drive 0",
> > status is OK.
> > 28-Mai 02:41 bacula-sd JobId 9147: Recycled volume
"usbchanger1_0005_0017"
> > on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0), all previous data lost.
> > 28-Mai 02:41 bacula-sd JobId 9147: New volume "usbchanger1_0005_0017"
> > mounted on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0) at 28-Mai-2010 02:41.
> > 28-Mai 02:53 bacula-sd JobId 9147: User defined maximum volume
capacity
> > 4,831,838,208 exceeded on device "usb-changer-1-drive-0"
> > (/home/bacula/working/usbchanger1/0/drive0).
> > 28-Mai 02:53 bacula-sd JobId 9147: End of medium on Volume
> > "usbchanger1_0005_0017" Bytes=4,831,819,881 Blocks=74,898 at
28-Mai-2010
> > 02:53.
> > 28-Mai 02:53 bacula-sd JobId 9147: 3307 Issuing autochanger "unload
slot 17,
> > drive 0" command.
> > 28-Mai 02:53 bacula-sd JobId 9147: 3995 Bad autochanger "unload slot
17,
> > drive 0": ERR=Child exited with code 1
> > Results=Could not write loaded0 file on /mnt/usbchanger1/mag
> >
> > 28-Mai 02:53 bacula-dir JobId 9147: There are no more Jobs associated
with
> > Volume "usbchanger1_0005_0031". Marking it purged.
> > 28-Mai 02:53 bacula-dir JobId 9147: All records pruned from Volume
> > "usbchanger1_0005_0031"; marking it "Purged"
> > 28-Mai 02:53 bacula-dir JobId 9147: Recycled volume
"usbchanger1_0005_0031"
> > 28-Mai 02:53 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:53 bacula-sd JobId 9147: 3991 Bad autochanger "loaded? drive
0"
> > command: ERR=Child exited with code 1.
> > Results=Could not write loaded0 file on /mnt/usbchanger1/mag
> >
> > 28-Mai 02:53 bacula-sd JobId 9147: 3301 Issuing autochanger "loaded?
drive
> > 0" command.
> > 28-Mai 02:53 bacula-sd JobId 9147: 3991 Bad autochanger "loaded? drive
0"
> > command: ERR=Child exited with code 1.
> > Results=Could not write loaded0 file on /mnt/usbchanger1/mag
> >
> > 28-Mai 02:53 bacula-sd JobId 9147: 3304 Issuing autochanger "load slot
31,
> > drive 0" command.
> > 28-Mai 02:53 bacula-sd JobId 9147: Fatal error: 3992 Bad autochanger
"load
> > slot 31, drive 0": ERR=Child exited with code 1.
> > Results=Could not write loaded0 file on /mnt/usbchanger1/mag
> >
>
> The problem looks to be with vchanger. Did you run out of space?
>
> John
>
>
------------------------------------------------------------------------------
Probably not, unless vchanger uses some temporary space on the disk. There
a 39 volumes with Maximum Volume Bytes = 4608 MB so that is about 175.5
GB. The disk is187 GB (df -h output). I always copy the bacula
configuration and a catalog dump to the disk, but that are just 2 GB so
there should be 9 GB free. Also before the backup all volumes were fully
written and then recycled.
"Results=Could not write loaded0 file on /mnt/usbchanger1/mag" leads me to
believe you are right, but there is also still "iq-fd JobId 9147: Fatal
error: backup.c:944 Network send error to SD. ERR=Connection reset by
peer"
I will try to monitor if there are some space related issues.
Chris
------------------------------------------------------------------------------
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
