From mboxrd@z Thu Jan 1 00:00:00 1970 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on polar.synack.me X-Spam-Level: X-Spam-Status: No, score=-1.9 required=5.0 tests=BAYES_00 autolearn=unavailable autolearn_force=no version=3.4.4 X-Received: by 2002:a6b:4f10:: with SMTP id d16mr10052742iob.38.1544019193183; Wed, 05 Dec 2018 06:13:13 -0800 (PST) X-Received: by 2002:aca:d607:: with SMTP id n7mr452393oig.1.1544019192907; Wed, 05 Dec 2018 06:13:12 -0800 (PST) Path: eternal-september.org!reader01.eternal-september.org!feeder.eternal-september.org!news.uzoreto.com!feeder.usenetexpress.com!feeder-in1.iad1.usenetexpress.com!border1.nntp.dca1.giganews.com!nntp.giganews.com!k10no87585itk.0!news-out.google.com!v141ni113ita.0!nntp.google.com!q69no86980itb.0!postnews.google.com!glegroupsg2000goo.googlegroups.com!not-for-mail Newsgroups: comp.lang.ada Date: Wed, 5 Dec 2018 06:13:12 -0800 (PST) In-Reply-To: <8441254e-f634-4077-b8d9-d988dab3406c@googlegroups.com> Complaints-To: groups-abuse@google.com Injection-Info: glegroupsg2000goo.googlegroups.com; posting-host=136.163.203.5; posting-account=g0yTkgoAAADdZGEYyZahxGlO3EkjH0Wv NNTP-Posting-Host: 136.163.203.5 References: <8441254e-f634-4077-b8d9-d988dab3406c@googlegroups.com> User-Agent: G2/1.0 MIME-Version: 1.0 Message-ID: <5846093f-ace9-4c8b-b4d7-d714b787d477@googlegroups.com> Subject: Re: Profiling Ada applications using gprof From: Petter Fryklund Injection-Date: Wed, 05 Dec 2018 14:13:13 +0000 Content-Type: text/plain; charset="UTF-8" Xref: reader01.eternal-september.org comp.lang.ada:54958 Date: 2018-12-05T06:13:12-08:00 List-Id: Den tisdag 4 december 2018 kl. 16:04:42 UTC+1 skrev joak...@kth.se: > Consider the following code: > > with Ada.Text_IO; > procedure Main is > > task A is > entry Stop; > end A; > > task body A is > begin > select > accept Stop do > delay 10.0; > end Stop; > end select; > end A; > > procedure Work is > begin > A.Stop; > end Work; > > begin > Work; > Ada.Text_IO.Put_Line ("Stopped"); > end Main; > > It is an application that takes 10.17 seconds to execute and "the problem" is the call A.Stop which takes too long (10 seconds) to return. The hope is to find this time consuming call with gprof. > > The code is built with the file default.gpr: > > project Default is > for Source_Dirs use ("src"); > for Object_Dir use "obj"; > for Main use ("main.adb"); > > package Compiler is > > for Switches ("Ada") use > ( > "-g", > "-pg" > ); > > end Compiler; > > package Linker is > > for Switches ("Ada") use > ( > "-g", > "-pg" > ); > > end Linker; > > end Default; > > Running the application creates a file gmon.out and running gprof on it and save the result in result.txt: > gprof --demangle=gnat main gmon.out > result.txt > > Looking at the contents of result.txt: > > Flat profile: > > Each sample counts as 0.01 seconds. > no time accumulated > > % cumulative self self total > time seconds seconds calls Ts/call Ts/call name > 0.00 0.00 0.00 2 0.00 0.00 main > 0.00 0.00 0.00 1 0.00 0.00 > 0.00 0.00 0.00 1 0.00 0.00 ada_main'Elab_Body > 0.00 0.00 0.00 1 0.00 0.00 ada_main.finalize_library > 0.00 0.00 0.00 1 0.00 0.00 adafinal > 0.00 0.00 0.00 1 0.00 0.00 adainit > 0.00 0.00 0.00 1 0.00 0.00 frame_dummy > > ... > > Call graph (explanation follows) > > > granularity: each sample hit covers 2 byte(s) no time propagated > > index % time self children called name > 0.00 0.00 1/1 ada_main'Elab_Body [2] > [1] 0.0 0.00 0.00 1 [1] > ----------------------------------------------- > 0.00 0.00 1/1 adainit [5] > [2] 0.0 0.00 0.00 1 ada_main'Elab_Body [2] > 0.00 0.00 1/1 [1] > ----------------------------------------------- > 0.00 0.00 1/1 system.tasking.stages.finalize_global_tasks [1193] > [3] 0.0 0.00 0.00 1 ada_main.finalize_library [3] > ----------------------------------------------- > 0.00 0.00 1/1 main [456] > [4] 0.0 0.00 0.00 1 adafinal [4] > ----------------------------------------------- > 0.00 0.00 1/1 main [456] > [5] 0.0 0.00 0.00 1 adainit [5] > 0.00 0.00 1/1 ada_main'Elab_Body [2] > ----------------------------------------------- > 0.00 0.00 1/1 main [1278] > [6] 0.0 0.00 0.00 1 frame_dummy [6] > ----------------------------------------------- > 4 main [1278] > 0.00 0.00 1/2 main [456] > 0.00 0.00 1/2 system.tasking.stages.task_wrapper [1196] > [1278] 0.0 0.00 0.00 2+4 main [1278] > 0.00 0.00 1/1 frame_dummy [6] > 4 main [1278] > ----------------------------------------------- > > As one can see there is nothing that indicates that something takes around 10 seconds to execute. Is it really impossible to detect the long running entry call A.Stop? > > Best regards, > Joakim Isn't a or missing before delay 10.0? The rendoz-vous will always take 10 sec. And then you can skip the do thing: select accept Stop; or delay 10.0; end select; Regards, Petter