Re: [Bacula-users] backup failed, network problems, vchanger or bacula?

2010/5/28  <C.Keschnat AT internet-mit-iq DOT 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 had this 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

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

_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users