<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 15 (filtered medium)">
<!--[if !mso]><style>v\:* {behavior:url(#default#VML);}
o\:* {behavior:url(#default#VML);}
w\:* {behavior:url(#default#VML);}
.shape {behavior:url(#default#VML);}
</style><![endif]--><style><!--
/* Font Definitions */
@font-face
        {font-family:"Cambria Math";
        panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
        {font-family:Calibri;
        panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
        {margin:0cm;
        margin-bottom:.0001pt;
        font-size:12.0pt;
        font-family:"Times New Roman",serif;}
a:link, span.MsoHyperlink
        {mso-style-priority:99;
        color:blue;
        text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
        {mso-style-priority:99;
        color:purple;
        text-decoration:underline;}
p.msonormal0, li.msonormal0, div.msonormal0
        {mso-style-name:msonormal;
        mso-margin-top-alt:auto;
        margin-right:0cm;
        mso-margin-bottom-alt:auto;
        margin-left:0cm;
        font-size:12.0pt;
        font-family:"Times New Roman",serif;}
span.EmailStyle18
        {mso-style-type:personal-reply;
        font-family:"Calibri",sans-serif;
        color:windowtext;}
.MsoChpDefault
        {mso-style-type:export-only;
        font-size:10.0pt;}
@page WordSection1
        {size:612.0pt 792.0pt;
        margin:72.0pt 72.0pt 72.0pt 72.0pt;}
div.WordSection1
        {page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="NL" link="blue" vlink="purple">
<div class="WordSection1">
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US">Dear Barry,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US"><o:p> </o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US">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.<o:p></o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US"><o:p> </o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US">With kind regards,<o:p></o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US"><o:p> </o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US">Koos<o:p></o:p></span></p>
<p class="MsoNormal"><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif;mso-fareast-language:EN-US"><o:p> </o:p></span></p>
<div>
<div style="border:none;border-top:solid #E1E1E1 1.0pt;padding:3.0pt 0cm 0cm 0cm">
<p class="MsoNormal"><b><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif">From:</span></b><span lang="EN-US" style="font-size:11.0pt;font-family:"Calibri",sans-serif"> Barry Smith [mailto:bsmith@mcs.anl.gov]
<br>
<b>Sent:</b> zondag 5 juni 2016 1:19<br>
<b>To:</b> Koos Huijssen <koos.huijssen@vortech.nl>; Richard Mills <richardtmills@gmail.com><br>
<b>Cc:</b> petsc-dev@mcs.anl.gov; Klaij, Christiaan <C.Klaij@marin.nl><br>
<b>Subject:</b> Re: [petsc-dev] Nested event logging and human friendly output<o:p></o:p></span></p>
</div>
</div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<p class="MsoNormal">   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 ...?<o:p></o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">   Thanks for any information,<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">    Barry<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">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 <o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">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<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">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.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">Simple programs such as: <o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">  ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);<br>
<br>
  ierr = PetscLogEventBegin(event1,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscSleep(1.0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventEnd(event1,0,0,0,0);CHKERRQ(ierr);<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">produce:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">[0]PETSC ERROR: Petsc has generated inconsistent data<br>
[0]PETSC ERROR: Depth 2 > maxdepth + 1 1<br>
[0]PETSC ERROR: See <a href="http://www.mcs.anl.gov/petsc/documentation/faq.html">
http://www.mcs.anl.gov/petsc/documentation/faq.html</a> for trouble shooting.<br>
[0]PETSC ERROR: Petsc Development GIT revision: v3.7.1-405-gbb23584  GIT Date: 2016-06-04 11:37:36 -0500<br>
[0]PETSC ERROR: ./ex30 on a arch-xmllog named Barrys-MacBook-Pro.local by barrysmith Sat Jun  4 18:13:00 2016<br>
[0]PETSC ERROR: Configure options --download-chaco --with-mpi-dir=/Users/barrysmith/libraries PETSC_ARCH=arch-xmllog<br>
[0]PETSC ERROR: #1 PetscCreateLogTreeNested() line 719 in /Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">  ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);<br>
  ierr = PetscLogEventRegister("Event2",0,&event2);CHKERRQ(ierr);<br>
  ierr = PetscLogEventRegister("Event3",0,&event3);CHKERRQ(ierr);<br>
<br>
  ierr = PetscLogEventBegin(event1,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscSleep(1.0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventBegin(event2,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscSleep(1.0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventBegin(event3,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscSleep(1.0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventEnd(event3,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventEnd(event2,0,0,0,0);CHKERRQ(ierr);<br>
  ierr = PetscLogEventEnd(event1,0,0,0,0);CHKERRQ(ierr);<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">doesn't crash but doesn't nest event2 and 3 in one but does nest 3 into 2.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">If seems that the ordering of the event values mater, if  I change the registration order to<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">  ierr = PetscLogEventRegister("Event2",0,&event2);CHKERRQ(ierr);<br>
  ierr = PetscLogEventRegister("Event1",0,&event1);CHKERRQ(ierr);<br>
  ierr = PetscLogEventRegister("Event3",0,&event3);CHKERRQ(ierr);<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">then it crashes with <o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">[0]PETSC ERROR: Petsc has generated inconsistent data<br>
[0]PETSC ERROR: Depth 2 > maxdepth + 1 1<br>
[0]PETSC ERROR: See <a href="http://www.mcs.anl.gov/petsc/documentation/faq.html">
http://www.mcs.anl.gov/petsc/documentation/faq.html</a> for trouble shooting.<br>
[0]PETSC ERROR: Petsc Development GIT revision: v3.7.1-405-gbb23584  GIT Date: 2016-06-04 11:37:36 -0500<br>
[0]PETSC ERROR: ./ex30 on a arch-xmllog named Barrys-MacBook-Pro.local by barrysmith Sat Jun  4 18:17:40 2016<br>
[0]PETSC ERROR: Configure options --download-chaco --with-mpi-dir=/Users/barrysmith/libraries PETSC_ARCH=arch-xmllog<br>
[0]PETSC ERROR: #1 PetscCreateLogTreeNested() line 719 in /Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c<br>
[0]PETSC ERROR: #2 PetscLogView_Nested() line 1399 in /Users/barrysmith/Src/petsc/src/sys/logging/xmllogevent.c<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">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.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal"><br>
<br>
<o:p></o:p></p>
<blockquote style="margin-top:5.0pt;margin-bottom:5.0pt">
<p class="MsoNormal">On Sep 18, 2<img border="0" width="1391" height="841" style="width:14.4895in;height:8.7604in" id="_x0037_161FB3B-B16D-4BEE-AA42-A31AA6E9B5D5" src="cid:image002.png@01D1C006.1C194550">015, at 10:09 PM, Barry Smith <<a href="mailto:bsmith@mcs.anl.gov">bsmith@mcs.anl.gov</a>>
 wrote:<o:p></o:p></p>
</blockquote>
<blockquote style="margin-top:5.0pt;margin-bottom:5.0pt">
<p class="MsoNormal"><br>
<br>
  Thank you for contributing the nested logging. I have incorporated into the PETSc branch barry/xml-nested-logging  if you look at  <a href="https://bitbucket.org/petsc/petsc/commits/bb1d7374b64f295b2ed5ff23b89435d65e905a54?at=master">https://bitbucket.org/petsc/petsc/commits/bb1d7374b64f295b2ed5ff23b89435d65e905a54?at=master</a>
 you 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<br>
<br>
 Thanks again,<br>
<br>
  Barry<br>
<br>
<br>
<br>
<br>
<br>
<br>
<o:p></o:p></p>
<blockquote style="margin-top:5.0pt;margin-bottom:5.0pt">
<p class="MsoNormal">On Sep 14, 2015, at 7:45 AM, Koos Huijssen <<a href="mailto:koos.huijssen@vortech.nl">koos.huijssen@vortech.nl</a>> wrote:<br>
<br>
Dear PETSc development team,<br>
<br>
We have developed an extension of the PETSc event logging facilities that has the following advanced features:<br>
<br>
- 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.<br>
- 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<br>
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.<br>
<br>
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.<br>
<br>
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.<br>
<br>
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.<br>
<br>
Can you take it up from here and realize the integration of the code in the PETSc distribution?<br>
<br>
With kind regards,<br>
<br>
Koos Huijssen<br>
<br>
-- <br>
____________________________________________________________________<br>
<br>
VORtech BV - Scientific software engineers<br>
____________________________________________________________________<br>
<br>
Dr.ir. Koos Huijssen<br>
<br>
P.O. Box 260<br>
2600 AG Delft<br>
The Netherlands<br>
<br>
phone  +31(0)15-285 0125<br>
mobile +31(0)6-3333 0803<br>
email <a href="mailto:koos.huijssen@vortech.nl">koos.huijssen@vortech.nl</a><br>
web   <a href="http://www.vortech.nl">www.vortech.nl</a><br>
____________________________________________________________________<br>
<br>
<timers.tar.gz><o:p></o:p></p>
</blockquote>
<p class="MsoNormal"><o:p> </o:p></p>
</blockquote>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
</div>
</div>
</div>
</div>
</body>
</html>