RE: determining window size

2011-04-29 Thread Shyam_Iyer


 -Original Message-
 From: open-iscsi@googlegroups.com [mailto:open-iscsi@googlegroups.com]
 On Behalf Of Joe Hoot
 Sent: Thursday, April 28, 2011 8:08 PM
 To: open-iscsi@googlegroups.com
 Subject: Re: determining window size
 
 Thanks for the quick response (as always) Mike.
 
 Ok.  I see where you're going.  I should be able to build a kernel, but
 I have already veered a little bit away from where Oracle already is
 with their OVM kernel.  I don't want to veer to far (even with printk
 statements)-- but maybe... let me think about possibly doing something
 with just tcpdump to see if I can see tcp windows scaling real low.
 
 We have a concern at ITEC that the EqualLogic is setting TCP windows
 towards zero.  And when it does that we are concerned that if it does
 this too much, even noop pings aren't getting through.

What is the NIC at the initiator..? Is it an offload session ?

I have seen a TCP zero window issue recently.

 
 So... let think about this and see if I can respond again to you
 tomorrow morning.
 
 Thanks again for jumping on this.
 
 Joe
 
 
 On Apr 28, 2011, at 6:29 PM, Mike Christie wrote:
 
  On 04/28/2011 02:42 PM, Joe Hoot wrote:
  Mike or others,
 
  I would like to enable a small (yes, feel free to snicker here...)
 bit of debugging on one of our systems to try to capture tcp window
 sizes (so that I can attempt to trend some behaviors).  Mike, recall
 awhile ago you had mentioned that the following will help us gather
 more information:
 
 
  How are you setting the window sizes?
 
echo 1  /sys/module/libiscsi2/parameters/debug_libiscsi
echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
echo 1  /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp
 
  I believe that the only one that I really need to turn on to get
 more information about size of data being sent would be this one:
 
echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 
  as it gives me something like this when I run this command:
  [root@oim61024006 ~]# echo 1
 /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp; sleep 1; dd
 if=/dev/zero
 of=/var/ovs/mount/DCA44DBDD7944327A7945E96BF8F7CCC/joetest.dd.img bs=1K
 count=1; echo 0
 /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
  1+0 records in
  1+0 records out
  1024 bytes (1.0 kB) copied, 3.7e-05 seconds, 27.7 MB/s
  [root@oim61024006 ~]#
 
  That produced this in /var/log/messages:
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_task_init task deq [itt 0x1c6 imm 0 unsol 0]
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 0 size 48 xmit
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 48 size 48 xmit
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done total copied 48 total size 48
 
  Need libiscsi debugging on, but this looks like it might have been a
  iscsi pdus related to scsi READ commands. On the next line we see
 some
  data coming in from the target in response to some command.
 
 
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb in 560 bytes
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb skb deace200 ptr=dd84c800 avail=560
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 0 size 48 recv
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_recv copying 48
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 48 size 48 recv
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done total copied 48 total size 48
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb segment done
 
  ---  and I'm thinking that this is actually where my dd starts
 going:
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_hdr_dissect opcode 0x25 ahslen 0 datalen 512
 
  opcode 25 is a iSCSI SCSI DATA_IN. Basically the target sends data to
  the initiator in this type of pdu in response to a read command.
 Below
  we see more data getting read in.
 
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_hdr_dissect iscsi_tcp_begin_data_in( offset=0, datalen=512)
 
  so here datalen means that the DATA_IN pdu has 512 bytes of data that
 we
  are going to read in.
 
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb in 512 bytes
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb skb deace200 ptr=dd84c830 avail=512
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 0 size 512 recv
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_recv copying 512
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 512 size 512 recv
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done total copied 512 total size 512
  Apr 28 15:26:07

Re: determining window size

2011-04-29 Thread Joe Hoot
We have a few environments that we're testing this with right now.  We are 
mostly using bnx2  (the nics are capable of offloading, but we aren't using 
that portion).  Since you can't disable the nic from doing offloading from the 
BIOS, we do ti when the system comes only with the following:

for ETH in eth0 eth1 eth2 eth3; do
   ethtool -K $ETH tx off
   ethtool -K $ETH rx off
   ethtool -K $ETH sg off
   ethtool -K $ETH tso off
   ethtool -K $ETH gso off
done

For some reason, bnx2i is still getting loaded in the OS as a module, but (I 
believe, because I tested this awhile ago) even if I rmmod bnx2i, it will 
automatically get loaded again once iscsid starts back up.


On Apr 29, 2011, at 10:46 AM, shyam_i...@dell.com shyam_i...@dell.com wrote:

 
 
 -Original Message-
 From: open-iscsi@googlegroups.com [mailto:open-iscsi@googlegroups.com]
 On Behalf Of Joe Hoot
 Sent: Thursday, April 28, 2011 8:08 PM
 To: open-iscsi@googlegroups.com
 Subject: Re: determining window size
 
 Thanks for the quick response (as always) Mike.
 
 Ok.  I see where you're going.  I should be able to build a kernel, but
 I have already veered a little bit away from where Oracle already is
 with their OVM kernel.  I don't want to veer to far (even with printk
 statements)-- but maybe... let me think about possibly doing something
 with just tcpdump to see if I can see tcp windows scaling real low.
 
 We have a concern at ITEC that the EqualLogic is setting TCP windows
 towards zero.  And when it does that we are concerned that if it does
 this too much, even noop pings aren't getting through.
 
 What is the NIC at the initiator..? Is it an offload session ?
 
 I have seen a TCP zero window issue recently.
 
 
 So... let think about this and see if I can respond again to you
 tomorrow morning.
 
 Thanks again for jumping on this.
 
 Joe
 
 
 On Apr 28, 2011, at 6:29 PM, Mike Christie wrote:
 
 On 04/28/2011 02:42 PM, Joe Hoot wrote:
 Mike or others,
 
 I would like to enable a small (yes, feel free to snicker here...)
 bit of debugging on one of our systems to try to capture tcp window
 sizes (so that I can attempt to trend some behaviors).  Mike, recall
 awhile ago you had mentioned that the following will help us gather
 more information:
 
 
 How are you setting the window sizes?
 
  echo 1  /sys/module/libiscsi2/parameters/debug_libiscsi
  echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
  echo 1  /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp
 
 I believe that the only one that I really need to turn on to get
 more information about size of data being sent would be this one:
 
  echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 
 as it gives me something like this when I run this command:
 [root@oim61024006 ~]# echo 1
 /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp; sleep 1; dd
 if=/dev/zero
 of=/var/ovs/mount/DCA44DBDD7944327A7945E96BF8F7CCC/joetest.dd.img bs=1K
 count=1; echo 0
 /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 1+0 records in
 1+0 records out
 1024 bytes (1.0 kB) copied, 3.7e-05 seconds, 27.7 MB/s
 [root@oim61024006 ~]#
 
 That produced this in /var/log/messages:
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_task_init task deq [itt 0x1c6 imm 0 unsol 0]
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 0 size 48 xmit
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 48 size 48 xmit
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done total copied 48 total size 48
 
 Need libiscsi debugging on, but this looks like it might have been a
 iscsi pdus related to scsi READ commands. On the next line we see
 some
 data coming in from the target in response to some command.
 
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb in 560 bytes
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb skb deace200 ptr=dd84c800 avail=560
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 0 size 48 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_recv copying 48
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done copied 0 48 size 48 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_segment_done total copied 48 total size 48
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_recv_skb segment done
 
 ---  and I'm thinking that this is actually where my dd starts
 going:
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_hdr_dissect opcode 0x25 ahslen 0 datalen 512
 
 opcode 25 is a iSCSI SCSI DATA_IN. Basically the target sends data to
 the initiator in this type of pdu in response to a read command.
 Below
 we see more data getting read in.
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
 iscsi_tcp_hdr_dissect iscsi_tcp_begin_data_in( offset=0, datalen=512)
 
 so here

Re: determining window size

2011-04-29 Thread Mike Christie

On 04/29/2011 10:47 AM, Joe Hoot wrote:


For some reason, bnx2i is still getting loaded in the OS as a module, but (I 
believe, because I tested this awhile ago) even if I rmmod bnx2i, it will 
automatically get loaded again once iscsid starts back up.



The iscsi init scripts are lazy and instead of loading modules when they 
are used, they just load all of them. The bnx2i module would only be 
used if you set it up to be used by passing a iface with bnx2i as the 
transport into a iscsiadm discovery or node command.


--
You received this message because you are subscribed to the Google Groups 
open-iscsi group.
To post to this group, send email to open-iscsi@googlegroups.com.
To unsubscribe from this group, send email to 
open-iscsi+unsubscr...@googlegroups.com.
For more options, visit this group at 
http://groups.google.com/group/open-iscsi?hl=en.



RE: determining window size

2011-04-29 Thread Shyam_Iyer


 -Original Message-
 From: open-iscsi@googlegroups.com [mailto:open-iscsi@googlegroups.com]
 On Behalf Of Joe Hoot
 Sent: Friday, April 29, 2011 11:47 AM
 To: open-iscsi@googlegroups.com
 Subject: Re: determining window size
 
 We have a few environments that we're testing this with right now.  We
 are mostly using bnx2  (the nics are capable of offloading, but we
 aren't using that portion).  Since you can't disable the nic from doing
 offloading from the BIOS, we do ti when the system comes only with the
 following:
 
Not really.. You are not using the offload stack when you configure your iscsi 
sessions to use TCP in the OS. Once the BIOS passes control to the OS, the OS 
can create sessions through either stack. In fact even if you enabled 
BIOS(offload mode) you can't really offload iSCSI unless there is a LICENSE key 
plugged into the motherboard.

I presume that is the case unless you created session using the iface created 
by bnx2i..


 for ETH in eth0 eth1 eth2 eth3; do
ethtool -K $ETH tx off
ethtool -K $ETH rx off
ethtool -K $ETH sg off
ethtool -K $ETH tso off
ethtool -K $ETH gso off
 done

This is not necessary to offload infact you may have a performance hit since 
you do this..

 
 For some reason, bnx2i is still getting loaded in the OS as a module,
 but (I believe, because I tested this awhile ago) even if I rmmod
 bnx2i, it will automatically get loaded again once iscsid starts back
 up.

Even this is not necessary.. Since even if it is loaded it is not getting used..


I guess.. the trace will exactly point to the tcp window sizes here...

Look for resets either by initiator or target a zero window could be pretty 
near to a reset..

Sometimes if  either initiator or target advertizes a zero window it results in 
TCP resets and therefore an error messages in the kernel. So watch for those 
kernel messages as well to profile where you need to search in the trace.

 
 
 On Apr 29, 2011, at 10:46 AM, shyam_i...@dell.com
 shyam_i...@dell.com wrote:
 
 
 
  -Original Message-
  From: open-iscsi@googlegroups.com [mailto:open-
 is...@googlegroups.com]
  On Behalf Of Joe Hoot
  Sent: Thursday, April 28, 2011 8:08 PM
  To: open-iscsi@googlegroups.com
  Subject: Re: determining window size
 
  Thanks for the quick response (as always) Mike.
 
  Ok.  I see where you're going.  I should be able to build a kernel,
 but
  I have already veered a little bit away from where Oracle already is
  with their OVM kernel.  I don't want to veer to far (even with
 printk
  statements)-- but maybe... let me think about possibly doing
 something
  with just tcpdump to see if I can see tcp windows scaling real low.
 
  We have a concern at ITEC that the EqualLogic is setting TCP windows
  towards zero.  And when it does that we are concerned that if it
 does
  this too much, even noop pings aren't getting through.
 
  What is the NIC at the initiator..? Is it an offload session ?
 
  I have seen a TCP zero window issue recently.
 
 
  So... let think about this and see if I can respond again to you
  tomorrow morning.
 
  Thanks again for jumping on this.
 
  Joe
 
 
  On Apr 28, 2011, at 6:29 PM, Mike Christie wrote:
 
  On 04/28/2011 02:42 PM, Joe Hoot wrote:
  Mike or others,
 
  I would like to enable a small (yes, feel free to snicker here...)
  bit of debugging on one of our systems to try to capture tcp window
  sizes (so that I can attempt to trend some behaviors).  Mike, recall
  awhile ago you had mentioned that the following will help us gather
  more information:
 
 
  How are you setting the window sizes?
 
   echo 1  /sys/module/libiscsi2/parameters/debug_libiscsi
   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
   echo 1  /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp
 
  I believe that the only one that I really need to turn on to get
  more information about size of data being sent would be this one:
 
   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 
  as it gives me something like this when I run this command:
  [root@oim61024006 ~]# echo 1
  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp; sleep 1; dd
  if=/dev/zero
  of=/var/ovs/mount/DCA44DBDD7944327A7945E96BF8F7CCC/joetest.dd.img
 bs=1K
  count=1; echo 0
  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
  1+0 records in
  1+0 records out
  1024 bytes (1.0 kB) copied, 3.7e-05 seconds, 27.7 MB/s
  [root@oim61024006 ~]#
 
  That produced this in /var/log/messages:
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
  iscsi_tcp_task_init task deq [itt 0x1c6 imm 0 unsol 0]
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
  iscsi_tcp_segment_done copied 0 0 size 48 xmit
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
  iscsi_tcp_segment_done copied 0 48 size 48 xmit
  Apr 28 15:26:07 oim61024006 kernel:  connection22:0:
  iscsi_tcp_segment_done total copied 48 total size 48
 
  Need libiscsi debugging on, but this looks like it might have been

Re: determining window size

2011-04-28 Thread Mike Christie

On 04/28/2011 02:42 PM, Joe Hoot wrote:

Mike or others,

I would like to enable a small (yes, feel free to snicker here...) bit of 
debugging on one of our systems to try to capture tcp window sizes (so that I 
can attempt to trend some behaviors).  Mike, recall awhile ago you had 
mentioned that the following will help us gather more information:



How are you setting the window sizes?


   echo 1  /sys/module/libiscsi2/parameters/debug_libiscsi
   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
   echo 1  /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp

I believe that the only one that I really need to turn on to get more 
information about size of data being sent would be this one:

   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp

as it gives me something like this when I run this command:
[root@oim61024006 ~]# echo 1  
/sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp; sleep 1; dd if=/dev/zero 
of=/var/ovs/mount/DCA44DBDD7944327A7945E96BF8F7CCC/joetest.dd.img bs=1K count=1; echo 
0  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
1+0 records in
1+0 records out
1024 bytes (1.0 kB) copied, 3.7e-05 seconds, 27.7 MB/s
[root@oim61024006 ~]#

That produced this in /var/log/messages:
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_task_init task 
deq [itt 0x1c6 imm 0 unsol 0]
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 0 size 48 xmit
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 48 size 48 xmit
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
total copied 48 total size 48


Need libiscsi debugging on, but this looks like it might have been a 
iscsi pdus related to scsi READ commands. On the next line we see some 
data coming in from the target in response to some command.




Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 560 
bytes
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb skb 
deace200 ptr=dd84c800 avail=560
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 0 size 48 recv
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_recv 
copying 48
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 48 size 48 recv
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
total copied 48 total size 48
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb segment 
done

---  and I'm thinking that this is actually where my dd starts going:
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_dissect 
opcode 0x25 ahslen 0 datalen 512


opcode 25 is a iSCSI SCSI DATA_IN. Basically the target sends data to 
the initiator in this type of pdu in response to a read command. Below 
we see more data getting read in.



Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_dissect 
iscsi_tcp_begin_data_in( offset=0, datalen=512)


so here datalen means that the DATA_IN pdu has 512 bytes of data that we 
are going to read in.



Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 512 
bytes
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb skb 
deace200 ptr=dd84c830 avail=512
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 0 size 512 recv
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_recv 
copying 512
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 512 size 512 recv
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
total copied 512 total size 512
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb segment 
done


So the above blob just means we got the 512 bytes read in successfully.


Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_recv_prep 
(digest disabled)
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 0 
bytes
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb no more 
data avail. Consumed 0
--  and this is where it had finished?

Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
copied 0 0 size 0 xmit
Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
total copied 0 total size 0

I'm assuming that these size 48 recv might be some keepalive thing (nop 
pings, dm-multipath readsector 0, etc..)?



Is a iscsi header. In a iscsi packet there is basically a header that 
tells us what type of command it is (ping, scsi command, ready to 
transfer, login, etc), how much data is going to be transferred in the 
data segment after the header, etc.


For the xmit path you need libiscsi debugging on as well as libiscsi_tcp 
to determine what type of iscsi header it is.


See above for info the packets.


3) iscsi_tcp_recv_skb in 512 bytes

skb 

Re: determining window size

2011-04-28 Thread Joe Hoot
Thanks for the quick response (as always) Mike.

Ok.  I see where you're going.  I should be able to build a kernel, but I have 
already veered a little bit away from where Oracle already is with their OVM 
kernel.  I don't want to veer to far (even with printk statements)-- but 
maybe... let me think about possibly doing something with just tcpdump to see 
if I can see tcp windows scaling real low.

We have a concern at ITEC that the EqualLogic is setting TCP windows towards 
zero.  And when it does that we are concerned that if it does this too much, 
even noop pings aren't getting through.

So... let think about this and see if I can respond again to you tomorrow 
morning.

Thanks again for jumping on this.

Joe


On Apr 28, 2011, at 6:29 PM, Mike Christie wrote:

 On 04/28/2011 02:42 PM, Joe Hoot wrote:
 Mike or others,
 
 I would like to enable a small (yes, feel free to snicker here...) bit of 
 debugging on one of our systems to try to capture tcp window sizes (so that 
 I can attempt to trend some behaviors).  Mike, recall awhile ago you had 
 mentioned that the following will help us gather more information:
 
 
 How are you setting the window sizes?
 
   echo 1  /sys/module/libiscsi2/parameters/debug_libiscsi
   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
   echo 1  /sys/module/iscsi_tcp/parameters/debug_iscsi_tcp
 
 I believe that the only one that I really need to turn on to get more 
 information about size of data being sent would be this one:
 
   echo 1  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 
 as it gives me something like this when I run this command:
 [root@oim61024006 ~]# echo 1  
 /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp; sleep 1; dd 
 if=/dev/zero 
 of=/var/ovs/mount/DCA44DBDD7944327A7945E96BF8F7CCC/joetest.dd.img bs=1K 
 count=1; echo 0  /sys/module/libiscsi_tcp/parameters/debug_libiscsi_tcp
 1+0 records in
 1+0 records out
 1024 bytes (1.0 kB) copied, 3.7e-05 seconds, 27.7 MB/s
 [root@oim61024006 ~]#
 
 That produced this in /var/log/messages:
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_task_init 
 task deq [itt 0x1c6 imm 0 unsol 0]
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 0 size 48 xmit
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 48 size 48 xmit
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 total copied 48 total size 48
 
 Need libiscsi debugging on, but this looks like it might have been a
 iscsi pdus related to scsi READ commands. On the next line we see some
 data coming in from the target in response to some command.
 
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 
 560 bytes
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb skb 
 deace200 ptr=dd84c800 avail=560
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 0 size 48 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_recv 
 copying 48
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 48 size 48 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 total copied 48 total size 48
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb 
 segment done
 
 ---  and I'm thinking that this is actually where my dd starts going:
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_dissect 
 opcode 0x25 ahslen 0 datalen 512
 
 opcode 25 is a iSCSI SCSI DATA_IN. Basically the target sends data to
 the initiator in this type of pdu in response to a read command. Below
 we see more data getting read in.
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_dissect 
 iscsi_tcp_begin_data_in( offset=0, datalen=512)
 
 so here datalen means that the DATA_IN pdu has 512 bytes of data that we
 are going to read in.
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 
 512 bytes
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb skb 
 deace200 ptr=dd84c830 avail=512
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 0 size 512 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_recv 
 copying 512
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 copied 0 512 size 512 recv
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_segment_done 
 total copied 512 total size 512
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb 
 segment done
 
 So the above blob just means we got the 512 bytes read in successfully.
 
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_hdr_recv_prep 
 (digest disabled)
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: iscsi_tcp_recv_skb in 0 
 bytes
 Apr 28 15:26:07 oim61024006 kernel:  connection22:0: