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

[Thomas Leonard <talex5@xxxxxxxxx>]

On 30 October 2014 15:40, Anil Madhavapeddy <anil@xxxxxxxxxx> wrote:
> On 30 Oct 2014, at 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]).
>>
>> 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.
>
>
> I didn't even know of the existence of this tool, so the trace format
> looks useful even if the Chrome tool itself doesn't quite match.  The
> HN thread mentioned the LTTng, which doesn't look quite as well used
> as this (which is used for actual profiling in Android and Chrome, by
> the looks of it).

I've been looking at LTT links in that post. Here's the format spec:

  http://www.efficios.com/ctf

I would like to move to a less GC-heavy logging format in
mirage-profile, and this is one candidate.


-- 
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