Solved 64512-byte tape record bigger than supplied buffer

I just upgraded my backup server from FreeBSD 9.3 to 10.3. After the upgrade, I see the following in /var/log/messages:

Code:
Jun 27 13:50:52 backup kernel: (sa0:mps0:0:3:0): 64512-byte tape record bigger than supplied buffer

Here is information on /dev/sa0:

Code:
% dmesg | grep sa0 | tail -6 | head -5
sa0 at mps0 bus 0 scbus0 target 3 lun 0
sa0: <QUANTUM ULTRIUM 5 3210> Removable Sequential Access SPC-4 SCSI device
sa0: Serial Number HU1313V6JA
sa0: 600.000MB/s transfers
sa0: Command Queueing enabled

And here are the details for /dev/mps0:

Code:
% dmesg | grep mps0 | head -3
mps0: <Avago Technologies (LSI) SAS2008> port 0xec00-0xecff mem 0xd9ff0000-0xd9ffffff,0xd9f80000-0xd9fbffff irq 48 at device 0.0 on pci8
mps0: Firmware: 07.15.08.00, Driver: 20.00.00.00-fbsd
mps0: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR>

I am using sysutils/bacula-server, and its default block size setting is 64512 bytes so nothing has changed there. I know that I can adjust that size for the Bacula storage daemon, but I'm not sure how to figure out what size the buffer should be.

Is there a command I can run to find the actual value for the "supplied buffer"?
 
Is there a command I can run to find the actual value for the "supplied buffer"?
I think you're looking for # mt -f /dev/sa0.ctl status -v. Note that the numbers may all report as 0 unless there's a tape physically in the drive.
Code:
(0:37) rz1:/sysprog/terry# mt -f /dev/sa0.ctl status -v
Drive: sa0: <IBM ULT3580-TD4 C7Q0> Serial Number: xxxxxxxxxx
---------------------------------
Mode      Density              Blocksize      bpi      Compression
Current:  0x46:LTO-4           variable       323215   enabled (0x1)
---------------------------------
Current Driver State: Writing.
---------------------------------
Partition:   0      Calc File Number:   0     Calc Record Number: 93382
Residual:    0  Reported File Number:  -1 Reported Record Number: -1
Flags: BOP
---------------------------------
Tape I/O parameters:
  Maximum I/O size allowed by driver and controller (maxio): 4718592 bytes
  Maximum I/O size reported by controller (cpi_maxio): 4718592 bytes
  Maximum block size supported by tape drive and media (max_blk): 16777215 bytes
  Minimum block size supported by tape drive and media (min_blk): 1 bytes
  Block granularity supported by tape drive and media (blk_gran): 0 bytes
  Maximum possible I/O size (max_effective_iosize): 4718592 bytes
This is on a modified kernel. Out-of-the-box, I think you get 131072.
 
Yep, that's the one, Terry. Thank you.

Code:
# mt -f /dev/sa0.ctl status -v
Drive: sa0: <QUANTUM ULTRIUM 5 3210> Serial Number: HU1313V6JA
---------------------------------
Mode  Density  Blocksize  bpi  Compression
Current:  0x58:LTO-5  variable  384607  enabled (0x1)
---------------------------------
Current Driver State: at rest.
---------------------------------
Partition:  0  Calc File Number:  4  Calc Record Number: 0
Residual:  0  Reported File Number:  4 Reported Record Number: 56240
Flags: None
---------------------------------
Tape I/O parameters:
  Maximum I/O size allowed by driver and controller (maxio): 131072 bytes
  Maximum I/O size reported by controller (cpi_maxio): 262144 bytes
  Maximum block size supported by tape drive and media (max_blk): 16777215 bytes
  Minimum block size supported by tape drive and media (min_blk): 1 bytes
  Block granularity supported by tape drive and media (blk_gran): 0 bytes
  Maximum possible I/O size (max_effective_iosize): 131072 bytes

The output shows that the supplied buffer is 131072 bytes; however, whatever process is giving me the aforementioned error message seems to be seeing a different value because 64512 is certainly not greater than 131072. I plan to troubleshoot Bacula's mtx-changer script to see how it uses mt and misc/mtx and if the script uses some other command or call to fetch that buffer. That being said, if anyone has come across a similar issue, please feel free to share any helpful information. :)
 
Since the main question regarding finding the supplied buffer was answered, I'll close this thread as being solved. As for the error message, I'll submit a bug report to the port maintainer.
 
Ah, so it's a test. I wonder if it gets around the issue where, in the past, I would run update slots in Bacula's console after changing the tapes in my Powervault 124T and misc/mtx would go into indefinite sleep. To get around that, I have always run chio -f /dev/ch0 status -S after changing the tapes, and then, I would run update slots in Bacula's console. I will have to try without using chio tomorrow.

Thanks, Dan. It is good to know that "error" message is nothing about which to be concerned.
 
So, to add to this topic.

The mtx sleep indefinitely is really a device wait, cannot be killed, etc. Same thing happens on Linux/Centos, whenever I open a changer magazine to change tapes. Problem on Centos is it does not clear the problem, but Centos does not have a CHIO command.

I am not sure why the -S on chio works. To get the id's, it might force some kind of a scsi bus reset, which clears the mtx device wait. I do not know, but it works for me too, which is good since rebooting a BACULA server to change tapes is a pain. Doing restores, required tape change/reboot/restore/replace tapes/reboot.

Now I run Bacula/tape in a BSD Jail. If it got in the device wait state, you could not even shutdown the jail!
 
Back
Top