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 <[email protected]> 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 | [email protected] | www.marin.nl > > <image15100b.PNG> <imageb2c83e.PNG> <imagebd077a.PNG> <image2e1442.PNG> > MARIN news: Numerical study of cavitation on a NACA0015 hydrofoil: solution > verification > From: Koos Huijssen <[email protected]> > Sent: Friday, August 12, 2016 8:07 AM > To: Barry Smith > Cc: [email protected]; 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 <[email protected]> > Sent: Friday, August 12, 2016 4:02:42 AM > To: Koos Huijssen > Cc: [email protected]; 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 <[email protected]> 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:[email protected]] > > Sent: vrijdag 5 augustus 2016 22:39 > > To: Koos Huijssen <[email protected]> > > Cc: [email protected]; Klaij, Christiaan <[email protected]>; Bas van 't > > Hof <[email protected]> > > 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 <[email protected]> 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 <[email protected]> > >> Subject: Fwd: [petsc-dev] Nested event logging and human friendly > >> output > >> > >> > >> > >> > >> Begin doorgestuurd bericht: > >> > >> Van: Barry Smith <[email protected]> > >> Datum: 17 juli 2016 04:44:04 CEST > >> Aan: Koos Huijssen <[email protected]> > >> Kopie: Richard Mills <[email protected]>, > >> "[email protected]" <[email protected]>, "Klaij, Christiaan" > >> <[email protected]>, "Bas van 't Hof" <[email protected]> > >> 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 <[email protected]> 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 [email protected] > >> web www.vortech.nl > >> > >> -----Oorspronkelijk bericht----- > >> Van: Barry Smith [mailto:[email protected]] > >> Verzonden: maandag 6 juni 2016 17:21 > >> Aan: Koos Huijssen > >> CC: Richard Mills; [email protected]; 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 <[email protected]> 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:[email protected]] > >> Sent: zondag 5 juni 2016 1:19 > >> To: Koos Huijssen <[email protected]>; Richard Mills > >> <[email protected]> > >> Cc: [email protected]; Klaij, Christiaan <[email protected]> > >> 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 > >> http://www.mcs.anl.gov/petsc/documentation/faq.html 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 > >> http://www.mcs.anl.gov/petsc/documentation/faq.html 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 > >> <[email protected]> wrote: > >> > >> > >> Thank you for contributing the nested logging. I have incorporated > >> into the PETSc branch barry/xml-nested-logging if you look at > >> https://bitbucket.org/petsc/petsc/commits/bb1d7374b64f295b2ed5ff23b894 > >> 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 <[email protected]> > >> 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 [email protected] > >> web www.vortech.nl > >> ____________________________________________________________________ > >> > >> <timers.tar.gz> > >> > >> > >> > >> <0001-ascii_xml-logging-fixes-to-nested-tree-generation-an.patch> > > >
