hwpmc: log name->pid, name->tid mappings

By logging all threads and processes 'pmc filter'
can now filter on process or thread name, relieving
the user of the burden of determining which tid or
pid was which when the sample was taken.

% pmc filter -T if_io_tqg -P nginx pmc.log pmc-iflib.log

% pmc filter -x -T idle pmc.log pmc-noidle.log

2 files changed, 145 insertions, 16 deletions

diff --git a/sys/dev/hwpmc/hwpmc_logging.c b/sys/dev/hwpmc/hwpmc_logging.c
index 482c91e46031..49996229480b 100644
--- a/sys/dev/hwpmc/hwpmc_logging.c
+++ b/sys/dev/hwpmc/hwpmc_logging.c
@@ -229,7 +229,7 @@ static void pmclog_loop(void *arg);
 static void pmclog_release(struct pmc_owner *po);
 static uint32_t *pmclog_reserve(struct pmc_owner *po, int length);
 static void pmclog_schedule_io(struct pmc_owner *po, int wakeup);
-static void pmclog_schedule_all(struct pmc_owner *po);
+static void pmclog_schedule_all(struct pmc_owner *po, int force);
 static void pmclog_stop_kthread(struct pmc_owner *po);
 
 /*
@@ -808,7 +808,7 @@ pmclog_deconfigure_log(struct pmc_owner *po)
  */
 
 int
-pmclog_flush(struct pmc_owner *po)
+pmclog_flush(struct pmc_owner *po, int force)
 {
 	int error;
 
@@ -832,7 +832,7 @@ pmclog_flush(struct pmc_owner *po)
 		goto error;
 	}
 
-	pmclog_schedule_all(po);
+	pmclog_schedule_all(po, force);
  error:
 	mtx_unlock(&pmc_kthread_mtx);
 
@@ -840,9 +840,8 @@ pmclog_flush(struct pmc_owner *po)
 }
 
 static void
-pmclog_schedule_one_cond(void *arg)
+pmclog_schedule_one_cond(struct pmc_owner *po, int force)
 {
-	struct pmc_owner *po = arg;
 	struct pmclog_buffer *plb;
 	int cpu;
 
@@ -851,7 +850,8 @@ pmclog_schedule_one_cond(void *arg)
 	/* tell hardclock not to run again */
 	if (PMC_CPU_HAS_SAMPLES(cpu))
 		PMC_CALL_HOOK_UNLOCKED(curthread, PMC_FN_DO_SAMPLES, NULL);
-	pmc_flush_samples(cpu);
+	if (force)
+		pmc_flush_samples(cpu);
 	plb = po->po_curbuf[cpu];
 	if (plb && plb->plb_ptr != plb->plb_base)
 		pmclog_schedule_io(po, 1);
@@ -859,7 +859,7 @@ pmclog_schedule_one_cond(void *arg)
 }
 
 static void
-pmclog_schedule_all(struct pmc_owner *po)
+pmclog_schedule_all(struct pmc_owner *po, int force)
 {
 	/*
 	 * Schedule the current buffer if any and not empty.
@@ -868,7 +868,7 @@ pmclog_schedule_all(struct pmc_owner *po)
 		thread_lock(curthread);
 		sched_bind(curthread, i);
 		thread_unlock(curthread);
-		pmclog_schedule_one_cond(po);
+		pmclog_schedule_one_cond(po, force);
 	}
 	thread_lock(curthread);
 	sched_unbind(curthread);
@@ -895,7 +895,7 @@ pmclog_close(struct pmc_owner *po)
 	/*
 	 * Schedule the current buffer.
 	 */
-	pmclog_schedule_all(po);
+	pmclog_schedule_all(po, 0);
 	wakeup_one(po);
 
 	mtx_unlock(&pmc_kthread_mtx);
@@ -1044,6 +1044,22 @@ pmclog_process_pmcdetach(struct pmc *pm, pid_t pid)
 	PMCLOG_DESPATCH_SYNC(po);
 }
 
+void
+pmclog_process_proccreate(struct pmc_owner *po, struct proc *p, int sync)
+{
+	if (sync) {
+		PMCLOG_RESERVE(po, PROC_CREATE, sizeof(struct pmclog_proccreate));
+		PMCLOG_EMIT32(p->p_pid);
+		PMCLOG_EMITSTRING(p->p_comm, MAXCOMLEN+1);
+		PMCLOG_DESPATCH_SYNC(po);
+	} else {
+		PMCLOG_RESERVE(po, PROC_CREATE, sizeof(struct pmclog_proccreate));
+		PMCLOG_EMIT32(p->p_pid);
+		PMCLOG_EMITSTRING(p->p_comm, MAXCOMLEN+1);
+		PMCLOG_DESPATCH(po);
+	}
+}
+
 /*
  * Log a context switch event to the log file.
  */
@@ -1079,14 +1095,13 @@ pmclog_process_procexec(struct pmc_owner *po, pmc_id_t pmid, pid_t pid,
 
 	pathlen   = strlen(path) + 1;	/* #bytes for the path */
 	recordlen = offsetof(struct pmclog_procexec, pl_pathname) + pathlen;
-
 	PMCLOG_RESERVE(po, PROCEXEC, recordlen);
 	PMCLOG_EMIT32(pid);
 	PMCLOG_EMIT32(pmid);
 	PMCLOG_EMIT32(0);
 	PMCLOG_EMITADDR(startaddr);
 	PMCLOG_EMITSTRING(path,pathlen);
-	PMCLOG_DESPATCH(po);
+	PMCLOG_DESPATCH_SYNC(po);
 }
 
 /*
@@ -1138,6 +1153,38 @@ pmclog_process_sysexit(struct pmc_owner *po, pid_t pid)
 	PMCLOG_DESPATCH(po);
 }
 
+void
+pmclog_process_threadcreate(struct pmc_owner *po, struct thread *td, int sync)
+{
+	struct proc *p;
+
+	p = td->td_proc;
+	if (sync) {
+		PMCLOG_RESERVE(po, THR_CREATE, sizeof(struct pmclog_threadcreate));
+		PMCLOG_EMIT32(td->td_tid);
+		PMCLOG_EMIT32(p->p_pid);
+		PMCLOG_EMIT32(0);
+		PMCLOG_EMITSTRING(td->td_name, MAXCOMLEN+1);
+		PMCLOG_DESPATCH_SYNC(po);
+	} else {
+		PMCLOG_RESERVE(po, THR_CREATE, sizeof(struct pmclog_threadcreate));
+		PMCLOG_EMIT32(td->td_tid);
+		PMCLOG_EMIT32(p->p_pid);
+		PMCLOG_EMIT32(0);
+		PMCLOG_EMITSTRING(td->td_name, MAXCOMLEN+1);
+		PMCLOG_DESPATCH(po);
+	}
+}
+
+void
+pmclog_process_threadexit(struct pmc_owner *po, struct thread *td)
+{
+
+	PMCLOG_RESERVE(po, THR_EXIT, sizeof(struct pmclog_threadexit));
+	PMCLOG_EMIT32(td->td_tid);
+	PMCLOG_DESPATCH(po);
+}
+
 /*
  * Write a user log entry.
  */
diff --git a/sys/dev/hwpmc/hwpmc_mod.c b/sys/dev/hwpmc/hwpmc_mod.c
index e9c47881894e..191f2554ee60 100644
--- a/sys/dev/hwpmc/hwpmc_mod.c
+++ b/sys/dev/hwpmc/hwpmc_mod.c
@@ -269,6 +269,11 @@ static int generic_switch_out(struct pmc_cpu *pc, struct pmc_process *pp);
 static struct pmc_mdep *pmc_generic_cpu_initialize(void);
 static void pmc_generic_cpu_finalize(struct pmc_mdep *md);
 static void pmc_post_callchain_callback(void);
+static void pmc_process_threadcreate(struct thread *td);
+static void pmc_process_threadexit(struct thread *td);
+static void pmc_process_proccreate(struct proc *p);
+static void pmc_process_allproc(struct pmc *pm);
+
 /*
  * Kernel tunables and sysctl(8) interface.
  */
@@ -2049,6 +2054,9 @@ const char *pmc_hooknames[] = {
 	"THR-CREATE",
 	"THR-EXIT",
 	"THR-USERRET",
+	"THR-CREATE-LOG",
+	"THR-EXIT-LOG",
+	"PROC-CREATE-LOG"
 };
 #endif
 
@@ -2225,6 +2233,10 @@ pmc_hook_handler(struct thread *td, int function, void *arg)
 		pmc_process_munmap(td, (struct pmckern_map_out *) arg);
 		break;
 
+	case PMC_FN_PROC_CREATE_LOG:
+		pmc_process_proccreate((struct proc *)arg);
+		break;
+
 	case PMC_FN_USER_CALLCHAIN:
 		/*
 		 * Record a call chain.
@@ -2270,14 +2282,22 @@ pmc_hook_handler(struct thread *td, int function, void *arg)
 
 	case PMC_FN_THR_CREATE:
 		pmc_process_thread_add(td);
+		pmc_process_threadcreate(td);
+		break;
+
+	case PMC_FN_THR_CREATE_LOG:
+		pmc_process_threadcreate(td);
 		break;
 
 	case PMC_FN_THR_EXIT:
 		KASSERT(td == curthread, ("[pmc,%d] td != curthread",
 		    __LINE__));
 		pmc_process_thread_delete(td);
+		pmc_process_threadexit(td);
+		break;
+	case PMC_FN_THR_EXIT_LOG:
+		pmc_process_threadexit(td);
 		break;
-
 	case PMC_FN_THR_USERRET:
 		KASSERT(td == curthread, ("[pmc,%d] td != curthread",
 		    __LINE__));
@@ -2697,9 +2717,9 @@ pmc_wait_for_pmc_idle(struct pmc *pm)
 	 * Loop (with a forced context switch) till the PMC's runcount
 	 * comes down to zero.
 	 */
-	pmclog_flush(pm->pm_owner);
+	pmclog_flush(pm->pm_owner, 1);
 	while (counter_u64_fetch(pm->pm_runcount) > 0) {
-		pmclog_flush(pm->pm_owner);
+		pmclog_flush(pm->pm_owner, 1);
 #ifdef HWPMC_DEBUG
 		maxloop--;
 		KASSERT(maxloop > 0,
@@ -3439,7 +3459,7 @@ pmc_syscall_handler(struct thread *td, void *syscall_args)
 			break;
 		}
 
-		error = pmclog_flush(po);
+		error = pmclog_flush(po, 0);
 	}
 	break;
 
@@ -4015,6 +4035,8 @@ pmc_syscall_handler(struct thread *td, void *syscall_args)
 			pmc = NULL;
 			break;
 		}
+		if (mode == PMC_MODE_SS)
+			pmc_process_allproc(pmc);
 
 		/*
 		 * Return the allocated index.
@@ -5216,8 +5238,10 @@ pmc_process_fork(void *arg __unused, struct proc *p1, struct proc *newproc,
 	 */
 	epoch_enter_preempt(global_epoch_preempt);
 	CK_LIST_FOREACH(po, &pmc_ss_owners, po_ssnext)
-	    if (po->po_flags & PMC_PO_OWNS_LOGFILE)
+	    if (po->po_flags & PMC_PO_OWNS_LOGFILE) {
 		    pmclog_process_procfork(po, p1->p_pid, newproc->p_pid);
+			pmclog_process_proccreate(po, newproc, 1);
+		}
 	epoch_exit_preempt(global_epoch_preempt);
 
 	if (!is_using_hwpmcs)
@@ -5280,6 +5304,64 @@ pmc_process_fork(void *arg __unused, struct proc *p1, struct proc *newproc,
 }
 
 static void
+pmc_process_threadcreate(struct thread *td)
+{
+	struct pmc_owner *po;
+
+	epoch_enter_preempt(global_epoch_preempt);
+	CK_LIST_FOREACH(po, &pmc_ss_owners, po_ssnext)
+	    if (po->po_flags & PMC_PO_OWNS_LOGFILE)
+			pmclog_process_threadcreate(po, td, 1);
+	epoch_exit_preempt(global_epoch_preempt);
+}
+
+static void
+pmc_process_threadexit(struct thread *td)
+{
+	struct pmc_owner *po;
+
+	epoch_enter_preempt(global_epoch_preempt);
+	CK_LIST_FOREACH(po, &pmc_ss_owners, po_ssnext)
+	    if (po->po_flags & PMC_PO_OWNS_LOGFILE)
+			pmclog_process_threadexit(po, td);
+	epoch_exit_preempt(global_epoch_preempt);
+}
+
+static void
+pmc_process_proccreate(struct proc *p)
+{
+	struct pmc_owner *po;
+
+	epoch_enter_preempt(global_epoch_preempt);
+	CK_LIST_FOREACH(po, &pmc_ss_owners, po_ssnext)
+	    if (po->po_flags & PMC_PO_OWNS_LOGFILE)
+			pmclog_process_proccreate(po, p, 1 /* sync */);
+	epoch_exit_preempt(global_epoch_preempt);
+}
+
+static void
+pmc_process_allproc(struct pmc *pm)
+{
+	struct pmc_owner *po;
+	struct thread *td;
+	struct proc *p;
+
+	po = pm->pm_owner;
+	if ((po->po_flags & PMC_PO_OWNS_LOGFILE) == 0)
+		return;
+	sx_slock(&allproc_lock);
+	FOREACH_PROC_IN_SYSTEM(p) {
+		pmclog_process_proccreate(po, p, 0 /* sync */);
+		PROC_LOCK(p);
+		FOREACH_THREAD_IN_PROC(p, td)
+			pmclog_process_threadcreate(po, td, 0 /* sync */);
+		PROC_UNLOCK(p);
+	}
+	sx_sunlock(&allproc_lock);
+	pmclog_flush(po, 0);
+}
+
+static void
 pmc_kld_load(void *arg __unused, linker_file_t lf)
 {
 	struct pmc_owner *po;