Module Name:    src
Committed By:   mlelstv
Date:           Sun Jun  5 04:36:05 UTC 2016

Modified Files:
        src/sys/dev/iscsi: iscsi_main.c iscsi_rcv.c iscsi_send.c iscsi_utils.c

Log Message:
More debugging output, changed debug levels for some.


To generate a diff of this commit:
cvs rdiff -u -r1.18 -r1.19 src/sys/dev/iscsi/iscsi_main.c
cvs rdiff -u -r1.12 -r1.13 src/sys/dev/iscsi/iscsi_rcv.c
cvs rdiff -u -r1.20 -r1.21 src/sys/dev/iscsi/iscsi_send.c
cvs rdiff -u -r1.11 -r1.12 src/sys/dev/iscsi/iscsi_utils.c

Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.

Modified files:

Index: src/sys/dev/iscsi/iscsi_main.c
diff -u src/sys/dev/iscsi/iscsi_main.c:1.18 src/sys/dev/iscsi/iscsi_main.c:1.19
--- src/sys/dev/iscsi/iscsi_main.c:1.18	Sun May 29 13:51:16 2016
+++ src/sys/dev/iscsi/iscsi_main.c	Sun Jun  5 04:36:05 2016
@@ -455,7 +455,7 @@ iscsi_scsipi_request(struct scsipi_chann
 		}
 
 		send_run_xfer(session, xs);
-		DEB(9, ("scsipi_req returns\n"));
+		DEB(15, ("scsipi_req returns\n"));
 		return;
 
 	case ADAPTER_REQ_GROW_RESOURCES:

Index: src/sys/dev/iscsi/iscsi_rcv.c
diff -u src/sys/dev/iscsi/iscsi_rcv.c:1.12 src/sys/dev/iscsi/iscsi_rcv.c:1.13
--- src/sys/dev/iscsi/iscsi_rcv.c:1.12	Wed Jun  1 05:13:07 2016
+++ src/sys/dev/iscsi/iscsi_rcv.c	Sun Jun  5 04:36:05 2016
@@ -1,4 +1,4 @@
-/*	$NetBSD: iscsi_rcv.c,v 1.12 2016/06/01 05:13:07 mlelstv Exp $	*/
+/*	$NetBSD: iscsi_rcv.c,v 1.13 2016/06/05 04:36:05 mlelstv Exp $	*/
 
 /*-
  * Copyright (c) 2004,2005,2006,2011 The NetBSD Foundation, Inc.
@@ -64,10 +64,10 @@ my_soo_read(connection_t *conn, struct u
 	KERNEL_UNLOCK_ONE(curlwp);
 
 	if (ret || (flags != MSG_DONTWAIT && u->uio_resid)) {
-		DEBC(conn, 1, ("Read failed (ret: %d, req: %zu, out: %zu)\n", ret, resid,
-				u->uio_resid));
+		DEBC(conn, 1, ("Read failed (ret: %d, req: %zu, out: %zu)\n",
+		               ret, resid, u->uio_resid));
 		handle_connection_error(conn, ISCSI_STATUS_SOCKET_ERROR,
-								RECOVER_CONNECTION);
+		                        RECOVER_CONNECTION);
 		return 1;
 	}
 	return 0;
@@ -131,6 +131,9 @@ ccb_from_itt(connection_t *conn, uint32_
 	}
 	ccb = &conn->session->ccb[cidx];
 	if (ccb->ITT != itt || ccb->disp <= CCBDISP_BUSY) {
+		DEBC(conn, 0,
+		     ("ccb_from_itt: received invalid CCB itt %08x != %08x\n",
+		      itt, ccb->ITT));
 		return NULL;
 	}
 	return ccb;
@@ -161,7 +164,7 @@ read_pdu_data(pdu_t *pdu, uint8_t *data,
 	int i, pad;
 	connection_t *conn = pdu->connection;
 
-	DEB(1, ("read_pdu_data: data segment length = %d\n",
+	DEB(15, ("read_pdu_data: data segment length = %d\n",
 		ntoh3(pdu->pdu.DataSegmentLength)));
 	if (!(len = ntoh3(pdu->pdu.DataSegmentLength))) {
 		return 0;
@@ -373,7 +376,7 @@ check_CmdSN(connection_t *conn, uint32_t
 		if (ccb->pdu_waiting != NULL && ccb->CmdSN > sn &&
 			!(ccb->flags & CCBF_GOT_RSP)) {
 			DEBC(conn, 1, ("CheckCmdSN resending - CmdSN=%d, ExpCmdSn=%d\n",
-						   ccb->CmdSN, sn));
+			               ccb->CmdSN, sn));
 
 			ccb->total_tries++;
 
@@ -944,7 +947,7 @@ STATIC int
 receive_nop_in_pdu(connection_t *conn, pdu_t *pdu, ccb_t *req_ccb)
 {
 	DEBC(conn, 10,
-		("Received NOP-In PDU, req_ccb=%p, ITT=%x, TTT=%x, StatSN=%x\n",
+		("Received NOP_In PDU, req_ccb=%p, ITT=%x, TTT=%x, StatSN=%x\n",
 		req_ccb, pdu->pdu.InitiatorTaskTag,
 		pdu->pdu.p.nop_in.TargetTransferTag,
 		ntohl(pdu->pdu.p.nop_in.StatSN)));
@@ -971,6 +974,9 @@ receive_nop_in_pdu(connection_t *conn, p
 		wake_ccb(req_ccb, ISCSI_STATUS_SUCCESS);
 
 		check_StatSN(conn, pdu->pdu.p.nop_in.StatSN, TRUE);
+	} else {
+		DEBC(conn, 0, ("Received unsolicted NOP_In, itt=%08x\n",
+		               pdu->pdu.InitiatorTaskTag));
 	}
 
 	return 0;
@@ -1009,6 +1015,9 @@ receive_pdu(connection_t *conn, pdu_t *p
 		}
 	}
 
+	DEBC(conn, 99, ("Received PDU ExpCmdSN = %u\n",
+	     ntohl(pdu->pdu.p.response.ExpCmdSN)));
+
 	req_ccb = ccb_from_itt(conn, pdu->pdu.InitiatorTaskTag);
 
 	if (req_ccb != NULL && req_ccb->data_in && req_ccb->data_len &&
@@ -1112,7 +1121,7 @@ receive_pdu(connection_t *conn, pdu_t *p
 			return 0;
 		}
 
-		DEBC(conn, 1, ("Unthrottling - MaxCmdSN = %d\n", MaxCmdSN));
+		DEBC(conn, 5, ("Unthrottling - MaxCmdSN = %d\n", MaxCmdSN));
 
 		TAILQ_INIT(&waiting);
 		while ((req_ccb = TAILQ_FIRST(&sess->ccbs_throttled)) != NULL) {
@@ -1124,7 +1133,7 @@ receive_pdu(connection_t *conn, pdu_t *p
 		while ((req_ccb = TAILQ_FIRST(&waiting)) != NULL) {
 			TAILQ_REMOVE(&waiting, req_ccb, chain);
 
-			DEBC(conn, 1, ("Unthrottling - ccb = %p, disp = %d\n",
+			DEBC(conn, 10, ("Unthrottling - ccb = %p, disp = %d\n",
 					req_ccb, req_ccb->disp));
 
 			if (req_ccb->flags & CCBF_WAITING) {

Index: src/sys/dev/iscsi/iscsi_send.c
diff -u src/sys/dev/iscsi/iscsi_send.c:1.20 src/sys/dev/iscsi/iscsi_send.c:1.21
--- src/sys/dev/iscsi/iscsi_send.c:1.20	Fri Jun  3 06:53:40 2016
+++ src/sys/dev/iscsi/iscsi_send.c	Sun Jun  5 04:36:05 2016
@@ -1,4 +1,4 @@
-/*	$NetBSD: iscsi_send.c,v 1.20 2016/06/03 06:53:40 mlelstv Exp $	*/
+/*	$NetBSD: iscsi_send.c,v 1.21 2016/06/05 04:36:05 mlelstv Exp $	*/
 
 /*-
  * Copyright (c) 2004,2005,2006,2011 The NetBSD Foundation, Inc.
@@ -314,7 +314,8 @@ iscsi_send_thread(void *par)
 
 				if (conn->HeaderDigest)
 					pdu->pdu.HeaderDigest = gen_digest(&pdu->pdu, BHS_SIZE);
-				DEBC(conn, 99, ("Send thread transmitting data\n"));
+				DEBC(conn, 99, ("Transmitting PDU CmdSN = %u\n",
+				                ntohl(pdu->pdu.p.command.CmdSN)));
 				my_soo_write(conn, &pdu->uio);
 
 				if (pdu->disp <= PDUDISP_FREE) {
@@ -1358,13 +1359,13 @@ send_command(ccb_t *ccb, ccb_disp_t disp
 		throttle_ccb(ccb, TRUE);
 
 		if (!waitok) {
-			DEBOUT(("Throttling send_command, ccb = %p\n",ccb));
+			DEBC(conn, 10, ("Throttling send_command, ccb = %p\n",ccb));
 			return;
 		}
 
+		DEBC(conn, 15, ("Wait send_command, ccb = %p\n",ccb));
 		cv_wait(&sess->ccb_cv, &sess->lock);
-
-		DEBOUT(("Resuming send_command, ccb = %p\n",ccb));
+		DEBC(conn, 15, ("Resuming send_command, ccb = %p\n",ccb));
 
 		throttle_ccb(ccb, FALSE);
 		ccb->flags &= ~CCBF_WAITING;
@@ -1423,8 +1424,8 @@ send_command(ccb_t *ccb, ccb_disp_t disp
 
 	pdu->p.command.CmdSN = htonl(ccb->CmdSN);
 
-	DEBC(conn, 10, ("Send Command: CmdSN %d, data_in %d, len %d, totlen %d\n",
-			ccb->CmdSN, ccb->data_in, len, totlen));
+	DEBC(conn, 10, ("Send Command: CmdSN %d (%d), data_in %d, len %d, totlen %d\n",
+			ccb->CmdSN, sess->MaxCmdSN, ccb->data_in, len, totlen));
 
 	setup_tx_uio(ppdu, len, ccb->data_ptr, ccb->data_in);
 	send_pdu(ccb, ppdu, (totlen) ? CCBDISP_DEFER : disp, PDUDISP_WAIT);

Index: src/sys/dev/iscsi/iscsi_utils.c
diff -u src/sys/dev/iscsi/iscsi_utils.c:1.11 src/sys/dev/iscsi/iscsi_utils.c:1.12
--- src/sys/dev/iscsi/iscsi_utils.c:1.11	Wed Jun  1 05:13:07 2016
+++ src/sys/dev/iscsi/iscsi_utils.c	Sun Jun  5 04:36:05 2016
@@ -1,4 +1,4 @@
-/*	$NetBSD: iscsi_utils.c,v 1.11 2016/06/01 05:13:07 mlelstv Exp $	*/
+/*	$NetBSD: iscsi_utils.c,v 1.12 2016/06/05 04:36:05 mlelstv Exp $	*/
 
 /*-
  * Copyright (c) 2004,2005,2006,2008 The NetBSD Foundation, Inc.
@@ -248,7 +248,7 @@ get_ccb(connection_t *conn, bool waitok)
 	ccb->connection = conn;
 	atomic_inc_uint(&conn->usecount);
 
-	DEBC(conn, 5, (
+	DEBC(conn, 15, (
 		"get_ccb: ccb = %p, usecount = %d\n",
 		ccb, conn->usecount));
 
@@ -268,7 +268,7 @@ free_ccb(ccb_t *ccb)
 	session_t *sess = ccb->session;
 	pdu_t *pdu;
 
-	DEBC(ccb->connection, 5, (
+	DEBC(ccb->connection, 15, (
 		"free_ccb: ccb = %p, usecount = %d\n",
 		ccb, ccb->connection->usecount-1));
 
@@ -622,7 +622,7 @@ add_sernum(sernum_buffer_t *buff, uint32
 	}
 
 	buff->top = t;
-	DEB(10, ("AddSernum bottom %d [%d], top %d, num %u, diff %d\n",
+	DEB(11, ("AddSernum bottom %d [%d], top %d, num %u, diff %d\n",
 			 b, buff->sernum[b], buff->top, num, diff));
 
 	return diff;
@@ -673,7 +673,7 @@ ack_sernum(sernum_buffer_t *buff, uint32
 	if (!sn_a_lt_b(num, buff->ExpSN))
 		buff->ExpSN = num + 1;
 
-	DEB(10, ("AckSernum bottom %d, top %d, num %d ExpSN %d\n",
+	DEB(11, ("AckSernum bottom %d, top %d, num %d ExpSN %d\n",
 			 buff->bottom, buff->top, num, buff->ExpSN));
 
 	return buff->ExpSN;

Reply via email to