changeset 11694:c35b670c8a4f

6925580 No easy way to extract firmware event logs
author David Hollister <David.Hollister@Sun.COM>
date Thu, 18 Feb 2010 14:15:42 -0700
parents 0a223da9570a
children 04bf1fc2c3f2
files usr/src/cmd/mdb/common/modules/pmcs/pmcs.c usr/src/uts/common/io/scsi/adapters/pmcs/pmcs.conf usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_attach.c usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_fwlog.c usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_intr.c usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs.h usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_param.h usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_proto.h
diffstat 8 files changed, 393 insertions(+), 3 deletions(-) [+]
line wrap: on
line diff
--- a/usr/src/cmd/mdb/common/modules/pmcs/pmcs.c	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/cmd/mdb/common/modules/pmcs/pmcs.c	Thu Feb 18 14:15:42 2010 -0700
@@ -32,6 +32,12 @@
 #include <sys/damap.h>
 #include <sys/scsi/scsi.h>
 #include <sys/scsi/adapters/pmcs/pmcs.h>
+#ifndef _KMDB
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <unistd.h>
+#endif	/* _KMDB */
 
 /*
  * We need use this to pass the settings when display_iport
@@ -2381,6 +2387,108 @@
 	return (DCMD_OK);
 }
 
+#ifndef _KMDB
+static int
+pmcs_dump_fwlog(struct pmcs_hw *ss, int instance, const char *ofile)
+{
+	uint8_t *fwlogp;
+	int	ofilefd = -1;
+	char	ofilename[MAXPATHLEN];
+	int	rval = DCMD_OK;
+
+	if (ss->fwlogp == NULL) {
+		mdb_warn("Firmware event log disabled for instance %d",
+		    instance);
+		return (DCMD_OK);
+	}
+
+	if (snprintf(ofilename, MAXPATHLEN, "%s%d", ofile, instance) >
+	    MAXPATHLEN) {
+		mdb_warn("Output filename is too long for instance %d",
+		    instance);
+		return (DCMD_ERR);
+	}
+
+	fwlogp = mdb_alloc(PMCS_FWLOG_SIZE, UM_SLEEP);
+
+	if (MDB_RD(fwlogp, PMCS_FWLOG_SIZE, ss->fwlogp) == -1) {
+		NOREAD(fwlogp, ss->fwlogp);
+		rval = DCMD_ERR;
+		goto cleanup;
+	}
+
+	ofilefd = open(ofilename, O_WRONLY | O_CREAT,
+	    S_IRUSR | S_IRGRP | S_IROTH);
+	if (ofilefd < 0) {
+		mdb_warn("Unable to open '%s' to dump instance %d event log",
+		    ofilename, instance);
+		rval = DCMD_ERR;
+		goto cleanup;
+	}
+
+	if (write(ofilefd, fwlogp, PMCS_FWLOG_SIZE) != PMCS_FWLOG_SIZE) {
+		mdb_warn("Failed to write %d bytes to output file: instance %d",
+		    PMCS_FWLOG_SIZE, instance);
+		rval = DCMD_ERR;
+		goto cleanup;
+	}
+
+	mdb_printf("Event log for instance %d written to %s\n", instance,
+	    ofilename);
+
+cleanup:
+	if (ofilefd >= 0) {
+		close(ofilefd);
+	}
+	mdb_free(fwlogp, PMCS_FWLOG_SIZE);
+	return (rval);
+}
+
+static int
+pmcs_fwlog(uintptr_t addr, uint_t flags, int argc, const mdb_arg_t *argv)
+{
+	void		*pmcs_state;
+	const char	*ofile = NULL;
+	struct pmcs_hw	ss;
+	struct dev_info	dip;
+
+	if (mdb_getopts(argc, argv, 'o', MDB_OPT_STR, &ofile, NULL) != argc) {
+		return (DCMD_USAGE);
+	}
+
+	if (ofile == NULL) {
+		mdb_printf("No output file specified\n");
+		return (DCMD_USAGE);
+	}
+
+	if (!(flags & DCMD_ADDRSPEC)) {
+		pmcs_state = NULL;
+		if (mdb_readvar(&pmcs_state, "pmcs_softc_state") == -1) {
+			mdb_warn("can't read pmcs_softc_state");
+			return (DCMD_ERR);
+		}
+		if (mdb_pwalk_dcmd("genunix`softstate", "pmcs`pmcs_fwlog", argc,
+		    argv, (uintptr_t)pmcs_state) == -1) {
+			mdb_warn("mdb_pwalk_dcmd failed for pmcs_log");
+			return (DCMD_ERR);
+		}
+		return (DCMD_OK);
+	}
+
+	if (MDB_RD(&ss, sizeof (ss), addr) == -1) {
+		NOREAD(pmcs_hw_t, addr);
+		return (DCMD_ERR);
+	}
+
+	if (MDB_RD(&dip, sizeof (struct dev_info), ss.dip) == -1) {
+		NOREAD(pmcs_hw_t, addr);
+		return (DCMD_ERR);
+	}
+
+	return (pmcs_dump_fwlog(&ss, dip.devi_instance, ofile));
+}
+#endif	/* _KMDB */
+
 static int
 pmcs_log(uintptr_t addr, uint_t flags, int argc, const mdb_arg_t *argv)
 {
@@ -2644,6 +2752,12 @@
 	    "Find work structures by tag type, serial number or index",
 	    pmcs_tag, pmcs_tag_help
 	},
+#ifndef _KMDB
+	{ "pmcs_fwlog",
+	    "?-o output_file",
+	    "dump pmcs firmware event log to output_file", pmcs_fwlog, NULL
+	},
+#endif	/* _KMDB */
 	{ NULL }
 };
 
--- a/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs.conf	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs.conf	Thu Feb 18 14:15:42 2010 -0700
@@ -17,7 +17,7 @@
 #
 # CDDL HEADER END
 #
-# Copyright 2009 Sun Microsystems, Inc.  All rights reserved.
+# Copyright 2010 Sun Microsystems, Inc.  All rights reserved.
 # Use is subject to license terms.
 #
 
@@ -40,6 +40,29 @@
 #name="pmcs" parent="/pci@0/pci10de,5d@e" unit-address="0" mpxio-disable="yes";
 
 #
+# If pmcs-fwlogfile is not defined, firmware event logs will only be resident
+# in memory.  If defined, the driver can write up to 10 event logs per HBA to
+# the specified location.  An absolute path must be specified, and all
+# directories in the path must already exist.  The basename will be the prefix
+# of the output files.
+#
+# For example, if pmcs-fwlogfile is defined as "/var/tmp/fwlog", the driver
+# will write the following files as needed:
+#
+# /var/tmp/fwlogX-aap1.[0-4]
+# /var/tmp/fwlogX-iop.[0-4]
+#
+# where "X" corresponds to the instance number of the HBA.
+#
+# Each file will be 1MB in size and will only be written when the in-memory
+# copy of the event log reaches a threshold.  If all five files have already
+# been written, the driver will simply cycle from 4 back to 0 and start over.
+# Thus, the .# suffix doesn't necessarily indicate the ordering.  Check the
+# files' timestamps to determine which is the oldest or newest.
+#
+#pmcs-fwlogfile="/var/tmp/fwlog";
+
+#
 # Global debug settings may be set using the 'pmcs-debug-mask' property.
 # Any combination of values may be set according to the following:
 #
--- a/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_attach.c	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_attach.c	Thu Feb 18 14:15:42 2010 -0700
@@ -423,6 +423,7 @@
 	pmcs_phy_t *phyp;
 	uint32_t num_threads;
 	char buf[64];
+	char *fwl_file;
 
 	switch (cmd) {
 	case DDI_ATTACH:
@@ -527,6 +528,23 @@
 	if (pwp->fwlog > PMCS_FWLOG_MAX) {
 		pwp->fwlog = PMCS_FWLOG_MAX;
 	}
+	if ((ddi_prop_lookup_string(DDI_DEV_T_ANY, dip, 0, "pmcs-fwlogfile",
+	    &fwl_file) == DDI_SUCCESS)) {
+		if (snprintf(pwp->fwlogfile_aap1, MAXPATHLEN, "%s%d-aap1.0",
+		    fwl_file, ddi_get_instance(dip)) > MAXPATHLEN) {
+			pwp->fwlogfile_aap1[0] = '\0';
+			pwp->fwlogfile_iop[0] = '\0';
+		} else if (snprintf(pwp->fwlogfile_iop, MAXPATHLEN,
+		    "%s%d-iop.0", fwl_file,
+		    ddi_get_instance(dip)) > MAXPATHLEN) {
+			pwp->fwlogfile_aap1[0] = '\0';
+			pwp->fwlogfile_iop[0] = '\0';
+		}
+		ddi_prop_free(fwl_file);
+	} else {
+		pwp->fwlogfile_aap1[0] = '\0';
+		pwp->fwlogfile_iop[0] = '\0';
+	}
 
 	mutex_enter(&pmcs_trace_lock);
 	if (pmcs_tbuf == NULL) {
@@ -546,6 +564,24 @@
 	}
 	mutex_exit(&pmcs_trace_lock);
 
+	if (pwp->fwlog && strlen(pwp->fwlogfile_aap1) > 0) {
+		pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+		    "%s: firmware event log files: %s, %s", __func__,
+		    pwp->fwlogfile_aap1, pwp->fwlogfile_iop);
+		pwp->fwlog_file = 1;
+	} else {
+		if (pwp->fwlog == 0) {
+			pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+			    "%s: No firmware event log will be written "
+			    "(event log disabled)", __func__);
+		} else {
+			pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+			    "%s: No firmware event log will be written "
+			    "(no filename configured - too long?)", __func__);
+		}
+		pwp->fwlog_file = 0;
+	}
+
 	disable_msix = ddi_prop_get_int(DDI_DEV_T_ANY, dip,
 	    DDI_PROP_DONTPASS | DDI_PROP_NOTPROM, "pmcs-disable-msix",
 	    disable_msix);
@@ -707,6 +743,9 @@
 			pwp->fwlog = 0;
 		} else {
 			bzero(pwp->fwlogp, PMCS_FWLOG_SIZE);
+			pwp->fwlogp_aap1 = (pmcs_fw_event_hdr_t *)pwp->fwlogp;
+			pwp->fwlogp_iop = (pmcs_fw_event_hdr_t *)((void *)
+			    ((caddr_t)pwp->fwlogp + (PMCS_FWLOG_SIZE / 2)));
 		}
 	}
 
--- a/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_fwlog.c	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_fwlog.c	Thu Feb 18 14:15:42 2010 -0700
@@ -43,6 +43,7 @@
 static int pmcs_dump_hsst_sregs(pmcs_hw_t *, caddr_t, uint32_t);
 static int pmcs_dump_sspa_sregs(pmcs_hw_t *, caddr_t, uint32_t);
 static int pmcs_dump_fwlog(pmcs_hw_t *, caddr_t, uint32_t);
+static void pmcs_write_fwlog(pmcs_hw_t *, pmcs_fw_event_hdr_t *);
 
 /*
  * Dump internal registers. Used after a firmware crash.
@@ -1156,3 +1157,165 @@
 	}
 	return (i);
 }
+
+/*
+ * Write out either the AAP1 or IOP event log
+ */
+static void
+pmcs_write_fwlog(pmcs_hw_t *pwp, pmcs_fw_event_hdr_t *fwlogp)
+{
+	struct vnode *vnp;
+	caddr_t fwlogfile, bufp;
+	rlim64_t rlimit;
+	ssize_t resid;
+	offset_t offset = 0;
+	int error;
+	uint32_t data_len;
+
+	if (fwlogp == pwp->fwlogp_aap1) {
+		fwlogfile = pwp->fwlogfile_aap1;
+	} else {
+		fwlogfile = pwp->fwlogfile_iop;
+	}
+
+	if ((error = vn_open(fwlogfile, UIO_SYSSPACE, FCREAT|FWRITE, 0644,
+	    &vnp, CRCREAT, 0)) != 0) {
+		pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+		    "%s: Could not create '%s', error %d", __func__,
+		    fwlogfile, error);
+		return;
+	}
+
+	bufp = (caddr_t)fwlogp;
+	data_len = PMCS_FWLOG_SIZE / 2;
+	rlimit = data_len + 1;
+	for (;;) {
+		error = vn_rdwr(UIO_WRITE, vnp, bufp, data_len, offset,
+		    UIO_SYSSPACE, FSYNC, rlimit, CRED(), &resid);
+		if (error) {
+			pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+			    "%s: could not write %s, error %d", __func__,
+			    fwlogfile, error);
+			break;
+		}
+		if (resid == data_len) {
+			pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+			    "%s: Out of space in %s, error %d", __func__,
+			    fwlogfile, error);
+			error = ENOSPC;
+			break;
+		}
+		if (resid == 0)
+			break;
+		offset += (data_len - resid);
+		data_len = (ssize_t)resid;
+	}
+
+	if (error = VOP_CLOSE(vnp, FWRITE, 1, (offset_t)0, kcred, NULL)) {
+		if (!error) {
+			pmcs_prt(pwp, PMCS_PRT_DEBUG, NULL, NULL,
+			    "%s: Error on close %s, error %d", __func__,
+			    fwlogfile, error);
+		}
+	}
+
+	VN_RELE(vnp);
+}
+
+/*
+ * Check the in-memory event log.  If it's filled up to or beyond the
+ * threshold, write it out to the configured filename.
+ */
+void
+pmcs_gather_fwlog(pmcs_hw_t *pwp)
+{
+	uint32_t num_entries_aap1, num_entries_iop, fname_suffix;
+
+	ASSERT(!mutex_owned(&pwp->lock));
+
+	/*
+	 * Get our copies of the latest indices
+	 */
+	pwp->fwlog_latest_idx_aap1 = pwp->fwlogp_aap1->fw_el_latest_idx;
+	pwp->fwlog_latest_idx_iop = pwp->fwlogp_iop->fw_el_latest_idx;
+
+	/*
+	 * We need entries in the log before we can know how big they are
+	 */
+	if ((pwp->fwlog_max_entries_aap1 == 0) &&
+	    (pwp->fwlogp_aap1->fw_el_latest_idx != 0)) {
+		pwp->fwlog_max_entries_aap1 =
+		    (PMCS_FWLOG_SIZE / 2) / pwp->fwlogp_aap1->fw_el_entry_size;
+		pwp->fwlog_threshold_aap1 =
+		    (pwp->fwlog_max_entries_aap1 * PMCS_FWLOG_THRESH) / 100;
+	}
+
+	if ((pwp->fwlog_max_entries_iop == 0) &&
+	    (pwp->fwlogp_iop->fw_el_latest_idx != 0)) {
+		pwp->fwlog_max_entries_iop =
+		    (PMCS_FWLOG_SIZE / 2) / pwp->fwlogp_iop->fw_el_entry_size;
+		pwp->fwlog_threshold_iop =
+		    (pwp->fwlog_max_entries_iop * PMCS_FWLOG_THRESH) / 100;
+	}
+
+	/*
+	 * Check if we've reached the threshold in the AAP1 log.  We do this
+	 * by comparing the latest index with our copy of the oldest index
+	 * (not the chip's).
+	 */
+	if (pwp->fwlog_latest_idx_aap1 >= pwp->fwlog_oldest_idx_aap1) {
+		/* Log has not wrapped */
+		num_entries_aap1 =
+		    pwp->fwlog_latest_idx_aap1 - pwp->fwlog_oldest_idx_aap1;
+	} else {
+		/* Log has wrapped */
+		num_entries_aap1 = pwp->fwlog_max_entries_aap1 -
+		    (pwp->fwlog_oldest_idx_aap1 - pwp->fwlog_latest_idx_aap1);
+	}
+
+	/*
+	 * Now check the IOP log
+	 */
+	if (pwp->fwlog_latest_idx_iop >= pwp->fwlog_oldest_idx_iop) {
+		/* Log has not wrapped */
+		num_entries_iop = pwp->fwlog_latest_idx_iop -
+		    pwp->fwlog_oldest_idx_iop;
+	} else {
+		/* Log has wrapped */
+		num_entries_iop = pwp->fwlog_max_entries_iop -
+		    (pwp->fwlog_oldest_idx_iop - pwp->fwlog_latest_idx_iop);
+	}
+
+	if ((num_entries_aap1 < pwp->fwlog_threshold_aap1) &&
+	    (num_entries_iop < pwp->fwlog_threshold_iop)) {
+		return;
+	}
+
+	/*
+	 * Write out the necessary log file(s), update the "oldest" pointers
+	 * and the suffix to the written filenames.
+	 */
+	if (num_entries_aap1 >= pwp->fwlog_threshold_aap1) {
+		pmcs_write_fwlog(pwp, pwp->fwlogp_aap1);
+		pwp->fwlog_oldest_idx_aap1 = pwp->fwlog_latest_idx_aap1;
+
+		fname_suffix = strlen(pwp->fwlogfile_aap1) - 1;
+		if (pwp->fwlogfile_aap1[fname_suffix] == '4') {
+			pwp->fwlogfile_aap1[fname_suffix] = '0';
+		} else {
+			++pwp->fwlogfile_aap1[fname_suffix];
+		}
+	}
+
+	if (num_entries_iop >= pwp->fwlog_threshold_iop) {
+		pmcs_write_fwlog(pwp, pwp->fwlogp_iop);
+		pwp->fwlog_oldest_idx_iop = pwp->fwlog_latest_idx_iop;
+
+		fname_suffix = strlen(pwp->fwlogfile_iop) - 1;
+		if (pwp->fwlogfile_iop[fname_suffix] == '4') {
+			pwp->fwlogfile_iop[fname_suffix] = '0';
+		} else {
+			++pwp->fwlogfile_iop[fname_suffix];
+		}
+	}
+}
--- a/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_intr.c	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/io/scsi/adapters/pmcs/pmcs_intr.c	Thu Feb 18 14:15:42 2010 -0700
@@ -1534,6 +1534,16 @@
 		ici->nsecs_between_intrs = 0;
 		ici->num_intrs = 0;
 		ici->num_io_completions = 0;
+
+		/*
+		 * If a firmware event log file is configured, check to see
+		 * if it needs to be written to the file.  We do this here
+		 * because writing to a file from a callout thread (i.e.
+		 * from the watchdog timer) can cause livelocks.
+		 */
+		if (pwp->fwlog_file) {
+			pmcs_gather_fwlog(pwp);
+		}
 	}
 
 	mutex_exit(&pwp->ict_lock);
--- a/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs.h	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs.h	Thu Feb 18 14:15:42 2010 -0700
@@ -38,6 +38,7 @@
 #include <sys/modctl.h>
 #include <sys/pci.h>
 #include <sys/pcie.h>
+#include <sys/file.h>
 #include <sys/isa_defs.h>
 #include <sys/sunmdi.h>
 #include <sys/mdi_impldefs.h>
@@ -326,7 +327,8 @@
 		resource_limited	: 1,
 		configuring		: 1,
 		ds_err_recovering	: 1,
-		quiesced		: 1;
+		quiesced		: 1,
+		fwlog_file		: 1;
 
 	/*
 	 * This HBA instance's iportmap and list of iport states.
@@ -464,10 +466,42 @@
 	volatile uint8_t	scratch_locked;	/* Scratch area ownership */
 
 	/*
-	 * Firmware log pointer
+	 * Firmware info
+	 *
+	 * fwlogp: Pointer to block of memory mapped for the event logs
+	 * fwlogp_aap1: Pointer to the beginning of the AAP1 event log
+	 * fwlogp_iop: Pointer to the beginning of the IOP event log
+	 * fwaddr: The physical address of fwlogp
+	 *
+	 * fwlogfile_aap1/iop: Path to the saved AAP1/IOP event logs
+	 * fwlog_max_entries_aap1/iop: Max # of entries in each log
+	 * fwlog_oldest_idx_aap1/iop: Index of oldest entry in each log
+	 * fwlog_latest_idx_aap1/iop: Index of newest entry in each log
+	 * fwlog_threshold_aap1/iop: % full at which we save the event log
+	 * fwlog_findex_aap1/iop: Suffix to each event log's next filename
+	 *
+	 * Firmware event logs are written out to the filenames specified in
+	 * fwlogp_aap1/iop when the number of entries in the in-memory copy
+	 * reaches or exceeds the threshold value.  The filenames are suffixed
+	 * with .X where X is an integer ranging from 0 to 4.  This allows us
+	 * to save up to 5MB of event log data for each log.
 	 */
 	uint32_t	*fwlogp;
+	pmcs_fw_event_hdr_t *fwlogp_aap1;
+	pmcs_fw_event_hdr_t *fwlogp_iop;
 	uint64_t	fwaddr;
+	char		fwlogfile_aap1[MAXPATHLEN + 1];
+	uint32_t	fwlog_max_entries_aap1;
+	uint32_t	fwlog_oldest_idx_aap1;
+	uint32_t	fwlog_latest_idx_aap1;
+	uint32_t	fwlog_threshold_aap1;
+	uint32_t	fwlog_findex_aap1;
+	char		fwlogfile_iop[MAXPATHLEN + 1];
+	uint32_t	fwlog_max_entries_iop;
+	uint32_t	fwlog_oldest_idx_iop;
+	uint32_t	fwlog_latest_idx_iop;
+	uint32_t	fwlog_threshold_iop;
+	uint32_t	fwlog_findex_iop;
 
 	/*
 	 * Internal register dump region and flash chunk DMA info
--- a/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_param.h	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_param.h	Thu Feb 18 14:15:42 2010 -0700
@@ -61,6 +61,8 @@
  */
 #define	PMCS_FWLOG_SIZE		(2 << 20)
 #define	PMCS_FWLOG_MAX		5	/* maximum logging level */
+#define	PMCS_FWLOG_THRESH	75	/* Write to file when log this % full */
+
 #define	SATLSIZE		1024
 
 /*
--- a/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_proto.h	Thu Feb 18 13:49:11 2010 -0700
+++ b/usr/src/uts/common/sys/scsi/adapters/pmcs/pmcs_proto.h	Thu Feb 18 14:15:42 2010 -0700
@@ -370,6 +370,11 @@
  */
 void pmcs_status_disposition(pmcs_phy_t *, uint32_t);
 
+/*
+ * Write out firmware event log (if configured to do so) if it's filled up
+ */
+void pmcs_gather_fwlog(pmcs_hw_t *);
+
 #ifdef	__cplusplus
 }
 #endif