From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Original-To: caml-list@yquem.inria.fr Delivered-To: caml-list@yquem.inria.fr Received: from nez-perce.inria.fr (nez-perce.inria.fr [192.93.2.78]) by yquem.inria.fr (Postfix) with ESMTP id BCD52BBBB for ; Fri, 17 Mar 2006 19:39:57 +0100 (CET) Received: from pauillac.inria.fr (pauillac.inria.fr [128.93.11.35]) by nez-perce.inria.fr (8.13.0/8.13.0) with ESMTP id k2HIdvfF030815 for ; Fri, 17 Mar 2006 19:39:57 +0100 Received: from nez-perce.inria.fr (nez-perce.inria.fr [192.93.2.78]) by pauillac.inria.fr (8.7.6/8.7.3) with ESMTP id TAA28382 for ; Fri, 17 Mar 2006 19:39:56 +0100 (MET) Received: from xproxy.gmail.com (xproxy.gmail.com [66.249.82.196]) by nez-perce.inria.fr (8.13.0/8.13.0) with ESMTP id k2HIdtYn030811 for ; Fri, 17 Mar 2006 19:39:56 +0100 Received: by xproxy.gmail.com with SMTP id h28so575583wxd for ; Fri, 17 Mar 2006 10:39:55 -0800 (PST) DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=beta; d=gmail.com; h=received:message-id:date:from:to:subject:mime-version:content-type; b=X2EHwat0QsluFp9XEPPyno3mA+8fleo+0ft/t/ZPEV/bT0g6yCc1rMQwejxO2S7FXlmVUaHoJN9yYvpH8i+pGCkhK1VY3a8BNVI6xT2+OqWtN7WpS1hSemleJfhz/+etzZ7CBi/olcL7Odd9rt7rDP7PpGwuZJWVBRazajEpldU= Received: by 10.70.79.6 with SMTP id c6mr3583419wxb; Fri, 17 Mar 2006 10:39:52 -0800 (PST) Received: by 10.70.57.14 with HTTP; Fri, 17 Mar 2006 10:39:52 -0800 (PST) Message-ID: Date: Fri, 17 Mar 2006 13:39:52 -0500 From: "Markus Mottl" To: ocaml Subject: Severe loss of performance due to new signal handling MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_7642_28059420.1142620792674" X-Miltered: at nez-perce with ID 441B027D.000 by Joe's j-chkmail (http://j-chkmail.ensmp.fr)! X-Miltered: at nez-perce with ID 441B027B.000 by Joe's j-chkmail (http://j-chkmail.ensmp.fr)! X-Spam: no; 0.00; markus:01 mottl:01 markus:01 mottl:01 ocaml:01 bug:01 surprising:01 bug:01 ocaml:01 3.08.4:01 threads:01 stdout:01 for-loop:01 async:01 timings:01 X-Attachments: type="application/octet-stream" name="slow.ml" name="slow.ml" X-Spam-Checker-Version: SpamAssassin 3.0.3 (2005-04-27) on yquem.inria.fr X-Spam-Level: X-Spam-Status: No, score=0.8 required=5.0 tests=HTML_10_20,HTML_MESSAGE, INFO_TLD,RCVD_BY_IP autolearn=disabled version=3.0.3 ------=_Part_7642_28059420.1142620792674 Content-Type: multipart/alternative; boundary="----=_Part_7643_20697436.1142620792674" ------=_Part_7643_20697436.1142620792674 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Hi, this report has also been posted to the OCaml bug tracker, but since it is = a surprising observation, it may be good if people on the list know that it exists without having to search the bug tracker archive. Maybe some assembler guru can repeat this result and explain to us what's going on... ---------- It seems that changes to signal handling between OCaml 3.08.4 and 3.09.1 ca= n lead to a very significant loss of performance (up to several orders of magnitude!) in code that uses threads and performs I/O (tested on Linux). The attached file (slow.ml) demonstrates this: it prints a character to stdout in a for-loop. The uploaded version will take approximately 600ms in native code to complete this test when redirecting output to /dev/null. If you comment out the line containing "module X =3D Thread" and compile witho= ut thread support, then the test suddenly only takes around 1.5ms, i.e. it run= s 400 times faster. Profiling using oprofile revealed that the function "caml_process_pending_signals" seems to be responsible for that. Annotated assembler output showed that the code was sampled an astonishing number of times in the instruction "test %eax,%eax" as obviously generated for "if (async_action !=3D NULL)" in this function. This is really weird, because everything else seems to be sampled a sensible number of times, but it woul= d surely explain the timings. OCaml-3.08.4 does not exhibit any problems of that kind. ---------- Best regards, Markus -- Markus Mottl http://www.ocaml.info markus.mottl@gmail.com ------=_Part_7643_20697436.1142620792674 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Hi,

this report has also been posted to the OCaml bug tracker, but since it is a surprising observation, it may be good if people on the list know that it exists without having to search the bug tracker archive.  Maybe some assembler guru can repeat this result and explain to us what's going on...

----------

It seems that changes to signal handling between OCaml 3.08.4 and 3.09.1 can lead to a very significant loss of performance (up to several orders of magnitude!) in code that uses threads and performs I/O (tested on Linux).

The attached file (slow.ml) demonstrates thi= s: it prints a character to stdout in a for-loop. The uploaded version will take approximately 600ms in native code to complete this test when redirecting output to /dev/null.  If you comment out the line containing "module X =3D = Thread" and compile without thread support, then the test suddenly only takes around 1.5ms, i.e. it runs 400 times faster.

Profiling using oprofile revealed that the function "caml_process_pending_signals" seems to be responsible for that.&= nbsp; Annotated assembler output showed that the code was sampled an astonishing number of times in the instruction "test %eax,%eax" a= s obviously generated for "if (async_action !=3D NULL)" in this fun= ction. This is really weird, because everything else seems to be sampled a sensible number of times, but it would surely explain the timings.

OCaml-3.08.4 does not exhibit any problems of that kind.

----------

Best regards,
Markus

--
Markus Mottl        http://www.ocaml.info      &n= bsp; markus.mottl@gmail.com<= /a> ------=_Part_7643_20697436.1142620792674-- ------=_Part_7642_28059420.1142620792674 Content-Type: application/octet-stream; name=slow.ml Content-Transfer-Encoding: 7bit X-Attachment-Id: f_ekwupuz2 Content-Disposition: attachment; filename="slow.ml" open Unix open Printf module X = Thread let () = let t1 = gettimeofday () in for i = 1 to 100000 do print_char '.'; done; let t2 = gettimeofday () in eprintf "%f\n" (t2 -. t1); ------=_Part_7642_28059420.1142620792674--