- Fixes for previous commit

 - Minor logging improvements

git-svn-id: https://scst.svn.sourceforge.net/svnroot/scst/trunk@296 d57e44dd-8a1f-0410-8b47-8ef2f437770f

diff --git a/iscsi-scst/kernel/conn.c b/iscsi-scst/kernel/conn.c
index c05a4cf..f7230e5 100644 (file)
--- a/iscsi-scst/kernel/conn.c
+++ b/iscsi-scst/kernel/conn.c
@@ -329,6 +329,7 @@ int conn_free(struct iscsi_conn *conn)
        sBUG_ON(atomic_read(&conn->conn_ref_cnt) != 0);
        sBUG_ON(!list_empty(&conn->cmd_list));
        sBUG_ON(!list_empty(&conn->write_list));
+       sBUG_ON(!list_empty(&conn->written_list));
 
        list_del(&conn->conn_list_entry);
 

diff --git a/iscsi-scst/kernel/iscsi.c b/iscsi-scst/kernel/iscsi.c
index fe55175..e3a7eb9 100644 (file)
--- a/iscsi-scst/kernel/iscsi.c
+++ b/iscsi-scst/kernel/iscsi.c
@@ -113,7 +113,7 @@ static inline void iscsi_restart_waiting_cmnd(struct iscsi_cmnd *cmnd)
 
 static inline void iscsi_fail_waiting_cmnd(struct iscsi_cmnd *cmnd)
 {
-       TRACE_DBG("Failing data waiting cmd %p", cmnd);
+       TRACE_MGMT_DBG("Failing data waiting cmd %p", cmnd);
 
        /*
         * There is no race with conn_abort(), since all functions
@@ -182,7 +182,7 @@ void cmnd_free(struct iscsi_cmnd *cmnd)
        if (unlikely(cmnd->on_write_list || cmnd->on_written_list)) {
                struct iscsi_scsi_cmd_hdr *req = cmnd_hdr(cmnd);
 
-               PRINT_ERROR("cmnd %p still on some list?, %x, %x, %x, %x, %x, %x, %x",
+               PRINT_CRIT_ERROR("cmnd %p still on some list?, %x, %x, %x, %x, %x, %x, %x",
                        cmnd, req->opcode, req->scb[0], req->flags, req->itt,
                        be32_to_cpu(req->data_length),
                        req->cmd_sn, be32_to_cpu(cmnd->pdu.datasize));
@@ -190,7 +190,7 @@ void cmnd_free(struct iscsi_cmnd *cmnd)
                if (unlikely(cmnd->parent_req)) {
                        struct iscsi_scsi_cmd_hdr *req =
                                        cmnd_hdr(cmnd->parent_req);
-                       PRINT_ERROR("%p %x %u", req, req->opcode, req->scb[0]);
+                       PRINT_CRIT_ERROR("%p %x %u", req, req->opcode, req->scb[0]);
                }
                sBUG();
        }
@@ -254,7 +254,7 @@ void cmnd_done(struct iscsi_cmnd *cmnd)
                                scst_tgt_cmd_done(cmnd->scst_cmd);
                                break;
                        default:
-                               PRINT_ERROR("Unexpected cmnd scst state %d",
+                               PRINT_CRIT_ERROR("Unexpected cmnd scst state %d",
                                        cmnd->scst_state);
                                sBUG();
                                break;
@@ -290,6 +290,13 @@ void cmnd_done(struct iscsi_cmnd *cmnd)
                        "new value %d)", cmnd, sess,
                        atomic_read(&sess->active_cmds)-1);
                atomic_dec(&sess->active_cmds);
+#ifdef EXTRACHECKS
+               if (unlikely(atomic_read(&sess->active_cmds) < 0)) {
+                       PRINT_CRIT_ERROR("active_cmds < 0 (%d)!!",
+                               atomic_read(&sess->active_cmds));
+                       sBUG();
+               }
+#endif
        }
 
        cmnd_free(cmnd);
@@ -310,7 +317,7 @@ void req_cmnd_release_force(struct iscsi_cmnd *req, int flags)
 
        TRACE_ENTRY();
 
-       TRACE_DBG("%p", req);
+       TRACE_MGMT_DBG("%p", req);
 
        sBUG_ON(req == conn->read_cmnd);
 
@@ -328,6 +335,7 @@ void req_cmnd_release_force(struct iscsi_cmnd *req, int flags)
                spin_unlock_bh(&conn->write_list_lock);
 
                list_for_each_entry_safe(rsp, t, &cmds_list, write_list_entry) {
+                       TRACE_MGMT_DBG("Putting write rsp %p", rsp);
                        list_del(&rsp->write_list_entry);
                        cmnd_put(rsp);
                }
@@ -361,6 +369,7 @@ again_rsp:
                 * If both on_write_list and write_processing_started not set,
                 * we can safely put() rsp.
                 */
+               TRACE_MGMT_DBG("Putting rsp %p", rsp);
                cmnd_put(rsp);
                goto again_rsp;
        }
@@ -412,6 +421,13 @@ void req_cmnd_release(struct iscsi_cmnd *req)
                        atomic_read(&sess->active_cmds)-1);
                atomic_dec(&sess->active_cmds);
                req->dec_active_cmnds = 0;
+#ifdef EXTRACHECKS
+               if (unlikely(atomic_read(&sess->active_cmds) < 0)) {
+                       PRINT_CRIT_ERROR("active_cmds < 0 (%d)!!",
+                               atomic_read(&sess->active_cmds));
+                       sBUG();
+               }
+#endif
        }
 
        cmnd_put(req);
@@ -533,7 +549,7 @@ static void iscsi_cmnd_init_write(struct iscsi_cmnd *rsp, int flags)
        LIST_HEAD(head);
 
        if (unlikely(rsp->on_write_list)) {
-               PRINT_ERROR("cmd already on write list (%x %x %x %x %u %u "
+               PRINT_CRIT_ERROR("cmd already on write list (%x %x %x %x %u %u "
                        "%u %u %u %u %u %d %d",
                        cmnd_itt(rsp), cmnd_ttt(rsp), cmnd_opcode(rsp),
                        cmnd_scsicode(rsp), rsp->r2t_sn,
@@ -1605,8 +1621,10 @@ static int cmnd_abort(struct iscsi_cmnd *req)
 
                cmnd_put(cmnd);
                err = 0;
-       } else
+       } else {
+               TRACE_MGMT_DBG("cmd RTT %x not found", req_hdr->rtt);
                err = ISCSI_RESPONSE_UNKNOWN_TASK;
+       }
 
 out:
        return err;
@@ -1834,6 +1852,7 @@ static void execute_task_management(struct iscsi_cmnd *req)
                        ISCSI_RESPONSE_FUNCTION_UNSUPPORTED);
                break;
        default:
+               PRINT_ERROR("Unknown TM function %d", function);
                iscsi_send_task_mgmt_resp(req,
                        ISCSI_RESPONSE_FUNCTION_REJECTED);
                break;
@@ -2076,7 +2095,7 @@ void cmnd_tx_end(struct iscsi_cmnd *cmnd)
        case ISCSI_OP_LOGOUT_RSP:
                break;
        default:
-               PRINT_ERROR("unexpected cmnd op %x", cmnd_opcode(cmnd));
+               PRINT_CRIT_ERROR("unexpected cmnd op %x", cmnd_opcode(cmnd));
                sBUG();
                break;
        }
@@ -2497,7 +2516,7 @@ static int iscsi_xmit_response(struct scst_cmd *scst_cmd)
 
        if (unlikely((req->bufflen != 0) &&
                     !(resp_flags & SCST_TSC_FLAG_STATUS))) {
-               PRINT_ERROR("%s", "Sending DATA without STATUS is unsupported");
+               PRINT_CRIT_ERROR("%s", "Sending DATA without STATUS is unsupported");
                scst_set_cmd_error(scst_cmd,
                        SCST_LOAD_SENSE(scst_sense_hardw_error));
                resp_flags = scst_cmd_get_tgt_resp_flags(scst_cmd);

diff --git a/iscsi-scst/kernel/iscsi.h b/iscsi-scst/kernel/iscsi.h
index 7af76bb..5bb7c87 100644 (file)
--- a/iscsi-scst/kernel/iscsi.h
+++ b/iscsi-scst/kernel/iscsi.h
@@ -235,7 +235,10 @@ typedef void (iscsi_show_info_t)(struct seq_file *seq, struct iscsi_target *targ
 struct iscsi_cmnd {
        struct iscsi_conn *conn;
 
-       /* Some flags protected by conn->write_list_lock */
+       /*
+        * Some flags protected by conn->write_list_lock, but all modified only
+        * from single read thread or when there are no references to cmd.
+        */
        unsigned int hashed:1;
        unsigned int should_close_conn:1;
        unsigned int pending:1;
@@ -246,7 +249,6 @@ struct iscsi_cmnd {
        unsigned int force_cleanup_done:1;
        unsigned int dec_active_cmnds:1;
        unsigned int ddigest_checked:1;
-       unsigned int on_written_list:1;
 #ifdef EXTRACHECKS
        unsigned int on_rx_digest_list:1;
        unsigned int release_called:1;
@@ -271,6 +273,8 @@ struct iscsi_cmnd {
                struct list_head write_list_entry;
        };
 
+       /* Both modified only from single write thread */
+       unsigned int on_written_list:1;
        unsigned long write_timeout;
 
        /*

diff --git a/iscsi-scst/kernel/iscsi_dbg.h b/iscsi-scst/kernel/iscsi_dbg.h
index 8f76aac..f4947ef 100644 (file)
--- a/iscsi-scst/kernel/iscsi_dbg.h
+++ b/iscsi-scst/kernel/iscsi_dbg.h
@@ -35,7 +35,7 @@
 #ifdef DEBUG
 #define ISCSI_DEFAULT_LOG_FLAGS (TRACE_FUNCTION | TRACE_LINE | TRACE_PID | \
        TRACE_OUT_OF_MEM | TRACE_MGMT | TRACE_MGMT_MINOR | TRACE_MGMT_DEBUG | \
-       TRACE_MINOR | TRACE_SPECIAL | TRACE_CONN_OC)
+       TRACE_MINOR | TRACE_SPECIAL | TRACE_CONN_OC | TRACE_CONN_OC_DBG)
 #else
 #define ISCSI_DEFAULT_LOG_FLAGS (TRACE_OUT_OF_MEM | TRACE_MGMT | \
        TRACE_MINOR | TRACE_SPECIAL)

diff --git a/iscsi-scst/kernel/nthread.c b/iscsi-scst/kernel/nthread.c
index 2058991..6f92c67 100644 (file)
--- a/iscsi-scst/kernel/nthread.c
+++ b/iscsi-scst/kernel/nthread.c
@@ -63,7 +63,7 @@ static void iscsi_check_closewait(struct iscsi_conn *conn)
 
        if ((conn->sock->sk->sk_state != TCP_CLOSE_WAIT) &&
            (conn->sock->sk->sk_state != TCP_CLOSE)) {
-               TRACE_CONN_CLOSE_DBG("sk_state %d, skipping",
+               TRACE_CONN_CLOSE("sk_state %d, skipping",
                        conn->sock->sk->sk_state);
                goto out;
        }
@@ -407,7 +407,16 @@ static void close_conn(struct iscsi_conn *conn)
        conn->sock->sk->sk_write_space = conn->old_write_space;
        write_unlock_bh(&conn->sock->sk->sk_callback_lock);
 
-       while(conn->wr_state != ISCSI_CONN_WR_STATE_IDLE) {
+       while(1) {
+               bool t;
+
+               spin_lock_bh(&iscsi_wr_lock);
+               t = (conn->wr_state == ISCSI_CONN_WR_STATE_IDLE);
+               spin_unlock_bh(&iscsi_wr_lock);
+
+               if (t && (atomic_read(&conn->conn_ref_cnt) == 0))
+                       break;
+
                TRACE_CONN_CLOSE("Waiting for wr thread (conn %p), wr_state %x",
                        conn, conn->wr_state);
                msleep(50);
@@ -418,6 +427,8 @@ static void close_conn(struct iscsi_conn *conn)
 
        wait_for_completion(&session->unreg_compl);
 
+       sBUG_ON(!session->shutting_down);
+
        mutex_lock(&target->target_mutex);
        conn_free(conn);
        /* ToDo: this is incompatible with MC/S */
@@ -681,7 +692,7 @@ static int recv(struct iscsi_conn *conn)
                }
                break;
        default:
-               PRINT_ERROR("%d %x", conn->read_state, cmnd_opcode(cmnd));
+               PRINT_CRIT_ERROR("%d %x", conn->read_state, cmnd_opcode(cmnd));
                sBUG();
        }
 
@@ -692,7 +703,8 @@ static int recv(struct iscsi_conn *conn)
                goto out;
 
        if (unlikely(conn->read_size)) {
-               PRINT_ERROR("%d %x %d", res, cmnd_opcode(cmnd), conn->read_size);
+               PRINT_CRIT_ERROR("%d %x %d", res, cmnd_opcode(cmnd),
+                       conn->read_size);
                sBUG();
        }
 
@@ -903,7 +915,7 @@ static int write_data(struct iscsi_conn *conn)
        }
 
        if (!timer_pending(&conn->rsp_timer)) {
-               sBUG_ON(!ref_cmd->write_timeout);
+               sBUG_ON(!ref_cmd->on_written_list);
                spin_lock_bh(&conn->write_list_lock);
                if (likely(!timer_pending(&conn->rsp_timer))) {
                        TRACE_DBG("Starting timer on %ld (conn %p)",
@@ -989,7 +1001,7 @@ retry:
 #ifdef NET_PAGE_CALLBACKS_DEFINED
                if (unlikely((sg_page(&sg[idx])->net_priv != NULL) &&
                                (sg_page(&sg[idx])->net_priv != ref_cmd))) {
-                       PRINT_ERROR("net_priv isn't NULL and != ref_cmd "
+                       PRINT_CRIT_ERROR("net_priv isn't NULL and != ref_cmd "
                                "(write_cmnd %p, ref_cmd %p, sg %p, idx %d, "
                                "net_priv %p)", write_cmnd, ref_cmd, sg, idx,
                                sg_page(&sg[idx])->net_priv);
@@ -1200,7 +1212,7 @@ int iscsi_send(struct iscsi_conn *conn)
                res = tx_ddigest(cmnd, TX_END);
                break;
        default:
-               PRINT_ERROR("%d %d %x", res, conn->write_state,
+               PRINT_CRIT_ERROR("%d %d %x", res, conn->write_state,
                        cmnd_opcode(cmnd));
                sBUG();
        }
@@ -1212,7 +1224,7 @@ int iscsi_send(struct iscsi_conn *conn)
                goto out;
 
        if (unlikely(conn->write_size)) {
-               PRINT_ERROR("%d %x %u", res, cmnd_opcode(cmnd),
+               PRINT_CRIT_ERROR("%d %x %u", res, cmnd_opcode(cmnd),
                        conn->write_size);
                sBUG();
        }

diff --git a/iscsi-scst/kernel/session.c b/iscsi-scst/kernel/session.c
index 6b8fcef..bb8aa75 100644 (file)
--- a/iscsi-scst/kernel/session.c
+++ b/iscsi-scst/kernel/session.c
@@ -134,7 +134,7 @@ int session_free(struct iscsi_session *session)
 
        sBUG_ON(!list_empty(&session->conn_list));
        if (unlikely(atomic_read(&session->active_cmds) != 0)) {
-               PRINT_ERROR("active_cmds not 0 (%d)!!",
+               PRINT_CRIT_ERROR("active_cmds not 0 (%d)!!",
                        atomic_read(&session->active_cmds));
                sBUG();
        }

diff --git a/scst/src/dev_handlers/scst_user.c b/scst/src/dev_handlers/scst_user.c
index 80dfe58..6d912d6 100644 (file)
--- a/scst/src/dev_handlers/scst_user.c
+++ b/scst/src/dev_handlers/scst_user.c
@@ -1946,7 +1946,7 @@ static void dev_user_unjam_cmd(struct scst_user_cmd *ucmd, int busy,
        }
 
        default:
-               PRINT_ERROR("Wrong ucmd state %x", state);
+               PRINT_CRIT_ERROR("Wrong ucmd state %x", state);
                sBUG();
                break;
        }

diff --git a/scst/src/scst_cdbprobe.h b/scst/src/scst_cdbprobe.h
index 84aa82e..4267138 100644 (file)
--- a/scst/src/scst_cdbprobe.h
+++ b/scst/src/scst_cdbprobe.h
@@ -118,7 +118,7 @@ static const struct scst_sdbops scst_scsi_op_table[] = {
        {0x03, "MMMMMMMMMMMMMMMM", "REQUEST SENSE",
         SCST_DATA_READ, SCST_SMALL_TIMEOUT, 4, get_trans_len_1},
        {0x04, "M    O O        ", "FORMAT UNIT",
-        SCST_DATA_NONE, SCST_LONG_TIMEOUT, 0, get_trans_len_none},
+        SCST_DATA_WRITE, SCST_LONG_TIMEOUT|SCST_UNKNOWN_LENGTH, 0, get_trans_len_none},
        {0x04, "  O             ", "FORMAT",
         SCST_DATA_NONE, FLAG_NONE, 0, get_trans_len_none},
        {0x05, "VMVVVV  V       ", "READ BLOCK LIMITS",

diff --git a/scst/src/scst_lib.c b/scst/src/scst_lib.c
index 86b40ad..0d9c2a0 100644 (file)
--- a/scst/src/scst_lib.c
+++ b/scst/src/scst_lib.c
@@ -260,7 +260,7 @@ void scst_free_device(struct scst_device *dev)
 #ifdef EXTRACHECKS
        if (!list_empty(&dev->dev_tgt_dev_list) || 
            !list_empty(&dev->dev_acg_dev_list)) {
-               PRINT_ERROR("%s: dev_tgt_dev_list or dev_acg_dev_list "
+               PRINT_CRIT_ERROR("%s: dev_tgt_dev_list or dev_acg_dev_list "
                        "is not empty!", __FUNCTION__);
                sBUG();
        }

diff --git a/scst/src/scst_targ.c b/scst/src/scst_targ.c
index 42609a3..bc7d246 100644 (file)
--- a/scst/src/scst_targ.c
+++ b/scst/src/scst_targ.c
@@ -63,7 +63,7 @@ struct scst_cmd *scst_rx_cmd(struct scst_session *sess,
 
 #ifdef EXTRACHECKS
        if (unlikely(sess->shut_phase != SCST_SESS_SPH_READY)) {
-               PRINT_ERROR("%s", "New cmd while shutting down the session");
+               PRINT_CRIT_ERROR("%s", "New cmd while shutting down the session");
                sBUG();
        }
 #endif
@@ -381,13 +381,15 @@ static int scst_pre_parse(struct scst_cmd *cmd)
                        if (scst_cmd_is_expected_set(cmd)) {
                                /*
                                 * Command data length can't be easily
-                                * determined from the CDB. ToDo, that should 
-                                * be fixed. Until it's fixed, get it from
-                                * the supplied expected value, but
-                                * limit it to some reasonable value (15MB).
+                                * determined from the CDB. ToDo, all such
+                                * commands should be fixed. Until they are
+                                * fixed, get it from the supplied expected
+                                * value, but limit it to some reasonable
+                                * value (15MB).
                                 */
                                cmd->bufflen = min(cmd->expected_transfer_len,
                                                        15*1024*1024);
+                               cmd->op_flags &= ~SCST_UNKNOWN_LENGTH;
                        } else
                                cmd->bufflen = 0;
                }
@@ -3136,8 +3138,8 @@ void scst_process_active_cmd(struct scst_cmd *cmd, int context)
                        break;
 
                default:
-                       PRINT_ERROR("cmd (%p) in state %d, but shouldn't be",
-                              cmd, cmd->state);
+                       PRINT_CRIT_ERROR("cmd (%p) in state %d, but shouldn't "
+                               "be", cmd, cmd->state);
                        sBUG();
                        res = SCST_CMD_STATE_RES_CONT_NEXT;
                        break;
@@ -3169,7 +3171,7 @@ void scst_process_active_cmd(struct scst_cmd *cmd, int context)
                /* not very valid commands */
                case SCST_CMD_STATE_DEFAULT:
                case SCST_CMD_STATE_NEED_THREAD_CTX:
-                       PRINT_ERROR("cmd %p is in state %d, not putting on "
+                       PRINT_CRIT_ERROR("cmd %p is in state %d, not putting on "
                                "useful list (left on scst cmd list)", cmd, 
                                cmd->state);
                        spin_unlock_irq(&cmd->cmd_lists->cmd_list_lock);
@@ -4575,7 +4577,7 @@ static int scst_post_rx_mgmt_cmd(struct scst_session *sess,
        scst_sess_get(sess);
 
        if (unlikely(sess->shut_phase != SCST_SESS_SPH_READY)) {
-               PRINT_ERROR("New mgmt cmd while shutting down the session %p "
+               PRINT_CRIT_ERROR("New mgmt cmd while shutting down the session %p "
                        "shut_phase %ld", sess, sess->shut_phase);
                sBUG();
        }
@@ -5024,7 +5026,7 @@ int scst_mgmt_thread(void *arg)
                        if (sess->init_phase == SCST_SESS_IPH_INITING)
                                scst_init_session(sess);
                        else {
-                               PRINT_ERROR("session %p is in "
+                               PRINT_CRIT_ERROR("session %p is in "
                                        "scst_sess_init_list, but in unknown "
                                        "init phase %x", sess,
                                        sess->init_phase);
@@ -5051,7 +5053,7 @@ int scst_mgmt_thread(void *arg)
                                scst_free_session_callback(sess);
                                break;
                        default:
-                               PRINT_ERROR("session %p is in "
+                               PRINT_CRIT_ERROR("session %p is in "
                                        "scst_sess_shut_list, but in unknown "
                                        "shut phase %lx", sess,
                                        sess->shut_phase);