From owner-svn-src-all@FreeBSD.ORG Mon May 25 22:13:24 2015 Return-Path: Delivered-To: svn-src-all@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 29E14856; Mon, 25 May 2015 22:13:24 +0000 (UTC) (envelope-from jhb@FreeBSD.org) Received: from svn.freebsd.org (svn.freebsd.org [IPv6:2001:1900:2254:2068::e6a:0]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 1660ACD9; Mon, 25 May 2015 22:13:24 +0000 (UTC) (envelope-from jhb@FreeBSD.org) Received: from svn.freebsd.org ([127.0.1.70]) by svn.freebsd.org (8.14.9/8.14.9) with ESMTP id t4PMDNx7099065; Mon, 25 May 2015 22:13:23 GMT (envelope-from jhb@FreeBSD.org) Received: (from jhb@localhost) by svn.freebsd.org (8.14.9/8.14.9/Submit) id t4PMDMLa099058; Mon, 25 May 2015 22:13:22 GMT (envelope-from jhb@FreeBSD.org) Message-Id: <201505252213.t4PMDMLa099058@svn.freebsd.org> X-Authentication-Warning: svn.freebsd.org: jhb set sender to jhb@FreeBSD.org using -f From: John Baldwin Date: Mon, 25 May 2015 22:13:22 +0000 (UTC) To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: svn commit: r283546 - in head/sys: kern sys X-SVN-Group: head MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-BeenThere: svn-src-all@freebsd.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: "SVN commit messages for the entire src tree \(except for " user" and " projects" \)" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 25 May 2015 22:13:24 -0000 Author: jhb Date: Mon May 25 22:13:22 2015 New Revision: 283546 URL: https://svnweb.freebsd.org/changeset/base/283546 Log: Add KTR tracing for some MI ptrace events. Differential Revision: https://reviews.freebsd.org/D2643 Reviewed by: kib Modified: head/sys/kern/kern_exit.c head/sys/kern/kern_fork.c head/sys/kern/kern_sig.c head/sys/kern/sys_process.c head/sys/sys/ktr_class.h Modified: head/sys/kern/kern_exit.c ============================================================================== --- head/sys/kern/kern_exit.c Mon May 25 22:12:30 2015 (r283545) +++ head/sys/kern/kern_exit.c Mon May 25 22:13:22 2015 (r283546) @@ -525,6 +525,8 @@ exit1(struct thread *td, int rv) */ while ((q = LIST_FIRST(&p->p_orphans)) != NULL) { PROC_LOCK(q); + CTR2(KTR_PTRACE, "exit: pid %d, clearing orphan %d", p->p_pid, + q->p_pid); clear_orphan(q); PROC_UNLOCK(q); } @@ -857,6 +859,9 @@ proc_reap(struct thread *td, struct proc t = proc_realparent(p); PROC_LOCK(t); PROC_LOCK(p); + CTR2(KTR_PTRACE, + "wait: traced child %d moved back to parent %d", p->p_pid, + t->p_pid); proc_reparent(p, t); p->p_oppid = 0; PROC_UNLOCK(p); @@ -1216,6 +1221,10 @@ loop: PROC_UNLOCK(q); } + CTR4(KTR_PTRACE, + "wait: returning trapped pid %d status %#x (xstat %d) xthread %d", + p->p_pid, W_STOPCODE(p->p_xstat), p->p_xstat, + p->p_xthread != NULL ? p->p_xthread->td_tid : -1); PROC_UNLOCK(p); return (0); } Modified: head/sys/kern/kern_fork.c ============================================================================== --- head/sys/kern/kern_fork.c Mon May 25 22:12:30 2015 (r283545) +++ head/sys/kern/kern_fork.c Mon May 25 22:13:22 2015 (r283546) @@ -1035,6 +1035,9 @@ fork_return(struct thread *td, struct tr dbg = p->p_pptr->p_pptr; p->p_flag |= P_TRACED; p->p_oppid = p->p_pptr->p_pid; + CTR2(KTR_PTRACE, + "fork_return: attaching to new child pid %d: oppid %d", + p->p_pid, p->p_oppid); proc_reparent(p, dbg); sx_xunlock(&proctree_lock); td->td_dbgflags |= TDB_CHILD; Modified: head/sys/kern/kern_sig.c ============================================================================== --- head/sys/kern/kern_sig.c Mon May 25 22:12:30 2015 (r283545) +++ head/sys/kern/kern_sig.c Mon May 25 22:13:22 2015 (r283546) @@ -2478,6 +2478,8 @@ ptracestop(struct thread *td, int sig) td->td_dbgflags |= TDB_XSIG; td->td_xsig = sig; + CTR4(KTR_PTRACE, "ptracestop: tid %d (pid %d) flags %#x sig %d", + td->td_tid, p->p_pid, td->td_dbgflags, sig); PROC_SLOCK(p); while ((p->p_flag & P_TRACED) && (td->td_dbgflags & TDB_XSIG)) { if (p->p_flag & P_SINGLE_EXIT) { Modified: head/sys/kern/sys_process.c ============================================================================== --- head/sys/kern/sys_process.c Mon May 25 22:12:30 2015 (r283545) +++ head/sys/kern/sys_process.c Mon May 25 22:13:22 2015 (r283546) @@ -432,6 +432,9 @@ ptrace_vm_entry(struct thread *td, struc free(freepath, M_TEMP); } } + if (error == 0) + CTR3(KTR_PTRACE, "PT_VM_ENTRY: pid %d, entry %d, start %p", + p->p_pid, pve->pve_entry, pve->pve_start); return (error); } @@ -826,6 +829,7 @@ kern_ptrace(struct thread *td, int req, if (p->p_flag & P_PPWAIT) p->p_flag |= P_PPTRACE; p->p_oppid = p->p_pptr->p_pid; + CTR1(KTR_PTRACE, "PT_TRACE_ME: pid %d", p->p_pid); break; case PT_ATTACH: @@ -845,17 +849,25 @@ kern_ptrace(struct thread *td, int req, proc_reparent(p, td->td_proc); } data = SIGSTOP; + CTR2(KTR_PTRACE, "PT_ATTACH: pid %d, oppid %d", p->p_pid, + p->p_oppid); goto sendsig; /* in PT_CONTINUE below */ case PT_CLEARSTEP: + CTR2(KTR_PTRACE, "PT_CLEARSTEP: tid %d (pid %d)", td2->td_tid, + p->p_pid); error = ptrace_clear_single_step(td2); break; case PT_SETSTEP: + CTR2(KTR_PTRACE, "PT_SETSTEP: tid %d (pid %d)", td2->td_tid, + p->p_pid); error = ptrace_single_step(td2); break; case PT_SUSPEND: + CTR2(KTR_PTRACE, "PT_SUSPEND: tid %d (pid %d)", td2->td_tid, + p->p_pid); td2->td_dbgflags |= TDB_SUSPEND; thread_lock(td2); td2->td_flags |= TDF_NEEDSUSPCHK; @@ -863,10 +875,15 @@ kern_ptrace(struct thread *td, int req, break; case PT_RESUME: + CTR2(KTR_PTRACE, "PT_RESUME: tid %d (pid %d)", td2->td_tid, + p->p_pid); td2->td_dbgflags &= ~TDB_SUSPEND; break; case PT_FOLLOW_FORK: + CTR3(KTR_PTRACE, "PT_FOLLOW_FORK: pid %d %s -> %s", p->p_pid, + p->p_flag & P_FOLLOWFORK ? "enabled" : "disabled", + data ? "enabled" : "disabled"); if (data) p->p_flag |= P_FOLLOWFORK; else @@ -887,6 +904,8 @@ kern_ptrace(struct thread *td, int req, switch (req) { case PT_STEP: + CTR2(KTR_PTRACE, "PT_STEP: tid %d (pid %d)", + td2->td_tid, p->p_pid); error = ptrace_single_step(td2); if (error) goto out; @@ -904,12 +923,25 @@ kern_ptrace(struct thread *td, int req, switch (req) { case PT_TO_SCE: p->p_stops |= S_PT_SCE; + CTR2(KTR_PTRACE, + "PT_TO_SCE: pid %d, stops = %#x", p->p_pid, + p->p_stops); break; case PT_TO_SCX: p->p_stops |= S_PT_SCX; + CTR2(KTR_PTRACE, + "PT_TO_SCX: pid %d, stops = %#x", p->p_pid, + p->p_stops); break; case PT_SYSCALL: p->p_stops |= S_PT_SCE | S_PT_SCX; + CTR2(KTR_PTRACE, + "PT_SYSCALL: pid %d, stops = %#x", p->p_pid, + p->p_stops); + break; + case PT_CONTINUE: + CTR1(KTR_PTRACE, + "PT_CONTINUE: pid %d", p->p_pid); break; } break; @@ -924,7 +956,11 @@ kern_ptrace(struct thread *td, int req, proc_reparent(p, pp); if (pp == initproc) p->p_sigparent = SIGCHLD; - } + CTR2(KTR_PTRACE, + "PT_DETACH: pid %d reparented to pid %d", + p->p_pid, pp->p_pid); + } else + CTR1(KTR_PTRACE, "PT_DETACH: pid %d", p->p_pid); p->p_oppid = 0; p->p_flag &= ~(P_TRACED | P_WAITED | P_FOLLOWFORK); @@ -1001,6 +1037,14 @@ kern_ptrace(struct thread *td, int req, } if (!write) td->td_retval[0] = tmp; + if (error == 0) { + if (write) + CTR3(KTR_PTRACE, "PT_WRITE: pid %d: %p <= %#x", + p->p_pid, addr, data); + else + CTR3(KTR_PTRACE, "PT_READ: pid %d: %p >= %#x", + p->p_pid, addr, tmp); + } PROC_LOCK(p); break; @@ -1033,10 +1077,14 @@ kern_ptrace(struct thread *td, int req, switch (tmp) { case PIOD_READ_D: case PIOD_READ_I: + CTR3(KTR_PTRACE, "PT_IO: pid %d: READ (%p, %#x)", + p->p_pid, (uintptr_t)uio.uio_offset, uio.uio_resid); uio.uio_rw = UIO_READ; break; case PIOD_WRITE_D: case PIOD_WRITE_I: + CTR3(KTR_PTRACE, "PT_IO: pid %d: WRITE (%p, %#x)", + p->p_pid, (uintptr_t)uio.uio_offset, uio.uio_resid); td2->td_dbgflags |= TDB_USERWR; uio.uio_rw = UIO_WRITE; break; @@ -1056,33 +1104,46 @@ kern_ptrace(struct thread *td, int req, break; case PT_KILL: + CTR1(KTR_PTRACE, "PT_KILL: pid %d", p->p_pid); data = SIGKILL; goto sendsig; /* in PT_CONTINUE above */ case PT_SETREGS: + CTR2(KTR_PTRACE, "PT_SETREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); td2->td_dbgflags |= TDB_USERWR; error = PROC_WRITE(regs, td2, addr); break; case PT_GETREGS: + CTR2(KTR_PTRACE, "PT_GETREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); error = PROC_READ(regs, td2, addr); break; case PT_SETFPREGS: + CTR2(KTR_PTRACE, "PT_SETFPREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); td2->td_dbgflags |= TDB_USERWR; error = PROC_WRITE(fpregs, td2, addr); break; case PT_GETFPREGS: + CTR2(KTR_PTRACE, "PT_GETFPREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); error = PROC_READ(fpregs, td2, addr); break; case PT_SETDBREGS: + CTR2(KTR_PTRACE, "PT_SETDBREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); td2->td_dbgflags |= TDB_USERWR; error = PROC_WRITE(dbregs, td2, addr); break; case PT_GETDBREGS: + CTR2(KTR_PTRACE, "PT_GETDBREGS: tid %d (pid %d)", td2->td_tid, + p->p_pid); error = PROC_READ(dbregs, td2, addr); break; @@ -1145,13 +1206,21 @@ kern_ptrace(struct thread *td, int req, if (wrap32) ptrace_lwpinfo_to32(pl, pl32); #endif + CTR5(KTR_PTRACE, + "PT_LWPINFO: tid %d (pid %d) event %d flags %#x child pid %d", + td2->td_tid, p->p_pid, pl->pl_event, pl->pl_flags, + pl->pl_child_pid); break; case PT_GETNUMLWPS: + CTR2(KTR_PTRACE, "PT_GETNUMLWPS: pid %d: %d threads", p->p_pid, + p->p_numthreads); td->td_retval[0] = p->p_numthreads; break; case PT_GETLWPLIST: + CTR3(KTR_PTRACE, "PT_GETLWPLIST: pid %d: data %d, actual %d", + p->p_pid, data, p->p_numthreads); if (data <= 0) { error = EINVAL; break; @@ -1175,6 +1244,8 @@ kern_ptrace(struct thread *td, int req, break; case PT_VM_TIMESTAMP: + CTR2(KTR_PTRACE, "PT_VM_TIMESTAMP: pid %d: timestamp %d", + p->p_pid, p->p_vmspace->vm_map.timestamp); td->td_retval[0] = p->p_vmspace->vm_map.timestamp; break; @@ -1225,6 +1296,8 @@ stopevent(struct proc *p, unsigned int e PROC_LOCK_ASSERT(p, MA_OWNED); p->p_step = 1; + CTR3(KTR_PTRACE, "stopevent: pid %d event %u val %u", p->p_pid, event, + val); do { p->p_xstat = val; p->p_xthread = NULL; Modified: head/sys/sys/ktr_class.h ============================================================================== --- head/sys/sys/ktr_class.h Mon May 25 22:12:30 2015 (r283545) +++ head/sys/sys/ktr_class.h Mon May 25 22:13:22 2015 (r283546) @@ -71,7 +71,8 @@ #define KTR_INET6 0x10000000 /* IPv6 stack */ #define KTR_SCHED 0x20000000 /* Machine parsed sched info. */ #define KTR_BUF 0x40000000 /* Buffer cache */ -#define KTR_ALL 0x7fffffff +#define KTR_PTRACE 0x80000000 /* Process debugging. */ +#define KTR_ALL 0xffffffff /* KTR trace classes to compile in */ #ifdef KTR