Tuesday, 20 May 2008

Filer iSCSI trace

Running a network trace from a filer

Data ONTAP has a built in packet trace capability, which can be run straight from the command line. The format of the capture is the standard BPF and so can be imported into pretty much any tool for viewing and analysis. By default the packet trace is stored in memory, but it can be easily switched to write out to a local volume on the filer in order to gather larger traces.

Start a trace on interface eOb and write the file out to '/' with a miximum trace size of 5 MB
rtpperfsrv053*> pktt start e0b -d / -s 5m

Measuring iSCSI traffic with tethereal

tethereal is a command line interface to Ethereal, I am not sure if it comes bundled with Wireshark, but it is available on some linux distros. I find the syntax and functionality nicer than tcpdump. There's lots of data on the net about using tethereal with NFS but not so much with iSCSI. Below are a few commands and filters I used to analyse some traces of iSCSI traffic.


  • In the example below the captured packet data rolled up into the iscsi protocol, and so we see the SCSI writes from the clients ( & to the filer ( The LBA: value is the offset into the LUN where the read/write will take place. I am using the '-r' switch to read a file creates by pktt. The filename is interfacename_datetimestamp.trc

$tethereal -r e0b_20080519_102523.trc iscsi

7   0.000450 -> iSCSI SCSI: Response LUN: 0xffff (CDB:0xffff) (Good)
8 0.000545 -> iSCSI SCSI: Response LUN: 0xffff (CDB:0xffff) (Good)
68 0.001521 -> iSCSI SCSI: Write(10) LUN: 0x07 (LBA: 0x00228718, Len: 112)SCSI: Data Out LUN: 0x07 (Write(10) Request Data)
69 0.002746 -> iSCSI SCSI: Response LUN: 0x07 (Write(10)) (Good)
129 0.003225 -> iSCSI SCSI: Write(10) LUN: 0x1e (LBA: 0x00228b00, Len: 112)SCSI: Data Out LUN: 0x1e (Write(10) Request Data)
180 0.004140 -> iSCSI SCSI: Write(10) LUN: 0x1a (LBA: 0x03dd12e8, Len: 96)SCSI: Data Out LUN: 0x1a (Write(10) Request Data)
236 0.004871 -> iSCSI SCSI: Write(10) LUN: 0x03 (LBA: 0x03de1060, Len: 104)SCSI: Data Out LUN: 0x03 (Write(10) Request Data)
315 0.005210 -> iSCSI SCSI: Write(10) LUN: 0x1c (LBA: 0x03de1b00, Len: 104)SCSI: Data Out LUN: 0x1c (Write(10) Request Data)
331 0.005320 -> iSCSI SCSI: Response LUN: 0x1e (Write(10)) (Good)

Gathering statistics

Although there are some really nice commands for viewing RPC (e.g. NFS) calls including the round trip time (RTT) of each NFS IO, I could not find anything similar for iSCSI.

  • tethereal does alow the display of per interval statistics, l, in the example below I tethereal displays stats every 1/2 second. It is possible specify any time value down to millisecond. In this example we are reading a pktt created file using '-r'. The output shows that the traffic is somewhat 'bursty' in nature.

  • I use the switch -tad to give me time as an absolute delta from the first packet. -r to read data from a file (rather than 'live' from a NIC). -q to print out just the summary result table. -z io,stat,0.5 tells tethereal to generate statistics on the I/O every 0.5 seconds.

$tethereal -tad -r e0b_20080519_153919.trc -qz io,stat,0.5

IO Statistics
Interval: 0.500 secs
Column #0:
| Column #0
Time |frames| bytes
000.000-000.500 15249 15114470
000.500-001.000 7828 7686548
001.000-001.500 9094 8857572
001.500-002.000 9774 9650058
002.000-002.500 6218 6062802
002.500-003.000 15552 15328528
003.000-003.500 4803 4643892
003.500-004.000 6354 6203928
004.000-004.500 10224 10086896
004.500-005.000 5312 5169636
005.000-005.500 13555 13354682
005.500-006.000 6451 6369138
006.000-006.500 7528 7393106

Using filters

The filter style used here is the 'display filter' syntax of ethereal explained here
Now I want to just see traffic from one of my iSCSI clients. I can filter iSCSI traffic from IP address N.B. Use quotes to achieve boolean logic, not parentheses '( )'
tethereal -tad -r e0b_20080519_153919.trc -R 'ip.src== && iscsi'

Now I want to filer further because I have several iSCSI sessions on that client. I know that the session I am interested in is using port 4704 as its source port. Now I can filter iSCSI traffic to/from AND the port is 4704 AND traffic is iSCSI - useful for watching one iSCSI session.

tethereal -tad -r e0b_20080519_153919.trc -R 'ip.addr== && iscsi &&; tcp.port==4704' 

Here is that filter in action. We see that we only see writes to a specific LUN which is what we expect in this example since I know that each session on the client only writes to one iSCSI LUN.

-bash-3.00$ sudo tethereal -tad -r e0b_20080519_153919.trc -R 'ip.addr== && iscsi && tcp.port==4704'
16620 2008-05-19 15:39:19.894110 -> iSCSI SCSI: Read(10) LUN: 0x0a (LBA: 0x00000001, Len: 1)
17072 2008-05-19 15:39:19.935890 -> iSCSI SCSI: Data In LUN: 0x0a (Read(10) Response Data) SCSI: Response LUN: 0x0a (Read(10)) (Good)
17172 2008-05-19 15:39:19.943567 -> iSCSI SCSI: Write(10) LUN: 0x0a (LBA: 0x0146c3a0, Len: 96)SCSI: Data Out LUN: 0x0a (Write(10) Request Data)
39667 2008-05-19 15:39:20.957360 -> iSCSI SCSI: Write(10) LUN: 0x0a (LBA: 0x0146c400, Len: 96)SCSI: Data Out LUN: 0x0a (Write(10) Request Data)
39909 2008-05-19 15:39:21.019261 -> iSCSI SCSI: Response LUN: 0x0a (Write(10)) (Good)
40226 2008-05-19 15:39:21.036799 -> iSCSI SCSI: Write(10) LUN: 0x0a (LBA: 0x0146c460, Len: 96)SCSI: Data Out LUN: 0x0a (Write(10) Request Data)

No comments: