Tracing facility

Edit online

IBMtape incorporates a tracing facility that is useful for completing problem determination. The tracing facility logs diagnostic information to /var/adm/messages based on the control variable IBM_trace. Refer to Setting the IBM_trace level for static tracing for instructions on how to set the trace value.

IBM_trace values range from 0-13 and result in posted messages as shown in Table 1. Postings are cumulative, so trace level 3 also posts items for levels 2, 1, and 0. A trace value of 2 or 3 is suitable for most normal production environments, with little or no degradation of throughput. IBM_trace values of 4 and higher increasingly degrade performance and generally is used only when directed by IBM® support personnel.

Table 1. Solaris: tracing facility
Trace level	Items traced
0	Severe error conditions only. For installations with small /var file systems, this setting can prevent filling the file system unexpectedly. However, this setting might be at the cost of not recording messages that are related to serious device or system environment errors.
1	Device sense data. Sense data can help in diagnosing the source of unexpected error conditions.
3	Device opens and closes, Decoded SCSI command, sense key, ASC and ASCQ for sense data.
4–13	Increasingly verbose tracing information. These tracing levels are useful only to IBMtape developers.
Note: IBMtape earlier than Version 4.0.2.7 had only `IBM_trace` values 0–4. Message content and selection differed significantly from current IBMtape versions.

By default, system error messages, including IBMtape trace messages, are placed in /var/adm/messages. If your installation modified /etc/syslog.conf to redirect system error messages, IBMtape tracing is handled as other kernel messages. Refer to the syslog.conf man page and the comments in syslog.conf for information about the system logging operation. Changes made to syslog.conf take effect after the next system restart.

The following shows trace level 2 output, with system date and time stamps removed. Device instance 390 is opened on the first line. The device minor number 12450 is decoded and shows that the SCSI medium changer (smc) special file was opened.

The second line decodes selected fields from the sense data that follows it. The decoded information shows that sense data was generated during a Move Medium command. Looking up the decoded Sense Key/ASC/ASCQ combination in the 3590 hardware reference, we find that the command failed because the move from location was empty. The actual sense data follows the decoded fields.

Note: Solaris, rather than printing multiple 16-byte lines of hexadecimal zeros, prints only the first such line, followed by a repeat count.

IBMtape(390) _open: 374 Inst 390, Minor 12450 (smc), Flags 0x5,
                TL 2/0/0, 4.0.2.8
IBMtape(390) check_sense: cmd 0xa5(move_medium), key/asc/ascq 0x5/3b/e,
               defer 0, retry 0, rc 22
IBMtape(390) 03590B11 SENSE DATA:
IBMtape(390)  70  0  5  0  0  0  0 58  0  0  0  0 3b  e ff  2
IBMtape(390)   0 20  1 40  a  9  1  0  0  0  0  0  0  0 a5  0
IBMtape(390)   0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0
last message repeated 1 time
IBMtape(390)   0  0  0  0  0  0  0  0 36 33 39 20 20 20 20  0
IBMtape(390)   0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0
IBMtape(390) _close: Inst 390, Minor 12450 (smc), Flags 0x5, exit(0)

In the next example, the device open line shows that a tape drive (drv) device special file was opened. The sense data for device instance 292 was generated during a space operation. The Sense Key/ASC/ASCQ shows that a filemark was encountered during the space.

IBMtape(292) _open: 554 Inst 292, Minor 9412 (drv), Flags 0x5,
                TL 2/0/0, 4.0.2.8
IBMtape(292) check_sense: cmd 0x11(space), key/asc/ascq 0x0/0/1,
                defer 0, retry 0, rc 5
IBMtape(292) 03570B02 SENSE DATA:
IBMtape(292)  f0  0 80  0  0  0  1 48  0  0  0  0  0  1 ff  a
IBMtape(292)  c4 b1  0 20  0  5  1 91  0 34  0  0  0  0 11  0
IBMtape(292)   0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  6
IBMtape(292)  6f 28  0 ad 73 32  0  0  0  0  0  0  0  0  0  0
IBMtape(292)   0  0  0  0  0  0 20  0 31 42 41 20 20 20 20  0
IBMtape(292) _close: Inst 292, Minor 9412 (drv), Flags 0x5, exit(0)

Finally, the sense data for device instance 230, a tape drive, occurred during a test unit ready and indicates that no tape is loaded in the drive.

IBMtape(230) _open: 728 Inst 230, Minor 7366 (drv), Flags 0x5,
                TL 2/0/0, 4.0.2.8
IBMtape(230) check_sense: cmd 0x0(test_unit_ready),
                key/asc/ascq 0x2/3a/0, defer 0, retry 0, rc 5
IBMtape(230) 03570B02 SENSE DATA:
IBMtape(230)  70  0  2  0  0  0  0 48  0  0  0  0 3a  0 ff  2
IBMtape(230)  c4  8  0 30  0  6  1 40  0  0  0  0  0  0  0  0
IBMtape(230)   0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0
last message repeated 1 time
IBMtape(230)   0  0  0  0  0  0  0  0 31 42 41 20 20 20 20  0
IBMtape(230) _close: Inst 230, Minor 7366 (drv), Flags 0x5, exit(0)

You can match an instance number with its corresponding device special file in two steps.

Find the instance number in /etc/path_to_inst.

$ grep 292 /etc/path_to_inst
"/pci@6,4000/scsi@2,1/IBMtape@2,0" 292 "IBMtape"

List long the contents of /dev/rmt and search for the path name you found in the previous step.

$ ls -l /dev/rmt | grep "/pci@6,4000/scsi@2,1/IBMtape@2,0"
lrwxrwxrwx   1 root     other         48 Aug  26 11:49 8st ->
   ../../devices/pci@6,4000/scsi@2,1/IBMtape@2,0:st
lrwxrwxrwx   1 root     other         49 Aug  26 11:49 8stb ->
   ../../devices/pci@6,4000/scsi@2,1/IBMtape@2,0:stb

In this example, /dev/rmt/8st, /dev/rmt/8stb, and so on, are symbolic links to the device special files that are associated with device instance 292.