Actual source code: eventlog.c

petsc-3.7.5 2017-01-01
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>  /*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(&l);
 35:   l->numEvents = 0;
 36:   l->maxEvents = 100;
 37:   PetscMalloc1(l->maxEvents, &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(&l);
 93:   l->numEvents = 0;
 94:   l->maxEvents = 100;
 95:   PetscMalloc1(l->maxEvents, &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:     PetscMalloc1(eventLog->maxEvents*2, &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:

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

286:   Level: developer

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

302:   /* Should check classid I think */
303:   e = eventLog->numEvents++;
304:   if (eventLog->numEvents > eventLog->maxEvents) {
305:     PetscMalloc1(eventLog->maxEvents*2, &eventInfo);
306:     PetscMemcpy(eventInfo, eventLog->eventInfo, eventLog->maxEvents * sizeof(PetscEventRegInfo));
307:     PetscFree(eventLog->eventInfo);

309:     eventLog->eventInfo  = eventInfo;
310:     eventLog->maxEvents *= 2;
311:   }
312:   PetscStrallocpy(ename, &str);

314:   eventLog->eventInfo[e].name    = str;
315:   eventLog->eventInfo[e].classid = classid;
316: #if defined(PETSC_HAVE_MPE)
317:   if (PetscLogPLB == PetscLogEventBeginMPE) {
318:     const char  *color;
319:     PetscMPIInt rank;
320:     int         beginID, endID;

322:     beginID = MPE_Log_get_event_number();
323:     endID   = MPE_Log_get_event_number();

325:     eventLog->eventInfo[e].mpe_id_begin = beginID;
326:     eventLog->eventInfo[e].mpe_id_end   = endID;

328:     MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
329:     if (!rank) {
330:       PetscLogMPEGetRGBColor(&color);
331:       MPE_Describe_state(beginID, endID, str, (char*)color);
332:     }
333:   }
334: #endif
335:   *event = e;
336:   return(0);
337: }

339: /*---------------------------------------------- Activation Functions -----------------------------------------------*/
342: /*@C
343:   EventPerfLogActivate - Indicates that a particular event should be logged.

345:   Not Collective

347:   Input Parameters:
348: + eventLog - The PetscEventPerfLog
349: - event    - The event

351:    Usage:
352: .vb
353:       EventPerfLogDeactivate(log, VEC_SetValues);
354:         [code where you do not want to log VecSetValues()]
355:       EventPerfLogActivate(log, VEC_SetValues);
356:         [code where you do want to log VecSetValues()]
357: .ve

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

363:   Level: developer

365: .keywords: log, event, activate
366: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogDeactivate()
367: @*/
368: PetscErrorCode EventPerfLogActivate(PetscEventPerfLog eventLog, PetscLogEvent event)
369: {
371:   eventLog->eventInfo[event].active = PETSC_TRUE;
372:   return(0);
373: }

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

380:   Not Collective

382:   Input Parameters:
383: + eventLog - The PetscEventPerfLog
384: - event    - The event

386:    Usage:
387: .vb
388:       EventPerfLogDeactivate(log, VEC_SetValues);
389:         [code where you do not want to log VecSetValues()]
390:       EventPerfLogActivate(log, VEC_SetValues);
391:         [code where you do want to log VecSetValues()]
392: .ve

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

398:   Level: developer

400: .keywords: log, event, activate
401: .seealso: PetscLogEventMPEDeactivate(), PetscLogEventMPEActivate(), EventPerfLogActivate()
402: @*/
403: PetscErrorCode EventPerfLogDeactivate(PetscEventPerfLog eventLog, PetscLogEvent event)
404: {
406:   eventLog->eventInfo[event].active = PETSC_FALSE;
407:   return(0);
408: }

412: /*@C
413:   EventPerfLogActivateClass - Activates 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: EventPerfLogDeactivateClass(), EventPerfLogActivate(), EventPerfLogDeactivate()
425: @*/
426: PetscErrorCode EventPerfLogActivateClass(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_TRUE;
434:   }
435:   return(0);
436: }

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

443:   Not Collective

445:   Input Parameters:
446: + eventLog    - The PetscEventPerfLog
447: . eventRegLog - The PetscEventRegLog
448: - classid - The class id, for example MAT_CLASSID, SNES_CLASSID,

450:   Level: developer

452: .seealso: EventPerfLogDeactivateClass(), EventPerfLogDeactivate(), EventPerfLogActivate()
453: @*/
454: PetscErrorCode EventPerfLogDeactivateClass(PetscEventPerfLog eventLog, PetscEventRegLog eventRegLog, PetscClassId classid)
455: {
456:   int e;

459:   for (e = 0; e < eventLog->numEvents; e++) {
460:     int c = eventRegLog->eventInfo[e].classid;
461:     if (c == classid) eventLog->eventInfo[e].active = PETSC_FALSE;
462:   }
463:   return(0);
464: }

466: /*------------------------------------------------ Query Functions --------------------------------------------------*/
469: /*@C
470:   EventRegLogGetEvent - This function returns the event id given the event name.

472:   Not Collective

474:   Input Parameters:
475: + eventLog - The PetscEventRegLog
476: - name     - The stage name

478:   Output Parameter:
479: . event    - The event id, or -1 if not found

481:   Level: developer

483: .keywords: log, stage
484: .seealso: EventRegLogRegister()
485: @*/
486: PetscErrorCode  EventRegLogGetEvent(PetscEventRegLog eventLog, const char name[], PetscLogEvent *event)
487: {
488:   PetscBool      match;
489:   int            e;

495:   *event = -1;
496:   for (e = 0; e < eventLog->numEvents; e++) {
497:     PetscStrcasecmp(eventLog->eventInfo[e].name, name, &match);
498:     if (match) {
499:       *event = e;
500:       break;
501:     }
502:   }
503:   return(0);
504: }

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

511:   Not Collective

513:   Input Parameters:
514: + eventLog  - The PetscEventPerfLog
515: . event     - The event to log
516: - isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)

518:   Database Options:
519: . -log_summary - Activates log summary

521:   Level: developer

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

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

538:   Not Collective

540:   Input Parameters:
541: + eventLog  - The PetscEventPerfLog
542: - event     - The event id to log

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

547:   Database Options:
548: . -log_summary - Activates log summary

550:   Level: developer

552: .keywords: log, visible, event
553: .seealso: EventPerfLogSetVisible(), EventRegLogRegister(), PetscStageLogGetEventLog()
554: @*/
555: PetscErrorCode EventPerfLogGetVisible(PetscEventPerfLog eventLog, PetscLogEvent event, PetscBool  *isVisible)
556: {
559:   *isVisible = eventLog->eventInfo[event].visible;
560:   return(0);
561: }

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

568:   Input Parameters:
569: + stage - The stage number or PETSC_DETERMINE for the current stage
570: - event - The event number

572:   Output Parameters:
573: . info - This structure is filled with the performance information

575:   Level: Intermediate

577: .seealso: PetscLogEventGetFlops()
578: @*/
579: PetscErrorCode PetscLogEventGetPerfInfo(int stage, PetscLogEvent event, PetscEventPerfInfo *info)
580: {
581:   PetscStageLog     stageLog;
582:   PetscEventPerfLog eventLog = NULL;
583:   PetscErrorCode    ierr;

587:   if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_summary or PetscLogDefaultBegin() before calling this routine");
588:   PetscLogGetStageLog(&stageLog);
589:   if (stage < 0) {PetscStageLogGetCurrent(stageLog, &stage);}
590:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
591:   *info = eventLog->eventInfo[event];
592:   return(0);
593: }

597: PetscErrorCode PetscLogEventGetFlops(PetscLogEvent event, PetscLogDouble *flops)
598: {
599:   PetscStageLog     stageLog;
600:   PetscEventPerfLog eventLog = NULL;
601:   int               stage;
602:   PetscErrorCode    ierr;

605:   if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_summary or PetscLogDefaultBegin() before calling this routine");
606:   PetscLogGetStageLog(&stageLog);
607:   PetscStageLogGetCurrent(stageLog, &stage);
608:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
609:   *flops = eventLog->eventInfo[event].flops;
610:   return(0);
611: }

615: PetscErrorCode PetscLogEventZeroFlops(PetscLogEvent event)
616: {
617:   PetscStageLog     stageLog;
618:   PetscEventPerfLog eventLog = NULL;
619:   int               stage;
620:   PetscErrorCode    ierr;

623:   PetscLogGetStageLog(&stageLog);
624:   PetscStageLogGetCurrent(stageLog, &stage);
625:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);

627:   eventLog->eventInfo[event].flops    = 0.0;
628:   eventLog->eventInfo[event].flops2   = 0.0;
629:   eventLog->eventInfo[event].flopsTmp = 0.0;
630:   return(0);
631: }

633: #if defined(PETSC_HAVE_PAPI)
634: #include <papi.h>
635: extern int PAPIEventSet;
636: #endif

640: PetscErrorCode PetscLogEventBeginDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
641: {
642:   PetscStageLog     stageLog;
643:   PetscEventPerfLog eventLog = NULL;
644:   int               stage;
645:   PetscErrorCode    ierr;

648:   PetscLogGetStageLog(&stageLog);
649:   PetscStageLogGetCurrent(stageLog, &stage);
650:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
651:   /* Check for double counting */
652:   eventLog->eventInfo[event].depth++;
653:   if (eventLog->eventInfo[event].depth > 1) return(0);
654:   /* Log performance info */
655:   eventLog->eventInfo[event].count++;
656:   eventLog->eventInfo[event].timeTmp = 0.0;
657:   PetscTimeSubtract(&eventLog->eventInfo[event].timeTmp);
658:   eventLog->eventInfo[event].flopsTmp = 0.0;
659: #if defined(PETSC_HAVE_PAPI)
660:   { long_long values[2];
661:     PAPI_read(PAPIEventSet,values);

663:     eventLog->eventInfo[event].flopsTmp -= values[0];
664:     /*    printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
665:   }
666: #else
667:   eventLog->eventInfo[event].flopsTmp -= petsc_TotalFlops;
668: #endif
669:   eventLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
670:   eventLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
671:   eventLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
672:   return(0);
673: }

677: PetscErrorCode PetscLogEventEndDefault(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
678: {
679:   PetscStageLog     stageLog;
680:   PetscEventPerfLog eventLog = NULL;
681:   int               stage;
682:   PetscErrorCode    ierr;

685:   PetscLogGetStageLog(&stageLog);
686:   PetscStageLogGetCurrent(stageLog, &stage);
687:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog);
688:   /* Check for double counting */
689:   eventLog->eventInfo[event].depth--;
690:   if (eventLog->eventInfo[event].depth > 0) return(0);
691:   else if (eventLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
692:   /* Log performance info */
693:   PetscTimeAdd(&eventLog->eventInfo[event].timeTmp);
694:   eventLog->eventInfo[event].time  += eventLog->eventInfo[event].timeTmp;
695:   eventLog->eventInfo[event].time2 += eventLog->eventInfo[event].timeTmp*eventLog->eventInfo[event].timeTmp;
696: #if defined(PETSC_HAVE_PAPI)
697:   { long_long values[2];
698:     PAPI_read(PAPIEventSet,values);

700:     eventLog->eventInfo[event].flopsTmp += values[0];
701:     /* printf("fma %g flops %g\n",(double)values[1],(double)values[0]); */
702:   }
703: #else
704:   eventLog->eventInfo[event].flopsTmp += petsc_TotalFlops;
705: #endif
706:   eventLog->eventInfo[event].flops         += eventLog->eventInfo[event].flopsTmp;
707:   eventLog->eventInfo[event].flops2        += eventLog->eventInfo[event].flopsTmp*eventLog->eventInfo[event].flopsTmp;
708:   eventLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
709:   eventLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
710:   eventLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
711:   return(0);
712: }

716: PetscErrorCode PetscLogEventBeginComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
717: {
718:   PetscStageLog     stageLog;
719:   PetscEventRegLog  eventRegLog;
720:   PetscEventPerfLog eventPerfLog = NULL;
721:   Action            *tmpAction;
722:   PetscLogDouble    start, end;
723:   PetscLogDouble    curTime;
724:   int               stage;
725:   PetscErrorCode    ierr;

728:   /* Dynamically enlarge logging structures */
729:   if (petsc_numActions >= petsc_maxActions) {
730:     PetscTime(&start);
731:     PetscMalloc1(petsc_maxActions*2, &tmpAction);
732:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
733:     PetscFree(petsc_actions);

735:     petsc_actions     = tmpAction;
736:     petsc_maxActions *= 2;
737:     PetscTime(&end);
738:     petsc_BaseTime += (end - start);
739:   }
740:   /* Record the event */
741:   PetscLogGetStageLog(&stageLog);
742:   PetscStageLogGetCurrent(stageLog, &stage);
743:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
744:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
745:   PetscTime(&curTime);
746:   if (petsc_logActions) {
747:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
748:     petsc_actions[petsc_numActions].action  = ACTIONBEGIN;
749:     petsc_actions[petsc_numActions].event   = event;
750:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
751:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
752:     else petsc_actions[petsc_numActions].id1 = -1;
753:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
754:     else petsc_actions[petsc_numActions].id2 = -1;
755:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
756:     else petsc_actions[petsc_numActions].id3 = -1;
757:     petsc_actions[petsc_numActions].flops = petsc_TotalFlops;

759:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
760:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
761:     petsc_numActions++;
762:   }
763:   /* Check for double counting */
764:   eventPerfLog->eventInfo[event].depth++;
765:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
766:   /* Log the performance info */
767:   eventPerfLog->eventInfo[event].count++;
768:   eventPerfLog->eventInfo[event].time          -= curTime;
769:   eventPerfLog->eventInfo[event].flops         -= petsc_TotalFlops;
770:   eventPerfLog->eventInfo[event].numMessages   -= petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
771:   eventPerfLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
772:   eventPerfLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
773:   return(0);
774: }

778: PetscErrorCode PetscLogEventEndComplete(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
779: {
780:   PetscStageLog     stageLog;
781:   PetscEventRegLog  eventRegLog;
782:   PetscEventPerfLog eventPerfLog = NULL;
783:   Action            *tmpAction;
784:   PetscLogDouble    start, end;
785:   PetscLogDouble    curTime;
786:   int               stage;
787:   PetscErrorCode    ierr;

790:   /* Dynamically enlarge logging structures */
791:   if (petsc_numActions >= petsc_maxActions) {
792:     PetscTime(&start);
793:     PetscMalloc1(petsc_maxActions*2, &tmpAction);
794:     PetscMemcpy(tmpAction, petsc_actions, petsc_maxActions * sizeof(Action));
795:     PetscFree(petsc_actions);

797:     petsc_actions     = tmpAction;
798:     petsc_maxActions *= 2;
799:     PetscTime(&end);
800:     petsc_BaseTime += (end - start);
801:   }
802:   /* Record the event */
803:   PetscLogGetStageLog(&stageLog);
804:   PetscStageLogGetCurrent(stageLog, &stage);
805:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
806:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
807:   PetscTime(&curTime);
808:   if (petsc_logActions) {
809:     petsc_actions[petsc_numActions].time    = curTime - petsc_BaseTime;
810:     petsc_actions[petsc_numActions].action  = ACTIONEND;
811:     petsc_actions[petsc_numActions].event   = event;
812:     petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
813:     if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
814:     else petsc_actions[petsc_numActions].id1 = -1;
815:     if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
816:     else petsc_actions[petsc_numActions].id2 = -1;
817:     if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
818:     else petsc_actions[petsc_numActions].id3 = -1;
819:     petsc_actions[petsc_numActions].flops = petsc_TotalFlops;

821:     PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
822:     PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
823:     petsc_numActions++;
824:   }
825:   /* Check for double counting */
826:   eventPerfLog->eventInfo[event].depth--;
827:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
828:   else if (eventPerfLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs");
829:   /* Log the performance info */
830:   eventPerfLog->eventInfo[event].count++;
831:   eventPerfLog->eventInfo[event].time          += curTime;
832:   eventPerfLog->eventInfo[event].flops         += petsc_TotalFlops;
833:   eventPerfLog->eventInfo[event].numMessages   += petsc_irecv_ct  + petsc_isend_ct  + petsc_recv_ct  + petsc_send_ct;
834:   eventPerfLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
835:   eventPerfLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
836:   return(0);
837: }

841: PetscErrorCode PetscLogEventBeginTrace(PetscLogEvent event, int t, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
842: {
843:   PetscStageLog     stageLog;
844:   PetscEventRegLog  eventRegLog;
845:   PetscEventPerfLog eventPerfLog = NULL;
846:   PetscLogDouble    cur_time;
847:   PetscMPIInt       rank;
848:   int               stage,err;
849:   PetscErrorCode    ierr;

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

854:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
855:   PetscLogGetStageLog(&stageLog);
856:   PetscStageLogGetCurrent(stageLog, &stage);
857:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
858:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
859:   /* Check for double counting */
860:   eventPerfLog->eventInfo[event].depth++;
861:   petsc_tracelevel++;
862:   if (eventPerfLog->eventInfo[event].depth > 1) return(0);
863:   /* Log performance info */
864:   PetscTime(&cur_time);
865:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event begin: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
866:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);

868:   petsc_tracespace[2*petsc_tracelevel] = 0;

870:   err = fflush(petsc_tracefile);
871:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
872:   return(0);
873: }

877: PetscErrorCode PetscLogEventEndTrace(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
878: {
879:   PetscStageLog     stageLog;
880:   PetscEventRegLog  eventRegLog;
881:   PetscEventPerfLog eventPerfLog = NULL;
882:   PetscLogDouble    cur_time;
883:   int               stage,err;
884:   PetscMPIInt       rank;
885:   PetscErrorCode    ierr;

888:   petsc_tracelevel--;
889:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
890:   PetscLogGetStageLog(&stageLog);
891:   PetscStageLogGetCurrent(stageLog, &stage);
892:   PetscStageLogGetEventRegLog(stageLog, &eventRegLog);
893:   PetscStageLogGetEventPerfLog(stageLog, stage, &eventPerfLog);
894:   /* Check for double counting */
895:   eventPerfLog->eventInfo[event].depth--;
896:   if (eventPerfLog->eventInfo[event].depth > 0) return(0);
897:   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");

899:   /* Log performance info */
900:   PetscStrncpy(petsc_tracespace, petsc_traceblanks, 2*petsc_tracelevel);

902:   petsc_tracespace[2*petsc_tracelevel] = 0;
903:   PetscTime(&cur_time);
904:   PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile, "%s[%d] %g Event end: %s\n", petsc_tracespace, rank, cur_time-petsc_tracetime, eventRegLog->eventInfo[event].name);
905:   err  = fflush(petsc_tracefile);
906:   if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
907:   return(0);
908: }