View Issue Details

IDProjectCategoryView StatusLast Update
0001333bareos-core[All Projects] storage daemonpublic2021-03-27 16:39
ReporternooneAssigned To 
PrioritynormalSeverityblockReproducibilityhave not tried
Status newResolutionopen 
Platformx86_64OSSLES OS Version15.1
Product Version19.2.9 
Fixed in Version 
Summary0001333: mtx-changer stopped working
Descriptionmtx-changer stopped working after an update.
Each time a new tape was loaded by bareos I got an error message like:
"""
Connecting to Storage daemon SL3-LTO5-00 at uranus.mcservice.eu:9103 ...
3304 Issuing autochanger "load slot 6, drive 0" command.
3992 Bad autochanger "load slot 6, drive 0": ERR=Child died from signal 15: Termination.
Results=Program killed by BAREOS (timeout)

3001 Mounted Volume: ALN043L5
3001 Device "tapedrive-lto-5" (/dev/tape/by-id/scsi-300e09e60001ce29a-nst) is already mounted with Volume "ALN043L5"
"""
In reality the tape was loaded and after 5 minutes the command was killed by timeout. The tape is loaded after roughly 120 seconds and is readable by that time using other applications (like dd or tapeinfo).

I tracked it down to the `wait_for_drive()` function in the script. I modified the function to look like
```
wait_for_drive() {
  i=0
  while [ $i -le 300 ]; do # Wait max 300 seconds
    debug "tapeinfo -f $1 2>&1"
    debug `tapeinfo -f $1 2>&1`
    debug "mt -f $1 status 2>&1"
    debug `mt -f $1 status 2>&1`
    if mt -f $1 status 2>&1 | grep "${ready}" >/dev/null 2>&1; then
      break
    fi
    debug "Device $1 - not ready, retrying..."
    sleep 1
    i=`expr $i + 1`
  done
}
```
An example protocol output is (shortened)
"""
20210327-16:20:35 tapeinfo -f /dev/tape/by-id/scsi-300e09e60001ce29a-nst 2>&1
20210327-16:20:35 mtx: Request Sense: Long Report=yes mtx: Request Sense: Valid Residual=no mtx: Request Sense: Error Code=0 (Unknown?!) mtx: Request Sense: Sense Key=No Sense mtx: Request Sense: FileMark=no mtx: Request Sense: EOM=no mtx: Request Sense: ILI=no mtx: Request Sense: Additional Sense Code = 00 mtx: Request Sense: Additional Sense Qualifier = 00 mtx: Request Sense: BPV=no mtx: Request Sense: Error in CDB=no mtx: Request Sense: SKSV=no INQUIRY Command Failed
20210327-16:20:35 mt -f /dev/tape/by-id/scsi-300e09e60001ce29a-nst status 2>&1
20210327-16:20:35 Unknown tape drive: file no= -1 block no= -1
20210327-16:20:35 Device /dev/tape/by-id/scsi-300e09e60001ce29a-nst - not ready, retrying...
"""
I verified via bash that at this time the tapedrive was ready using tapeinfo.



TagsNo tags attached.
bareos-master: impact
bareos-master: action
bareos-19.2: impact
bareos-19.2: action
bareos-18.2: impact
bareos-18.2: action
bareos-17.2: impact
bareos-17.2: action
bareos-16.2: impact
bareos-16.2: action
bareos-15.2: impact
bareos-15.2: action
bareos-14.2: impact
bareos-14.2: action
bareos-13.2: impact
bareos-13.2: action
bareos-12.4: impact
bareos-12.4: action

Activities

noone

noone

2021-03-27 16:39

reporter   ~0004105

For anyone facing this problem:

I found a workaround. The mt commands return value is the problem. So I am using now tapeinfo as a replacement.
At you own risk you could try to replace the `wait_for_drive` function by
```
wait_for_drive() {
  i=0
  while [ $i -le 300 ]; do # Wait max 300 seconds
    # Code Changed because mt has stopped working in December 2020. This is a provisional fix...
    #if mt -f $1 status 2>&1 | grep "${ready}" >/dev/null 2>&1; then
    if tapeinfo -f $1 2>&1 | grep "Ready: yes" >/dev/null 2>&1; then
      break
    fi
    debug "Device $1 - not ready, retrying..."
    sleep 1
    i=`expr $i + 1`
  done
}
```

Might or might not work on different systems. To work bareos-sd has to run as root on my machine.

PS:
I found out that the mt command returns
"""
uranus:~ # mt -f /dev/tape/by-id/scsi-300e09e60001ce29a-nst status
Unknown tape drive:

   file no= -1 block no= -1
"""
so this might be the reason why it stopped working. But I am unable to find out why the output of mt has changed.

Issue History

Date Modified Username Field Change
2021-03-27 16:33 noone New Issue
2021-03-27 16:39 noone Note Added: 0004105