Dtracing SCSI

I'm currently working a bug and escalation that is all in the closed source bit of Solaris which I find irritating however as part of this I've been working on a D script to print out every scsi IO that is done by the system, a sort of poor mans scsi snoop.

I'm not sure of the output format that I should used. Here is a sample of how it currently looks. While this was running I did a dd iseek=10 count=2 reading from target 8 on qus1 which was idle. You can clearly see the label being read, though why we read it twice is a mystery and then the pair of reads reading blocks 0xa and 0xb:

uata0:COMMAND 0x3 (REQUEST SENSE) address 2:0, lba 0, len 0x12, control 0 CDB 30001ac75f8 SDB 30001ac75f0
uata0:COMMAND 0 (TEST UNIT READY) address 2:0, lba 0, len 0, control 0 CDB 300050657d0 SDB 300050657b0
glm0:COMMAND 0x2a (WRITE(10)) address 2:0, lba 0x6a7603, len 0xe, control 0 cdbp 300011ce0a0 scb 300011ce060
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x6a, len 0x76, reason 0 (COMPLETED) state 0x1f Time 11, control 0x3 CDB 300011ce0a0 SDB 300011ce060
glm0:COMMAND 0xa (WRITE(6)) address 2:0, lba 0x87b8, len 0x24, control 0 CDB 300011ce0a0 SDB 300011ce060
glm0:RETURN  0xa (WRITE(6)) address 2:0, lba 0x87b8, len 0x24, reason 0 (COMPLETED) state 0x1f Time 6, control 0 CDB 300011ce0a0 SDB 300011ce060
qus1:RETURN  0 (TEST UNIT READY) address 8:0, lba 0, len 0, reason 0 (COMPLETED) state 0x17 Time 0, control 0 CDB 300016a9d90 SDB 300016a9dc0
qus1:RETURN  0 (TEST UNIT READY) address 8:0, lba 0, len 0, reason 0 (COMPLETED) state 0x17 Time 0, control 0 CDB 300016a9ab0 SDB 300016a9ae0
qus1:RETURN  0x1a (MODE SENSE(6)) address 8:0, lba 0x300, len 0x24, reason 0 (COMPLETED) state 0x5f Time 3, control 0 CDB 300016a94f0 SDB 300016a9520
qus1:RETURN  0x1a (MODE SENSE(6)) address 8:0, lba 0x400, len 0x24, reason 0 (COMPLETED) state 0x5f Time 2, control 0 CDB 300016a9940 SDB 300016a9970
qus1:RETURN  0x8 (READ(6)) address 8:0, lba 0, len 0x1, reason 0 (COMPLETED) state 0x5f Time 6, control 0 CDB 300016a9660 SDB 300016a9690
qus1:RETURN  0x8 (READ(6)) address 8:0, lba 0, len 0x1, reason 0 (COMPLETED) state 0x5f Time 0, control 0 CDB 300016a9c20 SDB 300016a9c50
qus1:RETURN  0x8 (READ(6)) address 8:0, lba 0xa, len 0x1, reason 0 (COMPLETED) state 0x5f Time 5, control 0 CDB 300016a9ab0 SDB 300016a9ae0
qus1:RETURN  0x8 (READ(6)) address 8:0, lba 0xb, len 0x1, reason 0 (COMPLETED) state 0x5f Time 0, control 0 CDB 300016a9d90 SDB 300016a9dc0
qus1:COMMAND 0 (TEST UNIT READY) address 8:0, lba 0, len 0, control 0 CDB 300016a9d90 SDB 300016a9dc0
qus1:COMMAND 0 (TEST UNIT READY) address 8:0, lba 0, len 0, control 0 CDB 300016a9ab0 SDB 300016a9ae0
qus1:COMMAND 0x1a (MODE SENSE(6)) address 8:0, lba 0x300, len 0x24, control 0 CDB 300016a94f0 SDB 300016a9520
qus1:COMMAND 0x1a (MODE SENSE(6)) address 8:0, lba 0x400, len 0x24, control 0 CDB 300016a9940 SDB 300016a9970
qus1:COMMAND 0x8 (READ(6)) address 8:0, lba 0, len 0x1, control 0 CDB 300016a9660 SDB 300016a9690
qus1:COMMAND 0x8 (READ(6)) address 8:0, lba 0, len 0x1, control 0 CDB 300016a9c20 SDB 300016a9c50
qus1:COMMAND 0x8 (READ(6)) address 8:0, lba 0xa, len 0x1, control 0 CDB 300016a9ab0 SDB 300016a9ae0
qus1:COMMAND 0x8 (READ(6)) address 8:0, lba 0xb, len 0x1, control 0 CDB 300016a9d90 SDB 300016a9dc0
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x40, reason 0 (COMPLETED) state 0x1f Time 6, control 0xb3 CDB 300011ce9d0 SDB 300011ce990
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x41, reason 0 (COMPLETED) state 0x1f Time 7, control 0x3d CDB 300002bc3b8 SDB 300002bc378
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x40, reason 0 (COMPLETED) state 0x1f Time 4, control 0x93 CDB 300011cece0 SDB 300011ceca0
glm0:COMMAND 0x2a (WRITE(10)) address 2:0, lba 0x3340b3, len 0x20, control 0 cdbp 300011ce9d0 scb 300011ce990
glm0:COMMAND 0x2a (WRITE(10)) address 2:0, lba 0x33413d, len 0x6, control 0 cdbp 300002bc3b8 scb 300002bc378
glm0:COMMAND 0x2a (WRITE(10)) address 2:0, lba 0x334093, len 0x10, control 0 cdbp 300011cece0 scb 300011ceca0
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x40, reason 0 (COMPLETED) state 0x1f Time 1, control 0xd3 CDB 300002bc6c8 SDB 300002bc688
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x43, reason 0 (COMPLETED) state 0x1f Time 5, control 0x9 CDB 300002bd180 SDB 300002bd140
glm0:RETURN  0x2a (WRITE(10)) address 2:0, lba 0x33, len 0x40, reason 0 (COMPLETED) state 0x1f Time 1, control 0xb3 CDB 300002bd308 SDB 300002bd2c8


The addresses are all of the format “target:lun” and are in hex. It has no knowledge of the host bus adapters which is only a problem for getting the return from the commands as these all come from the HBA's interrupt routine. Currently I cheat and look at the scsi pkt when scsi_destroy_pkt is called which covers the most common cases, but it is a hack.


That the COMMAND are sometimes outputted after they have returned is a oddity of dtrace which will either require the data to be timestamped and post processed or use speculations to get all the data output in the right order. My earlier attempts to use speculation were not successful under a moderate load.


My intention is to post the script here once I have cleaned it up a bit.


Tags:

Comments:

This is super cool! I look forward to reviewing the script.

Posted by Matty on February 08, 2006 at 12:58 PM GMT #

Post a Comment:
Comments are closed for this entry.
About

This is the old blog of Chris Gerhard. It has mostly moved to http://chrisgerhard.wordpress.com

Search

Archives
« April 2014
MonTueWedThuFriSatSun
 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
    
       
Today