#!/usr/sbin/dtrace -qCs /* * CDDL HEADER START * * The contents of this file are subject to the terms of the * Common Development and Distribution License, Version 1.0 only * (the "License"). You may not use this file except in compliance * with the License. * * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE * or http://www.opensolaris.org/os/licensing. * See the License for the specific language governing permissions * and limitations under the License. * * When distributing Covered Code, include this CDDL HEADER in each * file and include the License file at usr/src/OPENSOLARIS.LICENSE. * If applicable, add the following below this CDDL HEADER, with the * fields enclosed by brackets "[]" replaced with your own identifying * information: Portions Copyright [yyyy] [name of copyright owner] * * CDDL HEADER END */ /* * Copyright 2007 Sun Microsystems, Inc. All rights reserved. * Use is subject to license terms. */ /* * Chris.Gerhard@sun.com * Joel.Buckley@sun.com */ #pragma ident "@(#)scsi.d 1.9 07/02/19 SMI" /* * SCSI logging via dtrace. * * scsi.d [ time ['"hba"' [ '"inst"' X ]]] * * With no arguments it logs every scsi packet out and as many returns * as it can find. * * It's first argument is the name of the HBA that you wish to trace so * that the trace can be limited to just one class of HBA, eg: '"qus"', * '"isp"' etc. * * If it has a second argument it must be the string '"inst"' and then the * third argument is the instance number that you wish to trace. * * So to trace all the io going via instance 2 qus driver do: * * scsi.d time '"qus"' '"inst"' 2 * * The second argument of "inst" is rquired as I could not see a way to * differenciate between when $2 was set to a value of 0 and when $2 was * not set at all. * * All those quotes make for horrible syntax, sorry. * * Since dtrace does not output in real time it is useful to sort the output * of the script using sort -n to get the entries in chronological order. * */ #pragma D option quiet #pragma D option defaultargs /* * Set both lba & len to 64Bit values, to avoid type mismatch later... * * The following does not function due to DTrace insufficient registers... * * #define INT64(A, B, C, D, E, F, G, H) ( \ * (((A) & 0x0ffL) << 56) | \ * (((B) & 0x0ffL) << 48) | \ * (((C) & 0x0ffL) << 40) | \ * (((D) & 0x0ffL) << 32) | \ * (((E) & 0x0ffL) << 24) | \ * (((F) & 0x0ffL) << 16) | \ * (((G) & 0x0ffL) << 8) | \ * ((H) & 0x0ffL)) * * Instead, calculate lower & upper values, then pass them into this macro: */ #define INT64(A, B) ( \ (((A) & 0x0ffffffffLL) << 32) | \ ((B) & 0x0ffffffffL)) #define INT32(A, B, C, D) ( \ (((A) & 0x0ffL) << 24) | \ (((B) & 0x0ffL) << 16) | \ (((C) & 0x0ffL) << 8) | \ ((D) & 0x0ffL)) #define INT16(A, B) ( \ (((A) & 0x0ffL) << 8) | \ ((B) & 0x0ffL)) #define INT8(A) ( \ ((A) & 0x0ffL)) /* #define A_TO_TRAN(ap) ((ap)->a_hba_tran) */ #define P_TO_TRAN(pkt) ((pkt)->pkt_address.a_hba_tran) /* #define P_TO_ADDR(pkt) (&((pkt)->pkt_address)) */ #define P_TO_DEVINFO(pkt) ((struct dev_info *)(P_TO_TRAN(pkt)->tran_hba_dip)) #define PRINT8(A) printf(" %x %x %x %x %x %x %x %x", (A)[0], \ (A)[1], (A)[2], (A)[3], (A)[4], (A)[5], (A)[6], (A)[7]) #define DEV_NAME(pkt) \ stringof(`devnamesp[P_TO_DEVINFO(pkt)->devi_major].dn_name) /* ` */ #define DEV_INST(pkt) (P_TO_DEVINFO(pkt)->devi_instance) #define ARGUMENT_TEST ($2 == 0 || $2 == DEV_NAME(self->pkt) && \ ($3 == 0 || ($3 == "inst" && $4 == DEV_INST(self->pkt)))) /* * PRINT_DEV_FROM_PKT * * From a scsi_pkt get the name of the driver and the instance of the * hba. */ #define PRINT_DEV_FROM_PKT(pkt) \ printf("%s%d:", DEV_NAME(pkt), DEV_INST(pkt)) #define PRINT_TIMESTAMP() printf("%5.5d.%9.9d ", \ (timestamp - script_start_time)/1000000000, \ (timestamp - script_start_time)%1000000000); BEGIN { script_start_time = timestamp; end_time = timestamp + ($1 * 1000000000); scsi_ops[0x000, 0x0] = "TEST_UNIT_READY"; scsi_ops[0x001, 0x0] = "REZERO_UNIT_or_REWIND"; scsi_ops[0x003, 0x0] = "REQUEST_SENSE"; scsi_ops[0x004, 0x0] = "FORMAT_UNIT"; scsi_ops[0x007, 0x0] = "REASSIGN_BLOCKS"; scsi_ops[0x008, 0x0] = "READ(6)"; scsi_ops[0x00a, 0x0] = "WRITE(6)"; scsi_ops[0x00b, 0x0] = "SEEK(6)"; scsi_ops[0x012, 0x0] = "INQUIRY"; scsi_ops[0x015, 0x0] = "MODE_SELECT(6)"; scsi_ops[0x016, 0x0] = "RESERVE(6)"; scsi_ops[0x017, 0x0] = "RELEASE(6)"; scsi_ops[0x018, 0x0] = "COPY"; scsi_ops[0x019, 0x0] = "ERASE(6)"; scsi_ops[0x01a, 0x0] = "MODE_SENSE(6)"; scsi_ops[0x01b, 0x0] = "START_STOP_UNIT"; scsi_ops[0x01c, 0x0] = "RECIEVE_DIAGNOSTIC_RESULTS"; scsi_ops[0x01d, 0x0] = "SEND_DIAGNOSTIC"; scsi_ops[0x01e, 0x0] = "PREVENT_ALLOW_MEDIUM_REMOVAL"; scsi_ops[0x025, 0x0] = "READ_CAPACITY(10)"; scsi_ops[0x028, 0x0] = "READ(10)"; scsi_ops[0x02a, 0x0] = "WRITE(10)"; scsi_ops[0x02b, 0x0] = "SEEK(10)_or_LOCATE(10)"; scsi_ops[0x02e, 0x0] = "WRITE_AND_VERIFY(10)"; scsi_ops[0x02f, 0x0] = "VERIFY(10)"; scsi_ops[0x030, 0x0] = "SEARCH_DATA_HIGH"; scsi_ops[0x031, 0x0] = "SEARCH_DATA_EQUAL"; scsi_ops[0x032, 0x0] = "SEARCH_DATA_LOW"; scsi_ops[0x033, 0x0] = "SET_LIMITS(10)"; scsi_ops[0x034, 0x0] = "PRE-FETCH(10)"; scsi_ops[0x035, 0x0] = "SYNCHRONIZE_CACHE(10)"; scsi_ops[0x036, 0x0] = "LOCK_UNLOCK_CACHE(10)"; scsi_ops[0x037, 0x0] = "READ_DEFECT_DATA(10)"; scsi_ops[0x039, 0x0] = "COMPARE"; scsi_ops[0x03a, 0x0] = "COPY_AND_WRITE"; scsi_ops[0x03b, 0x0] = "WRITE_BUFFER"; scsi_ops[0x03c, 0x0] = "READ_BUFFER"; scsi_ops[0x03e, 0x0] = "READ_LONG"; scsi_ops[0x03f, 0x0] = "WRITE_LONG"; scsi_ops[0x040, 0x0] = "CHANGE_DEFINITION"; scsi_ops[0x041, 0x0] = "WRITE_SAME(10)"; scsi_ops[0x04c, 0x0] = "LOG_SELECT"; scsi_ops[0x04d, 0x0] = "LOG_SENSE"; scsi_ops[0x050, 0x0] = "XDWRITE(10)"; scsi_ops[0x051, 0x0] = "XPWRITE(10)"; scsi_ops[0x052, 0x0] = "XDREAD(10)"; scsi_ops[0x053, 0x0] = "XDWRITEREAD(10)"; scsi_ops[0x055, 0x0] = "MODE_SELECT(10)"; scsi_ops[0x056, 0x0] = "RESERVE(10)"; scsi_ops[0x057, 0x0] = "RELEASE(10)"; scsi_ops[0x05a, 0x0] = "MODE_SENSE(10)"; scsi_ops[0x05e, 0x0] = "PERSISTENT_RESERVE_IN"; scsi_ops[0x05f, 0x0] = "PERSISTENT_RESERVE_OUT"; scsi_ops[0x07f, 0x0] = "Variable_Length_CDB"; scsi_ops[0x07f, 0x3] = "XDREAD(32)"; scsi_ops[0x07f, 0x4] = "XDWRITE(32)"; scsi_ops[0x07f, 0x6] = "XPWRITE(32)"; scsi_ops[0x07f, 0x7] = "XDWRITEREAD(32)"; scsi_ops[0x07f, 0x9] = "READ(32)"; scsi_ops[0x07f, 0xb] = "WRITE(32)"; scsi_ops[0x07f, 0xa] = "VERIFY(32)"; scsi_ops[0x07f, 0xc] = "WRITE_AND_VERIFY(32)"; scsi_ops[0x080, 0x0] = "XDWRITE_EXTENDED(16)"; scsi_ops[0x081, 0x0] = "REBUILD(16)"; scsi_ops[0x082, 0x0] = "REGENERATE(16)"; scsi_ops[0x083, 0x0] = "EXTENDED_COPY"; scsi_ops[0x086, 0x0] = "ACCESS_CONTROL_IN"; scsi_ops[0x087, 0x0] = "ACCESS_CONTROL_OUT"; scsi_ops[0x088, 0x0] = "READ(16)"; scsi_ops[0x08a, 0x0] = "WRITE(16)"; scsi_ops[0x08c, 0x0] = "READ_ATTRIBUTES"; scsi_ops[0x08d, 0x0] = "WRITE_ATTRIBUTES"; scsi_ops[0x08e, 0x0] = "WRITE_AND_VERIFY(16)"; scsi_ops[0x08f, 0x0] = "VERIFY(16)"; scsi_ops[0x090, 0x0] = "PRE-FETCH(16)"; scsi_ops[0x091, 0x0] = "SYNCHRONIZE_CACHE(16)"; scsi_ops[0x092, 0x0] = "LOCK_UNLOCK_CACHE(16)_or_LOCATE(16)"; scsi_ops[0x093, 0x0] = "WRITE_SAME(16)_or_ERASE(16)"; scsi_ops[0x09e, 0x0] = "SERVICE_IN_or_READ_CAPACITY(16)"; scsi_ops[0x0a0, 0x0] = "REPORT_LUNS"; scsi_ops[0x0a3, 0x0] = "MAINTENANCE_IN_or_REPORT_TARGET_PORT_GROUPS"; scsi_ops[0x0a4, 0x0] = "MAINTENANCE_OUT_or_SET_TARGET_PORT_GROUPS"; scsi_ops[0x0a7, 0x0] = "MOVE_MEDIUM"; scsi_ops[0x0a8, 0x0] = "READ(12)"; scsi_ops[0x0aa, 0x0] = "WRITE(12)"; scsi_ops[0x0ae, 0x0] = "WRITE_AND_VERIFY(12)"; scsi_ops[0x0af, 0x0] = "VERIFY(12)"; scsi_ops[0x0b3, 0x0] = "SET_LIMITS(12)"; scsi_ops[0x0b4, 0x0] = "READ_ELEMENT_STATUS"; scsi_ops[0x0b7, 0x0] = "READ_DEFECT_DATA(12)"; scsi_ops[0x0ba, 0x0] = "REDUNDANCY_GROUP_IN"; scsi_ops[0x0bb, 0x0] = "REDUNDANCY_GROUP_OUT"; scsi_ops[0x0bc, 0x0] = "SPARE_IN"; scsi_ops[0x0bd, 0x0] = "SPARE_OUT"; scsi_ops[0x0be, 0x0] = "VOLUME_SET_IN"; scsi_ops[0x0bf, 0x0] = "VOLUME_SET_OUT"; scsi_ops[0x0d0, 0x0] = "EXPLICIT_LUN_FAILOVER"; scsi_ops[0x0f1, 0x0] = "STOREDGE_CONTROLLER"; scsi_reasons[0] = "COMPLETED"; scsi_reasons[1] = "INCOMPLETE"; scsi_reasons[2] = "DMA_ERR"; scsi_reasons[3] = "TRAN_ERR"; scsi_reasons[4] = "RESET"; scsi_reasons[5] = "ABORTED"; scsi_reasons[6] = "TIMEOUT"; scsi_reasons[7] = "DATA_OVERRUN"; scsi_reasons[8] = "COMMAND_OVERRUN"; scsi_reasons[9] = "STATUS_OVERRUN"; scsi_reasons[10] = "Bad_Message"; scsi_reasons[11] = "No_Message_Out"; scsi_reasons[12] = "XID_Failed"; scsi_reasons[13] = "IDE_Failed"; scsi_reasons[14] = "Abort_Failed"; scsi_reasons[15] = "Reject_Failed"; scsi_reasons[16] = "Nop_Failed"; scsi_reasons[17] = "Message_Parity_Error_Failed"; scsi_reasons[18] = "Bus_Device_Reset_Failed"; scsi_reasons[19] = "Identify_Message_Rejected"; scsi_reasons[20] = "Unexpected_Bus_free"; scsi_reasons[21] = "Tag_Rejected"; scsi_reasons[22] = "TERMINATED"; scsi_reasons[24] = "Device_Gone"; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / $1 != 0 && end_time < timestamp / { exit(0); } /* * relying on scsi_destroy_pkt to get the response is a * hack that may or may not always work depending on HBA * and target drivers. */ fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry { self->pkt = (struct scsi_pkt *)arg0; self->cdb = (uchar_t *)self->pkt->pkt_cdbp; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->group = ((self->cdb[0] & 0xe0) >> 5); } fbt:scsi:scsi_transport:entry { start_time[self->scb] = timestamp; self->name = "->"; } fbt:scsi:scsi_destroy_pkt:entry { self->name = "<-"; } /* * Now cope with the differnent CDB layouts based on the group. * * Trying to use x = self->group == 0 ? y : z; results in D running out * of registers so it is all done using seperate probes. * * Group Listing: * + Group 0: 6Byte CDBs: scsi_ops[0x000] thru scsi_ops[0x01f] * + Group 1: 10Byte CDBs: scsi_ops[0x020] thru scsi_ops[0x03f] * + Group 2: 10Byte CDBs: scsi_ops[0x040] thru scsi_ops[0x05f] * + Group 3: Variable Length CDBs: scsi_ops[0x060] thru scsi_ops[0x07f] * + Group 4: 16Byte CDBs: scsi_ops[0x080] thru scsi_ops[0x09f] * + Group 5: 12Byte CDBs: scsi_ops[0x0a0] thru scsi_ops[0x0bf] * Group 6: Vendor Specific CDBs: scsi_ops[0x0c0] thru scsi_ops[0x0df] * Group 7: Vendor Specific CDBs: scsi_ops[0x0e0] thru scsi_ops[0x0ff] * * The groups with a leading plus sign "+" are of importance. */ fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 0 / { self->lba = INT32(0, (self->cdb[1] & 0x1f), self->cdb[2], self->cdb[3]); self->lbalen = 6; self->len = INT8(self->cdb[4]); self->control = self->cdb[5]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = 0; self->cdblen = 6; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 1 / { self->lba = INT32(self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5]); self->lbalen = 8; self->len = INT16(self->cdb[7], self->cdb[8]); self->control = self->cdb[9]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = 0; self->cdblen = 10; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 2 / { self->lba = INT32(self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5]); self->lbalen = 8; self->len = INT16(self->cdb[7], self->cdb[8]); self->control = self->cdb[9]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = 0; self->cdblen = 10; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 3 / { /* * This is to get around insufficient DTrace Registers... * * Instead of doing this in a single step like: * * self->lba = INT64(\ * self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5], \ * self->cdb[6], self->cdb[7], self->cdb[8], self->cdb[9]); * * The int64 LBA value must be calculated in 5 steps... */ this->lbaUpper = INT32(self->cdb[12], self->cdb[13], self->cdb[14], self->cdb[15]); this->lbaLower = INT32(self->cdb[16], self->cdb[17], self->cdb[18], self->cdb[19]); self->lba = INT64(this->lbaUpper, this->lbaLower); this->lbaUpper = 0; this->lbaLower = 0; self->lbalen = 16; self->len = INT32(self->cdb[28], self->cdb[29], self->cdb[30], self->cdb[31]); self->control = self->cdb[1]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = INT16(self->cdb[8], self->cdb[9]); self->cdblen = 32 } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 4 / { /* * This is to get around insufficient DTrace Registers... * * Instead of doing this in a single step like: * * self->lba = INT64(\ * self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5], \ * self->cdb[6], self->cdb[7], self->cdb[8], self->cdb[9]); * * The int64 LBA value must be calculated in 5 steps... */ this->lbaUpper = INT32(self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5]); this->lbaLower = INT32(self->cdb[6], self->cdb[7], self->cdb[8], self->cdb[9]); self->lba = INT64(this->lbaUpper, this->lbaLower); this->lbaUpper = 0; this->lbaLower = 0; self->lbalen = 16; self->len = INT32(self->cdb[10], self->cdb[11], self->cdb[12], self->cdb[13]); self->control = self->cdb[15]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = 0; self->cdblen = 16; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry / self->group == 5 / { self->lba = INT32(self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5]); self->lbalen = 8; self->len = INT32(self->cdb[6], self->cdb[7], self->cdb[8], self->cdb[9]); self->control = self->cdb[11]; self->scb = (uchar_t *)self->pkt->pkt_scbp; self->sa = 0; self->cdblen = 12; } /* * The guts of the script. Report what we have if we are required. * First the stuff we do for both outgoing and incoming. */ fbt:scsi:scsi_destroy_pkt:entry, fbt:scsi:scsi_transport:entry / ARGUMENT_TEST / { PRINT_TIMESTAMP(); PRINT_DEV_FROM_PKT(self->pkt); printf("%s 0x%2.2x %9s address %2.2d:%2.2d, lba 0x%*.*x, ", self->name, self->cdb[0], scsi_ops[(uint_t)self->cdb[0], self->sa] != 0 ? scsi_ops[(uint_t)self->cdb[0], self->sa] : "Unknown", self->pkt->pkt_address.a_target, self->pkt->pkt_address.a_lun, self->lbalen, self->lbalen, self->lba); printf("len 0x%6.6x, control 0x%2.2x timeout %d CDBP %p", self->len, self->control, self->pkt->pkt_time, self->cdb); self->name = 0; } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST / { printf(" %s(%d)", execname, pid); } /* * For those who are just not happy without some raw hex numbers print the * raw cdb. */ fbt:scsi:scsi_transport:entry / ARGUMENT_TEST && self->cdblen / { printf(" cdb(%d) %2.2x%2.2x%2.2x%2.2x%2.2x%2.2x", self->cdblen, self->cdb[0], self->cdb[1], self->cdb[2], self->cdb[3], self->cdb[4], self->cdb[5]); } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST && self->cdblen > 6/ { printf("%2.2x%2.2x%2.2x%2.2x", self->cdb[6], self->cdb[7], self->cdb[8], self->cdb[9]); } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST && self->cdblen > 10 / { printf("%2.2x%2.2x", self->cdb[10], self->cdb[11]); } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST && self->cdblen > 12/ { printf("%2.2x%2.2x%2.2x%2.2x", self->cdb[12], self->cdb[13], self->cdb[14], self->cdb[15]); } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST && self->cdblen > 16/ { printf("%2.2x%2.2x%2.2x%2.2x%2.2x2.2x%2.2x%2.2x%2.2x", self->cdb[16], self->cdb[17], self->cdb[18], self->cdb[19], self->cdb[20], self->cdb[21], self->cdb[22], self->cdb[23]); printf("%2.2x%2.2x%2.2x%2.2x%2.2x2.2x%2.2x%2.2x%2.2x", self->cdb[24], self->cdb[25], self->cdb[26], self->cdb[27], self->cdb[28], self->cdb[29], self->cdb[30], self->cdb[31]); } fbt:scsi:scsi_transport:entry / ARGUMENT_TEST / { printf("\n"); } /* * Now the result on the incoming. */ fbt:scsi:scsi_destroy_pkt:entry / ARGUMENT_TEST / { printf(", reason 0x%x (%s) state 0x%x Time %dus\n", self->pkt->pkt_reason, scsi_reasons[self->pkt->pkt_reason] != 0 ? scsi_reasons[self->pkt->pkt_reason] : "Unknown", self->pkt->pkt_state, start_time[self->scb] != 0 ? (timestamp - start_time[self->scb])/1000 : 0); start_time[self->scb] = 0; } fbt:scsi:scsi_transport:return, fbt:scsi:scsi_destroy_pkt:return / self->pkt != 0/ { self->pkt = 0; self->cdb = 0; self->scb = 0; self->len = 0; self->control = 0; self->lba = 0; self->lbalen = 0; self->sa = 0; self->cdblen = 0; }