Actual source code: eventlog.c

petsc-3.4.4 2014-03-13
  2: /*
  3:      This defines part of the private API for logging performance information. It is intended to be used only by the
  4:    PETSc PetscLog...() interface and not elsewhere, nor by users. Hence the prototypes for these functions are NOT
  5:    in the public PETSc include files.

  7: */
  8: #include <petsc-private/logimpl.h>  /*I    "petscsys.h"   I*/

 10: /*----------------------------------------------- Creation Functions -------------------------------------------------*/
 11: /* Note: these functions do not have prototypes in a public directory, so they are considered "internal" and not exported. */

 15: /*@C
 16:   EventRegLogCreate - This creates a PetscEventRegLog object.

 18:   Not collective

 20:   Input Parameter:
 21: . eventLog - The PetscEventRegLog

 23:   Level: developer

 25: .keywords: log, event, create
 26: .seealso: EventRegLogDestroy(), PetscStageLogCreate()
 27: @*/
 28: PetscErrorCode EventRegLogCreate(PetscEventRegLog *eventLog)
 29: {
 30:   PetscEventRegLog l;
 31:   PetscErrorCode   ierr;

 34:   PetscNew(struct _n_PetscEventRegLog, &l);
 35:   l->numEvents = 0;
 36:   l->maxEvents = 100;
 37:   PetscMalloc(l->maxEvents * sizeof(PetscEventRegInfo), &l->eventInfo);
 38:   *eventLog    = l;
 39:   return(0);
 40: }

 44: /*@C
 45:   EventRegLogDestroy - This destroys a PetscEventRegLog object.

 47:   Not collective

 49:   Input Paramter:
 50: . eventLog - The PetscEventRegLog

 52:   Level: developer

 54: .keywords: log, event, destroy
 55: .seealso: EventRegLogCreate()
 56: @*/
 57: PetscErrorCode EventRegLogDestroy(PetscEventRegLog eventLog)
 58: {
 59:   int            e;

 63:   for (e = 0; e < eventLog->numEvents; e++) {
 64:     PetscFree(eventLog->eventInfo[e].name);
 65:   }
 66:   PetscFree(eventLog->eventInfo);
 67:   PetscFree(eventLog);
 68:   return(0);
 69: }

 73: /*@C
 74:   EventPerfLogCreate - This creates a PetscEventPerfLog object.

 76:   Not collective

 78:   Input Parameter:
 79: . eventLog - The PetscEventPerfLog

 81:   Level: developer

 83: .keywords: log, event, create
 84: .seealso: EventPerfLogDestroy(), PetscStageLogCreate()
 85: @*/
 86: PetscErrorCode EventPerfLogCreate(PetscEventPerfLog *eventLog)
 87: {
 88:   PetscEventPerfLog l;
 89:   PetscErrorCode    ierr;

 92:   PetscNew(struct _n_PetscEventPerfLog, &l);
 93:   l->numEvents = 0;
 94:   l->maxEvents = 100;
 95:   PetscMalloc(l->maxEvents * sizeof(PetscEventPerfInfo), &l->eventInfo);
 96:   *eventLog    = l;
 97:   return(0);
 98: }

102: /*@C
103:   EventPerfLogDestroy - This destroys a PetscEventPerfLog object.

105:   Not collective

107:   Input Paramter:
108: . eventLog - The PetscEventPerfLog

110:   Level: developer

112: .keywords: log, event, destroy
113: .seealso: EventPerfLogCreate()
114: @*/
115: PetscErrorCode EventPerfLogDestroy(PetscEventPerfLog eventLog)
116: {

120:   PetscFree(eventLog->eventInfo);
121:   PetscFree(eventLog);
122:   return(0);
123: }

125: /*------------------------------------------------ General Functions -------------------------------------------------*/
128: /*@C
129:   EventPerfInfoClear - This clears a PetscEventPerfInfo object.

131:   Not collective

133:   Input Paramter:
134: . eventInfo - The PetscEventPerfInfo

136:   Level: developer

138: .keywords: log, event, destroy
139: .seealso: EventPerfLogCreate()
140: @*/
141: PetscErrorCode EventPerfInfoClear(PetscEventPerfInfo *eventInfo)
142: {
144:   eventInfo->id            = -1;
145:   eventInfo->active        = PETSC_TRUE;
146:   eventInfo->visible       = PETSC_TRUE;
147:   eventInfo->depth         = 0;
148:   eventInfo->count         = 0;
149:   eventInfo->flops         = 0.0;
150:   eventInfo->flops2        = 0.0;
151:   eventInfo->flopsTmp      = 0.0;
152:   eventInfo->time          = 0.0;
153:   eventInfo->time2         = 0.0;
154:   eventInfo->timeTmp       = 0.0;
155:   eventInfo->numMessages   = 0.0;
156:   eventInfo->messageLength = 0.0;
157:   eventInfo->numReductions = 0.0;
158:   return(0);
159: }

163: /*@C
164:   EventPerfInfoCopy - Copy the activity and visibility data in eventInfo to outInfo

166:   Not collective

168:   Input Paramter:
169: . eventInfo - The input PetscEventPerfInfo

171:   Output Paramter:
172: . outInfo   - The output PetscEventPerfInfo

174:   Level: developer

176: .keywords: log, event, copy
177: .seealso: EventPerfInfoClear()
178: @*/
179: PetscErrorCode EventPerfInfoCopy(PetscEventPerfInfo *eventInfo, PetscEventPerfInfo *outInfo)
180: {
182:   outInfo->id      = eventInfo->id;
183:   outInfo->active  = eventInfo->active;
184:   outInfo->visible = eventInfo->visible;
185:   return(0);
186: }

190: /*@C
191:   EventPerfLogEnsureSize - This ensures that a PetscEventPerfLog is at least of a certain size.

193:   Not collective

195:   Input Paramters:
196: + eventLog - The PetscEventPerfLog
197: - size     - The size

199:   Level: developer

201: .keywords: log, event, size, ensure
202: .seealso: EventPerfLogCreate()
203: @*/
204: PetscErrorCode EventPerfLogEnsureSize(PetscEventPerfLog eventLog, int size)
205: {
206:   PetscEventPerfInfo *eventInfo;
207:   PetscErrorCode     ierr;

210:   while (size > eventLog->maxEvents) {
211:     PetscMalloc(eventLog->maxEvents*2 * sizeof(PetscEventPerfInfo), &eventInfo);
212:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(PetscEventPerfInfo));
213:     PetscFree(eventLog->eventInfo);

215:     eventLog->eventInfo  = eventInfo;
216:     eventLog->maxEvents *= 2;
217:   }
218:   while (eventLog->numEvents < size) {
219:     EventPerfInfoClear(&eventLog->eventInfo[eventLog->numEvents++]);
220:   }
221:   return(0);
222: }

224: #if defined(PETSC_HAVE_MPE)
225: #include "mpe.h"
226: PETSC_INTERN PetscErrorCode PetscLogMPEGetRGBColor(const char*[]);
229: PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
230: {
231:   PetscErrorCode    ierr;

234:   MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_begin,0,NULL);
235:   return(0);
236: }

240: PetscErrorCode PetscLogEventEndMPE(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
241: {
242:   PetscErrorCode    ierr;

245:   MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_end,0,NULL);
246:   return(0);
247: }
248: #endif

250: /*--------------------------------------------- Registration Functions ----------------------------------------------*/
253: /*@C
254:   EventRegLogRegister - Registers an event for logging operations in an application code.

256:   Not Collective

258:   Input Parameters:
259: + eventLog - The EventLog
260: . ename    - The name associated with the event
261: - classid   - The classid associated to the class for this event

263:   Output Parameter:
264: . event    - The event

266:   Example of Usage:
267: .vb
268:       int USER_EVENT;
269:       PetscLogDouble user_event_flops;
270:       PetscLogEventRegister("User event name",0,&USER_EVENT);
271:       PetscLogEventBegin(USER_EVENT,0,0,0,0);
272:          [code segment to monitor]
273:          PetscLogFlops(user_event_flops);
274:       PetscLogEventEnd(USER_EVENT,0,0,0,0);
275: .ve

277:   Notes:
278:   PETSc automatically logs library events if the code has been
279:   compiled with -DPETSC_USE_LOG (which is the default) and -log,
280:   -log_summary, or -log_all are specified.  PetscLogEventRegister() is
281:   intended for logging user events to supplement this PETSc
282:   information.

284:   PETSc can gather data for use with the utilities Jumpshot
285:   (part of the MPICH distribution).  If PETSc has been compiled
286:   with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
287:   MPICH), the user can employ another command line option, -log_mpe,
288:   to create a logfile, "mpe.log", which can be visualized
289:   Jumpshot.

291:   Level: developer

293: .keywords: log, event, register
294: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
295:           EventLogActivate(), EventLogDeactivate()
296: @*/
297: PetscErrorCode EventRegLogRegister(PetscEventRegLog eventLog, const char ename[], PetscClassId classid, PetscLogEvent *event)
298: {
299:   PetscEventRegInfo *eventInfo;
300:   char              *str;
301:   int               e;
302:   PetscErrorCode    ierr;

307:   /* Should check classid I think */
308:   e = eventLog->numEvents++;
309:   if (eventLog->numEvents > eventLog->maxEvents) {
310:     PetscMalloc(eventLog->maxEvents*2 * sizeof(PetscEventRegInfo), &eventInfo);
311:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(PetscEventRegInfo));
312:     PetscFree(eventLog->eventInfo);

314:     eventLog->eventInfo  = eventInfo;
315:     eventLog->maxEvents *= 2;
316:   }
317:   PetscStrallocpy(ename, &str);

319:   eventLog->eventInfo[e].name    = str;
320:   eventLog->eventInfo[e].classid = classid;
321: #if defined(PETSC_HAVE_MPE)
322:   if (PetscLogPLB == PetscLogEventBeginMPE) {
323:     const char  *color;
324:     PetscMPIInt rank;
325:     int         beginID, endID;

327:     beginID = MPE_Log_get_event_number();
328:     endID   = MPE_Log_get_event_number();

330:     eventLog->eventInfo[e].mpe_id_begin = beginID;
331:     eventLog->eventInfo[e].mpe_id_end   = endID;

333:     MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
334:     if (!rank) {
335:       PetscLogMPEGetRGBColor(&color);
336:       MPE_Describe_state(beginID, endID, str, (char*)color);
337:     }
338:   }
339: #endif
340:   *event = e;
341:   return(0);
342: }

344: /*---------------------------------------------- Activation Functions -----------------------------------------------*/
347: /*@C
348:   EventPerfLogActivate - Indicates that a particular event should be logged.

350:   Not Collective

352:   Input Parameters:
353: + eventLog - The PetscEventPerfLog
354: - event    - The event

356:    Usage:
357: .vb
358:       EventPerfLogDeactivate(log, VEC_SetValues);
359:         [code where you do not want to log VecSetValues()]
360:       EventPerfLogActivate(log, VEC_SetValues);
361:         [code where you do want to log VecSetValues()]
362: .ve

364:   Note:
365:   The event may be either a pre-defined PETSc event (found in
366:   include/petsclog.h) or an event number obtained with EventRegLogRegister().

368:   Level: developer

370: .keywords: log, event, activate
371: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogDeactivate()
372: @*/
373: PetscErrorCode EventPerfLogActivate(PetscEventPerfLog eventLog, PetscLogEvent event)
374: {
376:   eventLog->eventInfo[event].active = PETSC_TRUE;
377:   return(0);
378: }

382: /*@C
383:   EventPerfLogDeactivate - Indicates that a particular event should not be logged.

385:   Not Collective

387:   Input Parameters:
388: + eventLog - The PetscEventPerfLog
389: - event    - The event

391:    Usage:
392: .vb
393:       EventPerfLogDeactivate(log, VEC_SetValues);
394:         [code where you do not want to log VecSetValues()]
395:       EventPerfLogActivate(log, VEC_SetValues);
396:         [code where you do want to log VecSetValues()]
397: .ve

399:   Note:
400:   The event may be either a pre-defined PETSc event (found in
401:   include/petsclog.h) or an event number obtained with EventRegLogRegister().

403:   Level: developer

405: .keywords: log, event, activate
406: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogActivate()
407: @*/
408: PetscErrorCode EventPerfLogDeactivate(PetscEventPerfLog eventLog, PetscLogEvent event)
409: {
411:   eventLog->eventInfo[event].active = PETSC_FALSE;
412:   return(0);
413: }

417: /*@C
418:   EventPerfLogActivateClass - Activates event logging for a PETSc object class.

420:   Not Collective

422:   Input Parameters:
423: + eventLog    - The PetscEventPerfLog
424: . eventRegLog - The PetscEventRegLog
425: - classid      - The class id, for example MAT_CLASSID, SNES_CLASSID,

427:   Level: developer

429: .seealso: EventPerfLogDeactivateClass(), EventPerfLogActivate(), EventPerfLogDeactivate()
430: @*/
431: PetscErrorCode EventPerfLogActivateClass(PetscEventPerfLog eventLog, PetscEventRegLog eventRegLog, PetscClassId classid)
432: {
433:   int e;

436:   for (e = 0; e < eventLog->numEvents; e++) {
437:     int c = eventRegLog->eventInfo[e].classid;
438:     if (c == classid) eventLog->eventInfo[e].active = PETSC_TRUE;
439:   }
440:   return(0);
441: }

445: /*@C
446:   EventPerfLogDeactivateClass - Deactivates event logging for a PETSc object class.

448:   Not Collective

450:   Input Parameters:
451: + eventLog    - The PetscEventPerfLog
452: . eventRegLog - The PetscEventRegLog
453: - classid - The class id, for example MAT_CLASSID, SNES_CLASSID,

455:   Level: developer

457: .seealso: EventPerfLogDeactivateClass(), EventPerfLogDeactivate(), EventPerfLogActivate()
458: @*/
459: PetscErrorCode EventPerfLogDeactivateClass(PetscEventPerfLog eventLog, PetscEventRegLog eventRegLog, PetscClassId classid)
460: {
461:   int e;

464:   for (e = 0; e < eventLog->numEvents; e++) {
465:     int c = eventRegLog->eventInfo[e].classid;
466:     if (c == classid) eventLog->eventInfo[e].active = PETSC_FALSE;
467:   }
468:   return(0);
469: }

471: /*------------------------------------------------ Query Functions --------------------------------------------------*/
474: /*@C
475:   EventRegLogGetEvent - This function returns the event id given the event name.

477:   Not Collective

479:   Input Parameters:
480: + eventLog - The PetscEventRegLog
481: - name     - The stage name

483:   Output Parameter:
484: . event    - The event id

486:   Level: developer

488: .keywords: log, stage
489: .seealso: EventRegLogRegister()
490: @*/
491: PetscErrorCode  EventRegLogGetEvent(PetscEventRegLog eventLog, const char name[], PetscLogEvent *event)
492: {
493:   PetscBool      match;
494:   int            e;

500:   *event = -1;
501:   for (e = 0; e < eventLog->numEvents; e++) {
502:     PetscStrcasecmp(eventLog->eventInfo[e].name, name, &match);
503:     if (match) break;
504:   }
505:   if (e == eventLog->numEvents) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONG, "No event named %s", name);
506:   *event = e;
507:   return(0);
508: }

512: /*@C
513:   EventPerfLogSetVisible - This function determines whether an event is printed during PetscLogView()

515:   Not Collective

517:   Input Parameters:
518: + eventLog  - The PetscEventPerfLog
519: . event     - The event to log
520: - isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)

522:   Database Options:
523: . -log_summary - Activates log summary

525:   Level: developer

527: .keywords: log, visible, event
528: .seealso: EventPerfLogGetVisible(), EventRegLogRegister(), PetscStageLogGetEventLog()
529: @*/
530: PetscErrorCode EventPerfLogSetVisible(PetscEventPerfLog eventLog, PetscLogEvent event, PetscBool isVisible)
531: {
533:   eventLog->eventInfo[event].visible = isVisible;
534:   return(0);
535: }

539: /*@C
540:   EventPerfLogGetVisible - This function returns whether an event is printed during PetscLogView()

542:   Not Collective

544:   Input Parameters:
545: + eventLog  - The PetscEventPerfLog
546: - event     - The event id to log

548:   Output Parameter:
549: . isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)

551:   Database Options:
552: . -log_summary - Activates log summary

554:   Level: developer

556: .keywords: log, visible, event
557: .seealso: EventPerfLogSetVisible(), EventRegLogRegister(), PetscStageLogGetEventLog()
558: @*/
559: PetscErrorCode EventPerfLogGetVisible(PetscEventPerfLog eventLog, PetscLogEvent event, PetscBool  *isVisible)
560: {
563:   *isVisible = eventLog->eventInfo[event].visible;
564:   return(0);
565: }

569: PetscErrorCode PetscLogEventGetFlops(PetscLogEvent event, PetscLogDouble *flops)
570: {
571:   PetscStageLog     stageLog;
572:   PetscEventPerfLog eventLog = NULL;
573:   int               stage;
574:   PetscErrorCode    ierr;

577:   PetscLogGetStageLog(&stageLog);
578:   PetscStageLogGetCurrent(stageLog, &stage);
579:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
580:   *flops = eventLog->eventInfo[event].flops;
581:   return(0);
582: }

586: PetscErrorCode PetscLogEventZeroFlops(PetscLogEvent event)
587: {
588:   PetscStageLog     stageLog;
589:   PetscEventPerfLog eventLog = NULL;
590:   int               stage;
591:   PetscErrorCode    ierr;

594:   PetscLogGetStageLog(&stageLog);
595:   PetscStageLogGetCurrent(stageLog, &stage);
596:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);

598:   eventLog->eventInfo[event].flops    = 0.0;
599:   eventLog->eventInfo[event].flops2   = 0.0;
600:   eventLog->eventInfo[event].flopsTmp = 0.0;
601:   return(0);
602: }

604: #if defined(PETSC_HAVE_CHUD)
605: #include <CHUD/CHUD.h>
606: #endif
607: #if defined(PETSC_HAVE_PAPI)
608: #include <papi.h>
609: extern int PAPIEventSet;
610: #endif

614: PetscErrorCode PetscLogEventBeginDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
615: {
616:   PetscStageLog     stageLog;
617:   PetscEventPerfLog eventLog = NULL;
618:   int               stage;
619:   PetscErrorCode    ierr;

622:   PetscLogGetStageLog(&stageLog);
623:   PetscStageLogGetCurrent(stageLog, &stage);
624:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
625:   /* Check for double counting */
626:   eventLog->eventInfo[event].depth++;
627:   if (eventLog->eventInfo[event].depth > 1) return(0);
628:   /* Log performance info */
629:   eventLog->eventInfo[event].count++;
630:   eventLog->eventInfo[event].timeTmp = 0.0;
631:   PetscTimeSubtract(&eventLog->eventInfo[event].timeTmp);
632:   eventLog->eventInfo[event].flopsTmp = 0.0;
633: #if defined(PETSC_HAVE_CHUD)
634:   eventLog->eventInfo[event].flopsTmp -= chudGetPMCEventCount(chudCPU1Dev,PMC_1);
635: #elif defined(PETSC_HAVE_PAPI)
636:   { long_long values[2];
637:     PAPI_read(PAPIEventSet,values);

639:     eventLog->eventInfo[event].flopsTmp -= values[0];
640:     /*    printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
641:   }
642: #else
643:   eventLog->eventInfo[event].flopsTmp -= petsc_TotalFlops;
644: #endif
645:   eventLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
646:   eventLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
647:   eventLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
648:   return(0);
649: }

653: PetscErrorCode PetscLogEventEndDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
654: {
655:   PetscStageLog     stageLog;
656:   PetscEventPerfLog eventLog = NULL;
657:   int               stage;
658:   PetscErrorCode    ierr;

661:   PetscLogGetStageLog(&stageLog);
662:   PetscStageLogGetCurrent(stageLog, &stage);
663:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
664:   /* Check for double counting */
665:   eventLog->eventInfo[event].depth--;
666:   if (eventLog->eventInfo[event].depth > 0) return(0);
667:   else if (eventLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
668:   /* Log performance info */
669:   PetscTimeAdd(&eventLog->eventInfo[event].timeTmp);
670:   eventLog->eventInfo[event].time  += eventLog->eventInfo[event].timeTmp;
671:   eventLog->eventInfo[event].time2 += eventLog->eventInfo[event].timeTmp*eventLog->eventInfo[event].timeTmp;
672: #if defined(PETSC_HAVE_CHUD)
673:   eventLog->eventInfo[event].flopsTmp += chudGetPMCEventCount(chudCPU1Dev,PMC_1);
674: #elif defined(PETSC_HAVE_PAPI)
675:   { long_long values[2];
676:     PAPI_read(PAPIEventSet,values);

678:     eventLog->eventInfo[event].flopsTmp += values[0];
679:     /* printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
680:   }
681: #else
682:   eventLog->eventInfo[event].flopsTmp += petsc_TotalFlops;
683: #endif
684:   eventLog->eventInfo[event].flops         += eventLog->eventInfo[event].flopsTmp;
685:   eventLog->eventInfo[event].flops2        += eventLog->eventInfo[event].flopsTmp*eventLog->eventInfo[event].flopsTmp;
686:   eventLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
687:   eventLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
688:   eventLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
689:   return(0);
690: }

694: PetscErrorCode PetscLogEventBeginComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
695: {
696:   PetscStageLog     stageLog;
697:   PetscEventRegLog  eventRegLog;
698:   PetscEventPerfLog eventPerfLog = NULL;
699:   Action            *tmpAction;
700:   PetscLogDouble    start, end;
701:   PetscLogDouble    curTime;
702:   int               stage;
703:   PetscErrorCode    ierr;

706:   /* Dynamically enlarge logging structures */
707:   if (petsc_numActions >= petsc_maxActions) {
708:     PetscTime(&start);
709:     PetscMalloc(petsc_maxActions*2 * sizeof(Action), &tmpAction);
710:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
711:     PetscFree(petsc_actions);

713:     petsc_actions     = tmpAction;
714:     petsc_maxActions *= 2;
715:     PetscTime(&end);
716:     petsc_BaseTime += (end - start);
717:   }
718:   /* Record the event */
719:   PetscLogGetStageLog(&stageLog);
720:   PetscStageLogGetCurrent(stageLog, &stage);
721:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
722:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
723:   PetscTime(&curTime);
724:   if (petsc_logActions) {
725:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
726:     petsc_actions[petsc_numActions].action  = ACTIONBEGIN;
727:     petsc_actions[petsc_numActions].event   = event;
728:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
729:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
730:     else petsc_actions[petsc_numActions].id1 = -1;
731:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
732:     else petsc_actions[petsc_numActions].id2 = -1;
733:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
734:     else petsc_actions[petsc_numActions].id3 = -1;
735:     petsc_actions[petsc_numActions].flops = petsc_TotalFlops;

737:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
738:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
739:     petsc_numActions++;
740:   }
741:   /* Check for double counting */
742:   eventPerfLog->eventInfo[event].depth++;
743:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
744:   /* Log the performance info */
745:   eventPerfLog->eventInfo[event].count++;
746:   eventPerfLog->eventInfo[event].time          -= curTime;
747:   eventPerfLog->eventInfo[event].flops         -= petsc_TotalFlops;
748:   eventPerfLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
749:   eventPerfLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
750:   eventPerfLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
751:   return(0);
752: }

756: PetscErrorCode PetscLogEventEndComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
757: {
758:   PetscStageLog     stageLog;
759:   PetscEventRegLog  eventRegLog;
760:   PetscEventPerfLog eventPerfLog = NULL;
761:   Action            *tmpAction;
762:   PetscLogDouble    start, end;
763:   PetscLogDouble    curTime;
764:   int               stage;
765:   PetscErrorCode    ierr;

768:   /* Dynamically enlarge logging structures */
769:   if (petsc_numActions >= petsc_maxActions) {
770:     PetscTime(&start);
771:     PetscMalloc(petsc_maxActions*2 * sizeof(Action), &tmpAction);
772:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
773:     PetscFree(petsc_actions);

775:     petsc_actions     = tmpAction;
776:     petsc_maxActions *= 2;
777:     PetscTime(&end);
778:     petsc_BaseTime += (end - start);
779:   }
780:   /* Record the event */
781:   PetscLogGetStageLog(&stageLog);
782:   PetscStageLogGetCurrent(stageLog, &stage);
783:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
784:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
785:   PetscTime(&curTime);
786:   if (petsc_logActions) {
787:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
788:     petsc_actions[petsc_numActions].action  = ACTIONEND;
789:     petsc_actions[petsc_numActions].event   = event;
790:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
791:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
792:     else petsc_actions[petsc_numActions].id1 = -1;
793:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
794:     else petsc_actions[petsc_numActions].id2 = -1;
795:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
796:     else petsc_actions[petsc_numActions].id3 = -1;
797:     petsc_actions[petsc_numActions].flops = petsc_TotalFlops;

799:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
800:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
801:     petsc_numActions++;
802:   }
803:   /* Check for double counting */
804:   eventPerfLog->eventInfo[event].depth--;
805:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
806:   else if (eventPerfLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
807:   /* Log the performance info */
808:   eventPerfLog->eventInfo[event].count++;
809:   eventPerfLog->eventInfo[event].time          += curTime;
810:   eventPerfLog->eventInfo[event].flops         += petsc_TotalFlops;
811:   eventPerfLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
812:   eventPerfLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
813:   eventPerfLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
814:   return(0);
815: }

819: PetscErrorCode PetscLogEventBeginTrace(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
820: {
821:   PetscStageLog     stageLog;
822:   PetscEventRegLog  eventRegLog;
823:   PetscEventPerfLog eventPerfLog = NULL;
824:   PetscLogDouble    cur_time;
825:   PetscMPIInt       rank;
826:   int               stage,err;
827:   PetscErrorCode    ierr;

830:   if (!petsc_tracetime) PetscTime(&petsc_tracetime);

832:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
833:   PetscLogGetStageLog(&stageLog);
834:   PetscStageLogGetCurrent(stageLog, &stage);
835:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
836:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
837:   /* Check for double counting */
838:   eventPerfLog->eventInfo[event].depth++;
839:   petsc_tracelevel++;
840:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
841:   /* Log performance info */
842:   PetscTime(&cur_time);
843:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event begin: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
844:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);

846:   petsc_tracespace[2*petsc_tracelevel] = 0;

848:   err = fflush(petsc_tracefile);
849:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
850:   return(0);
851: }

855: PetscErrorCode PetscLogEventEndTrace(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
856: {
857:   PetscStageLog     stageLog;
858:   PetscEventRegLog  eventRegLog;
859:   PetscEventPerfLog eventPerfLog = NULL;
860:   PetscLogDouble    cur_time;
861:   int               stage,err;
862:   PetscMPIInt       rank;
863:   PetscErrorCode    ierr;

866:   petsc_tracelevel--;
867:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
868:   PetscLogGetStageLog(&stageLog);
869:   PetscStageLogGetCurrent(stageLog, &stage);
870:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
871:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
872:   /* Check for double counting */
873:   eventPerfLog->eventInfo[event].depth--;
874:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
875:   else if (eventPerfLog->eventInfo[event].depth < 0 || petsc_tracelevel < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");

877:   /* Log performance info */
878:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);

880:   petsc_tracespace[2*petsc_tracelevel] = 0;
881:   PetscTime(&cur_time);
882:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event end: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
883:   err  = fflush(petsc_tracefile);
884:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
885:   return(0);
886: }