Add new ktrace records for the start and end of VM faults. This gives

a pair of records similar to syscall entry and return that a user can
use to determine how long page faults take.  The new ktrace records are
enabled via the 'p' trace type, and are enabled in the default set of
trace points.

Reviewed by:	kib
MFC after:	2 weeks

9 files changed, 148 insertions, 6 deletions

diff --git a/sys/kern/kern_ktrace.c b/sys/kern/kern_ktrace.c
index 2c6e36c..363b8b8 100644
--- a/sys/kern/kern_ktrace.c
+++ b/sys/kern/kern_ktrace.c
@@ -101,6 +101,8 @@ struct ktr_request {
 		struct	ktr_genio ktr_genio;
 		struct	ktr_psig ktr_psig;
 		struct	ktr_csw ktr_csw;
+		struct	ktr_fault ktr_fault;
+		struct	ktr_faultend ktr_faultend;
 	} ktr_data;
 	STAILQ_ENTRY(ktr_request) ktr_list;
 };
@@ -119,6 +121,8 @@ static int data_lengths[] = {
 	sizeof(struct ktr_proc_ctor),		/* KTR_PROCCTOR */
 	0,					/* KTR_PROCDTOR */
 	sizeof(struct ktr_cap_fail),		/* KTR_CAPFAIL */
+	sizeof(struct ktr_fault),		/* KTR_FAULT */
+	sizeof(struct ktr_faultend),		/* KTR_FAULTEND */
 };
 
 static STAILQ_HEAD(, ktr_request) ktr_free;
@@ -791,6 +795,42 @@ ktrcapfail(type, needed, held)
 	ktr_enqueuerequest(td, req);
 	ktrace_exit(td);
 }
+
+void
+ktrfault(vaddr, type)
+	vm_offset_t vaddr;
+	int type;
+{
+	struct thread *td = curthread;
+	struct ktr_request *req;
+	struct ktr_fault *kf;
+
+	req = ktr_getrequest(KTR_FAULT);
+	if (req == NULL)
+		return;
+	kf = &req->ktr_data.ktr_fault;
+	kf->vaddr = vaddr;
+	kf->type = type;
+	ktr_enqueuerequest(td, req);
+	ktrace_exit(td);
+}
+
+void
+ktrfaultend(result)
+	int result;
+{
+	struct thread *td = curthread;
+	struct ktr_request *req;
+	struct ktr_faultend *kf;
+
+	req = ktr_getrequest(KTR_FAULTEND);
+	if (req == NULL)
+		return;
+	kf = &req->ktr_data.ktr_faultend;
+	kf->result = result;
+	ktr_enqueuerequest(td, req);
+	ktrace_exit(td);
+}
 #endif /* KTRACE */
 
 /* Interface and common routines */
diff --git a/sys/sys/ktrace.h b/sys/sys/ktrace.h
index d537c1b..68008e2 100644
--- a/sys/sys/ktrace.h
+++ b/sys/sys/ktrace.h
@@ -194,6 +194,23 @@ struct ktr_cap_fail {
 };
 
 /*
+ * KTR_FAULT - page fault record
+ */
+#define KTR_FAULT	13
+struct ktr_fault {
+	vm_offset_t vaddr;
+	int type;
+};
+
+/*
+ * KTR_FAULTEND - end of page fault record
+ */
+#define KTR_FAULTEND	14
+struct ktr_faultend {
+	int result;
+};
+
+/*
  * KTR_DROP - If this bit is set in ktr_type, then at least one event
  * between the previous record and this record was dropped.
  */
@@ -215,6 +232,8 @@ struct ktr_cap_fail {
 #define KTRFAC_PROCCTOR	(1<<KTR_PROCCTOR)
 #define KTRFAC_PROCDTOR	(1<<KTR_PROCDTOR)
 #define KTRFAC_CAPFAIL	(1<<KTR_CAPFAIL)
+#define KTRFAC_FAULT	(1<<KTR_FAULT)
+#define KTRFAC_FAULTEND	(1<<KTR_FAULTEND)
 
 /*
  * trace flags (also in p_traceflags)
@@ -227,6 +246,8 @@ struct ktr_cap_fail {
 void	ktrnamei(char *);
 void	ktrcsw(int, int);
 void	ktrpsig(int, sig_t, sigset_t *, int);
+void	ktrfault(vm_offset_t, int);
+void	ktrfaultend(int);
 void	ktrgenio(int, enum uio_rw, struct uio *, int);
 void	ktrsyscall(int, int narg, register_t args[]);
 void	ktrsysctl(int *name, u_int namelen);
diff --git a/sys/vm/vm_fault.c b/sys/vm/vm_fault.c
index 8477c35..b1a0d0c 100644
--- a/sys/vm/vm_fault.c
+++ b/sys/vm/vm_fault.c
@@ -74,6 +74,7 @@
 #include <sys/cdefs.h>
 __FBSDID("$FreeBSD$");
 
+#include "opt_ktrace.h"
 #include "opt_vm.h"
 
 #include <sys/param.h>
@@ -86,6 +87,9 @@ __FBSDID("$FreeBSD$");
 #include <sys/sysctl.h>
 #include <sys/vmmeter.h>
 #include <sys/vnode.h>
+#ifdef KTRACE
+#include <sys/ktrace.h>
+#endif
 
 #include <vm/vm.h>
 #include <vm/vm_param.h>
@@ -208,10 +212,23 @@ int
 vm_fault(vm_map_t map, vm_offset_t vaddr, vm_prot_t fault_type,
     int fault_flags)
 {
+	struct thread *td;
+	int result;
 
-	if ((curthread->td_pflags & TDP_NOFAULTING) != 0)
+	td = curthread;
+	if ((td->td_pflags & TDP_NOFAULTING) != 0)
 		return (KERN_PROTECTION_FAILURE);
-	return (vm_fault_hold(map, vaddr, fault_type, fault_flags, NULL));
+#ifdef KTRACE
+	if (map != kernel_map && KTRPOINT(td, KTR_FAULT))
+		ktrfault(vaddr, fault_type);
+#endif
+	result = vm_fault_hold(map, trunc_page(vaddr), fault_type, fault_flags,
+	    NULL);
+#ifdef KTRACE
+	if (map != kernel_map && KTRPOINT(td, KTR_FAULTEND))
+		ktrfaultend(result);
+#endif
+	return (result);
 }
 
 int
diff --git a/usr.bin/kdump/kdump.1 b/usr.bin/kdump/kdump.1
index 4e60137..c03985e 100644
--- a/usr.bin/kdump/kdump.1
+++ b/usr.bin/kdump/kdump.1
@@ -28,7 +28,7 @@
 .\"	@(#)kdump.1	8.1 (Berkeley) 6/6/93
 .\" $FreeBSD$
 .\"
-.Dd February 23, 2008
+.Dd April 5, 2012
 .Dt KDUMP 1
 .Os
 .Sh NAME
@@ -171,6 +171,8 @@ The possible operations are:
 .It Li USER Ta data from user process Ta the data
 .It Li STRU Ta various syscalls Ta structure
 .It Li SCTL Ta Xr sysctl 3 requests Ta MIB name
+.It Li PFLT Ta enter page fault Ta fault address and type
+.It Li PRET Ta return from page fault Ta fault result
 .El
 .Sh SEE ALSO
 .Xr ktrace 1
diff --git a/usr.bin/kdump/kdump.c b/usr.bin/kdump/kdump.c
index 2756778..4d8e109 100644
--- a/usr.bin/kdump/kdump.c
+++ b/usr.bin/kdump/kdump.c
@@ -102,6 +102,8 @@ void ktrsockaddr(struct sockaddr *);
 void ktrstat(struct stat *);
 void ktrstruct(char *, size_t);
 void ktrcapfail(struct ktr_cap_fail *);
+void ktrfault(struct ktr_fault *);
+void ktrfaultend(struct ktr_faultend *);
 void usage(void);
 void ioctlname(unsigned long, int);
 
@@ -306,6 +308,13 @@ main(int argc, char *argv[])
 			break;
 		case KTR_CAPFAIL:
 			ktrcapfail((struct ktr_cap_fail *)m);
+			break;
+		case KTR_FAULT:
+			ktrfault((struct ktr_fault *)m);
+			break;
+		case KTR_FAULTEND:
+			ktrfaultend((struct ktr_faultend *)m);
+			break;
 		default:
 			printf("\n");
 			break;
@@ -448,6 +457,12 @@ dumpheader(struct ktr_header *kth)
 	case KTR_CAPFAIL:
 		type = "CAP ";
 		break;
+	case KTR_FAULT:
+		type = "PFLT";
+		break;
+	case KTR_FAULTEND:
+		type = "PRET";
+		break;
 	default:
 		sprintf(unknown, "UNKNOWN(%d)", kth->ktr_type);
 		type = unknown;
@@ -1631,6 +1646,24 @@ ktrcapfail(struct ktr_cap_fail *ktr)
 		capname((intmax_t)ktr->cap_held);
 		break;
 	}
+	printf("\n");
+}
+
+void
+ktrfault(struct ktr_fault *ktr)
+{
+
+	printf("0x%jx ", ktr->vaddr);
+	vmprotname(ktr->type);
+	printf("\n");
+}
+
+void
+ktrfaultend(struct ktr_faultend *ktr)
+{
+
+	vmresultname(ktr->result);
+	printf("\n");
 }
 
 #if defined(__amd64__) || defined(__i386__)
diff --git a/usr.bin/kdump/mksubr b/usr.bin/kdump/mksubr
index 99dd80f..bc466d5 100644
--- a/usr.bin/kdump/mksubr
+++ b/usr.bin/kdump/mksubr
@@ -187,6 +187,8 @@ cat <<_EOF_
 #include <nfsserver/nfs.h>
 #include <ufs/ufs/quota.h>
 #include <sys/capability.h>
+#include <vm/vm.h>
+#include <vm/vm_param.h>
 
 #include "kdump_subr.h"
 
@@ -334,6 +336,26 @@ sockoptlevelname(int level, int decimal)
 	}
 }
 
+/*
+ * MANUAL
+ *
+ * Used for page fault type.  Cannot use auto_or_type since the macro
+ * values contain a cast.  Also, VM_PROT_NONE has to be handled specially.
+ */
+void
+vmprotname (int type)
+{
+	int	or = 0;
+
+	if (type == VM_PROT_NONE) {
+		(void)printf("VM_PROT_NONE");
+		return;
+	}
+	if_print_or(type, VM_PROT_READ, or);
+	if_print_or(type, VM_PROT_WRITE, or);
+	if_print_or(type, VM_PROT_EXECUTE, or);
+	if_print_or(type, VM_PROT_COPY, or);
+}
 _EOF_
 
 auto_or_type     "accessmodename"      "[A-Z]_OK[[:space:]]+0?x?[0-9A-Fa-f]+"         "sys/unistd.h"
@@ -373,6 +395,7 @@ auto_if_type     "sockipprotoname"     "IPPROTO_[[:alnum:]]+[[:space:]]+"
 auto_switch_type "sockoptname"         "SO_[A-Z]+[[:space:]]+0x[0-9]+"                "sys/socket.h"
 auto_switch_type "socktypename"        "SOCK_[A-Z]+[[:space:]]+[1-9]+[0-9]*"          "sys/socket.h"
 auto_or_type     "thrcreateflagsname"  "THR_[A-Z]+[[:space:]]+0x[0-9]+"               "sys/thr.h"
+auto_switch_type "vmresultname"        "KERN_[A-Z]+[[:space:]]+[0-9]+"                "vm/vm_param.h"
 auto_or_type     "wait4optname"        "W[A-Z]+[[:space:]]+[0-9]+"                    "sys/wait.h"
 auto_switch_type "whencename"          "SEEK_[A-Z]+[[:space:]]+[0-9]+"                "sys/unistd.h"
 
diff --git a/usr.bin/ktrace/ktrace.1 b/usr.bin/ktrace/ktrace.1
index 86f23ef..28a5f7a 100644
--- a/usr.bin/ktrace/ktrace.1
+++ b/usr.bin/ktrace/ktrace.1
@@ -28,7 +28,7 @@
 .\"	@(#)ktrace.1	8.1 (Berkeley) 6/6/93
 .\" $FreeBSD$
 .\"
-.Dd October 10, 2011
+.Dd April 5, 2012
 .Dt KTRACE 1
 .Os
 .Sh NAME
@@ -108,6 +108,8 @@ The following table equates the letters with the tracepoints:
 .Bl -tag -width flag -compact
 .It Cm c
 trace system calls
+.It Cm f
+trace page faults
 .It Cm i
 trace
 .Tn I/O
@@ -129,7 +131,7 @@ trace
 requests
 .It Cm +
 trace the default set of trace points -
-.Cm c , i , n , p , s , t , u , y
+.Cm c , f , i , n , p , s , t , u , y
 .El
 .It Ar command
 Execute
diff --git a/usr.bin/ktrace/ktrace.h b/usr.bin/ktrace/ktrace.h
index e4e4dbf..220eb83 100644
--- a/usr.bin/ktrace/ktrace.h
+++ b/usr.bin/ktrace/ktrace.h
@@ -32,7 +32,8 @@
 
 #define DEF_POINTS (KTRFAC_SYSCALL | KTRFAC_SYSRET | KTRFAC_NAMEI | \
 		    KTRFAC_GENIO | KTRFAC_PSIG | KTRFAC_USER | \
-		    KTRFAC_STRUCT | KTRFAC_SYSCTL | KTRFAC_CAPFAIL)
+		    KTRFAC_STRUCT | KTRFAC_SYSCTL | KTRFAC_CAPFAIL | \
+		    KTRFAC_FAULT | KTRFAC_FAULTEND)
 
 #define PROC_ABI_POINTS (KTRFAC_PROCCTOR | KTRFAC_PROCDTOR)
 
diff --git a/usr.bin/ktrace/subr.c b/usr.bin/ktrace/subr.c
index 5051de8..eacd44c 100644
--- a/usr.bin/ktrace/subr.c
+++ b/usr.bin/ktrace/subr.c
@@ -64,6 +64,9 @@ getpoints(char *s)
 		case 'i':
 			facs |= KTRFAC_GENIO;
 			break;
+		case 'f':
+			facs |= KTRFAC_FAULT | KTRFAC_FAULTEND;
+			break;
 		case 'n':
 			facs |= KTRFAC_NAMEI;
 			break;