[petsc-dev] Nested event logging and human friendly output

Klaij, Christiaan C.Klaij at marin.nl
Fri Mar 16 06:49:35 CDT 2018


Good idea! But not for our production clusters which do not have internet access.


Chris

dr. ir. Christiaan Klaij | Senior Researcher | Research & Development
MARIN | T +31 317 49 33 44 | C.Klaij at marin.nl<mailto:C.Klaij at marin.nl> | www.marin.nl<http://www.marin.nl>

[LinkedIn]<https://www.linkedin.com/company/marin> [YouTube] <http://www.youtube.com/marinmultimedia>  [Twitter] <https://twitter.com/MARIN_nieuws>  [Facebook] <https://www.facebook.com/marin.wageningen>
MARIN news: SSSRI-MARIN seminar, May 18, 2018, Shanghai<http://www.marin.nl/web/News/News-items/SSSRIMARIN-seminar-May-18-2018-Shanghai.htm>

________________________________
From: Koos Huijssen <koos.huijssen at vortech.nl>
Sent: Friday, March 16, 2018 12:06 PM
To: Klaij, Christiaan; Smith, Barry F.
Cc: petsc-dev at mcs.anl.gov
Subject: Re: [petsc-dev] Nested event logging and human friendly output


A solution seems to be that the style sheet is present on a public server, so that it can be retrieved using http. This should be fine for all browsers. Maybe somewhere on https://www.mcs.anl.gov/petsc ...?

Regards,

Koos

On 03/16/2018 12:04 PM, Klaij, Christiaan wrote:

Thanks Koos! We have the same problem on microsoft internet explorer. Safari does some magic for sure.


Chris

dr. ir.Christiaan Klaij | Senior Researcher | Research & Development
MARIN | T +31 317 49 33 44 | C.Klaij at marin.nl<mailto:C.Klaij at marin.nl> | www.marin.nl<https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.marin.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=NjVrv%2FmosOc05tQIwym5aFTIc2247xiqZN7Z%2FRY0mGw%3D&reserved=0>

[LinkedIn]<https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.linkedin.com%2Fcompany%2Fmarin&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=XUEA%2ByAjIK7zkn200VKGqPtvKxYLP1tSBpbD2DzjW4U%3D&reserved=0> [YouTube] <https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.youtube.com%2Fmarinmultimedia&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=htguXyp5gngXlzIEX1EYh79nbm64v9dl0UeCXQvni9w%3D&reserved=0>  [Twitter] <https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Ftwitter.com%2FMARIN_nieuws&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=ff636Ec1T901oV5LY0V88u2b6nYygxMd2aCLMZRBiyU%3D&reserved=0>  [Facebook] <https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.facebook.com%2Fmarin.wageningen&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=FIDDBNdEJ82%2BdxGcaRK1dKsQyUV15CaLdIpAt36RH1k%3D&reserved=0>
MARIN news: Putting a new spin on propeller design<https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.marin.nl%2Fweb%2FNews%2FNews-items%2FPutting-a-new-spin-on-propeller-design-1.htm&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=jHNUEXItIWAEBfeoVPdwakIcg2ZMxCuppakg0MvyZso%3D&reserved=0>
________________________________
From: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>
Sent: Friday, March 16, 2018 12:02 PM
To: Klaij, Christiaan; Smith, Barry F.
Cc: petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>
Subject: Re: [petsc-dev] Nested event logging and human friendly output


Hi Chris,

Indeed, this is exactly the issue. When we investigated this it seemed to work on Barry's system, but it has never worked on mine either. The browsers do not allow hard paths to be used for the xml style sheet.

For Chrome there is an extra thing. If you launch Chrome with the flag '--allow-file-access-from-files' it should give the desired result (see here<https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fstackoverflow.com%2Fquestions%2F39174013%2Fwhy-isnt-my-xml-and-xslt-stylesheet-not-loading-in-chrome&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=YAtZ97%2FldyOzIjkpZDjCGhA%2BB8W6stmyCLIB5xO9Qy0%3D&reserved=0>).

A note in the manual would surely be a good thing.

With kind regards,

Koos

On 03/16/2018 11:54 AM, Klaij, Christiaan wrote:

Barry,

I've tried it quickly with petsc-3.8.3 and
snes/examples/tutorials/ex70.c and it seems to work except for
the stylesheet. The xml log has this header in my case:

<?xml-stylesheet type="text/xsl" href="/home/cklaij/ReFRESCO/Dev/trunk/Libs/build/petsc-3.8.3-dbg/share/petsc/xml/performance_xml2html.xsl"?>

Even though the path is correct, both Firefox and Chrome on linux
do not load the stylesheet. I have to

1) copy "performance_xml2html.xsl" to the directory which
contains the xml log (a symlink won't do),

2) then edit the header to href="performance_xml2html.xsl".

These steps work for Firefox, but not for Chrome (it just shows a
blank page).

If I remember correctly (Koos?) then this problem was due to some
browser safety stuff which can't be avoided. If this is still
true and not fixable, we should probably add a note in the manual
explaining both steps?

Chris



dr. ir. Christiaan Klaij  | Senior Researcher | Research & Development
MARIN | T +31 317 49 33 44 | mailto:C.Klaij at marin.nl | https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.marin.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=wf%2BYdEvdpvMh9aK7D51yBDHFQvlziBS9U3ArOA85etE%3D&reserved=0

MARIN news: https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.marin.nl%2Fweb%2FNews%2FNews-items%2FFrequency-of-spill-model-for-area-risk-assessment-of-shipsource-oil-spills-in-Canadian-waters-1.htm&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=2TVwn1x5EZuNHzVHCMO1BLNNRMv%2BrSe4eOJ3tQ7vhJg%3D&reserved=0

________________________________________
From: Smith, Barry F. <bsmith at mcs.anl.gov><mailto:bsmith at mcs.anl.gov>
Sent: Thursday, March 15, 2018 3:00 PM
To: Klaij, Christiaan
Cc: Koos Huijssen; petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Bas van 't Hof
Subject: Re: [petsc-dev] Nested event logging and human friendly output

   It is in 3.8 please let us know if you have any trouble with it.

   Barry




On Mar 15, 2018, at 3:03 AM, Klaij, Christiaan <C.Klaij at marin.nl><mailto:C.Klaij at marin.nl> wrote:

Hi Barry,

It's been a while and I'll soon be upgrading our production
software from petsc-3.7.5 to petsc-3.8.3. Can you tell me if the
nested event logging made it into 3.8? If so, I would probably
remove our own version in favor of the petsc maintained
version.

Best regards,
Chris

dr. ir. Christiaan Klaij | Senior Researcher | Research & Development
MARIN | T +31 317 49 33 44 | C.Klaij at marin.nl<mailto:C.Klaij at marin.nl> | https://emea01.safelinks.protection.outlook.com/?url=www.marin.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=GPHrId893OZ0dHpzLHEHgjmQHBOsest1JEl6sZ6wef4%3D&reserved=0

<image15100b.PNG> <imageb2c83e.PNG> <imagebd077a.PNG> <image2e1442.PNG>
MARIN news: Numerical study of cavitation on a NACA0015 hydrofoil: solution verification
From: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>
Sent: Friday, August 12, 2016 8:07 AM
To: Barry Smith
Cc: petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Klaij, Christiaan; Bas van 't Hof
Subject: Re: [petsc-dev] Nested event logging and human friendly output

Hi Barry,

Looking forward to that!

Koos
From: Barry Smith <bsmith at mcs.anl.gov><mailto:bsmith at mcs.anl.gov>
Sent: Friday, August 12, 2016 4:02:42 AM
To: Koos Huijssen
Cc: petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Klaij, Christiaan; Bas van 't Hof
Subject: Re: [petsc-dev] Nested event logging and human friendly output


  Thanks. This will be in master soon.

   Barry



On Aug 8, 2016, at 5:15 AM, Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl> wrote:

Hi Barry,

The fix is to replace the "j<=depth" on line 736 with "j<depth". So it should read

for (j=0; same && j<depth; j++) { same = (same &&  nstMyPath[j] == nstPath[j]) ? PETSC_TRUE : PETSC_FALSE;}

That should resolve the valgrind issue.

With kind regards,

Koos


-----Original Message-----
From: Barry Smith [mailto:bsmith at mcs.anl.gov]
Sent: vrijdag 5 augustus 2016 22:39
To: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>
Cc: petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Klaij, Christiaan <C.Klaij at marin.nl><mailto:C.Klaij at marin.nl>; Bas van 't Hof <bas.vanthof at vortech.nl><mailto:bas.vanthof at vortech.nl>
Subject: Re: [petsc-dev] Nested event logging and human friendly output


   There appears to be an error indicated by valgrind at: ftp://ftp.mcs.anl.gov/pub/petsc/nightlylogs/archive/2016/08/04/examples_master_arch-linux-pkgs-valgrind_grind.log

Note that the nstPath[] arrays only seem to filled up to but not including depth but the  "same" loop has j<=depth. Could you please clarify how I should fix this?


     if (i<nTimers) {
       for (j=0;             j<tree[i].depth; j++) nstMyPath[j] = tree[i].nstPath[j];
       for (j=tree[i].depth; j<depth;         j++) nstMyPath[j] = illegalEvent;
     } else {
       for (j=0;             j<depth;         j++) nstMyPath[j] = illegalEvent;
     }

     /* Communicate with other processes to obtain the next path and its depth */
     ierr = MPIU_Allreduce(nstMyPath, nstPath, depth, MPI_INT, MPI_MIN, comm);CHKERRQ(ierr);
     for (j=depth-1; (int) j>=0; j--) {
       if (nstPath[j]==illegalEvent) depth=j;
     }

     if (depth>0) {
       /* If the path exists */

       /* check whether the next path is the same as this process's next path */
       same = PETSC_TRUE;
       for (j=0; same && j<=depth; j++) { same = (same &&  nstMyPath[j] == nstPath[j]) ? PETSC_TRUE : PETSC_FALSE;}





On Aug 4, 2016, at 5:01 PM, Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl> wrote:

Hi Barry,

I did some analysis on the results, but I see nothing strange. The missing MatAssemblyBegin could be because its time falls under the threshold of 0.01% of the total runtime, in which case it is left out of the tree. I ran the same case, and I got both Begin/End operations, but both at 0% (so probably both dwindling around the 0.01% threshold). The MatAssemblyBegin/MatAssemblyEnd pair are part of the SNESSolve routine, but they are not located within the SNES_Solve log event. This event only registers the time spent in the solve routine in snes->ops->solve. If I set an event around the call to SNESSolve in ex19.c, they do appear within that event. Maybe something to do with MatInterpolate or DMInterpolate?

Since the log events have never been used in a nested logging before, it could be that this type of misunderstanding will occur more often whenever a log event is not one-to-one coupled to its routine but to a section within that routine.

With kind regards,

Koos

From: Koos Huijssen
Sent: donderdag 4 augustus 2016 22:12
To: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>
Subject: Fwd: [petsc-dev] Nested event logging and human friendly
output




Begin doorgestuurd bericht:

Van: Barry Smith <bsmith at mcs.anl.gov><mailto:bsmith at mcs.anl.gov>
Datum: 17 juli 2016 04:44:04 CEST
Aan: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>
Kopie: Richard Mills <richardtmills at gmail.com><mailto:richardtmills at gmail.com>,
"petsc-dev at mcs.anl.gov"<mailto:petsc-dev at mcs.anl.gov> <petsc-dev at mcs.anl.gov><mailto:petsc-dev at mcs.anl.gov>, "Klaij, Christiaan"
<C.Klaij at marin.nl><mailto:C.Klaij at marin.nl>, "Bas van 't Hof" <bas.vanthof at vortech.nl><mailto:bas.vanthof at vortech.nl>
Onderwerp: Antw.: [petsc-dev] Nested event logging and human friendly
output


 Thank you very much for fixing the errors I introduced and improving the code. I have put it into branch barry/fix-xml-logging and merged to next for testing.

 I do have one concern, when I run on
src/snes/examples/tutorials/ex19.c with no options (see attached
result) <joe.xml> it lists a MatAssemblyEnd() as a top-level event (but not a MatAssemblyBegin()) but there is no MatAssemblyEnd() at the top level, they should all be occurring inside the SNESSolve() and when I run in the debugger all the MatAssemblyEnd() occur within the SNESSolve(). I am not sure why it incorrectly locates the MatAssemblyEnd() as a top level event?

 Thanks again

 Barry






On Jul 8, 2016, at 7:59 AM, Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl> wrote:

Dear Barry,

I found some time to fix the issues with the nested timers. The
attached patch file should work on commit

c03b0cd 2016-07-07 | Merge branch 'stefano_zampini/hypre-ams-zerointerior-feature'

What I have found is the following:

- There were some issues with the merging of the code into the Petsc code base. I have reviewed the merge and fixed this (mainly the section around depth/maxdepth determination).
- There was indeed a fundamental issue, concerning a wrong assumption that the PetscLogEvent id =0 was reserved for the overall 'awake' root event. As it was also used for a normal event, this normal event was mistakenly considered as the root event which caused some trouble. I fixed the code. The issue of the single-event example giving a crash is now resolved as well.
- When running snes/examples/tutorial/ex56, I found that a timer in DMPlexDistribute was not properly ended. If fixed this.

With regard to the latter I wonder why the 'standard' timer events did not notice the fact that the DMPLEX_Distribute was not closed and that it should count as the event with the longest evaluation time. Could it be that the logging disregards any timers that are still open? I was thinking of including a warning message in the nested timers for any open timers at the time of the log generation, but I haven't done that for now.

One thing that is still open is the fact that the nested timers are only considering the timings of the events as far as they are logged in the Main Stage. Timings in other stages are simply ignored. For instance, with the example snes/examples/tutorial/ex56.c, we will only get meaningful nested timing information from the ascii_xml viewer if we set log_stages = PETSC_FALSE on line 13. For now, I see three possible approaches to resolve this:
- Tell the users that they should turn off stages in their code if they would like to use the nested timers. Given the fact that the nested timer functionality basically makes the stages obsolete, this could be a future option.
- After the Main Stage is pushed in PetscLogInitialize, disable the PetscLogStagePush() and PetscLogStagePop() functionality if the ascii_xml viewer is selected for output.
- Adjust the xmllogevent functions to consider the eventPerfInfo array of all stages that are in use. This is however a complex code adjustment which I would not prefer to do, also given the fact that the staging functionality is not relevant for the nested timers.

Please let me know what you think of the above. Could you please include the patch in the Petsc code?

With kind regards,

Koos Huijssen
__________________________________________

VORtech BV - Scientific software engineers
__________________________________________

Dr.ir. Koos Huijssen

P.O. Box 260
2600 AG Delft
The Netherlands

phone  +31(0)15-285 0125
mobile +31(0)6-3333 0803
email koos.huijssen at vortech.nl<mailto:koos.huijssen at vortech.nl>
web   https://emea01.safelinks.protection.outlook.com/?url=www.vortech.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=TIwKTlC0%2FBVOWA6TXzQQKkPUcMYhsAmKagm0W9MXPg8%3D&reserved=0

-----Oorspronkelijk bericht-----
Van: Barry Smith [mailto:bsmith at mcs.anl.gov]
Verzonden: maandag 6 juni 2016 17:21
Aan: Koos Huijssen
CC: Richard Mills; petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Klaij, Christiaan
Onderwerp: Re: [petsc-dev] Nested event logging and human friendly
output


Whenever you can get to it is fine.

Thanks

Barry

On Jun 6, 2016, at 8:14 AM, Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl> wrote:

Dear Barry,

Thanks for notifying us of these issues. There seems to be quite a few fundamental issues with the nested timer functionality and the xml output. We will have to check the case, reproduce the problems and start looking into the code. However, currently we are unable to do so. We may be able to look into the issue in a month or so. Would that be okay for you? If so, then we will come back on the issue in the beginning of July.

With kind regards,

Koos

From: Barry Smith [mailto:bsmith at mcs.anl.gov]
Sent: zondag 5 juni 2016 1:19
To: Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl>; Richard Mills
<richardtmills at gmail.com><mailto:richardtmills at gmail.com>
Cc: petsc-dev at mcs.anl.gov<mailto:petsc-dev at mcs.anl.gov>; Klaij, Christiaan <C.Klaij at marin.nl><mailto:C.Klaij at marin.nl>
Subject: Re: [petsc-dev] Nested event logging and human friendly
output


We are having some major problems with your xml nested logging on a slightly more complicated example and I've been trying to debug it with no success. So I went back to my original commit bb1d7374b64f295b2ed5ff23b89435d65e905a54 and found something I was not expecting. When I run src/snes/examples/tutorials/ex19 with logging it generates the attached image. Which is wrong, note that SNESJacobianEvaluate, KSPSolve etc are embedded in the SNES solver but this is not properly displayed. Shouldn't they be in one level from the SNESSolve? Is this a bug, a feature? Or ...?

Thanks for any information,

 Barry

The major problem we are seeing with the nested logging is in the
branch mark/snes-ex56c when we run src/snes/examples/tutorials/ex56
with

petscmpiexec -n 1 ./ex56 -dm_refine 2 -ne 8 -alpha 1.e-3 -two_solves
false  -petscspace_poly_tensor -petscspace_order 1 -ksp_type cg
-ksp_monitor_short -ksp_rtol 1.e-8 -pc_type gamg -pc_gamg_type agg
-pc_gamg_agg_nsmooths 1 -pc_gamg_coarse_eq_limit 100
-pc_gamg_reuse_interpolation true -pc_gamg_square_graph 1
-pc_gamg_threshold 0.0 -ksp_converged_reason -use_mat_nearnullspace
true -mg_levels_ksp_max_it 2 -mg_levels_ksp_type chebyshev
-mg_levels_esteig_ksp_type cg -mg_levels_esteig_ksp_max_it 10
-mg_levels_ksp_chebyshev_esteig 0,0.05,0,1.05 -mg_levels_pc_type sor
-mat_block_size 3 -petscpartitioner_type chaco -log_view
ascii:ex56-intel2016_knl_fast_64ranks_ne8_dmrefine3_log.xml:ascii_xml

it messes up the nesting and has total nonsense for the numerical values of time, for example in the different events, while the traditional -log_summary prints out reasonable results. It seems somehow either to be not gathering the data properly into the nested event data structures you have or not properly processing the data to generate the xml. I tried debugging but the logic is unclear to me.

Simple programs such as:
ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);

ierr = PetscLogEventBegin(event1,0,0,0,0);CHKERRQ(ierr);
ierr = PetscSleep(1.0);CHKERRQ(ierr);
ierr = PetscLogEventEnd(event1,0,0,0,0);CHKERRQ(ierr);

produce:

[0]PETSC ERROR: Petsc has generated inconsistent data [0]PETSC ERROR:
Depth 2 > maxdepth + 1 1 [0]PETSC ERROR: See
https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.mcs.anl.gov%2Fpetsc%2Fdocumentation%2Ffaq.html&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=7qyvMdTARqZ%2Fj2F3dyI27vL4eaTUFZ9RJPonqdl5fcY%3D&reserved=0 for trouble shooting.
[0]PETSC ERROR: Petsc Development GIT revision: v3.7.1-405-gbb23584
GIT Date: 2016-06-04 11:37:36 -0500 [0]PETSC ERROR: ./ex30 on a
arch-xmllog named Barrys-MacBook-Pro.local by barrysmith Sat Jun  4
18:13:00 2016 [0]PETSC ERROR: Configure options --download-chaco
--with-mpi-dir=/Users/barrysmith/libraries PETSC_ARCH=arch-xmllog
[0]PETSC ERROR: #1 PetscCreateLogTreeNested() line 719 in
/Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c

ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);
ierr = PetscLogEventRegister("Event2",0,&event2);CHKERRQ(ierr);
ierr = PetscLogEventRegister("Event3",0,&event3);CHKERRQ(ierr);

ierr = PetscLogEventBegin(event1,0,0,0,0);CHKERRQ(ierr);
ierr = PetscSleep(1.0);CHKERRQ(ierr);
ierr = PetscLogEventBegin(event2,0,0,0,0);CHKERRQ(ierr);
ierr = PetscSleep(1.0);CHKERRQ(ierr);
ierr = PetscLogEventBegin(event3,0,0,0,0);CHKERRQ(ierr);
ierr = PetscSleep(1.0);CHKERRQ(ierr);
ierr = PetscLogEventEnd(event3,0,0,0,0);CHKERRQ(ierr);
ierr = PetscLogEventEnd(event2,0,0,0,0);CHKERRQ(ierr);
ierr = PetscLogEventEnd(event1,0,0,0,0);CHKERRQ(ierr);

doesn't crash but doesn't nest event2 and 3 in one but does nest 3 into 2.

If seems that the ordering of the event values mater, if  I change the
registration order to

ierr = PetscLogEventRegister("Event2",0,&event2);CHKERRQ(ierr);
ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);
ierr = PetscLogEventRegister("Event3",0,&event3);CHKERRQ(ierr);

then it crashes with

[0]PETSC ERROR: Petsc has generated inconsistent data [0]PETSC ERROR:
Depth 2 > maxdepth + 1 1 [0]PETSC ERROR: See
https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.mcs.anl.gov%2Fpetsc%2Fdocumentation%2Ffaq.html&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=7qyvMdTARqZ%2Fj2F3dyI27vL4eaTUFZ9RJPonqdl5fcY%3D&reserved=0 for trouble shooting.
[0]PETSC ERROR: Petsc Development GIT revision: v3.7.1-405-gbb23584
GIT Date: 2016-06-04 11:37:36 -0500 [0]PETSC ERROR: ./ex30 on a
arch-xmllog named Barrys-MacBook-Pro.local by barrysmith Sat Jun  4
18:17:40 2016 [0]PETSC ERROR: Configure options --download-chaco
--with-mpi-dir=/Users/barrysmith/libraries PETSC_ARCH=arch-xmllog
[0]PETSC ERROR: #1 PetscCreateLogTreeNested() line 719 in
/Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c
[0]PETSC ERROR: #2 PetscLogView_Nested() line 1399 in
/Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c



Possibly related issue: If you run an example that has nothing that is actually logged but attempt to use the -log_view it crashes, there is some implicit assumption in your generation of the xml that some values will be non-empty.






On Sep 18, 2<image002.png>015, at 10:09 PM, Barry Smith <bsmith at mcs.anl.gov><mailto:bsmith at mcs.anl.gov> wrote:


Thank you for contributing the nested logging. I have incorporated
into the PETSc branch barry/xml-nested-logging  if you look at
https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fbitbucket.org%2Fpetsc%2Fpetsc%2Fcommits%2Fbb1d7374b64f295b2ed5ff23b894&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=FwS%2FOWxWFpeBNYTYWoROFjewhf304uPHdZKAYxQqGZA%3D&reserved=0
35d65e905a54?at=masteryou can see exactly what I have incorporated
into PETSc.  I will merge it into next for portability testing in the
next couple of days. I expect over time as I understand it better I
will be able to improve its integration with PETSc.  Currently to
generate the nested logging it is as simple to use as -log_view
:filename.xml:ascii_xml

Thanks again,

Barry






On Sep 14, 2015, at 7:45 AM, Koos Huijssen <koos.huijssen at vortech.nl><mailto:koos.huijssen at vortech.nl> wrote:

Dear PETSc development team,

We have developed an extension of the PETSc event logging facilities that has the following advanced features:

- It allows logging of events in the form of a nested tree. So if some function is called from multiple locations in the code, these instances are distinguished. This in contrast with the standard event logger, which only logs the amount of total call time.
- It allows the output report to be formatted in XML format. This
output can then be viewed in a human-friendly form in a web browser with the use of the XSL Transformation script performance_xml2html.xsl. The html features an nested timings tree that can be expanded and collapsed as desired.

This tool has been very useful for us to analyze the code and pinpoint performance bottle necks. We think that it can be useful for others as well, and therefore we are providing the code here for integration in the open source distribution of PETSc.

For more information I refer to the included manual. We have also provided a test program and a makefile for convenience. The test program can be run using MPI with for instance 3-6 processes.

I apologize for not using the git repo to submit the developed code. I also apologize for not adhering to the PETSc coding standards (or at least not as far as I know), but I hope that it is not too far off.. Apart from the whole capital/underscore standardization stuff one issue may require special attention, namely the (ab)use of the format PETSc_VIEWER_ASCII_IMPL for signaling the XML format in XMLViewer.c. I couldn't find an already existing and better fitting format, but it could be necessary to add a new format here for this purpose.

Can you take it up from here and realize the integration of the code in the PETSc distribution?

With kind regards,

Koos Huijssen

--
____________________________________________________________________

VORtech BV - Scientific software engineers
____________________________________________________________________

Dr.ir. Koos Huijssen

P.O. Box 260
2600 AG Delft
The Netherlands

phone  +31(0)15-285 0125
mobile +31(0)6-3333 0803
email koos.huijssen at vortech.nl<mailto:koos.huijssen at vortech.nl>
web   https://emea01.safelinks.protection.outlook.com/?url=www.vortech.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cf467bc9cbee84636730208d58b2c45c1%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567944636671153&sdata=TIwKTlC0%2FBVOWA6TXzQQKkPUcMYhsAmKagm0W9MXPg8%3D&reserved=0
____________________________________________________________________

<timers.tar.gz>



<0001-ascii_xml-logging-fixes-to-nested-tree-generation-an.patch>



--
____________________________________________________________________

VORtech BV - Scientific software engineers
____________________________________________________________________

Dr.ir. Koos Huijssen

P.O. Box 260
2600 AG Delft
The Netherlands

phone  +31(0)15-251 1942
mobile +31(0)6-3333 0803
email koos.huijssen at vortech.nl<mailto:koos.huijssen at vortech.nl>
web   www.vortech.nl<https://emea01.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.vortech.nl&data=02%7C01%7Ckoos.huijssen%40vortech.nl%7Cfacd8d7d62774fbd849808d58b2da691%7C5fe8f8070fe44cdf8dc636475a0b8555%7C0%7C0%7C636567950566401050&sdata=eD1Vxr3vvRR7N2B0sL09QThjiNsnJtweQwGdJG%2FnAyM%3D&reserved=0>
____________________________________________________________________


--
____________________________________________________________________

VORtech BV - Scientific software engineers
____________________________________________________________________

Dr.ir. Koos Huijssen

P.O. Box 260
2600 AG Delft
The Netherlands

phone  +31(0)15-251 1942
mobile +31(0)6-3333 0803
email koos.huijssen at vortech.nl<mailto:koos.huijssen at vortech.nl>
web   www.vortech.nl<http://www.vortech.nl>
____________________________________________________________________


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagecbaa01.PNG
Type: image/png
Size: 293 bytes
Desc: imagecbaa01.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0008.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagea81454.PNG
Type: image/png
Size: 331 bytes
Desc: imagea81454.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0009.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagebf5793.PNG
Type: image/png
Size: 333 bytes
Desc: imagebf5793.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0010.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imageafd0a5.PNG
Type: image/png
Size: 253 bytes
Desc: imageafd0a5.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0011.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagef19a4a.PNG
Type: image/png
Size: 293 bytes
Desc: imagef19a4a.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0012.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagec9c7db.PNG
Type: image/png
Size: 331 bytes
Desc: imagec9c7db.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0013.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: imagee77338.PNG
Type: image/png
Size: 333 bytes
Desc: imagee77338.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0014.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image1fe079.PNG
Type: image/png
Size: 253 bytes
Desc: image1fe079.PNG
URL: <http://lists.mcs.anl.gov/pipermail/petsc-dev/attachments/20180316/90bdaf50/attachment-0015.png>


More information about the petsc-dev mailing list