Actual source code: plog.c
petsc-3.6.4 2016-04-12
2: /*
3: PETSc code to log object creation and destruction and PETSc events.
5: This provides the public API used by the rest of PETSc and by users.
7: These routines use a private API that is not used elsewhere in PETSc and is not
8: accessible to users. The private API is defined in logimpl.h and the utils directory.
10: */
11: #include <petsc/private/logimpl.h> /*I "petscsys.h" I*/
12: #include <petsctime.h>
13: #include <petscviewer.h>
15: PetscErrorCode PetscLogObjectParent(PetscObject p,PetscObject c)
16: {
17: if (!c || !p) return 0;
18: c->parent = p;
19: c->parentid = p->id;
20: return 0;
21: }
23: PetscErrorCode PetscLogObjectMemory(PetscObject p,PetscLogDouble m)
24: {
25: if (!p) return 0;
26: p->mem += m;
27: return 0;
28: }
30: PetscLogEvent PETSC_LARGEST_EVENT = PETSC_EVENT;
32: #if defined(PETSC_USE_LOG)
33: #include <petscmachineinfo.h>
34: #include <petscconfiginfo.h>
36: /* used in the MPI_XXX() count macros in petsclog.h */
38: /* Action and object logging variables */
39: Action *petsc_actions = NULL;
40: Object *petsc_objects = NULL;
41: PetscBool petsc_logActions = PETSC_FALSE;
42: PetscBool petsc_logObjects = PETSC_FALSE;
43: int petsc_numActions = 0, petsc_maxActions = 100;
44: int petsc_numObjects = 0, petsc_maxObjects = 100;
45: int petsc_numObjectsDestroyed = 0;
47: /* Global counters */
48: PetscLogDouble petsc_BaseTime = 0.0;
49: PetscLogDouble petsc_TotalFlops = 0.0; /* The number of flops */
50: PetscLogDouble petsc_tmp_flops = 0.0; /* The incremental number of flops */
51: PetscLogDouble petsc_send_ct = 0.0; /* The number of sends */
52: PetscLogDouble petsc_recv_ct = 0.0; /* The number of receives */
53: PetscLogDouble petsc_send_len = 0.0; /* The total length of all sent messages */
54: PetscLogDouble petsc_recv_len = 0.0; /* The total length of all received messages */
55: PetscLogDouble petsc_isend_ct = 0.0; /* The number of immediate sends */
56: PetscLogDouble petsc_irecv_ct = 0.0; /* The number of immediate receives */
57: PetscLogDouble petsc_isend_len = 0.0; /* The total length of all immediate send messages */
58: PetscLogDouble petsc_irecv_len = 0.0; /* The total length of all immediate receive messages */
59: PetscLogDouble petsc_wait_ct = 0.0; /* The number of waits */
60: PetscLogDouble petsc_wait_any_ct = 0.0; /* The number of anywaits */
61: PetscLogDouble petsc_wait_all_ct = 0.0; /* The number of waitalls */
62: PetscLogDouble petsc_sum_of_waits_ct = 0.0; /* The total number of waits */
63: PetscLogDouble petsc_allreduce_ct = 0.0; /* The number of reductions */
64: PetscLogDouble petsc_gather_ct = 0.0; /* The number of gathers and gathervs */
65: PetscLogDouble petsc_scatter_ct = 0.0; /* The number of scatters and scattervs */
67: /* Logging functions */
68: PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL;
69: PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL;
70: PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
71: PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
73: /* Tracing event logging variables */
74: FILE *petsc_tracefile = NULL;
75: int petsc_tracelevel = 0;
76: const char *petsc_traceblanks = " ";
77: char petsc_tracespace[128] = " ";
78: PetscLogDouble petsc_tracetime = 0.0;
79: static PetscBool PetscLogInitializeCalled = PETSC_FALSE;
81: /*---------------------------------------------- General Functions --------------------------------------------------*/
84: /*@C
85: PetscLogDestroy - Destroys the object and event logging data and resets the global counters.
87: Not Collective
89: Notes:
90: This routine should not usually be used by programmers. Instead employ
91: PetscLogStagePush() and PetscLogStagePop().
93: Level: developer
95: .keywords: log, destroy
96: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogStagePush(), PlogStagePop()
97: @*/
98: PetscErrorCode PetscLogDestroy(void)
99: {
100: PetscStageLog stageLog;
104: PetscFree(petsc_actions);
105: PetscFree(petsc_objects);
106: PetscLogSet(NULL, NULL);
108: /* Resetting phase */
109: PetscLogGetStageLog(&stageLog);
110: PetscStageLogDestroy(stageLog);
112: petsc_TotalFlops = 0.0;
113: petsc_numActions = 0;
114: petsc_numObjects = 0;
115: petsc_numObjectsDestroyed = 0;
116: petsc_maxActions = 100;
117: petsc_maxObjects = 100;
118: petsc_actions = NULL;
119: petsc_objects = NULL;
120: petsc_logActions = PETSC_FALSE;
121: petsc_logObjects = PETSC_FALSE;
122: petsc_BaseTime = 0.0;
123: petsc_TotalFlops = 0.0;
124: petsc_tmp_flops = 0.0;
125: petsc_send_ct = 0.0;
126: petsc_recv_ct = 0.0;
127: petsc_send_len = 0.0;
128: petsc_recv_len = 0.0;
129: petsc_isend_ct = 0.0;
130: petsc_irecv_ct = 0.0;
131: petsc_isend_len = 0.0;
132: petsc_irecv_len = 0.0;
133: petsc_wait_ct = 0.0;
134: petsc_wait_any_ct = 0.0;
135: petsc_wait_all_ct = 0.0;
136: petsc_sum_of_waits_ct = 0.0;
137: petsc_allreduce_ct = 0.0;
138: petsc_gather_ct = 0.0;
139: petsc_scatter_ct = 0.0;
140: PETSC_LARGEST_EVENT = PETSC_EVENT;
141: PetscLogPHC = NULL;
142: PetscLogPHD = NULL;
143: petsc_tracefile = NULL;
144: petsc_tracelevel = 0;
145: petsc_traceblanks = " ";
146: petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0;
147: petsc_tracetime = 0.0;
148: PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
149: PETSC_OBJECT_CLASSID = 0;
150: petsc_stageLog = 0;
151: PetscLogInitializeCalled = PETSC_FALSE;
152: return(0);
153: }
157: /*@C
158: PetscLogSet - Sets the logging functions called at the beginning and ending of every event.
160: Not Collective
162: Input Parameters:
163: + b - The function called at beginning of event
164: - e - The function called at end of event
166: Level: developer
168: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogAllBegin(), PetscLogTraceBegin()
169: @*/
170: PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject),
171: PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject))
172: {
174: PetscLogPLB = b;
175: PetscLogPLE = e;
176: return(0);
177: }
179: #if defined(PETSC_HAVE_PAPI)
180: #include <papi.h>
181: int PAPIEventSet = PAPI_NULL;
182: #endif
184: /*------------------------------------------- Initialization Functions ----------------------------------------------*/
187: /*
188: The data structures for logging are always created even if no logging is turned on. This is so events etc can
189: be registered in the code before the actually logging is turned on.
190: */
191: PetscErrorCode PetscLogInitialize(void)
192: {
193: int stage;
194: PetscBool opt;
198: if (PetscLogInitializeCalled) return(0);
199: PetscLogInitializeCalled = PETSC_TRUE;
201: PetscOptionsHasName(NULL, "-log_exclude_actions", &opt);
202: if (opt) petsc_logActions = PETSC_FALSE;
203: PetscOptionsHasName(NULL, "-log_exclude_objects", &opt);
204: if (opt) petsc_logObjects = PETSC_FALSE;
205: if (petsc_logActions) {
206: PetscMalloc1(petsc_maxActions, &petsc_actions);
207: }
208: if (petsc_logObjects) {
209: PetscMalloc1(petsc_maxObjects, &petsc_objects);
210: }
211: PetscLogPHC = PetscLogObjCreateDefault;
212: PetscLogPHD = PetscLogObjDestroyDefault;
213: /* Setup default logging structures */
214: PetscStageLogCreate(&petsc_stageLog);
215: PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);
216: #if defined(PETSC_HAVE_PAPI)
217: PAPI_library_init(PAPI_VER_CURRENT);
218: if (ierr != PAPI_VER_CURRENT) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_LIB,"Cannot initialize PAPI");
219: PAPI_query_event(PAPI_FP_INS);
220: PAPI_create_eventset(&PAPIEventSet);
221: PAPI_add_event(PAPIEventSet,PAPI_FP_INS);
222: PAPI_start(PAPIEventSet);
223: #endif
225: /* All processors sync here for more consistent logging */
226: MPI_Barrier(PETSC_COMM_WORLD);
227: PetscTime(&petsc_BaseTime);
228: PetscLogStagePush(stage);
229: return(0);
230: }
234: /*@C
235: PetscLogBegin - Turns on logging of objects and events. This logs flop
236: rates and object creation and should not slow programs down too much.
237: This routine may be called more than once.
239: Logically Collective over PETSC_COMM_WORLD
241: Options Database Keys:
242: + -log_summary - Prints summary of flop and timing information to the
243: screen (for code compiled with PETSC_USE_LOG)
244: - -log - Prints detailed log information (for code compiled with PETSC_USE_LOG)
246: Usage:
247: .vb
248: PetscInitialize(...);
249: PetscLogBegin();
250: ... code ...
251: PetscLogView(viewer); or PetscLogDump();
252: PetscFinalize();
253: .ve
255: Notes:
256: PetscLogView(viewer) or PetscLogDump() actually cause the printing of
257: the logging information.
259: Level: advanced
261: .keywords: log, begin
262: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin()
263: @*/
264: PetscErrorCode PetscLogBegin(void)
265: {
269: PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
270: return(0);
271: }
275: /*@C
276: PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
277: all events. This creates large log files and slows the program down.
279: Logically Collective on PETSC_COMM_WORLD
281: Options Database Keys:
282: . -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)
284: Usage:
285: .vb
286: PetscInitialize(...);
287: PetscLogAllBegin();
288: ... code ...
289: PetscLogDump(filename);
290: PetscFinalize();
291: .ve
293: Notes:
294: A related routine is PetscLogBegin() (with the options key -log), which is
295: intended for production runs since it logs only flop rates and object
296: creation (and shouldn't significantly slow the programs).
298: Level: advanced
300: .keywords: log, all, begin
301: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogTraceBegin()
302: @*/
303: PetscErrorCode PetscLogAllBegin(void)
304: {
308: PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
309: return(0);
310: }
314: /*@
315: PetscLogTraceBegin - Activates trace logging. Every time a PETSc event
316: begins or ends, the event name is printed.
318: Logically Collective on PETSC_COMM_WORLD
320: Input Parameter:
321: . file - The file to print trace in (e.g. stdout)
323: Options Database Key:
324: . -log_trace [filename] - Activates PetscLogTraceBegin()
326: Notes:
327: PetscLogTraceBegin() prints the processor number, the execution time (sec),
328: then "Event begin:" or "Event end:" followed by the event name.
330: PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
331: to determine where a program is hanging without running in the
332: debugger. Can be used in conjunction with the -info option.
334: Level: intermediate
336: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogBegin()
337: @*/
338: PetscErrorCode PetscLogTraceBegin(FILE *file)
339: {
343: petsc_tracefile = file;
345: PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
346: return(0);
347: }
351: /*@
352: PetscLogActions - Determines whether actions are logged for the graphical viewer.
354: Not Collective
356: Input Parameter:
357: . flag - PETSC_TRUE if actions are to be logged
359: Level: intermediate
361: Note: Logging of actions continues to consume more memory as the program
362: runs. Long running programs should consider turning this feature off.
364: Options Database Keys:
365: . -log_exclude_actions - Turns off actions logging
367: .keywords: log, stage, register
368: .seealso: PetscLogStagePush(), PetscLogStagePop()
369: @*/
370: PetscErrorCode PetscLogActions(PetscBool flag)
371: {
373: petsc_logActions = flag;
374: return(0);
375: }
379: /*@
380: PetscLogObjects - Determines whether objects are logged for the graphical viewer.
382: Not Collective
384: Input Parameter:
385: . flag - PETSC_TRUE if objects are to be logged
387: Level: intermediate
389: Note: Logging of objects continues to consume more memory as the program
390: runs. Long running programs should consider turning this feature off.
392: Options Database Keys:
393: . -log_exclude_objects - Turns off objects logging
395: .keywords: log, stage, register
396: .seealso: PetscLogStagePush(), PetscLogStagePop()
397: @*/
398: PetscErrorCode PetscLogObjects(PetscBool flag)
399: {
401: petsc_logObjects = flag;
402: return(0);
403: }
405: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
408: /*@C
409: PetscLogStageRegister - Attaches a charactor string name to a logging stage.
411: Not Collective
413: Input Parameter:
414: . sname - The name to associate with that stage
416: Output Parameter:
417: . stage - The stage number
419: Level: intermediate
421: .keywords: log, stage, register
422: .seealso: PetscLogStagePush(), PetscLogStagePop()
423: @*/
424: PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage)
425: {
426: PetscStageLog stageLog;
427: PetscLogEvent event;
431: PetscLogGetStageLog(&stageLog);
432: PetscStageLogRegister(stageLog, sname, stage);
433: /* Copy events already changed in the main stage, this sucks */
434: EventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
435: for (event = 0; event < stageLog->eventLog->numEvents; event++) {
436: EventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
437: }
438: ClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
439: return(0);
440: }
444: /*@C
445: PetscLogStagePush - This function pushes a stage on the stack.
447: Not Collective
449: Input Parameter:
450: . stage - The stage on which to log
452: Usage:
453: If the option -log_sumary is used to run the program containing the
454: following code, then 2 sets of summary data will be printed during
455: PetscFinalize().
456: .vb
457: PetscInitialize(int *argc,char ***args,0,0);
458: [stage 0 of code]
459: PetscLogStagePush(1);
460: [stage 1 of code]
461: PetscLogStagePop();
462: PetscBarrier(...);
463: [more stage 0 of code]
464: PetscFinalize();
465: .ve
467: Notes:
468: Use PetscLogStageRegister() to register a stage.
470: Level: intermediate
472: .keywords: log, push, stage
473: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
474: @*/
475: PetscErrorCode PetscLogStagePush(PetscLogStage stage)
476: {
477: PetscStageLog stageLog;
481: PetscLogGetStageLog(&stageLog);
482: PetscStageLogPush(stageLog, stage);
483: return(0);
484: }
488: /*@C
489: PetscLogStagePop - This function pops a stage from the stack.
491: Not Collective
493: Usage:
494: If the option -log_sumary is used to run the program containing the
495: following code, then 2 sets of summary data will be printed during
496: PetscFinalize().
497: .vb
498: PetscInitialize(int *argc,char ***args,0,0);
499: [stage 0 of code]
500: PetscLogStagePush(1);
501: [stage 1 of code]
502: PetscLogStagePop();
503: PetscBarrier(...);
504: [more stage 0 of code]
505: PetscFinalize();
506: .ve
508: Notes:
509: Use PetscLogStageRegister() to register a stage.
511: Level: intermediate
513: .keywords: log, pop, stage
514: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
515: @*/
516: PetscErrorCode PetscLogStagePop(void)
517: {
518: PetscStageLog stageLog;
522: PetscLogGetStageLog(&stageLog);
523: PetscStageLogPop(stageLog);
524: return(0);
525: }
529: /*@
530: PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().
532: Not Collective
534: Input Parameters:
535: + stage - The stage
536: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
538: Level: intermediate
540: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
541: @*/
542: PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive)
543: {
544: PetscStageLog stageLog;
548: PetscLogGetStageLog(&stageLog);
549: PetscStageLogSetActive(stageLog, stage, isActive);
550: return(0);
551: }
555: /*@
556: PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().
558: Not Collective
560: Input Parameter:
561: . stage - The stage
563: Output Parameter:
564: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
566: Level: intermediate
568: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
569: @*/
570: PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive)
571: {
572: PetscStageLog stageLog;
576: PetscLogGetStageLog(&stageLog);
577: PetscStageLogGetActive(stageLog, stage, isActive);
578: return(0);
579: }
583: /*@
584: PetscLogStageSetVisible - Determines stage visibility in PetscLogView()
586: Not Collective
588: Input Parameters:
589: + stage - The stage
590: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
592: Level: intermediate
594: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
595: @*/
596: PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible)
597: {
598: PetscStageLog stageLog;
602: PetscLogGetStageLog(&stageLog);
603: PetscStageLogSetVisible(stageLog, stage, isVisible);
604: return(0);
605: }
609: /*@
610: PetscLogStageGetVisible - Returns stage visibility in PetscLogView()
612: Not Collective
614: Input Parameter:
615: . stage - The stage
617: Output Parameter:
618: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
620: Level: intermediate
622: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
623: @*/
624: PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible)
625: {
626: PetscStageLog stageLog;
630: PetscLogGetStageLog(&stageLog);
631: PetscStageLogGetVisible(stageLog, stage, isVisible);
632: return(0);
633: }
637: /*@C
638: PetscLogStageGetId - Returns the stage id when given the stage name.
640: Not Collective
642: Input Parameter:
643: . name - The stage name
645: Output Parameter:
646: . stage - The stage, , or -1 if no stage with that name exists
648: Level: intermediate
650: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
651: @*/
652: PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage)
653: {
654: PetscStageLog stageLog;
658: PetscLogGetStageLog(&stageLog);
659: PetscStageLogGetStage(stageLog, name, stage);
660: return(0);
661: }
663: /*------------------------------------------------ Event Functions --------------------------------------------------*/
666: /*@C
667: PetscLogEventRegister - Registers an event name for logging operations in an application code.
669: Not Collective
671: Input Parameter:
672: + name - The name associated with the event
673: - classid - The classid associated to the class for this event, obtain either with
674: PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones
675: are only available in C code
677: Output Parameter:
678: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().
680: Example of Usage:
681: .vb
682: PetscLogEvent USER_EVENT;
683: PetscClassId classid;
684: PetscLogDouble user_event_flops;
685: PetscClassIdRegister("class name",&classid);
686: PetscLogEventRegister("User event name",classid,&USER_EVENT);
687: PetscLogEventBegin(USER_EVENT,0,0,0,0);
688: [code segment to monitor]
689: PetscLogFlops(user_event_flops);
690: PetscLogEventEnd(USER_EVENT,0,0,0,0);
691: .ve
693: Notes:
694: PETSc automatically logs library events if the code has been
695: compiled with -DPETSC_USE_LOG (which is the default) and -log,
696: -log_summary, or -log_all are specified. PetscLogEventRegister() is
697: intended for logging user events to supplement this PETSc
698: information.
700: PETSc can gather data for use with the utilities Jumpshot
701: (part of the MPICH distribution). If PETSc has been compiled
702: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
703: MPICH), the user can employ another command line option, -log_mpe,
704: to create a logfile, "mpe.log", which can be visualized
705: Jumpshot.
707: The classid is associated with each event so that classes of events
708: can be disabled simultaneously, such as all matrix events. The user
709: can either use an existing classid, such as MAT_CLASSID, or create
710: their own as shown in the example.
712: If an existing event with the same name exists, its event handle is
713: returned instead of creating a new event.
715: Level: intermediate
717: .keywords: log, event, register
718: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
719: PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
720: PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister()
721: @*/
722: PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event)
723: {
724: PetscStageLog stageLog;
725: int stage;
729: *event = PETSC_DECIDE;
730: PetscLogGetStageLog(&stageLog);
731: EventRegLogGetEvent(stageLog->eventLog, name, event);
732: if (*event > 0) return(0);
733: EventRegLogRegister(stageLog->eventLog, name, classid, event);
734: for (stage = 0; stage < stageLog->numStages; stage++) {
735: EventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
736: ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
737: }
738: return(0);
739: }
743: /*@
744: PetscLogEventActivate - Indicates that a particular event should be logged.
746: Not Collective
748: Input Parameter:
749: . event - The event id
751: Usage:
752: .vb
753: PetscLogEventDeactivate(VEC_SetValues);
754: [code where you do not want to log VecSetValues()]
755: PetscLogEventActivate(VEC_SetValues);
756: [code where you do want to log VecSetValues()]
757: .ve
759: Note:
760: The event may be either a pre-defined PETSc event (found in include/petsclog.h)
761: or an event number obtained with PetscLogEventRegister().
763: Level: advanced
765: .keywords: log, event, activate
766: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventDeactivate()
767: @*/
768: PetscErrorCode PetscLogEventActivate(PetscLogEvent event)
769: {
770: PetscStageLog stageLog;
771: int stage;
775: PetscLogGetStageLog(&stageLog);
776: PetscStageLogGetCurrent(stageLog, &stage);
777: EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
778: return(0);
779: }
783: /*@
784: PetscLogEventDeactivate - Indicates that a particular event should not be logged.
786: Not Collective
788: Input Parameter:
789: . event - The event id
791: Usage:
792: .vb
793: PetscLogEventDeactivate(VEC_SetValues);
794: [code where you do not want to log VecSetValues()]
795: PetscLogEventActivate(VEC_SetValues);
796: [code where you do want to log VecSetValues()]
797: .ve
799: Note:
800: The event may be either a pre-defined PETSc event (found in
801: include/petsclog.h) or an event number obtained with PetscLogEventRegister()).
803: Level: advanced
805: .keywords: log, event, deactivate
806: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate()
807: @*/
808: PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event)
809: {
810: PetscStageLog stageLog;
811: int stage;
815: PetscLogGetStageLog(&stageLog);
816: PetscStageLogGetCurrent(stageLog, &stage);
817: EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
818: return(0);
819: }
823: /*@
824: PetscLogEventSetActiveAll - Sets the event activity in every stage.
826: Not Collective
828: Input Parameters:
829: + event - The event id
830: - isActive - The activity flag determining whether the event is logged
832: Level: advanced
834: .keywords: log, event, activate
835: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate(),PlogEventDeactivate()
836: @*/
837: PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive)
838: {
839: PetscStageLog stageLog;
840: int stage;
844: PetscLogGetStageLog(&stageLog);
845: for (stage = 0; stage < stageLog->numStages; stage++) {
846: if (isActive) {
847: EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
848: } else {
849: EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
850: }
851: }
852: return(0);
853: }
857: /*@
858: PetscLogEventActivateClass - Activates event logging for a PETSc object class.
860: Not Collective
862: Input Parameter:
863: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
865: Level: developer
867: .keywords: log, event, activate, class
868: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
869: @*/
870: PetscErrorCode PetscLogEventActivateClass(PetscClassId classid)
871: {
872: PetscStageLog stageLog;
873: int stage;
877: PetscLogGetStageLog(&stageLog);
878: PetscStageLogGetCurrent(stageLog, &stage);
879: EventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
880: return(0);
881: }
885: /*@
886: PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.
888: Not Collective
890: Input Parameter:
891: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
893: Level: developer
895: .keywords: log, event, deactivate, class
896: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
897: @*/
898: PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid)
899: {
900: PetscStageLog stageLog;
901: int stage;
905: PetscLogGetStageLog(&stageLog);
906: PetscStageLogGetCurrent(stageLog, &stage);
907: EventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
908: return(0);
909: }
911: /*MC
912: PetscLogEventBegin - Logs the beginning of a user event.
914: Synopsis:
915: #include <petsclog.h>
916: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
918: Not Collective
920: Input Parameters:
921: + e - integer associated with the event obtained from PetscLogEventRegister()
922: - o1,o2,o3,o4 - objects associated with the event, or 0
925: Fortran Synopsis:
926: void PetscLogEventBegin(int e,PetscErrorCode ierr)
928: Usage:
929: .vb
930: PetscLogEvent USER_EVENT;
931: PetscLogDouble user_event_flops;
932: PetscLogEventRegister("User event",0,&USER_EVENT);
933: PetscLogEventBegin(USER_EVENT,0,0,0,0);
934: [code segment to monitor]
935: PetscLogFlops(user_event_flops);
936: PetscLogEventEnd(USER_EVENT,0,0,0,0);
937: .ve
939: Notes:
940: You need to register each integer event with the command
941: PetscLogEventRegister(). The source code must be compiled with
942: -DPETSC_USE_LOG, which is the default.
944: PETSc automatically logs library events if the code has been
945: compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
946: specified. PetscLogEventBegin() is intended for logging user events
947: to supplement this PETSc information.
949: Level: intermediate
951: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
953: .keywords: log, event, begin
954: M*/
956: /*MC
957: PetscLogEventEnd - Log the end of a user event.
959: Synopsis:
960: #include <petsclog.h>
961: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
963: Not Collective
965: Input Parameters:
966: + e - integer associated with the event obtained with PetscLogEventRegister()
967: - o1,o2,o3,o4 - objects associated with the event, or 0
970: Fortran Synopsis:
971: void PetscLogEventEnd(int e,PetscErrorCode ierr)
973: Usage:
974: .vb
975: PetscLogEvent USER_EVENT;
976: PetscLogDouble user_event_flops;
977: PetscLogEventRegister("User event",0,&USER_EVENT,);
978: PetscLogEventBegin(USER_EVENT,0,0,0,0);
979: [code segment to monitor]
980: PetscLogFlops(user_event_flops);
981: PetscLogEventEnd(USER_EVENT,0,0,0,0);
982: .ve
984: Notes:
985: You should also register each additional integer event with the command
986: PetscLogEventRegister(). Source code must be compiled with
987: -DPETSC_USE_LOG, which is the default.
989: PETSc automatically logs library events if the code has been
990: compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
991: specified. PetscLogEventEnd() is intended for logging user events
992: to supplement this PETSc information.
994: Level: intermediate
996: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
998: .keywords: log, event, end
999: M*/
1001: /*MC
1002: PetscLogEventBarrierBegin - Logs the time in a barrier before an event.
1004: Synopsis:
1005: #include <petsclog.h>
1006: PetscErrorCode PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
1008: Not Collective
1010: Input Parameters:
1011: . e - integer associated with the event obtained from PetscLogEventRegister()
1012: . o1,o2,o3,o4 - objects associated with the event, or 0
1013: . comm - communicator the barrier takes place over
1016: Usage:
1017: .vb
1018: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1019: MPI_Allreduce()
1020: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1021: .ve
1023: Notes:
1024: This is for logging the amount of time spent in a barrier for an event
1025: that requires synchronization.
1027: Additional Notes:
1028: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1029: VEC_NormComm = VEC_NormBarrier + 1
1031: Level: advanced
1033: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1034: PetscLogEventBarrierEnd()
1036: .keywords: log, event, begin, barrier
1037: M*/
1039: /*MC
1040: PetscLogEventBarrierEnd - Logs the time in a barrier before an event.
1042: Synopsis:
1043: #include <petsclog.h>
1044: PetscErrorCode PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
1046: Logically Collective on MPI_Comm
1048: Input Parameters:
1049: . e - integer associated with the event obtained from PetscLogEventRegister()
1050: . o1,o2,o3,o4 - objects associated with the event, or 0
1051: . comm - communicator the barrier takes place over
1054: Usage:
1055: .vb
1056: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1057: MPI_Allreduce()
1058: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1059: .ve
1061: Notes:
1062: This is for logging the amount of time spent in a barrier for an event
1063: that requires synchronization.
1065: Additional Notes:
1066: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1067: VEC_NormComm = VEC_NormBarrier + 1
1069: Level: advanced
1071: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1072: PetscLogEventBarrierBegin()
1074: .keywords: log, event, begin, barrier
1075: M*/
1079: /*@C
1080: PetscLogEventGetId - Returns the event id when given the event name.
1082: Not Collective
1084: Input Parameter:
1085: . name - The event name
1087: Output Parameter:
1088: . event - The event, or -1 if no event with that name exists
1090: Level: intermediate
1092: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1093: @*/
1094: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1095: {
1096: PetscStageLog stageLog;
1100: PetscLogGetStageLog(&stageLog);
1101: EventRegLogGetEvent(stageLog->eventLog, name, event);
1102: return(0);
1103: }
1106: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1109: /*@C
1110: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1111: be read by bin/petscview. This program no longer exists.
1113: Collective on PETSC_COMM_WORLD
1115: Input Parameter:
1116: . name - an optional file name
1118: Options Database Keys:
1119: + -log - Prints basic log information (for code compiled with PETSC_USE_LOG)
1120: - -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)
1122: Usage:
1123: .vb
1124: PetscInitialize(...);
1125: PetscLogBegin(); or PetscLogAllBegin();
1126: ... code ...
1127: PetscLogDump(filename);
1128: PetscFinalize();
1129: .ve
1131: Notes:
1132: The default file name is
1133: $ Log.<rank>
1134: where <rank> is the processor number. If no name is specified,
1135: this file will be used.
1137: Level: advanced
1139: .keywords: log, dump
1140: .seealso: PetscLogBegin(), PetscLogAllBegin(), PetscLogView()
1141: @*/
1142: PetscErrorCode PetscLogDump(const char sname[])
1143: {
1144: PetscStageLog stageLog;
1145: PetscEventPerfInfo *eventInfo;
1146: FILE *fd;
1147: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1148: PetscLogDouble flops, _TotalTime;
1149: PetscMPIInt rank;
1150: int action, object, curStage;
1151: PetscLogEvent event;
1152: PetscErrorCode ierr;
1155: /* Calculate the total elapsed time */
1156: PetscTime(&_TotalTime);
1157: _TotalTime -= petsc_BaseTime;
1158: /* Open log file */
1159: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1160: if (sname) sprintf(file, "%s.%d", sname, rank);
1161: else sprintf(file, "Log.%d", rank);
1162: PetscFixFilename(file, fname);
1163: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1164: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1165: /* Output totals */
1166: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flops %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1167: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1168: /* Output actions */
1169: if (petsc_logActions) {
1170: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1171: for (action = 0; action < petsc_numActions; action++) {
1172: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1173: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1174: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1175: }
1176: }
1177: /* Output objects */
1178: if (petsc_logObjects) {
1179: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1180: for (object = 0; object < petsc_numObjects; object++) {
1181: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1182: if (!petsc_objects[object].name[0]) {
1183: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1184: } else {
1185: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1186: }
1187: if (petsc_objects[object].info[0] != 0) {
1188: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1189: } else {
1190: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1191: }
1192: }
1193: }
1194: /* Output events */
1195: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1196: PetscLogGetStageLog(&stageLog);
1197: PetscIntStackTop(stageLog->stack, &curStage);
1198: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1199: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1200: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1201: else flops = 0.0;
1202: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1203: eventInfo[event].flops, eventInfo[event].time, flops);
1204: }
1205: PetscFClose(PETSC_COMM_WORLD, fd);
1206: return(0);
1207: }
1211: /*
1212: PetscLogView_Detailed - Each process prints the times for its own events
1214: */
1215: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1216: {
1217: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1218: PetscEventPerfInfo *eventInfo = NULL;
1219: PetscLogDouble locTotalTime, numRed, maxMem;
1220: PetscStageLog stageLog;
1221: int numStages,numEvents,stage,event;
1222: PetscMPIInt rank,size;
1223: PetscErrorCode ierr;
1226: MPI_Comm_size(comm, &size);
1227: MPI_Comm_rank(comm, &rank);
1228: /* Must preserve reduction count before we go on */
1229: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1230: /* Get the total elapsed time */
1231: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1232: PetscViewerASCIIPrintf(viewer,"numProcs = %d\n",size);
1233: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1234: PetscViewerASCIIPrintf(viewer,"LocalFlops = {}\n");
1235: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1236: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1237: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1238: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1239: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1240: PetscLogGetStageLog(&stageLog);
1241: MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1242: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1243: for (stage=0; stage<numStages; stage++) {
1244: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1245: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1246: MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1247: for (event = 0; event < numEvents; event++) {
1248: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1249: }
1250: }
1251: PetscViewerASCIISynchronizedAllow(viewer,PETSC_TRUE);
1252: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1253: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlops[%d] = %g\n",rank,petsc_TotalFlops);
1254: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1255: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1256: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1257: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %g\n",rank,petsc_numObjects);
1258: PetscMallocGetMaximumUsage(&maxMem);
1259: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1260: PetscViewerFlush(viewer);
1261: for (stage=0; stage<numStages; stage++) {
1262: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flops\" : %g}\n",
1263: stageLog->stageInfo[stage].name,rank,
1264: stageLog->stageInfo[stage].perfInfo.time,stageLog->stageInfo[stage].perfInfo.numMessages,stageLog->stageInfo[stage].perfInfo.messageLength,
1265: stageLog->stageInfo[stage].perfInfo.numReductions,stageLog->stageInfo[stage].perfInfo.flops);
1266: MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1267: for (event = 0; event < numEvents; event++) {
1268: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1269: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flops\" : %g}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank,
1270: eventInfo[event].count, eventInfo[event].time,eventInfo[event].numMessages, eventInfo[event].messageLength,
1271: eventInfo[event].numReductions,eventInfo[event].flops);
1272: }
1273: }
1274: PetscViewerFlush(viewer);
1275: PetscViewerASCIISynchronizedAllow(viewer,PETSC_FALSE);
1276: return(0);
1277: }
1281: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1282: {
1283: FILE *fd;
1284: PetscLogDouble zero = 0.0;
1285: PetscStageLog stageLog;
1286: PetscStageInfo *stageInfo = NULL;
1287: PetscEventPerfInfo *eventInfo = NULL;
1288: PetscClassPerfInfo *classInfo;
1289: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1290: const char *name;
1291: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1292: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1293: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1294: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1295: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1296: PetscLogDouble min, max, tot, ratio, avg, x, y;
1297: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr;
1298: PetscMPIInt minCt, maxCt;
1299: PetscMPIInt size, rank;
1300: PetscBool *localStageUsed, *stageUsed;
1301: PetscBool *localStageVisible, *stageVisible;
1302: int numStages, localNumEvents, numEvents;
1303: int stage, oclass;
1304: PetscLogEvent event;
1305: PetscErrorCode ierr;
1306: char version[256];
1307: MPI_Comm comm;
1310: PetscObjectGetComm((PetscObject)viewer,&comm);
1311: PetscViewerASCIIGetPointer(viewer,&fd);
1312: MPI_Comm_size(comm, &size);
1313: MPI_Comm_rank(comm, &rank);
1314: /* Get the total elapsed time */
1315: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1317: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1318: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1319: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1320: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1321: PetscGetArchType(arch,sizeof(arch));
1322: PetscGetHostName(hostname,sizeof(hostname));
1323: PetscGetUserName(username,sizeof(username));
1324: PetscGetProgramName(pname,sizeof(pname));
1325: PetscGetDate(date,sizeof(date));
1326: PetscGetVersion(version,sizeof(version));
1327: if (size == 1) {
1328: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1329: } else {
1330: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1331: }
1333: PetscFPrintf(comm, fd, "Using %s\n", version);
1335: /* Must preserve reduction count before we go on */
1336: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1338: /* Calculate summary information */
1339: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1340: /* Time */
1341: MPI_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1342: MPI_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1343: MPI_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1344: avg = (tot)/((PetscLogDouble) size);
1345: if (min != 0.0) ratio = max/min;
1346: else ratio = 0.0;
1347: PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);
1348: TotalTime = tot;
1349: /* Objects */
1350: avg = (PetscLogDouble) petsc_numObjects;
1351: MPI_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1352: MPI_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1353: MPI_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1354: avg = (tot)/((PetscLogDouble) size);
1355: if (min != 0.0) ratio = max/min;
1356: else ratio = 0.0;
1357: PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);
1358: /* Flops */
1359: MPI_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1360: MPI_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1361: MPI_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1362: avg = (tot)/((PetscLogDouble) size);
1363: if (min != 0.0) ratio = max/min;
1364: else ratio = 0.0;
1365: PetscFPrintf(comm, fd, "Flops: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1366: TotalFlops = tot;
1367: /* Flops/sec -- Must talk to Barry here */
1368: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime;
1369: else flops = 0.0;
1370: MPI_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1371: MPI_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1372: MPI_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1373: avg = (tot)/((PetscLogDouble) size);
1374: if (min != 0.0) ratio = max/min;
1375: else ratio = 0.0;
1376: PetscFPrintf(comm, fd, "Flops/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1377: /* Memory */
1378: PetscMallocGetMaximumUsage(&mem);
1379: if (mem > 0.0) {
1380: MPI_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1381: MPI_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1382: MPI_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1383: avg = (tot)/((PetscLogDouble) size);
1384: if (min != 0.0) ratio = max/min;
1385: else ratio = 0.0;
1386: PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);
1387: }
1388: /* Messages */
1389: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1390: MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1391: MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1392: MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1393: avg = (tot)/((PetscLogDouble) size);
1394: if (min != 0.0) ratio = max/min;
1395: else ratio = 0.0;
1396: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1397: numMessages = tot;
1398: /* Message Lengths */
1399: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1400: MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1401: MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1402: MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1403: if (numMessages != 0) avg = (tot)/(numMessages);
1404: else avg = 0.0;
1405: if (min != 0.0) ratio = max/min;
1406: else ratio = 0.0;
1407: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1408: messageLength = tot;
1409: /* Reductions */
1410: MPI_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1411: MPI_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1412: MPI_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1413: if (min != 0.0) ratio = max/min;
1414: else ratio = 0.0;
1415: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);
1416: numReductions = red; /* wrong because uses count from process zero */
1417: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1418: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flops\n");
1419: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flops\n");
1421: /* Get total number of stages --
1422: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1423: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1424: This seems best accomplished by assoicating a communicator with each stage.
1425: */
1426: PetscLogGetStageLog(&stageLog);
1427: MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1428: PetscMalloc1(numStages, &localStageUsed);
1429: PetscMalloc1(numStages, &stageUsed);
1430: PetscMalloc1(numStages, &localStageVisible);
1431: PetscMalloc1(numStages, &stageVisible);
1432: if (numStages > 0) {
1433: stageInfo = stageLog->stageInfo;
1434: for (stage = 0; stage < numStages; stage++) {
1435: if (stage < stageLog->numStages) {
1436: localStageUsed[stage] = stageInfo[stage].used;
1437: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1438: } else {
1439: localStageUsed[stage] = PETSC_FALSE;
1440: localStageVisible[stage] = PETSC_TRUE;
1441: }
1442: }
1443: MPI_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1444: MPI_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1445: for (stage = 0; stage < numStages; stage++) {
1446: if (stageUsed[stage]) {
1447: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flops ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");
1448: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");
1449: break;
1450: }
1451: }
1452: for (stage = 0; stage < numStages; stage++) {
1453: if (!stageUsed[stage]) continue;
1454: if (localStageUsed[stage]) {
1455: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1456: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1457: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1458: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1459: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1460: name = stageInfo[stage].name;
1461: } else {
1462: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1463: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1464: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1465: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1466: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1467: name = "";
1468: }
1469: mess *= 0.5; messLen *= 0.5; red /= size;
1470: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1471: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1472: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1473: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1474: if (numMessages != 0.0) avgMessLen = messLen/numMessages; else avgMessLen = 0.0;
1475: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1476: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1477: 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",
1478: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1479: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1480: }
1481: }
1483: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1484: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1485: PetscFPrintf(comm, fd, "Phase summary info:\n");
1486: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1487: PetscFPrintf(comm, fd, " Time and Flops: Max - maximum over all processors\n");
1488: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1489: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1490: PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");
1491: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1492: PetscFPrintf(comm, fd, " Global: entire computation\n");
1493: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1494: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flops in this phase\n");
1495: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1496: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1497: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flops over all processors)/(max time over all processors)\n");
1498: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1500: #if defined(PETSC_USE_DEBUG)
1501: PetscFPrintf(comm, fd, "\n\n");
1502: PetscFPrintf(comm, fd, " ##########################################################\n");
1503: PetscFPrintf(comm, fd, " # #\n");
1504: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1505: PetscFPrintf(comm, fd, " # #\n");
1506: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");
1507: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1508: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1509: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1510: PetscFPrintf(comm, fd, " # #\n");
1511: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1512: #endif
1513: #if defined(PETSC_USE_COMPLEX) && !defined(PETSC_USE_FORTRAN_KERNELS)
1514: PetscFPrintf(comm, fd, "\n\n");
1515: PetscFPrintf(comm, fd, " ##########################################################\n");
1516: PetscFPrintf(comm, fd, " # #\n");
1517: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1518: PetscFPrintf(comm, fd, " # #\n");
1519: PetscFPrintf(comm, fd, " # The code for various complex numbers numerical #\n");
1520: PetscFPrintf(comm, fd, " # kernels uses C++, which generally is not well #\n");
1521: PetscFPrintf(comm, fd, " # optimized. For performance that is about 4-5 times #\n");
1522: PetscFPrintf(comm, fd, " # faster, specify --with-fortran-kernels=1 #\n");
1523: PetscFPrintf(comm, fd, " # when running ./configure.py. #\n");
1524: PetscFPrintf(comm, fd, " # #\n");
1525: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1526: #endif
1528: /* Report events */
1529: PetscFPrintf(comm, fd,"Event Count Time (sec) Flops --- Global --- --- Stage --- Total\n");
1530: PetscFPrintf(comm, fd," Max Ratio Max Ratio Max Ratio Mess Avg len Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s\n");
1531: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1533: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1534: for (stage = 0; stage < numStages; stage++) {
1535: if (!stageVisible[stage]) continue;
1536: if (localStageUsed[stage]) {
1537: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1538: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1539: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1540: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1541: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1542: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1543: } else {
1544: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1545: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1546: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1547: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1548: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1549: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1550: }
1551: mess *= 0.5; messLen *= 0.5; red /= size;
1553: /* Get total number of events in this stage --
1554: Currently, a single processor can register more events than another, but events must all be registered in order,
1555: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1556: on the event ID. This seems best accomplished by assoicating a communicator with each stage.
1558: Problem: If the event did not happen on proc 1, its name will not be available.
1559: Problem: Event visibility is not implemented
1560: */
1561: if (localStageUsed[stage]) {
1562: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1563: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1564: } else localNumEvents = 0;
1565: MPI_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1566: for (event = 0; event < numEvents; event++) {
1567: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1568: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops;
1569: else flopr = 0.0;
1571: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1572: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1573: MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1574: MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1575: MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1576: MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1577: MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1578: MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1579: MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1580: MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);
1581: MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1582: name = stageLog->eventLog->eventInfo[event].name;
1583: } else {
1584: flopr = 0.0;
1585: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1586: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1587: MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1588: MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1589: MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1590: MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1591: MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1592: MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1593: MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1594: MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);
1595: MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1596: name = "";
1597: }
1598: if (mint < 0.0) {
1599: PetscFPrintf(comm, fd, "WARNING!!! Minimum time %g over all processors for %s is negative! This happens\n on some machines whose times cannot handle too rapid calls.!\n artificially changing minimum to zero.\n",mint,name);
1600: mint = 0;
1601: }
1602: if (minf < 0.0) SETERRQ2(PETSC_COMM_SELF,PETSC_ERR_PLIB,"Minimum flops %g over all processors for %s is negative! Not possible!",minf,name);
1603: totm *= 0.5; totml *= 0.5; totr /= size;
1605: if (maxCt != 0) {
1606: if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0;
1607: if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0;
1608: if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0;
1609: if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0;
1610: if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0;
1611: if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0;
1612: if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0;
1613: if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0;
1614: if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0;
1615: if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0;
1616: if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0;
1617: if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0;
1618: if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0;
1619: if (totm != 0.0) totml /= totm; else totml = 0.0;
1620: if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0;
1621: if (fracStageTime > 1.00) PetscFPrintf(comm, fd,"Warning -- total time of even greater than time of entire stage -- something is wrong with the timer\n");
1622: PetscFPrintf(comm, fd,
1623: "%-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",
1624: name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr,
1625: 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
1626: 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
1627: PetscAbsReal(flopr/1.0e6));
1628: }
1629: }
1630: }
1632: /* Memory usage and object creation */
1633: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1634: PetscFPrintf(comm, fd, "\n");
1635: PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");
1637: /* Right now, only stages on the first processor are reported here, meaning only objects associated with
1638: the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
1639: stats for stages local to processor sets.
1640: */
1641: /* We should figure out the longest object name here (now 20 characters) */
1642: PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");
1643: PetscFPrintf(comm, fd, "Reports information only for process 0.\n");
1644: for (stage = 0; stage < numStages; stage++) {
1645: if (localStageUsed[stage]) {
1646: classInfo = stageLog->stageInfo[stage].classLog->classInfo;
1647: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1648: for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
1649: if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
1650: PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name,
1651: classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem,
1652: classInfo[oclass].descMem);
1653: }
1654: }
1655: } else {
1656: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1657: }
1658: }
1660: PetscFree(localStageUsed);
1661: PetscFree(stageUsed);
1662: PetscFree(localStageVisible);
1663: PetscFree(stageVisible);
1665: /* Information unrelated to this particular run */
1666: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1667: PetscTime(&y);
1668: PetscTime(&x);
1669: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1670: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1671: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1672: /* MPI information */
1673: if (size > 1) {
1674: MPI_Status status;
1675: PetscMPIInt tag;
1676: MPI_Comm newcomm;
1678: MPI_Barrier(comm);
1679: PetscTime(&x);
1680: MPI_Barrier(comm);
1681: MPI_Barrier(comm);
1682: MPI_Barrier(comm);
1683: MPI_Barrier(comm);
1684: MPI_Barrier(comm);
1685: PetscTime(&y);
1686: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1687: PetscCommDuplicate(comm,&newcomm, &tag);
1688: MPI_Barrier(comm);
1689: if (rank) {
1690: MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);
1691: MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1692: } else {
1693: PetscTime(&x);
1694: MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);
1695: MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);
1696: PetscTime(&y);
1697: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1698: }
1699: PetscCommDestroy(&newcomm);
1700: }
1701: PetscOptionsView(viewer);
1703: /* Machine and compile information */
1704: #if defined(PETSC_USE_FORTRAN_KERNELS)
1705: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1706: #else
1707: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1708: #endif
1709: #if defined(PETSC_USE_REAL_SINGLE)
1710: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1711: #elif defined(PETSC_USE_LONGDOUBLE)
1712: PetscFPrintf(comm, fd, "Compiled with long double precision PetscScalar and PetscReal\n");
1713: #endif
1715: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1716: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1717: #else
1718: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1719: #endif
1720: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1721: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1723: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1724: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1725: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1726: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1727: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1729: /* Cleanup */
1730: PetscFPrintf(comm, fd, "\n");
1731: return(0);
1732: }
1736: /*@C
1737: PetscLogView - Prints a summary of the logging.
1739: Collective over MPI_Comm
1741: Input Parameter:
1742: . viewer - an ASCII viewer
1744: Options Database Keys:
1745: . -log_view [viewertype[:filename[:format]]] - Prints summary of log information (for code compiled with PETSC_USE_LOG)
1747: Usage:
1748: .vb
1749: PetscInitialize(...);
1750: PetscLogBegin();
1751: ... code ...
1752: PetscLogView(PetscViewer);
1753: PetscFinalize(...);
1754: .ve
1756: Notes:
1757: By default the summary is printed to stdout.
1759: Level: beginner
1761: .keywords: log, dump, print
1762: .seealso: PetscLogBegin(), PetscLogDump()
1763: @*/
1764: PetscErrorCode PetscLogView(PetscViewer viewer)
1765: {
1766: PetscErrorCode ierr;
1767: PetscBool isascii;
1768: PetscViewerFormat format;
1769: int stage, lastStage;
1770: PetscStageLog stageLog;
1773: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_summary or PetscLogBegin() before calling this routine");
1774: /* Pop off any stages the user forgot to remove */
1775: lastStage = 0;
1776: PetscLogGetStageLog(&stageLog);
1777: PetscStageLogGetCurrent(stageLog, &stage);
1778: while (stage >= 0) {
1779: lastStage = stage;
1780: PetscStageLogPop(stageLog);
1781: PetscStageLogGetCurrent(stageLog, &stage);
1782: }
1783: PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);
1784: if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII");
1785: PetscViewerGetFormat(viewer,&format);
1786: if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) {
1787: PetscLogView_Default(viewer);
1788: } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) {
1789: PetscLogView_Detailed(viewer);
1790: }
1791: PetscStageLogPush(stageLog, lastStage);
1792: return(0);
1793: }
1797: /*@C
1798: PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed.
1800: Collective on PETSC_COMM_WORLD
1802: Not normally called by user
1804: Level: intermediate
1806: @*/
1807: PetscErrorCode PetscLogViewFromOptions(void)
1808: {
1809: PetscErrorCode ierr;
1810: PetscViewer viewer;
1811: PetscBool flg;
1812: PetscViewerFormat format;
1815: PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);
1816: if (flg) {
1817: PetscViewerPushFormat(viewer,format);
1818: PetscLogView(viewer);
1819: PetscViewerPopFormat(viewer);
1820: PetscViewerDestroy(&viewer);
1821: }
1822: return(0);
1823: }
1827: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
1830: /*@C
1831: PetscGetFlops - Returns the number of flops used on this processor
1832: since the program began.
1834: Not Collective
1836: Output Parameter:
1837: flops - number of floating point operations
1839: Notes:
1840: A global counter logs all PETSc flop counts. The user can use
1841: PetscLogFlops() to increment this counter to include flops for the
1842: application code.
1844: PETSc automatically logs library events if the code has been
1845: compiled with -DPETSC_USE_LOG (which is the default), and -log,
1846: -log_summary, or -log_all are specified. PetscLogFlops() is
1847: intended for logging user flops to supplement this PETSc
1848: information.
1850: Level: intermediate
1852: .keywords: log, flops, floating point operations
1854: .seealso: PetscTime(), PetscLogFlops()
1855: @*/
1856: PetscErrorCode PetscGetFlops(PetscLogDouble *flops)
1857: {
1859: *flops = petsc_TotalFlops;
1860: return(0);
1861: }
1865: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1866: {
1868: size_t fullLength;
1869: va_list Argp;
1872: if (!petsc_logObjects) return(0);
1873: va_start(Argp, format);
1874: PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);
1875: va_end(Argp);
1876: return(0);
1877: }
1880: /*MC
1881: PetscLogFlops - Adds floating point operations to the global counter.
1883: Synopsis:
1884: #include <petsclog.h>
1885: PetscErrorCode PetscLogFlops(PetscLogDouble f)
1887: Not Collective
1889: Input Parameter:
1890: . f - flop counter
1893: Usage:
1894: .vb
1895: PetscLogEvent USER_EVENT;
1896: PetscLogEventRegister("User event",0,&USER_EVENT);
1897: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1898: [code segment to monitor]
1899: PetscLogFlops(user_flops)
1900: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1901: .ve
1903: Notes:
1904: A global counter logs all PETSc flop counts. The user can use
1905: PetscLogFlops() to increment this counter to include flops for the
1906: application code.
1908: PETSc automatically logs library events if the code has been
1909: compiled with -DPETSC_USE_LOG (which is the default), and -log,
1910: -log_summary, or -log_all are specified. PetscLogFlops() is
1911: intended for logging user flops to supplement this PETSc
1912: information.
1914: Level: intermediate
1916: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()
1918: .keywords: log, flops, floating point operations
1919: M*/
1921: /*MC
1922: PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice)
1923: to get accurate timings
1925: Synopsis:
1926: #include <petsclog.h>
1927: void PetscPreLoadBegin(PetscBool flag,char *name);
1929: Not Collective
1931: Input Parameter:
1932: + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
1933: with command line option -preload true or -preload false
1934: - name - name of first stage (lines of code timed separately with -log_summary) to
1935: be preloaded
1937: Usage:
1938: .vb
1939: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1940: lines of code
1941: PetscPreLoadStage("second stage");
1942: lines of code
1943: PetscPreLoadEnd();
1944: .ve
1946: Notes: Only works in C/C++, not Fortran
1948: Flags available within the macro.
1949: + PetscPreLoadingUsed - true if we are or have done preloading
1950: . PetscPreLoadingOn - true if it is CURRENTLY doing preload
1951: . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
1952: - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on
1953: The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin()
1954: and PetscPreLoadEnd()
1956: Level: intermediate
1958: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage()
1960: Concepts: preloading
1961: Concepts: timing^accurate
1962: Concepts: paging^eliminating effects of
1965: M*/
1967: /*MC
1968: PetscPreLoadEnd - End a segment of code that may be preloaded (run twice)
1969: to get accurate timings
1971: Synopsis:
1972: #include <petsclog.h>
1973: void PetscPreLoadEnd(void);
1975: Not Collective
1977: Usage:
1978: .vb
1979: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1980: lines of code
1981: PetscPreLoadStage("second stage");
1982: lines of code
1983: PetscPreLoadEnd();
1984: .ve
1986: Notes: only works in C/C++ not fortran
1988: Level: intermediate
1990: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage()
1992: M*/
1994: /*MC
1995: PetscPreLoadStage - Start a new segment of code to be timed separately.
1996: to get accurate timings
1998: Synopsis:
1999: #include <petsclog.h>
2000: void PetscPreLoadStage(char *name);
2002: Not Collective
2004: Usage:
2005: .vb
2006: PetscPreLoadBegin(PETSC_TRUE,"first stage);
2007: lines of code
2008: PetscPreLoadStage("second stage");
2009: lines of code
2010: PetscPreLoadEnd();
2011: .ve
2013: Notes: only works in C/C++ not fortran
2015: Level: intermediate
2017: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd()
2019: M*/
2022: #else /* end of -DPETSC_USE_LOG section */
2026: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
2027: {
2029: return(0);
2030: }
2032: #endif /* PETSC_USE_LOG*/
2035: PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
2036: PetscClassId PETSC_OBJECT_CLASSID = 0;
2040: /*@C
2041: PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code.
2043: Not Collective
2045: Input Parameter:
2046: . name - The class name
2048: Output Parameter:
2049: . oclass - The class id or classid
2051: Level: developer
2053: .keywords: log, class, register
2055: @*/
2056: PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass)
2057: {
2058: #if defined(PETSC_USE_LOG)
2059: PetscStageLog stageLog;
2060: PetscInt stage;
2062: #endif
2065: *oclass = ++PETSC_LARGEST_CLASSID;
2066: #if defined(PETSC_USE_LOG)
2067: PetscLogGetStageLog(&stageLog);
2068: PetscClassRegLogRegister(stageLog->classLog, name, *oclass);
2069: for (stage = 0; stage < stageLog->numStages; stage++) {
2070: ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
2071: }
2072: #endif
2073: return(0);
2074: }
2076: #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE)
2077: #include <mpe.h>
2079: PetscBool PetscBeganMPE = PETSC_FALSE;
2081: PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2082: PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2086: /*@C
2087: PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files
2088: and slows the program down.
2090: Collective over PETSC_COMM_WORLD
2092: Options Database Keys:
2093: . -log_mpe - Prints extensive log information (for code compiled with PETSC_USE_LOG)
2095: Notes:
2096: A related routine is PetscLogBegin() (with the options key -log_summary), which is
2097: intended for production runs since it logs only flop rates and object
2098: creation (and should not significantly slow the programs).
2100: Level: advanced
2102: Concepts: logging^MPE
2103: Concepts: logging^message passing
2105: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogAllBegin(), PetscLogEventActivate(),
2106: PetscLogEventDeactivate()
2107: @*/
2108: PetscErrorCode PetscLogMPEBegin(void)
2109: {
2113: /* Do MPE initialization */
2114: if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */
2115: PetscInfo(0,"Initializing MPE.\n");
2116: MPE_Init_log();
2118: PetscBeganMPE = PETSC_TRUE;
2119: } else {
2120: PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");
2121: }
2122: PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);
2123: return(0);
2124: }
2128: /*@C
2129: PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot.
2131: Collective over PETSC_COMM_WORLD
2133: Level: advanced
2135: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin()
2136: @*/
2137: PetscErrorCode PetscLogMPEDump(const char sname[])
2138: {
2139: char name[PETSC_MAX_PATH_LEN];
2143: if (PetscBeganMPE) {
2144: PetscInfo(0,"Finalizing MPE.\n");
2145: if (sname) {
2146: PetscStrcpy(name,sname);
2147: } else {
2148: PetscGetProgramName(name,PETSC_MAX_PATH_LEN);
2149: }
2150: MPE_Finish_log(name);
2151: } else {
2152: PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");
2153: }
2154: return(0);
2155: }
2157: #define PETSC_RGB_COLORS_MAX 39
2158: static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {
2159: "OliveDrab: ",
2160: "BlueViolet: ",
2161: "CadetBlue: ",
2162: "CornflowerBlue: ",
2163: "DarkGoldenrod: ",
2164: "DarkGreen: ",
2165: "DarkKhaki: ",
2166: "DarkOliveGreen: ",
2167: "DarkOrange: ",
2168: "DarkOrchid: ",
2169: "DarkSeaGreen: ",
2170: "DarkSlateGray: ",
2171: "DarkTurquoise: ",
2172: "DeepPink: ",
2173: "DarkKhaki: ",
2174: "DimGray: ",
2175: "DodgerBlue: ",
2176: "GreenYellow: ",
2177: "HotPink: ",
2178: "IndianRed: ",
2179: "LavenderBlush: ",
2180: "LawnGreen: ",
2181: "LemonChiffon: ",
2182: "LightCoral: ",
2183: "LightCyan: ",
2184: "LightPink: ",
2185: "LightSalmon: ",
2186: "LightSlateGray: ",
2187: "LightYellow: ",
2188: "LimeGreen: ",
2189: "MediumPurple: ",
2190: "MediumSeaGreen: ",
2191: "MediumSlateBlue:",
2192: "MidnightBlue: ",
2193: "MintCream: ",
2194: "MistyRose: ",
2195: "NavajoWhite: ",
2196: "NavyBlue: ",
2197: "OliveDrab: "
2198: };
2202: /*@C
2203: PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister()
2205: Not collective. Maybe it should be?
2207: Output Parameter
2208: . str - character string representing the color
2210: Level: developer
2212: .keywords: log, mpe , color
2213: .seealso: PetscLogEventRegister
2214: @*/
2215: PetscErrorCode PetscLogMPEGetRGBColor(const char *str[])
2216: {
2217: static int idx = 0;
2220: *str = PetscLogMPERGBColors[idx];
2221: idx = (idx + 1)% PETSC_RGB_COLORS_MAX;
2222: return(0);
2223: }
2225: #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */