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

4 files changed, 51 insertions, 0 deletions

diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c
index f207b0bd0cad..466a689c538f 100644
--- 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 aad75cfa1c60..9a4d870a820a 100644
--- 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 55e034b10ded..335ab70181e8 100644
--- 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 e10ed145baa7..6de0147d84d8 100644
--- 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 *,