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)
This commit is contained in:
Adrian Chadd 2015-11-02 03:36:15 +00:00
parent aaca704590
commit d24766cc51

View File

@ -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;