[SCSI] zfcp: Add trace records for recovery actions.

This patch writes trace records for various phases of a recovery action:
action being created, action being processed, action continueing
asynchronously, action gone, action timed out, action dismissed etc.

Signed-off-by: Martin Peschke <mp3@de.ibm.com>
Signed-off-by: Christof Schmitt <christof.schmitt@de.ibm.com>
Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c
index f207b0b..466a689 100644 (file)
--- a/drivers/s390/scsi/zfcp_dbf.c
+++ b/drivers/s390/scsi/zfcp_dbf.c
@@ -524,6 +524,7 @@ static const char *zfcp_rec_dbf_tags[] = {
        [ZFCP_REC_DBF_ID_THREAD] = "thread",
        [ZFCP_REC_DBF_ID_TARGET] = "target",
        [ZFCP_REC_DBF_ID_TRIGGER] = "trigger",
+       [ZFCP_REC_DBF_ID_ACTION] = "action",
 };
 
 static const char *zfcp_rec_dbf_ids[] = {
@@ -671,6 +672,11 @@ static const char *zfcp_rec_dbf_ids[] = {
        [139]   = "hbaapi unit shutdown",
        [140]   = "qdio error",
        [141]   = "scsi host reset",
+       [142]   = "dismissing fsf request for recovery action",
+       [143]   = "recovery action timed out",
+       [144]   = "recovery action gone",
+       [145]   = "recovery action being processed",
+       [146]   = "recovery action ready for next step",
 };
 
 static int zfcp_rec_dbf_view_format(debug_info_t *id, struct debug_view *view,
@@ -708,6 +714,12 @@ static int zfcp_rec_dbf_view_format(debug_info_t *id, struct debug_view *view,
                zfcp_dbf_out(&p, "port_status", "0x%08x", r->u.trigger.ps);
                zfcp_dbf_out(&p, "unit_status", "0x%08x", r->u.trigger.us);
                break;
+       case ZFCP_REC_DBF_ID_ACTION:
+               zfcp_dbf_out(&p, "erp_action", "0x%016Lx", r->u.action.action);
+               zfcp_dbf_out(&p, "fsf_req", "0x%016Lx", r->u.action.fsf_req);
+               zfcp_dbf_out(&p, "status", "0x%08Lx", r->u.action.status);
+               zfcp_dbf_out(&p, "step", "0x%08Lx", r->u.action.step);
+               break;
        }
        sprintf(p, "\n");
        return (p - buf) + 1;
@@ -861,6 +873,29 @@ void zfcp_rec_dbf_event_trigger(u8 id2, u64 ref, u8 want, u8 need, u64 action,
        spin_unlock_irqrestore(&adapter->rec_dbf_lock, flags);
 }
 
+/**
+ * zfcp_rec_dbf_event_action - trace event showing progress of recovery action
+ * @id2: identifier
+ * @erp_action: error recovery action struct pointer
+ */
+void zfcp_rec_dbf_event_action(u8 id2, struct zfcp_erp_action *erp_action)
+{
+       struct zfcp_adapter *adapter = erp_action->adapter;
+       struct zfcp_rec_dbf_record *r = &adapter->rec_dbf_buf;
+       unsigned long flags;
+
+       spin_lock_irqsave(&adapter->rec_dbf_lock, flags);
+       memset(r, 0, sizeof(*r));
+       r->id = ZFCP_REC_DBF_ID_ACTION;
+       r->id2 = id2;
+       r->u.action.action = (u64)erp_action;
+       r->u.action.status = erp_action->status;
+       r->u.action.step = erp_action->step;
+       r->u.action.fsf_req = (u64)erp_action->fsf_req;
+       debug_event(adapter->rec_dbf, 4, r, sizeof(*r));
+       spin_unlock_irqrestore(&adapter->rec_dbf_lock, flags);
+}
+
 static void
 _zfcp_san_dbf_event_common_ct(const char *tag, struct zfcp_fsf_req *fsf_req,
                              u32 s_id, u32 d_id, void *buffer, int buflen)

diff --git a/drivers/s390/scsi/zfcp_def.h b/drivers/s390/scsi/zfcp_def.h
index aad75cf..9a4d870 100644 (file)
--- a/drivers/s390/scsi/zfcp_def.h
+++ b/drivers/s390/scsi/zfcp_def.h
@@ -307,10 +307,18 @@ struct zfcp_rec_dbf_record_trigger {
        u64 fcp_lun;
 } __attribute__ ((packed));
 
+struct zfcp_rec_dbf_record_action {
+       u32 status;
+       u32 step;
+       u64 action;
+       u64 fsf_req;
+} __attribute__ ((packed));
+
 struct zfcp_rec_dbf_record {
        u8 id;
        u8 id2;
        union {
+               struct zfcp_rec_dbf_record_action action;
                struct zfcp_rec_dbf_record_thread thread;
                struct zfcp_rec_dbf_record_target target;
                struct zfcp_rec_dbf_record_trigger trigger;
@@ -318,6 +326,7 @@ struct zfcp_rec_dbf_record {
 } __attribute__ ((packed));
 
 enum {
+       ZFCP_REC_DBF_ID_ACTION,
        ZFCP_REC_DBF_ID_THREAD,
        ZFCP_REC_DBF_ID_TARGET,
        ZFCP_REC_DBF_ID_TRIGGER,

diff --git a/drivers/s390/scsi/zfcp_erp.c b/drivers/s390/scsi/zfcp_erp.c
index 55e034b..335ab70 100644 (file)
--- a/drivers/s390/scsi/zfcp_erp.c
+++ b/drivers/s390/scsi/zfcp_erp.c
@@ -893,8 +893,10 @@ zfcp_erp_strategy_check_fsfreq(struct zfcp_erp_action *erp_action)
                                                 "a_ca_disreq");
                                erp_action->fsf_req->status |=
                                        ZFCP_STATUS_FSFREQ_DISMISSED;
+                               zfcp_rec_dbf_event_action(142, erp_action);
                        }
                        if (erp_action->status & ZFCP_STATUS_ERP_TIMEDOUT) {
+                               zfcp_rec_dbf_event_action(143, erp_action);
                                ZFCP_LOG_NORMAL("error: erp step timed out "
                                                "(action=%d, fsf_req=%p)\n ",
                                                erp_action->action,
@@ -3162,6 +3164,8 @@ zfcp_erp_action_dequeue(struct zfcp_erp_action *erp_action)
        debug_text_event(adapter->erp_dbf, 4, "a_actdeq");
        debug_event(adapter->erp_dbf, 4, &erp_action->action, sizeof (int));
        list_del(&erp_action->list);
+       zfcp_rec_dbf_event_action(144, erp_action);
+
        switch (erp_action->action) {
        case ZFCP_ERP_ACTION_REOPEN_UNIT:
                atomic_clear_mask(ZFCP_STATUS_COMMON_ERP_INUSE,
@@ -3305,6 +3309,7 @@ static void zfcp_erp_action_to_running(struct zfcp_erp_action *erp_action)
        debug_text_event(adapter->erp_dbf, 6, "a_toru");
        debug_event(adapter->erp_dbf, 6, &erp_action->action, sizeof (int));
        list_move(&erp_action->list, &erp_action->adapter->erp_running_head);
+       zfcp_rec_dbf_event_action(145, erp_action);
 }
 
 static void zfcp_erp_action_to_ready(struct zfcp_erp_action *erp_action)
@@ -3314,6 +3319,7 @@ static void zfcp_erp_action_to_ready(struct zfcp_erp_action *erp_action)
        debug_text_event(adapter->erp_dbf, 6, "a_tore");
        debug_event(adapter->erp_dbf, 6, &erp_action->action, sizeof (int));
        list_move(&erp_action->list, &erp_action->adapter->erp_ready_head);
+       zfcp_rec_dbf_event_action(146, erp_action);
 }
 
 void zfcp_erp_port_boxed(struct zfcp_port *port, u8 id, u64 ref)

diff --git a/drivers/s390/scsi/zfcp_ext.h b/drivers/s390/scsi/zfcp_ext.h
index e10ed14..6de0147 100644 (file)
--- a/drivers/s390/scsi/zfcp_ext.h
+++ b/drivers/s390/scsi/zfcp_ext.h
@@ -173,6 +173,7 @@ extern void zfcp_rec_dbf_event_unit(u8 id, u64 ref, struct zfcp_unit *unit);
 extern void zfcp_rec_dbf_event_trigger(u8 id, u64 ref, u8 want, u8 need,
                                       u64 action, struct zfcp_adapter *,
                                       struct zfcp_port *, struct zfcp_unit *);
+extern void zfcp_rec_dbf_event_action(u8 id, struct zfcp_erp_action *);
 
 extern void zfcp_hba_dbf_event_fsf_response(struct zfcp_fsf_req *);
 extern void zfcp_hba_dbf_event_fsf_unsol(const char *, struct zfcp_adapter *,