mips: rate limit the trap handler output; add pid/tid/program name.

I discovered that we're logging each trap, which gets pretty spendy;
and there wasn't any further information on the pid/tid/progname involved.

I originally noticed this because I don't attach anything to /dev/log and so
the log() output stays going to the kernel.  That's an oops on my part, but
I'm glad I did it.

This commit adds the following:

* a rate limiter, which could do with some eyeballs/ideas on how to
  make it more predictable on SMP;
* log pid, tid, progname (comm) as part of the output.

I now get output like this:

Unaligned Load Word: pid=621 (pmcstat), tid=100060, pc=0xffffffff803ae898, badvaddr=0x40a10055
Unaligned Load Word: pid=621 (pmcstat), tid=100060, pc=0xffffffff803ae898, badvaddr=0x40a10051
Unaligned Load Word: pid=621 (pmcstat), tid=100060, pc=0xffffffff803ae898, badvaddr=0x40a1004d
Unaligned Load Word: pid=602 (login), tid=100042, pc=0xffffffff803ae898, badvaddr=0x401159
Unaligned Load Word: pid=602 (login), tid=100042, pc=0xffffffff803ae898, badvaddr=0x401155
Unaligned Load Word: pid=602 (login), tid=100042, pc=0xffffffff803ae898, badvaddr=0x401151

.. which makes it much easier to start figuring out what/where to fix.

The pc looks suss (it looks like it's in kernel space); I'll dig into that one next.

Tested:

* AR9331 SoC (Carambola2)

1 files changed, 27 insertions, 3 deletions

diff --git a/sys/mips/mips/trap.c b/sys/mips/mips/trap.c
index b193463..9467679 100644
--- a/sys/mips/mips/trap.c
+++ b/sys/mips/mips/trap.c
@@ -1660,11 +1660,25 @@ mips_unaligned_load_store(struct trapframe *frame, int mode, register_t addr, re
 }
 
 
+/*
+ * XXX TODO: SMP?
+ */
+static struct timeval unaligned_lasterr;
+static int unaligned_curerr;
+
+static int unaligned_pps_log_limit = 4;
+
+SYSCTL_INT(_machdep, OID_AUTO, unaligned_log_pps_limit, CTLFLAG_RWTUN,
+    &unaligned_pps_log_limit, 0,
+    "limit number of userland unaligned log messages per second");
+
 static int
 emulate_unaligned_access(struct trapframe *frame, int mode)
 {
 	register_t pc;
 	int access_type = 0;
+	struct thread *td = curthread;
+	struct proc *p = curproc;
 
 	pc = frame->pc + (DELAYBRANCH(frame->cause) ? 4 : 0);
 
@@ -1691,9 +1705,19 @@ emulate_unaligned_access(struct trapframe *frame, int mode)
 			else
 				frame->pc += 4;
 
-			log(LOG_INFO, "Unaligned %s: pc=%#jx, badvaddr=%#jx\n",
-			    access_name[access_type - 1], (intmax_t)pc,
-			    (intmax_t)frame->badvaddr);
+			if (ppsratecheck(&unaligned_lasterr,
+			    &unaligned_curerr, unaligned_pps_log_limit)) {
+				/* XXX TODO: keep global/tid/pid counters? */
+				log(LOG_INFO,
+				    "Unaligned %s: pid=%ld (%s), tid=%ld, "
+				    "pc=%#jx, badvaddr=%#jx\n",
+				    access_name[access_type - 1],
+				    (long) p->p_pid,
+				    p->p_comm,
+				    (long) td->td_tid,
+				    (intmax_t)pc,
+				    (intmax_t)frame->badvaddr);
+			}
 		}
 	}
 	return access_type;