Re: [MirageOS-devel] Tracing and profiling blog post

[Thomas Leonard <talex5@xxxxxxxxx>]

On 30 October 2014 14:30, Len Maxwell <len@xxxxxxxx> wrote:
> On Thu, Oct 30, 2014 at 5:36 AM, Thomas Leonard <talex5@xxxxxxxxx> wrote:
>>
>> Here's what I have so far:
>>
>> https://github.com/talex5/mirage-profile/blob/new-api/lib/trace_stubs.mli
>> https://github.com/talex5/mirage-profile/blob/new-api/lib/counter.mli
>>
>> There's not much here, but it would be good to keep this API stable as
>> pretty much all mirage libraries will be using it.
>>
>> The API for controlling the tracing, dumping out events, etc is much
>> less critical and can be changed later, as it only matters to the
>> developer profiling their unikernel.
>>
>> Comments welcome!
>
> Nice blog post; it was interesting to see some of the earlier
> performance puzzles re-examined with your new tools.
>
> Recently I found the Google trace-viewer [1] tool; it was built to
> analyze performance issues in Chrome [2], is now being used for
> Android, and the Go language may adopt it as well [3].  I think it
> would be worthwhile to a) review their event types and JSON format [4]
> for inspiration, and b) consider trace-viewer as an alternative viewer
> for some use cases.
>
> As an experiment, I manually instrumented mirage-www with trace-viewer
> JSON output, and the result is here [5].  Download that file, open
> about://tracing in Chrome, then Load the .trace file.  (Failing that,
> you can get the trace-viewer source [1] and run the dev_server, or
> view the self-contained HTML/JS version [6]).  Press '?' for help.
>
> The trace shows a browser loading the mirage-www home page, from the
> server's point-of-view.  At the top are some GC counters, captured
> once per second; the (hard-to-see) vertical green lines represent Gc
> alarm callbacks.  Below that are all of the HTTP requests and related
> FS calls, organized by HTTP connection -- in the Cohttp callback, I
> store the conn_id in a thread-local, and use that as a "thread ID"
> when recording events.
>
> Overall you should see that the browser used 6 concurrent connections
> to load all of the resources on the home page, and that generating
> index.html requires reading a lot of files.  It would be nice if I
> could look deeper into Cohttp and FS with mirage-profile, but use
> trace-viewer as the presentation format.  (So far I am using just a
> few features of the trace output, there are other examples in the
> test_data folder of [1]).

It would be good if we could do this sort of thing with the same
tracing framework, indeed.

To get this output with mirage-profile, you'd probably want a
structured way to indicate a new HTTP connection, file read, etc,
rather than the current free-form text in MProf.Trace.label.

It should be fairly easy to recover the TCP connection from the
recorded Lwt thread ID, by following the Creates links. e.g.

- Thread 5 notes that it is handling TCP connection 1
- Thread 5 creates 6
- Thread 6 reads file "index.html"

(you can also correlate things in more complicated ways, as Mort
showed earlier with the Magpie work)

> To be clear, I don't think that trace-viewer could present low-level
> Lwt scheduling as well as mirage-trace-viewer does.  However, it could
> be useful for viewing a unikernel's behavior from other perspectives.

Yes. Although, I suspect in this case you could get a similar simple
output with mirage-trace-viewer if you did some preprocessing on the
input trace (e.g. pruning network driver threads, ring acks and other
low-level details).

> [1] https://github.com/google/trace-viewer
> [2] http://dev.chromium.org/developers/how-tos/trace-event-profiling-tool
> [3] 
> http://dotgo.sourcegraph.com/post/99652962343/brad-fitzpatrick-on-the-future-of-the-go-programming
> (see: GOTRACE)
> [4] 
> https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/edit?usp=sharing
> [5] https://s3.amazonaws.com/lnmx-public/mirage-www.trace
> [6] https://s3.amazonaws.com/lnmx-public/mirage-www.html



-- 
Dr Thomas Leonard        http://0install.net/
GPG: 9242 9807 C985 3C07 44A6  8B9A AE07 8280 59A5 3CC1
GPG: DA98 25AE CAD0 8975 7CDA  BD8E 0713 3F96 CA74 D8BA

_______________________________________________
MirageOS-devel mailing list
MirageOS-devel@xxxxxxxxxxxxxxxxxxxx
http://lists.xenproject.org/cgi-bin/mailman/listinfo/mirageos-devel