diff --git a/iscsi-scst/kernel/conn.c b/iscsi-scst/kernel/conn.c index c05a4cf81..f7230e5ee 100644 --- 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 fe55175e5..e3a7eb933 100644 --- 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 7af76bbf7..5bb7c8737 100644 --- 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 8f76aac75..f4947efe2 100644 --- 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 205899120..6f92c67d9 100644 --- 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 6b8fcefa8..bb8aa759e 100644 --- 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 80dfe58ef..6d912d6c9 100644 --- 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 84aa82e3d..426713888 100644 --- 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 86b40ad4f..0d9c2a045 100644 --- 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 42609a386..bc7d2469a 100644 --- 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);