Actual source code: plog.c
petsc-3.8.4 2018-03-24
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: PetscLogSet(NULL, NULL);
122: /* Resetting phase */
123: PetscLogGetStageLog(&stageLog);
124: PetscStageLogDestroy(stageLog);
126: petsc_TotalFlops = 0.0;
127: petsc_numActions = 0;
128: petsc_numObjects = 0;
129: petsc_numObjectsDestroyed = 0;
130: petsc_maxActions = 100;
131: petsc_maxObjects = 100;
132: petsc_actions = NULL;
133: petsc_objects = NULL;
134: petsc_logActions = PETSC_FALSE;
135: petsc_logObjects = PETSC_FALSE;
136: petsc_BaseTime = 0.0;
137: petsc_TotalFlops = 0.0;
138: petsc_tmp_flops = 0.0;
139: petsc_send_ct = 0.0;
140: petsc_recv_ct = 0.0;
141: petsc_send_len = 0.0;
142: petsc_recv_len = 0.0;
143: petsc_isend_ct = 0.0;
144: petsc_irecv_ct = 0.0;
145: petsc_isend_len = 0.0;
146: petsc_irecv_len = 0.0;
147: petsc_wait_ct = 0.0;
148: petsc_wait_any_ct = 0.0;
149: petsc_wait_all_ct = 0.0;
150: petsc_sum_of_waits_ct = 0.0;
151: petsc_allreduce_ct = 0.0;
152: petsc_gather_ct = 0.0;
153: petsc_scatter_ct = 0.0;
154: PETSC_LARGEST_EVENT = PETSC_EVENT;
155: PetscLogPHC = NULL;
156: PetscLogPHD = NULL;
157: petsc_tracefile = NULL;
158: petsc_tracelevel = 0;
159: petsc_traceblanks = " ";
160: petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0;
161: petsc_tracetime = 0.0;
162: PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
163: PETSC_OBJECT_CLASSID = 0;
164: petsc_stageLog = 0;
165: PetscLogInitializeCalled = PETSC_FALSE;
166: return(0);
167: }
169: /*@C
170: PetscLogSet - Sets the logging functions called at the beginning and ending of every event.
172: Not Collective
174: Input Parameters:
175: + b - The function called at beginning of event
176: - e - The function called at end of event
178: Level: developer
180: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogTraceBegin()
181: @*/
182: PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject),
183: PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject))
184: {
186: PetscLogPLB = b;
187: PetscLogPLE = e;
188: return(0);
189: }
191: /*------------------------------------------- Initialization Functions ----------------------------------------------*/
192: /*
193: The data structures for logging are always created even if no logging is turned on. This is so events etc can
194: be registered in the code before the actually logging is turned on.
195: */
196: PetscErrorCode PetscLogInitialize(void)
197: {
198: int stage;
199: PetscBool opt;
203: if (PetscLogInitializeCalled) return(0);
204: PetscLogInitializeCalled = PETSC_TRUE;
206: PetscOptionsHasName(NULL,NULL, "-log_exclude_actions", &opt);
207: if (opt) petsc_logActions = PETSC_FALSE;
208: PetscOptionsHasName(NULL,NULL, "-log_exclude_objects", &opt);
209: if (opt) petsc_logObjects = PETSC_FALSE;
210: if (petsc_logActions) {
211: PetscMalloc1(petsc_maxActions, &petsc_actions);
212: }
213: if (petsc_logObjects) {
214: PetscMalloc1(petsc_maxObjects, &petsc_objects);
215: }
216: PetscLogPHC = PetscLogObjCreateDefault;
217: PetscLogPHD = PetscLogObjDestroyDefault;
218: /* Setup default logging structures */
219: PetscStageLogCreate(&petsc_stageLog);
220: PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);
222: /* All processors sync here for more consistent logging */
223: MPI_Barrier(PETSC_COMM_WORLD);
224: PetscTime(&petsc_BaseTime);
225: PetscLogStagePush(stage);
226: return(0);
227: }
229: /*@C
230: PetscLogDefaultBegin - Turns on logging of objects and events. This logs flop
231: rates and object creation and should not slow programs down too much.
232: This routine may be called more than once.
234: Logically Collective over PETSC_COMM_WORLD
236: Options Database Keys:
237: . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the
238: screen (for code configured with --with-log=1 (which is the default))
240: Usage:
241: .vb
242: PetscInitialize(...);
243: PetscLogDefaultBegin();
244: ... code ...
245: PetscLogView(viewer); or PetscLogDump();
246: PetscFinalize();
247: .ve
249: Notes:
250: PetscLogView(viewer) or PetscLogDump() actually cause the printing of
251: the logging information.
253: Level: advanced
255: .keywords: log, begin
256: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin()
257: @*/
258: PetscErrorCode PetscLogDefaultBegin(void)
259: {
263: PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
264: return(0);
265: }
267: /*@C
268: PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
269: all events. This creates large log files and slows the program down.
271: Logically Collective on PETSC_COMM_WORLD
273: Options Database Keys:
274: . -log_all - Prints extensive log information
276: Usage:
277: .vb
278: PetscInitialize(...);
279: PetscLogAllBegin();
280: ... code ...
281: PetscLogDump(filename);
282: PetscFinalize();
283: .ve
285: Notes:
286: A related routine is PetscLogDefaultBegin() (with the options key -log), which is
287: intended for production runs since it logs only flop rates and object
288: creation (and shouldn't significantly slow the programs).
290: Level: advanced
292: .keywords: log, all, begin
293: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogTraceBegin()
294: @*/
295: PetscErrorCode PetscLogAllBegin(void)
296: {
300: PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
301: return(0);
302: }
304: /*@
305: PetscLogTraceBegin - Activates trace logging. Every time a PETSc event
306: begins or ends, the event name is printed.
308: Logically Collective on PETSC_COMM_WORLD
310: Input Parameter:
311: . file - The file to print trace in (e.g. stdout)
313: Options Database Key:
314: . -log_trace [filename] - Activates PetscLogTraceBegin()
316: Notes:
317: PetscLogTraceBegin() prints the processor number, the execution time (sec),
318: then "Event begin:" or "Event end:" followed by the event name.
320: PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
321: to determine where a program is hanging without running in the
322: debugger. Can be used in conjunction with the -info option.
324: Level: intermediate
326: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogDefaultBegin()
327: @*/
328: PetscErrorCode PetscLogTraceBegin(FILE *file)
329: {
333: petsc_tracefile = file;
335: PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
336: return(0);
337: }
339: /*@
340: PetscLogActions - Determines whether actions are logged for the graphical viewer.
342: Not Collective
344: Input Parameter:
345: . flag - PETSC_TRUE if actions are to be logged
347: Level: intermediate
349: Note: Logging of actions continues to consume more memory as the program
350: runs. Long running programs should consider turning this feature off.
352: Options Database Keys:
353: . -log_exclude_actions - Turns off actions logging
355: .keywords: log, stage, register
356: .seealso: PetscLogStagePush(), PetscLogStagePop()
357: @*/
358: PetscErrorCode PetscLogActions(PetscBool flag)
359: {
361: petsc_logActions = flag;
362: return(0);
363: }
365: /*@
366: PetscLogObjects - Determines whether objects are logged for the graphical viewer.
368: Not Collective
370: Input Parameter:
371: . flag - PETSC_TRUE if objects are to be logged
373: Level: intermediate
375: Note: Logging of objects continues to consume more memory as the program
376: runs. Long running programs should consider turning this feature off.
378: Options Database Keys:
379: . -log_exclude_objects - Turns off objects logging
381: .keywords: log, stage, register
382: .seealso: PetscLogStagePush(), PetscLogStagePop()
383: @*/
384: PetscErrorCode PetscLogObjects(PetscBool flag)
385: {
387: petsc_logObjects = flag;
388: return(0);
389: }
391: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
392: /*@C
393: PetscLogStageRegister - Attaches a character string name to a logging stage.
395: Not Collective
397: Input Parameter:
398: . sname - The name to associate with that stage
400: Output Parameter:
401: . stage - The stage number
403: Level: intermediate
405: .keywords: log, stage, register
406: .seealso: PetscLogStagePush(), PetscLogStagePop()
407: @*/
408: PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage)
409: {
410: PetscStageLog stageLog;
411: PetscLogEvent event;
415: PetscLogGetStageLog(&stageLog);
416: PetscStageLogRegister(stageLog, sname, stage);
417: /* Copy events already changed in the main stage, this sucks */
418: PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
419: for (event = 0; event < stageLog->eventLog->numEvents; event++) {
420: PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
421: }
422: PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
423: return(0);
424: }
426: /*@C
427: PetscLogStagePush - This function pushes a stage on the stack.
429: Not Collective
431: Input Parameter:
432: . stage - The stage on which to log
434: Usage:
435: If the option -log_sumary is used to run the program containing the
436: following code, then 2 sets of summary data will be printed during
437: PetscFinalize().
438: .vb
439: PetscInitialize(int *argc,char ***args,0,0);
440: [stage 0 of code]
441: PetscLogStagePush(1);
442: [stage 1 of code]
443: PetscLogStagePop();
444: PetscBarrier(...);
445: [more stage 0 of code]
446: PetscFinalize();
447: .ve
449: Notes:
450: Use PetscLogStageRegister() to register a stage.
452: Level: intermediate
454: .keywords: log, push, stage
455: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
456: @*/
457: PetscErrorCode PetscLogStagePush(PetscLogStage stage)
458: {
459: PetscStageLog stageLog;
463: PetscLogGetStageLog(&stageLog);
464: PetscStageLogPush(stageLog, stage);
465: return(0);
466: }
468: /*@C
469: PetscLogStagePop - This function pops a stage from the stack.
471: Not Collective
473: Usage:
474: If the option -log_sumary is used to run the program containing the
475: following code, then 2 sets of summary data will be printed during
476: PetscFinalize().
477: .vb
478: PetscInitialize(int *argc,char ***args,0,0);
479: [stage 0 of code]
480: PetscLogStagePush(1);
481: [stage 1 of code]
482: PetscLogStagePop();
483: PetscBarrier(...);
484: [more stage 0 of code]
485: PetscFinalize();
486: .ve
488: Notes:
489: Use PetscLogStageRegister() to register a stage.
491: Level: intermediate
493: .keywords: log, pop, stage
494: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
495: @*/
496: PetscErrorCode PetscLogStagePop(void)
497: {
498: PetscStageLog stageLog;
502: PetscLogGetStageLog(&stageLog);
503: PetscStageLogPop(stageLog);
504: return(0);
505: }
507: /*@
508: PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().
510: Not Collective
512: Input Parameters:
513: + stage - The stage
514: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
516: Level: intermediate
518: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
519: @*/
520: PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive)
521: {
522: PetscStageLog stageLog;
526: PetscLogGetStageLog(&stageLog);
527: PetscStageLogSetActive(stageLog, stage, isActive);
528: return(0);
529: }
531: /*@
532: PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().
534: Not Collective
536: Input Parameter:
537: . stage - The stage
539: Output Parameter:
540: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
542: Level: intermediate
544: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
545: @*/
546: PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive)
547: {
548: PetscStageLog stageLog;
552: PetscLogGetStageLog(&stageLog);
553: PetscStageLogGetActive(stageLog, stage, isActive);
554: return(0);
555: }
557: /*@
558: PetscLogStageSetVisible - Determines stage visibility in PetscLogView()
560: Not Collective
562: Input Parameters:
563: + stage - The stage
564: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
566: Level: intermediate
568: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
569: @*/
570: PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible)
571: {
572: PetscStageLog stageLog;
576: PetscLogGetStageLog(&stageLog);
577: PetscStageLogSetVisible(stageLog, stage, isVisible);
578: return(0);
579: }
581: /*@
582: PetscLogStageGetVisible - Returns stage visibility in PetscLogView()
584: Not Collective
586: Input Parameter:
587: . stage - The stage
589: Output Parameter:
590: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
592: Level: intermediate
594: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
595: @*/
596: PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible)
597: {
598: PetscStageLog stageLog;
602: PetscLogGetStageLog(&stageLog);
603: PetscStageLogGetVisible(stageLog, stage, isVisible);
604: return(0);
605: }
607: /*@C
608: PetscLogStageGetId - Returns the stage id when given the stage name.
610: Not Collective
612: Input Parameter:
613: . name - The stage name
615: Output Parameter:
616: . stage - The stage, , or -1 if no stage with that name exists
618: Level: intermediate
620: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
621: @*/
622: PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage)
623: {
624: PetscStageLog stageLog;
628: PetscLogGetStageLog(&stageLog);
629: PetscStageLogGetStage(stageLog, name, stage);
630: return(0);
631: }
633: /*------------------------------------------------ Event Functions --------------------------------------------------*/
634: /*@C
635: PetscLogEventRegister - Registers an event name for logging operations in an application code.
637: Not Collective
639: Input Parameter:
640: + name - The name associated with the event
641: - classid - The classid associated to the class for this event, obtain either with
642: PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones
643: are only available in C code
645: Output Parameter:
646: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().
648: Example of Usage:
649: .vb
650: PetscLogEvent USER_EVENT;
651: PetscClassId classid;
652: PetscLogDouble user_event_flops;
653: PetscClassIdRegister("class name",&classid);
654: PetscLogEventRegister("User event name",classid,&USER_EVENT);
655: PetscLogEventBegin(USER_EVENT,0,0,0,0);
656: [code segment to monitor]
657: PetscLogFlops(user_event_flops);
658: PetscLogEventEnd(USER_EVENT,0,0,0,0);
659: .ve
661: Notes:
662: PETSc automatically logs library events if the code has been
663: configured with --with-log (which is the default) and
664: -log_view or -log_all is specified. PetscLogEventRegister() is
665: intended for logging user events to supplement this PETSc
666: information.
668: PETSc can gather data for use with the utilities Jumpshot
669: (part of the MPICH distribution). If PETSc has been compiled
670: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
671: MPICH), the user can employ another command line option, -log_mpe,
672: to create a logfile, "mpe.log", which can be visualized
673: Jumpshot.
675: The classid is associated with each event so that classes of events
676: can be disabled simultaneously, such as all matrix events. The user
677: can either use an existing classid, such as MAT_CLASSID, or create
678: their own as shown in the example.
680: If an existing event with the same name exists, its event handle is
681: returned instead of creating a new event.
683: Level: intermediate
685: .keywords: log, event, register
686: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
687: PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister()
688: @*/
689: PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event)
690: {
691: PetscStageLog stageLog;
692: int stage;
696: *event = PETSC_DECIDE;
697: PetscLogGetStageLog(&stageLog);
698: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
699: if (*event > 0) return(0);
700: PetscEventRegLogRegister(stageLog->eventLog, name, classid, event);
701: for (stage = 0; stage < stageLog->numStages; stage++) {
702: PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
703: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
704: }
705: return(0);
706: }
708: /*@
709: PetscLogEventActivate - Indicates that a particular event should be logged.
711: Not Collective
713: Input Parameter:
714: . event - The event id
716: Usage:
717: .vb
718: PetscLogEventDeactivate(VEC_SetValues);
719: [code where you do not want to log VecSetValues()]
720: PetscLogEventActivate(VEC_SetValues);
721: [code where you do want to log VecSetValues()]
722: .ve
724: Note:
725: The event may be either a pre-defined PETSc event (found in include/petsclog.h)
726: or an event number obtained with PetscLogEventRegister().
728: Level: advanced
730: .keywords: log, event, activate
731: .seealso: PlogEventDeactivate()
732: @*/
733: PetscErrorCode PetscLogEventActivate(PetscLogEvent event)
734: {
735: PetscStageLog stageLog;
736: int stage;
740: PetscLogGetStageLog(&stageLog);
741: PetscStageLogGetCurrent(stageLog, &stage);
742: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
743: return(0);
744: }
746: /*@
747: PetscLogEventDeactivate - Indicates that a particular event should not be logged.
749: Not Collective
751: Input Parameter:
752: . event - The event id
754: Usage:
755: .vb
756: PetscLogEventDeactivate(VEC_SetValues);
757: [code where you do not want to log VecSetValues()]
758: PetscLogEventActivate(VEC_SetValues);
759: [code where you do want to log VecSetValues()]
760: .ve
762: Note:
763: The event may be either a pre-defined PETSc event (found in
764: include/petsclog.h) or an event number obtained with PetscLogEventRegister()).
766: Level: advanced
768: .keywords: log, event, deactivate
769: .seealso: PlogEventActivate()
770: @*/
771: PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event)
772: {
773: PetscStageLog stageLog;
774: int stage;
778: PetscLogGetStageLog(&stageLog);
779: PetscStageLogGetCurrent(stageLog, &stage);
780: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
781: return(0);
782: }
784: /*@
785: PetscLogEventSetActiveAll - Sets the event activity in every stage.
787: Not Collective
789: Input Parameters:
790: + event - The event id
791: - isActive - The activity flag determining whether the event is logged
793: Level: advanced
795: .keywords: log, event, activate
796: .seealso: PlogEventActivate(),PlogEventDeactivate()
797: @*/
798: PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive)
799: {
800: PetscStageLog stageLog;
801: int stage;
805: PetscLogGetStageLog(&stageLog);
806: for (stage = 0; stage < stageLog->numStages; stage++) {
807: if (isActive) {
808: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
809: } else {
810: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
811: }
812: }
813: return(0);
814: }
816: /*@
817: PetscLogEventActivateClass - Activates event logging for a PETSc object class.
819: Not Collective
821: Input Parameter:
822: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
824: Level: developer
826: .keywords: log, event, activate, class
827: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
828: @*/
829: PetscErrorCode PetscLogEventActivateClass(PetscClassId classid)
830: {
831: PetscStageLog stageLog;
832: int stage;
836: PetscLogGetStageLog(&stageLog);
837: PetscStageLogGetCurrent(stageLog, &stage);
838: PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
839: return(0);
840: }
842: /*@
843: PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.
845: Not Collective
847: Input Parameter:
848: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
850: Level: developer
852: .keywords: log, event, deactivate, class
853: .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate()
854: @*/
855: PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid)
856: {
857: PetscStageLog stageLog;
858: int stage;
862: PetscLogGetStageLog(&stageLog);
863: PetscStageLogGetCurrent(stageLog, &stage);
864: PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
865: return(0);
866: }
868: /*MC
869: PetscLogEventBegin - Logs the beginning of a user event.
871: Synopsis:
872: #include <petsclog.h>
873: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
875: Not Collective
877: Input Parameters:
878: + e - integer associated with the event obtained from PetscLogEventRegister()
879: - o1,o2,o3,o4 - objects associated with the event, or 0
882: Fortran Synopsis:
883: void PetscLogEventBegin(int e,PetscErrorCode ierr)
885: Usage:
886: .vb
887: PetscLogEvent USER_EVENT;
888: PetscLogDouble user_event_flops;
889: PetscLogEventRegister("User event",0,&USER_EVENT);
890: PetscLogEventBegin(USER_EVENT,0,0,0,0);
891: [code segment to monitor]
892: PetscLogFlops(user_event_flops);
893: PetscLogEventEnd(USER_EVENT,0,0,0,0);
894: .ve
896: Notes:
897: You need to register each integer event with the command
898: PetscLogEventRegister().
900: Level: intermediate
902: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
904: .keywords: log, event, begin
905: M*/
907: /*MC
908: PetscLogEventEnd - Log the end of a user event.
910: Synopsis:
911: #include <petsclog.h>
912: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
914: Not Collective
916: Input Parameters:
917: + e - integer associated with the event obtained with PetscLogEventRegister()
918: - o1,o2,o3,o4 - objects associated with the event, or 0
921: Fortran Synopsis:
922: void PetscLogEventEnd(int e,PetscErrorCode ierr)
924: Usage:
925: .vb
926: PetscLogEvent USER_EVENT;
927: PetscLogDouble user_event_flops;
928: PetscLogEventRegister("User event",0,&USER_EVENT,);
929: PetscLogEventBegin(USER_EVENT,0,0,0,0);
930: [code segment to monitor]
931: PetscLogFlops(user_event_flops);
932: PetscLogEventEnd(USER_EVENT,0,0,0,0);
933: .ve
935: Notes:
936: You should also register each additional integer event with the command
937: PetscLogEventRegister().
939: Level: intermediate
941: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
943: .keywords: log, event, end
944: M*/
946: /*MC
947: PetscLogEventBarrierBegin - Logs the time in a barrier before an event.
949: Synopsis:
950: #include <petsclog.h>
951: PetscErrorCode PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
953: Not Collective
955: Input Parameters:
956: . e - integer associated with the event obtained from PetscLogEventRegister()
957: . o1,o2,o3,o4 - objects associated with the event, or 0
958: . comm - communicator the barrier takes place over
961: Usage:
962: .vb
963: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
964: MPIU_Allreduce()
965: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
966: .ve
968: Notes:
969: This is for logging the amount of time spent in a barrier for an event
970: that requires synchronization.
972: Additional Notes:
973: Synchronization events always come in pairs; for example, VEC_NormBarrier and
974: VEC_NormComm = VEC_NormBarrier + 1
976: Level: advanced
978: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
979: PetscLogEventBarrierEnd()
981: .keywords: log, event, begin, barrier
982: M*/
984: /*MC
985: PetscLogEventBarrierEnd - Logs the time in a barrier before an event.
987: Synopsis:
988: #include <petsclog.h>
989: PetscErrorCode PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm)
991: Logically Collective on MPI_Comm
993: Input Parameters:
994: . e - integer associated with the event obtained from PetscLogEventRegister()
995: . o1,o2,o3,o4 - objects associated with the event, or 0
996: . comm - communicator the barrier takes place over
999: Usage:
1000: .vb
1001: PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm);
1002: MPIU_Allreduce()
1003: PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm);
1004: .ve
1006: Notes:
1007: This is for logging the amount of time spent in a barrier for an event
1008: that requires synchronization.
1010: Additional Notes:
1011: Synchronization events always come in pairs; for example, VEC_NormBarrier and
1012: VEC_NormComm = VEC_NormBarrier + 1
1014: Level: advanced
1016: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(),
1017: PetscLogEventBarrierBegin()
1019: .keywords: log, event, begin, barrier
1020: M*/
1022: /*@C
1023: PetscLogEventGetId - Returns the event id when given the event name.
1025: Not Collective
1027: Input Parameter:
1028: . name - The event name
1030: Output Parameter:
1031: . event - The event, or -1 if no event with that name exists
1033: Level: intermediate
1035: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1036: @*/
1037: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1038: {
1039: PetscStageLog stageLog;
1043: PetscLogGetStageLog(&stageLog);
1044: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
1045: return(0);
1046: }
1049: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1050: /*@C
1051: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1052: be read by bin/petscview. This program no longer exists.
1054: Collective on PETSC_COMM_WORLD
1056: Input Parameter:
1057: . name - an optional file name
1059: Usage:
1060: .vb
1061: PetscInitialize(...);
1062: PetscLogDefaultBegin(); or PetscLogAllBegin();
1063: ... code ...
1064: PetscLogDump(filename);
1065: PetscFinalize();
1066: .ve
1068: Notes:
1069: The default file name is
1070: $ Log.<rank>
1071: where <rank> is the processor number. If no name is specified,
1072: this file will be used.
1074: Level: advanced
1076: .keywords: log, dump
1077: .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView()
1078: @*/
1079: PetscErrorCode PetscLogDump(const char sname[])
1080: {
1081: PetscStageLog stageLog;
1082: PetscEventPerfInfo *eventInfo;
1083: FILE *fd;
1084: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1085: PetscLogDouble flops, _TotalTime;
1086: PetscMPIInt rank;
1087: int action, object, curStage;
1088: PetscLogEvent event;
1089: PetscErrorCode ierr;
1092: /* Calculate the total elapsed time */
1093: PetscTime(&_TotalTime);
1094: _TotalTime -= petsc_BaseTime;
1095: /* Open log file */
1096: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1097: if (sname) sprintf(file, "%s.%d", sname, rank);
1098: else sprintf(file, "Log.%d", rank);
1099: PetscFixFilename(file, fname);
1100: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1101: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1102: /* Output totals */
1103: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1104: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1105: /* Output actions */
1106: if (petsc_logActions) {
1107: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1108: for (action = 0; action < petsc_numActions; action++) {
1109: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1110: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1111: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1112: }
1113: }
1114: /* Output objects */
1115: if (petsc_logObjects) {
1116: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1117: for (object = 0; object < petsc_numObjects; object++) {
1118: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1119: if (!petsc_objects[object].name[0]) {
1120: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1121: } else {
1122: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1123: }
1124: if (petsc_objects[object].info[0] != 0) {
1125: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1126: } else {
1127: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1128: }
1129: }
1130: }
1131: /* Output events */
1132: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1133: PetscLogGetStageLog(&stageLog);
1134: PetscIntStackTop(stageLog->stack, &curStage);
1135: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1136: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1137: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1138: else flops = 0.0;
1139: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1140: eventInfo[event].flops, eventInfo[event].time, flops);
1141: }
1142: PetscFClose(PETSC_COMM_WORLD, fd);
1143: return(0);
1144: }
1146: /*
1147: PetscLogView_Detailed - Each process prints the times for its own events
1149: */
1150: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1151: {
1152: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1153: PetscEventPerfInfo *eventInfo = NULL;
1154: PetscLogDouble locTotalTime, numRed, maxMem;
1155: PetscStageLog stageLog;
1156: int numStages,numEvents,stage,event;
1157: PetscMPIInt rank,size;
1158: PetscErrorCode ierr;
1161: MPI_Comm_size(comm, &size);
1162: MPI_Comm_rank(comm, &rank);
1163: /* Must preserve reduction count before we go on */
1164: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1165: /* Get the total elapsed time */
1166: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1167: PetscViewerASCIIPrintf(viewer,"size = %d\n",size);
1168: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1169: PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");
1170: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1171: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1172: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1173: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1174: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1175: PetscLogGetStageLog(&stageLog);
1176: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1177: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1178: for (stage=0; stage<numStages; stage++) {
1179: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1180: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1181: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1182: for (event = 0; event < numEvents; event++) {
1183: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1184: }
1185: }
1186: PetscViewerASCIIPushSynchronized(viewer);
1187: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1188: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);
1189: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1190: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1191: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1192: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);
1193: PetscMallocGetMaximumUsage(&maxMem);
1194: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1195: PetscViewerFlush(viewer);
1196: for (stage=0; stage<numStages; stage++) {
1197: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",
1198: stageLog->stageInfo[stage].name,rank,
1199: stageLog->stageInfo[stage].perfInfo.time,stageLog->stageInfo[stage].perfInfo.numMessages,stageLog->stageInfo[stage].perfInfo.messageLength,
1200: stageLog->stageInfo[stage].perfInfo.numReductions,stageLog->stageInfo[stage].perfInfo.flops);
1201: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1202: for (event = 0; event < numEvents; event++) {
1203: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1204: 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,
1205: eventInfo[event].count, eventInfo[event].time,eventInfo[event].numMessages, eventInfo[event].messageLength,
1206: eventInfo[event].numReductions,eventInfo[event].flops);
1207: }
1208: }
1209: PetscViewerFlush(viewer);
1210: PetscViewerASCIIPopSynchronized(viewer);
1211: return(0);
1212: }
1214: static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd)
1215: {
1216: #if defined(PETSC_USE_DEBUG)
1220: PetscFPrintf(comm, fd, "\n\n");
1221: PetscFPrintf(comm, fd, " ##########################################################\n");
1222: PetscFPrintf(comm, fd, " # #\n");
1223: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1224: PetscFPrintf(comm, fd, " # #\n");
1225: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");
1226: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1227: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1228: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1229: PetscFPrintf(comm, fd, " # #\n");
1230: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1231: return(0);
1232: #else
1233: return 0;
1234: #endif
1235: }
1237: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1238: {
1239: FILE *fd;
1240: PetscLogDouble zero = 0.0;
1241: PetscStageLog stageLog;
1242: PetscStageInfo *stageInfo = NULL;
1243: PetscEventPerfInfo *eventInfo = NULL;
1244: PetscClassPerfInfo *classInfo;
1245: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1246: const char *name;
1247: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1248: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1249: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1250: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1251: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1252: PetscLogDouble min, max, tot, ratio, avg, x, y;
1253: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr;
1254: PetscMPIInt minCt, maxCt;
1255: PetscMPIInt size, rank;
1256: PetscBool *localStageUsed, *stageUsed;
1257: PetscBool *localStageVisible, *stageVisible;
1258: int numStages, localNumEvents, numEvents;
1259: int stage, oclass;
1260: PetscLogEvent event;
1261: PetscErrorCode ierr;
1262: char version[256];
1263: MPI_Comm comm;
1266: PetscObjectGetComm((PetscObject)viewer,&comm);
1267: PetscViewerASCIIGetPointer(viewer,&fd);
1268: MPI_Comm_size(comm, &size);
1269: MPI_Comm_rank(comm, &rank);
1270: /* Get the total elapsed time */
1271: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1273: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1274: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1275: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1276: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1277: PetscLogViewWarnDebugging(comm,fd);
1278: PetscGetArchType(arch,sizeof(arch));
1279: PetscGetHostName(hostname,sizeof(hostname));
1280: PetscGetUserName(username,sizeof(username));
1281: PetscGetProgramName(pname,sizeof(pname));
1282: PetscGetDate(date,sizeof(date));
1283: PetscGetVersion(version,sizeof(version));
1284: if (size == 1) {
1285: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1286: } else {
1287: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1288: }
1290: PetscFPrintf(comm, fd, "Using %s\n", version);
1292: /* Must preserve reduction count before we go on */
1293: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1295: /* Calculate summary information */
1296: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1297: /* Time */
1298: MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1299: MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1300: MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1301: avg = (tot)/((PetscLogDouble) size);
1302: if (min != 0.0) ratio = max/min;
1303: else ratio = 0.0;
1304: PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);
1305: TotalTime = tot;
1306: /* Objects */
1307: avg = (PetscLogDouble) petsc_numObjects;
1308: MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1309: MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1310: MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1311: avg = (tot)/((PetscLogDouble) size);
1312: if (min != 0.0) ratio = max/min;
1313: else ratio = 0.0;
1314: PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);
1315: /* Flops */
1316: MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1317: MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1318: MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1319: avg = (tot)/((PetscLogDouble) size);
1320: if (min != 0.0) ratio = max/min;
1321: else ratio = 0.0;
1322: PetscFPrintf(comm, fd, "Flop: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1323: TotalFlops = tot;
1324: /* Flops/sec -- Must talk to Barry here */
1325: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime;
1326: else flops = 0.0;
1327: MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1328: MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1329: MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1330: avg = (tot)/((PetscLogDouble) size);
1331: if (min != 0.0) ratio = max/min;
1332: else ratio = 0.0;
1333: PetscFPrintf(comm, fd, "Flop/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1334: /* Memory */
1335: PetscMallocGetMaximumUsage(&mem);
1336: if (mem > 0.0) {
1337: MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1338: MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1339: MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1340: avg = (tot)/((PetscLogDouble) size);
1341: if (min != 0.0) ratio = max/min;
1342: else ratio = 0.0;
1343: PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);
1344: }
1345: /* Messages */
1346: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1347: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1348: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1349: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1350: avg = (tot)/((PetscLogDouble) size);
1351: if (min != 0.0) ratio = max/min;
1352: else ratio = 0.0;
1353: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1354: numMessages = tot;
1355: /* Message Lengths */
1356: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1357: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1358: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1359: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1360: if (numMessages != 0) avg = (tot)/(numMessages);
1361: else avg = 0.0;
1362: if (min != 0.0) ratio = max/min;
1363: else ratio = 0.0;
1364: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);
1365: messageLength = tot;
1366: /* Reductions */
1367: MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1368: MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1369: MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1370: if (min != 0.0) ratio = max/min;
1371: else ratio = 0.0;
1372: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);
1373: numReductions = red; /* wrong because uses count from process zero */
1374: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1375: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");
1376: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");
1378: /* Get total number of stages --
1379: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1380: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1381: This seems best accomplished by assoicating a communicator with each stage.
1382: */
1383: PetscLogGetStageLog(&stageLog);
1384: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1385: PetscMalloc1(numStages, &localStageUsed);
1386: PetscMalloc1(numStages, &stageUsed);
1387: PetscMalloc1(numStages, &localStageVisible);
1388: PetscMalloc1(numStages, &stageVisible);
1389: if (numStages > 0) {
1390: stageInfo = stageLog->stageInfo;
1391: for (stage = 0; stage < numStages; stage++) {
1392: if (stage < stageLog->numStages) {
1393: localStageUsed[stage] = stageInfo[stage].used;
1394: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1395: } else {
1396: localStageUsed[stage] = PETSC_FALSE;
1397: localStageVisible[stage] = PETSC_TRUE;
1398: }
1399: }
1400: MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1401: MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1402: for (stage = 0; stage < numStages; stage++) {
1403: if (stageUsed[stage]) {
1404: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");
1405: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");
1406: break;
1407: }
1408: }
1409: for (stage = 0; stage < numStages; stage++) {
1410: if (!stageUsed[stage]) continue;
1411: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1412: if (localStageUsed[stage]) {
1413: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1414: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1415: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1416: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1417: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1418: name = stageInfo[stage].name;
1419: } else {
1420: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1421: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1422: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1423: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1424: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1425: name = "";
1426: }
1427: mess *= 0.5; messLen *= 0.5; red /= size;
1428: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1429: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1430: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1431: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1432: if (numMessages != 0.0) avgMessLen = messLen/numMessages; else avgMessLen = 0.0;
1433: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1434: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1435: 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",
1436: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1437: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1438: }
1439: }
1441: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1442: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1443: PetscFPrintf(comm, fd, "Phase summary info:\n");
1444: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1445: PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");
1446: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1447: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1448: PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");
1449: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1450: PetscFPrintf(comm, fd, " Global: entire computation\n");
1451: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1452: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");
1453: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1454: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1455: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");
1456: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1458: PetscLogViewWarnDebugging(comm,fd);
1460: /* Report events */
1461: PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage --- Total\n");
1462: 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");
1463: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1465: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1466: for (stage = 0; stage < numStages; stage++) {
1467: if (!stageVisible[stage]) continue;
1468: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1469: if (localStageUsed[stage]) {
1470: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1471: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1472: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1473: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1474: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1475: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1476: } else {
1477: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1478: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1479: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1480: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1481: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1482: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1483: }
1484: mess *= 0.5; messLen *= 0.5; red /= size;
1486: /* Get total number of events in this stage --
1487: Currently, a single processor can register more events than another, but events must all be registered in order,
1488: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1489: on the event ID. This seems best accomplished by assoicating a communicator with each stage.
1491: Problem: If the event did not happen on proc 1, its name will not be available.
1492: Problem: Event visibility is not implemented
1493: */
1494: if (localStageUsed[stage]) {
1495: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1496: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1497: } else localNumEvents = 0;
1498: MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1499: for (event = 0; event < numEvents; event++) {
1500: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1501: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1502: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops;
1503: else flopr = 0.0;
1505: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1506: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1507: MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1508: MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1509: MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1510: MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1511: MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1512: MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1513: MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1514: MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);
1515: MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1516: name = stageLog->eventLog->eventInfo[event].name;
1517: } else {
1518: flopr = 0.0;
1519: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1520: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1521: MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1522: MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1523: MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1524: MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1525: MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1526: MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1527: MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1528: MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);
1529: MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);
1530: name = "";
1531: }
1532: if (mint < 0.0) {
1533: 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);
1534: mint = 0;
1535: }
1536: 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);
1537: totm *= 0.5; totml *= 0.5; totr /= size;
1539: if (maxCt != 0) {
1540: if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0;
1541: if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0;
1542: if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0;
1543: if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0;
1544: if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0;
1545: if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0;
1546: if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0;
1547: if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0;
1548: if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0;
1549: if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0;
1550: if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0;
1551: if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0;
1552: if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0;
1553: if (totm != 0.0) totml /= totm; else totml = 0.0;
1554: if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0;
1555: 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");
1556: PetscFPrintf(comm, fd,
1557: "%-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",
1558: name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr,
1559: 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
1560: 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
1561: PetscAbsReal(flopr/1.0e6));
1562: }
1563: }
1564: }
1566: /* Memory usage and object creation */
1567: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1568: PetscFPrintf(comm, fd, "\n");
1569: PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");
1571: /* Right now, only stages on the first processor are reported here, meaning only objects associated with
1572: the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
1573: stats for stages local to processor sets.
1574: */
1575: /* We should figure out the longest object name here (now 20 characters) */
1576: PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");
1577: PetscFPrintf(comm, fd, "Reports information only for process 0.\n");
1578: for (stage = 0; stage < numStages; stage++) {
1579: if (localStageUsed[stage]) {
1580: classInfo = stageLog->stageInfo[stage].classLog->classInfo;
1581: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1582: for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
1583: if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
1584: PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name,
1585: classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem,
1586: classInfo[oclass].descMem);
1587: }
1588: }
1589: } else {
1590: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1591: }
1592: }
1594: PetscFree(localStageUsed);
1595: PetscFree(stageUsed);
1596: PetscFree(localStageVisible);
1597: PetscFree(stageVisible);
1599: /* Information unrelated to this particular run */
1600: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1601: PetscTime(&y);
1602: PetscTime(&x);
1603: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1604: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1605: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1606: /* MPI information */
1607: if (size > 1) {
1608: MPI_Status status;
1609: PetscMPIInt tag;
1610: MPI_Comm newcomm;
1612: MPI_Barrier(comm);
1613: PetscTime(&x);
1614: MPI_Barrier(comm);
1615: MPI_Barrier(comm);
1616: MPI_Barrier(comm);
1617: MPI_Barrier(comm);
1618: MPI_Barrier(comm);
1619: PetscTime(&y);
1620: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1621: PetscCommDuplicate(comm,&newcomm, &tag);
1622: MPI_Barrier(comm);
1623: if (rank) {
1624: MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);
1625: MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1626: } else {
1627: PetscTime(&x);
1628: MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);
1629: MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);
1630: PetscTime(&y);
1631: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1632: }
1633: PetscCommDestroy(&newcomm);
1634: }
1635: PetscOptionsView(NULL,viewer);
1637: /* Machine and compile information */
1638: #if defined(PETSC_USE_FORTRAN_KERNELS)
1639: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1640: #else
1641: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1642: #endif
1643: #if defined(PETSC_USE_REAL_SINGLE)
1644: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1645: #elif defined(PETSC_USE_LONGDOUBLE)
1646: PetscFPrintf(comm, fd, "Compiled with long double precision PetscScalar and PetscReal\n");
1647: #endif
1649: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1650: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1651: #else
1652: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1653: #endif
1654: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1655: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1657: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1658: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1659: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1660: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1661: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1663: /* Cleanup */
1664: PetscFPrintf(comm, fd, "\n");
1665: PetscLogViewWarnDebugging(comm,fd);
1666: return(0);
1667: }
1669: PetscErrorCode PetscLogView_Nested(PetscViewer);
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 */