#!/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.12 07/03/16 SMI" /* * SCSI logging via dtrace. * * scsi.d [ @t time ][ hba [ X ]] * * With no arguments it logs every scsi packet out and as many returns * as it can find. * * So to trace all the io going via instance 2 qus driver do: * * scsi.d qus 2 * * To do the same trace for 20 seconds do: * * scsi.d @T 20 qus 2 * * NOTE: the "@" is used instead of the more traditional "-" as dtrace will * continue to parse arguments so would see "-T" as an argument to dtrace and * produce a usage error. * * 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. * * NOTE: This does not directly trace what goes onto the scsi bus or fibre, * to do so would require this script have knowledge of every HBA that could * ever be connected to a system. It traces the SCSI packets as they are * passed from the target driver to the HBA in the SCSA layer and then back * again. Although to get the packet when it is returned it guesses that the * packet will be destroyed using scsi_destroy_pkt and not modified before it * is. So far this has worked but there is no garauntee that it will work for * all HBAs and target drivers in the future. * */ #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 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 (hba_set == 0 || hba == DEV_NAME(this->pkt) && \ (inst_set == 0 || inst == DEV_INST(this->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); /* * Look away now. * * This is just hackery to get around me being so stubborn I * don't want to wrap this in a shell script. */ #define TIMEOUT_SELECT "@T" #define DO_ARGS(N, NS, M, MS) \ BEGIN \ / hba_set == 0 && NS != "" && NS != TIMEOUT_SELECT / \ { \ hba = NS; \ hba_set = 1; \ } \ BEGIN \ / hba_set == 1 && inst_set == 0 && MS != "" / \ { \ inst = M; \ inst_set = 1; \ } \ BEGIN / $$1 == TIMEOUT_SELECT / { timeout = $2; } DO_ARGS($1, $$1, $2, $$2) DO_ARGS($3, $$3, $4, $$4) /* * You can open your eyes again now. */ BEGIN { script_start_time = timestamp; end_time = timestamp + (timeout * 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 /timeout != 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 { this->pkt = (struct scsi_pkt *)arg0; this->cdb = (uchar_t *)this->pkt->pkt_cdbp; this->scb = (uchar_t *)this->pkt->pkt_scbp; this->group = ((this->cdb[0] & 0xe0) >> 5); this->lbalen = 0; this->arg_test_passed = 0; } /* * 5.11 allows this->name = "->" but vanilla 5.10 does not so I'm sticking * to the setting a variable and then choosing the string later. */ fbt:scsi:scsi_transport:entry { start_time[this->scb] = timestamp; this->name = 1; } fbt:scsi:scsi_destroy_pkt:entry { this->name = 0; } /* * Now cope with the differnent CDB layouts based on the group. * * Trying to use x = this->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 /this->group == 0/ { this->lba = INT32(0, (this->cdb[1] & 0x1f), this->cdb[2], this->cdb[3]); this->lbalen = 6; this->len = INT8(this->cdb[4]); this->control = this->cdb[5]; this->sa = 0; this->cdblen = 6; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group == 1/ { this->lba = INT32(this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5]); this->lbalen = 8; this->len = INT16(this->cdb[7], this->cdb[8]); this->control = this->cdb[9]; this->sa = 0; this->cdblen = 10; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group == 2/ { this->lba = INT32(this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5]); this->lbalen = 8; this->len = INT16(this->cdb[7], this->cdb[8]); this->control = this->cdb[9]; this->sa = 0; this->cdblen = 10; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group == 3/ { /* * This is to get around insufficient DTrace Registers... * * Instead of doing this in a single step like: * * this->lba = INT64(\ * this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5], \ * this->cdb[6], this->cdb[7], this->cdb[8], this->cdb[9]); * * The int64 LBA value must be calculated in 5 steps... */ this->lbaUpper = INT32(this->cdb[12], this->cdb[13], this->cdb[14], this->cdb[15]); this->lbaLower = INT32(this->cdb[16], this->cdb[17], this->cdb[18], this->cdb[19]); this->lba = INT64(this->lbaUpper, this->lbaLower); this->lbaUpper = 0; this->lbaLower = 0; this->lbalen = 16; this->len = INT32(this->cdb[28], this->cdb[29], this->cdb[30], this->cdb[31]); this->control = this->cdb[1]; this->sa = INT16(this->cdb[8], this->cdb[9]); this->cdblen = 32 } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group == 4/ { /* * This is to get around insufficient DTrace Registers... * * Instead of doing this in a single step like: * * this->lba = INT64(\ * this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5], \ * this->cdb[6], this->cdb[7], this->cdb[8], this->cdb[9]); * * The int64 LBA value must be calculated in 5 steps... */ this->lbaUpper = INT32(this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5]); this->lbaLower = INT32(this->cdb[6], this->cdb[7], this->cdb[8], this->cdb[9]); this->lba = INT64(this->lbaUpper, this->lbaLower); this->lbaUpper = 0; this->lbaLower = 0; this->lbalen = 16; this->len = INT32(this->cdb[10], this->cdb[11], this->cdb[12], this->cdb[13]); this->control = this->cdb[15]; this->sa = 0; this->cdblen = 16; } fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group == 5/ { this->lba = INT32(this->cdb[2], this->cdb[3], this->cdb[4], this->cdb[5]); this->lbalen = 8; this->len = INT32(this->cdb[6], this->cdb[7], this->cdb[8], this->cdb[9]); this->control = this->cdb[11]; this->sa = 0; this->cdblen = 12; } /* * We don't know the format of the group 6 and 7 commands as they are * vendor specific. So I just print the cdb up to a maximum of 32 bytes. */ fbt:scsi:scsi_transport:entry, fbt:scsi:scsi_destroy_pkt:entry /this->group > 5/ { this->lba = 0; this->lbalen = 0; this->len = 0; this->control = 0; this->sa = 0; /* * At some point pkt_cdblen will make it into 5.10 but I can at this moment * workout how I can test this before the script compiles (without wrapping * this in a ksh script which as I have mentioned above I'm not going to do). */ #ifndef __SunOS_5_10 this->cdblen = this->pkt->pkt_cdblen; #else this->cdblen = 32; #endif } /* * 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/ { this->arg_test_passed = 1; PRINT_TIMESTAMP(); PRINT_DEV_FROM_PKT(this->pkt); printf("%s 0x%2.2x %9s address %2.2d:%2.2d, lba 0x%*.*x, ", this->name ? "->" : "<-", this->cdb[0], scsi_ops[(uint_t)this->cdb[0], this->sa] != 0 ? scsi_ops[(uint_t)this->cdb[0], this->sa] : "Unknown", this->pkt->pkt_address.a_target, this->pkt->pkt_address.a_lun, this->lbalen, this->lbalen, this->lba); printf("len 0x%6.6x, control 0x%2.2x timeout %d CDBP %p", this->len, this->control, this->pkt->pkt_time, this->cdb); } fbt:scsi:scsi_transport:entry /this->arg_test_passed == 1/ { 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 /this->arg_test_passed == 1 && this->cdblen/ { printf(" cdb(%d) ", this->cdblen); } /* * Now print each byte out of the cdb. */ #define PRINT_CDB(N) \ fbt:scsi:scsi_transport:entry \ /this->arg_test_passed == 1 && this->cdblen > N/ \ { \ printf("%2.2x", this->cdb[N]) \ } PRINT_CDB(0) PRINT_CDB(1) PRINT_CDB(2) PRINT_CDB(3) PRINT_CDB(4) PRINT_CDB(5) PRINT_CDB(6) PRINT_CDB(7) PRINT_CDB(8) PRINT_CDB(9) PRINT_CDB(10) PRINT_CDB(11) PRINT_CDB(12) PRINT_CDB(13) PRINT_CDB(14) PRINT_CDB(15) PRINT_CDB(16) PRINT_CDB(17) PRINT_CDB(18) PRINT_CDB(19) PRINT_CDB(20) PRINT_CDB(21) PRINT_CDB(22) PRINT_CDB(23) PRINT_CDB(24) PRINT_CDB(25) PRINT_CDB(26) PRINT_CDB(27) PRINT_CDB(28) PRINT_CDB(29) PRINT_CDB(30) PRINT_CDB(31) fbt:scsi:scsi_transport:entry /this->arg_test_passed == 1/ { printf("\n"); } /* * Now the result on the incoming. */ fbt:scsi:scsi_destroy_pkt:entry /this->arg_test_passed == 1/ { printf(", reason 0x%x (%s) state 0x%x Time %dus\n", this->pkt->pkt_reason, scsi_reasons[this->pkt->pkt_reason] != 0 ? scsi_reasons[this->pkt->pkt_reason] : "Unknown", this->pkt->pkt_state, start_time[this->scb] != 0 ? (timestamp - start_time[this->scb])/1000 : 0); start_time[this->scb] = 0; }