Autchanger Script fails

332 views
Skip to first unread message

tilmang...@googlemail.com

unread,
Feb 21, 2021, 12:38:31 PM2/21/21
to bareos-users
Dear all,

I have ADIC DDS Tape library which no longer cleaner removes the tape from the library. When I issue an umount command, I get an error message. With an older version of bareos, it used to work. Any advice on how I can debug and fix this?

> umount storage=TapeStorage1
Automatically selected Catalog: QtronCatalog
Using Catalog "QtronCatalog"
Connecting to Storage daemon TapeStorage1 at qtron.fritz.box:9103 ...
3307 Issuing autochanger "unload slot 8, drive 0" command.
3995 Bad autochanger "unload slot 8, drive 0": ERR=Child died from signal 15: Termination
Results=Program killed by BAREOS (timeout)

3002 Device ""TapeDrive1" (/dev/nst0)" unmounted

Thanks
Tilman

spadaj...@gmail.com

unread,
Feb 21, 2021, 3:36:08 PM2/21/21
to bareos-users
Bareos uses a script called mtx-changer (probably located in /usr/lib/bareos/scripts) which in turn calls mtx.
You can check mtx-changer log (/var/log/bareos/mtx.log) and/or try to manually run mtx manually to see if mtx itself runs ok.

Andreas Rogge

unread,
Feb 22, 2021, 6:06:59 AM2/22/21
to bareos...@googlegroups.com
Hi Tilman,

are you using Bareos 20 and have data-spooling enabled on the tape drive?
You may have hit a bug that will be fixed in the upcoming 20.0.1, then.

Best Regards,
Andreas

--
Andreas Rogge andrea...@bareos.com
Bareos GmbH & Co. KG Phone: +49 221-630693-86
http://www.bareos.com

Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
Komplementär: Bareos Verwaltungs-GmbH
Geschäftsführer: S. Dühr, M. Außendorf, J. Steffens, Philipp Storz

tilmang...@googlemail.com

unread,
Feb 27, 2021, 6:21:37 AM2/27/21
to bareos-users
Dear spadaj

I forgot to mention that mtx runs OK. It lives in /usr/sbin/mtx, and the log files are in /var/bareos/working/. The logfiles are however empty.
mtx-changer script lives in /etc/bareos

Dear Andreas

I am using bareos 19.2.6 (self compiled).  I do not think that the drive has a data spooling option as it is a relatively old HP C5683A

Thanks
Tilman

Spadajspadaj

unread,
Feb 27, 2021, 7:04:07 AM2/27/21
to bareos...@googlegroups.com

If mtx runs fine. I'd try to run the mtx-changer script with bash "debug mode" (bash -x mtx-changer...) and see what is it that the mtx hangs and times out on.

--
You received this message because you are subscribed to the Google Groups "bareos-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to bareos-users...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/bareos-users/ffeeeab8-59bb-4ca5-a051-10f9a9f0a207n%40googlegroups.com.

tilmang...@googlemail.com

unread,
Mar 7, 2021, 4:16:10 PM3/7/21
to bareos-users
1) I gave it a try. Using the  mtx-changer script directly (without using bconsole after booting up) seems to work.  I mounted a tape via the script and then umounted it:
./mtx-changer  /dev/changer1 unload  8 /dev/nst0 0
+ test ! -r /etc/bareos//mtx-changer.conf
+ . /etc/bareos//mtx-changer.conf
+ offline=0
+ offline_sleep=0
+ load_sleep=0
+ inventory=0
+ vxa_packetloader=0
+ debug_log=0
+ uname
+ OS=Linux
+ ready=ONLINE
+ test -f /etc/debian_version
+ grep mt-st
+ mt --version
+ test 0 -eq 1
+ MTX=/usr/sbin/mtx
+ test ! -x /usr/sbin/mtx
+ MT=/bin/mt
+ test ! -x /bin/mt
+ dbgfile=/var/bareos/logs/mtx.log
+ test 0 -ne 0
+ check_parm_count 5 5
+ pCount=5
+ pCountNeed=5
+ test 5 -lt 5
+ ctl=/dev/changer1
+ cmd=unload
+ slot=8
+ device=/dev/nst0
+ drive=0
+ debug Parms: /dev/changer1 unload 8 /dev/nst0 0
+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210307-18:32:02 Parms: /dev/changer1 unload 8 /dev/nst0 0
+ debug Doing mtx -f /dev/changer1 unload 8 0
+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210307-18:32:02 Doing mtx -f /dev/changer1 unload 8 0
+ test 0 -eq 1
+ test 0 -ne 0
+ make_err_file
+ mktemp /var/bareos/working/mtx.err.XXXXXXXXXX
+ ERRFILE=/var/bareos/working/mtx.err.pJijcI8Tu2
+ test x/var/bareos/working/mtx.err.pJijcI8Tu2 = x
+ /bin/mt -f /dev/nst0 eject
+ sleep 10
+ /usr/sbin/mtx -f /dev/changer1 unload 8 0
Unloading drive 0 into Storage Element 8...done
+ rtn=0
+ cat /var/bareos/working/mtx.err.pJijcI8Tu2
+ rm -f /var/bareos/working/mtx.err.pJijcI8Tu2
+ exit 0

2) mount and unmount a tape and thereby loading and unloading a tape from a freshly booted machine via bconsole works.

3) mount a tape, running a backup job and then trying to umount/unloading the tape does not work and leads to the error message "ERR=Child died from signal 15: ". Unload the tape with mtx_changer works however:  The debug mode of the mtx-changer script shows an error message  "/dev/nst0: No medium found" which is consistent: The previously failing umount command issued an eject command.  The tape is  ejected from the drive but not unloaded into the magazine. When subsequently running the mtx_changer command,the medium is indeed no longer in the drive -- but also not yet in its slot

*status storage=TapeStorage1
Connecting to Storage daemon TapeStorage

Version: 19.2.6 (11 February 2020) Linux-4.15.0-112-generic ubuntu Ubuntu 18.04.4 LTS
Daemon started 07-Mär021 18:55. Jobs: run=2, running=0, self-compiled binary
 Sizes: boffset_t=8 size_t=4 int32_t=4 int64_t=8 bwlimit=0kB/s

Running Jobs:
No Jobs running.
====

Jobs waiting to reserve a drive:
====

Terminated Jobs:
 JobId  Level    Files      Bytes   Status   Finished        Name
===================================================================
 ..
  2730  Full     42,072    16.36 G  OK       07-Mär021 21:25 BackupTgvs2ToTape
====

Device status:
Autochanger "AutoChanger1" with devices:
   "TapeDrive1" (/dev/nst0)

Device "TapeDrive1" (/dev/nst0) is mounted with:
    Volume:      Tgvs2Tape-14
    Pool:        Tgvs2-Tape
    Media type:  DDS-4
    Slot 9 is loaded in drive 0.
    Total Bytes=16,380,499,968 Blocks=253,913 Bytes/block=64,512
    Positioned at File=17 Block=0
==
====

Used Volume status:
Tgvs2Tape-14 on device "TapeDrive1" (/dev/nst0)
    Reader=0 writers=0 reserves=0 volinuse=0
====

====

*umount storage=TapeStorage1

Connecting to Storage daemon TapeStorage1 ...
3307 Issuing autochanger "unload slot 9, drive 0" command.
3995 Bad autochanger "unload slot 9, drive 0": ERR=Child died from signal 15: Termination

Results=Program killed by BAREOS (timeout)

3002 Device ""TapeDrive1" (/dev/nst0)" unmounted.

#> mtx -f /dev/changer1 status
  Storage Changer /dev/changer1:1 Drives, 12 Slots ( 0 Import/Export )
Data Transfer Element 0:Full (Storage Element 9 Loaded)
      Storage Element 1:Full
      Storage Element 2:Full
      Storage Element 3:Full
      Storage Element 4:Full
      Storage Element 5:Full
      Storage Element 6:Full
      Storage Element 7:Full
      Storage Element 8:Full
      Storage Element 9:Empty
      Storage Element 10:Full
      Storage Element 11:Full
      Storage Element 12:Full

#>  ./mtx-changer  /dev/changer1 unload  9 /dev/nst0 0
+ test ! -r /etc/bareos//mtx-changer.conf
+ . /etc/bareos//mtx-changer.conf
+ offline=0
+ offline_sleep=0
+ load_sleep=0
+ inventory=0
+ vxa_packetloader=0
+ debug_log=0
+ uname
+ OS=Linux
+ ready=ONLINE
+ test -f /etc/debian_version
+ grep mt-st
+ mt --version
+ test 0 -eq 1
+ MTX=/usr/sbin/mtx
+ test ! -x /usr/sbin/mtx
+ MT=/bin/mt
+ test ! -x /bin/mt
+ dbgfile=/var/bareos/logs/mtx.log
+ test 0 -ne 0
+ check_parm_count 5 5
+ pCount=5
+ pCountNeed=5
+ test 5 -lt 5
+ ctl=/dev/changer1
+ cmd=unload
+ slot=9
+ device=/dev/nst0
+ drive=0
+ debug Parms: /dev/changer1 unload 9 /dev/nst0 0
+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210307-21:59:39 Parms: /dev/changer1 unload 9 /dev/nst0 0
+ debug Doing mtx -f /dev/changer1 unload 9 0
+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210307-21:59:39 Doing mtx -f /dev/changer1 unload 9 0
+ test 0 -eq 1
+ test 0 -ne 0
+ make_err_file
+ mktemp /var/bareos/working/mtx.err.XXXXXXXXXX
+ ERRFILE=/var/bareos/working/mtx.err.Lfbq8DDkK5
+ test x/var/bareos/working/mtx.err.Lfbq8DDkK5 = x
+ /bin/mt -f /dev/nst0 eject
+ sleep 10
+ /usr/sbin/mtx -f /dev/changer1 unload 9 0
Unloading drive 0 into Storage Element 9...done
+ rtn=0
+ cat /var/bareos/working/mtx.err.Lfbq8DDkK5
/dev/nst0: No medium found
+ rm -f /var/bareos/working/mtx.err.Lfbq8DDkK5
+ exit 0

# mtx -f /dev/changer1 status
  Storage Changer /dev/changer1:1 Drives, 12 Slots ( 0 Import/Export )
Data Transfer Element 0:Empty
      Storage Element 1:Full
      Storage Element 2:Full
      Storage Element 3:Full
      Storage Element 4:Full
      Storage Element 5:Full
      Storage Element 6:Full
      Storage Element 7:Full
      Storage Element 8:Full
      Storage Element 9:Full
      Storage Element 10:Full
      Storage Element 11:Full
      Storage Element 12:Full

Thanks
Tilman

Spadajspadaj

unread,
Mar 8, 2021, 2:34:03 AM3/8/21
to bareos...@googlegroups.com

+ offline=0
+ offline_sleep=0
+ load_sleep=0

Have you tried playing with those values?

It seems a good place to start.

By default they're defined in /etc/bareos/mtx-changer.conf

tilmang...@googlemail.com

unread,
Mar 21, 2021, 3:26:10 PM3/21/21
to bareos-users
I have set offline =1 and ran a backup job. I could not mount the drive from bconsole (Fatal error: 3992 Bad autochanger "load slot 12, drive 0": ERR=Child exited with code 1),
so I  did this manually with mtx.

Then I ran the backup job that failed
-----------------------------------
1-Mär 19:15 JobId 2741: Connected File Daemon
21-Mär 19:15JobId 2741: 3304 Issuing autochanger "load slot 12, drive 0" command.
21-Mär 19:15 JobId 2741: Fatal error: 3992 Bad autochanger "load slot 12, drive 0": ERR=Child exited with code 1.
Results=+ test ! -r /etc/bareos//mtx-changer.conf
+ . /etc/bareos//mtx-changer.conf
+ offline=1
+ offline_sleep=2

+ load_sleep=0
+ inventory=0
+ vxa_packetloader=0
+ debug_log=0
+ uname
+ OS=Linux
+ ready=ONLINE
+ test -f /etc/debian_version
+ grep mt-st
+ mt --version
+ test 0 -eq 1
+ MTX=/usr/sbin/mtx
+ test ! -x /usr/sbin/mtx
+ MT=/bin/mt
+ test ! -x /bin/mt
+ dbgfile=/var/bareos/logs/mtx.log
+ test 0 -ne 0
+ check_parm_count 5 5
+ pCount=5
+ pCountNeed=5
+ test 5 -lt 5
+ ctl=/dev/changer1
+ cmd=load
+ slot=12
+ device=/dev/nst0
+ drive=0
+ debug Parms: /dev/changer1 load 12 /dev/nst0 0

+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210321-19:15:30 Parms: /dev/changer1 load 12 /dev/nst0 0
+ debug Doing mtx -f /dev/changer1 load 12 0

+ test -f /var/bareos/logs/mtx.log
+ date +%Y%m%d-%H:%M:%S
+ echo 20210321-19:15:30 Doing mtx -f /dev/changer1 load 12 0

+ make_err_file
+ mktemp /var/bareos/working/mtx.err.XXXXXXXXXX
+ ERRFILE=/var/bareos/working/mtx.err.qafC0jyzNu
+ test x/var/bareos/working/mtx.err.qafC0jyzNu = x
+ /usr/sbin/mtx -f /dev/changer1 load 12 0
+ rtn=1

+ test 0 -ne 0
+ wait_for_drive /dev/nst0
+ i=0
+ [ 0 -le 300 ]
+ + grep ONLINE
mt -f /dev/nst0 status
+ break
+ cat /var/bareos/working/mtx.err.qafC0jyzNu
Drive 0 Full (Storage Element 12 loaded)
+ rm -f /var/bareos/working/mtx.err.qafC0jyzNu
+ exit 1

21-Mär 19:15 JobId 2741: Fatal error: filed/dir_cmd.cc:2695 Bad response to Append Data command. Wanted 3000 OK data
, got 3903 Error append data

-----------------------------------
The subsequent status storage command reveals an anomaly, as it claims that slot 65535 is loaded.

*status storage=TapeStorage1
Connecting to Storage daemon TapeStorage1

 Version: 19.2.7 (16 April 2020) Linux-3.10.0-1062.18.1.el7.x86_64 ubuntu Ubuntu 16.04.6 LTS
Daemon started 21-Mär021 17:18. Jobs: run=5, running=0, bareos.org build binary

 Sizes: boffset_t=8 size_t=4 int32_t=4 int64_t=8 bwlimit=0kB/s
....


Device status:
Autochanger "AutoChanger1" with devices:
   "TapeDrive1" (/dev/nst0)

Device "TapeDrive1" (/dev/nst0) is not open.
    Slot 65535 was last loaded in drive 0.

==
====

Used Volume status:
Tgvs2Tape-16 on device "TapeDrive1" (/dev/nst0)
    Reader=0 writers=0 reserves=0 volinuse=1
====


It would be helpful to understand how the mtx-changer script is interacting with bareos.

I think the issues are all software related rather than connected with th e hardware. And I am approaching the point where I feel that setting up the machine from scratch is easier than debugging it.

Any advice on how to continue would be appreciated....

Thanks
Tilman

tilmang...@googlemail.com

unread,
Oct 1, 2021, 11:24:18 AM10/1/21
to bareos-users
Dear all

I compiled and installed  a new version of bareos.(V20.0.1). The problem of unloading the tape persists. I traced it down offline command in the mtx-changer script, i.e. the command
mt  -f /dev/nst0 offline
hangs and eventually bareos kills the script.

If I run mt from command line, mt will eventually time out and return an error message "/dev/nst0: No medium found". The tape is however loaded.

The issue seems to be related to the tape drive or the scsi driver. The tape drive is a  C5683A from HP.

Removing the offline command also does not work as bareos then complains about the drive still being online.

Did anybody experience and solve this  before?

Thanks
Tilman
Reply all
Reply to author
Forward
0 new messages