⬢ DragonFlyBSD Kernel Audit
DF-5420 / instrument.diff
← back to finding ↓ download raw
--- a/sys/platform/pc64/x86_64/pmap_inval.c
+++ b/sys/platform/pc64/x86_64/pmap_inval.c
@@ -107,6 +107,65 @@
 #endif
 extern cpumask_t		smp_smurf_mask;
 #endif
+
+/*
+ * DF-5420 instrumentation (audit-only, never upstream).
+ * mode encodes: 0=shortcut-exit 9=full-exit 1x=slave-skip 2x=slave-quiesce
+ * 3x=slave-wait 4x=slave-invlpg 5x=orig-wait 6x=orig-exec 7x=orig-final
+ * 8x=publish, where x = originator cpu (n).
+ */
+#define DF5420_VA	0x0000200000000000UL
+struct df5420_ent {
+	uint64_t	tsc;
+	cpumask_t	arg1;
+	cpumask_t	arg2;
+	cpumask_t	arg3;
+	int		cpu;
+	int		mode;
+};
+static struct df5420_ent df5420_ring[32768];
+static volatile int df5420_idx;
+static int df5420_en;
+static int df5420_dumpvar;
+
+static __inline void
+df5420_log(int mode, cpumask_t a1, cpumask_t a2, cpumask_t a3)
+{
+	struct df5420_ent *e;
+	int i;
+
+	if (df5420_en == 0)
+		return;
+	i = atomic_fetchadd_int(&df5420_idx, 1) & 32767;
+	e = &df5420_ring[i];
+	e->tsc = rdtsc();
+	e->arg1 = a1;
+	e->arg2 = a2;
+	e->arg3 = a3;
+	e->cpu = mycpu->gd_cpuid;
+	e->mode = mode;
+}
+
+static int
+df5420_dump(SYSCTL_HANDLER_ARGS)
+{
+	int error, i, n;
+
+	error = sysctl_handle_int(oidp, &df5420_dumpvar, 0, req);
+	if (error || req->newptr == NULL)
+		return (error);
+	n = df5420_idx;
+	kprintf("DF5420 ring idx=%d\n", n);
+	for (i = n - 1; i >= n - 32768 && i >= 0; --i) {
+		struct df5420_ent *e = &df5420_ring[i & 32767];
+		kprintf("DF5420 [%d] tsc=%ju cpu=%d mode=%d "
+			"a1=%08jx a2=%08jx a3=%08jx\n",
+			i, (uintmax_t)e->tsc, e->cpu, e->mode,
+			e->arg1.ary[0], e->arg2.ary[0], e->arg3.ary[0]);
+	}
+	return (0);
+}
+
 static int pmap_inval_watchdog_print;	/* must always default off */
 static int pmap_inval_force_allcpus;
 static int pmap_inval_force_nonopt;
@@ -117,6 +176,10 @@
 	    &pmap_inval_force_allcpus, 0, "");
 SYSCTL_INT(_machdep, OID_AUTO, pmap_inval_force_nonopt, CTLFLAG_RW,
 	    &pmap_inval_force_nonopt, 0, "");
+SYSCTL_INT(_machdep, OID_AUTO, df5420_en, CTLFLAG_RW, &df5420_en, 0, "");
+SYSCTL_PROC(_machdep, OID_AUTO, df5420_dump,
+	    CTLTYPE_INT | CTLFLAG_RW, NULL, 0, df5420_dump, "I",
+	    "dump DF5420 trace ring");
 
 static void
 pmap_inval_init(pmap_t pmap)
@@ -267,6 +330,7 @@
 	pt_entry_t opte = 0;
 	int cpu = gd->gd_cpuid;
 	cpumask_t tmpmask;
+	cpumask_t df_pre, df_mask;
 	unsigned long rflags;
 
 	/*
@@ -275,12 +339,14 @@
 	 */
 	if (pmap == NULL)
 		pmap = kernel_pmap;
+	df_pre = pmap->pm_active;
 
 	/*
 	 * Shortcut single-cpu case if possible.
 	 */
 	if (CPUMASK_CMPMASKEQ(pmap->pm_active, gd->gd_cpumask) &&
 	    pmap_inval_force_nonopt == 0) {
+		cpumask_t pre_active = pmap->pm_active;
 		/*
 		 * Convert to invltlb if there are too many pages to
 		 * invlpg on.
@@ -316,6 +382,9 @@
 		}
 		if (pmap->pm_flags & PMAP_MULTI)
 			pmap_inval_done(pmap);
+		if (va == DF5420_VA && pmap != kernel_pmap)
+			df5420_log(0, pre_active, pmap->pm_active,
+				   gd->gd_cpumask);
 
 		return opte;
 	}
@@ -388,6 +457,7 @@
 		smp_smurf_idleinvlclr(&tmpmask);
 	CPUMASK_ORBIT(tmpmask, cpu);
 	info->mask = tmpmask;
+	df_mask = tmpmask;
 
 	/*
 	 * Command may start executing the moment 'done' is initialized,
@@ -405,6 +475,8 @@
 	cpu_disable_intr();
 
 	ATOMIC_CPUMASK_COPY(info->done, tmpmask);
+	if (va == DF5420_VA && pmap != kernel_pmap)
+		df5420_log(800 + cpu, info->mask, info->done, df_pre);
 	/* execution can begin here on other cpus due to races */
 
 	/*
@@ -418,6 +490,8 @@
 	smp_invlpg(&tmpmask);
 	opte = info->opte;
 	KKASSERT(info->mode == INVDONE);
+	if (va == DF5420_VA && pmap != kernel_pmap)
+		df5420_log(900 + cpu, df_pre, df_mask, info->done);
 
 	/*
 	 * Target cpus will be in their loop exiting concurrently with our
@@ -693,8 +767,12 @@
 		 *
 		 * A fence is needed once we detect the (not) done bit.
 		 */
-		if (!CPUMASK_TESTBIT(info->done, cpu))
+		if (!CPUMASK_TESTBIT(info->done, cpu)) {
+			if (info->va == DF5420_VA)
+				df5420_log(100 + n, info->mask, info->done,
+					   info->mask);
 			continue;
+		}
 		cpu_lfence();
 #ifdef LOOPRECOVER
 		if (toolong) {
@@ -731,6 +809,9 @@
 				 * Other cpus indicate to originator that they
 				 * are quiesced.
 				 */
+				if (info->va == DF5420_VA)
+					df5420_log(200 + n, info->mask,
+						   info->done, info->mask);
 				ATOMIC_CPUMASK_NANDBIT(info->mask, cpu);
 				loopme = 1;
 			} else if (info->ptep &&
@@ -739,6 +820,9 @@
 				 * Other cpu must wait for the originator (n)
 				 * to complete its command if ptep is not NULL.
 				 */
+				if (info->va == DF5420_VA)
+					df5420_log(300 + n, info->mask,
+						   info->done, info->mask);
 				loopme = 1;
 			} else {
 				/*
@@ -761,6 +845,9 @@
 						va += PAGE_SIZE;
 					}
 				}
+				if (info->va == DF5420_VA)
+					df5420_log(400 + n, info->mask,
+						   info->done, info->mask);
 				ATOMIC_CPUMASK_NANDBIT(info->done, cpu);
 				/* info invalid now */
 				/* loopme left alone */
@@ -770,6 +857,9 @@
 			 * Originator is waiting for other cpus
 			 */
 			if (CPUMASK_CMPMASKNEQ(info->mask, gd->gd_cpumask)) {
+				if (info->va == DF5420_VA)
+					df5420_log(500 + n, info->mask,
+						   info->done, info->mask);
 				/*
 				 * Originator waits for other cpus to enter
 				 * their loop (aka quiesce).
@@ -804,6 +894,9 @@
 				 * mask to allow other cpus to finish.
 				 */
 				KKASSERT(info->mode != INVDONE);
+				if (info->va == DF5420_VA)
+					df5420_log(600 + n, info->mask,
+						   info->done, info->mask);
 				if (info->mode == INVSTORE) {
 					if (info->ptep)
 						info->opte = atomic_swap_long(info->ptep, info->npte);
@@ -847,6 +940,9 @@
 			/* leave loopme alone */
 			/* other cpus may still be finishing up */
 			/* can't race originator since that's us */
+			if (info->va == DF5420_VA)
+				df5420_log(700 + n, info->mask, info->done,
+					   info->mask);
 			info->mode = INVDONE;
 			ATOMIC_CPUMASK_NANDBIT(info->done, cpu);
 		}