On 04/14/2011 06:39 AM, Joe Hoot wrote:
Here's what I am seeing (roughly... with lines scraped in between.. and I'm 
only grepping for connect7/session7):

Apr 11 13:22:24 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
...lots of the above types of messages...
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: 
iscsi_check_transport_timeouts Setting next tmo 2279563
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
...lots of the above types of messages...
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: 
iscsi_check_transport_timeouts Setting next tmo 2279563
Apr 11 13:22:24 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
...lots of the above types of messages...
Apr 11 13:22:25 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
Apr 11 13:22:25 oim61024009 kernel:  connection7:0: 
iscsi_check_transport_timeouts Sending nopout as ping
Apr 11 13:22:25 oim61024009 kernel:  connection7:0: 
iscsi_check_transport_timeouts Setting next tmo 2280813
Apr 11 13:22:25 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit
...lots of the above types of messages...
Apr 11 13:22:30 oim61024009 kernel:  connection7:0: iscsi_tcp_segment_done 
copied 2592 0 size 4096 xmit

Does it always say "xmit" in the iscsi_tcp_segment_done messages from 13:22:20 - 13:22:30 or does it sometimes say "recv"? Just send the full logs actually.

And are you running with that kernel fix (I think oracle merged if for you right). This fix:
http://git.kernel.org/?p=linux/kernel/git/jejb/scsi-misc-2.6.git;a=commitdiff;h=4c48a82935f833d94fcf44c2b0c5d2922acfc77a;hp=d1acfae514425d680912907c6554852f1e258551


If there is no "recv"s in there then you need the attached patch. No idea if this applies to the oracle kernel you are using.

The weird thing though would be that it means for 10 seconds we just send data and never get a response to any of the pdus we have sent.

What is the output of iscsiadm -m session -P 2 when you are logged into the target?

Apr 11 13:22:30 oim61024009 kernel:  connection7:0: ping timeout of 5 secs 
expired, recv timeout 5, last rx 2278313, last ping 2279563, now 2280813

--
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.

diff --git a/drivers/scsi/iscsi_tcp.c b/drivers/scsi/iscsi_tcp.c
index a860452..c188267 100644
--- a/drivers/scsi/iscsi_tcp.c
+++ b/drivers/scsi/iscsi_tcp.c
@@ -274,7 +274,8 @@ static int iscsi_sw_tcp_xmit_segment(struct iscsi_tcp_conn 
*tcp_conn,
                if (r < 0) {
                        iscsi_tcp_segment_unmap(segment);
                        return r;
-               }
+               } else if (r > 0)
+                       tcp_conn->iscsi_conn->last_xfer = jiffies;
                copied += r;
        }
        return copied;
diff --git a/drivers/scsi/libiscsi.c b/drivers/scsi/libiscsi.c
index 0c550d5..5d981f2 100644
--- a/drivers/scsi/libiscsi.c
+++ b/drivers/scsi/libiscsi.c
@@ -610,7 +610,7 @@ void iscsi_complete_scsi_task(struct iscsi_task *task,
 
        ISCSI_DBG_SESSION(conn->session, "[itt 0x%x]\n", task->itt);
 
-       conn->last_recv = jiffies;
+       conn->last_xfer = jiffies;
        __iscsi_update_cmdsn(conn->session, exp_cmdsn, max_cmdsn);
        iscsi_complete_task(task, ISCSI_TASK_COMPLETED);
 }
@@ -1130,7 +1130,7 @@ int __iscsi_complete_pdu(struct iscsi_conn *conn, struct 
iscsi_hdr *hdr,
        struct iscsi_task *task;
        uint32_t itt;
 
-       conn->last_recv = jiffies;
+       conn->last_xfer = jiffies;
        rc = iscsi_verify_itt(conn, hdr->itt);
        if (rc)
                return rc;
@@ -1902,7 +1902,7 @@ static void iscsi_start_tx(struct iscsi_conn *conn)
 static int iscsi_has_ping_timed_out(struct iscsi_conn *conn)
 {
        if (conn->ping_task &&
-           time_before_eq(conn->last_recv + (conn->recv_timeout * HZ) +
+           time_before_eq(conn->last_xfer+ (conn->recv_timeout * HZ) +
                           (conn->ping_timeout * HZ), jiffies))
                return 1;
        else
@@ -2047,7 +2047,7 @@ static void iscsi_check_transport_timeouts(unsigned long 
data)
 {
        struct iscsi_conn *conn = (struct iscsi_conn *)data;
        struct iscsi_session *session = conn->session;
-       unsigned long recv_timeout, next_timeout = 0, last_recv;
+       unsigned long recv_timeout, next_timeout = 0, last_xfer;
 
        spin_lock(&session->lock);
        if (session->state != ISCSI_STATE_LOGGED_IN)
@@ -2058,26 +2058,26 @@ static void iscsi_check_transport_timeouts(unsigned 
long data)
                goto done;
 
        recv_timeout *= HZ;
-       last_recv = conn->last_recv;
+       last_xfer = conn->last_xfer;
 
        if (iscsi_has_ping_timed_out(conn)) {
                iscsi_conn_printk(KERN_ERR, conn, "ping timeout of %d secs "
                                  "expired, recv timeout %d, last rx %lu, "
                                  "last ping %lu, now %lu\n",
                                  conn->ping_timeout, conn->recv_timeout,
-                                 last_recv, conn->last_ping, jiffies);
+                                 last_xfer, conn->last_ping, jiffies);
                spin_unlock(&session->lock);
                iscsi_conn_failure(conn, ISCSI_ERR_CONN_FAILED);
                return;
        }
 
-       if (time_before_eq(last_recv + recv_timeout, jiffies)) {
+       if (time_before_eq(last_xfer + recv_timeout, jiffies)) {
                /* send a ping to try to provoke some traffic */
                ISCSI_DBG_CONN(conn, "Sending nopout as ping\n");
                iscsi_send_nopout(conn, NULL);
                next_timeout = conn->last_ping + (conn->ping_timeout * HZ);
        } else
-               next_timeout = last_recv + recv_timeout;
+               next_timeout = last_xfer + recv_timeout;
 
        ISCSI_DBG_CONN(conn, "Setting next tmo %lu\n", next_timeout);
        mod_timer(&conn->transport_timer, next_timeout);
@@ -3001,7 +3001,7 @@ int iscsi_conn_start(struct iscsi_cls_conn *cls_conn)
        session->state = ISCSI_STATE_LOGGED_IN;
        session->queued_cmdsn = session->cmdsn;
 
-       conn->last_recv = jiffies;
+       conn->last_xfer = jiffies;
        conn->last_ping = jiffies;
        if (conn->recv_timeout && conn->ping_timeout)
                mod_timer(&conn->transport_timer,
diff --git a/drivers/scsi/libiscsi_tcp.c b/drivers/scsi/libiscsi_tcp.c
index e98ae33..f503fc9 100644
--- a/drivers/scsi/libiscsi_tcp.c
+++ b/drivers/scsi/libiscsi_tcp.c
@@ -882,7 +882,7 @@ int iscsi_tcp_recv_skb(struct iscsi_conn *conn, struct 
sk_buff *skb,
         * data_in's data could take a while to read in. We also want to
         * account for r2ts.
         */
-       conn->last_recv = jiffies;
+       conn->last_xfer = jiffies;
 
        if (unlikely(conn->suspend_rx)) {
                ISCSI_DBG_TCP(conn, "Rx suspended!\n");
diff --git a/include/scsi/libiscsi.h b/include/scsi/libiscsi.h
index 0f43677..a4df5ea 100644
--- a/include/scsi/libiscsi.h
+++ b/include/scsi/libiscsi.h
@@ -165,7 +165,7 @@ struct iscsi_conn {
         */
         int                    stop_stage;
        struct timer_list       transport_timer;
-       unsigned long           last_recv;
+       unsigned long           last_xfer;
        unsigned long           last_ping;
        int                     ping_timeout;
        int                     recv_timeout;

Reply via email to