[Bacula-users] bacula seems not to get mtx-changer output

Hello everybody

I hope that someone can help me:

I'm trying to setup an HP MSL 2024 to work with bacula 5.0.0 (26 January 2010) - I installed it with yum using CentOS 6 base repository

notice that I have already added bacula user to tape group and issued mtx-changer command on a shell logged as bacula user, and it works

the really strange thing is that if a issue a label barcode command in bconsole it starts the label process, but the output of the process return errors as if mtx-changer output is not returned to bacula:

here is the situation before issuing the label brcodes command - as you can see there is PT7785L3 loaded from slot 11 in Drive 0

/usr/libexec/bacula/mtx-changer /dev/sg3 listall 0 /dev/nst0
D:0:F:11:PT7785L3
S:1:E
S:2:E
S:3:E
S:4:E
S:5:F:PT7783L3
S:6:E
S:7:E
S:8:E
S:9:F:PT7782L3
S:10:E
S:11:E
S:12:E
S:13:E
S:14:E
S:15:E
S:16:E
S:17:E
S:18:E
S:19:E
S:20:E
S:21:E
S:22:E
S:23:E
S:24:E

bacula correctly notice that the cartdrige in already in Drive 0 is from slot 11 and try to unload it, ... but got timeouts and ERR=Child died from signal 15: Termination

anyway the cartdrige is actually unloaded from the drive:

/usr/libexec/bacula/mtx-changer /dev/sg3 listall 0 /dev/nst0
D:0:E
S:1:E
S:2:E
S:3:E
S:4:E
S:5:F:PT7783L3
S:6:E
S:7:E
S:8:E
S:9:F:PT7782L3
S:10:E
S:11:F:PT7785L3
S:12:E
S:13:E
S:14:E
S:15:E
S:16:E
S:17:E
S:18:E
S:19:E
S:20:E
S:21:E
S:22:E
S:23:E
S:24:E

so it seems to me that mtx-changer is working but not sends it output to bacula

any ideas? This actually is driving me crazy

thanks

Marco Carcano

label barcodes
Automatically selected Storage: snh02-fs-tapelibrary01
Connecting to Storage daemon snh02-fs-tapelibrary01 at snh02.farm01.statusnobilis.local:9103 ...
3306 Issuing autochanger "slots" command.
Device "Autochanger" has 24 slots.
Connecting to Storage daemon snh02-fs-tapelibrary01 at snh02.farm01.statusnobilis.local:9103 ...
3306 Issuing autochanger "list" command.
The following Volumes will be labeled:
Slot Volume
==============
   5 PT7783L3
   9 PT7782L3
11 PT7785L3
Do you want to label these Volumes? (yes|no): yes
Defined Pools:
     1: Scratch
     2: Default
Select the Pool (1-2): 1
Connecting to Storage daemon snh02-fs-tapelibrary01 at snh02.farm01.statusnobilis.local:9103 ...
Sending label command for Volume "PT7783L3" Slot 5 ...
3307 Issuing autochanger "unload slot 11, drive 0" command.
3995 Bad autochanger "unload slot 11, drive 0": ERR=Child died from signal 15: Termination
Results=Program killed by Bacula (timeout)

Label command failed for Volume PT7783L3.
Sending label command for Volume "PT7782L3" Slot 9 ...
3301 Issuing autochanger "loaded? drive 0" command.
3302 Autochanger "loaded? drive 0", result: nothing loaded.
3304 Issuing autochanger "load slot 9, drive 0" command.
3992 Bad autochanger "load slot 9, drive 0": ERR=Child died from signal 15: Termination.
Results=Program killed by Bacula (timeout)

Label command failed for Volume PT7782L3.
Sending label command for Volume "PT7785L3" Slot 11 ...
3301 Issuing autochanger "loaded? drive 0" command.
3302 Autochanger "loaded? drive 0", result is Slot 9.
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 Bacula (timeout)

Label command failed for Volume PT7785L3.

here is a btape test output too:

btape -c /etc/bacula/bacula-sd.conf /dev/nst0
Tape block granularity is 1024 bytes.
btape: butil.c:285 Using device: "/dev/nst0" for writing.
15-Apr 17:48 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command.
15-Apr 17:48 btape JobId 0: 3302 Autochanger "loaded? drive 0", result is Slot 1.
btape: btape.c:476 open device "Drive-0" (/dev/nst0): OK
*test

=== Write, rewind, and re-read test ===

I'm going to write 10000 records and an EOF
then write 10000 records and an EOF, then rewind,
and re-read the data to verify that it is correct.

This is an *essential* feature ...

btape: btape.c:1148 Wrote 10000 blocks of 64412 bytes.
...
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1206 Rewind OK.
10000 blocks re-read correctly.
Got EOF on tape.
10000 blocks re-read correctly.
=== Test Succeeded. End Write, rewind, and re-read test ===

btape: btape.c:1274 Block position test
btape: btape.c:1286 Rewind OK.
Reposition to file:block 0:4
Block 5 re-read correctly.
...
Reposition to file:block 1:9999
Block 20000 re-read correctly.
=== Test Succeeded. End Write, rewind, and re-read test ===

=== Append files test ===

This test is essential to Bacula.

I'm going to write one record in file 0,
                   two records in file 1,
             and three records in file 2

btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
...
btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
btape: btape.c:1418 Now moving to end of medium.
btape: btape.c:629 Moved to end of medium.
We should be in file 3. I am at file 3. This is correct!

Now the important part, I am going to attempt to append to the tape.

btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
Done appending, there should be no I/O errors

Doing Bacula scan of blocks:
1 block of 64448 bytes in file 1
End of File mark.
2 blocks of 64448 bytes in file 2
End of File mark.
3 blocks of 64448 bytes in file 3
End of File mark.
1 block of 64448 bytes in file 4
End of File mark.
Total files=4, blocks=7, bytes = 451,136
End scanning the tape.
We should be in file 4. I am at file 4. This is correct!

The above Bacula scan should have output identical to what follows.
Please double check it ...
=== Sample correct output ===
1 block of 64448 bytes in file 1
End of File mark.
2 blocks of 64448 bytes in file 2
End of File mark.
3 blocks of 64448 bytes in file 3
End of File mark.
1 block of 64448 bytes in file 4
End of File mark.
Total files=4, blocks=7, bytes = 451,136
=== End sample correct output ===

If the above scan output is not identical to the
sample output, you MUST correct the problem
or Bacula will not be able to write multiple Jobs to
the tape.

Skipping read backwards test because BSR turned off.

=== Forward space files test ===

This test is essential to Bacula.

I'm going to write five files then test forward spacing

btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:1905 Wrote one record of 64412 bytes.
btape: btape.c:1907 Wrote block to device.
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:608 Wrote 1 EOF to "Drive-0" (/dev/nst0)
btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
btape: btape.c:1632 Now forward spacing 1 file.
We should be in file 1. I am at file 1. This is correct!
btape: btape.c:1644 Now forward spacing 2 files.
We should be in file 3. I am at file 3. This is correct!
btape: btape.c:578 Rewound "Drive-0" (/dev/nst0)
btape: btape.c:1657 Now forward spacing 4 files.
We should be in file 4. I am at file 4. This is correct!

btape: btape.c:1675 Now forward spacing 1 more file.
We should be in file 5. I am at file 5. This is correct!

=== End Forward space files test ===

Ah, I see you have an autochanger configured.
To test the autochanger you must have a blank tape
that I can write on in Slot 1.

Do you wish to continue with the Autochanger test? (y/n): y

=== Autochanger test ===

3301 Issuing autochanger "loaded" command.
3991 Bad autochanger command: /usr/libexec/bacula/mtx-changer /dev/sg3 loaded 1 /dev/nst0 0
3991 result="": ERR=Child died from signal 9: Kill, unblockable
You must correct this error or the Autochanger will not work.

=== End Forward space files test ===

Ah, I see you have an autochanger configured.
To test the autochanger you must have a blank tape
that I can write on in Slot 1.

Do you wish to continue with the Autochanger test? (y/n): y

=== Autochanger test ===

3301 Issuing autochanger "loaded" command.
3991 Bad autochanger command: /usr/libexec/bacula/mtx-changer /dev/sg3 loaded 1 /dev/nst0 0
3991 result="": ERR=Child died from signal 9: Kill, unblockable
You must correct this error or the Autochanger will not work.

------------------------------------------------------------------------------
Precog is a next-generation analytics platform capable of advanced
analytics on semi-structured data. The platform includes APIs for building
apps and a phenomenal toolset for data science. Developers can use
our toolset for easy data analysis & visualization. Get a free account!
http://www2.precog.com/precogplatform/slashdotnewsletter

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