Actual source code: plog.c

      1: #define PETSC_DLL
      2: /*
      3:       PETSc code to log object creation and destruction and PETSc events.
      4: */
     5:  #include petsc.h
      6: #include "petscmachineinfo.h"
      7: #if defined(PETSC_HAVE_MPE)
      8: #include "mpe.h"
      9: #endif
     10: #include <stdarg.h>
     11: #include <sys/types.h>
     12:  #include petscsys.h
     13: #if defined(PETSC_HAVE_STDLIB_H)
     14: #include <stdlib.h>
     15: #endif
     16: #if defined(PETSC_HAVE_MALLOC_H)
     17: #include <malloc.h>
     18: #endif
     19: #include "petscfix.h"
     20:  #include src/sys/src/plog/ptime.h
     21:  #include plog.h

     23: PetscCookie PETSC_LARGEST_COOKIE = PETSC_COOKIE;
     24: PetscEvent  PETSC_LARGEST_EVENT  = PETSC_EVENT;

     26: #if defined(PETSC_USE_LOG)

     28: /* used in the MPI_XXX() count macros in petsclog.h */
     29: int PETSC_DLLEXPORT PETSC_DUMMY_SIZE = 0;
     30: int PETSC_DLLEXPORT PETSC_DUMMY_COUNT = 0;

     32: /* Action and object logging variables */
     33: Action    *actions    = PETSC_NULL;
     34: Object    *objects    = PETSC_NULL;
     35: PetscTruth logActions = PETSC_FALSE;
     36: PetscTruth logObjects = PETSC_FALSE;
     37: int        numActions = 0, maxActions = 100;
     38: int        numObjects = 0, maxObjects = 100;
     39: int        numObjectsDestroyed = 0;

     41: /* Global counters */
     42: PetscLogDouble PETSC_DLLEXPORT BaseTime        = 0.0;
     43: PetscLogDouble PETSC_DLLEXPORT _TotalFlops     = 0.0; /* The number of flops */
     44: PetscLogDouble PETSC_DLLEXPORT send_ct         = 0.0; /* The number of sends */
     45: PetscLogDouble PETSC_DLLEXPORT recv_ct         = 0.0; /* The number of receives */
     46: PetscLogDouble PETSC_DLLEXPORT send_len        = 0.0; /* The total length of all sent messages */
     47: PetscLogDouble PETSC_DLLEXPORT recv_len        = 0.0; /* The total length of all received messages */
     48: PetscLogDouble PETSC_DLLEXPORT isend_ct        = 0.0; /* The number of immediate sends */
     49: PetscLogDouble PETSC_DLLEXPORT irecv_ct        = 0.0; /* The number of immediate receives */
     50: PetscLogDouble PETSC_DLLEXPORT isend_len       = 0.0; /* The total length of all immediate send messages */
     51: PetscLogDouble PETSC_DLLEXPORT irecv_len       = 0.0; /* The total length of all immediate receive messages */
     52: PetscLogDouble PETSC_DLLEXPORT wait_ct         = 0.0; /* The number of waits */
     53: PetscLogDouble PETSC_DLLEXPORT wait_any_ct     = 0.0; /* The number of anywaits */
     54: PetscLogDouble PETSC_DLLEXPORT wait_all_ct     = 0.0; /* The number of waitalls */
     55: PetscLogDouble PETSC_DLLEXPORT sum_of_waits_ct = 0.0; /* The total number of waits */
     56: PetscLogDouble PETSC_DLLEXPORT allreduce_ct    = 0.0; /* The number of reductions */

     58: /* Logging functions */
     59: PetscErrorCode PETSC_DLLEXPORT (*_PetscLogPHC)(PetscObject) = PETSC_NULL;
     60: PetscErrorCode PETSC_DLLEXPORT (*_PetscLogPHD)(PetscObject) = PETSC_NULL;
     61: PetscErrorCode PETSC_DLLEXPORT (*_PetscLogPLB)(PetscEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = PETSC_NULL;
     62: PetscErrorCode PETSC_DLLEXPORT (*_PetscLogPLE)(PetscEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = PETSC_NULL;

     64: /* Tracing event logging variables */
     65: FILE          *tracefile       = PETSC_NULL;
     66: int            tracelevel      = 0;
     67: const char    *traceblanks     = "                                                                                                    ";
     68: char           tracespace[128] = " ";
     69: PetscLogDouble tracetime       = 0.0;

     71: /*---------------------------------------------- General Functions --------------------------------------------------*/
     74: /*@C
     75:   PetscLogDestroy - Destroys the object and event logging data and resets the global counters.

     77:   Not Collective

     79:   Notes:
     80:   This routine should not usually be used by programmers. Instead employ
     81:   PetscLogStagePush() and PetscLogStagePop().

     83:   Level: developer

     85: .keywords: log, destroy
     86: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogPrintSummary(), PetscLogStagePush(), PlogStagePop()
     87: @*/
     88: PetscErrorCode PETSC_DLLEXPORT PetscLogDestroy(void)
     89: {
     90:   StageLog stageLog;

     94:   if (actions) {
     95:     PetscFree(actions);
     96:     actions = PETSC_NULL;
     97:   }
     98:   if (objects) {
     99:     PetscFree(objects);
    100:     objects =  PETSC_NULL;
    101:   }
    102:   PetscLogSet(PETSC_NULL, PETSC_NULL);

    104:   /* Resetting phase */
    105:   PetscLogGetStageLog(&stageLog);
    106:   StageLogDestroy(stageLog);
    107:   _TotalFlops         = 0.0;
    108:   numActions          = 0;
    109:   numObjects          = 0;
    110:   numObjectsDestroyed = 0;
    111:   return(0);
    112: }

    116: /*@C
    117:   PetscLogSet - Sets the logging functions called at the beginning and ending of every event.

    119:   Not Collective

    121:   Input Parameters:
    122: + b - The function called at beginning of event
    123: - e - The function called at end of event

    125:   Level: developer

    127: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogAllBegin(), PetscLogTraceBegin()
    128: @*/
    129: PetscErrorCode PETSC_DLLEXPORT PetscLogSet(PetscErrorCode (*b)(PetscEvent, int, PetscObject, PetscObject, PetscObject, PetscObject),
    130:             PetscErrorCode (*e)(PetscEvent, int, PetscObject, PetscObject, PetscObject, PetscObject))
    131: {
    133:   _PetscLogPLB = b;
    134:   _PetscLogPLE = e;
    135:   return(0);
    136: }

    138: /*------------------------------------------- Initialization Functions ----------------------------------------------*/
    141: PetscErrorCode PETSC_DLLEXPORT PetscLogBegin_Private(void)
    142: {
    143:   static PetscTruth initialized = PETSC_FALSE;
    144:   int               stage;
    145:   PetscTruth        opt;
    146:   PetscErrorCode    ierr;

    149:   if (initialized) return(0);
    150:   initialized = PETSC_TRUE;
    151:   PetscOptionsHasName(PETSC_NULL, "-log_exclude_actions", &opt);
    152:   if (opt) {
    153:     logActions = PETSC_FALSE;
    154:   }
    155:   PetscOptionsHasName(PETSC_NULL, "-log_exclude_objects", &opt);
    156:   if (opt) {
    157:     logObjects = PETSC_FALSE;
    158:   }
    159:   if (logActions) {
    160:     PetscMalloc(maxActions * sizeof(Action), &actions);
    161:   }
    162:   if (logObjects) {
    163:     PetscMalloc(maxObjects * sizeof(Object), &objects);
    164:   }
    165:   _PetscLogPHC = PetscLogObjCreateDefault;
    166:   _PetscLogPHD = PetscLogObjDestroyDefault;
    167:   /* Setup default logging structures */
    168:   StageLogCreate(&_stageLog);
    169:   StageLogRegister(_stageLog, "Main Stage", &stage);
    170:   /* All processors sync here for more consistent logging */
    171:   MPI_Barrier(PETSC_COMM_WORLD);
    172:   PetscTime(BaseTime);
    173:   PetscLogStagePush(stage);
    174:   return(0);
    175: }

    179: /*@C
    180:   PetscLogBegin - Turns on logging of objects and events. This logs flop
    181:   rates and object creation and should not slow programs down too much.
    182:   This routine may be called more than once.

    184:   Collective over PETSC_COMM_WORLD

    186:   Options Database Keys:
    187: + -log_summary - Prints summary of flop and timing information to the
    188:                   screen (for code compiled with PETSC_USE_LOG)
    189: - -log - Prints detailed log information (for code compiled with PETSC_USE_LOG)

    191:   Usage:
    192: .vb
    193:       PetscInitialize(...);
    194:       PetscLogBegin();
    195:        ... code ...
    196:       PetscLogPrintSummary(MPI_Comm,filename); or PetscLogDump();
    197:       PetscFinalize();
    198: .ve

    200:   Notes:
    201:   PetscLogPrintSummary(MPI_Comm,filename) or PetscLogDump() actually cause the printing of
    202:   the logging information.

    204:   Level: advanced

    206: .keywords: log, begin
    207: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogPrintSummary(), PetscLogTraceBegin()
    208: @*/
    209: PetscErrorCode PETSC_DLLEXPORT PetscLogBegin(void)
    210: {

    214:   PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
    215:   PetscLogBegin_Private();
    216:   return(0);
    217: }

    221: /*@C
    222:   PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
    223:   all events. This creates large log files and slows the program down.

    225:   Collective on PETSC_COMM_WORLD

    227:   Options Database Keys:
    228: . -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)

    230:   Usage:
    231: .vb
    232:      PetscInitialize(...);
    233:      PetscLogAllBegin();
    234:      ... code ...
    235:      PetscLogDump(filename);
    236:      PetscFinalize();
    237: .ve

    239:   Notes:
    240:   A related routine is PetscLogBegin (with the options key -log), which is
    241:   intended for production runs since it logs only flop rates and object
    242:   creation (and shouldn't significantly slow the programs).

    244:   Level: advanced

    246: .keywords: log, all, begin
    247: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogTraceBegin()
    248: @*/
    249: PetscErrorCode PETSC_DLLEXPORT PetscLogAllBegin(void)
    250: {

    254:   PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
    255:   PetscLogBegin_Private();
    256:   return(0);
    257: }

    261: /*@
    262:   PetscLogTraceBegin - Activates trace logging.  Every time a PETSc event
    263:   begins or ends, the event name is printed.

    265:   Collective on PETSC_COMM_WORLD

    267:   Input Parameter:
    268: . file - The file to print trace in (e.g. stdout)

    270:   Options Database Key:
    271: . -log_trace [filename] - Activates PetscLogTraceBegin()

    273:   Notes:
    274:   PetscLogTraceBegin() prints the processor number, the execution time (sec),
    275:   then "Event begin:" or "Event end:" followed by the event name.

    277:   PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
    278:   to determine where a program is hanging without running in the
    279:   debugger.  Can be used in conjunction with the -log_info option.

    281:   Level: intermediate

    283: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogPrintSummary(), PetscLogBegin()
    284: @*/
    285: PetscErrorCode PETSC_DLLEXPORT PetscLogTraceBegin(FILE *file)
    286: {

    290:   tracefile = file;
    291:   PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
    292:   PetscLogBegin_Private();
    293:   return(0);
    294: }

    298: /*@
    299:   PetscLogActions - Determines whether actions are logged for the graphical viewer.

    301:   Not Collective

    303:   Input Parameter:
    304: . flag - PETSC_TRUE if actions are to be logged

    306:   Level: intermediate

    308:   Note: Logging of actions continues to consume more memory as the program
    309:   runs. Long running programs should consider turning this feature off.

    311:   Options Database Keys:
    312: . -log_exclude_actions - Turns off actions logging

    314: .keywords: log, stage, register
    315: .seealso: PetscLogStagePush(), PetscLogStagePop()
    316: @*/
    317: PetscErrorCode PETSC_DLLEXPORT PetscLogActions(PetscTruth flag)
    318: {
    320:   logActions = flag;
    321:   return(0);
    322: }

    326: /*@
    327:   PetscLogObjects - Determines whether objects are logged for the graphical viewer.

    329:   Not Collective

    331:   Input Parameter:
    332: . flag - PETSC_TRUE if objects are to be logged

    334:   Level: intermediate

    336:   Note: Logging of objects continues to consume more memory as the program
    337:   runs. Long running programs should consider turning this feature off.

    339:   Options Database Keys:
    340: . -log_exclude_objects - Turns off objects logging

    342: .keywords: log, stage, register
    343: .seealso: PetscLogStagePush(), PetscLogStagePop()
    344: @*/
    345: PetscErrorCode PETSC_DLLEXPORT PetscLogObjects(PetscTruth flag)
    346: {
    348:   logObjects = flag;
    349:   return(0);
    350: }

    352: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
    355: /*@C
    356:   PetscLogStageRegister - Attaches a charactor string name to a logging stage.

    358:   Not Collective

    360:   Input Parameter:
    361: . sname - The name to associate with that stage

    363:   Output Parameter:
    364: . stage - The stage number

    366:   Level: intermediate

    368: .keywords: log, stage, register
    369: .seealso: PetscLogStagePush(), PetscLogStagePop()
    370: @*/
    371: PetscErrorCode PETSC_DLLEXPORT PetscLogStageRegister(int *stage, const char sname[])
    372: {
    373:   StageLog       stageLog;
    374:   PetscEvent     event;

    378:   PetscLogGetStageLog(&stageLog);
    379:   StageLogRegister(stageLog, sname, stage);
    380:   /* Copy events already changed in the main stage, this sucks */
    381:   EventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
    382:   for(event = 0; event < stageLog->eventLog->numEvents; event++) {
    383:     EventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],
    384:                              &stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
    385:   }
    386:   ClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
    387:   return(0);
    388: }

    392: /*@C
    393:   PetscLogStagePush - This function pushes a stage on the stack.

    395:   Not Collective

    397:   Input Parameter:
    398: . stage - The stage on which to log

    400:   Usage:
    401:   If the option -log_sumary is used to run the program containing the
    402:   following code, then 2 sets of summary data will be printed during
    403:   PetscFinalize().
    404: .vb
    405:       PetscInitialize(int *argc,char ***args,0,0);
    406:       [stage 0 of code]
    407:       PetscLogStagePush(1);
    408:       [stage 1 of code]
    409:       PetscLogStagePop();
    410:       PetscBarrier(...);
    411:       [more stage 0 of code]
    412:       PetscFinalize();
    413: .ve
    414:
    415:   Notes:
    416:   Use PetscLogStageRegister() to register a stage.

    418:   Level: intermediate

    420: .keywords: log, push, stage
    421: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
    422: @*/
    423: PetscErrorCode PETSC_DLLEXPORT PetscLogStagePush(int stage)
    424: {
    425:   StageLog       stageLog;

    429:   PetscLogGetStageLog(&stageLog);
    430:   StageLogPush(stageLog, stage);
    431:   return(0);
    432: }

    436: /*@C
    437:   PetscLogStagePop - This function pops a stage from the stack.

    439:   Not Collective

    441:   Usage:
    442:   If the option -log_sumary is used to run the program containing the
    443:   following code, then 2 sets of summary data will be printed during
    444:   PetscFinalize().
    445: .vb
    446:       PetscInitialize(int *argc,char ***args,0,0);
    447:       [stage 0 of code]
    448:       PetscLogStagePush(1);
    449:       [stage 1 of code]
    450:       PetscLogStagePop();
    451:       PetscBarrier(...);
    452:       [more stage 0 of code]
    453:       PetscFinalize();
    454: .ve

    456:   Notes:
    457:   Use PetscLogStageRegister() to register a stage.

    459:   Level: intermediate

    461: .keywords: log, pop, stage
    462: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
    463: @*/
    464: PetscErrorCode PETSC_DLLEXPORT PetscLogStagePop(void)
    465: {
    466:   StageLog       stageLog;

    470:   PetscLogGetStageLog(&stageLog);
    471:   StageLogPop(stageLog);
    472:   return(0);
    473: }

    477: /*@
    478:   PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().

    480:   Not Collective

    482:   Input Parameters:
    483: + stage    - The stage
    484: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)

    486:   Level: intermediate

    488: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PreLoadBegin(), PreLoadEnd(), PreLoadStage()
    489: @*/
    490: PetscErrorCode PETSC_DLLEXPORT PetscLogStageSetActive(int stage, PetscTruth isActive)
    491: {
    492:   StageLog       stageLog;

    496:   PetscLogGetStageLog(&stageLog);
    497:   StageLogSetActive(stageLog, stage, isActive);
    498:   return(0);
    499: }

    503: /*@
    504:   PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().

    506:   Not Collective

    508:   Input Parameter:
    509: . stage    - The stage

    511:   Output Parameter:
    512: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)

    514:   Level: intermediate

    516: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PreLoadBegin(), PreLoadEnd(), PreLoadStage()
    517: @*/
    518: PetscErrorCode PETSC_DLLEXPORT PetscLogStageGetActive(int stage, PetscTruth *isActive) \
    519: {
    520:   StageLog       stageLog;

    524:   PetscLogGetStageLog(&stageLog);
    525:   StageLogGetActive(stageLog, stage, isActive);
    526:   return(0);
    527: }

    531: /*@
    532:   PetscLogStageSetVisible - Determines stage visibility in PetscLogPrintSummary()

    534:   Not Collective

    536:   Input Parameters:
    537: + stage     - The stage
    538: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)

    540:   Level: intermediate

    542: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogPrintSummary()
    543: @*/
    544: PetscErrorCode PETSC_DLLEXPORT PetscLogStageSetVisible(int stage, PetscTruth isVisible)
    545: {
    546:   StageLog       stageLog;

    550:   PetscLogGetStageLog(&stageLog);
    551:   StageLogSetVisible(stageLog, stage, isVisible);
    552:   return(0);
    553: }

    557: /*@
    558:   PetscLogStageGetVisible - Returns stage visibility in PetscLogPrintSummary()

    560:   Not Collective

    562:   Input Parameter:
    563: . stage     - The stage

    565:   Output Parameter:
    566: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)

    568:   Level: intermediate

    570: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogPrintSummary()
    571: @*/
    572: PetscErrorCode PETSC_DLLEXPORT PetscLogStageGetVisible(int stage, PetscTruth *isVisible)
    573: {
    574:   StageLog       stageLog;

    578:   PetscLogGetStageLog(&stageLog);
    579:   StageLogGetVisible(stageLog, stage, isVisible);
    580:   return(0);
    581: }

    585: /*@
    586:   PetscLogStageGetId - Returns the stage id when given the stage name.

    588:   Not Collective

    590:   Input Parameter:
    591: . name  - The stage name

    593:   Output Parameter:
    594: . stage - The stage

    596:   Level: intermediate

    598: .seealso: PetscLogStagePush(), PetscLogStagePop(), PreLoadBegin(), PreLoadEnd(), PreLoadStage()
    599: @*/
    600: PetscErrorCode PETSC_DLLEXPORT PetscLogStageGetId(const char name[], int *stage)
    601: {
    602:   StageLog       stageLog;

    606:   PetscLogGetStageLog(&stageLog);
    607:   StageLogGetStage(stageLog, name, stage);
    608:   return(0);
    609: }

    611: /*------------------------------------------------ Event Functions --------------------------------------------------*/
    614: /*@C
    615:   PetscLogEventRegister - Registers an event name for logging operations in an application code.

    617:   Not Collective

    619:   Input Parameter:
    620: + name   - The name associated with the event
    621: - cookie - The cookie associated to the class for this event
    622:
    623:   Output Parameter:
    624: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().

    626:   Example of Usage:
    627: .vb
    628:       int USER_EVENT;
    629:       int user_event_flops;
    630:       PetscLogEventRegister(&USER_EVENT,"User event name");
    631:       PetscLogEventBegin(USER_EVENT,0,0,0,0);
    632:          [code segment to monitor]
    633:          PetscLogFlops(user_event_flops);
    634:       PetscLogEventEnd(USER_EVENT,0,0,0,0);
    635: .ve

    637:   Notes:
    638:   PETSc automatically logs library events if the code has been
    639:   compiled with -DPETSC_USE_LOG (which is the default) and -log,
    640:   -log_summary, or -log_all are specified.  PetscLogEventRegister() is
    641:   intended for logging user events to supplement this PETSc
    642:   information.

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

    651:   Level: intermediate

    653: .keywords: log, event, register
    654: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
    655:           PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
    656:           PetscLogEventActivate(), PetscLogEventDeactivate()
    657: @*/
    658: PetscErrorCode PETSC_DLLEXPORT PetscLogEventRegister(PetscEvent *event, const char name[],PetscCookie cookie)
    659: {
    660:   StageLog       stageLog;
    661:   int            stage;

    665:   *event = PETSC_DECIDE;
    666:   PetscLogGetStageLog(&stageLog);
    667:   EventRegLogRegister(stageLog->eventLog, name, cookie, event);
    668:   for(stage = 0; stage < stageLog->numStages; stage++) {
    669:     EventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
    670:     ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
    671:   }
    672:   return(0);
    673: }

    677: /*@
    678:   PetscLogEventActivate - Indicates that a particular event should be logged.

    680:   Not Collective

    682:   Input Parameter:
    683: . event - The event id

    685:   Usage:
    686: .vb
    687:       PetscLogEventDeactivate(VEC_SetValues);
    688:         [code where you do not want to log VecSetValues()]
    689:       PetscLogEventActivate(VEC_SetValues);
    690:         [code where you do want to log VecSetValues()]
    691: .ve

    693:   Note:
    694:   The event may be either a pre-defined PETSc event (found in include/petsclog.h)
    695:   or an event number obtained with PetscLogEventRegister().

    697:   Level: advanced

    699: .keywords: log, event, activate
    700: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventDeactivate()
    701: @*/
    702: PetscErrorCode PETSC_DLLEXPORT PetscLogEventActivate(PetscEvent event)
    703: {
    704:   StageLog       stageLog;
    705:   int            stage;

    709:   PetscLogGetStageLog(&stageLog);
    710:   StageLogGetCurrent(stageLog, &stage);
    711:   EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
    712:   return(0);
    713: }

    717: /*@
    718:   PetscLogEventDeactivate - Indicates that a particular event should not be logged.

    720:   Not Collective

    722:   Input Parameter:
    723: . event - The event id

    725:   Usage:
    726: .vb
    727:       PetscLogEventDeactivate(VEC_SetValues);
    728:         [code where you do not want to log VecSetValues()]
    729:       PetscLogEventActivate(VEC_SetValues);
    730:         [code where you do want to log VecSetValues()]
    731: .ve

    733:   Note:
    734:   The event may be either a pre-defined PETSc event (found in
    735:   include/petsclog.h) or an event number obtained with PetscLogEventRegister()).

    737:   Level: advanced

    739: .keywords: log, event, deactivate
    740: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate()
    741: @*/
    742: PetscErrorCode PETSC_DLLEXPORT PetscLogEventDeactivate(PetscEvent event)
    743: {
    744:   StageLog       stageLog;
    745:   int            stage;

    749:   PetscLogGetStageLog(&stageLog);
    750:   StageLogGetCurrent(stageLog, &stage);
    751:   EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
    752:   return(0);
    753: }

    757: /*@
    758:   PetscLogEventSetActiveAll - Sets the event activity in every stage.

    760:   Not Collective

    762:   Input Parameters:
    763: + event    - The event id
    764: - isActive - The activity flag determining whether the event is logged

    766:   Level: advanced

    768: .keywords: log, event, activate
    769: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate(),PlogEventDeactivate()
    770: @*/
    771: PetscErrorCode PETSC_DLLEXPORT PetscLogEventSetActiveAll(PetscEvent event, PetscTruth isActive)
    772: {
    773:   StageLog       stageLog;
    774:   int            stage;

    778:   PetscLogGetStageLog(&stageLog);
    779:   for(stage = 0; stage < stageLog->numStages; stage++) {
    780:     if (isActive) {
    781:       EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
    782:     } else {
    783:       EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
    784:     }
    785:   }
    786:   return(0);
    787: }

    791: /*@
    792:   PetscLogEventActivateClass - Activates event logging for a PETSc object class.

    794:   Not Collective

    796:   Input Parameter:
    797: . cookie - The event class, for example MAT_COOKIE, SNES_COOKIE, etc.

    799:   Level: developer

    801: .keywords: log, event, activate, class
    802: .seealso: PetscLogInfoActivate(),PetscLogInfo(),PetscLogInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
    803: @*/
    804: PetscErrorCode PETSC_DLLEXPORT PetscLogEventActivateClass(PetscCookie cookie)
    805: {
    806:   StageLog       stageLog;
    807:   int            stage;

    811:   PetscLogGetStageLog(&stageLog);
    812:   StageLogGetCurrent(stageLog, &stage);
    813:   EventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, cookie);
    814:   return(0);
    815: }

    819: /*@
    820:   PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.

    822:   Not Collective

    824:   Input Parameter:
    825: . cookie - The event class, for example MAT_COOKIE, SNES_COOKIE, etc.

    827:   Level: developer

    829: .keywords: log, event, deactivate, class
    830: .seealso: PetscLogInfoActivate(),PetscLogInfo(),PetscLogInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
    831: @*/
    832: PetscErrorCode PETSC_DLLEXPORT PetscLogEventDeactivateClass(PetscCookie cookie)
    833: {
    834:   StageLog       stageLog;
    835:   int            stage;

    839:   PetscLogGetStageLog(&stageLog);
    840:   StageLogGetCurrent(stageLog, &stage);
    841:   EventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, cookie);
    842:   return(0);
    843: }

    845: /*MC
    846:    PetscLogEventBegin - Logs the beginning of a user event.

    848:    Input Parameters:
    849: +  e - integer associated with the event obtained from PetscLogEventRegister()
    850: -  o1,o2,o3,o4 - objects associated with the event, or 0

    852:    Synopsis:
    853:    void PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,
    854:                        PetscObject o4)

    856:    Fortran Synopsis:
    857:    void PetscLogEventEnd(int e,PetscErrorCode ierr)

    859:    Usage:
    860: .vb
    861:      int USER_EVENT;
    862:      int user_event_flops;
    863:      PetscLogEventRegister(&USER_EVENT,"User event");
    864:      PetscLogEventBegin(USER_EVENT,0,0,0,0);
    865:         [code segment to monitor]
    866:         PetscLogFlops(user_event_flops);
    867:      PetscLogEventEnd(USER_EVENT,0,0,0,0);
    868: .ve

    870:    Notes:
    871:    You need to register each integer event with the command
    872:    PetscLogEventRegister().  The source code must be compiled with
    873:    -DPETSC_USE_LOG, which is the default.

    875:    PETSc automatically logs library events if the code has been
    876:    compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
    877:    specified.  PetscLogEventBegin() is intended for logging user events
    878:    to supplement this PETSc information.

    880:    Level: intermediate

    882: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()

    884: .keywords: log, event, begin
    885: M*/

    887: /*MC
    888:    PetscLogEventEnd - Log the end of a user event.

    890:    Input Parameters:
    891: +  e - integer associated with the event obtained with PetscLogEventRegister()
    892: -  o1,o2,o3,o4 - objects associated with the event, or 0

    894:    Synopsis:
    895:    void PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,
    896:                      PetscObject o4)

    898:    Fortran Synopsis:
    899:    void PetscLogEventEnd(int e,PetscErrorCode ierr)

    901:    Usage:
    902: .vb
    903:      int USER_EVENT;
    904:      int user_event_flops;
    905:      PetscLogEventRegister(&USER_EVENT,"User event");
    906:      PetscLogEventBegin(USER_EVENT,0,0,0,0);
    907:         [code segment to monitor]
    908:         PetscLogFlops(user_event_flops);
    909:      PetscLogEventEnd(USER_EVENT,0,0,0,0);
    910: .ve

    912:    Notes:
    913:    You should also register each additional integer event with the command
    914:    PetscLogEventRegister(). Source code must be compiled with
    915:    -DPETSC_USE_LOG, which is the default.

    917:    PETSc automatically logs library events if the code has been
    918:    compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
    919:    specified.  PetscLogEventEnd() is intended for logging user events
    920:    to supplement this PETSc information.

    922:    Level: intermediate

    924: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()

    926: .keywords: log, event, end
    927: M*/

    929: /*MC
    930:    PetscLogEventBarrierBegin - Logs the time in a barrier before an event.

    932:    Input Parameters:
    933: .  e - integer associated with the event obtained from PetscLogEventRegister()
    934: .  o1,o2,o3,o4 - objects associated with the event, or 0
    935: .  comm - communicator the barrier takes place over

    937:    Synopsis:
    938:    void PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,
    939:                   PetscObject o4,MPI_Comm comm)

    941:    Usage:
    942: .vb
    943:      PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
    944:        MPI_Allreduce()
    945:      PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
    946: .ve

    948:    Notes:
    949:    This is for logging the amount of time spent in a barrier for an event
    950:    that requires synchronization.

    952:    Additional Notes:
    953:    Synchronization events always come in pairs; for example, VEC_NormBarrier and
    954:    VEC_NormComm = VEC_NormBarrier + 1

    956:    Level: advanced

    958: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
    959:           PetscLogEventBarrierEnd()

    961: .keywords: log, event, begin, barrier
    962: M*/

    964: /*MC
    965:    PetscLogEventBarrierEnd - Logs the time in a barrier before an event.

    967:    Input Parameters:
    968: .  e - integer associated with the event obtained from PetscLogEventRegister()
    969: .  o1,o2,o3,o4 - objects associated with the event, or 0
    970: .  comm - communicator the barrier takes place over

    972:    Synopsis:
    973:    void PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,
    974:                   PetscObject o4,MPI_Comm comm)

    976:     Usage:
    977: .vb
    978:      PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
    979:        MPI_Allreduce()
    980:      PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
    981: .ve

    983:    Notes:
    984:    This is for logging the amount of time spent in a barrier for an event
    985:    that requires synchronization.

    987:    Additional Notes:
    988:    Synchronization events always come in pairs; for example, VEC_NormBarrier and
    989:    VEC_NormComm = VEC_NormBarrier + 1

    991:    Level: advanced

    993: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
    994:           PetscLogEventBarrierBegin()

    996: .keywords: log, event, begin, barrier
    997: M*/

    999: /*------------------------------------------------ Class Functions --------------------------------------------------*/
    1002: /*@C
    1003:   PetscLogClassRegister - Registers a class name for logging operations in an application code.

    1005:   Not Collective

    1007:   Input Parameter:
    1008: . name   - The class name
    1009:
    1010:   Output Parameter:
    1011: . oclass - The class id or cookie

    1013:   Level: developer

    1015: .keywords: log, class, register
    1016: .seealso: ClassLogRegister()
    1017: @*/
    1018: PetscErrorCode PETSC_DLLEXPORT PetscLogClassRegister(PetscCookie *oclass, const char name[])
    1019: {
    1020:   StageLog       stageLog;
    1021:   int            stage;

    1025:   *oclass = PETSC_DECIDE;
    1026:   PetscLogGetStageLog(&stageLog);
    1027:   ClassRegLogRegister(stageLog->classLog, name, oclass);
    1028:   for(stage = 0; stage < stageLog->numStages; stage++) {
    1029:     ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
    1030:   }
    1031:   return(0);
    1032: }

    1034: /*------------------------------------------------ Output Functions -------------------------------------------------*/
    1037: /*@C
    1038:   PetscLogDump - Dumps logs of objects to a file. This file is intended to
    1039:   be read by petsc/bin/petscview.

    1041:   Collective on PETSC_COMM_WORLD

    1043:   Input Parameter:
    1044: . name - an optional file name

    1046:   Options Database Keys:
    1047: + -log     - Prints basic log information (for code compiled with PETSC_USE_LOG)
    1048: - -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)
    1049:
    1050:   Usage:
    1051: .vb
    1052:      PetscInitialize(...);
    1053:      PetscLogBegin(); or PetscLogAllBegin();
    1054:      ... code ...
    1055:      PetscLogDump(filename);
    1056:      PetscFinalize();
    1057: .ve

    1059:   Notes:
    1060:   The default file name is
    1061: $    Log.<rank>
    1062:   where <rank> is the processor number. If no name is specified,
    1063:   this file will be used.

    1065:   Level: advanced

    1067: .keywords: log, dump
    1068: .seealso: PetscLogBegin(), PetscLogAllBegin(), PetscLogPrintSummary()
    1069: @*/
    1070: PetscErrorCode PETSC_DLLEXPORT PetscLogDump(const char sname[])
    1071: {
    1072:   StageLog       stageLog;
    1073:   EventPerfInfo *eventInfo;
    1074:   FILE          *fd;
    1075:   char           file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
    1076:   PetscLogDouble flops, _TotalTime;
    1077:   PetscMPIInt    rank;
    1078:   int            action, object, curStage;
    1079:   PetscEvent     event;
    1081:
    1083:   /* Calculate the total elapsed time */
    1084:   PetscTime(_TotalTime);
    1085:   _TotalTime -= BaseTime;
    1086:   /* Open log file */
    1087:   MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
    1088:   if (sname) {
    1089:     sprintf(file, "%s.%d", sname, rank);
    1090:   } else {
    1091:     sprintf(file, "Log.%d", rank);
    1092:   }
    1093:   PetscFixFilename(file, fname);
    1094:   PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
    1095:   if ((!rank) && (!fd)) SETERRQ1(PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
    1096:   /* Output totals */
    1097:   PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flops %14e %16.8e\n", _TotalFlops, _TotalTime);
    1098:   PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
    1099:   /* Output actions */
    1100:   PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", numActions);
    1101:   for(action = 0; action < numActions; action++) {
    1102:     PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
    1103:                         actions[action].time, actions[action].action, (int)actions[action].event, (int)actions[action].cookie, actions[action].id1,
    1104:                         actions[action].id2, actions[action].id3, actions[action].flops, actions[action].mem, actions[action].maxmem);
    1105:   }
    1106:   /* Output objects */
    1107:   PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", numObjects, numObjectsDestroyed);
    1108:   for(object = 0; object < numObjects; object++) {
    1109:     PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", objects[object].parent, (int) objects[object].mem);
    1110:     if (!objects[object].name[0]) {
    1111:       PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
    1112:     } else {
    1113:       PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", objects[object].name);
    1114:     }
    1115:     if (objects[object].info[0] != 0) {
    1116:       PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
    1117:     } else {
    1118:       PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", objects[object].info);
    1119:     }
    1120:   }
    1121:   /* Output events */
    1122:   PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
    1123:   PetscLogGetStageLog(&stageLog);
    1124:   StackTop(stageLog->stack, &curStage);
    1125:   eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
    1126:   for(event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
    1127:     if (eventInfo[event].time != 0.0) {
    1128:       flops = eventInfo[event].flops/eventInfo[event].time;
    1129:     } else {
    1130:       flops = 0.0;
    1131:     }
    1132:     PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
    1133:                         eventInfo[event].flops, eventInfo[event].time, flops);
    1134:   }
    1135:   PetscFClose(PETSC_COMM_WORLD, fd);
    1136:   return(0);
    1137: }

    1141: /*@C
    1142:   PetscLogPrintSummary - Prints a summary of the logging.

    1144:   Collective over MPI_Comm

    1146:   Input Parameter:
    1147: + comm - The MPI communicator (only one processor prints output)
    1148: - file - [Optional] The output file name

    1150:   Options Database Keys:
    1151: . -log_summary - Prints summary of log information (for code compiled with PETSC_USE_LOG)

    1153:   Usage:
    1154: .vb
    1155:      PetscInitialize(...);
    1156:      PetscLogBegin();
    1157:      ... code ...
    1158:      PetscLogPrintSummary(MPI_Comm,filename);
    1159:      PetscFinalize(...);
    1160: .ve

    1162:   Notes:
    1163:   By default the summary is printed to stdout.
    1164:   More extensive examination of the log information can be done with
    1165:   PetscLogDump(), which is activated by the option -log or -log_all, in
    1166:   combination with petsc/bin/petscview.

    1168:   Level: beginner
    1169:
    1170: .keywords: log, dump, print
    1171: .seealso: PetscLogBegin(), PetscLogDump()
    1172: @*/
    1173: PetscErrorCode PETSC_DLLEXPORT PetscLogPrintSummary(MPI_Comm comm, const char filename[])
    1174: {
    1175:   FILE          *fd   = stdout;
    1176:   PetscScalar    zero = 0.0;
    1177:   StageLog       stageLog;
    1178:   StageInfo     *stageInfo = PETSC_NULL;
    1179:   EventPerfInfo *eventInfo = PETSC_NULL;
    1180:   ClassPerfInfo *classInfo;
    1181:   char           arch[10], hostname[64], username[16], pname[PETSC_MAX_PATH_LEN], date[64];
    1182:   const char    *name;
    1183:   PetscLogDouble locTotalTime, TotalTime, TotalFlops;
    1184:   PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
    1185:   PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
    1186:   PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
    1187:   PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
    1188:   PetscLogDouble min, max, tot, ratio, avg, x, y;
    1189:   PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr;
    1190:   int            minCt, maxCt;
    1191:   PetscMPIInt    size, rank;
    1192:   PetscTruth    *localStageUsed,    *stageUsed;
    1193:   PetscTruth    *localStageVisible, *stageVisible;
    1194:   int            numStages, localNumEvents, numEvents;
    1195:   int            stage, oclass;
    1196:   PetscEvent     event;
    1198:   char           version[256];

    1201:   MPI_Comm_size(comm, &size);
    1202:   MPI_Comm_rank(comm, &rank);
    1203:   /* Pop off any stages the user forgot to remove */
    1204:   PetscLogGetStageLog(&stageLog);
    1205:   StageLogGetCurrent(stageLog, &stage);
    1206:   while (stage >= 0) {
    1207:     StageLogPop(stageLog);
    1208:     StageLogGetCurrent(stageLog, &stage);
    1209:   }
    1210:   /* Get the total elapsed time */
    1211:   PetscTime(locTotalTime);  locTotalTime -= BaseTime;
    1212:   /* Open the summary file */
    1213:   if (filename) {
    1214:     PetscFOpen(comm, filename, "w", &fd);
    1215:   }

    1217:   PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
    1218:   PetscFPrintf(comm, fd, "***             WIDEN YOUR WINDOW TO 120 CHARACTERS.  Use 'enscript -r -fCourier9' to print this document            ***\n");
    1219:   PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
    1220:   PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
    1221:   PetscGetArchType(arch, 10);
    1222:   PetscGetHostName(hostname, 64);
    1223:   PetscGetUserName(username, 16);
    1224:   PetscGetProgramName(pname, PETSC_MAX_PATH_LEN);
    1225:   PetscGetDate(date, 64);
    1226:   PetscGetVersion(&version);
    1227:   if (size == 1) {
    1228:     PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
    1229:
    1230:   } else {
    1231:     PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
    1232:
    1233:   }
    1234:   PetscFPrintf(comm, fd, "Using %s\n", version);

    1236:   /* Must preserve reduction count before we go on */
    1237:   red  = allreduce_ct/((PetscLogDouble) size);

    1239:   /* Calculate summary information */
    1240:   PetscFPrintf(comm, fd, "\n                         Max       Max/Min        Avg      Total \n");
    1241:   /*   Time */
    1242:   MPI_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1243:   MPI_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1244:   MPI_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1245:   avg  = (tot)/((PetscLogDouble) size);
    1246:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1247:   PetscFPrintf(comm, fd, "Time (sec):           %5.3e   %10.5f   %5.3e\n", max, ratio, avg);
    1248:   TotalTime = tot;
    1249:   /*   Objects */
    1250:   avg  = (PetscLogDouble) numObjects;
    1251:   MPI_Allreduce(&avg,          &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1252:   MPI_Allreduce(&avg,          &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1253:   MPI_Allreduce(&avg,          &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1254:   avg  = (tot)/((PetscLogDouble) size);
    1255:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1256:   PetscFPrintf(comm, fd, "Objects:              %5.3e   %10.5f   %5.3e\n", max, ratio, avg);
    1257:   /*   Flops */
    1258:   MPI_Allreduce(&_TotalFlops,  &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1259:   MPI_Allreduce(&_TotalFlops,  &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1260:   MPI_Allreduce(&_TotalFlops,  &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1261:   avg  = (tot)/((PetscLogDouble) size);
    1262:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1263:   PetscFPrintf(comm, fd, "Flops:                %5.3e   %10.5f   %5.3e  %5.3e\n", max, ratio, avg, tot);
    1264:   TotalFlops = tot;
    1265:   /*   Flops/sec -- Must talk to Barry here */
    1266:   if (locTotalTime != 0.0) flops = _TotalFlops/locTotalTime; else flops = 0.0;
    1267:   MPI_Allreduce(&flops,        &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1268:   MPI_Allreduce(&flops,        &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1269:   MPI_Allreduce(&flops,        &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1270:   avg  = (tot)/((PetscLogDouble) size);
    1271:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1272:   PetscFPrintf(comm, fd, "Flops/sec:            %5.3e   %10.5f   %5.3e  %5.3e\n", max, ratio, avg, tot);
    1273:   /*   Memory */
    1274:   PetscMallocGetMaximumUsage(&mem);
    1275:   if (mem > 0.0) {
    1276:     MPI_Allreduce(&mem,          &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1277:     MPI_Allreduce(&mem,          &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1278:     MPI_Allreduce(&mem,          &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1279:     avg  = (tot)/((PetscLogDouble) size);
    1280:     if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1281:     PetscFPrintf(comm, fd, "Memory:               %5.3e   %10.5f              %5.3e\n", max, ratio, tot);
    1282:   }
    1283:   /*   Messages */
    1284:   mess = 0.5*(irecv_ct + isend_ct + recv_ct + send_ct);
    1285:   MPI_Allreduce(&mess,         &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1286:   MPI_Allreduce(&mess,         &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1287:   MPI_Allreduce(&mess,         &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1288:   avg  = (tot)/((PetscLogDouble) size);
    1289:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1290:   PetscFPrintf(comm, fd, "MPI Messages:         %5.3e   %10.5f   %5.3e  %5.3e\n", max, ratio, avg, tot);
    1291:   numMessages = tot;
    1292:   /*   Message Lengths */
    1293:   mess = 0.5*(irecv_len + isend_len + recv_len + send_len);
    1294:   MPI_Allreduce(&mess,         &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1295:   MPI_Allreduce(&mess,         &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1296:   MPI_Allreduce(&mess,         &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1297:   if (numMessages != 0) avg = (tot)/(numMessages); else avg = 0.0;
    1298:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1299:   PetscFPrintf(comm, fd, "MPI Message Lengths:  %5.3e   %10.5f   %5.3e  %5.3e\n", max, ratio, avg, tot);
    1300:   messageLength = tot;
    1301:   /*   Reductions */
    1302:   MPI_Allreduce(&red,          &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1303:   MPI_Allreduce(&red,          &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1304:   MPI_Allreduce(&red,          &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1305:   if (min != 0.0) ratio = max/min; else ratio = 0.0;
    1306:   PetscFPrintf(comm, fd, "MPI Reductions:       %5.3e   %10.5f\n", max, ratio);
    1307:   numReductions = tot;
    1308:   PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
    1309:   PetscFPrintf(comm, fd, "                            e.g., VecAXPY() for real vectors of length N --> 2N flops\n");
    1310:   PetscFPrintf(comm, fd, "                            and VecAXPY() for complex vectors of length N --> 8N flops\n");

    1312:   /* Get total number of stages --
    1313:        Currently, a single processor can register more stages than another, but stages must all be registered in order.
    1314:        We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
    1315:        This seems best accomplished by assoicating a communicator with each stage.
    1316:   */
    1317:   MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
    1318:   PetscMalloc(numStages * sizeof(PetscTruth), &localStageUsed);
    1319:   PetscMalloc(numStages * sizeof(PetscTruth), &stageUsed);
    1320:   PetscMalloc(numStages * sizeof(PetscTruth), &localStageVisible);
    1321:   PetscMalloc(numStages * sizeof(PetscTruth), &stageVisible);
    1322:   if (numStages > 0) {
    1323:     stageInfo = stageLog->stageInfo;
    1324:     for(stage = 0; stage < numStages; stage++) {
    1325:       if (stage < stageLog->numStages) {
    1326:         localStageUsed[stage]    = stageInfo[stage].used;
    1327:         localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
    1328:       } else {
    1329:         localStageUsed[stage]    = PETSC_FALSE;
    1330:         localStageVisible[stage] = PETSC_TRUE;
    1331:       }
    1332:     }
    1333:     MPI_Allreduce(localStageUsed,    stageUsed,    numStages, MPI_INT, MPI_LOR,  comm);
    1334:     MPI_Allreduce(localStageVisible, stageVisible, numStages, MPI_INT, MPI_LAND, comm);
    1335:     for(stage = 0; stage < numStages; stage++) {
    1336:       if (stageUsed[stage]) {
    1337:         PetscFPrintf(comm, fd, "\nSummary of Stages:   ----- Time ------  ----- Flops -----  --- Messages ---  -- Message Lengths --  -- Reductions --\n");
    1338:         PetscFPrintf(comm, fd, "                        Avg     %%Total     Avg     %%Total   counts   %%Total     Avg         %%Total   counts   %%Total \n");
    1339:         break;
    1340:       }
    1341:     }
    1342:     for(stage = 0; stage < numStages; stage++) {
    1343:       if (!stageUsed[stage]) continue;
    1344:       if (localStageUsed[stage]) {
    1345:         MPI_Allreduce(&stageInfo[stage].perfInfo.time,          &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1346:         MPI_Allreduce(&stageInfo[stage].perfInfo.flops,         &flops,     1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1347:         MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages,   &mess,      1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1348:         MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen,   1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1349:         MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red,       1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1350:         name = stageInfo[stage].name;
    1351:       } else {
    1352:         MPI_Allreduce(&zero,                           &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1353:         MPI_Allreduce(&zero,                           &flops,     1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1354:         MPI_Allreduce(&zero,                           &mess,      1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1355:         MPI_Allreduce(&zero,                           &messLen,   1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1356:         MPI_Allreduce(&zero,                           &red,       1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1357:         name = "";
    1358:       }
    1359:       mess *= 0.5; messLen *= 0.5; red /= size;
    1360:       if (TotalTime     != 0.0) fracTime       = stageTime/TotalTime;    else fracTime       = 0.0;
    1361:       if (TotalFlops    != 0.0) fracFlops      = flops/TotalFlops;       else fracFlops      = 0.0;
    1362:       /* Talk to Barry if (stageTime     != 0.0) flops          = (size*flops)/stageTime; else flops          = 0.0; */
    1363:       if (numMessages   != 0.0) fracMessages   = mess/numMessages;       else fracMessages   = 0.0;
    1364:       if (numMessages   != 0.0) avgMessLen     = messLen/numMessages;    else avgMessLen     = 0.0;
    1365:       if (messageLength != 0.0) fracLength     = messLen/messageLength;  else fracLength     = 0.0;
    1366:       if (numReductions != 0.0) fracReductions = red/numReductions;      else fracReductions = 0.0;
    1367:       PetscFPrintf(comm, fd, "%2d: %15s: %6.4e %5.1f%%  %6.4e %5.1f%%  %5.3e %5.1f%%  %5.3e      %5.1f%%  %5.3e %5.1f%% \n",
    1368:                           stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
    1369:                           mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
    1370:
    1371:     }
    1372:   }

    1374:   PetscFPrintf(comm, fd,
    1375:     "\n------------------------------------------------------------------------------------------------------------------------\n");
    1376:
    1377:   PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
    1378:   PetscFPrintf(comm, fd, "Phase summary info:\n");
    1379:   PetscFPrintf(comm, fd, "   Count: number of times phase was executed\n");
    1380:   PetscFPrintf(comm, fd, "   Time and Flops/sec: Max - maximum over all processors\n");
    1381:   PetscFPrintf(comm, fd, "                       Ratio - ratio of maximum to minimum over all processors\n");
    1382:   PetscFPrintf(comm, fd, "   Mess: number of messages sent\n");
    1383:   PetscFPrintf(comm, fd, "   Avg. len: average message length\n");
    1384:   PetscFPrintf(comm, fd, "   Reduct: number of global reductions\n");
    1385:   PetscFPrintf(comm, fd, "   Global: entire computation\n");
    1386:   PetscFPrintf(comm, fd, "   Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
    1387:   PetscFPrintf(comm, fd, "      %%T - percent time in this phase         %%F - percent flops in this phase\n");
    1388:   PetscFPrintf(comm, fd, "      %%M - percent messages in this phase     %%L - percent message lengths in this phase\n");
    1389:   PetscFPrintf(comm, fd, "      %%R - percent reductions in this phase\n");
    1390:   PetscFPrintf(comm, fd, "   Total Mflop/s: 10e-6 * (sum of flops over all processors)/(max time over all processors)\n");
    1391:   PetscFPrintf(comm, fd,
    1392:     "------------------------------------------------------------------------------------------------------------------------\n");
    1393:

    1395: #if defined(PETSC_USE_DEBUG)
    1396:   PetscFPrintf(comm, fd, "\n\n");
    1397:   PetscFPrintf(comm, fd, "      ##########################################################\n");
    1398:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1399:   PetscFPrintf(comm, fd, "      #                          WARNING!!!                    #\n");
    1400:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1401:   PetscFPrintf(comm, fd, "      #   This code was compiled with a debugging option,      #\n");
    1402:   PetscFPrintf(comm, fd, "      #   To get timing results run config/configure.py        #\n");
    1403:   PetscFPrintf(comm, fd, "      #   without --with-debugging=no, the performance will    #\n");
    1404:   PetscFPrintf(comm, fd, "      #   be generally two or three times faster.              #\n");
    1405:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1406:   PetscFPrintf(comm, fd, "      ##########################################################\n\n\n");
    1407: #endif
    1408: #if defined(PETSC_USE_COMPLEX) && !defined(PETSC_USE_FORTRAN_KERNELS)
    1409:   PetscFPrintf(comm, fd, "\n\n");
    1410:   PetscFPrintf(comm, fd, "      ##########################################################\n");
    1411:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1412:   PetscFPrintf(comm, fd, "      #                          WARNING!!!                    #\n");
    1413:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1414:   PetscFPrintf(comm, fd, "      #   The code for various complex numbers numerical       #\n");
    1415:   PetscFPrintf(comm, fd, "      #   kernels uses C++, which generally is not well        #\n");
    1416:   PetscFPrintf(comm, fd, "      #   optimized.  For performance that is about 4-5 times  #\n");
    1417:   PetscFPrintf(comm, fd, "      #   faster, specify the flag -DPETSC_USE_FORTRAN_KERNELS #\n");
    1418:   PetscFPrintf(comm, fd, "      #   in base_variables and recompile the PETSc libraries. #\n");
    1419:   PetscFPrintf(comm, fd, "      #                                                        #\n");
    1420:   PetscFPrintf(comm, fd, "      ##########################################################\n\n\n");
    1421: #endif

    1423:   if (!PetscPreLoadingUsed) {
    1424:     PetscFPrintf(comm,fd,"\n\n");
    1425:     PetscFPrintf(comm,fd,"      ##########################################################\n");
    1426:     PetscFPrintf(comm,fd,"      #                                                        #\n");
    1427:     PetscFPrintf(comm,fd,"      #                          WARNING!!!                    #\n");
    1428:     PetscFPrintf(comm,fd,"      #                                                        #\n");
    1429:     PetscFPrintf(comm,fd,"      #   This code was run without the PreLoadBegin()         #\n");
    1430:     PetscFPrintf(comm,fd,"      #   macros. To get timing results we always recommend    #\n");
    1431:     PetscFPrintf(comm,fd,"      #   preloading. otherwise timing numbers may be          #\n");
    1432:     PetscFPrintf(comm,fd,"      #   meaningless.                                         #\n");
    1433:     PetscFPrintf(comm,fd,"      ##########################################################\n\n\n");
    1434:   }

    1436:   /* Report events */
    1437:   PetscFPrintf(comm, fd,
    1438:     "Event                Count      Time (sec)     Flops/sec                         --- Global ---  --- Stage ---   Total\n");
    1439:
    1440:   PetscFPrintf(comm, fd,
    1441:     "                   Max Ratio  Max     Ratio   Max  Ratio  Mess   Avg len Reduct  %%T %%F %%M %%L %%R  %%T %%F %%M %%L %%R Mflop/s\n");
    1442:
    1443:   PetscFPrintf(comm,fd,
    1444:     "------------------------------------------------------------------------------------------------------------------------\n");

    1446:
    1447:   /* Problem: The stage name will not show up unless the stage executed on proc 1 */
    1448:   for(stage = 0; stage < numStages; stage++) {
    1449:     if (!stageVisible[stage]) continue;
    1450:     if (localStageUsed[stage]) {
    1451:       PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
    1452:       MPI_Allreduce(&stageInfo[stage].perfInfo.time,          &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1453:       MPI_Allreduce(&stageInfo[stage].perfInfo.flops,         &flops,     1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1454:       MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages,   &mess,      1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1455:       MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen,   1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1456:       MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red,       1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1457:     } else {
    1458:       PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
    1459:       MPI_Allreduce(&zero,                           &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1460:       MPI_Allreduce(&zero,                           &flops,     1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1461:       MPI_Allreduce(&zero,                           &mess,      1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1462:       MPI_Allreduce(&zero,                           &messLen,   1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1463:       MPI_Allreduce(&zero,                           &red,       1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1464:     }
    1465:     mess *= 0.5; messLen *= 0.5; red /= size;

    1467:     /* Get total number of events in this stage --
    1468:        Currently, a single processor can register more events than another, but events must all be registered in order,
    1469:        just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
    1470:        on the event ID. This seems best accomplished by assoicating a communicator with each stage.

    1472:        Problem: If the event did not happen on proc 1, its name will not be available.
    1473:        Problem: Event visibility is not implemented
    1474:     */
    1475:     if (localStageUsed[stage]) {
    1476:       eventInfo      = stageLog->stageInfo[stage].eventLog->eventInfo;
    1477:       localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
    1478:     } else {
    1479:       localNumEvents = 0;
    1480:     }
    1481:     MPI_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
    1482:     for(event = 0; event < numEvents; event++) {
    1483:       if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents)) {
    1484:         if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) {
    1485:           flopr = eventInfo[event].flops/eventInfo[event].time;
    1486:         } else {
    1487:           flopr = 0.0;
    1488:         }
    1489:         MPI_Allreduce(&flopr,                          &minf,  1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1490:         MPI_Allreduce(&flopr,                          &maxf,  1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1491:         MPI_Allreduce(&eventInfo[event].flops,         &totf,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1492:         MPI_Allreduce(&eventInfo[event].time,          &mint,  1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1493:         MPI_Allreduce(&eventInfo[event].time,          &maxt,  1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1494:         MPI_Allreduce(&eventInfo[event].time,          &tott,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1495:         MPI_Allreduce(&eventInfo[event].numMessages,   &totm,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1496:         MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1497:         MPI_Allreduce(&eventInfo[event].numReductions, &totr,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1498:         MPI_Allreduce(&eventInfo[event].count,         &minCt, 1, MPI_INT,             MPI_MIN, comm);
    1499:         MPI_Allreduce(&eventInfo[event].count,         &maxCt, 1, MPI_INT,             MPI_MAX, comm);
    1500:         name = stageLog->eventLog->eventInfo[event].name;
    1501:       } else {
    1502:         flopr = 0.0;
    1503:         MPI_Allreduce(&flopr,                          &minf,  1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1504:         MPI_Allreduce(&flopr,                          &maxf,  1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1505:         MPI_Allreduce(&zero,                           &totf,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1506:         MPI_Allreduce(&zero,                           &mint,  1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
    1507:         MPI_Allreduce(&zero,                           &maxt,  1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
    1508:         MPI_Allreduce(&zero,                           &tott,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1509:         MPI_Allreduce(&zero,                           &totm,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1510:         MPI_Allreduce(&zero,                           &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1511:         MPI_Allreduce(&zero,                           &totr,  1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
    1512:         MPI_Allreduce(&ierr,                           &minCt, 1, MPI_INT,             MPI_MIN, comm);
    1513:         MPI_Allreduce(&ierr,                           &maxCt, 1, MPI_INT,             MPI_MAX, comm);
    1514:         name = "";
    1515:       }
    1516:       totm *= 0.5; totml *= 0.5; totr /= size;
    1517:
    1518:       if (maxCt != 0) {
    1519:         if (minCt         != 0)   ratCt            = ((PetscLogDouble) maxCt)/minCt; else ratCt            = 0.0;
    1520:         if (mint          != 0.0) ratt             = maxt/mint;                  else ratt             = 0.0;
    1521:         if (minf          != 0.0) ratf             = maxf/minf;                  else ratf             = 0.0;
    1522:         if (TotalTime     != 0.0) fracTime         = tott/TotalTime;             else fracTime         = 0.0;
    1523:         if (TotalFlops    != 0.0) fracFlops        = totf/TotalFlops;            else fracFlops        = 0.0;
    1524:         if (stageTime     != 0.0) fracStageTime    = tott/stageTime;             else fracStageTime    = 0.0;
    1525:         if (flops         != 0.0) fracStageFlops   = totf/flops;                 else fracStageFlops   = 0.0;
    1526:         if (numMessages   != 0.0) fracMess         = totm/numMessages;           else fracMess         = 0.0;
    1527:         if (messageLength != 0.0) fracMessLen      = totml/messageLength;        else fracMessLen      = 0.0;
    1528:         if (numReductions != 0.0) fracRed          = totr/numReductions;         else fracRed          = 0.0;
    1529:         if (mess          != 0.0) fracStageMess    = totm/mess;                  else fracStageMess    = 0.0;
    1530:         if (messLen       != 0.0) fracStageMessLen = totml/messLen;              else fracStageMessLen = 0.0;
    1531:         if (red           != 0.0) fracStageRed     = totr/red;                   else fracStageRed     = 0.0;
    1532:         if (totm          != 0.0) totml           /= totm;                       else totml            = 0.0;
    1533:         if (maxt          != 0.0) flopr            = totf/maxt;                  else flopr            = 0.0;
    1534:         PetscFPrintf(comm, fd,
    1535:           "%-16s %7d%4.1f %5.4e%4.1f %3.2e%4.1f %2.1e %2.1e %2.1e%3.0f%3.0f%3.0f%3.0f%3.0f %3.0f%3.0f%3.0f%3.0f%3.0f %5.0f\n",
    1536:                             name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr,
    1537:                             100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
    1538:                             100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
    1539:                             flopr/1.0e6);
    1540:
    1541:       }
    1542:     }
    1543:   }

    1545:   /* Memory usage and object creation */
    1546:   PetscFPrintf(comm, fd,
    1547:     "------------------------------------------------------------------------------------------------------------------------\n");
    1548:
    1549:   PetscFPrintf(comm, fd, "\n");
    1550:   PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");

    1552:   /* Right now, only stages on the first processor are reported here, meaning only objects associated with
    1553:      the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
    1554:      stats for stages local to processor sets.
    1555:   */
    1556:   /* We should figure out the longest object name here (now 20 characters) */
    1557:   PetscFPrintf(comm, fd, "Object Type          Creations   Destructions   Memory  Descendants' Mem.\n");
    1558:   for(stage = 0; stage < numStages; stage++) {
    1559:     if (localStageUsed[stage]) {
    1560:       classInfo = stageLog->stageInfo[stage].classLog->classInfo;
    1561:       PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
    1562:       for(oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
    1563:         if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
    1564:           PetscFPrintf(comm, fd, "%20s %5d          %5d  %9d     %g\n", stageLog->classLog->classInfo[oclass].name,
    1565:                               classInfo[oclass].creations, classInfo[oclass].destructions, (int) classInfo[oclass].mem,
    1566:                               classInfo[oclass].descMem);
    1567:
    1568:         }
    1569:       }
    1570:     } else {
    1571:       PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
    1572:     }
    1573:   }

    1575:   PetscFree(localStageUsed);
    1576:   PetscFree(stageUsed);
    1577:   PetscFree(localStageVisible);
    1578:   PetscFree(stageVisible);

    1580:   /* Information unrelated to this particular run */
    1581:   PetscFPrintf(comm, fd,
    1582:     "========================================================================================================================\n");
    1583:
    1584:   PetscTime(y);
    1585:   PetscTime(x);
    1586:   PetscTime(y); PetscTime(y); PetscTime(y); PetscTime(y); PetscTime(y);
    1587:   PetscTime(y); PetscTime(y); PetscTime(y); PetscTime(y); PetscTime(y);
    1588:   PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
    1589:   /* MPI information */
    1590:   if (size > 1) {
    1591:     MPI_Status  status;
    1592:     PetscMPIInt tag;
    1593:     MPI_Comm    newcomm;

    1595:     MPI_Barrier(comm);
    1596:     PetscTime(x);
    1597:     MPI_Barrier(comm);
    1598:     MPI_Barrier(comm);
    1599:     MPI_Barrier(comm);
    1600:     MPI_Barrier(comm);
    1601:     MPI_Barrier(comm);
    1602:     PetscTime(y);
    1603:     PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
    1604:     PetscCommDuplicate(comm,&newcomm, &tag);
    1605:     MPI_Barrier(comm);
    1606:     if (rank) {
    1607:       MPI_Recv(0, 0, MPI_INT, rank-1,            tag, newcomm, &status);
    1608:       MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);
    1609:     } else {
    1610:       PetscTime(x);
    1611:       MPI_Send(0, 0, MPI_INT, 1,          tag, newcomm);
    1612:       MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);
    1613:       PetscTime(y);
    1614:       PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
    1615:     }
    1616:     PetscCommDestroy(&newcomm);
    1617:   }
    1618:   /* Machine and compile information */
    1619: #if defined(PETSC_USE_FORTRAN_KERNELS)
    1620:   PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
    1621: #else
    1622:   PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
    1623: #endif
    1624: #if defined(PETSC_USE_MAT_SINGLE)
    1625:   PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
    1626: #else
    1627:   PetscFPrintf(comm, fd, "Compiled with double precision matrices (default)\n");
    1628: #endif
    1629:   PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d\n",
    1630:                       (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*));

    1632:   PetscFPrintf(comm, fd, "Configure run at: %s\n",PETSC_CONFIGURE_RUN_TIME);
    1633:   PetscFPrintf(comm, fd, "Configure options: %s",PETSC_CONFIGURE_OPTIONS);
    1634:   PetscFPrintf(comm, fd, "%s", petscmachineinfo);
    1635:   PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
    1636:   PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
    1637:   PetscFPrintf(comm, fd, "%s", petsclinkerinfo);

    1639:   /* Cleanup */
    1640:   PetscFPrintf(comm, fd, "\n");
    1641:   PetscFClose(comm, fd);
    1642:   return(0);
    1643: }

    1645: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
    1648: /*@C
    1649:    PetscGetFlops - Returns the number of flops used on this processor
    1650:    since the program began.

    1652:    Not Collective

    1654:    Output Parameter:
    1655:    flops - number of floating point operations

    1657:    Notes:
    1658:    A global counter logs all PETSc flop counts.  The user can use
    1659:    PetscLogFlops() to increment this counter to include flops for the
    1660:    application code.

    1662:    PETSc automatically logs library events if the code has been
    1663:    compiled with -DPETSC_USE_LOG (which is the default), and -log,
    1664:    -log_summary, or -log_all are specified.  PetscLogFlops() is
    1665:    intended for logging user flops to supplement this PETSc
    1666:    information.

    1668:    Level: intermediate

    1670: .keywords: log, flops, floating point operations

    1672: .seealso: PetscGetTime(), PetscLogFlops()
    1673: @*/
    1674: PetscErrorCode PETSC_DLLEXPORT PetscGetFlops(PetscLogDouble *flops)
    1675: {
    1677:   *flops = _TotalFlops;
    1678:   return(0);
    1679: }

    1683: PetscErrorCode PETSC_DLLEXPORT PetscLogObjectState(PetscObject obj, const char format[], ...)
    1684: {
    1686:   va_list        Argp;

    1689:   if (!logObjects) return(0);
    1690:   va_start(Argp, format);
    1691:   PetscVSNPrintf(objects[obj->id].info, 64,format, Argp);
    1692:   va_end(Argp);
    1693:   return(0);
    1694: }

    1696: #else /* end of -DPETSC_USE_LOG section */

    1700: PetscErrorCode PETSC_DLLEXPORT PetscLogObjectState(PetscObject obj, const char format[], ...)
    1701: {
    1703:   return(0);
    1704: }

    1706: #endif /* PETSC_USE_LOG*/

    1710: /*@
    1711:    PetscGetTime - Returns the current time of day in seconds. This
    1712:    returns wall-clock time.

    1714:    Not Collective

    1716:    Output Parameter:
    1717: .  v - time counter

    1719:    Usage:
    1720: .vb
    1721:       PetscLogDouble v1,v2,elapsed_time;
    1722:       PetscGetTime(&v1);CHKERR(ierr);
    1723:       .... perform some calculation ...
    1724:       PetscGetTime(&v2);CHKERR(ierr);
    1725:       elapsed_time = v2 - v1;
    1726: .ve

    1728:    Notes:
    1729:    Since the PETSc libraries incorporate timing of phases and operations,
    1730:    PetscGetTime() is intended only for timing of application codes.
    1731:    The options database commands -log, -log_summary, and -log_all activate
    1732:    PETSc library timing.  See the users manual for further details.

    1734:    Level: intermediate

    1736: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(),  PetscLogStagePush(),
    1737:           PetscLogStagePop(), PetscLogStageRegister(), PetscGetFlops()

    1739: .keywords:  get, time
    1740: @*/
    1741: PetscErrorCode PETSC_DLLEXPORT PetscGetTime(PetscLogDouble *t)
    1742: {
    1744:   PetscTime(*t);
    1745:   return(0);
    1746: }

    1750: /*@
    1751:   PetscLogGetStageLog - This function returns the default stage logging object.

    1753:   Not collective

    1755:   Output Parameter:
    1756: . stageLog - The default StageLog

    1758:   Level: beginner

    1760: .keywords: log, stage
    1761: .seealso: StageLogCreate()
    1762: @*/
    1763: PetscErrorCode PETSC_DLLEXPORT PetscLogGetStageLog(StageLog *stageLog)
    1764: {
    1767:   *stageLog = _stageLog;
    1768:   return(0);
    1769: }

    1771: /*MC
    1772:    PetscLogFlops - Adds floating point operations to the global counter.

    1774:    Input Parameter:
    1775: .  f - flop counter

    1777:    Synopsis:
    1778:    void PetscLogFlops(int f)

    1780:    Usage:
    1781: .vb
    1782:      int USER_EVENT;
    1783:      PetscLogEventRegister(&USER_EVENT,"User event");
    1784:      PetscLogEventBegin(USER_EVENT,0,0,0,0);
    1785:         [code segment to monitor]
    1786:         PetscLogFlops(user_flops)
    1787:      PetscLogEventEnd(USER_EVENT,0,0,0,0);
    1788: .ve

    1790:    Notes:
    1791:    A global counter logs all PETSc flop counts.  The user can use
    1792:    PetscLogFlops() to increment this counter to include flops for the
    1793:    application code.

    1795:    PETSc automatically logs library events if the code has been
    1796:    compiled with -DPETSC_USE_LOG (which is the default), and -log,
    1797:    -log_summary, or -log_all are specified.  PetscLogFlops() is
    1798:    intended for logging user flops to supplement this PETSc
    1799:    information.

    1801:    Level: intermediate

    1803: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()

    1805: .keywords: log, flops, floating point operations
    1806: M*/

    1808: PetscTruth PetscPreLoadingUsed = PETSC_FALSE;
    1809: PetscTruth PetscPreLoadingOn   = PETSC_FALSE;

    1811: /*MC
    1812:    PreLoadBegin - Begin a segment of code that may be preloaded (run twice)
    1813:     to get accurate timings

    1815:    Input Parameter:
    1816: +   flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
    1817:            with command line option -preload true or -preload false
    1818: -   name - name of first stage (lines of code timed seperately with -log_summary) to
    1819:            be preloaded

    1821:    Synopsis:
    1822:    void PreLoadBegin(PetscTruth flag,char *name);

    1824:    Usage:
    1825: .vb
    1826:      PreLoadBegin(PETSC_TRUE,"first stage);
    1827:        lines of code
    1828:        PreLoadStage("second stage");
    1829:        lines of code
    1830:      PreLoadEnd();
    1831: .ve

    1833:    Notes: Only works in C/C++, not Fortran

    1835:      Flags available within the macro.
    1836: +    PetscPreLoadingUsed - true if we are or have done preloading
    1837: .    PetscPreLoadingOn - true if it is CURRENTLY doing preload
    1838: .    PreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
    1839: -    PreLoadMax - number of times it will do the computation, only one when preloading is turned on
    1840:      The first two variables are available throughout the program, the second two only between the PreLoadBegin()
    1841:      and PreLoadEnd()

    1843:    Level: intermediate

    1845: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PreLoadEnd(), PreLoadStage()

    1847:    Concepts: preloading
    1848:    Concepts: timing^accurate
    1849:    Concepts: paging^eliminating effects of

    1852: M*/

    1854: /*MC
    1855:    PreLoadEnd - End a segment of code that may be preloaded (run twice)
    1856:     to get accurate timings

    1858:    Synopsis:
    1859:    void PreLoadEnd(void);

    1861:    Usage:
    1862: .vb
    1863:      PreLoadBegin(PETSC_TRUE,"first stage);
    1864:        lines of code
    1865:        PreLoadStage("second stage");
    1866:        lines of code
    1867:      PreLoadEnd();
    1868: .ve

    1870:    Notes: only works in C/C++ not fortran

    1872:    Level: intermediate

    1874: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PreLoadBegin(), PreLoadStage()

    1876: M*/

    1878: /*MC
    1879:    PreLoadStage - Start a new segment of code to be timed seperately.
    1880:     to get accurate timings

    1882:    Synopsis:
    1883:    void PreLoadStage(char *name);

    1885:    Usage:
    1886: .vb
    1887:      PreLoadBegin(PETSC_TRUE,"first stage);
    1888:        lines of code
    1889:        PreLoadStage("second stage");
    1890:        lines of code
    1891:      PreLoadEnd();
    1892: .ve

    1894:    Notes: only works in C/C++ not fortran

    1896:    Level: intermediate

    1898: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PreLoadBegin(), PreLoadEnd()

    1900: M*/

    1902: /*----------------------------------------------- Stack Functions ---------------------------------------------------*/
    1905: /*@C
    1906:   StackDestroy - This function destroys a stack.

    1908:   Not Collective

    1910:   Input Parameter:
    1911: . stack - The stack

    1913:   Level: beginner

    1915: .keywords: log, stack, destroy
    1916: .seealso: StackCreate(), StackEmpty(), StackPush(), StackPop(), StackTop()
    1917: @*/
    1918: PetscErrorCode StackDestroy(IntStack stack)
    1919: {

    1923:   PetscFree(stack->stack);
    1924:   PetscFree(stack);
    1925:   return(0);
    1926: }

    1930: /*@C
    1931:   StackEmpty - This function determines whether any items have been pushed.

    1933:   Not Collective

    1935:   Input Parameter:
    1936: . stack - The stack

    1938:   Output Parameter:
    1939: . empty - PETSC_TRUE if the stack is empty

    1941:   Level: intermediate

    1943: .keywords: log, stack, empty
    1944: .seealso: StackCreate(), StackDestroy(), StackPush(), StackPop(), StackTop()
    1945: @*/
    1946: PetscErrorCode StackEmpty(IntStack stack, PetscTruth *empty)
    1947: {
    1950:   if (stack->top == -1) {
    1951:     *empty = PETSC_TRUE;
    1952:   } else {
    1953:     *empty = PETSC_FALSE;
    1954:   }
    1955:   return(0);
    1956: }

    1960: /*@C
    1961:   StackTop - This function returns the top of the stack.

    1963:   Not Collective

    1965:   Input Parameter:
    1966: . stack - The stack

    1968:   Output Parameter:
    1969: . top - The integer on top of the stack

    1971:   Level: intermediate

    1973: .keywords: log, stack, top
    1974: .seealso: StackCreate(), StackDestroy(), StackEmpty(), StackPush(), StackPop()
    1975: @*/
    1976: PetscErrorCode StackTop(IntStack stack, int *top)
    1977: {
    1980:   *top = stack->stack[stack->top];
    1981:   return(0);
    1982: }

    1986: /*@C
    1987:   StackPush - This function pushes an integer on the stack.

    1989:   Not Collective

    1991:   Input Parameters:
    1992: + stack - The stack
    1993: - item  - The integer to push

    1995:   Level: intermediate

    1997: .keywords: log, stack, push
    1998: .seealso: StackCreate(), StackDestroy(), StackEmpty(), StackPop(), StackTop()
    1999: @*/
    2000: PetscErrorCode StackPush(IntStack stack, int item)
    2001: {
    2002:   int            *array;

    2006:   stack->top++;
    2007:   if (stack->top >= stack->max) {
    2008:     PetscMalloc(stack->max*2 * sizeof(int), &array);
    2009:     PetscMemcpy(array, stack->stack, stack->max * sizeof(int));
    2010:     PetscFree(stack->stack);
    2011:     stack->stack = array;
    2012:     stack->max  *= 2;
    2013:   }
    2014:   stack->stack[stack->top] = item;
    2015:   return(0);
    2016: }

    2020: /*@C
    2021:   StackPop - This function pops an integer from the stack.

    2023:   Not Collective

    2025:   Input Parameter:
    2026: . stack - The stack

    2028:   Output Parameter:
    2029: . item  - The integer popped

    2031:   Level: intermediate

    2033: .keywords: log, stack, pop
    2034: .seealso: StackCreate(), StackDestroy(), StackEmpty(), StackPush(), StackTop()
    2035: @*/
    2036: PetscErrorCode StackPop(IntStack stack, int *item)
    2037: {
    2040:   if (stack->top == -1) SETERRQ(PETSC_ERR_ARG_WRONGSTATE, "Stack is empty");
    2041:   *item = stack->stack[stack->top--];
    2042:   return(0);
    2043: }

    2047: /*@C
    2048:   StackCreate - This function creates a stack.

    2050:   Not Collective

    2052:   Output Parameter:
    2053: . stack - The stack

    2055:   Level: beginner

    2057: .keywords: log, stack, pop
    2058: .seealso: StackDestroy(), StackEmpty(), StackPush(), StackPop(), StackTop()
    2059: @*/
    2060: PetscErrorCode StackCreate(IntStack *stack)
    2061: {
    2062:   IntStack       s;

    2067:   PetscNew(struct _IntStack, &s);
    2068:   s->top = -1;
    2069:   s->max = 128;
    2070:   PetscMalloc(s->max * sizeof(int), &s->stack);
    2071:   PetscMemzero(s->stack, s->max * sizeof(int));
    2072:   *stack = s;
    2073:   return(0);
    2074: }