Monday, November 10, 2008

DTrace Probing 0.2

What a way to cut it down to the wire.

After about 2 weeks of finishing my job at the Country Club, and with 1 week left in the project. I get this email from Vladimir Vukicevic from Mozilla.

Whoops, just now save this mail when dave pointed it out. What I can
offer as an immediate take is a patch that jonas and I put together for
basically manual probing of a few things. It's not complete, but it'll
be a start.

http://people.mozilla.com/~vladimir/misc/debug-appshell.patch

Basically look at all the printfs; they time certain things, and we'd
probably want probes at the start and end (basically where the timings
start and end). This covers the main chunks of reflow, parsing, and
event handling.

I'd like to see proposed names for all the probes and their location;
I'd suggest xxxxx.start and xxxxx.end. For example, in nsThread.cpp,
the patch has:

diff --git a/xpcom/threads/nsThread.cpp b/xpcom/threads/nsThread.cpp
--- a/xpcom/threads/nsThread.cpp
+++ b/xpcom/threads/nsThread.cpp
@@ -506,9 +506,27 @@ nsThread::ProcessNextEvent(PRBool mayWai

if (event) {
LOG(("THRD(%p) running [%p]\n", this, event.get()));
+
+ PRBool isMainThread = NS_IsMainThread();
+ if (isMainThread)
+ printf ("{");
+
+ PRIntervalTime t0 = PR_IntervalNow();
+
++mRunningEvent;
event->Run();
--mRunningEvent;
+
+ PRIntervalTime t1 = PR_IntervalNow();
+
+ PRUint32 td = PR_IntervalToMilliseconds(t1 - t0);
+ if (isMainThread) {
+ if (td > 100) {
+ printf ("-E(0x%08x,%d)", (unsigned int) (void*) event.get(), td);
+ }
+ printf ("}");
+ }
+
} else if (mayWait) {
NS_ASSERTION(ShuttingDown(), "This should only happen when
shutting down");
rv = NS_ERROR_UNEXPECTED;


So we should have an nsthread event processing start probe at the t0 =
PR_IntervalNow(); for args, initially let's pass down the thread ID and
whether the thread is the main thread or not (or actually, let's just
pass 0 for the thread id if it's the main thread). A second nsthread
event processing end probe should happen at the t1 = PR_IntervalNow bit.

The patch has a bunch of if (t > 100) { ... }, which is just for sanity
sake when printing output -- the probes should not be conditional on how
long things take.

Args for the various probes should just be kept simple for now, we can
figure out later what data we want to pass down.

The big piece that's missing here is painting; since I'm assuming we're
MacOS X only for now, the right place would be in nsChildView.mm in
drawRect -- basically at the start of drawRect and at the end of
drawRect. (I guess a probe isn't really needed, since it's just one
function, but we should have one anyway.)

Getting this stuff in would be a huge help, thanks for taking this on!
I'd love to ship with the dtrace probes enabled in release builds at
some point.

- Vlad

He has been working on this probing portion for Sayrer for some time. And has created a patch to help with debugging the code base. And basically, he would like me to add start and end probe calls on places where

PRIntervalTime xx = PRIntervalNow( );

The first one gets the start, the next one gets the end.

I think I am able to do this, but with 5 days left and the assignment due at 11:59:59 on Saturday - I will really need to cut it down to the wire.

Thankfully, I am gathering all the resources I need to work on it today. And reviewing the patch to make sure I know where things are needed to go.

Hopefully, the patch will compile with and without the probes.

No comments: