Actual source code: eventLog.c

      1: #define PETSC_DLL

     3:  #include petsc.h
     4:  #include src/sys/src/plog/ptime.h
     5:  #include plog.h

      7: /* Variables for the tracing logger */

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

     19: /*@C
     20:   EventRegLogCreate - This creates a EventRegLog object.

     22:   Not collective

     24:   Input Parameter:
     25: . eventLog - The EventRegLog

     27:   Level: beginner

     29: .keywords: log, event, create
     30: .seealso: EventRegLogDestroy(), StageLogCreate()
     31: @*/
     32: PetscErrorCode EventRegLogCreate(EventRegLog *eventLog)
     33: {
     34:   EventRegLog l;

     38:   PetscNew(struct _EventRegLog, &l);
     39:   l->numEvents   = 0;
     40:   l->maxEvents   = 100;
     41:   PetscMalloc(l->maxEvents * sizeof(EventRegInfo), &l->eventInfo);
     42:   *eventLog = l;
     43:   return(0);
     44: }

     48: /*@C
     49:   EventRegLogDestroy - This destroys a EventRegLog object.

     51:   Not collective

     53:   Input Paramter:
     54: . eventLog - The EventRegLog

     56:   Level: beginner

     58: .keywords: log, event, destroy
     59: .seealso: EventRegLogCreate()
     60: @*/
     61: PetscErrorCode EventRegLogDestroy(EventRegLog eventLog)
     62: {
     63:   int e;

     67:   for(e = 0; e < eventLog->numEvents; e++) {
     68:     PetscFree(eventLog->eventInfo[e].name);
     69:   }
     70:   PetscFree(eventLog->eventInfo);
     71:   PetscFree(eventLog);
     72:   return(0);
     73: }

     77: /*@C
     78:   EventPerfLogCreate - This creates a EventPerfLog object.

     80:   Not collective

     82:   Input Parameter:
     83: . eventLog - The EventPerfLog

     85:   Level: beginner

     87: .keywords: log, event, create
     88: .seealso: EventPerfLogDestroy(), StageLogCreate()
     89: @*/
     90: PetscErrorCode EventPerfLogCreate(EventPerfLog *eventLog)
     91: {
     92:   EventPerfLog l;

     96:   PetscNew(struct _EventPerfLog, &l);
     97:   l->numEvents   = 0;
     98:   l->maxEvents   = 100;
     99:   PetscMalloc(l->maxEvents * sizeof(EventPerfInfo), &l->eventInfo);
    100:   *eventLog = l;
    101:   return(0);
    102: }

    106: /*@C
    107:   EventPerfLogDestroy - This destroys a EventPerfLog object.

    109:   Not collective

    111:   Input Paramter:
    112: . eventLog - The EventPerfLog

    114:   Level: beginner

    116: .keywords: log, event, destroy
    117: .seealso: EventPerfLogCreate()
    118: @*/
    119: PetscErrorCode EventPerfLogDestroy(EventPerfLog eventLog)
    120: {

    124:   PetscFree(eventLog->eventInfo);
    125:   PetscFree(eventLog);
    126:   return(0);
    127: }

    129: /*------------------------------------------------ General Functions -------------------------------------------------*/
    132: /*@C
    133:   EventPerfInfoClear - This clears a EventPerfInfo object.

    135:   Not collective

    137:   Input Paramter:
    138: . eventInfo - The EventPerfInfo

    140:   Level: beginner

    142: .keywords: log, event, destroy
    143: .seealso: EventPerfLogCreate()
    144: @*/
    145: PetscErrorCode EventPerfInfoClear(EventPerfInfo *eventInfo)
    146: {
    148:   eventInfo->id            = -1;
    149:   eventInfo->active        = PETSC_TRUE;
    150:   eventInfo->visible       = PETSC_TRUE;
    151:   eventInfo->depth         = 0;
    152:   eventInfo->count         = 0;
    153:   eventInfo->flops         = 0.0;
    154:   eventInfo->time          = 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 EventPerfInfo

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

    174:   Level: beginner

    176: .keywords: log, event, copy
    177: .seealso: EventPerfInfoClear()
    178: @*/
    179: PetscErrorCode EventPerfInfoCopy(EventPerfInfo *eventInfo, EventPerfInfo *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 EventPerfLog is at least of a certain size.

    193:   Not collective

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

    199:   Level: intermediate

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

    210:   while(size > eventLog->maxEvents) {
    211:     PetscMalloc(eventLog->maxEvents*2 * sizeof(EventPerfInfo), &eventInfo);
    212:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(EventPerfInfo));
    213:     PetscFree(eventLog->eventInfo);
    214:     eventLog->eventInfo  = eventInfo;
    215:     eventLog->maxEvents *= 2;
    216:   }
    217:   while(eventLog->numEvents < size) {
    218:     EventPerfInfoClear(&eventLog->eventInfo[eventLog->numEvents++]);
    219:   }
    220:   return(0);
    221: }

    223: /*--------------------------------------------- Registration Functions ----------------------------------------------*/
    226: /*@C
    227:   EventRegLogRegister - Registers an event for logging operations in an application code.

    229:   Not Collective

    231:   Input Parameters:
    232: + eventLog - The EventLog
    233: . ename    - The name associated with the event
    234: - cookie   - The cookie associated to the class for this event

    236:   Output Parameter:
    237: . event    - The event

    239:   Example of Usage:
    240: .vb
    241:       int USER_EVENT;
    242:       int user_event_flops;
    243:       PetscLogEventRegister(&USER_EVENT,"User event name");
    244:       PetscLogEventBegin(USER_EVENT,0,0,0,0);
    245:          [code segment to monitor]
    246:          PetscLogFlops(user_event_flops);
    247:       PetscLogEventEnd(USER_EVENT,0,0,0,0);
    248: .ve

    250:   Notes:
    251:   PETSc automatically logs library events if the code has been
    252:   compiled with -DPETSC_USE_LOG (which is the default) and -log,
    253:   -log_summary, or -log_all are specified.  PetscLogEventRegister() is
    254:   intended for logging user events to supplement this PETSc
    255:   information.

    257:   PETSc can gather data for use with the utilities Upshot/Nupshot
    258:   (part of the MPICH distribution).  If PETSc has been compiled
    259:   with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
    260:   MPICH), the user can employ another command line option, -log_mpe,
    261:   to create a logfile, "mpe.log", which can be visualized
    262:   Upshot/Nupshot.

    264:   Level: intermediate

    266: .keywords: log, event, register
    267: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
    268:           EventLogActivate(), EventLogDeactivate()
    269: @*/
    270: PetscErrorCode EventRegLogRegister(EventRegLog eventLog, const char ename[], PetscCookie cookie, PetscEvent *event)
    271: {
    272:   EventRegInfo *eventInfo;
    273:   char         *str;
    274:   int           e;

    280:   /* Should check cookie I think */
    281:   e = eventLog->numEvents++;
    282:   if (eventLog->numEvents > eventLog->maxEvents) {
    283:     PetscMalloc(eventLog->maxEvents*2 * sizeof(EventRegInfo), &eventInfo);
    284:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(EventRegInfo));
    285:     PetscFree(eventLog->eventInfo);
    286:     eventLog->eventInfo  = eventInfo;
    287:     eventLog->maxEvents *= 2;
    288:   }
    289:   PetscStrallocpy(ename, &str);
    290:   eventLog->eventInfo[e].name   = str;
    291:   eventLog->eventInfo[e].cookie = cookie;
    292: #if defined(PETSC_HAVE_MPE)
    293:   if (UseMPE) {
    294:     const char  *color;
    295:     PetscMPIInt rank;
    296:     int         beginID, endID;

    298:     beginID = MPE_Log_get_event_number();
    299:     endID   = MPE_Log_get_event_number();
    300:     eventLog->eventInfo[e].mpe_id_begin = beginID;
    301:     eventLog->eventInfo[e].mpe_id_end   = endID;
    302:     MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
    303:     if (!rank) {
    304:       PetscLogGetRGBColor(&color);
    305:       MPE_Describe_state(beginID, endID, str, (char*)color);
    306:     }
    307:   }
    308: #endif
    309:   *event = e;
    310:   return(0);
    311: }

    313: /*---------------------------------------------- Activation Functions -----------------------------------------------*/
    316: /*@C
    317:   EventPerfLogActivate - Indicates that a particular event should be logged.

    319:   Not Collective

    321:   Input Parameters:
    322: + eventLog - The EventPerfLog
    323: - event    - The event

    325:    Usage:
    326: .vb
    327:       EventPerfLogDeactivate(log, VEC_SetValues);
    328:         [code where you do not want to log VecSetValues()]
    329:       EventPerfLogActivate(log, VEC_SetValues);
    330:         [code where you do want to log VecSetValues()]
    331: .ve

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

    337:   Level: advanced

    339: .keywords: log, event, activate
    340: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogDeactivate()
    341: @*/
    342: PetscErrorCode EventPerfLogActivate(EventPerfLog eventLog, PetscEvent event)
    343: {
    345:   eventLog->eventInfo[event].active = PETSC_TRUE;
    346:   return(0);
    347: }

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

    354:   Not Collective

    356:   Input Parameters:
    357: + eventLog - The EventPerfLog
    358: - event    - The event

    360:    Usage:
    361: .vb
    362:       EventPerfLogDeactivate(log, VEC_SetValues);
    363:         [code where you do not want to log VecSetValues()]
    364:       EventPerfLogActivate(log, VEC_SetValues);
    365:         [code where you do want to log VecSetValues()]
    366: .ve

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

    372:   Level: advanced

    374: .keywords: log, event, activate
    375: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogActivate()
    376: @*/
    377: PetscErrorCode EventPerfLogDeactivate(EventPerfLog eventLog, PetscEvent event)
    378: {
    380:   eventLog->eventInfo[event].active = PETSC_FALSE;
    381:   return(0);
    382: }

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

    389:   Not Collective

    391:   Input Parameters:
    392: + eventLog    - The EventPerfLog
    393: . eventRegLog - The EventRegLog
    394: - cookie      - The class id, for example MAT_COOKIE, SNES_COOKIE,

    396:   Level: developer

    398: .seealso: EventPerfLogDeactivateClass(), EventPerfLogActivate(), EventPerfLogDeactivate()
    399: @*/
    400: PetscErrorCode EventPerfLogActivateClass(EventPerfLog eventLog, EventRegLog eventRegLog, PetscCookie cookie)
    401: {
    402:   int e;

    405:   for(e = 0; e < eventLog->numEvents; e++) {
    406:     int c = eventRegLog->eventInfo[e].cookie;

    408:     if (c == cookie) eventLog->eventInfo[e].active = PETSC_TRUE;
    409:   }
    410:   return(0);
    411: }

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

    418:   Not Collective

    420:   Input Parameters:
    421: + eventLog    - The EventPerfLog
    422: . eventRegLog - The EventRegLog
    423: - cookie - The class id, for example MAT_COOKIE, SNES_COOKIE,

    425:   Level: developer

    427: .seealso: EventPerfLogDeactivateClass(), EventPerfLogDeactivate(), EventPerfLogActivate()
    428: @*/
    429: PetscErrorCode EventPerfLogDeactivateClass(EventPerfLog eventLog, EventRegLog eventRegLog, PetscCookie cookie)
    430: {
    431:   int e;

    434:   for(e = 0; e < eventLog->numEvents; e++) {
    435:     int c = eventRegLog->eventInfo[e].cookie;

    437:     if (c == cookie) eventLog->eventInfo[e].active = PETSC_FALSE;
    438:   }
    439:   return(0);
    440: }

    442: /*------------------------------------------------ Query Functions --------------------------------------------------*/
    445: /*@C
    446:   EventPerfLogSetVisible - This function determines whether an event is printed during PetscLogPrintSummary()

    448:   Not Collective

    450:   Input Parameters:
    451: + eventLog  - The EventPerfLog
    452: . event     - The event to log
    453: - isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)

    455:   Database Options:
    456: . -log_summary - Activates log summary

    458:   Level: intermediate

    460: .keywords: log, visible, event
    461: .seealso: EventPerfLogGetVisible(), EventRegLogRegister(), StageLogGetEventLog()
    462: @*/
    463: PetscErrorCode EventPerfLogSetVisible(EventPerfLog eventLog, PetscEvent event, PetscTruth isVisible)
    464: {
    466:   eventLog->eventInfo[event].visible = isVisible;
    467:   return(0);
    468: }

    472: /*@C
    473:   EventPerfLogGetVisible - This function returns whether an event is printed during PetscLogPrintSummary()

    475:   Not Collective

    477:   Input Parameters:
    478: + eventLog  - The EventPerfLog
    479: - event     - The event id to log

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

    484:   Database Options:
    485: . -log_summary - Activates log summary

    487:   Level: intermediate

    489: .keywords: log, visible, event
    490: .seealso: EventPerfLogSetVisible(), EventRegLogRegister(), StageLogGetEventLog()
    491: @*/
    492: PetscErrorCode EventPerfLogGetVisible(EventPerfLog eventLog, PetscEvent event, PetscTruth *isVisible)
    493: {
    496:   *isVisible = eventLog->eventInfo[event].visible;
    497:   return(0);
    498: }

    500: /*------------------------------------------------ Action Functions -------------------------------------------------*/
    503: PetscErrorCode PetscLogEventBeginDefault(PetscEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
    504: {
    505:   StageLog     stageLog;
    506:   EventPerfLog eventLog;
    507:   int          stage;

    511:   PetscLogGetStageLog(&stageLog);
    512:   StageLogGetCurrent(stageLog, &stage);
    513:   StageLogGetEventPerfLog(stageLog, stage, &eventLog);
    514:   /* Check for double counting */
    515:   eventLog->eventInfo[event].depth++;
    516:   if (eventLog->eventInfo[event].depth > 1) return(0);
    517:   /* Log performance info */
    518:   eventLog->eventInfo[event].count++;
    519:   PetscTimeSubtract(eventLog->eventInfo[event].time);
    520:   eventLog->eventInfo[event].flops         -= _TotalFlops;
    521:   eventLog->eventInfo[event].numMessages   -= irecv_ct  + isend_ct  + recv_ct  + send_ct;
    522:   eventLog->eventInfo[event].messageLength -= irecv_len + isend_len + recv_len + send_len;
    523:   eventLog->eventInfo[event].numReductions -= allreduce_ct;
    524:   return(0);
    525: }

    529: PetscErrorCode PetscLogEventEndDefault(PetscEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
    530: {
    531:   StageLog     stageLog;
    532:   EventPerfLog eventLog;
    533:   int          stage;

    537:   PetscLogGetStageLog(&stageLog);
    538:   StageLogGetCurrent(stageLog, &stage);
    539:   StageLogGetEventPerfLog(stageLog, stage, &eventLog);
    540:   /* Check for double counting */
    541:   eventLog->eventInfo[event].depth--;
    542:   if (eventLog->eventInfo[event].depth > 0) {
    543:     return(0);
    544:   } else if (eventLog->eventInfo[event].depth < 0) {
    545:     SETERRQ(PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
    546:   }
    547:   /* Log performance info */
    548:   PetscTimeAdd(eventLog->eventInfo[event].time);
    549:   eventLog->eventInfo[event].flops         += _TotalFlops;
    550:   eventLog->eventInfo[event].numMessages   += irecv_ct  + isend_ct  + recv_ct  + send_ct;
    551:   eventLog->eventInfo[event].messageLength += irecv_len + isend_len + recv_len + send_len;
    552:   eventLog->eventInfo[event].numReductions += allreduce_ct;
    553:   return(0);
    554: }

    558: PetscErrorCode PetscLogEventBeginComplete(PetscEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
    559: {
    560:   StageLog       stageLog;
    561:   EventRegLog    eventRegLog;
    562:   EventPerfLog   eventPerfLog;
    563:   Action        *tmpAction;
    564:   PetscLogDouble start, end;
    565:   PetscLogDouble curTime;
    566:   int            stage;

    570:   /* Dynamically enlarge logging structures */
    571:   if (numActions >= maxActions) {
    572:     PetscTime(start);
    573:     PetscMalloc(maxActions*2 * sizeof(Action), &tmpAction);
    574:     PetscMemcpy(tmpAction, actions, maxActions * sizeof(Action));
    575:     PetscFree(actions);
    576:     actions     = tmpAction;
    577:     maxActions *= 2;
    578:     PetscTime(end);
    579:     BaseTime += (end - start);
    580:   }
    581:   /* Record the event */
    582:   PetscLogGetStageLog(&stageLog);
    583:   StageLogGetCurrent(stageLog, &stage);
    584:   StageLogGetEventRegLog(stageLog, &eventRegLog);
    585:   StageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
    586:   PetscTime(curTime);
    587:   if (logActions) {
    588:     actions[numActions].time   = curTime - BaseTime;
    589:     actions[numActions].action = ACTIONBEGIN;
    590:     actions[numActions].event  = event;
    591:     actions[numActions].cookie = eventRegLog->eventInfo[event].cookie;
    592:     if (o1) actions[numActions].id1 = o1->id; else actions[numActions].id1 = -1;
    593:     if (o2) actions[numActions].id2 = o2->id; else actions[numActions].id2 = -1;
    594:     if (o3) actions[numActions].id3 = o3->id; else actions[numActions].id3 = -1;
    595:     actions[numActions].flops    = _TotalFlops;
    596:     PetscMallocGetCurrentUsage(&actions[numActions].mem);
    597:     PetscMallocGetMaximumUsage(&actions[numActions].maxmem);
    598:     numActions++;
    599:   }
    600:   /* Check for double counting */
    601:   eventPerfLog->eventInfo[event].depth++;
    602:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
    603:   /* Log the performance info */
    604:   eventPerfLog->eventInfo[event].count++;
    605:   eventPerfLog->eventInfo[event].time          -= curTime;
    606:   eventPerfLog->eventInfo[event].flops         -= _TotalFlops;
    607:   eventPerfLog->eventInfo[event].numMessages   -= irecv_ct  + isend_ct  + recv_ct  + send_ct;
    608:   eventPerfLog->eventInfo[event].messageLength -= irecv_len + isend_len + recv_len + send_len;
    609:   eventPerfLog->eventInfo[event].numReductions -= allreduce_ct;
    610:   return(0);
    611: }

    615: PetscErrorCode PetscLogEventEndComplete(PetscEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
    616: {
    617:   StageLog       stageLog;
    618:   EventRegLog    eventRegLog;
    619:   EventPerfLog   eventPerfLog;
    620:   Action        *tmpAction;
    621:   PetscLogDouble start, end;
    622:   PetscLogDouble curTime;
    623:   int            stage;

    627:   /* Dynamically enlarge logging structures */
    628:   if (numActions >= maxActions) {
    629:     PetscTime(start);
    630:     PetscMalloc(maxActions*2 * sizeof(Action), &tmpAction);
    631:     PetscMemcpy(tmpAction, actions, maxActions * sizeof(Action));
    632:     PetscFree(actions);
    633:     actions     = tmpAction;
    634:     maxActions *= 2;
    635:     PetscTime(end);
    636:     BaseTime += (end - start);
    637:   }
    638:   /* Record the event */
    639:   PetscLogGetStageLog(&stageLog);
    640:   StageLogGetCurrent(stageLog, &stage);
    641:   StageLogGetEventRegLog(stageLog, &eventRegLog);
    642:   StageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
    643:   PetscTime(curTime);
    644:   if (logActions) {
    645:     actions[numActions].time   = curTime - BaseTime;
    646:     actions[numActions].action = ACTIONEND;
    647:     actions[numActions].event  = event;
    648:     actions[numActions].cookie = eventRegLog->eventInfo[event].cookie;
    649:     if (o1) actions[numActions].id1 = o1->id; else actions[numActions].id1 = -1;
    650:     if (o2) actions[numActions].id2 = o2->id; else actions[numActions].id2 = -1;
    651:     if (o3) actions[numActions].id3 = o3->id; else actions[numActions].id3 = -1;
    652:     actions[numActions].flops    = _TotalFlops;
    653:     PetscMallocGetCurrentUsage(&actions[numActions].mem);
    654:     PetscMallocGetMaximumUsage(&actions[numActions].maxmem);
    655:     numActions++;
    656:   }
    657:   /* Check for double counting */
    658:   eventPerfLog->eventInfo[event].depth--;
    659:   if (eventPerfLog->eventInfo[event].depth > 0) {
    660:     return(0);
    661:   } else if (eventPerfLog->eventInfo[event].depth < 0) {
    662:     SETERRQ(PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
    663:   }
    664:   /* Log the performance info */
    665:   eventPerfLog->eventInfo[event].count++;
    666:   eventPerfLog->eventInfo[event].time          += curTime;
    667:   eventPerfLog->eventInfo[event].flops         += _TotalFlops;
    668:   eventPerfLog->eventInfo[event].numMessages   += irecv_ct  + isend_ct  + recv_ct  + send_ct;
    669:   eventPerfLog->eventInfo[event].messageLength += irecv_len + isend_len + recv_len + send_len;
    670:   eventPerfLog->eventInfo[event].numReductions += allreduce_ct;
    671:   return(0);
    672: }

    676: PetscErrorCode PetscLogEventBeginTrace(PetscEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
    677: {
    678:   StageLog       stageLog;
    679:   EventRegLog    eventRegLog;
    680:   EventPerfLog   eventPerfLog;
    681:   PetscLogDouble cur_time;
    682:   PetscMPIInt    rank;
    683:   int            stage;

    687:   if (!tracetime) {PetscTime(tracetime);}

    689:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
    690:   PetscLogGetStageLog(&stageLog);
    691:   StageLogGetCurrent(stageLog, &stage);
    692:   StageLogGetEventRegLog(stageLog, &eventRegLog);
    693:   StageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
    694:   /* Check for double counting */
    695:   eventPerfLog->eventInfo[event].depth++;
    696:   tracelevel++;
    697:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
    698:   /* Log performance info */
    699:   PetscStrncpy(tracespace, traceblanks, 2*tracelevel);
    700:   tracespace[2*tracelevel] = 0;
    701:   PetscTime(cur_time);
    702:   PetscFPrintf(PETSC_COMM_SELF,tracefile, "%s[%d] %g Event begin: %s\n", tracespace, rank, cur_time-tracetime, eventRegLog->eventInfo[event].name);
    703:   fflush(tracefile);

    705:   return(0);
    706: }

    710: PetscErrorCode PetscLogEventEndTrace(PetscEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
    711: {
    712:   StageLog       stageLog;
    713:   EventRegLog    eventRegLog;
    714:   EventPerfLog   eventPerfLog;
    715:   PetscLogDouble cur_time;
    716:   int            stage;
    717:   PetscMPIInt    rank;

    721:   tracelevel--;
    722:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
    723:   PetscLogGetStageLog(&stageLog);
    724:   StageLogGetCurrent(stageLog, &stage);
    725:   StageLogGetEventRegLog(stageLog, &eventRegLog);
    726:   StageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
    727:   /* Check for double counting */
    728:   eventPerfLog->eventInfo[event].depth--;
    729:   if (eventPerfLog->eventInfo[event].depth > 0) {
    730:     return(0);
    731:   } else if (eventPerfLog->eventInfo[event].depth < 0 || tracelevel < 0) {
    732:     SETERRQ(PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
    733:   }
    734:   /* Log performance info */
    735:   PetscStrncpy(tracespace, traceblanks, 2*tracelevel);
    736:   tracespace[2*tracelevel] = 0;
    737:   PetscTime(cur_time);
    738:   PetscFPrintf(PETSC_COMM_SELF,tracefile, "%s[%d] %g Event end: %s\n", tracespace, rank, cur_time-tracetime, eventRegLog->eventInfo[event].name);
    739:   fflush(tracefile);
    740:   return(0);
    741: }