Actual source code: eventLog.c

petsc-3.3-p7 2013-05-11
  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;

 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;

 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->time          = 0.0;
151:   eventInfo->numMessages   = 0.0;
152:   eventInfo->messageLength = 0.0;
153:   eventInfo->numReductions = 0.0;
154:   return(0);
155: }

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

162:   Not collective

164:   Input Paramter:
165: . eventInfo - The input PetscEventPerfInfo

167:   Output Paramter:
168: . outInfo   - The output PetscEventPerfInfo

170:   Level: developer

172: .keywords: log, event, copy
173: .seealso: EventPerfInfoClear()
174: @*/
175: PetscErrorCode EventPerfInfoCopy(PetscEventPerfInfo *eventInfo, PetscEventPerfInfo *outInfo)
176: {
178:   outInfo->id      = eventInfo->id;
179:   outInfo->active  = eventInfo->active;
180:   outInfo->visible = eventInfo->visible;
181:   return(0);
182: }

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

189:   Not collective

191:   Input Paramters:
192: + eventLog - The PetscEventPerfLog
193: - size     - The size

195:   Level: developer

197: .keywords: log, event, size, ensure
198: .seealso: EventPerfLogCreate()
199: @*/
200: PetscErrorCode EventPerfLogEnsureSize(PetscEventPerfLog eventLog, int size)
201: {
202:   PetscEventPerfInfo  *eventInfo;

206:   while(size > eventLog->maxEvents) {
207:     PetscMalloc(eventLog->maxEvents*2 * sizeof(PetscEventPerfInfo), &eventInfo);
208:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(PetscEventPerfInfo));
209:     PetscFree(eventLog->eventInfo);
210:     eventLog->eventInfo  = eventInfo;
211:     eventLog->maxEvents *= 2;
212:   }
213:   while(eventLog->numEvents < size) {
214:     EventPerfInfoClear(&eventLog->eventInfo[eventLog->numEvents++]);
215:   }
216:   return(0);
217: }

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

225:   Not Collective

227:   Input Parameters:
228: + eventLog - The EventLog
229: . ename    - The name associated with the event
230: - classid   - The classid associated to the class for this event

232:   Output Parameter:
233: . event    - The event

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

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

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

260:   Level: developer

262: .keywords: log, event, register
263: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
264:           EventLogActivate(), EventLogDeactivate()
265: @*/
266: PetscErrorCode EventRegLogRegister(PetscEventRegLog eventLog, const char ename[], PetscClassId classid, PetscLogEvent *event)
267: {
268:   PetscEventRegInfo   *eventInfo;
269:   char           *str;
270:   int            e;

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

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

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

315:   Not Collective

317:   Input Parameters:
318: + eventLog - The PetscEventPerfLog
319: - event    - The event

321:    Usage:
322: .vb
323:       EventPerfLogDeactivate(log, VEC_SetValues);
324:         [code where you do not want to log VecSetValues()]
325:       EventPerfLogActivate(log, VEC_SetValues);
326:         [code where you do want to log VecSetValues()]
327: .ve 

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

333:   Level: developer

335: .keywords: log, event, activate
336: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogDeactivate()
337: @*/
338: PetscErrorCode EventPerfLogActivate(PetscEventPerfLog eventLog, PetscLogEvent event)
339: {
341:   eventLog->eventInfo[event].active = PETSC_TRUE;
342:   return(0);
343: }

347: /*@C
348:   EventPerfLogDeactivate - Indicates that a particular event should not 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(), EventPerfLogActivate()
372: @*/
373: PetscErrorCode EventPerfLogDeactivate(PetscEventPerfLog eventLog, PetscLogEvent event)
374: {
376:   eventLog->eventInfo[event].active = PETSC_FALSE;
377:   return(0);
378: }

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

385:   Not Collective

387:   Input Parameters:
388: + eventLog    - The PetscEventPerfLog
389: . eventRegLog - The PetscEventRegLog
390: - classid      - The class id, for example MAT_CLASSID, SNES_CLASSID,

392:   Level: developer

394: .seealso: EventPerfLogDeactivateClass(), EventPerfLogActivate(), EventPerfLogDeactivate()
395: @*/
396: PetscErrorCode EventPerfLogActivateClass(PetscEventPerfLog eventLog, PetscEventRegLog eventRegLog, PetscClassId classid)
397: {
398:   int e;

401:   for(e = 0; e < eventLog->numEvents; e++) {
402:     int c = eventRegLog->eventInfo[e].classid;
403:     if (c == classid) eventLog->eventInfo[e].active = PETSC_TRUE;
404:   }
405:   return(0);
406: }

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

413:   Not Collective

415:   Input Parameters:
416: + eventLog    - The PetscEventPerfLog
417: . eventRegLog - The PetscEventRegLog
418: - classid - The class id, for example MAT_CLASSID, SNES_CLASSID,

420:   Level: developer

422: .seealso: EventPerfLogDeactivateClass(), EventPerfLogDeactivate(), EventPerfLogActivate()
423: @*/
424: PetscErrorCode EventPerfLogDeactivateClass(PetscEventPerfLog eventLog, PetscEventRegLog eventRegLog, PetscClassId classid)
425: {
426:   int e;

429:   for(e = 0; e < eventLog->numEvents; e++) {
430:     int c = eventRegLog->eventInfo[e].classid;
431:     if (c == classid) eventLog->eventInfo[e].active = PETSC_FALSE;
432:   }
433:   return(0);
434: }

436: /*------------------------------------------------ Query Functions --------------------------------------------------*/
439: /*@C
440:   EventRegLogGetEvent - This function returns the event id given the event name.

442:   Not Collective

444:   Input Parameters:
445: + eventLog - The PetscEventRegLog
446: - name     - The stage name

448:   Output Parameter:
449: . event    - The event id

451:   Level: developer

453: .keywords: log, stage
454: .seealso: EventRegLogRegister()
455: @*/
456: PetscErrorCode  EventRegLogGetEvent(PetscEventRegLog eventLog, const char name[], PetscLogEvent *event)
457: {
458:   PetscBool      match;
459:   int            e;

465:   *event = -1;
466:   for(e = 0; e < eventLog->numEvents; e++) {
467:     PetscStrcasecmp(eventLog->eventInfo[e].name, name, &match);
468:     if (match) break;
469:   }
470:   if (e == eventLog->numEvents) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONG, "No event named %s", name);
471:   *event = e;
472:   return(0);
473: }

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

480:   Not Collective

482:   Input Parameters:
483: + eventLog  - The PetscEventPerfLog
484: . event     - The event to log
485: - isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)

487:   Database Options:
488: . -log_summary - Activates log summary

490:   Level: developer

492: .keywords: log, visible, event
493: .seealso: EventPerfLogGetVisible(), EventRegLogRegister(), PetscStageLogGetEventLog()
494: @*/
495: PetscErrorCode EventPerfLogSetVisible(PetscEventPerfLog eventLog, PetscLogEvent event, PetscBool  isVisible)
496: {
498:   eventLog->eventInfo[event].visible = isVisible;
499:   return(0);
500: }

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

507:   Not Collective

509:   Input Parameters:
510: + eventLog  - The PetscEventPerfLog
511: - event     - The event id to log

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

516:   Database Options:
517: . -log_summary - Activates log summary

519:   Level: developer

521: .keywords: log, visible, event
522: .seealso: EventPerfLogSetVisible(), EventRegLogRegister(), PetscStageLogGetEventLog()
523: @*/
524: PetscErrorCode EventPerfLogGetVisible(PetscEventPerfLog eventLog, PetscLogEvent event, PetscBool  *isVisible)
525: {
528:   *isVisible = eventLog->eventInfo[event].visible;
529:   return(0);
530: }

534: PetscErrorCode PetscLogEventGetFlops(PetscLogEvent event, PetscLogDouble *flops)
535: {
536:   PetscStageLog       stageLog;
537:   PetscEventPerfLog   eventLog = PETSC_NULL;
538:   int            stage;

542:   PetscLogGetStageLog(&stageLog);
543:   PetscStageLogGetCurrent(stageLog, &stage);
544:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
545:   *flops = eventLog->eventInfo[event].flops;
546:   return(0);
547: }

551: PetscErrorCode PetscLogEventZeroFlops(PetscLogEvent event)
552: {
553:   PetscStageLog       stageLog;
554:   PetscEventPerfLog   eventLog = PETSC_NULL;
555:   int            stage;

559:   PetscLogGetStageLog(&stageLog);
560:   PetscStageLogGetCurrent(stageLog, &stage);
561:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
562:   eventLog->eventInfo[event].flops = 0.0;
563:   return(0);
564: }

566: #if defined(PETSC_HAVE_CHUD)
567: #include <CHUD/CHUD.h>
568: #endif
569: #if defined(PETSC_HAVE_PAPI)
570: #include <papi.h>
571: extern int PAPIEventSet;
572: #endif

574: /*------------------------------------------------ Action Functions -------------------------------------------------*/
577: PetscErrorCode PetscLogEventBeginDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
578: {
579:   PetscStageLog       stageLog;
580:   PetscEventPerfLog   eventLog = PETSC_NULL;
581:   int            stage;

585:   PetscLogGetStageLog(&stageLog);
586:   PetscStageLogGetCurrent(stageLog, &stage);
587:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
588:   /* Check for double counting */
589:   eventLog->eventInfo[event].depth++;
590:   if (eventLog->eventInfo[event].depth > 1) return(0);
591:   /* Log performance info */
592:   eventLog->eventInfo[event].count++;
593:   PetscTimeSubtract(eventLog->eventInfo[event].time);
594: #if defined(PETSC_HAVE_CHUD)
595:   eventLog->eventInfo[event].flops         -= chudGetPMCEventCount(chudCPU1Dev,PMC_1);
596: #elif defined(PETSC_HAVE_PAPI)
597:   { long_long values[2];
598:     PAPI_read(PAPIEventSet,values);
599:     eventLog->eventInfo[event].flops -= values[0];
600:     /*    printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
601:   }
602: #else
603:   eventLog->eventInfo[event].flops         -= petsc_TotalFlops;
604: #endif
605:   eventLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
606:   eventLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
607:   eventLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
608:   return(0);
609: }

613: PetscErrorCode PetscLogEventEndDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
614: {
615:   PetscStageLog       stageLog;
616:   PetscEventPerfLog   eventLog = PETSC_NULL;
617:   int            stage;

621:   PetscLogGetStageLog(&stageLog);
622:   PetscStageLogGetCurrent(stageLog, &stage);
623:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
624:   /* Check for double counting */
625:   eventLog->eventInfo[event].depth--;
626:   if (eventLog->eventInfo[event].depth > 0) {
627:     return(0);
628:   } else if (eventLog->eventInfo[event].depth < 0) {
629:     SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
630:   }
631:   /* Log performance info */
632:   PetscTimeAdd(eventLog->eventInfo[event].time);
633: #if defined(PETSC_HAVE_CHUD)
634:   eventLog->eventInfo[event].flops         += chudGetPMCEventCount(chudCPU1Dev,PMC_1);
635: #elif defined(PETSC_HAVE_PAPI)
636:   { long_long values[2];
637:     PAPI_read(PAPIEventSet,values);
638:     eventLog->eventInfo[event].flops += values[0];
639:     /* printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
640:   }
641: #else
642:   eventLog->eventInfo[event].flops         += petsc_TotalFlops;
643: #endif
644:   eventLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
645:   eventLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
646:   eventLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
647:   return(0);
648: }

652: PetscErrorCode PetscLogEventBeginComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
653: {
654:   PetscStageLog       stageLog;
655:   PetscEventRegLog    eventRegLog;
656:   PetscEventPerfLog   eventPerfLog = PETSC_NULL;
657:   Action        *tmpAction;
658:   PetscLogDouble start, end;
659:   PetscLogDouble curTime;
660:   int            stage;

664:   /* Dynamically enlarge logging structures */
665:   if (petsc_numActions >= petsc_maxActions) {
666:     PetscTime(start);
667:     PetscMalloc(petsc_maxActions*2 * sizeof(Action), &tmpAction);
668:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
669:     PetscFree(petsc_actions);
670:     petsc_actions     = tmpAction;
671:     petsc_maxActions *= 2;
672:     PetscTime(end);
673:     petsc_BaseTime += (end - start);
674:   }
675:   /* Record the event */
676:   PetscLogGetStageLog(&stageLog);
677:   PetscStageLogGetCurrent(stageLog, &stage);
678:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
679:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
680:   PetscTime(curTime);
681:   if (petsc_logActions) {
682:     petsc_actions[petsc_numActions].time   = curTime - petsc_BaseTime;
683:     petsc_actions[petsc_numActions].action = ACTIONBEGIN;
684:     petsc_actions[petsc_numActions].event  = event;
685:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
686:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id; else petsc_actions[petsc_numActions].id1 = -1;
687:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id; else petsc_actions[petsc_numActions].id2 = -1;
688:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id; else petsc_actions[petsc_numActions].id3 = -1;
689:     petsc_actions[petsc_numActions].flops    = petsc_TotalFlops;
690:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
691:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
692:     petsc_numActions++;
693:   }
694:   /* Check for double counting */
695:   eventPerfLog->eventInfo[event].depth++;
696:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
697:   /* Log the performance info */
698:   eventPerfLog->eventInfo[event].count++;
699:   eventPerfLog->eventInfo[event].time          -= curTime;
700:   eventPerfLog->eventInfo[event].flops         -= petsc_TotalFlops;
701:   eventPerfLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
702:   eventPerfLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
703:   eventPerfLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
704:   return(0);
705: }

709: PetscErrorCode PetscLogEventEndComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
710: {
711:   PetscStageLog       stageLog;
712:   PetscEventRegLog    eventRegLog;
713:   PetscEventPerfLog   eventPerfLog = PETSC_NULL;
714:   Action        *tmpAction;
715:   PetscLogDouble start, end;
716:   PetscLogDouble curTime;
717:   int            stage;

721:   /* Dynamically enlarge logging structures */
722:   if (petsc_numActions >= petsc_maxActions) {
723:     PetscTime(start);
724:     PetscMalloc(petsc_maxActions*2 * sizeof(Action), &tmpAction);
725:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
726:     PetscFree(petsc_actions);
727:     petsc_actions     = tmpAction;
728:     petsc_maxActions *= 2;
729:     PetscTime(end);
730:     petsc_BaseTime += (end - start);
731:   }
732:   /* Record the event */
733:   PetscLogGetStageLog(&stageLog);
734:   PetscStageLogGetCurrent(stageLog, &stage);
735:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
736:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
737:   PetscTime(curTime);
738:   if (petsc_logActions) {
739:     petsc_actions[petsc_numActions].time   = curTime - petsc_BaseTime;
740:     petsc_actions[petsc_numActions].action = ACTIONEND;
741:     petsc_actions[petsc_numActions].event  = event;
742:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
743:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id; else petsc_actions[petsc_numActions].id1 = -1;
744:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id; else petsc_actions[petsc_numActions].id2 = -1;
745:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id; else petsc_actions[petsc_numActions].id3 = -1;
746:     petsc_actions[petsc_numActions].flops    = petsc_TotalFlops;
747:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
748:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
749:     petsc_numActions++;
750:   }
751:   /* Check for double counting */
752:   eventPerfLog->eventInfo[event].depth--;
753:   if (eventPerfLog->eventInfo[event].depth > 0) {
754:     return(0);
755:   } else if (eventPerfLog->eventInfo[event].depth < 0) {
756:     SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
757:   }
758:   /* Log the performance info */
759:   eventPerfLog->eventInfo[event].count++;
760:   eventPerfLog->eventInfo[event].time          += curTime;
761:   eventPerfLog->eventInfo[event].flops         += petsc_TotalFlops;
762:   eventPerfLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
763:   eventPerfLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
764:   eventPerfLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
765:   return(0);
766: }

770: PetscErrorCode PetscLogEventBeginTrace(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
771: {
772:   PetscStageLog       stageLog;
773:   PetscEventRegLog    eventRegLog;
774:   PetscEventPerfLog   eventPerfLog = PETSC_NULL;
775:   PetscLogDouble cur_time;
776:   PetscMPIInt    rank;
777:   int            stage,err;

781:   if (!petsc_tracetime) {PetscTime(petsc_tracetime);}

783:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
784:   PetscLogGetStageLog(&stageLog);
785:   PetscStageLogGetCurrent(stageLog, &stage);
786:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
787:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
788:   /* Check for double counting */
789:   eventPerfLog->eventInfo[event].depth++;
790:   petsc_tracelevel++;
791:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
792:   /* Log performance info */
793:   PetscTime(cur_time);
794:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event begin: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
795:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);
796:   petsc_tracespace[2*petsc_tracelevel] = 0;
797:   err = fflush(petsc_tracefile);
798:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");

800:   return(0);
801: }

805: PetscErrorCode PetscLogEventEndTrace(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
806: {
807:   PetscStageLog       stageLog;
808:   PetscEventRegLog    eventRegLog;
809:   PetscEventPerfLog   eventPerfLog = PETSC_NULL;
810:   PetscLogDouble cur_time;
811:   int            stage,err;
812:   PetscMPIInt    rank;

816:   petsc_tracelevel--;
817:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
818:   PetscLogGetStageLog(&stageLog);
819:   PetscStageLogGetCurrent(stageLog, &stage);
820:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
821:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
822:   /* Check for double counting */
823:   eventPerfLog->eventInfo[event].depth--;
824:   if (eventPerfLog->eventInfo[event].depth > 0) {
825:     return(0);
826:   } else if (eventPerfLog->eventInfo[event].depth < 0 || petsc_tracelevel < 0) {
827:     SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
828:   }
829:   /* Log performance info */
830:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);
831:   petsc_tracespace[2*petsc_tracelevel] = 0;
832:   PetscTime(cur_time);
833:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event end: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
834:   err = fflush(petsc_tracefile);
835:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
836:   return(0);
837: }