Actual source code: plog.c
petsc-3.5.4 2015-05-23
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>
14: #include <petscthreadcomm.h>
16: PetscErrorCode PetscLogObjectParent(PetscObject p,PetscObject c)
17: {
18: if (!c || !p) return 0;
19: c->parent = p;
20: c->parentid = p->id;
21: return 0;
22: }
24: PetscErrorCode PetscLogObjectMemory(PetscObject p,PetscLogDouble m)
25: {
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 PetscLogBegin_PrivateCalled = 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: PetscLogBegin_PrivateCalled = 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_CHUD)
180: #include <CHUD/CHUD.h>
181: #endif
182: #if defined(PETSC_HAVE_PAPI)
183: #include <papi.h>
184: int PAPIEventSet = PAPI_NULL;
185: #endif
187: /*------------------------------------------- Initialization Functions ----------------------------------------------*/
190: PetscErrorCode PetscLogBegin_Private(void)
191: {
192: int stage;
193: PetscBool opt;
197: if (PetscLogBegin_PrivateCalled) return(0);
198: PetscLogBegin_PrivateCalled = PETSC_TRUE;
200: PetscOptionsHasName(NULL, "-log_exclude_actions", &opt);
201: if (opt) petsc_logActions = PETSC_FALSE;
202: PetscOptionsHasName(NULL, "-log_exclude_objects", &opt);
203: if (opt) petsc_logObjects = PETSC_FALSE;
204: if (petsc_logActions) {
205: PetscMalloc1(petsc_maxActions, &petsc_actions);
206: }
207: if (petsc_logObjects) {
208: PetscMalloc1(petsc_maxObjects, &petsc_objects);
209: }
210: PetscLogPHC = PetscLogObjCreateDefault;
211: PetscLogPHD = PetscLogObjDestroyDefault;
212: /* Setup default logging structures */
213: PetscStageLogCreate(&petsc_stageLog);
214: PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);
215: #if defined(PETSC_HAVE_CHUD)
216: chudInitialize();
217: chudAcquireSamplingFacility(CHUD_BLOCKING);
218: chudSetSamplingDevice(chudCPU1Dev);
219: chudSetStartDelay(0,chudNanoSeconds);
220: chudClearPMCMode(chudCPU1Dev,chudUnused);
221: chudClearPMCs();
222: /* chudSetPMCMuxPosition(chudCPU1Dev,0,0); */
223: printf("%s\n",chudGetEventName(chudCPU1Dev,PMC_1,193));
224: printf("%s\n",chudGetEventDescription(chudCPU1Dev,PMC_1,193));
225: printf("%s\n",chudGetEventNotes(chudCPU1Dev,PMC_1,193));
226: chudSetPMCEvent(chudCPU1Dev,PMC_1,193);
227: chudSetPMCMode(chudCPU1Dev,PMC_1,chudCounter);
228: chudSetPrivilegeFilter(chudCPU1Dev,PMC_1,chudCountUserEvents);
229: chudSetPMCEventMask(chudCPU1Dev,PMC_1,0xFE);
230: if (!chudIsEventValid(chudCPU1Dev,PMC_1,193)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_SUP,"Event is not valid %d",193);
231: chudStartPMCs();
232: #endif
233: #if defined(PETSC_HAVE_PAPI)
234: PAPI_library_init(PAPI_VER_CURRENT);
235: if (ierr != PAPI_VER_CURRENT) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_LIB,"Cannot initialize PAPI");
236: PAPI_query_event(PAPI_FP_INS);
237: PAPI_create_eventset(&PAPIEventSet);
238: PAPI_add_event(PAPIEventSet,PAPI_FP_INS);
239: PAPI_start(PAPIEventSet);
240: #endif
242: /* All processors sync here for more consistent logging */
243: MPI_Barrier(PETSC_COMM_WORLD);
244: PetscTime(&petsc_BaseTime);
245: PetscLogStagePush(stage);
246: return(0);
247: }
251: /*@C
252: PetscLogBegin - Turns on logging of objects and events. This logs flop
253: rates and object creation and should not slow programs down too much.
254: This routine may be called more than once.
256: Logically Collective over PETSC_COMM_WORLD
258: Options Database Keys:
259: + -log_summary - Prints summary of flop and timing information to the
260: screen (for code compiled with PETSC_USE_LOG)
261: - -log - Prints detailed log information (for code compiled with PETSC_USE_LOG)
263: Usage:
264: .vb
265: PetscInitialize(...);
266: PetscLogBegin();
267: ... code ...
268: PetscLogView(viewer); or PetscLogDump();
269: PetscFinalize();
270: .ve
272: Notes:
273: PetscLogView(viewer) or PetscLogDump() actually cause the printing of
274: the logging information.
276: Level: advanced
278: .keywords: log, begin
279: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin()
280: @*/
281: PetscErrorCode PetscLogBegin(void)
282: {
286: PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
287: PetscLogBegin_Private();
288: return(0);
289: }
293: /*@C
294: PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
295: all events. This creates large log files and slows the program down.
297: Logically Collective on PETSC_COMM_WORLD
299: Options Database Keys:
300: . -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)
302: Usage:
303: .vb
304: PetscInitialize(...);
305: PetscLogAllBegin();
306: ... code ...
307: PetscLogDump(filename);
308: PetscFinalize();
309: .ve
311: Notes:
312: A related routine is PetscLogBegin() (with the options key -log), which is
313: intended for production runs since it logs only flop rates and object
314: creation (and shouldn't significantly slow the programs).
316: Level: advanced
318: .keywords: log, all, begin
319: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogTraceBegin()
320: @*/
321: PetscErrorCode PetscLogAllBegin(void)
322: {
326: PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
327: PetscLogBegin_Private();
328: return(0);
329: }
333: /*@
334: PetscLogTraceBegin - Activates trace logging. Every time a PETSc event
335: begins or ends, the event name is printed.
337: Logically Collective on PETSC_COMM_WORLD
339: Input Parameter:
340: . file - The file to print trace in (e.g. stdout)
342: Options Database Key:
343: . -log_trace [filename] - Activates PetscLogTraceBegin()
345: Notes:
346: PetscLogTraceBegin() prints the processor number, the execution time (sec),
347: then "Event begin:" or "Event end:" followed by the event name.
349: PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
350: to determine where a program is hanging without running in the
351: debugger. Can be used in conjunction with the -info option.
353: Level: intermediate
355: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogBegin()
356: @*/
357: PetscErrorCode PetscLogTraceBegin(FILE *file)
358: {
362: petsc_tracefile = file;
364: PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
365: PetscLogBegin_Private();
366: return(0);
367: }
371: /*@
372: PetscLogActions - Determines whether actions are logged for the graphical viewer.
374: Not Collective
376: Input Parameter:
377: . flag - PETSC_TRUE if actions are to be logged
379: Level: intermediate
381: Note: Logging of actions continues to consume more memory as the program
382: runs. Long running programs should consider turning this feature off.
384: Options Database Keys:
385: . -log_exclude_actions - Turns off actions logging
387: .keywords: log, stage, register
388: .seealso: PetscLogStagePush(), PetscLogStagePop()
389: @*/
390: PetscErrorCode PetscLogActions(PetscBool flag)
391: {
393: petsc_logActions = flag;
394: return(0);
395: }
399: /*@
400: PetscLogObjects - Determines whether objects are logged for the graphical viewer.
402: Not Collective
404: Input Parameter:
405: . flag - PETSC_TRUE if objects are to be logged
407: Level: intermediate
409: Note: Logging of objects continues to consume more memory as the program
410: runs. Long running programs should consider turning this feature off.
412: Options Database Keys:
413: . -log_exclude_objects - Turns off objects logging
415: .keywords: log, stage, register
416: .seealso: PetscLogStagePush(), PetscLogStagePop()
417: @*/
418: PetscErrorCode PetscLogObjects(PetscBool flag)
419: {
421: petsc_logObjects = flag;
422: return(0);
423: }
425: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
428: /*@C
429: PetscLogStageRegister - Attaches a charactor string name to a logging stage.
431: Not Collective
433: Input Parameter:
434: . sname - The name to associate with that stage
436: Output Parameter:
437: . stage - The stage number
439: Level: intermediate
441: .keywords: log, stage, register
442: .seealso: PetscLogStagePush(), PetscLogStagePop()
443: @*/
444: PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage)
445: {
446: PetscStageLog stageLog;
447: PetscLogEvent event;
451: PetscLogGetStageLog(&stageLog);
452: PetscStageLogRegister(stageLog, sname, stage);
453: /* Copy events already changed in the main stage, this sucks */
454: EventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
455: for (event = 0; event < stageLog->eventLog->numEvents; event++) {
456: EventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
457: }
458: ClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
459: return(0);
460: }
464: /*@C
465: PetscLogStagePush - This function pushes a stage on the stack.
467: Not Collective
469: Input Parameter:
470: . stage - The stage on which to log
472: Usage:
473: If the option -log_sumary is used to run the program containing the
474: following code, then 2 sets of summary data will be printed during
475: PetscFinalize().
476: .vb
477: PetscInitialize(int *argc,char ***args,0,0);
478: [stage 0 of code]
479: PetscLogStagePush(1);
480: [stage 1 of code]
481: PetscLogStagePop();
482: PetscBarrier(...);
483: [more stage 0 of code]
484: PetscFinalize();
485: .ve
487: Notes:
488: Use PetscLogStageRegister() to register a stage.
490: Level: intermediate
492: .keywords: log, push, stage
493: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
494: @*/
495: PetscErrorCode PetscLogStagePush(PetscLogStage stage)
496: {
497: PetscStageLog stageLog;
501: PetscLogGetStageLog(&stageLog);
502: PetscStageLogPush(stageLog, stage);
503: return(0);
504: }
508: /*@C
509: PetscLogStagePop - This function pops a stage from the stack.
511: Not Collective
513: Usage:
514: If the option -log_sumary is used to run the program containing the
515: following code, then 2 sets of summary data will be printed during
516: PetscFinalize().
517: .vb
518: PetscInitialize(int *argc,char ***args,0,0);
519: [stage 0 of code]
520: PetscLogStagePush(1);
521: [stage 1 of code]
522: PetscLogStagePop();
523: PetscBarrier(...);
524: [more stage 0 of code]
525: PetscFinalize();
526: .ve
528: Notes:
529: Use PetscLogStageRegister() to register a stage.
531: Level: intermediate
533: .keywords: log, pop, stage
534: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
535: @*/
536: PetscErrorCode PetscLogStagePop(void)
537: {
538: PetscStageLog stageLog;
542: PetscLogGetStageLog(&stageLog);
543: PetscStageLogPop(stageLog);
544: return(0);
545: }
549: /*@
550: PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().
552: Not Collective
554: Input Parameters:
555: + stage - The stage
556: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
558: Level: intermediate
560: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
561: @*/
562: PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive)
563: {
564: PetscStageLog stageLog;
568: PetscLogGetStageLog(&stageLog);
569: PetscStageLogSetActive(stageLog, stage, isActive);
570: return(0);
571: }
575: /*@
576: PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().
578: Not Collective
580: Input Parameter:
581: . stage - The stage
583: Output Parameter:
584: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
586: Level: intermediate
588: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
589: @*/
590: PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive)
591: {
592: PetscStageLog stageLog;
596: PetscLogGetStageLog(&stageLog);
597: PetscStageLogGetActive(stageLog, stage, isActive);
598: return(0);
599: }
603: /*@
604: PetscLogStageSetVisible - Determines stage visibility in PetscLogView()
606: Not Collective
608: Input Parameters:
609: + stage - The stage
610: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
612: Level: intermediate
614: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
615: @*/
616: PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible)
617: {
618: PetscStageLog stageLog;
622: PetscLogGetStageLog(&stageLog);
623: PetscStageLogSetVisible(stageLog, stage, isVisible);
624: return(0);
625: }
629: /*@
630: PetscLogStageGetVisible - Returns stage visibility in PetscLogView()
632: Not Collective
634: Input Parameter:
635: . stage - The stage
637: Output Parameter:
638: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
640: Level: intermediate
642: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
643: @*/
644: PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible)
645: {
646: PetscStageLog stageLog;
650: PetscLogGetStageLog(&stageLog);
651: PetscStageLogGetVisible(stageLog, stage, isVisible);
652: return(0);
653: }
657: /*@C
658: PetscLogStageGetId - Returns the stage id when given the stage name.
660: Not Collective
662: Input Parameter:
663: . name - The stage name
665: Output Parameter:
666: . stage - The stage
668: Level: intermediate
670: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
671: @*/
672: PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage)
673: {
674: PetscStageLog stageLog;
678: PetscLogGetStageLog(&stageLog);
679: PetscStageLogGetStage(stageLog, name, stage);
680: return(0);
681: }
683: /*------------------------------------------------ Event Functions --------------------------------------------------*/
686: /*@C
687: PetscLogEventRegister - Registers an event name for logging operations in an application code.
689: Not Collective
691: Input Parameter:
692: + name - The name associated with the event
693: - classid - The classid associated to the class for this event, obtain either with
694: PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones
695: are only available in C code
697: Output Parameter:
698: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().
700: Example of Usage:
701: .vb
702: PetscLogEvent USER_EVENT;
703: PetscClassId classid;
704: PetscLogDouble user_event_flops;
705: PetscClassIdRegister("class name",&classid);
706: PetscLogEventRegister("User event name",classid,&USER_EVENT);
707: PetscLogEventBegin(USER_EVENT,0,0,0,0);
708: [code segment to monitor]
709: PetscLogFlops(user_event_flops);
710: PetscLogEventEnd(USER_EVENT,0,0,0,0);
711: .ve
713: Notes:
714: PETSc automatically logs library events if the code has been
715: compiled with -DPETSC_USE_LOG (which is the default) and -log,
716: -log_summary, or -log_all are specified. PetscLogEventRegister() is
717: intended for logging user events to supplement this PETSc
718: information.
720: PETSc can gather data for use with the utilities Jumpshot
721: (part of the MPICH distribution). If PETSc has been compiled
722: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
723: MPICH), the user can employ another command line option, -log_mpe,
724: to create a logfile, "mpe.log", which can be visualized
725: Jumpshot.
727: The classid is associated with each event so that classes of events
728: can be disabled simultaneously, such as all matrix events. The user
729: can either use an existing classid, such as MAT_CLASSID, or create
730: their own as shown in the example.
732: If an existing event with the same name exists, its event handle is
733: returned instead of creating a new event.
735: Level: intermediate
737: .keywords: log, event, register
738: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
739: PetscLogEventMPEActivate(), PetscLogEventMPEDeactivate(),
740: PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister()
741: @*/
742: PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event)
743: {
744: PetscStageLog stageLog;
745: int stage;
749: *event = PETSC_DECIDE;
750: PetscLogGetStageLog(&stageLog);
751: EventRegLogGetEvent(stageLog->eventLog, name, event);
752: if (*event > 0) return(0);
753: EventRegLogRegister(stageLog->eventLog, name, classid, event);
754: for (stage = 0; stage < stageLog->numStages; stage++) {
755: EventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
756: ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
757: }
758: return(0);
759: }
763: /*@
764: PetscLogEventActivate - Indicates that a particular event should be logged.
766: Not Collective
768: Input Parameter:
769: . event - The event id
771: Usage:
772: .vb
773: PetscLogEventDeactivate(VEC_SetValues);
774: [code where you do not want to log VecSetValues()]
775: PetscLogEventActivate(VEC_SetValues);
776: [code where you do want to log VecSetValues()]
777: .ve
779: Note:
780: The event may be either a pre-defined PETSc event (found in include/petsclog.h)
781: or an event number obtained with PetscLogEventRegister().
783: Level: advanced
785: .keywords: log, event, activate
786: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventDeactivate()
787: @*/
788: PetscErrorCode PetscLogEventActivate(PetscLogEvent event)
789: {
790: PetscStageLog stageLog;
791: int stage;
795: PetscLogGetStageLog(&stageLog);
796: PetscStageLogGetCurrent(stageLog, &stage);
797: EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
798: return(0);
799: }
803: /*@
804: PetscLogEventDeactivate - Indicates that a particular event should not be logged.
806: Not Collective
808: Input Parameter:
809: . event - The event id
811: Usage:
812: .vb
813: PetscLogEventDeactivate(VEC_SetValues);
814: [code where you do not want to log VecSetValues()]
815: PetscLogEventActivate(VEC_SetValues);
816: [code where you do want to log VecSetValues()]
817: .ve
819: Note:
820: The event may be either a pre-defined PETSc event (found in
821: include/petsclog.h) or an event number obtained with PetscLogEventRegister()).
823: Level: advanced
825: .keywords: log, event, deactivate
826: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate()
827: @*/
828: PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event)
829: {
830: PetscStageLog stageLog;
831: int stage;
835: PetscLogGetStageLog(&stageLog);
836: PetscStageLogGetCurrent(stageLog, &stage);
837: EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
838: return(0);
839: }
843: /*@
844: PetscLogEventSetActiveAll - Sets the event activity in every stage.
846: Not Collective
848: Input Parameters:
849: + event - The event id
850: - isActive - The activity flag determining whether the event is logged
852: Level: advanced
854: .keywords: log, event, activate
855: .seealso: PetscLogEventMPEDeactivate(),PetscLogEventMPEActivate(),PlogEventActivate(),PlogEventDeactivate()
856: @*/
857: PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive)
858: {
859: PetscStageLog stageLog;
860: int stage;
864: PetscLogGetStageLog(&stageLog);
865: for (stage = 0; stage < stageLog->numStages; stage++) {
866: if (isActive) {
867: EventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
868: } else {
869: EventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
870: }
871: }
872: return(0);
873: }
877: /*@
878: PetscLogEventActivateClass - Activates event logging for a PETSc object class.
880: Not Collective
882: Input Parameter:
883: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
885: Level: developer
887: .keywords: log, event, activate, class
888: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
889: @*/
890: PetscErrorCode PetscLogEventActivateClass(PetscClassId classid)
891: {
892: PetscStageLog stageLog;
893: int stage;
897: PetscLogGetStageLog(&stageLog);
898: PetscStageLogGetCurrent(stageLog, &stage);
899: EventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
900: return(0);
901: }
905: /*@
906: PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.
908: Not Collective
910: Input Parameter:
911: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
913: Level: developer
915: .keywords: log, event, deactivate, class
916: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
917: @*/
918: PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid)
919: {
920: PetscStageLog stageLog;
921: int stage;
925: PetscLogGetStageLog(&stageLog);
926: PetscStageLogGetCurrent(stageLog, &stage);
927: EventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
928: return(0);
929: }
931: /*MC
932: PetscLogEventBegin - Logs the beginning of a user event.
934: Synopsis:
935: #include <petsclog.h>
936: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
938: Not Collective
940: Input Parameters:
941: + e - integer associated with the event obtained from PetscLogEventRegister()
942: - o1,o2,o3,o4 - objects associated with the event, or 0
945: Fortran Synopsis:
946: void PetscLogEventBegin(int e,PetscErrorCode ierr)
948: Usage:
949: .vb
950: PetscLogEvent USER_EVENT;
951: PetscLogDouble user_event_flops;
952: PetscLogEventRegister("User event",0,&USER_EVENT);
953: PetscLogEventBegin(USER_EVENT,0,0,0,0);
954: [code segment to monitor]
955: PetscLogFlops(user_event_flops);
956: PetscLogEventEnd(USER_EVENT,0,0,0,0);
957: .ve
959: Notes:
960: You need to register each integer event with the command
961: PetscLogEventRegister(). The source code must be compiled with
962: -DPETSC_USE_LOG, which is the default.
964: PETSc automatically logs library events if the code has been
965: compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
966: specified. PetscLogEventBegin() is intended for logging user events
967: to supplement this PETSc information.
969: Level: intermediate
971: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
973: .keywords: log, event, begin
974: M*/
976: /*MC
977: PetscLogEventEnd - Log the end of a user event.
979: Synopsis:
980: #include <petsclog.h>
981: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
983: Not Collective
985: Input Parameters:
986: + e - integer associated with the event obtained with PetscLogEventRegister()
987: - o1,o2,o3,o4 - objects associated with the event, or 0
990: Fortran Synopsis:
991: void PetscLogEventEnd(int e,PetscErrorCode ierr)
993: Usage:
994: .vb
995: PetscLogEvent USER_EVENT;
996: PetscLogDouble user_event_flops;
997: PetscLogEventRegister("User event",0,&USER_EVENT,);
998: PetscLogEventBegin(USER_EVENT,0,0,0,0);
999: [code segment to monitor]
1000: PetscLogFlops(user_event_flops);
1001: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1002: .ve
1004: Notes:
1005: You should also register each additional integer event with the command
1006: PetscLogEventRegister(). Source code must be compiled with
1007: -DPETSC_USE_LOG, which is the default.
1009: PETSc automatically logs library events if the code has been
1010: compiled with -DPETSC_USE_LOG, and -log, -log_summary, or -log_all are
1011: specified. PetscLogEventEnd() is intended for logging user events
1012: to supplement this PETSc information.
1014: Level: intermediate
1016: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
1018: .keywords: log, event, end
1019: M*/
1021: /*MC
1022: PetscLogEventBarrierBegin - Logs the time in a barrier before an event.
1024: Synopsis:
1025: #include <petsclog.h>
1026: PetscErrorCode PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
1028: Not Collective
1030: Input Parameters:
1031: . e - integer associated with the event obtained from PetscLogEventRegister()
1032: . o1,o2,o3,o4 - objects associated with the event, or 0
1033: . comm - communicator the barrier takes place over
1036: Usage:
1037: .vb
1038: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1039: MPI_Allreduce()
1040: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1041: .ve
1043: Notes:
1044: This is for logging the amount of time spent in a barrier for an event
1045: that requires synchronization.
1047: Additional Notes:
1048: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1049: VEC_NormComm = VEC_NormBarrier + 1
1051: Level: advanced
1053: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1054: PetscLogEventBarrierEnd()
1056: .keywords: log, event, begin, barrier
1057: M*/
1059: /*MC
1060: PetscLogEventBarrierEnd - Logs the time in a barrier before an event.
1062: Synopsis:
1063: #include <petsclog.h>
1064: PetscErrorCode PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
1066: Logically Collective on MPI_Comm
1068: Input Parameters:
1069: . e - integer associated with the event obtained from PetscLogEventRegister()
1070: . o1,o2,o3,o4 - objects associated with the event, or 0
1071: . comm - communicator the barrier takes place over
1074: Usage:
1075: .vb
1076: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1077: MPI_Allreduce()
1078: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1079: .ve
1081: Notes:
1082: This is for logging the amount of time spent in a barrier for an event
1083: that requires synchronization.
1085: Additional Notes:
1086: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1087: VEC_NormComm = VEC_NormBarrier + 1
1089: Level: advanced
1091: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1092: PetscLogEventBarrierBegin()
1094: .keywords: log, event, begin, barrier
1095: M*/
1099: /*@C
1100: PetscLogEventGetId - Returns the event id when given the event name.
1102: Not Collective
1104: Input Parameter:
1105: . name - The event name
1107: Output Parameter:
1108: . event - The event, or -1 if no event with that name exists
1110: Level: intermediate
1112: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1113: @*/
1114: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1115: {
1116: PetscStageLog stageLog;
1120: PetscLogGetStageLog(&stageLog);
1121: EventRegLogGetEvent(stageLog->eventLog, name, event);
1122: return(0);
1123: }
1126: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1129: /*@C
1130: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1131: be read by bin/petscview. This program no longer exists.
1133: Collective on PETSC_COMM_WORLD
1135: Input Parameter:
1136: . name - an optional file name
1138: Options Database Keys:
1139: + -log - Prints basic log information (for code compiled with PETSC_USE_LOG)
1140: - -log_all - Prints extensive log information (for code compiled with PETSC_USE_LOG)
1142: Usage:
1143: .vb
1144: PetscInitialize(...);
1145: PetscLogBegin(); or PetscLogAllBegin();
1146: ... code ...
1147: PetscLogDump(filename);
1148: PetscFinalize();
1149: .ve
1151: Notes:
1152: The default file name is
1153: $ Log.<rank>
1154: where <rank> is the processor number. If no name is specified,
1155: this file will be used.
1157: Level: advanced
1159: .keywords: log, dump
1160: .seealso: PetscLogBegin(), PetscLogAllBegin(), PetscLogView()
1161: @*/
1162: PetscErrorCode PetscLogDump(const char sname[])
1163: {
1164: PetscStageLog stageLog;
1165: PetscEventPerfInfo *eventInfo;
1166: FILE *fd;
1167: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1168: PetscLogDouble flops, _TotalTime;
1169: PetscMPIInt rank;
1170: int action, object, curStage;
1171: PetscLogEvent event;
1172: PetscErrorCode ierr;
1175: /* Calculate the total elapsed time */
1176: PetscTime(&_TotalTime);
1177: _TotalTime -= petsc_BaseTime;
1178: /* Open log file */
1179: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1180: if (sname) sprintf(file, "%s.%d", sname, rank);
1181: else sprintf(file, "Log.%d", rank);
1182: PetscFixFilename(file, fname);
1183: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1184: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1185: /* Output totals */
1186: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flops %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1187: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1188: /* Output actions */
1189: if (petsc_logActions) {
1190: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1191: for (action = 0; action < petsc_numActions; action++) {
1192: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1193: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1194: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1195: }
1196: }
1197: /* Output objects */
1198: if (petsc_logObjects) {
1199: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1200: for (object = 0; object < petsc_numObjects; object++) {
1201: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1202: if (!petsc_objects[object].name[0]) {
1203: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1204: } else {
1205: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1206: }
1207: if (petsc_objects[object].info[0] != 0) {
1208: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1209: } else {
1210: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1211: }
1212: }
1213: }
1214: /* Output events */
1215: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1216: PetscLogGetStageLog(&stageLog);
1217: PetscIntStackTop(stageLog->stack, &curStage);
1218: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1219: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1220: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1221: else flops = 0.0;
1222: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1223: eventInfo[event].flops, eventInfo[event].time, flops);
1224: }
1225: PetscFClose(PETSC_COMM_WORLD, fd);
1226: return(0);
1227: }
1231: /*
1232: PetscLogView_Detailed - Each process prints the times for its own events
1234: */
1235: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1236: {
1237: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1238: PetscEventPerfInfo *eventInfo = NULL;
1239: PetscLogDouble locTotalTime, numRed, maxMem;
1240: PetscStageLog stageLog;
1241: int numStages,numEvents,stage,event;
1242: PetscMPIInt rank,size;
1243: PetscErrorCode ierr;
1246: MPI_Comm_size(comm, &size);
1247: MPI_Comm_rank(comm, &rank);
1248: /* Must preserve reduction count before we go on */
1249: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1250: /* Get the total elapsed time */
1251: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1252: PetscViewerASCIIPrintf(viewer,"numProcs = %d\n",size);
1253: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1254: PetscViewerASCIIPrintf(viewer,"LocalFlops = {}\n");
1255: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1256: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1257: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1258: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1259: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1260: PetscLogGetStageLog(&stageLog);
1261: MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1262: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1263: for (stage=0; stage<numStages; stage++) {
1264: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1265: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1266: MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1267: for (event = 0; event < numEvents; event++) {
1268: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1269: }
1270: }
1271: PetscViewerASCIISynchronizedAllow(viewer,PETSC_TRUE);
1272: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1273: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlops[%d] = %g\n",rank,petsc_TotalFlops);
1274: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1275: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1276: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1277: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %g\n",rank,petsc_numObjects);
1278: PetscMallocGetMaximumUsage(&maxMem);
1279: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1280: PetscViewerFlush(viewer);
1281: for (stage=0; stage<numStages; stage++) {
1282: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flops\" : %g}\n",
1283: stageLog->stageInfo[stage].name,rank,
1284: stageLog->stageInfo[stage].perfInfo.time,stageLog->stageInfo[stage].perfInfo.numMessages,stageLog->stageInfo[stage].perfInfo.messageLength,
1285: stageLog->stageInfo[stage].perfInfo.numReductions,stageLog->stageInfo[stage].perfInfo.flops);
1286: MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1287: for (event = 0; event < numEvents; event++) {
1288: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1289: 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,
1290: eventInfo[event].count, eventInfo[event].time,eventInfo[event].numMessages, eventInfo[event].messageLength,
1291: eventInfo[event].numReductions,eventInfo[event].flops);
1292: }
1293: }
1294: PetscViewerFlush(viewer);
1295: PetscViewerASCIISynchronizedAllow(viewer,PETSC_FALSE);
1296: return(0);
1297: }
1301: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1302: {
1303: FILE *fd;
1304: PetscLogDouble zero = 0.0;
1305: PetscStageLog stageLog;
1306: PetscStageInfo *stageInfo = NULL;
1307: PetscEventPerfInfo *eventInfo = NULL;
1308: PetscClassPerfInfo *classInfo;
1309: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1310: const char *name;
1311: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1312: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1313: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1314: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1315: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1316: PetscLogDouble min, max, tot, ratio, avg, x, y;
1317: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr;
1318: PetscMPIInt minCt, maxCt;
1319: PetscMPIInt size, rank;
1320: PetscBool *localStageUsed, *stageUsed;
1321: PetscBool *localStageVisible, *stageVisible;
1322: int numStages, localNumEvents, numEvents;
1323: int stage, oclass;
1324: PetscLogEvent event;
1325: PetscErrorCode ierr;
1326: char version[256];
1327: MPI_Comm comm;
1328: PetscInt nthreads;
1331: PetscObjectGetComm((PetscObject)viewer,&comm);
1332: PetscViewerASCIIGetPointer(viewer,&fd);
1333: MPI_Comm_size(comm, &size);
1334: MPI_Comm_rank(comm, &rank);
1335: /* Get the total elapsed time */
1336: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1338: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1339: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1340: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1341: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1342: PetscGetArchType(arch,sizeof(arch));
1343: PetscGetHostName(hostname,sizeof(hostname));
1344: PetscGetUserName(username,sizeof(username));
1345: PetscGetProgramName(pname,sizeof(pname));
1346: PetscGetDate(date,sizeof(date));
1347: PetscGetVersion(version,sizeof(version));
1348: if (size == 1) {
1349: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1350: } else {
1351: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1352: }
1353: PetscThreadCommGetNThreads(PETSC_COMM_WORLD,&nthreads);
1354: if (nthreads > 1) {
1355: PetscFPrintf(comm,fd,"With %d threads per MPI_Comm\n", (int)nthreads);
1356: }
1358: PetscFPrintf(comm, fd, "Using %s\n", version);
1360: /* Must preserve reduction count before we go on */
1361: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1363: /* Calculate summary information */
1364: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1365: /* Time */
1366: MPI_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1367: MPI_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1368: MPI_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1369: avg = (tot)/((PetscLogDouble) size);
1370: if (min != 0.0) ratio = max/min;
1371: else ratio = 0.0;
1372: PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);
1373: TotalTime = tot;
1374: /* Objects */
1375: avg = (PetscLogDouble) petsc_numObjects;
1376: MPI_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1377: MPI_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1378: MPI_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1379: avg = (tot)/((PetscLogDouble) size);
1380: if (min != 0.0) ratio = max/min;
1381: else ratio = 0.0;
1382: PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);
1383: /* Flops */
1384: MPI_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1385: MPI_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1386: MPI_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1387: avg = (tot)/((PetscLogDouble) size);
1388: if (min != 0.0) ratio = max/min;
1389: else ratio = 0.0;
1390: PetscFPrintf(comm, fd, "Flops: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1391: TotalFlops = tot;
1392: /* Flops/sec -- Must talk to Barry here */
1393: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime;
1394: else flops = 0.0;
1395: MPI_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1396: MPI_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1397: MPI_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1398: avg = (tot)/((PetscLogDouble) size);
1399: if (min != 0.0) ratio = max/min;
1400: else ratio = 0.0;
1401: PetscFPrintf(comm, fd, "Flops/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1402: /* Memory */
1403: PetscMallocGetMaximumUsage(&mem);
1404: if (mem > 0.0) {
1405: MPI_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1406: MPI_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1407: MPI_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1408: avg = (tot)/((PetscLogDouble) size);
1409: if (min != 0.0) ratio = max/min;
1410: else ratio = 0.0;
1411: PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);
1412: }
1413: /* Messages */
1414: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1415: MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1416: MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1417: MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1418: avg = (tot)/((PetscLogDouble) size);
1419: if (min != 0.0) ratio = max/min;
1420: else ratio = 0.0;
1421: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1422: numMessages = tot;
1423: /* Message Lengths */
1424: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1425: MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1426: MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1427: MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1428: if (numMessages != 0) avg = (tot)/(numMessages);
1429: else avg = 0.0;
1430: if (min != 0.0) ratio = max/min;
1431: else ratio = 0.0;
1432: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1433: messageLength = tot;
1434: /* Reductions */
1435: MPI_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1436: MPI_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1437: MPI_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1438: if (min != 0.0) ratio = max/min;
1439: else ratio = 0.0;
1440: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);
1441: numReductions = red; /* wrong because uses count from process zero */
1442: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1443: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flops\n");
1444: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flops\n");
1446: /* Get total number of stages --
1447: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1448: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1449: This seems best accomplished by assoicating a communicator with each stage.
1450: */
1451: PetscLogGetStageLog(&stageLog);
1452: MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1453: PetscMalloc1(numStages, &localStageUsed);
1454: PetscMalloc1(numStages, &stageUsed);
1455: PetscMalloc1(numStages, &localStageVisible);
1456: PetscMalloc1(numStages, &stageVisible);
1457: if (numStages > 0) {
1458: stageInfo = stageLog->stageInfo;
1459: for (stage = 0; stage < numStages; stage++) {
1460: if (stage < stageLog->numStages) {
1461: localStageUsed[stage] = stageInfo[stage].used;
1462: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1463: } else {
1464: localStageUsed[stage] = PETSC_FALSE;
1465: localStageVisible[stage] = PETSC_TRUE;
1466: }
1467: }
1468: MPI_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1469: MPI_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1470: for (stage = 0; stage < numStages; stage++) {
1471: if (stageUsed[stage]) {
1472: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flops ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");
1473: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");
1474: break;
1475: }
1476: }
1477: for (stage = 0; stage < numStages; stage++) {
1478: if (!stageUsed[stage]) continue;
1479: if (localStageUsed[stage]) {
1480: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1481: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1482: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1483: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1484: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1485: name = stageInfo[stage].name;
1486: } else {
1487: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1488: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1489: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1490: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1491: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1492: name = "";
1493: }
1494: mess *= 0.5; messLen *= 0.5; red /= size;
1495: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1496: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1497: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1498: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1499: if (numMessages != 0.0) avgMessLen = messLen/numMessages; else avgMessLen = 0.0;
1500: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1501: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1502: 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",
1503: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1504: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1505: }
1506: }
1508: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1509: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1510: PetscFPrintf(comm, fd, "Phase summary info:\n");
1511: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1512: PetscFPrintf(comm, fd, " Time and Flops: Max - maximum over all processors\n");
1513: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1514: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1515: PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");
1516: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1517: PetscFPrintf(comm, fd, " Global: entire computation\n");
1518: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1519: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flops in this phase\n");
1520: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1521: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1522: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flops over all processors)/(max time over all processors)\n");
1523: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1525: #if defined(PETSC_USE_DEBUG)
1526: PetscFPrintf(comm, fd, "\n\n");
1527: PetscFPrintf(comm, fd, " ##########################################################\n");
1528: PetscFPrintf(comm, fd, " # #\n");
1529: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1530: PetscFPrintf(comm, fd, " # #\n");
1531: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");
1532: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1533: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1534: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1535: PetscFPrintf(comm, fd, " # #\n");
1536: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1537: #endif
1538: #if defined(PETSC_USE_COMPLEX) && !defined(PETSC_USE_FORTRAN_KERNELS)
1539: PetscFPrintf(comm, fd, "\n\n");
1540: PetscFPrintf(comm, fd, " ##########################################################\n");
1541: PetscFPrintf(comm, fd, " # #\n");
1542: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1543: PetscFPrintf(comm, fd, " # #\n");
1544: PetscFPrintf(comm, fd, " # The code for various complex numbers numerical #\n");
1545: PetscFPrintf(comm, fd, " # kernels uses C++, which generally is not well #\n");
1546: PetscFPrintf(comm, fd, " # optimized. For performance that is about 4-5 times #\n");
1547: PetscFPrintf(comm, fd, " # faster, specify --with-fortran-kernels=1 #\n");
1548: PetscFPrintf(comm, fd, " # when running ./configure.py. #\n");
1549: PetscFPrintf(comm, fd, " # #\n");
1550: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1551: #endif
1553: /* Report events */
1554: PetscFPrintf(comm, fd,"Event Count Time (sec) Flops --- Global --- --- Stage --- Total\n");
1555: 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");
1556: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1558: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1559: for (stage = 0; stage < numStages; stage++) {
1560: if (!stageVisible[stage]) continue;
1561: if (localStageUsed[stage]) {
1562: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1563: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1564: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1565: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1566: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1567: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1568: } else {
1569: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1570: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1571: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1572: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1573: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1574: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1575: }
1576: mess *= 0.5; messLen *= 0.5; red /= size;
1578: /* Get total number of events in this stage --
1579: Currently, a single processor can register more events than another, but events must all be registered in order,
1580: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1581: on the event ID. This seems best accomplished by assoicating a communicator with each stage.
1583: Problem: If the event did not happen on proc 1, its name will not be available.
1584: Problem: Event visibility is not implemented
1585: */
1586: if (localStageUsed[stage]) {
1587: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1588: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1589: } else localNumEvents = 0;
1590: MPI_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1591: for (event = 0; event < numEvents; event++) {
1592: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1593: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops;
1594: else flopr = 0.0;
1596: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1597: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1598: MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1599: MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1600: MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1601: MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1602: MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1603: MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1604: MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1605: MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);
1606: MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1607: name = stageLog->eventLog->eventInfo[event].name;
1608: } else {
1609: flopr = 0.0;
1610: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1611: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1612: MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1613: MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1614: MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1615: MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1616: MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1617: MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1618: MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1619: MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);
1620: MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1621: name = "";
1622: }
1623: if (mint < 0.0) {
1624: 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);
1625: mint = 0;
1626: }
1627: 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);
1628: totm *= 0.5; totml *= 0.5; totr /= size;
1630: if (maxCt != 0) {
1631: if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0;
1632: if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0;
1633: if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0;
1634: if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0;
1635: if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0;
1636: if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0;
1637: if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0;
1638: if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0;
1639: if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0;
1640: if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0;
1641: if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0;
1642: if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0;
1643: if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0;
1644: if (totm != 0.0) totml /= totm; else totml = 0.0;
1645: if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0;
1646: 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");
1647: PetscFPrintf(comm, fd,
1648: "%-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",
1649: name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr,
1650: 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
1651: 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
1652: PetscAbsReal(flopr/1.0e6));
1653: }
1654: }
1655: }
1657: /* Memory usage and object creation */
1658: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1659: PetscFPrintf(comm, fd, "\n");
1660: PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");
1662: /* Right now, only stages on the first processor are reported here, meaning only objects associated with
1663: the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
1664: stats for stages local to processor sets.
1665: */
1666: /* We should figure out the longest object name here (now 20 characters) */
1667: PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");
1668: PetscFPrintf(comm, fd, "Reports information only for process 0.\n");
1669: for (stage = 0; stage < numStages; stage++) {
1670: if (localStageUsed[stage]) {
1671: classInfo = stageLog->stageInfo[stage].classLog->classInfo;
1672: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1673: for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
1674: if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
1675: PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name,
1676: classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem,
1677: classInfo[oclass].descMem);
1678: }
1679: }
1680: } else {
1681: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1682: }
1683: }
1685: PetscFree(localStageUsed);
1686: PetscFree(stageUsed);
1687: PetscFree(localStageVisible);
1688: PetscFree(stageVisible);
1690: /* Information unrelated to this particular run */
1691: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1692: PetscTime(&y);
1693: PetscTime(&x);
1694: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1695: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1696: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1697: /* MPI information */
1698: if (size > 1) {
1699: MPI_Status status;
1700: PetscMPIInt tag;
1701: MPI_Comm newcomm;
1703: MPI_Barrier(comm);
1704: PetscTime(&x);
1705: MPI_Barrier(comm);
1706: MPI_Barrier(comm);
1707: MPI_Barrier(comm);
1708: MPI_Barrier(comm);
1709: MPI_Barrier(comm);
1710: PetscTime(&y);
1711: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1712: PetscCommDuplicate(comm,&newcomm, &tag);
1713: MPI_Barrier(comm);
1714: if (rank) {
1715: MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);
1716: MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1717: } else {
1718: PetscTime(&x);
1719: MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);
1720: MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);
1721: PetscTime(&y);
1722: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1723: }
1724: PetscCommDestroy(&newcomm);
1725: }
1726: PetscOptionsView(viewer);
1728: /* Machine and compile information */
1729: #if defined(PETSC_USE_FORTRAN_KERNELS)
1730: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1731: #else
1732: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1733: #endif
1734: #if defined(PETSC_USE_REAL_SINGLE)
1735: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1736: #elif defined(PETSC_USE_LONGDOUBLE)
1737: PetscFPrintf(comm, fd, "Compiled with long double precision PetscScalar and PetscReal\n");
1738: #endif
1740: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1741: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1742: #else
1743: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1744: #endif
1745: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1746: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1748: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1749: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1750: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1751: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1752: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1754: /* Cleanup */
1755: PetscFPrintf(comm, fd, "\n");
1756: return(0);
1757: }
1761: /*@C
1762: PetscLogView - Prints a summary of the logging.
1764: Collective over MPI_Comm
1766: Input Parameter:
1767: . viewer - an ASCII viewer
1769: Options Database Keys:
1770: . -log_view [viewertype[:filename[:format]]] - Prints summary of log information (for code compiled with PETSC_USE_LOG)
1772: Usage:
1773: .vb
1774: PetscInitialize(...);
1775: PetscLogBegin();
1776: ... code ...
1777: PetscLogView(PetscViewer);
1778: PetscFinalize(...);
1779: .ve
1781: Notes:
1782: By default the summary is printed to stdout.
1784: Level: beginner
1786: .keywords: log, dump, print
1787: .seealso: PetscLogBegin(), PetscLogDump()
1788: @*/
1789: PetscErrorCode PetscLogView(PetscViewer viewer)
1790: {
1791: PetscErrorCode ierr;
1792: PetscBool isascii;
1793: PetscViewerFormat format;
1794: int stage, lastStage;
1795: PetscStageLog stageLog;
1798: if (!PetscLogBegin_PrivateCalled) SETERRQ(PetscObjectComm((PetscObject)viewer), PETSC_ERR_ORDER, "No call to PetscLogBegin() before PetscLogView()");
1799: /* Pop off any stages the user forgot to remove */
1800: lastStage = 0;
1801: PetscLogGetStageLog(&stageLog);
1802: PetscStageLogGetCurrent(stageLog, &stage);
1803: while (stage >= 0) {
1804: lastStage = stage;
1805: PetscStageLogPop(stageLog);
1806: PetscStageLogGetCurrent(stageLog, &stage);
1807: }
1808: PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);
1809: if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII");
1810: PetscViewerGetFormat(viewer,&format);
1811: if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) {
1812: PetscLogView_Default(viewer);
1813: } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) {
1814: PetscLogView_Detailed(viewer);
1815: }
1816: PetscStageLogPush(stageLog, lastStage);
1817: return(0);
1818: }
1822: /*@C
1823: PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed.
1825: Collective on PETSC_COMM_WORLD
1827: Not normally called by user
1829: Level: intermediate
1831: @*/
1832: PetscErrorCode PetscLogViewFromOptions(void)
1833: {
1834: PetscErrorCode ierr;
1835: PetscViewer viewer;
1836: PetscBool flg;
1837: PetscViewerFormat format;
1840: PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);
1841: if (flg) {
1842: PetscViewerPushFormat(viewer,format);
1843: PetscLogView(viewer);
1844: PetscViewerPopFormat(viewer);
1845: PetscViewerDestroy(&viewer);
1846: }
1847: return(0);
1848: }
1852: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
1855: /*@C
1856: PetscGetFlops - Returns the number of flops used on this processor
1857: since the program began.
1859: Not Collective
1861: Output Parameter:
1862: flops - number of floating point operations
1864: Notes:
1865: A global counter logs all PETSc flop counts. The user can use
1866: PetscLogFlops() to increment this counter to include flops for the
1867: application code.
1869: PETSc automatically logs library events if the code has been
1870: compiled with -DPETSC_USE_LOG (which is the default), and -log,
1871: -log_summary, or -log_all are specified. PetscLogFlops() is
1872: intended for logging user flops to supplement this PETSc
1873: information.
1875: Level: intermediate
1877: .keywords: log, flops, floating point operations
1879: .seealso: PetscTime(), PetscLogFlops()
1880: @*/
1881: PetscErrorCode PetscGetFlops(PetscLogDouble *flops)
1882: {
1884: *flops = petsc_TotalFlops;
1885: return(0);
1886: }
1890: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1891: {
1893: size_t fullLength;
1894: va_list Argp;
1897: if (!petsc_logObjects) return(0);
1898: va_start(Argp, format);
1899: PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);
1900: va_end(Argp);
1901: return(0);
1902: }
1905: /*MC
1906: PetscLogFlops - Adds floating point operations to the global counter.
1908: Synopsis:
1909: #include <petsclog.h>
1910: PetscErrorCode PetscLogFlops(PetscLogDouble f)
1912: Not Collective
1914: Input Parameter:
1915: . f - flop counter
1918: Usage:
1919: .vb
1920: PetscLogEvent USER_EVENT;
1921: PetscLogEventRegister("User event",0,&USER_EVENT);
1922: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1923: [code segment to monitor]
1924: PetscLogFlops(user_flops)
1925: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1926: .ve
1928: Notes:
1929: A global counter logs all PETSc flop counts. The user can use
1930: PetscLogFlops() to increment this counter to include flops for the
1931: application code.
1933: PETSc automatically logs library events if the code has been
1934: compiled with -DPETSC_USE_LOG (which is the default), and -log,
1935: -log_summary, or -log_all are specified. PetscLogFlops() is
1936: intended for logging user flops to supplement this PETSc
1937: information.
1939: Level: intermediate
1941: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()
1943: .keywords: log, flops, floating point operations
1944: M*/
1946: /*MC
1947: PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice)
1948: to get accurate timings
1950: Synopsis:
1951: #include <petsclog.h>
1952: void PetscPreLoadBegin(PetscBool flag,char *name);
1954: Not Collective
1956: Input Parameter:
1957: + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
1958: with command line option -preload true or -preload false
1959: - name - name of first stage (lines of code timed separately with -log_summary) to
1960: be preloaded
1962: Usage:
1963: .vb
1964: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1965: lines of code
1966: PetscPreLoadStage("second stage");
1967: lines of code
1968: PetscPreLoadEnd();
1969: .ve
1971: Notes: Only works in C/C++, not Fortran
1973: Flags available within the macro.
1974: + PetscPreLoadingUsed - true if we are or have done preloading
1975: . PetscPreLoadingOn - true if it is CURRENTLY doing preload
1976: . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
1977: - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on
1978: The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin()
1979: and PetscPreLoadEnd()
1981: Level: intermediate
1983: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage()
1985: Concepts: preloading
1986: Concepts: timing^accurate
1987: Concepts: paging^eliminating effects of
1990: M*/
1992: /*MC
1993: PetscPreLoadEnd - End a segment of code that may be preloaded (run twice)
1994: to get accurate timings
1996: Synopsis:
1997: #include <petsclog.h>
1998: void PetscPreLoadEnd(void);
2000: Not Collective
2002: Usage:
2003: .vb
2004: PetscPreLoadBegin(PETSC_TRUE,"first stage);
2005: lines of code
2006: PetscPreLoadStage("second stage");
2007: lines of code
2008: PetscPreLoadEnd();
2009: .ve
2011: Notes: only works in C/C++ not fortran
2013: Level: intermediate
2015: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage()
2017: M*/
2019: /*MC
2020: PetscPreLoadStage - Start a new segment of code to be timed separately.
2021: to get accurate timings
2023: Synopsis:
2024: #include <petsclog.h>
2025: void PetscPreLoadStage(char *name);
2027: Not Collective
2029: Usage:
2030: .vb
2031: PetscPreLoadBegin(PETSC_TRUE,"first stage);
2032: lines of code
2033: PetscPreLoadStage("second stage");
2034: lines of code
2035: PetscPreLoadEnd();
2036: .ve
2038: Notes: only works in C/C++ not fortran
2040: Level: intermediate
2042: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd()
2044: M*/
2047: #else /* end of -DPETSC_USE_LOG section */
2051: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
2052: {
2054: return(0);
2055: }
2057: #endif /* PETSC_USE_LOG*/
2060: PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
2061: PetscClassId PETSC_OBJECT_CLASSID = 0;
2065: /*@C
2066: PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code.
2068: Not Collective
2070: Input Parameter:
2071: . name - The class name
2073: Output Parameter:
2074: . oclass - The class id or classid
2076: Level: developer
2078: .keywords: log, class, register
2080: @*/
2081: PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass)
2082: {
2083: #if defined(PETSC_USE_LOG)
2084: PetscStageLog stageLog;
2085: PetscInt stage;
2087: #endif
2090: *oclass = ++PETSC_LARGEST_CLASSID;
2091: #if defined(PETSC_USE_LOG)
2092: PetscLogGetStageLog(&stageLog);
2093: PetscClassRegLogRegister(stageLog->classLog, name, *oclass);
2094: for (stage = 0; stage < stageLog->numStages; stage++) {
2095: ClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
2096: }
2097: #endif
2098: return(0);
2099: }
2101: #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE)
2102: #include <mpe.h>
2104: PetscBool PetscBeganMPE = PETSC_FALSE;
2106: PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2107: PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2111: /*@C
2112: PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files
2113: and slows the program down.
2115: Collective over PETSC_COMM_WORLD
2117: Options Database Keys:
2118: . -log_mpe - Prints extensive log information (for code compiled with PETSC_USE_LOG)
2120: Notes:
2121: A related routine is PetscLogBegin() (with the options key -log_summary), which is
2122: intended for production runs since it logs only flop rates and object
2123: creation (and should not significantly slow the programs).
2125: Level: advanced
2127: Concepts: logging^MPE
2128: Concepts: logging^message passing
2130: .seealso: PetscLogDump(), PetscLogBegin(), PetscLogAllBegin(), PetscLogEventActivate(),
2131: PetscLogEventDeactivate()
2132: @*/
2133: PetscErrorCode PetscLogMPEBegin(void)
2134: {
2138: /* Do MPE initialization */
2139: if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */
2140: PetscInfo(0,"Initializing MPE.\n");
2141: MPE_Init_log();
2143: PetscBeganMPE = PETSC_TRUE;
2144: } else {
2145: PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");
2146: }
2147: PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);
2148: return(0);
2149: }
2153: /*@C
2154: PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot.
2156: Collective over PETSC_COMM_WORLD
2158: Level: advanced
2160: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin()
2161: @*/
2162: PetscErrorCode PetscLogMPEDump(const char sname[])
2163: {
2164: char name[PETSC_MAX_PATH_LEN];
2168: if (PetscBeganMPE) {
2169: PetscInfo(0,"Finalizing MPE.\n");
2170: if (sname) {
2171: PetscStrcpy(name,sname);
2172: } else {
2173: PetscGetProgramName(name,PETSC_MAX_PATH_LEN);
2174: }
2175: MPE_Finish_log(name);
2176: } else {
2177: PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");
2178: }
2179: return(0);
2180: }
2182: #define PETSC_RGB_COLORS_MAX 39
2183: static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {
2184: "OliveDrab: ",
2185: "BlueViolet: ",
2186: "CadetBlue: ",
2187: "CornflowerBlue: ",
2188: "DarkGoldenrod: ",
2189: "DarkGreen: ",
2190: "DarkKhaki: ",
2191: "DarkOliveGreen: ",
2192: "DarkOrange: ",
2193: "DarkOrchid: ",
2194: "DarkSeaGreen: ",
2195: "DarkSlateGray: ",
2196: "DarkTurquoise: ",
2197: "DeepPink: ",
2198: "DarkKhaki: ",
2199: "DimGray: ",
2200: "DodgerBlue: ",
2201: "GreenYellow: ",
2202: "HotPink: ",
2203: "IndianRed: ",
2204: "LavenderBlush: ",
2205: "LawnGreen: ",
2206: "LemonChiffon: ",
2207: "LightCoral: ",
2208: "LightCyan: ",
2209: "LightPink: ",
2210: "LightSalmon: ",
2211: "LightSlateGray: ",
2212: "LightYellow: ",
2213: "LimeGreen: ",
2214: "MediumPurple: ",
2215: "MediumSeaGreen: ",
2216: "MediumSlateBlue:",
2217: "MidnightBlue: ",
2218: "MintCream: ",
2219: "MistyRose: ",
2220: "NavajoWhite: ",
2221: "NavyBlue: ",
2222: "OliveDrab: "
2223: };
2227: /*@C
2228: PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister()
2230: Not collective. Maybe it should be?
2232: Output Parameter
2233: . str - character string representing the color
2235: Level: developer
2237: .keywords: log, mpe , color
2238: .seealso: PetscLogEventRegister
2239: @*/
2240: PetscErrorCode PetscLogMPEGetRGBColor(const char *str[])
2241: {
2242: static int idx = 0;
2245: *str = PetscLogMPERGBColors[idx];
2246: idx = (idx + 1)% PETSC_RGB_COLORS_MAX;
2247: return(0);
2248: }
2250: #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */