From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Original-To: caml-list@sympa.inria.fr Delivered-To: caml-list@sympa.inria.fr Received: from mail3-relais-sop.national.inria.fr (mail3-relais-sop.national.inria.fr [192.134.164.104]) by sympa.inria.fr (Postfix) with ESMTPS id E5E9C7FDE2 for ; Mon, 30 May 2016 21:49:11 +0200 (CEST) IronPort-PHdr: 9a23:837ZDBbieiQGUQtSTPULcy7/LSx+4OfEezUN459isYplN5qZpcS4bnLW6fgltlLVR4KTs6sC0LqH9f27EjVasd6oizMrTt9lb1c9k8IYnggtUoauKHbQC7rUVRE8B9lIT1R//nu2YgB/Ecf6YEDO8DXptWZBUiv2OQc9HOnpAIma153xjLDjvcCIKFwS1HKUWvBbElaflU3prM4YgI9veO4a6yDihT92QdlQ3n5iPlmJnhzxtY+a9Z9n9DlM6bp6r5YTGY2zRakzTKRZATI6KCh1oZSz7ViQBTeIs3AVV2FejwFFGRONuBrzW5O0tirhqsJ83jObNIv4V+Zndy6l6vJEQRXyiSoDfwUy8GzNh9Y42K1Sqgigqhg52IXUbZuYLtJxe6rceZURQm8XDZUZbDBIHo7pN9hHNOEGJ+sN6tCl/1Y= Authentication-Results: mail3-smtp-sop.national.inria.fr; spf=None smtp.pra=gabriel.scherer@gmail.com; spf=Pass smtp.mailfrom=gabriel.scherer@gmail.com; spf=None smtp.helo=postmaster@mail-it0-f49.google.com Received-SPF: None (mail3-smtp-sop.national.inria.fr: no sender authenticity information available from domain of gabriel.scherer@gmail.com) identity=pra; client-ip=209.85.214.49; receiver=mail3-smtp-sop.national.inria.fr; envelope-from="gabriel.scherer@gmail.com"; x-sender="gabriel.scherer@gmail.com"; x-conformance=sidf_compatible Received-SPF: Pass (mail3-smtp-sop.national.inria.fr: domain of gabriel.scherer@gmail.com designates 209.85.214.49 as permitted sender) identity=mailfrom; client-ip=209.85.214.49; receiver=mail3-smtp-sop.national.inria.fr; envelope-from="gabriel.scherer@gmail.com"; x-sender="gabriel.scherer@gmail.com"; x-conformance=sidf_compatible; x-record-type="v=spf1" Received-SPF: None (mail3-smtp-sop.national.inria.fr: no sender authenticity information available from domain of postmaster@mail-it0-f49.google.com) identity=helo; client-ip=209.85.214.49; receiver=mail3-smtp-sop.national.inria.fr; envelope-from="gabriel.scherer@gmail.com"; x-sender="postmaster@mail-it0-f49.google.com"; x-conformance=sidf_compatible X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: A0CaAwDil0xXfzHWVdFbg1o4fQaDPasrjR0khW2BMQc8EAEBAQEBAQEBEQEBCQsLCSEvgjCCGBYRHQEbHQEDEhAPAiYCJAERAQUBIhsah3IBAxcOnUaBMT4xizuBaoJYBYdjChknDVKDTQEBCAIBHAIGEHGFJowWglkFmDeBVoQqiCCCN4xljg0SHoEPN4IkghAgMgGJPAEBAQ X-IPAS-Result: A0CaAwDil0xXfzHWVdFbg1o4fQaDPasrjR0khW2BMQc8EAEBAQEBAQEBEQEBCQsLCSEvgjCCGBYRHQEbHQEDEhAPAiYCJAERAQUBIhsah3IBAxcOnUaBMT4xizuBaoJYBYdjChknDVKDTQEBCAIBHAIGEHGFJowWglkFmDeBVoQqiCCCN4xljg0SHoEPN4IkghAgMgGJPAEBAQ X-IronPort-AV: E=Sophos;i="5.26,391,1459807200"; d="scan'208";a="179518469" Received: from mail-it0-f49.google.com ([209.85.214.49]) by mail3-smtp-sop.national.inria.fr with ESMTP/TLS/AES128-GCM-SHA256; 30 May 2016 21:49:10 +0200 Received: by mail-it0-f49.google.com with SMTP id v125so6841664itc.0; Mon, 30 May 2016 12:49:10 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:from:date:message-id:subject:to:cc :content-transfer-encoding; bh=LBKtzq8PXVZQaEOXzo1wzhjnTsoSerhZ2NF0O2vQGyw=; b=CzGrpyJwI5PsFk2woucfEpJuZBh76nKlvmVuc3l5y2xw+RXvPQY5xdRSsGKmuYTrqp cvv3brWac9NVa89+PTHKygN8mc9fLgE+xZ+r+XOPeqsfXfPz7G8Yu4NySB2V51vn0BX9 UgoqFQm5B77Za2O1q0z1mEjz8KeUsTUnyIeYUD1Z8Z0o3zu3XPntq9mrcKIani6k02QX KPO4Xo4YELW5biX6X5nzDX6qKnNN6BgOcvwO/tpe+vl6Xy/G4siNT8wp+Y5dGdGLv4DL vETOddtSW120qHEdri9hUWf4nC5/rDV1N45py6kc0Lm9BDuKTzh7rRMxFCZJkZcz7pCe endg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:from:date:message-id:subject:to:cc :content-transfer-encoding; bh=LBKtzq8PXVZQaEOXzo1wzhjnTsoSerhZ2NF0O2vQGyw=; b=m3XlTD/zHL0ygEWvrAmdU1giuk4RnhirTwZKzInmugJpbYJgqd8SjKurDlQR+NLDBm RFpA+uwXb17RmchbAQA7x8xveAhr3x6APireGzUNpiyTh1QWhNPwUryarJHPbUH5DNUW zg6thyjIy1gG0bqpXmAIO5qAndmjIF8NoRS9i4DEn1WXeBa+Bei/LutvotDcuaQKyxhT Y53DjodMdgA31JCWXn9uPGyrMXiKU9B88/oFcqXui19uQgK6ko6NnrS3jp1XzIgDaHa+ yuBwlWIDh8N/XW2wEHCslwIKy63ASdZwgtH2OMYFi+ygvni/H+IL4GJ2tFF6GgD1qr57 rxug== X-Gm-Message-State: ALyK8tKakNqSRaZFBSS8sIsWEfJ+k7iCcmBMU4P4qPI2BbdhhIR516VIaQR6EWiWrQHWsxH08zgbo3XeEIG99Q== X-Received: by 10.36.3.7 with SMTP id e7mr9014777ite.15.1464637749108; Mon, 30 May 2016 12:49:09 -0700 (PDT) MIME-Version: 1.0 Received: by 10.79.89.195 with HTTP; Mon, 30 May 2016 12:48:29 -0700 (PDT) From: Gabriel Scherer Date: Mon, 30 May 2016 15:48:29 -0400 Message-ID: To: caml users Cc: Damien Doligez Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Subject: [Caml-list] Measuring GC latencies for OCaml program Dear caml-list, You may be interested in the following blog post, in which I give instructions to measure the worst-case latencies incurred by the GC: Measuring GC latencies in Haskell, OCaml, Racket http://prl.ccs.neu.edu/blog/2016/05/24/measuring-gc-latencies-in-haskell-= ocaml-racket/ In summary, the commands to measure latencies look something like: % build the program with the instrumented runtime ocamlbuild -tag "runtime_variant(i)" myprog.native % run with instrumentation enabled OCAML_INSTR_FILE=3D"ocaml.log" ./main.native % visualize results from the raw log $(OCAML_SOURCES)/tools/ocaml-instr-graph ocaml.log $(OCAML_SOURCES)/tools/ocaml-instr-report ocaml.log While the OCaml GC has had a good incremental mode with low latencies for most workloads for a long time, the ability to instrument it to actually measure latencies is still in its infancy: it is a side-result of Damien Doligez's stint at Jane Street last year, and 4.03.0 is the first release in which this work is available. A practical consequence of this youth is that the "user experience" of actually performing these measurements is currently very bad. The GC measurements are activated in an instrumented runtime variant (OCaml supports having several variants of the runtime available, and deciding which one to use for a specific program at link-time), which is the right design choice, but right now this variant is not built by default by the compiler distribution -- building it is a configure-time option disabled by default. This means that, as a user interested in doing the measurements, you have to compile an alternative OCaml compiler. Furthermore, processing the raw instrumented log requires tool that are also in their infancy, and are currently included in the compiler distribution sources but not installed -- so you have to have a source checkout available to use them. In contrast, GHC's instrumentation is enabled by just passing the option "+RTS -s" to the Haskell program of interest; this is superbly convenient and something we should aim at. I discussed with Damien whether we should enable building the instrumented runtime by default (for example pass the --with-instrumented-runtime option to the opam switches people are using, and encourage distributions to use it in their packages as well). Of course there is a cost/benefit trade-off: currently virtually nobody is using this instrumentation, but enabling it by default would increase the compilation time of the compiler distribution for everyone. (On my machine it only adds 5 seconds to total build time.) I personally think that we should aim for a rock-solid experience for profiling and instrumenting OCaml program enabled by default=C2=B9. It is worth making it slightly longer for anyone to install the compiler if we can make it vastly easier to measure GC pauses in our program when the need arises (even if it's not very often). But that is a discussion that should be had before making any choice. Regarding the log analysis tools, before finding about Damien's included-but-not installed tools (a shell and an awk script, in the finest Unix tradition) I built a quick&dirty OCaml script to do some measurements, which can be found in the benchmark repository below. It would not be much more work to grow this in a reusable library to extract the current log format into a structured data structure -- the format is undocumented but the provided scripts in tools/ have enough information to infer the structure. Such a script/library would, of course, remain tightly coupled to the OCaml version, but I think it could be useful to have it packaged for users to play with. https://gitlab.com/gasche/gc-latency-experiment/blob/master/parse_ocaml_l= og.ml =C2=B9: We cannot expect users to effectively write performant code if they don't have the tool support for it. The fact that lazyness in Haskell makes it harder for users to reason about efficiency or memory usage has made the avaibility of excellent performance tooling *necessary*, where it is merely nice-to-have in OCaml. Rather ironically, Haskell tooling is now much better than OCaml's in this area, to the point that it can be easier to write efficient code in Haskell. Three side-notes on profiling tools: 1. `perf record --call-graph=3Ddwarf` works fine for ocamlopt binaries (no need for a frame-pointers switch), and this is documented: https://ocaml.org/learn/tutorials/performance_and_profiling.html#Usingp= erfonLinux 2. Thomas Leonard has done excellent work on domain-specific profiling tools for Mirage, and this is the kind of tool support that I think should be available to anyone out of the box. http://roscidus.com/blog/blog/2014/08/15/optimising-the-unikernel/ http://roscidus.com/blog/blog/2014/10/27/visualising-an-asynchronous-m= onad/ 3. There is currently more debate than anyone could wish for around a pull request of Mark Shinwell for runtime support for dynamic call graph construction and its use for memory profiling. https://github.com/ocaml/ocaml/pull/585 4. Providing a good user experience for performance or space profiling is a fundamentally harder problem than for GC pauses. It may require specially-compiled versions of the libraries used by your program, and thus a general policy/agreement across the ecosystem. Swapping a different runtime at link-time is very easy.