The profiler is awesome. But we need more data about the details of where the time went so we can tune individual components and so we can construct a call graph. Splitting the "Millis" component out by type would be an excellent first step. I realize it may be hard with MM files, but perhaps just treat all calls to MM files as I/O for now. We would not be able to see physical vs logical I/O, but ok, thats a compromise. But understanding I/O vs other items would be excellent! Especially if a write was waiting to get time on the writer process. I would love something like:

read:
{ "ts" : "Mon Sep 20 2010...", "info" : "query test.foo reslen:174 nscanned:4 \nquery: {} nreturned:4 bytes:158", "millis" :

{"IO":4,"Lock":1,"Net":1,"Total":6}

, }

write:
{ "ts" : "Mon Sep 20 2010...", "info" : "insert test.foo", "millis" :

{"IO":1,"Queue":4,"Net":1,"Fsync":1,"Total":7 }

I think the various types that makes sense are:

• Network Time
• I/O Time (faults)
• Queue Time (waiting for writer process for instance)
• Connection Time
• Lock Time
• CPU Time
• Fsync Time
• GetLastError() Time

The idea of DB profiling is not new. The Oracle world as a great deal of expertise in this area, and it's one of it's great strengths. If you are not already familar here is a paper by Cary Milsap (who IMHO is the master of all things profiling in Oracle):
http://www.scribd.com/doc/16884539/Millsap-Profiling-Oracle-How-It-Works