Actual source code: plog.c
petsc-3.9.4 2018-09-11
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>
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: /*@C
24: PetscLogObjectMemory - Adds to an object a count of additional amount of memory that is used by the object.
26: Not collective.
28: Input Parameters:
29: + obj - the PETSc object
30: - mem - the amount of memory that is being added to the object
32: Level: developer
34: Developer Notes: Currently we do not always do a good job of associating all memory allocations with an object.
36: .seealso: PetscFinalize(), PetscInitializeFortran(), PetscGetArgs(), PetscInitializeNoArguments()
38: @*/
39: PetscErrorCode PetscLogObjectMemory(PetscObject p,PetscLogDouble m)
40: {
41: if (!p) return 0;
42: p->mem += m;
43: return 0;
44: }
46: PetscLogEvent PETSC_LARGEST_EVENT = PETSC_EVENT;
48: #if defined(PETSC_USE_LOG)
49: #include <petscmachineinfo.h>
50: #include <petscconfiginfo.h>
52: /* used in the MPI_XXX() count macros in petsclog.h */
54: /* Action and object logging variables */
55: Action *petsc_actions = NULL;
56: Object *petsc_objects = NULL;
57: PetscBool petsc_logActions = PETSC_FALSE;
58: PetscBool petsc_logObjects = PETSC_FALSE;
59: int petsc_numActions = 0, petsc_maxActions = 100;
60: int petsc_numObjects = 0, petsc_maxObjects = 100;
61: int petsc_numObjectsDestroyed = 0;
63: /* Global counters */
64: PetscLogDouble petsc_BaseTime = 0.0;
65: PetscLogDouble petsc_TotalFlops = 0.0; /* The number of flops */
66: PetscLogDouble petsc_tmp_flops = 0.0; /* The incremental number of flops */
67: PetscLogDouble petsc_send_ct = 0.0; /* The number of sends */
68: PetscLogDouble petsc_recv_ct = 0.0; /* The number of receives */
69: PetscLogDouble petsc_send_len = 0.0; /* The total length of all sent messages */
70: PetscLogDouble petsc_recv_len = 0.0; /* The total length of all received messages */
71: PetscLogDouble petsc_isend_ct = 0.0; /* The number of immediate sends */
72: PetscLogDouble petsc_irecv_ct = 0.0; /* The number of immediate receives */
73: PetscLogDouble petsc_isend_len = 0.0; /* The total length of all immediate send messages */
74: PetscLogDouble petsc_irecv_len = 0.0; /* The total length of all immediate receive messages */
75: PetscLogDouble petsc_wait_ct = 0.0; /* The number of waits */
76: PetscLogDouble petsc_wait_any_ct = 0.0; /* The number of anywaits */
77: PetscLogDouble petsc_wait_all_ct = 0.0; /* The number of waitalls */
78: PetscLogDouble petsc_sum_of_waits_ct = 0.0; /* The total number of waits */
79: PetscLogDouble petsc_allreduce_ct = 0.0; /* The number of reductions */
80: PetscLogDouble petsc_gather_ct = 0.0; /* The number of gathers and gathervs */
81: PetscLogDouble petsc_scatter_ct = 0.0; /* The number of scatters and scattervs */
83: /* Logging functions */
84: PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL;
85: PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL;
86: PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
87: PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
89: /* Tracing event logging variables */
90: FILE *petsc_tracefile = NULL;
91: int petsc_tracelevel = 0;
92: const char *petsc_traceblanks = " ";
93: char petsc_tracespace[128] = " ";
94: PetscLogDouble petsc_tracetime = 0.0;
95: static PetscBool PetscLogInitializeCalled = PETSC_FALSE;
97: /*---------------------------------------------- General Functions --------------------------------------------------*/
98: /*@C
99: PetscLogDestroy - Destroys the object and event logging data and resets the global counters.
101: Not Collective
103: Notes:
104: This routine should not usually be used by programmers. Instead employ
105: PetscLogStagePush() and PetscLogStagePop().
107: Level: developer
109: .keywords: log, destroy
110: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogStagePush(), PlogStagePop()
111: @*/
112: PetscErrorCode PetscLogDestroy(void)
113: {
114: PetscStageLog stageLog;
118: PetscFree(petsc_actions);
119: PetscFree(petsc_objects);
120: PetscLogNestedEnd();
121: PetscLogSet(NULL, NULL);
123: /* Resetting phase */
124: PetscLogGetStageLog(&stageLog);
125: PetscStageLogDestroy(stageLog);
127: petsc_TotalFlops = 0.0;
128: petsc_numActions = 0;
129: petsc_numObjects = 0;
130: petsc_numObjectsDestroyed = 0;
131: petsc_maxActions = 100;
132: petsc_maxObjects = 100;
133: petsc_actions = NULL;
134: petsc_objects = NULL;
135: petsc_logActions = PETSC_FALSE;
136: petsc_logObjects = PETSC_FALSE;
137: petsc_BaseTime = 0.0;
138: petsc_TotalFlops = 0.0;
139: petsc_tmp_flops = 0.0;
140: petsc_send_ct = 0.0;
141: petsc_recv_ct = 0.0;
142: petsc_send_len = 0.0;
143: petsc_recv_len = 0.0;
144: petsc_isend_ct = 0.0;
145: petsc_irecv_ct = 0.0;
146: petsc_isend_len = 0.0;
147: petsc_irecv_len = 0.0;
148: petsc_wait_ct = 0.0;
149: petsc_wait_any_ct = 0.0;
150: petsc_wait_all_ct = 0.0;
151: petsc_sum_of_waits_ct = 0.0;
152: petsc_allreduce_ct = 0.0;
153: petsc_gather_ct = 0.0;
154: petsc_scatter_ct = 0.0;
155: PETSC_LARGEST_EVENT = PETSC_EVENT;
156: PetscLogPHC = NULL;
157: PetscLogPHD = NULL;
158: petsc_tracefile = NULL;
159: petsc_tracelevel = 0;
160: petsc_traceblanks = " ";
161: petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0;
162: petsc_tracetime = 0.0;
163: PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
164: PETSC_OBJECT_CLASSID = 0;
165: petsc_stageLog = 0;
166: PetscLogInitializeCalled = PETSC_FALSE;
167: return(0);
168: }
170: /*@C
171: PetscLogSet - Sets the logging functions called at the beginning and ending of every event.
173: Not Collective
175: Input Parameters:
176: + b - The function called at beginning of event
177: - e - The function called at end of event
179: Level: developer
181: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogTraceBegin()
182: @*/
183: PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject),
184: PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject))
185: {
187: PetscLogPLB = b;
188: PetscLogPLE = e;
189: return(0);
190: }
192: /*------------------------------------------- Initialization Functions ----------------------------------------------*/
193: /*
194: The data structures for logging are always created even if no logging is turned on. This is so events etc can
195: be registered in the code before the actually logging is turned on.
196: */
197: PetscErrorCode PetscLogInitialize(void)
198: {
199: int stage;
200: PetscBool opt;
204: if (PetscLogInitializeCalled) return(0);
205: PetscLogInitializeCalled = PETSC_TRUE;
207: PetscOptionsHasName(NULL,NULL, "-log_exclude_actions", &opt);
208: if (opt) petsc_logActions = PETSC_FALSE;
209: PetscOptionsHasName(NULL,NULL, "-log_exclude_objects", &opt);
210: if (opt) petsc_logObjects = PETSC_FALSE;
211: if (petsc_logActions) {
212: PetscMalloc1(petsc_maxActions, &petsc_actions);
213: }
214: if (petsc_logObjects) {
215: PetscMalloc1(petsc_maxObjects, &petsc_objects);
216: }
217: PetscLogPHC = PetscLogObjCreateDefault;
218: PetscLogPHD = PetscLogObjDestroyDefault;
219: /* Setup default logging structures */
220: PetscStageLogCreate(&petsc_stageLog);
221: PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);
223: /* All processors sync here for more consistent logging */
224: MPI_Barrier(PETSC_COMM_WORLD);
225: PetscTime(&petsc_BaseTime);
226: PetscLogStagePush(stage);
227: return(0);
228: }
230: /*@C
231: PetscLogDefaultBegin - Turns on logging of objects and events. This logs flop
232: rates and object creation and should not slow programs down too much.
233: This routine may be called more than once.
235: Logically Collective over PETSC_COMM_WORLD
237: Options Database Keys:
238: . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the
239: screen (for code configured with --with-log=1 (which is the default))
241: Usage:
242: .vb
243: PetscInitialize(...);
244: PetscLogDefaultBegin();
245: ... code ...
246: PetscLogView(viewer); or PetscLogDump();
247: PetscFinalize();
248: .ve
250: Notes:
251: PetscLogView(viewer) or PetscLogDump() actually cause the printing of
252: the logging information.
254: Level: advanced
256: .keywords: log, begin
257: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin()
258: @*/
259: PetscErrorCode PetscLogDefaultBegin(void)
260: {
264: PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
265: return(0);
266: }
268: /*@C
269: PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
270: all events. This creates large log files and slows the program down.
272: Logically Collective on PETSC_COMM_WORLD
274: Options Database Keys:
275: . -log_all - Prints extensive log information
277: Usage:
278: .vb
279: PetscInitialize(...);
280: PetscLogAllBegin();
281: ... code ...
282: PetscLogDump(filename);
283: PetscFinalize();
284: .ve
286: Notes:
287: A related routine is PetscLogDefaultBegin() (with the options key -log), which is
288: intended for production runs since it logs only flop rates and object
289: creation (and shouldn't significantly slow the programs).
291: Level: advanced
293: .keywords: log, all, begin
294: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogTraceBegin()
295: @*/
296: PetscErrorCode PetscLogAllBegin(void)
297: {
301: PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
302: return(0);
303: }
305: /*@
306: PetscLogTraceBegin - Activates trace logging. Every time a PETSc event
307: begins or ends, the event name is printed.
309: Logically Collective on PETSC_COMM_WORLD
311: Input Parameter:
312: . file - The file to print trace in (e.g. stdout)
314: Options Database Key:
315: . -log_trace [filename] - Activates PetscLogTraceBegin()
317: Notes:
318: PetscLogTraceBegin() prints the processor number, the execution time (sec),
319: then "Event begin:" or "Event end:" followed by the event name.
321: PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
322: to determine where a program is hanging without running in the
323: debugger. Can be used in conjunction with the -info option.
325: Level: intermediate
327: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogDefaultBegin()
328: @*/
329: PetscErrorCode PetscLogTraceBegin(FILE *file)
330: {
334: petsc_tracefile = file;
336: PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
337: return(0);
338: }
340: /*@
341: PetscLogActions - Determines whether actions are logged for the graphical viewer.
343: Not Collective
345: Input Parameter:
346: . flag - PETSC_TRUE if actions are to be logged
348: Level: intermediate
350: Note: Logging of actions continues to consume more memory as the program
351: runs. Long running programs should consider turning this feature off.
353: Options Database Keys:
354: . -log_exclude_actions - Turns off actions logging
356: .keywords: log, stage, register
357: .seealso: PetscLogStagePush(), PetscLogStagePop()
358: @*/
359: PetscErrorCode PetscLogActions(PetscBool flag)
360: {
362: petsc_logActions = flag;
363: return(0);
364: }
366: /*@
367: PetscLogObjects - Determines whether objects are logged for the graphical viewer.
369: Not Collective
371: Input Parameter:
372: . flag - PETSC_TRUE if objects are to be logged
374: Level: intermediate
376: Note: Logging of objects continues to consume more memory as the program
377: runs. Long running programs should consider turning this feature off.
379: Options Database Keys:
380: . -log_exclude_objects - Turns off objects logging
382: .keywords: log, stage, register
383: .seealso: PetscLogStagePush(), PetscLogStagePop()
384: @*/
385: PetscErrorCode PetscLogObjects(PetscBool flag)
386: {
388: petsc_logObjects = flag;
389: return(0);
390: }
392: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
393: /*@C
394: PetscLogStageRegister - Attaches a character string name to a logging stage.
396: Not Collective
398: Input Parameter:
399: . sname - The name to associate with that stage
401: Output Parameter:
402: . stage - The stage number
404: Level: intermediate
406: .keywords: log, stage, register
407: .seealso: PetscLogStagePush(), PetscLogStagePop()
408: @*/
409: PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage)
410: {
411: PetscStageLog stageLog;
412: PetscLogEvent event;
416: PetscLogGetStageLog(&stageLog);
417: PetscStageLogRegister(stageLog, sname, stage);
418: /* Copy events already changed in the main stage, this sucks */
419: PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
420: for (event = 0; event < stageLog->eventLog->numEvents; event++) {
421: PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
422: }
423: PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
424: return(0);
425: }
427: /*@C
428: PetscLogStagePush - This function pushes a stage on the stack.
430: Not Collective
432: Input Parameter:
433: . stage - The stage on which to log
435: Usage:
436: If the option -log_sumary is used to run the program containing the
437: following code, then 2 sets of summary data will be printed during
438: PetscFinalize().
439: .vb
440: PetscInitialize(int *argc,char ***args,0,0);
441: [stage 0 of code]
442: PetscLogStagePush(1);
443: [stage 1 of code]
444: PetscLogStagePop();
445: PetscBarrier(...);
446: [more stage 0 of code]
447: PetscFinalize();
448: .ve
450: Notes:
451: Use PetscLogStageRegister() to register a stage.
453: Level: intermediate
455: .keywords: log, push, stage
456: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
457: @*/
458: PetscErrorCode PetscLogStagePush(PetscLogStage stage)
459: {
460: PetscStageLog stageLog;
464: PetscLogGetStageLog(&stageLog);
465: PetscStageLogPush(stageLog, stage);
466: return(0);
467: }
469: /*@C
470: PetscLogStagePop - This function pops a stage from the stack.
472: Not Collective
474: Usage:
475: If the option -log_sumary is used to run the program containing the
476: following code, then 2 sets of summary data will be printed during
477: PetscFinalize().
478: .vb
479: PetscInitialize(int *argc,char ***args,0,0);
480: [stage 0 of code]
481: PetscLogStagePush(1);
482: [stage 1 of code]
483: PetscLogStagePop();
484: PetscBarrier(...);
485: [more stage 0 of code]
486: PetscFinalize();
487: .ve
489: Notes:
490: Use PetscLogStageRegister() to register a stage.
492: Level: intermediate
494: .keywords: log, pop, stage
495: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
496: @*/
497: PetscErrorCode PetscLogStagePop(void)
498: {
499: PetscStageLog stageLog;
503: PetscLogGetStageLog(&stageLog);
504: PetscStageLogPop(stageLog);
505: return(0);
506: }
508: /*@
509: PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().
511: Not Collective
513: Input Parameters:
514: + stage - The stage
515: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
517: Level: intermediate
519: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
520: @*/
521: PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive)
522: {
523: PetscStageLog stageLog;
527: PetscLogGetStageLog(&stageLog);
528: PetscStageLogSetActive(stageLog, stage, isActive);
529: return(0);
530: }
532: /*@
533: PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().
535: Not Collective
537: Input Parameter:
538: . stage - The stage
540: Output Parameter:
541: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
543: Level: intermediate
545: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
546: @*/
547: PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive)
548: {
549: PetscStageLog stageLog;
553: PetscLogGetStageLog(&stageLog);
554: PetscStageLogGetActive(stageLog, stage, isActive);
555: return(0);
556: }
558: /*@
559: PetscLogStageSetVisible - Determines stage visibility in PetscLogView()
561: Not Collective
563: Input Parameters:
564: + stage - The stage
565: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
567: Level: intermediate
569: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
570: @*/
571: PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible)
572: {
573: PetscStageLog stageLog;
577: PetscLogGetStageLog(&stageLog);
578: PetscStageLogSetVisible(stageLog, stage, isVisible);
579: return(0);
580: }
582: /*@
583: PetscLogStageGetVisible - Returns stage visibility in PetscLogView()
585: Not Collective
587: Input Parameter:
588: . stage - The stage
590: Output Parameter:
591: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
593: Level: intermediate
595: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
596: @*/
597: PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible)
598: {
599: PetscStageLog stageLog;
603: PetscLogGetStageLog(&stageLog);
604: PetscStageLogGetVisible(stageLog, stage, isVisible);
605: return(0);
606: }
608: /*@C
609: PetscLogStageGetId - Returns the stage id when given the stage name.
611: Not Collective
613: Input Parameter:
614: . name - The stage name
616: Output Parameter:
617: . stage - The stage, , or -1 if no stage with that name exists
619: Level: intermediate
621: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
622: @*/
623: PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage)
624: {
625: PetscStageLog stageLog;
629: PetscLogGetStageLog(&stageLog);
630: PetscStageLogGetStage(stageLog, name, stage);
631: return(0);
632: }
634: /*------------------------------------------------ Event Functions --------------------------------------------------*/
635: /*@C
636: PetscLogEventRegister - Registers an event name for logging operations in an application code.
638: Not Collective
640: Input Parameter:
641: + name - The name associated with the event
642: - classid - The classid associated to the class for this event, obtain either with
643: PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones
644: are only available in C code
646: Output Parameter:
647: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().
649: Example of Usage:
650: .vb
651: PetscLogEvent USER_EVENT;
652: PetscClassId classid;
653: PetscLogDouble user_event_flops;
654: PetscClassIdRegister("class name",&classid);
655: PetscLogEventRegister("User event name",classid,&USER_EVENT);
656: PetscLogEventBegin(USER_EVENT,0,0,0,0);
657: [code segment to monitor]
658: PetscLogFlops(user_event_flops);
659: PetscLogEventEnd(USER_EVENT,0,0,0,0);
660: .ve
662: Notes:
663: PETSc automatically logs library events if the code has been
664: configured with --with-log (which is the default) and
665: -log_view or -log_all is specified. PetscLogEventRegister() is
666: intended for logging user events to supplement this PETSc
667: information.
669: PETSc can gather data for use with the utilities Jumpshot
670: (part of the MPICH distribution). If PETSc has been compiled
671: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
672: MPICH), the user can employ another command line option, -log_mpe,
673: to create a logfile, "mpe.log", which can be visualized
674: Jumpshot.
676: The classid is associated with each event so that classes of events
677: can be disabled simultaneously, such as all matrix events. The user
678: can either use an existing classid, such as MAT_CLASSID, or create
679: their own as shown in the example.
681: If an existing event with the same name exists, its event handle is
682: returned instead of creating a new event.
684: Level: intermediate
686: .keywords: log, event, register
687: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
688: PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister()
689: @*/
690: PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event)
691: {
692: PetscStageLog stageLog;
693: int stage;
697: *event = PETSC_DECIDE;
698: PetscLogGetStageLog(&stageLog);
699: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
700: if (*event > 0) return(0);
701: PetscEventRegLogRegister(stageLog->eventLog, name, classid, event);
702: for (stage = 0; stage < stageLog->numStages; stage++) {
703: PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
704: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
705: }
706: return(0);
707: }
709: /*@
710: PetscLogEventActivate - Indicates that a particular event should be logged.
712: Not Collective
714: Input Parameter:
715: . event - The event id
717: Usage:
718: .vb
719: PetscLogEventDeactivate(VEC_SetValues);
720: [code where you do not want to log VecSetValues()]
721: PetscLogEventActivate(VEC_SetValues);
722: [code where you do want to log VecSetValues()]
723: .ve
725: Note:
726: The event may be either a pre-defined PETSc event (found in include/petsclog.h)
727: or an event number obtained with PetscLogEventRegister().
729: Level: advanced
731: .keywords: log, event, activate
732: .seealso: PlogEventDeactivate()
733: @*/
734: PetscErrorCode PetscLogEventActivate(PetscLogEvent event)
735: {
736: PetscStageLog stageLog;
737: int stage;
741: PetscLogGetStageLog(&stageLog);
742: PetscStageLogGetCurrent(stageLog, &stage);
743: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
744: return(0);
745: }
747: /*@
748: PetscLogEventDeactivate - Indicates that a particular event should not be logged.
750: Not Collective
752: Input Parameter:
753: . event - The event id
755: Usage:
756: .vb
757: PetscLogEventDeactivate(VEC_SetValues);
758: [code where you do not want to log VecSetValues()]
759: PetscLogEventActivate(VEC_SetValues);
760: [code where you do want to log VecSetValues()]
761: .ve
763: Note:
764: The event may be either a pre-defined PETSc event (found in
765: include/petsclog.h) or an event number obtained with PetscLogEventRegister()).
767: Level: advanced
769: .keywords: log, event, deactivate
770: .seealso: PlogEventActivate()
771: @*/
772: PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event)
773: {
774: PetscStageLog stageLog;
775: int stage;
779: PetscLogGetStageLog(&stageLog);
780: PetscStageLogGetCurrent(stageLog, &stage);
781: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
782: return(0);
783: }
785: /*@
786: PetscLogEventSetActiveAll - Sets the event activity in every stage.
788: Not Collective
790: Input Parameters:
791: + event - The event id
792: - isActive - The activity flag determining whether the event is logged
794: Level: advanced
796: .keywords: log, event, activate
797: .seealso: PlogEventActivate(),PlogEventDeactivate()
798: @*/
799: PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive)
800: {
801: PetscStageLog stageLog;
802: int stage;
806: PetscLogGetStageLog(&stageLog);
807: for (stage = 0; stage < stageLog->numStages; stage++) {
808: if (isActive) {
809: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
810: } else {
811: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
812: }
813: }
814: return(0);
815: }
817: /*@
818: PetscLogEventActivateClass - Activates event logging for a PETSc object class.
820: Not Collective
822: Input Parameter:
823: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
825: Level: developer
827: .keywords: log, event, activate, class
828: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
829: @*/
830: PetscErrorCode PetscLogEventActivateClass(PetscClassId classid)
831: {
832: PetscStageLog stageLog;
833: int stage;
837: PetscLogGetStageLog(&stageLog);
838: PetscStageLogGetCurrent(stageLog, &stage);
839: PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
840: return(0);
841: }
843: /*@
844: PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.
846: Not Collective
848: Input Parameter:
849: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
851: Level: developer
853: .keywords: log, event, deactivate, class
854: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
855: @*/
856: PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid)
857: {
858: PetscStageLog stageLog;
859: int stage;
863: PetscLogGetStageLog(&stageLog);
864: PetscStageLogGetCurrent(stageLog, &stage);
865: PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
866: return(0);
867: }
869: /*MC
870: PetscLogEventBegin - Logs the beginning of a user event.
872: Synopsis:
873: #include <petsclog.h>
874: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
876: Not Collective
878: Input Parameters:
879: + e - integer associated with the event obtained from PetscLogEventRegister()
880: - o1,o2,o3,o4 - objects associated with the event, or 0
883: Fortran Synopsis:
884: void PetscLogEventBegin(int e,PetscErrorCode ierr)
886: Usage:
887: .vb
888: PetscLogEvent USER_EVENT;
889: PetscLogDouble user_event_flops;
890: PetscLogEventRegister("User event",0,&USER_EVENT);
891: PetscLogEventBegin(USER_EVENT,0,0,0,0);
892: [code segment to monitor]
893: PetscLogFlops(user_event_flops);
894: PetscLogEventEnd(USER_EVENT,0,0,0,0);
895: .ve
897: Notes:
898: You need to register each integer event with the command
899: PetscLogEventRegister().
901: Level: intermediate
903: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
905: .keywords: log, event, begin
906: M*/
908: /*MC
909: PetscLogEventEnd - Log the end of a user event.
911: Synopsis:
912: #include <petsclog.h>
913: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
915: Not Collective
917: Input Parameters:
918: + e - integer associated with the event obtained with PetscLogEventRegister()
919: - o1,o2,o3,o4 - objects associated with the event, or 0
922: Fortran Synopsis:
923: void PetscLogEventEnd(int e,PetscErrorCode ierr)
925: Usage:
926: .vb
927: PetscLogEvent USER_EVENT;
928: PetscLogDouble user_event_flops;
929: PetscLogEventRegister("User event",0,&USER_EVENT,);
930: PetscLogEventBegin(USER_EVENT,0,0,0,0);
931: [code segment to monitor]
932: PetscLogFlops(user_event_flops);
933: PetscLogEventEnd(USER_EVENT,0,0,0,0);
934: .ve
936: Notes:
937: You should also register each additional integer event with the command
938: PetscLogEventRegister().
940: Level: intermediate
942: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
944: .keywords: log, event, end
945: M*/
947: /*MC
948: PetscLogEventBarrierBegin - Logs the time in a barrier before an event.
950: Synopsis:
951: #include <petsclog.h>
952: PetscErrorCode PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
954: Not Collective
956: Input Parameters:
957: . e - integer associated with the event obtained from PetscLogEventRegister()
958: . o1,o2,o3,o4 - objects associated with the event, or 0
959: . comm - communicator the barrier takes place over
962: Usage:
963: .vb
964: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
965: MPIU_Allreduce()
966: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
967: .ve
969: Notes:
970: This is for logging the amount of time spent in a barrier for an event
971: that requires synchronization.
973: Additional Notes:
974: Synchronization events always come in pairs; for example, VEC_NormBarrier and
975: VEC_NormComm = VEC_NormBarrier + 1
977: Level: advanced
979: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
980: PetscLogEventBarrierEnd()
982: .keywords: log, event, begin, barrier
983: M*/
985: /*MC
986: PetscLogEventBarrierEnd - Logs the time in a barrier before an event.
988: Synopsis:
989: #include <petsclog.h>
990: PetscErrorCode PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
992: Logically Collective on MPI_Comm
994: Input Parameters:
995: . e - integer associated with the event obtained from PetscLogEventRegister()
996: . o1,o2,o3,o4 - objects associated with the event, or 0
997: . comm - communicator the barrier takes place over
1000: Usage:
1001: .vb
1002: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1003: MPIU_Allreduce()
1004: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1005: .ve
1007: Notes:
1008: This is for logging the amount of time spent in a barrier for an event
1009: that requires synchronization.
1011: Additional Notes:
1012: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1013: VEC_NormComm = VEC_NormBarrier + 1
1015: Level: advanced
1017: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1018: PetscLogEventBarrierBegin()
1020: .keywords: log, event, begin, barrier
1021: M*/
1023: /*@C
1024: PetscLogEventGetId - Returns the event id when given the event name.
1026: Not Collective
1028: Input Parameter:
1029: . name - The event name
1031: Output Parameter:
1032: . event - The event, or -1 if no event with that name exists
1034: Level: intermediate
1036: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1037: @*/
1038: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1039: {
1040: PetscStageLog stageLog;
1044: PetscLogGetStageLog(&stageLog);
1045: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
1046: return(0);
1047: }
1050: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1051: /*@C
1052: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1053: be read by bin/petscview. This program no longer exists.
1055: Collective on PETSC_COMM_WORLD
1057: Input Parameter:
1058: . name - an optional file name
1060: Usage:
1061: .vb
1062: PetscInitialize(...);
1063: PetscLogDefaultBegin(); or PetscLogAllBegin();
1064: ... code ...
1065: PetscLogDump(filename);
1066: PetscFinalize();
1067: .ve
1069: Notes:
1070: The default file name is
1071: $ Log.<rank>
1072: where <rank> is the processor number. If no name is specified,
1073: this file will be used.
1075: Level: advanced
1077: .keywords: log, dump
1078: .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView()
1079: @*/
1080: PetscErrorCode PetscLogDump(const char sname[])
1081: {
1082: PetscStageLog stageLog;
1083: PetscEventPerfInfo *eventInfo;
1084: FILE *fd;
1085: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1086: PetscLogDouble flops, _TotalTime;
1087: PetscMPIInt rank;
1088: int action, object, curStage;
1089: PetscLogEvent event;
1090: PetscErrorCode ierr;
1093: /* Calculate the total elapsed time */
1094: PetscTime(&_TotalTime);
1095: _TotalTime -= petsc_BaseTime;
1096: /* Open log file */
1097: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1098: if (sname) sprintf(file, "%s.%d", sname, rank);
1099: else sprintf(file, "Log.%d", rank);
1100: PetscFixFilename(file, fname);
1101: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1102: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1103: /* Output totals */
1104: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1105: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1106: /* Output actions */
1107: if (petsc_logActions) {
1108: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1109: for (action = 0; action < petsc_numActions; action++) {
1110: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1111: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1112: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1113: }
1114: }
1115: /* Output objects */
1116: if (petsc_logObjects) {
1117: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1118: for (object = 0; object < petsc_numObjects; object++) {
1119: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1120: if (!petsc_objects[object].name[0]) {
1121: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1122: } else {
1123: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1124: }
1125: if (petsc_objects[object].info[0] != 0) {
1126: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1127: } else {
1128: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1129: }
1130: }
1131: }
1132: /* Output events */
1133: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1134: PetscLogGetStageLog(&stageLog);
1135: PetscIntStackTop(stageLog->stack, &curStage);
1136: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1137: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1138: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1139: else flops = 0.0;
1140: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1141: eventInfo[event].flops, eventInfo[event].time, flops);
1142: }
1143: PetscFClose(PETSC_COMM_WORLD, fd);
1144: return(0);
1145: }
1147: /*
1148: PetscLogView_Detailed - Each process prints the times for its own events
1150: */
1151: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1152: {
1153: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1154: PetscEventPerfInfo *eventInfo = NULL;
1155: PetscLogDouble locTotalTime, numRed, maxMem;
1156: PetscStageLog stageLog;
1157: int numStages,numEvents,stage,event;
1158: PetscMPIInt rank,size;
1159: PetscErrorCode ierr;
1162: MPI_Comm_size(comm, &size);
1163: MPI_Comm_rank(comm, &rank);
1164: /* Must preserve reduction count before we go on */
1165: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1166: /* Get the total elapsed time */
1167: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1168: PetscViewerASCIIPrintf(viewer,"size = %d\n",size);
1169: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1170: PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");
1171: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1172: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1173: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1174: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1175: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1176: PetscLogGetStageLog(&stageLog);
1177: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1178: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1179: for (stage=0; stage<numStages; stage++) {
1180: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1181: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1182: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1183: for (event = 0; event < numEvents; event++) {
1184: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1185: }
1186: }
1187: PetscViewerASCIIPushSynchronized(viewer);
1188: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1189: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);
1190: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1191: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1192: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1193: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);
1194: PetscMallocGetMaximumUsage(&maxMem);
1195: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1196: PetscViewerFlush(viewer);
1197: for (stage=0; stage<numStages; stage++) {
1198: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",
1199: stageLog->stageInfo[stage].name,rank,
1200: stageLog->stageInfo[stage].perfInfo.time,stageLog->stageInfo[stage].perfInfo.numMessages,stageLog->stageInfo[stage].perfInfo.messageLength,
1201: stageLog->stageInfo[stage].perfInfo.numReductions,stageLog->stageInfo[stage].perfInfo.flops);
1202: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1203: for (event = 0; event < numEvents; event++) {
1204: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1205: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank,
1206: eventInfo[event].count, eventInfo[event].time,eventInfo[event].numMessages, eventInfo[event].messageLength,
1207: eventInfo[event].numReductions,eventInfo[event].flops);
1208: }
1209: }
1210: PetscViewerFlush(viewer);
1211: PetscViewerASCIIPopSynchronized(viewer);
1212: return(0);
1213: }
1215: static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd)
1216: {
1217: #if defined(PETSC_USE_DEBUG)
1221: PetscFPrintf(comm, fd, "\n\n");
1222: PetscFPrintf(comm, fd, " ##########################################################\n");
1223: PetscFPrintf(comm, fd, " # #\n");
1224: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1225: PetscFPrintf(comm, fd, " # #\n");
1226: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");
1227: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1228: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1229: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1230: PetscFPrintf(comm, fd, " # #\n");
1231: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1232: return(0);
1233: #else
1234: return 0;
1235: #endif
1236: }
1238: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1239: {
1240: FILE *fd;
1241: PetscLogDouble zero = 0.0;
1242: PetscStageLog stageLog;
1243: PetscStageInfo *stageInfo = NULL;
1244: PetscEventPerfInfo *eventInfo = NULL;
1245: PetscClassPerfInfo *classInfo;
1246: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1247: const char *name;
1248: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1249: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1250: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1251: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1252: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1253: PetscLogDouble min, max, tot, ratio, avg, x, y;
1254: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr;
1255: PetscMPIInt minCt, maxCt;
1256: PetscMPIInt size, rank;
1257: PetscBool *localStageUsed, *stageUsed;
1258: PetscBool *localStageVisible, *stageVisible;
1259: int numStages, localNumEvents, numEvents;
1260: int stage, oclass;
1261: PetscLogEvent event;
1262: PetscErrorCode ierr;
1263: char version[256];
1264: MPI_Comm comm;
1267: PetscObjectGetComm((PetscObject)viewer,&comm);
1268: PetscViewerASCIIGetPointer(viewer,&fd);
1269: MPI_Comm_size(comm, &size);
1270: MPI_Comm_rank(comm, &rank);
1271: /* Get the total elapsed time */
1272: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1274: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1275: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1276: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1277: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1278: PetscLogViewWarnDebugging(comm,fd);
1279: PetscGetArchType(arch,sizeof(arch));
1280: PetscGetHostName(hostname,sizeof(hostname));
1281: PetscGetUserName(username,sizeof(username));
1282: PetscGetProgramName(pname,sizeof(pname));
1283: PetscGetDate(date,sizeof(date));
1284: PetscGetVersion(version,sizeof(version));
1285: if (size == 1) {
1286: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1287: } else {
1288: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1289: }
1291: PetscFPrintf(comm, fd, "Using %s\n", version);
1293: /* Must preserve reduction count before we go on */
1294: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1296: /* Calculate summary information */
1297: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1298: /* Time */
1299: MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1300: MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1301: MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1302: avg = (tot)/((PetscLogDouble) size);
1303: if (min != 0.0) ratio = max/min;
1304: else ratio = 0.0;
1305: PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);
1306: TotalTime = tot;
1307: /* Objects */
1308: avg = (PetscLogDouble) petsc_numObjects;
1309: MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1310: MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1311: MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1312: avg = (tot)/((PetscLogDouble) size);
1313: if (min != 0.0) ratio = max/min;
1314: else ratio = 0.0;
1315: PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);
1316: /* Flops */
1317: MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1318: MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1319: MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1320: avg = (tot)/((PetscLogDouble) size);
1321: if (min != 0.0) ratio = max/min;
1322: else ratio = 0.0;
1323: PetscFPrintf(comm, fd, "Flop: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1324: TotalFlops = tot;
1325: /* Flops/sec -- Must talk to Barry here */
1326: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime;
1327: else flops = 0.0;
1328: MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1329: MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1330: MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1331: avg = (tot)/((PetscLogDouble) size);
1332: if (min != 0.0) ratio = max/min;
1333: else ratio = 0.0;
1334: PetscFPrintf(comm, fd, "Flop/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1335: /* Memory */
1336: PetscMallocGetMaximumUsage(&mem);
1337: if (mem > 0.0) {
1338: MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1339: MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1340: MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1341: avg = (tot)/((PetscLogDouble) size);
1342: if (min != 0.0) ratio = max/min;
1343: else ratio = 0.0;
1344: PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);
1345: }
1346: /* Messages */
1347: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1348: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1349: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1350: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1351: avg = (tot)/((PetscLogDouble) size);
1352: if (min != 0.0) ratio = max/min;
1353: else ratio = 0.0;
1354: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1355: numMessages = tot;
1356: /* Message Lengths */
1357: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1358: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1359: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1360: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1361: if (numMessages != 0) avg = (tot)/(numMessages);
1362: else avg = 0.0;
1363: if (min != 0.0) ratio = max/min;
1364: else ratio = 0.0;
1365: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1366: messageLength = tot;
1367: /* Reductions */
1368: MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1369: MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1370: MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1371: if (min != 0.0) ratio = max/min;
1372: else ratio = 0.0;
1373: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);
1374: numReductions = red; /* wrong because uses count from process zero */
1375: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1376: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");
1377: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");
1379: /* Get total number of stages --
1380: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1381: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1382: This seems best accomplished by assoicating a communicator with each stage.
1383: */
1384: PetscLogGetStageLog(&stageLog);
1385: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1386: PetscMalloc1(numStages, &localStageUsed);
1387: PetscMalloc1(numStages, &stageUsed);
1388: PetscMalloc1(numStages, &localStageVisible);
1389: PetscMalloc1(numStages, &stageVisible);
1390: if (numStages > 0) {
1391: stageInfo = stageLog->stageInfo;
1392: for (stage = 0; stage < numStages; stage++) {
1393: if (stage < stageLog->numStages) {
1394: localStageUsed[stage] = stageInfo[stage].used;
1395: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1396: } else {
1397: localStageUsed[stage] = PETSC_FALSE;
1398: localStageVisible[stage] = PETSC_TRUE;
1399: }
1400: }
1401: MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1402: MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1403: for (stage = 0; stage < numStages; stage++) {
1404: if (stageUsed[stage]) {
1405: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");
1406: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");
1407: break;
1408: }
1409: }
1410: for (stage = 0; stage < numStages; stage++) {
1411: if (!stageUsed[stage]) continue;
1412: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1413: if (localStageUsed[stage]) {
1414: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1415: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1416: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1417: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1418: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1419: name = stageInfo[stage].name;
1420: } else {
1421: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1422: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1423: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1424: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1425: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1426: name = "";
1427: }
1428: mess *= 0.5; messLen *= 0.5; red /= size;
1429: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1430: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1431: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1432: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1433: if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0;
1434: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1435: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1436: 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",
1437: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1438: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1439: }
1440: }
1442: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1443: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1444: PetscFPrintf(comm, fd, "Phase summary info:\n");
1445: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1446: PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");
1447: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1448: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1449: PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");
1450: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1451: PetscFPrintf(comm, fd, " Global: entire computation\n");
1452: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1453: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");
1454: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1455: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1456: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");
1457: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1459: PetscLogViewWarnDebugging(comm,fd);
1461: /* Report events */
1462: PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage --- Total\n");
1463: 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");
1464: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1466: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1467: for (stage = 0; stage < numStages; stage++) {
1468: if (!stageVisible[stage]) continue;
1469: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1470: if (localStageUsed[stage]) {
1471: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1472: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1473: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1474: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1475: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1476: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1477: } else {
1478: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1479: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1480: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1481: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1482: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1483: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1484: }
1485: mess *= 0.5; messLen *= 0.5; red /= size;
1487: /* Get total number of events in this stage --
1488: Currently, a single processor can register more events than another, but events must all be registered in order,
1489: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1490: on the event ID. This seems best accomplished by assoicating a communicator with each stage.
1492: Problem: If the event did not happen on proc 1, its name will not be available.
1493: Problem: Event visibility is not implemented
1494: */
1495: if (localStageUsed[stage]) {
1496: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1497: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1498: } else localNumEvents = 0;
1499: MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1500: for (event = 0; event < numEvents; event++) {
1501: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1502: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1503: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops;
1504: else flopr = 0.0;
1506: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1507: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1508: MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1509: MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1510: MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1511: MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1512: MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1513: MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1514: MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1515: MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);
1516: MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1517: name = stageLog->eventLog->eventInfo[event].name;
1518: } else {
1519: flopr = 0.0;
1520: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1521: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1522: MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1523: MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1524: MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1525: MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1526: MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1527: MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1528: MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1529: MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);
1530: MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1531: name = "";
1532: }
1533: if (mint < 0.0) {
1534: 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);
1535: mint = 0;
1536: }
1537: if (minf < 0.0) SETERRQ2(PETSC_COMM_SELF,PETSC_ERR_PLIB,"Minimum flop %g over all processors for %s is negative! Not possible!",minf,name);
1538: totm *= 0.5; totml *= 0.5; totr /= size;
1540: if (maxCt != 0) {
1541: if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0;
1542: if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0;
1543: if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0;
1544: if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0;
1545: if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0;
1546: if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0;
1547: if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0;
1548: if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0;
1549: if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0;
1550: if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0;
1551: if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0;
1552: if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0;
1553: if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0;
1554: if (totm != 0.0) totml /= totm; else totml = 0.0;
1555: if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0;
1556: if (fracStageTime > 1.00) PetscFPrintf(comm, fd,"Warning -- total time of event greater than time of entire stage -- something is wrong with the timer\n");
1557: PetscFPrintf(comm, fd,
1558: "%-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",
1559: name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr,
1560: 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
1561: 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
1562: PetscAbs(flopr)/1.0e6);
1563: }
1564: }
1565: }
1567: /* Memory usage and object creation */
1568: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1569: PetscFPrintf(comm, fd, "\n");
1570: PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");
1572: /* Right now, only stages on the first processor are reported here, meaning only objects associated with
1573: the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
1574: stats for stages local to processor sets.
1575: */
1576: /* We should figure out the longest object name here (now 20 characters) */
1577: PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");
1578: PetscFPrintf(comm, fd, "Reports information only for process 0.\n");
1579: for (stage = 0; stage < numStages; stage++) {
1580: if (localStageUsed[stage]) {
1581: classInfo = stageLog->stageInfo[stage].classLog->classInfo;
1582: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1583: for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
1584: if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
1585: PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name,
1586: classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem,
1587: classInfo[oclass].descMem);
1588: }
1589: }
1590: } else {
1591: if (!localStageVisible[stage]) continue;
1592: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1593: }
1594: }
1596: PetscFree(localStageUsed);
1597: PetscFree(stageUsed);
1598: PetscFree(localStageVisible);
1599: PetscFree(stageVisible);
1601: /* Information unrelated to this particular run */
1602: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1603: PetscTime(&y);
1604: PetscTime(&x);
1605: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1606: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1607: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1608: /* MPI information */
1609: if (size > 1) {
1610: MPI_Status status;
1611: PetscMPIInt tag;
1612: MPI_Comm newcomm;
1614: MPI_Barrier(comm);
1615: PetscTime(&x);
1616: MPI_Barrier(comm);
1617: MPI_Barrier(comm);
1618: MPI_Barrier(comm);
1619: MPI_Barrier(comm);
1620: MPI_Barrier(comm);
1621: PetscTime(&y);
1622: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1623: PetscCommDuplicate(comm,&newcomm, &tag);
1624: MPI_Barrier(comm);
1625: if (rank) {
1626: MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);
1627: MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1628: } else {
1629: PetscTime(&x);
1630: MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);
1631: MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);
1632: PetscTime(&y);
1633: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1634: }
1635: PetscCommDestroy(&newcomm);
1636: }
1637: PetscOptionsView(NULL,viewer);
1639: /* Machine and compile information */
1640: #if defined(PETSC_USE_FORTRAN_KERNELS)
1641: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1642: #else
1643: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1644: #endif
1645: #if defined(PETSC_USE_REAL_SINGLE)
1646: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1647: #elif defined(PETSC_USE___FLOAT128)
1648: PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");
1649: #endif
1651: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1652: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1653: #else
1654: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1655: #endif
1656: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1657: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1659: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1660: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1661: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1662: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1663: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1665: /* Cleanup */
1666: PetscFPrintf(comm, fd, "\n");
1667: PetscLogViewWarnDebugging(comm,fd);
1668: return(0);
1669: }
1671: /*@C
1672: PetscLogView - Prints a summary of the logging.
1674: Collective over MPI_Comm
1676: Input Parameter:
1677: . viewer - an ASCII viewer
1679: Options Database Keys:
1680: + -log_view [:filename] - Prints summary of log information
1681: . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file
1682: . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it)
1683: . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation
1684: - -log_trace [filename] - Displays a trace of what each process is doing
1686: Notes:
1687: It is possible to control the logging programatically but we recommend using the options database approach whenever possible
1688: By default the summary is printed to stdout.
1690: Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin()
1692: If PETSc is configured with --with-logging=0 then this functionality is not available
1694: To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current
1695: directory then open filename.xml with your browser. Specific notes for certain browsers
1696: $ Firefox and Internet explorer - simply open the file
1697: $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files
1698: $ Safari - see http://ccm.net/faq/36342-safari-how-to-enable-local-file-access
1699: or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with
1700: your browser.
1702: The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS
1704: Level: beginner
1706: .keywords: log, dump, print
1707: .seealso: PetscLogDefaultBegin(), PetscLogDump()
1708: @*/
1709: PetscErrorCode PetscLogView(PetscViewer viewer)
1710: {
1711: PetscErrorCode ierr;
1712: PetscBool isascii;
1713: PetscViewerFormat format;
1714: int stage, lastStage;
1715: PetscStageLog stageLog;
1718: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
1719: /* Pop off any stages the user forgot to remove */
1720: lastStage = 0;
1721: PetscLogGetStageLog(&stageLog);
1722: PetscStageLogGetCurrent(stageLog, &stage);
1723: while (stage >= 0) {
1724: lastStage = stage;
1725: PetscStageLogPop(stageLog);
1726: PetscStageLogGetCurrent(stageLog, &stage);
1727: }
1728: PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);
1729: if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII");
1730: PetscViewerGetFormat(viewer,&format);
1731: if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) {
1732: PetscLogView_Default(viewer);
1733: } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) {
1734: PetscLogView_Detailed(viewer);
1735: } else if (format == PETSC_VIEWER_ASCII_XML) {
1736: PetscLogView_Nested(viewer);
1737: }
1738: PetscStageLogPush(stageLog, lastStage);
1739: return(0);
1740: }
1742: /*@C
1743: PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed.
1745: Collective on PETSC_COMM_WORLD
1747: Not normally called by user
1749: Level: intermediate
1751: @*/
1752: PetscErrorCode PetscLogViewFromOptions(void)
1753: {
1754: PetscErrorCode ierr;
1755: PetscViewer viewer;
1756: PetscBool flg;
1757: PetscViewerFormat format;
1760: PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);
1761: if (flg) {
1762: PetscViewerPushFormat(viewer,format);
1763: PetscLogView(viewer);
1764: PetscViewerPopFormat(viewer);
1765: PetscViewerDestroy(&viewer);
1766: }
1767: return(0);
1768: }
1772: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
1773: /*@C
1774: PetscGetFlops - Returns the number of flops used on this processor
1775: since the program began.
1777: Not Collective
1779: Output Parameter:
1780: flops - number of floating point operations
1782: Notes:
1783: A global counter logs all PETSc flop counts. The user can use
1784: PetscLogFlops() to increment this counter to include flops for the
1785: application code.
1787: Level: intermediate
1789: .keywords: log, flops, floating point operations
1791: .seealso: PetscTime(), PetscLogFlops()
1792: @*/
1793: PetscErrorCode PetscGetFlops(PetscLogDouble *flops)
1794: {
1796: *flops = petsc_TotalFlops;
1797: return(0);
1798: }
1800: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1801: {
1803: size_t fullLength;
1804: va_list Argp;
1807: if (!petsc_logObjects) return(0);
1808: va_start(Argp, format);
1809: PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);
1810: va_end(Argp);
1811: return(0);
1812: }
1815: /*MC
1816: PetscLogFlops - Adds floating point operations to the global counter.
1818: Synopsis:
1819: #include <petsclog.h>
1820: PetscErrorCode PetscLogFlops(PetscLogDouble f)
1822: Not Collective
1824: Input Parameter:
1825: . f - flop counter
1828: Usage:
1829: .vb
1830: PetscLogEvent USER_EVENT;
1831: PetscLogEventRegister("User event",0,&USER_EVENT);
1832: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1833: [code segment to monitor]
1834: PetscLogFlops(user_flops)
1835: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1836: .ve
1838: Notes:
1839: A global counter logs all PETSc flop counts. The user can use
1840: PetscLogFlops() to increment this counter to include flops for the
1841: application code.
1843: Level: intermediate
1845: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()
1847: .keywords: log, flops, floating point operations
1848: M*/
1850: /*MC
1851: PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice)
1852: to get accurate timings
1854: Synopsis:
1855: #include <petsclog.h>
1856: void PetscPreLoadBegin(PetscBool flag,char *name);
1858: Not Collective
1860: Input Parameter:
1861: + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
1862: with command line option -preload true or -preload false
1863: - name - name of first stage (lines of code timed separately with -log_view) to
1864: be preloaded
1866: Usage:
1867: .vb
1868: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1869: lines of code
1870: PetscPreLoadStage("second stage");
1871: lines of code
1872: PetscPreLoadEnd();
1873: .ve
1875: Notes: Only works in C/C++, not Fortran
1877: Flags available within the macro.
1878: + PetscPreLoadingUsed - true if we are or have done preloading
1879: . PetscPreLoadingOn - true if it is CURRENTLY doing preload
1880: . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
1881: - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on
1882: The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin()
1883: and PetscPreLoadEnd()
1885: Level: intermediate
1887: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage()
1889: Concepts: preloading
1890: Concepts: timing^accurate
1891: Concepts: paging^eliminating effects of
1894: M*/
1896: /*MC
1897: PetscPreLoadEnd - End a segment of code that may be preloaded (run twice)
1898: to get accurate timings
1900: Synopsis:
1901: #include <petsclog.h>
1902: void PetscPreLoadEnd(void);
1904: Not Collective
1906: Usage:
1907: .vb
1908: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1909: lines of code
1910: PetscPreLoadStage("second stage");
1911: lines of code
1912: PetscPreLoadEnd();
1913: .ve
1915: Notes: only works in C/C++ not fortran
1917: Level: intermediate
1919: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage()
1921: M*/
1923: /*MC
1924: PetscPreLoadStage - Start a new segment of code to be timed separately.
1925: to get accurate timings
1927: Synopsis:
1928: #include <petsclog.h>
1929: void PetscPreLoadStage(char *name);
1931: Not Collective
1933: Usage:
1934: .vb
1935: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1936: lines of code
1937: PetscPreLoadStage("second stage");
1938: lines of code
1939: PetscPreLoadEnd();
1940: .ve
1942: Notes: only works in C/C++ not fortran
1944: Level: intermediate
1946: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd()
1948: M*/
1951: #else /* end of -DPETSC_USE_LOG section */
1953: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1954: {
1956: return(0);
1957: }
1959: #endif /* PETSC_USE_LOG*/
1962: PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
1963: PetscClassId PETSC_OBJECT_CLASSID = 0;
1965: /*@C
1966: PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code.
1968: Not Collective
1970: Input Parameter:
1971: . name - The class name
1973: Output Parameter:
1974: . oclass - The class id or classid
1976: Level: developer
1978: .keywords: log, class, register
1980: @*/
1981: PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass)
1982: {
1983: #if defined(PETSC_USE_LOG)
1984: PetscStageLog stageLog;
1985: PetscInt stage;
1987: #endif
1990: *oclass = ++PETSC_LARGEST_CLASSID;
1991: #if defined(PETSC_USE_LOG)
1992: PetscLogGetStageLog(&stageLog);
1993: PetscClassRegLogRegister(stageLog->classLog, name, *oclass);
1994: for (stage = 0; stage < stageLog->numStages; stage++) {
1995: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
1996: }
1997: #endif
1998: return(0);
1999: }
2001: #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE)
2002: #include <mpe.h>
2004: PetscBool PetscBeganMPE = PETSC_FALSE;
2006: PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2007: PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2009: /*@C
2010: PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files
2011: and slows the program down.
2013: Collective over PETSC_COMM_WORLD
2015: Options Database Keys:
2016: . -log_mpe - Prints extensive log information
2018: Notes:
2019: A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is
2020: intended for production runs since it logs only flop rates and object
2021: creation (and should not significantly slow the programs).
2023: Level: advanced
2025: Concepts: logging^MPE
2026: Concepts: logging^message passing
2028: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(),
2029: PetscLogEventDeactivate()
2030: @*/
2031: PetscErrorCode PetscLogMPEBegin(void)
2032: {
2036: /* Do MPE initialization */
2037: if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */
2038: PetscInfo(0,"Initializing MPE.\n");
2039: MPE_Init_log();
2041: PetscBeganMPE = PETSC_TRUE;
2042: } else {
2043: PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");
2044: }
2045: PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);
2046: return(0);
2047: }
2049: /*@C
2050: PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot.
2052: Collective over PETSC_COMM_WORLD
2054: Level: advanced
2056: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin()
2057: @*/
2058: PetscErrorCode PetscLogMPEDump(const char sname[])
2059: {
2060: char name[PETSC_MAX_PATH_LEN];
2064: if (PetscBeganMPE) {
2065: PetscInfo(0,"Finalizing MPE.\n");
2066: if (sname) {
2067: PetscStrcpy(name,sname);
2068: } else {
2069: PetscGetProgramName(name,PETSC_MAX_PATH_LEN);
2070: }
2071: MPE_Finish_log(name);
2072: } else {
2073: PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");
2074: }
2075: return(0);
2076: }
2078: #define PETSC_RGB_COLORS_MAX 39
2079: static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {
2080: "OliveDrab: ",
2081: "BlueViolet: ",
2082: "CadetBlue: ",
2083: "CornflowerBlue: ",
2084: "DarkGoldenrod: ",
2085: "DarkGreen: ",
2086: "DarkKhaki: ",
2087: "DarkOliveGreen: ",
2088: "DarkOrange: ",
2089: "DarkOrchid: ",
2090: "DarkSeaGreen: ",
2091: "DarkSlateGray: ",
2092: "DarkTurquoise: ",
2093: "DeepPink: ",
2094: "DarkKhaki: ",
2095: "DimGray: ",
2096: "DodgerBlue: ",
2097: "GreenYellow: ",
2098: "HotPink: ",
2099: "IndianRed: ",
2100: "LavenderBlush: ",
2101: "LawnGreen: ",
2102: "LemonChiffon: ",
2103: "LightCoral: ",
2104: "LightCyan: ",
2105: "LightPink: ",
2106: "LightSalmon: ",
2107: "LightSlateGray: ",
2108: "LightYellow: ",
2109: "LimeGreen: ",
2110: "MediumPurple: ",
2111: "MediumSeaGreen: ",
2112: "MediumSlateBlue:",
2113: "MidnightBlue: ",
2114: "MintCream: ",
2115: "MistyRose: ",
2116: "NavajoWhite: ",
2117: "NavyBlue: ",
2118: "OliveDrab: "
2119: };
2121: /*@C
2122: PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister()
2124: Not collective. Maybe it should be?
2126: Output Parameter
2127: . str - character string representing the color
2129: Level: developer
2131: .keywords: log, mpe , color
2132: .seealso: PetscLogEventRegister
2133: @*/
2134: PetscErrorCode PetscLogMPEGetRGBColor(const char *str[])
2135: {
2136: static int idx = 0;
2139: *str = PetscLogMPERGBColors[idx];
2140: idx = (idx + 1)% PETSC_RGB_COLORS_MAX;
2141: return(0);
2142: }
2144: #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */