Implicit backspace file in btape #2001
Description
Bareos component version
23.0.5~pre146.7e91df1c0
Steps to reproduce
Hello,
There is some strange behavior while reading blocks with btape on IBM ULTRIUM-HH9 drive. After tape rewinding, I try to read blocks from the second file, but device file status number goes back to the previous file after a 'rb' command, If I rewind the tape, retry fsf 1, next reading is made using expected file and block. I think that the issue is not only related to the ptape tool, as I got a more or less similar error when during a backup, the tape was filled and bareos tried to reread the last record before loading next tape...
*qfill
btape: stored/btape.cc:2721-0 Test writing blocks of 64512 bytes to tape.
How many blocks do you want to write? (1000):
btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape1)
btape: stored/btape.cc:2737-0 Begin writing 1000 Bareos blocks to tape ...
btape: stored/btape.cc:431-0 Volume bytes=1.048 GB. Write rate = 18.39 MB/s
btape: stored/btape.cc:604-0 Wrote 1 EOF to "Drive-2" (/dev/nst/tape1)
btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape1)
953 blocks of 1048512 bytes in file 1
End of File mark.
47 blocks of 1048512 bytes in file 2
End of File mark.
Total files=2, blocks=1000, bytes = 1,048,512,000
EOD EOF
Error:
*rew
btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape1)
*st
Bareos status: file=0 block=0
Device status: BOT ONLINE IM_REP_EN file=0 block=0
Device status: TAPE BOT ONLINE IMMREPORT. ERR=
*fsf 1
btape: stored/btape.cc:1784-0 Forward spaced 1 file.
*st
EOF Bareos status: file=1 block=0
Device status: EOF ONLINE IM_REP_EN file=1 block=0
Device status: TAPE EOF ONLINE IMMREPORT. ERR=
*rb
*st
Bareos status: file=1 block=1
Device status: ONLINE IM_REP_EN file=0 block=1
Device status: TAPE ONLINE IMMREPORT. ERR=
Correct behavior:
*rew
btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape2)
*st
Bareos status: file=0 block=0
Device status: BOT ONLINE IM_REP_EN file=0 block=0
Device status: TAPE BOT ONLINE IMMREPORT. ERR=
*fsf 1
btape: stored/btape.cc:1784-0 Forward spaced 1 file.
*st
EOF Bareos status: file=1 block=0
Device status: EOF ONLINE IM_REP_EN file=1 block=0
Device status: TAPE EOF ONLINE IMMREPORT. ERR=
*rb
*st
Bareos status: file=1 block=1
Device status: ONLINE IM_REP_EN file=1 block=1
Device status: TAPE ONLINE IMMREPORT. ERR=
*st
Bareos status: file=1 block=1
Device status: ONLINE IM_REP_EN file=1 block=1
Device status: TAPE ONLINE IMMREPORT. ERR=
Expected results
See above.
Actual results
See above.
Environment
- OS:
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"Relevant log output
02-Nov-2024 17:26:05.734486 btape (100): backends/generic_tape_device.cc:67-0 Try open "Drive-2" (/dev/nst/tape1) mode=OPEN_READ_ONLY
02-Nov-2024 17:26:05.736018 btape (100): backends/generic_tape_device.cc:87-0 Rewind after open
02-Nov-2024 17:26:05.741815 btape (100): backends/generic_tape_device.cc:926-0 In SetOsDeviceParameters
02-Nov-2024 17:26:05.741846 btape (100): backends/generic_tape_device.cc:132-0 open dev: tape 3 opened
02-Nov-2024 17:26:05.741853 btape (100): stored/dev.cc:529-0 preserve=33121012206 fd=3
02-Nov-2024 17:26:05.741861 btape (129): stored/device.cc:287-0 open dev "Drive-2" (/dev/nst/tape1) OK
02-Nov-2024 17:26:05.741883 btape (250): stored/sd_plugins.cc:311-0 No bplugin_list: GeneratePluginEvent ignored.
02-Nov-2024 17:26:05.741895 btape (100): stored/block.cc:137-0 created new block of blocksize 1048576 (dev->max_block_size)
02-Nov-2024 17:26:05.741942 btape (200): stored/btape.cc:490-0 Opening device
02-Nov-2024 17:26:05.741959 btape (100): stored/dev.cc:492-0 Close fd for mode change.
02-Nov-2024 17:26:05.741965 btape (100): stored/dev.cc:505-0 open dev: type=124617200 archive_device_string="Drive-2" (/dev/nst/tape1) vol= mode=OPEN_READ_WRITE
02-Nov-2024 17:26:05.741973 btape (250): stored/sd_plugins.cc:311-0 No bplugin_list: GeneratePluginEvent ignored.
02-Nov-2024 17:26:05.741979 btape (100): stored/dev.cc:523-0 call OpenDevice mode=OPEN_READ_WRITE
02-Nov-2024 17:26:05.741986 btape (190): stored/dev.cc:951-0 Enter mount
02-Nov-2024 17:26:05.741992 btape (100): backends/generic_tape_device.cc:58-0 Open dev: device is tape
02-Nov-2024 17:26:05.742001 btape (100): backends/generic_tape_device.cc:67-0 Try open "Drive-2" (/dev/nst/tape1) mode=OPEN_READ_WRITE
02-Nov-2024 17:26:05.743473 btape (100): backends/generic_tape_device.cc:87-0 Rewind after open
02-Nov-2024 17:26:05.749661 btape (100): backends/generic_tape_device.cc:926-0 In SetOsDeviceParameters
02-Nov-2024 17:26:05.749692 btape (100): backends/generic_tape_device.cc:132-0 open dev: tape 3 opened
02-Nov-2024 17:26:05.749700 btape (100): stored/dev.cc:529-0 preserve=33121012646 fd=3
btape: stored/btape.cc:496-0 open device "Drive-2" (/dev/nst/tape1): OK
02-Nov-2024 17:26:05.749772 btape (200): stored/btape.cc:346-0 Do tape commands
***btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape1)
****02-Nov-2024 17:26:22.883659 btape (100): backends/generic_tape_device.cc:401-0 fsf
02-Nov-2024 17:26:22.890224 btape (200): backends/generic_tape_device.cc:431-0 fsf file=1
btape: stored/btape.cc:1784-0 Forward spaced 1 file.
* EOF Bareos status: file=1 block=0
Device status: EOF ONLINE IM_REP_EN file=1 block=0
Device status: TAPE EOF ONLINE IMMREPORT. ERR=
*02-Nov-2024 17:26:25.930150 btape (100): stored/dev.cc:492-0 Close fd for mode change.
02-Nov-2024 17:26:25.930193 btape (100): stored/dev.cc:505-0 open dev: type=124617200 archive_device_string="Drive-2" (/dev/nst/tape1) vol= mode=OPEN_READ_ONLY
02-Nov-2024 17:26:25.930203 btape (250): stored/sd_plugins.cc:311-0 No bplugin_list: GeneratePluginEvent ignored.
02-Nov-2024 17:26:25.930210 btape (100): stored/dev.cc:523-0 call OpenDevice mode=OPEN_READ_ONLY
02-Nov-2024 17:26:25.930217 btape (190): stored/dev.cc:951-0 Enter mount
02-Nov-2024 17:26:25.930223 btape (100): backends/generic_tape_device.cc:58-0 Open dev: device is tape
02-Nov-2024 17:26:25.930231 btape (100): backends/generic_tape_device.cc:67-0 Try open "Drive-2" (/dev/nst/tape1) mode=OPEN_READ_ONLY
02-Nov-2024 17:26:25.931927 btape (100): backends/generic_tape_device.cc:87-0 Rewind after open
02-Nov-2024 17:26:25.938096 btape (100): backends/generic_tape_device.cc:926-0 In SetOsDeviceParameters
02-Nov-2024 17:26:25.938127 btape (100): backends/generic_tape_device.cc:132-0 open dev: tape 3 opened
02-Nov-2024 17:26:25.938135 btape (100): stored/dev.cc:529-0 preserve=33121012706 fd=3
02-Nov-2024 17:26:25.938149 btape (250): stored/block.cc:959-0 Full read in ReadBlockFromDevice() len=1048576
02-Nov-2024 17:26:25.944662 btape (250): stored/block.cc:1019-0 Read device got 1048576 bytes at 1:0
02-Nov-2024 17:26:25.945848 btape (250): stored/block.cc:1164-0 At end of read block
02-Nov-2024 17:26:25.945859 btape (250): stored/block.cc:1177-0 Exit read_block read_len=1048576 block_len=1048512
* Bareos status: file=1 block=1
Device status: ONLINE IM_REP_EN file=0 block=1
Device status: TAPE ONLINE IMMREPORT. ERR=
**btape: stored/btape.cc:585-0 Rewound "Drive-2" (/dev/nst/tape1)
***02-Nov-2024 17:26:58.150555 btape (100): backends/generic_tape_device.cc:401-0 fsf
02-Nov-2024 17:26:58.156989 btape (200): backends/generic_tape_device.cc:431-0 fsf file=1
btape: stored/btape.cc:1784-0 Forward spaced 1 file.
*02-Nov-2024 17:27:12.731163 btape (250): stored/block.cc:959-0 Full read in ReadBlockFromDevice() len=1048576
02-Nov-2024 17:27:12.738673 btape (250): stored/block.cc:1019-0 Read device got 1048576 bytes at 1:0
02-Nov-2024 17:27:12.739857 btape (250): stored/block.cc:1164-0 At end of read block
02-Nov-2024 17:27:12.739867 btape (250): stored/block.cc:1177-0 Exit read_block read_len=1048576 block_len=1048512
* Bareos status: file=1 block=1
Device status: ONLINE IM_REP_EN file=1 block=1
Device status: TAPE ONLINE IMMREPORT. ERR=Relevant traces output
No response
Anything else?
No response