Actual source code: eventlog.c

petsc-3.8.3 2017-12-09
Report Typos and Errors

  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>

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

 13: /*@C
 14:   PetscEventRegLogCreate - This creates a PetscEventRegLog object.

 16:   Not collective

 18:   Input Parameter:
 19: . eventLog - The PetscEventRegLog

 21:   Level: developer

 23: .keywords: log, event, create
 24: .seealso: PetscEventRegLogDestroy(), PetscStageLogCreate()
 25: @*/
 26: PetscErrorCode PetscEventRegLogCreate(PetscEventRegLog *eventLog)
 27: {
 28:   PetscEventRegLog l;
 29:   PetscErrorCode   ierr;

 32:   PetscNew(&l);
 33:   l->numEvents = 0;
 34:   l->maxEvents = 100;
 35:   PetscMalloc1(l->maxEvents,&l->eventInfo);
 36:   *eventLog    = l;
 37:   return(0);
 38: }

 40: /*@C
 41:   PetscEventRegLogDestroy - This destroys a PetscEventRegLog object.

 43:   Not collective

 45:   Input Paramter:
 46: . eventLog - The PetscEventRegLog

 48:   Level: developer

 50: .keywords: log, event, destroy
 51: .seealso: PetscEventRegLogCreate()
 52: @*/
 53: PetscErrorCode PetscEventRegLogDestroy(PetscEventRegLog eventLog)
 54: {
 55:   int            e;

 59:   for (e = 0; e < eventLog->numEvents; e++) {
 60:     PetscFree(eventLog->eventInfo[e].name);
 61:   }
 62:   PetscFree(eventLog->eventInfo);
 63:   PetscFree(eventLog);
 64:   return(0);
 65: }

 67: /*@C
 68:   PetscEventPerfLogCreate - This creates a PetscEventPerfLog object.

 70:   Not collective

 72:   Input Parameter:
 73: . eventLog - The PetscEventPerfLog

 75:   Level: developer

 77: .keywords: log, event, create
 78: .seealso: PetscEventPerfLogDestroy(), PetscStageLogCreate()
 79: @*/
 80: PetscErrorCode PetscEventPerfLogCreate(PetscEventPerfLog *eventLog)
 81: {
 82:   PetscEventPerfLog l;
 83:   PetscErrorCode    ierr;

 86:   PetscNew(&l);
 87:   l->numEvents = 0;
 88:   l->maxEvents = 100;
 89:   PetscMalloc1(l->maxEvents,&l->eventInfo);
 90:   *eventLog    = l;
 91:   return(0);
 92: }

 94: /*@C
 95:   PetscEventPerfLogDestroy - This destroys a PetscEventPerfLog object.

 97:   Not collective

 99:   Input Paramter:
100: . eventLog - The PetscEventPerfLog

102:   Level: developer

104: .keywords: log, event, destroy
105: .seealso: PetscEventPerfLogCreate()
106: @*/
107: PetscErrorCode PetscEventPerfLogDestroy(PetscEventPerfLog eventLog)
108: {

112:   PetscFree(eventLog->eventInfo);
113:   PetscFree(eventLog);
114:   return(0);
115: }

117: /*------------------------------------------------ General Functions -------------------------------------------------*/
118: /*@C
119:   PetscEventPerfInfoClear - This clears a PetscEventPerfInfo object.

121:   Not collective

123:   Input Paramter:
124: . eventInfo - The PetscEventPerfInfo

126:   Level: developer

128: .keywords: log, event, destroy
129: .seealso: PetscEventPerfLogCreate()
130: @*/
131: PetscErrorCode PetscEventPerfInfoClear(PetscEventPerfInfo *eventInfo)
132: {
134:   eventInfo->id            = -1;
135:   eventInfo->active        = PETSC_TRUE;
136:   eventInfo->visible       = PETSC_TRUE;
137:   eventInfo->depth         = 0;
138:   eventInfo->count         = 0;
139:   eventInfo->flops         = 0.0;
140:   eventInfo->flops2        = 0.0;
141:   eventInfo->flopsTmp      = 0.0;
142:   eventInfo->time          = 0.0;
143:   eventInfo->time2         = 0.0;
144:   eventInfo->timeTmp       = 0.0;
145:   eventInfo->numMessages   = 0.0;
146:   eventInfo->messageLength = 0.0;
147:   eventInfo->numReductions = 0.0;
148:   return(0);
149: }

151: /*@C
152:   PetscEventPerfInfoCopy - Copy the activity and visibility data in eventInfo to outInfo

154:   Not collective

156:   Input Paramter:
157: . eventInfo - The input PetscEventPerfInfo

159:   Output Paramter:
160: . outInfo   - The output PetscEventPerfInfo

162:   Level: developer

164: .keywords: log, event, copy
165: .seealso: PetscEventPerfInfoClear()
166: @*/
167: PetscErrorCode PetscEventPerfInfoCopy(PetscEventPerfInfo *eventInfo,PetscEventPerfInfo *outInfo)
168: {
170:   outInfo->id      = eventInfo->id;
171:   outInfo->active  = eventInfo->active;
172:   outInfo->visible = eventInfo->visible;
173:   return(0);
174: }

176: /*@C
177:   PetscEventPerfLogEnsureSize - This ensures that a PetscEventPerfLog is at least of a certain size.

179:   Not collective

181:   Input Paramters:
182: + eventLog - The PetscEventPerfLog
183: - size     - The size

185:   Level: developer

187: .keywords: log, event, size, ensure
188: .seealso: PetscEventPerfLogCreate()
189: @*/
190: PetscErrorCode PetscEventPerfLogEnsureSize(PetscEventPerfLog eventLog,int size)
191: {
192:   PetscEventPerfInfo *eventInfo;
193:   PetscErrorCode     ierr;

196:   while (size > eventLog->maxEvents) {
197:     PetscMalloc1(eventLog->maxEvents*2,&eventInfo);
198:     PetscMemcpy(eventInfo,eventLog->eventInfo,eventLog->maxEvents * sizeof(PetscEventPerfInfo));
199:     PetscFree(eventLog->eventInfo);

201:     eventLog->eventInfo  = eventInfo;
202:     eventLog->maxEvents *= 2;
203:   }
204:   while (eventLog->numEvents < size) {
205:     PetscEventPerfInfoClear(&eventLog->eventInfo[eventLog->numEvents++]);
206:   }
207:   return(0);
208: }

210: #if defined(PETSC_HAVE_MPE)
211: #include <mpe.h>
212: PETSC_INTERN PetscErrorCode PetscLogMPEGetRGBColor(const char*[]);
213: PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
214: {
215:   PetscErrorCode    ierr;

218:   MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_begin,0,NULL);
219:   return(0);
220: }

222: PetscErrorCode PetscLogEventEndMPE(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
223: {
224:   PetscErrorCode    ierr;

227:   MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_end,0,NULL);
228:   return(0);
229: }
230: #endif

232: /*--------------------------------------------- Registration Functions ----------------------------------------------*/
233: /*@C
234:   PetscEventRegLogRegister - Registers an event for logging operations in an application code.

236:   Not Collective

238:   Input Parameters:
239: + eventLog - The PetscEventLog
240: . ename    - The name associated with the event
241: - classid   - The classid associated to the class for this event

243:   Output Parameter:
244: . event    - The event

246:   Example of Usage:
247: .vb
248:       int USER_EVENT;
249:       PetscLogDouble user_event_flops;
250:       PetscLogEventRegister("User event name",0,&USER_EVENT);
251:       PetscLogEventBegin(USER_EVENT,0,0,0,0);
252:          [code segment to monitor]
253:          PetscLogFlops(user_event_flops);
254:       PetscLogEventEnd(USER_EVENT,0,0,0,0);
255: .ve

257:   Notes:

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

266:   Level: developer

268: .keywords: log, event, register
269: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), 
270:           PetscEventLogActivate(), PetscEventLogDeactivate()
271: @*/
272: PetscErrorCode PetscEventRegLogRegister(PetscEventRegLog eventLog,const char ename[],PetscClassId classid,PetscLogEvent *event)
273: {
274:   PetscEventRegInfo *eventInfo;
275:   char              *str;
276:   int               e;
277:   PetscErrorCode    ierr;

282:   /* Should check classid I think */
283:   e = eventLog->numEvents++;
284:   if (eventLog->numEvents > eventLog->maxEvents) {
285:     PetscMalloc1(eventLog->maxEvents*2,&eventInfo);
286:     PetscMemcpy(eventInfo,eventLog->eventInfo,eventLog->maxEvents * sizeof(PetscEventRegInfo));
287:     PetscFree(eventLog->eventInfo);

289:     eventLog->eventInfo  = eventInfo;
290:     eventLog->maxEvents *= 2;
291:   }
292:   PetscStrallocpy(ename,&str);

294:   eventLog->eventInfo[e].name    = str;
295:   eventLog->eventInfo[e].classid = classid;
296: #if defined(PETSC_HAVE_MPE)
297:   if (PetscLogPLB == PetscLogEventBeginMPE) {
298:     const char  *color;
299:     PetscMPIInt rank;
300:     int         beginID,endID;

302:     beginID = MPE_Log_get_event_number();
303:     endID   = MPE_Log_get_event_number();

305:     eventLog->eventInfo[e].mpe_id_begin = beginID;
306:     eventLog->eventInfo[e].mpe_id_end   = endID;

308:     MPI_Comm_rank(PETSC_COMM_WORLD,&rank);
309:     if (!rank) {
310:       PetscLogMPEGetRGBColor(&color);
311:       MPE_Describe_state(beginID,endID,str,(char*)color);
312:     }
313:   }
314: #endif
315:   *event = e;
316:   return(0);
317: }

319: /*---------------------------------------------- Activation Functions -----------------------------------------------*/
320: /*@C
321:   PetscEventPerfLogActivate - Indicates that a particular event should be logged.

323:   Not Collective

325:   Input Parameters:
326: + eventLog - The PetscEventPerfLog
327: - event    - The event

329:    Usage:
330: .vb
331:       PetscEventPerfLogDeactivate(log, VEC_SetValues);
332:         [code where you do not want to log VecSetValues()]
333:       PetscEventPerfLogActivate(log, VEC_SetValues);
334:         [code where you do want to log VecSetValues()]
335: .ve

337:   Note:
338:   The event may be either a pre-defined PETSc event (found in
339:   include/petsclog.h) or an event number obtained with PetscEventRegLogRegister().

341:   Level: developer

343: .keywords: log, event, activate
344: .seealso: PetscEventPerfLogDeactivate()
345: @*/
346: PetscErrorCode PetscEventPerfLogActivate(PetscEventPerfLog eventLog,PetscLogEvent event)
347: {
349:   eventLog->eventInfo[event].active = PETSC_TRUE;
350:   return(0);
351: }

353: /*@C
354:   PetscEventPerfLogDeactivate - Indicates that a particular event should not be logged.

356:   Not Collective

358:   Input Parameters:
359: + eventLog - The PetscEventPerfLog
360: - event    - The event

362:    Usage:
363: .vb
364:       PetscEventPerfLogDeactivate(log, VEC_SetValues);
365:         [code where you do not want to log VecSetValues()]
366:       PetscEventPerfLogActivate(log, VEC_SetValues);
367:         [code where you do want to log VecSetValues()]
368: .ve

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

374:   Level: developer

376: .keywords: log, event, activate
377: .seealso: PetscEventPerfLogActivate()
378: @*/
379: PetscErrorCode PetscEventPerfLogDeactivate(PetscEventPerfLog eventLog,PetscLogEvent event)
380: {
382:   eventLog->eventInfo[event].active = PETSC_FALSE;
383:   return(0);
384: }

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

389:   Not Collective

391:   Input Parameters:
392: + eventLog    - The PetscEventPerfLog
393: . eventRegLog - The PetscEventRegLog
394: - classid      - The class id, for example MAT_CLASSID, SNES_CLASSID,

396:   Level: developer

398: .seealso: PetscEventPerfLogDeactivateClass(), PetscEventPerfLogActivate(), PetscEventPerfLogDeactivate()
399: @*/
400: PetscErrorCode PetscEventPerfLogActivateClass(PetscEventPerfLog eventLog,PetscEventRegLog eventRegLog,PetscClassId classid)
401: {
402:   int e;

405:   for (e = 0; e < eventLog->numEvents; e++) {
406:     int c = eventRegLog->eventInfo[e].classid;
407:     if (c == classid) eventLog->eventInfo[e].active = PETSC_TRUE;
408:   }
409:   return(0);
410: }

412: /*@C
413:   PetscEventPerfLogDeactivateClass - Deactivates event logging for a PETSc object class.

415:   Not Collective

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

422:   Level: developer

424: .seealso: PetscEventPerfLogDeactivateClass(), PetscEventPerfLogDeactivate(), PetscEventPerfLogActivate()
425: @*/
426: PetscErrorCode PetscEventPerfLogDeactivateClass(PetscEventPerfLog eventLog,PetscEventRegLog eventRegLog,PetscClassId classid)
427: {
428:   int e;

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

438: /*------------------------------------------------ Query Functions --------------------------------------------------*/
439: /*@C
440:   PetscEventRegLogGetEvent - 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, or -1 if not found

451:   Level: developer

453: .keywords: log, stage
454: .seealso: PetscEventRegLogRegister()
455: @*/
456: PetscErrorCode  PetscEventRegLogGetEvent(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) {
469:       *event = e;
470:       break;
471:     }
472:   }
473:   return(0);
474: }

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

479:   Not Collective

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

486:   Database Options:
487: . -log_view - Activates log summary

489:   Level: developer

491: .keywords: log, visible, event
492: .seealso: PetscEventPerfLogGetVisible(), PetscEventRegLogRegister(), PetscStageLogGetEventLog()
493: @*/
494: PetscErrorCode PetscEventPerfLogSetVisible(PetscEventPerfLog eventLog,PetscLogEvent event,PetscBool isVisible)
495: {
497:   eventLog->eventInfo[event].visible = isVisible;
498:   return(0);
499: }

501: /*@C
502:   PetscEventPerfLogGetVisible - This function returns whether an event is printed during PetscLogView()

504:   Not Collective

506:   Input Parameters:
507: + eventLog  - The PetscEventPerfLog
508: - event     - The event id to log

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

513:   Database Options:
514: . -log_view - Activates log summary

516:   Level: developer

518: .keywords: log, visible, event
519: .seealso: PetscEventPerfLogSetVisible(), PetscEventRegLogRegister(), PetscStageLogGetEventLog()
520: @*/
521: PetscErrorCode PetscEventPerfLogGetVisible(PetscEventPerfLog eventLog,PetscLogEvent event,PetscBool  *isVisible)
522: {
525:   *isVisible = eventLog->eventInfo[event].visible;
526:   return(0);
527: }

529: /*@C
530:   PetscLogEventGetPerfInfo - Return the performance information about the given event in the given stage

532:   Input Parameters:
533: + stage - The stage number or PETSC_DETERMINE for the current stage
534: - event - The event number

536:   Output Parameters:
537: . info - This structure is filled with the performance information

539:   Level: Intermediate

541: .seealso: PetscLogEventGetFlops()
542: @*/
543: PetscErrorCode PetscLogEventGetPerfInfo(int stage,PetscLogEvent event,PetscEventPerfInfo *info)
544: {
545:   PetscStageLog     stageLog;
546:   PetscEventPerfLog eventLog = NULL;
547:   PetscErrorCode    ierr;

551:   if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
552:   PetscLogGetStageLog(&stageLog);
553:   if (stage < 0) {PetscStageLogGetCurrent(stageLog,&stage);}
554:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
555:   *info = eventLog->eventInfo[event];
556:   return(0);
557: }

559: PetscErrorCode PetscLogEventGetFlops(PetscLogEvent event,PetscLogDouble *flops)
560: {
561:   PetscStageLog     stageLog;
562:   PetscEventPerfLog eventLog = NULL;
563:   int               stage;
564:   PetscErrorCode    ierr;

567:   if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
568:   PetscLogGetStageLog(&stageLog);
569:   PetscStageLogGetCurrent(stageLog,&stage);
570:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
571:   *flops = eventLog->eventInfo[event].flops;
572:   return(0);
573: }

575: PetscErrorCode PetscLogEventZeroFlops(PetscLogEvent event)
576: {
577:   PetscStageLog     stageLog;
578:   PetscEventPerfLog eventLog = NULL;
579:   int               stage;
580:   PetscErrorCode    ierr;

583:   PetscLogGetStageLog(&stageLog);
584:   PetscStageLogGetCurrent(stageLog,&stage);
585:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);

587:   eventLog->eventInfo[event].flops    = 0.0;
588:   eventLog->eventInfo[event].flops2   = 0.0;
589:   eventLog->eventInfo[event].flopsTmp = 0.0;
590:   return(0);
591: }

593: PetscErrorCode PetscLogEventBeginDefault(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
594: {
595:   PetscStageLog     stageLog;
596:   PetscEventPerfLog eventLog = NULL;
597:   int               stage;
598:   PetscErrorCode    ierr;

601:   PetscLogGetStageLog(&stageLog);
602:   PetscStageLogGetCurrent(stageLog,&stage);
603:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
604:   /* Check for double counting */
605:   eventLog->eventInfo[event].depth++;
606:   if (eventLog->eventInfo[event].depth > 1) return(0);
607:   /* Log performance info */
608:   eventLog->eventInfo[event].count++;
609:   eventLog->eventInfo[event].timeTmp = 0.0;
610:   PetscTimeSubtract(&eventLog->eventInfo[event].timeTmp);
611:   eventLog->eventInfo[event].flopsTmp       = 0.0;
612:   eventLog->eventInfo[event].flopsTmp      -= petsc_TotalFlops;
613:   eventLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
614:   eventLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
615:   eventLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
616:   return(0);
617: }

619: PetscErrorCode PetscLogEventEndDefault(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
620: {
621:   PetscStageLog     stageLog;
622:   PetscEventPerfLog eventLog = NULL;
623:   int               stage;
624:   PetscErrorCode    ierr;

627:   PetscLogGetStageLog(&stageLog);
628:   PetscStageLogGetCurrent(stageLog,&stage);
629:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
630:   /* Check for double counting */
631:   eventLog->eventInfo[event].depth--;
632:   if (eventLog->eventInfo[event].depth > 0) return(0);
633:   else if (eventLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE,"Logging event had unbalanced begin/end pairs");
634:   /* Log performance info */
635:   PetscTimeAdd(&eventLog->eventInfo[event].timeTmp);
636:   eventLog->eventInfo[event].time          += eventLog->eventInfo[event].timeTmp;
637:   eventLog->eventInfo[event].time2         += eventLog->eventInfo[event].timeTmp*eventLog->eventInfo[event].timeTmp;
638:   eventLog->eventInfo[event].flopsTmp      += petsc_TotalFlops;
639:   eventLog->eventInfo[event].flops         += eventLog->eventInfo[event].flopsTmp;
640:   eventLog->eventInfo[event].flops2        += eventLog->eventInfo[event].flopsTmp*eventLog->eventInfo[event].flopsTmp;
641:   eventLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
642:   eventLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
643:   eventLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
644:   return(0);
645: }

647: PetscErrorCode PetscLogEventBeginComplete(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
648: {
649:   PetscStageLog     stageLog;
650:   PetscEventRegLog  eventRegLog;
651:   PetscEventPerfLog eventPerfLog = NULL;
652:   Action            *tmpAction;
653:   PetscLogDouble    start,end;
654:   PetscLogDouble    curTime;
655:   int               stage;
656:   PetscErrorCode    ierr;

659:   /* Dynamically enlarge logging structures */
660:   if (petsc_numActions >= petsc_maxActions) {
661:     PetscTime(&start);
662:     PetscMalloc1(petsc_maxActions*2,&tmpAction);
663:     PetscMemcpy(tmpAction,petsc_actions,petsc_maxActions * sizeof(Action));
664:     PetscFree(petsc_actions);

666:     petsc_actions     = tmpAction;
667:     petsc_maxActions *= 2;
668:     PetscTime(&end);
669:     petsc_BaseTime += (end - start);
670:   }
671:   /* Record the event */
672:   PetscLogGetStageLog(&stageLog);
673:   PetscStageLogGetCurrent(stageLog,&stage);
674:   PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
675:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
676:   PetscTime(&curTime);
677:   if (petsc_logActions) {
678:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
679:     petsc_actions[petsc_numActions].action  = ACTIONBEGIN;
680:     petsc_actions[petsc_numActions].event   = event;
681:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
682:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
683:     else petsc_actions[petsc_numActions].id1 = -1;
684:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
685:     else petsc_actions[petsc_numActions].id2 = -1;
686:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
687:     else petsc_actions[petsc_numActions].id3 = -1;
688:     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: }

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

719:   /* Dynamically enlarge logging structures */
720:   if (petsc_numActions >= petsc_maxActions) {
721:     PetscTime(&start);
722:     PetscMalloc1(petsc_maxActions*2,&tmpAction);
723:     PetscMemcpy(tmpAction,petsc_actions,petsc_maxActions * sizeof(Action));
724:     PetscFree(petsc_actions);

726:     petsc_actions     = tmpAction;
727:     petsc_maxActions *= 2;
728:     PetscTime(&end);
729:     petsc_BaseTime += (end - start);
730:   }
731:   /* Record the event */
732:   PetscLogGetStageLog(&stageLog);
733:   PetscStageLogGetCurrent(stageLog,&stage);
734:   PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
735:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
736:   PetscTime(&curTime);
737:   if (petsc_logActions) {
738:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
739:     petsc_actions[petsc_numActions].action  = ACTIONEND;
740:     petsc_actions[petsc_numActions].event   = event;
741:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
742:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
743:     else petsc_actions[petsc_numActions].id1 = -1;
744:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
745:     else petsc_actions[petsc_numActions].id2 = -1;
746:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
747:     else petsc_actions[petsc_numActions].id3 = -1;
748:     petsc_actions[petsc_numActions].flops = petsc_TotalFlops;

750:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
751:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
752:     petsc_numActions++;
753:   }
754:   /* Check for double counting */
755:   eventPerfLog->eventInfo[event].depth--;
756:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
757:   else if (eventPerfLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE,"Logging event had unbalanced begin/end pairs");
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: }

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

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

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

795:   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");
799:   return(0);
800: }

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

813:   petsc_tracelevel--;
814:   MPI_Comm_rank(PETSC_COMM_WORLD,&rank);
815:   PetscLogGetStageLog(&stageLog);
816:   PetscStageLogGetCurrent(stageLog,&stage);
817:   PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
818:   PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
819:   /* Check for double counting */
820:   eventPerfLog->eventInfo[event].depth--;
821:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
822:   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");

824:   /* Log performance info */
825:   PetscStrncpy(petsc_tracespace,petsc_traceblanks,2*petsc_tracelevel);

827:   petsc_tracespace[2*petsc_tracelevel] = 0;
828:   PetscTime(&cur_time);
829:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile,"%s[%d] %g Event end: %s\n",petsc_tracespace,rank,cur_time-petsc_tracetime,eventRegLog->eventInfo[event].name);
830:   err  = fflush(petsc_tracefile);
831:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
832:   return(0);
833: }