Add queue depth at complete time into DiskIOTraceData class

[fliang-ms]

It is amazing to see DiskServiceTime (similar to the one in WPA disk IO summary table). While analyzing disk IO performance, queue depth is as important as IOPS, throughput and latency. The disk IO information in history is already maintained in diskEventTimeStamp. It should not be too hard to extend DiskIOTime class and calculate queue depth at complete time for every DiskIOTraceData. I am happy to contribute. Please let me know your idea.

[vancem]

I think your goal is reasonable. However the details are probably harder than you think.

It turned out we got 'lucky' in that DiskServiceTime could be computed knowing only the events that happened earlier in the trace. Thus we could keep 'on the fly' data as we read the stream and refer to that when a particular Disk Event was being viewed to get new fields.

Sadly this is not true for QueueLength because it depends on START times and normally you don't have those but only END times and duration (from which you can calculate start times), but significantly some of these end events will occur AFTER the focus event. Thus unlike DiskServiceTime you need some sort of 'two pass' system.

Nowt this is possible, but it does make the implementation more complex (and would not leverage the trick used for DiskServiceTime).

This problem does occur for stacks (the stack events happen after the events they are for, sometimes quite a bit after), and the solution there is to convert the original ETL file into a 'ETLX' file that has 'extra' information on the side (e.g. a table that maps event# to the stack associated with it).

This problem (needing two passes) is not just for I/O and it would be nice to a way that could be done for many related problems. One way of doing this is to introduce the concept of a 'injected event' into ETLX. Thus we could make the ETL->ETLX process understand how to 'inject' new events into the stream at given time locations. Thus you could 'inject' a 'start' I/O event and even add things like the current Disk size (and anything else you wanted to caclcuate), which then would immediately be available in the 'Events' view (as well as for other processing if you desire.

I have not given this too much thought, so there may be other (better) options. Suffice it to say, that it is no longer a trivial feature, but I am willing to help if you are interested in pursuing it.

[fliang-ms]

I thought that DISK_IO_INIT event has disk number field when I started this discussion. It seems to only have Irp. Yes, it is harder than I thought.

The solution of two passes is ideal. Here is another candidate if we can delay the callback of DiskIOTraceData for several seconds. We can keep all of DiskIOTraceData in a queue. When a new disk IO completes, we increase the queue depth of the disk IOs in the queue which are overlapped with this new disk IO. Additionally, we trigger the DiskIOTraceData callback of those disk IOs which completed x seconds before. On the modern platform, x should be smaller than 2 or 3 for most of disk IOs.

It is based on the assumption that the IO time of most disk IOs are smaller than 2 or 3 seconds. It has 2 impacts. 1) the callback of DiskIOTraceData is delayed for seconds. 2) Some long disk IOs(longer than 2 or 3 seconds) might be missed while calculating queue depth. I don't think that the latter one is a big problem. But the former one is tricky. Look forward to your opinion.

[vancem]

We actually have something much along the lines you describe (a queue that delays things so that you can do some match up), so that we could support events with stacks in real time traces (since stack events come after the event that they are describing). (see CreateFromTraceEventSession for that).

There is a basic issue that some information to make a 'high level' view may require information from events that happen after it in time. I would want whatever solution we come up with for Disk/IO to be just an instance of a generic design.

One solution is the two pass approach (either explicitly (you read the data twice)). Another is to have two files (process the original data into a new file that 'fixes' things by augmenting the event stream events with the extra data they need (which may have come from later in the trace). Neither of these first two work for real-time streams, so the third option is a delay-queue that allows you a window in which you can do this transformation (which is what we did for CreateFromTraceEventSession)

I think we examples of all three approaches already, and even ancient 'architecture' so you can build-once and have all three work (since they serve different scenarios). They all start with what I call a 'Computer' which is just code that knows how to create the 'extra' data from the stream of events.

If you are interested in pursuing this I can give more details. I just want to warn you that it may take longer than you think, and while there are roughly related examples of doing things like this, there will be some things that we will have to figure out along the way, which will also slow us down. Still if you are up for it, I will help

[fliang-ms]

sorry for so long delay. I haven't got chance to make real progress yet. I will reply back once I have the prototype ready. Thanks for detailed explanation.

[brianrob]

@fliang-ms is this something that you're still looking at? Thanks.