Actual source code: plog.c
petsc-3.11.4 2019-09-28
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:
35: Currently we do not always do a good job of associating all memory allocations with an object.
37: .seealso: PetscFinalize(), PetscInitializeFortran(), PetscGetArgs(), PetscInitializeNoArguments()
39: @*/
40: PetscErrorCode PetscLogObjectMemory(PetscObject p,PetscLogDouble m)
41: {
42: if (!p) return 0;
43: p->mem += m;
44: return 0;
45: }
47: PetscLogEvent PETSC_LARGEST_EVENT = PETSC_EVENT;
49: #if defined(PETSC_USE_LOG)
50: #include <petscmachineinfo.h>
51: #include <petscconfiginfo.h>
53: /* used in the MPI_XXX() count macros in petsclog.h */
55: /* Action and object logging variables */
56: Action *petsc_actions = NULL;
57: Object *petsc_objects = NULL;
58: PetscBool petsc_logActions = PETSC_FALSE;
59: PetscBool petsc_logObjects = PETSC_FALSE;
60: int petsc_numActions = 0, petsc_maxActions = 100;
61: int petsc_numObjects = 0, petsc_maxObjects = 100;
62: int petsc_numObjectsDestroyed = 0;
64: /* Global counters */
65: PetscLogDouble petsc_BaseTime = 0.0;
66: PetscLogDouble petsc_TotalFlops = 0.0; /* The number of flops */
67: PetscLogDouble petsc_tmp_flops = 0.0; /* The incremental number of flops */
68: PetscLogDouble petsc_send_ct = 0.0; /* The number of sends */
69: PetscLogDouble petsc_recv_ct = 0.0; /* The number of receives */
70: PetscLogDouble petsc_send_len = 0.0; /* The total length of all sent messages */
71: PetscLogDouble petsc_recv_len = 0.0; /* The total length of all received messages */
72: PetscLogDouble petsc_isend_ct = 0.0; /* The number of immediate sends */
73: PetscLogDouble petsc_irecv_ct = 0.0; /* The number of immediate receives */
74: PetscLogDouble petsc_isend_len = 0.0; /* The total length of all immediate send messages */
75: PetscLogDouble petsc_irecv_len = 0.0; /* The total length of all immediate receive messages */
76: PetscLogDouble petsc_wait_ct = 0.0; /* The number of waits */
77: PetscLogDouble petsc_wait_any_ct = 0.0; /* The number of anywaits */
78: PetscLogDouble petsc_wait_all_ct = 0.0; /* The number of waitalls */
79: PetscLogDouble petsc_sum_of_waits_ct = 0.0; /* The total number of waits */
80: PetscLogDouble petsc_allreduce_ct = 0.0; /* The number of reductions */
81: PetscLogDouble petsc_gather_ct = 0.0; /* The number of gathers and gathervs */
82: PetscLogDouble petsc_scatter_ct = 0.0; /* The number of scatters and scattervs */
84: /* Logging functions */
85: PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL;
86: PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL;
87: PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
88: PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL;
90: /* Tracing event logging variables */
91: FILE *petsc_tracefile = NULL;
92: int petsc_tracelevel = 0;
93: const char *petsc_traceblanks = " ";
94: char petsc_tracespace[128] = " ";
95: PetscLogDouble petsc_tracetime = 0.0;
96: static PetscBool PetscLogInitializeCalled = PETSC_FALSE;
98: PETSC_INTERN PetscErrorCode PetscLogInitialize(void)
99: {
100: int stage;
101: PetscBool opt;
105: if (PetscLogInitializeCalled) return(0);
106: PetscLogInitializeCalled = PETSC_TRUE;
108: PetscOptionsHasName(NULL,NULL, "-log_exclude_actions", &opt);
109: if (opt) petsc_logActions = PETSC_FALSE;
110: PetscOptionsHasName(NULL,NULL, "-log_exclude_objects", &opt);
111: if (opt) petsc_logObjects = PETSC_FALSE;
112: if (petsc_logActions) {
113: PetscMalloc1(petsc_maxActions, &petsc_actions);
114: }
115: if (petsc_logObjects) {
116: PetscMalloc1(petsc_maxObjects, &petsc_objects);
117: }
118: PetscLogPHC = PetscLogObjCreateDefault;
119: PetscLogPHD = PetscLogObjDestroyDefault;
120: /* Setup default logging structures */
121: PetscStageLogCreate(&petsc_stageLog);
122: PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);
124: /* All processors sync here for more consistent logging */
125: MPI_Barrier(PETSC_COMM_WORLD);
126: PetscTime(&petsc_BaseTime);
127: PetscLogStagePush(stage);
128: return(0);
129: }
131: PETSC_INTERN PetscErrorCode PetscLogFinalize(void)
132: {
133: PetscStageLog stageLog;
137: PetscFree(petsc_actions);
138: PetscFree(petsc_objects);
139: PetscLogNestedEnd();
140: PetscLogSet(NULL, NULL);
142: /* Resetting phase */
143: PetscLogGetStageLog(&stageLog);
144: PetscStageLogDestroy(stageLog);
146: petsc_TotalFlops = 0.0;
147: petsc_numActions = 0;
148: petsc_numObjects = 0;
149: petsc_numObjectsDestroyed = 0;
150: petsc_maxActions = 100;
151: petsc_maxObjects = 100;
152: petsc_actions = NULL;
153: petsc_objects = NULL;
154: petsc_logActions = PETSC_FALSE;
155: petsc_logObjects = PETSC_FALSE;
156: petsc_BaseTime = 0.0;
157: petsc_TotalFlops = 0.0;
158: petsc_tmp_flops = 0.0;
159: petsc_send_ct = 0.0;
160: petsc_recv_ct = 0.0;
161: petsc_send_len = 0.0;
162: petsc_recv_len = 0.0;
163: petsc_isend_ct = 0.0;
164: petsc_irecv_ct = 0.0;
165: petsc_isend_len = 0.0;
166: petsc_irecv_len = 0.0;
167: petsc_wait_ct = 0.0;
168: petsc_wait_any_ct = 0.0;
169: petsc_wait_all_ct = 0.0;
170: petsc_sum_of_waits_ct = 0.0;
171: petsc_allreduce_ct = 0.0;
172: petsc_gather_ct = 0.0;
173: petsc_scatter_ct = 0.0;
174: PETSC_LARGEST_EVENT = PETSC_EVENT;
175: PetscLogPHC = NULL;
176: PetscLogPHD = NULL;
177: petsc_tracefile = NULL;
178: petsc_tracelevel = 0;
179: petsc_traceblanks = " ";
180: petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0;
181: petsc_tracetime = 0.0;
182: PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
183: PETSC_OBJECT_CLASSID = 0;
184: petsc_stageLog = 0;
185: PetscLogInitializeCalled = PETSC_FALSE;
186: return(0);
187: }
189: /*@C
190: PetscLogSet - Sets the logging functions called at the beginning and ending of every event.
192: Not Collective
194: Input Parameters:
195: + b - The function called at beginning of event
196: - e - The function called at end of event
198: Level: developer
200: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogTraceBegin()
201: @*/
202: PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject),
203: PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject))
204: {
206: PetscLogPLB = b;
207: PetscLogPLE = e;
208: return(0);
209: }
211: /*@C
212: PetscLogDefaultBegin - Turns on logging of objects and events. This logs flop
213: rates and object creation and should not slow programs down too much.
214: This routine may be called more than once.
216: Logically Collective over PETSC_COMM_WORLD
218: Options Database Keys:
219: . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the
220: screen (for code configured with --with-log=1 (which is the default))
222: Usage:
223: .vb
224: PetscInitialize(...);
225: PetscLogDefaultBegin();
226: ... code ...
227: PetscLogView(viewer); or PetscLogDump();
228: PetscFinalize();
229: .ve
231: Notes:
232: PetscLogView(viewer) or PetscLogDump() actually cause the printing of
233: the logging information.
235: Level: advanced
237: .keywords: log, begin
238: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin()
239: @*/
240: PetscErrorCode PetscLogDefaultBegin(void)
241: {
245: PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);
246: return(0);
247: }
249: /*@C
250: PetscLogAllBegin - Turns on extensive logging of objects and events. Logs
251: all events. This creates large log files and slows the program down.
253: Logically Collective on PETSC_COMM_WORLD
255: Options Database Keys:
256: . -log_all - Prints extensive log information
258: Usage:
259: .vb
260: PetscInitialize(...);
261: PetscLogAllBegin();
262: ... code ...
263: PetscLogDump(filename);
264: PetscFinalize();
265: .ve
267: Notes:
268: A related routine is PetscLogDefaultBegin() (with the options key -log), which is
269: intended for production runs since it logs only flop rates and object
270: creation (and shouldn't significantly slow the programs).
272: Level: advanced
274: .keywords: log, all, begin
275: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogTraceBegin()
276: @*/
277: PetscErrorCode PetscLogAllBegin(void)
278: {
282: PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);
283: return(0);
284: }
286: /*@
287: PetscLogTraceBegin - Activates trace logging. Every time a PETSc event
288: begins or ends, the event name is printed.
290: Logically Collective on PETSC_COMM_WORLD
292: Input Parameter:
293: . file - The file to print trace in (e.g. stdout)
295: Options Database Key:
296: . -log_trace [filename] - Activates PetscLogTraceBegin()
298: Notes:
299: PetscLogTraceBegin() prints the processor number, the execution time (sec),
300: then "Event begin:" or "Event end:" followed by the event name.
302: PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful
303: to determine where a program is hanging without running in the
304: debugger. Can be used in conjunction with the -info option.
306: Level: intermediate
308: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogDefaultBegin()
309: @*/
310: PetscErrorCode PetscLogTraceBegin(FILE *file)
311: {
315: petsc_tracefile = file;
317: PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);
318: return(0);
319: }
321: /*@
322: PetscLogActions - Determines whether actions are logged for the graphical viewer.
324: Not Collective
326: Input Parameter:
327: . flag - PETSC_TRUE if actions are to be logged
329: Level: intermediate
331: Note: Logging of actions continues to consume more memory as the program
332: runs. Long running programs should consider turning this feature off.
334: Options Database Keys:
335: . -log_exclude_actions - Turns off actions logging
337: .keywords: log, stage, register
338: .seealso: PetscLogStagePush(), PetscLogStagePop()
339: @*/
340: PetscErrorCode PetscLogActions(PetscBool flag)
341: {
343: petsc_logActions = flag;
344: return(0);
345: }
347: /*@
348: PetscLogObjects - Determines whether objects are logged for the graphical viewer.
350: Not Collective
352: Input Parameter:
353: . flag - PETSC_TRUE if objects are to be logged
355: Level: intermediate
357: Note: Logging of objects continues to consume more memory as the program
358: runs. Long running programs should consider turning this feature off.
360: Options Database Keys:
361: . -log_exclude_objects - Turns off objects logging
363: .keywords: log, stage, register
364: .seealso: PetscLogStagePush(), PetscLogStagePop()
365: @*/
366: PetscErrorCode PetscLogObjects(PetscBool flag)
367: {
369: petsc_logObjects = flag;
370: return(0);
371: }
373: /*------------------------------------------------ Stage Functions --------------------------------------------------*/
374: /*@C
375: PetscLogStageRegister - Attaches a character string name to a logging stage.
377: Not Collective
379: Input Parameter:
380: . sname - The name to associate with that stage
382: Output Parameter:
383: . stage - The stage number
385: Level: intermediate
387: .keywords: log, stage, register
388: .seealso: PetscLogStagePush(), PetscLogStagePop()
389: @*/
390: PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage)
391: {
392: PetscStageLog stageLog;
393: PetscLogEvent event;
397: PetscLogGetStageLog(&stageLog);
398: PetscStageLogRegister(stageLog, sname, stage);
399: /* Copy events already changed in the main stage, this sucks */
400: PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);
401: for (event = 0; event < stageLog->eventLog->numEvents; event++) {
402: PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);
403: }
404: PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);
405: return(0);
406: }
408: /*@C
409: PetscLogStagePush - This function pushes a stage on the stack.
411: Not Collective
413: Input Parameter:
414: . stage - The stage on which to log
416: Usage:
417: If the option -log_sumary is used to run the program containing the
418: following code, then 2 sets of summary data will be printed during
419: PetscFinalize().
420: .vb
421: PetscInitialize(int *argc,char ***args,0,0);
422: [stage 0 of code]
423: PetscLogStagePush(1);
424: [stage 1 of code]
425: PetscLogStagePop();
426: PetscBarrier(...);
427: [more stage 0 of code]
428: PetscFinalize();
429: .ve
431: Notes:
432: Use PetscLogStageRegister() to register a stage.
434: Level: intermediate
436: .keywords: log, push, stage
437: .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier()
438: @*/
439: PetscErrorCode PetscLogStagePush(PetscLogStage stage)
440: {
441: PetscStageLog stageLog;
445: PetscLogGetStageLog(&stageLog);
446: PetscStageLogPush(stageLog, stage);
447: return(0);
448: }
450: /*@C
451: PetscLogStagePop - This function pops a stage from the stack.
453: Not Collective
455: Usage:
456: If the option -log_sumary is used to run the program containing the
457: following code, then 2 sets of summary data will be printed during
458: PetscFinalize().
459: .vb
460: PetscInitialize(int *argc,char ***args,0,0);
461: [stage 0 of code]
462: PetscLogStagePush(1);
463: [stage 1 of code]
464: PetscLogStagePop();
465: PetscBarrier(...);
466: [more stage 0 of code]
467: PetscFinalize();
468: .ve
470: Notes:
471: Use PetscLogStageRegister() to register a stage.
473: Level: intermediate
475: .keywords: log, pop, stage
476: .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier()
477: @*/
478: PetscErrorCode PetscLogStagePop(void)
479: {
480: PetscStageLog stageLog;
484: PetscLogGetStageLog(&stageLog);
485: PetscStageLogPop(stageLog);
486: return(0);
487: }
489: /*@
490: PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd().
492: Not Collective
494: Input Parameters:
495: + stage - The stage
496: - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
498: Level: intermediate
500: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
501: @*/
502: PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive)
503: {
504: PetscStageLog stageLog;
508: PetscLogGetStageLog(&stageLog);
509: PetscStageLogSetActive(stageLog, stage, isActive);
510: return(0);
511: }
513: /*@
514: PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd().
516: Not Collective
518: Input Parameter:
519: . stage - The stage
521: Output Parameter:
522: . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE)
524: Level: intermediate
526: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
527: @*/
528: PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive)
529: {
530: PetscStageLog stageLog;
534: PetscLogGetStageLog(&stageLog);
535: PetscStageLogGetActive(stageLog, stage, isActive);
536: return(0);
537: }
539: /*@
540: PetscLogStageSetVisible - Determines stage visibility in PetscLogView()
542: Not Collective
544: Input Parameters:
545: + stage - The stage
546: - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
548: Level: intermediate
550: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
551: @*/
552: PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible)
553: {
554: PetscStageLog stageLog;
558: PetscLogGetStageLog(&stageLog);
559: PetscStageLogSetVisible(stageLog, stage, isVisible);
560: return(0);
561: }
563: /*@
564: PetscLogStageGetVisible - Returns stage visibility in PetscLogView()
566: Not Collective
568: Input Parameter:
569: . stage - The stage
571: Output Parameter:
572: . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE)
574: Level: intermediate
576: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView()
577: @*/
578: PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible)
579: {
580: PetscStageLog stageLog;
584: PetscLogGetStageLog(&stageLog);
585: PetscStageLogGetVisible(stageLog, stage, isVisible);
586: return(0);
587: }
589: /*@C
590: PetscLogStageGetId - Returns the stage id when given the stage name.
592: Not Collective
594: Input Parameter:
595: . name - The stage name
597: Output Parameter:
598: . stage - The stage, , or -1 if no stage with that name exists
600: Level: intermediate
602: .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage()
603: @*/
604: PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage)
605: {
606: PetscStageLog stageLog;
610: PetscLogGetStageLog(&stageLog);
611: PetscStageLogGetStage(stageLog, name, stage);
612: return(0);
613: }
615: /*------------------------------------------------ Event Functions --------------------------------------------------*/
616: /*@C
617: PetscLogEventRegister - Registers an event name for logging operations in an application code.
619: Not Collective
621: Input Parameter:
622: + name - The name associated with the event
623: - classid - The classid associated to the class for this event, obtain either with
624: PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones
625: are only available in C code
627: Output Parameter:
628: . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd().
630: Example of Usage:
631: .vb
632: PetscLogEvent USER_EVENT;
633: PetscClassId classid;
634: PetscLogDouble user_event_flops;
635: PetscClassIdRegister("class name",&classid);
636: PetscLogEventRegister("User event name",classid,&USER_EVENT);
637: PetscLogEventBegin(USER_EVENT,0,0,0,0);
638: [code segment to monitor]
639: PetscLogFlops(user_event_flops);
640: PetscLogEventEnd(USER_EVENT,0,0,0,0);
641: .ve
643: Notes:
644: PETSc automatically logs library events if the code has been
645: configured with --with-log (which is the default) and
646: -log_view or -log_all is specified. PetscLogEventRegister() is
647: intended for logging user events to supplement this PETSc
648: information.
650: PETSc can gather data for use with the utilities Jumpshot
651: (part of the MPICH distribution). If PETSc has been compiled
652: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
653: MPICH), the user can employ another command line option, -log_mpe,
654: to create a logfile, "mpe.log", which can be visualized
655: Jumpshot.
657: The classid is associated with each event so that classes of events
658: can be disabled simultaneously, such as all matrix events. The user
659: can either use an existing classid, such as MAT_CLASSID, or create
660: their own as shown in the example.
662: If an existing event with the same name exists, its event handle is
663: returned instead of creating a new event.
665: Level: intermediate
667: .keywords: log, event, register
668: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
669: PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister()
670: @*/
671: PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event)
672: {
673: PetscStageLog stageLog;
674: int stage;
678: *event = PETSC_DECIDE;
679: PetscLogGetStageLog(&stageLog);
680: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
681: if (*event > 0) return(0);
682: PetscEventRegLogRegister(stageLog->eventLog, name, classid, event);
683: for (stage = 0; stage < stageLog->numStages; stage++) {
684: PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);
685: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
686: }
687: return(0);
688: }
690: /*@
691: PetscLogEventSetCollective - Indicates that a particular event is collective.
693: Not Collective
695: Input Parameter:
696: + event - The event id
697: - collective - Bolean flag indicating whether a particular event is collective
699: Note:
700: New events returned from PetscLogEventRegister() are collective by default.
702: Level: developer
704: .keywords: log, event, collective
705: .seealso: PetscLogEventRegister()
706: @*/
707: PetscErrorCode PetscLogEventSetCollective(PetscLogEvent event,PetscBool collective)
708: {
709: PetscStageLog stageLog;
710: PetscEventRegLog eventRegLog;
711: PetscErrorCode ierr;
714: PetscLogGetStageLog(&stageLog);
715: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
716: if (event < 0 || event > eventRegLog->numEvents) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_OUTOFRANGE,"Invalid event id");
717: eventRegLog->eventInfo[event].collective = collective;
718: return(0);
719: }
721: /*@
722: PetscLogEventIncludeClass - Activates event logging for a PETSc object class in every stage.
724: Not Collective
726: Input Parameter:
727: . classid - The object class, for example MAT_CLASSID, SNES_CLASSID, etc.
729: Level: developer
731: .keywords: log, event, include, class
732: .seealso: PetscLogEventActivateClass(),PetscLogEventDeactivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate()
733: @*/
734: PetscErrorCode PetscLogEventIncludeClass(PetscClassId classid)
735: {
736: PetscStageLog stageLog;
737: int stage;
741: PetscLogGetStageLog(&stageLog);
742: for (stage = 0; stage < stageLog->numStages; stage++) {
743: PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
744: }
745: return(0);
746: }
748: /*@
749: PetscLogEventExcludeClass - Deactivates event logging for a PETSc object class in every stage.
751: Not Collective
753: Input Parameter:
754: . classid - The object class, for example MAT_CLASSID, SNES_CLASSID, etc.
756: Level: developer
758: .keywords: log, event, exclude, class
759: .seealso: PetscLogEventDeactivateClass(),PetscLogEventActivateClass(),PetscLogEventDeactivate(),PetscLogEventActivate()
760: @*/
761: PetscErrorCode PetscLogEventExcludeClass(PetscClassId classid)
762: {
763: PetscStageLog stageLog;
764: int stage;
768: PetscLogGetStageLog(&stageLog);
769: for (stage = 0; stage < stageLog->numStages; stage++) {
770: PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
771: }
772: return(0);
773: }
775: /*@
776: PetscLogEventActivate - Indicates that a particular event should be logged.
778: Not Collective
780: Input Parameter:
781: . event - The event id
783: Usage:
784: .vb
785: PetscLogEventDeactivate(VEC_SetValues);
786: [code where you do not want to log VecSetValues()]
787: PetscLogEventActivate(VEC_SetValues);
788: [code where you do want to log VecSetValues()]
789: .ve
791: Note:
792: The event may be either a pre-defined PETSc event (found in include/petsclog.h)
793: or an event number obtained with PetscLogEventRegister().
795: Level: advanced
797: .keywords: log, event, activate
798: .seealso: PlogEventDeactivate()
799: @*/
800: PetscErrorCode PetscLogEventActivate(PetscLogEvent event)
801: {
802: PetscStageLog stageLog;
803: int stage;
807: PetscLogGetStageLog(&stageLog);
808: PetscStageLogGetCurrent(stageLog, &stage);
809: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
810: return(0);
811: }
813: /*@
814: PetscLogEventDeactivate - Indicates that a particular event should not be logged.
816: Not Collective
818: Input Parameter:
819: . event - The event id
821: Usage:
822: .vb
823: PetscLogEventDeactivate(VEC_SetValues);
824: [code where you do not want to log VecSetValues()]
825: PetscLogEventActivate(VEC_SetValues);
826: [code where you do want to log VecSetValues()]
827: .ve
829: Note:
830: The event may be either a pre-defined PETSc event (found in
831: include/petsclog.h) or an event number obtained with PetscLogEventRegister()).
833: Level: advanced
835: .keywords: log, event, deactivate
836: .seealso: PlogEventActivate()
837: @*/
838: PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event)
839: {
840: PetscStageLog stageLog;
841: int stage;
845: PetscLogGetStageLog(&stageLog);
846: PetscStageLogGetCurrent(stageLog, &stage);
847: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
848: return(0);
849: }
851: /*@
852: PetscLogEventSetActiveAll - Sets the event activity in every stage.
854: Not Collective
856: Input Parameters:
857: + event - The event id
858: - isActive - The activity flag determining whether the event is logged
860: Level: advanced
862: .keywords: log, event, activate
863: .seealso: PlogEventActivate(),PlogEventDeactivate()
864: @*/
865: PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive)
866: {
867: PetscStageLog stageLog;
868: int stage;
872: PetscLogGetStageLog(&stageLog);
873: for (stage = 0; stage < stageLog->numStages; stage++) {
874: if (isActive) {
875: PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);
876: } else {
877: PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);
878: }
879: }
880: return(0);
881: }
883: /*@
884: PetscLogEventActivateClass - Activates event logging for a PETSc object class.
886: Not Collective
888: Input Parameter:
889: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
891: Level: developer
893: .keywords: log, event, activate, class
894: .seealso: PetscLogEventDeactivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate()
895: @*/
896: PetscErrorCode PetscLogEventActivateClass(PetscClassId classid)
897: {
898: PetscStageLog stageLog;
899: int stage;
903: PetscLogGetStageLog(&stageLog);
904: PetscStageLogGetCurrent(stageLog, &stage);
905: PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
906: return(0);
907: }
909: /*@
910: PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class.
912: Not Collective
914: Input Parameter:
915: . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc.
917: Level: developer
919: .keywords: log, event, deactivate, class
920: .seealso: PetscLogEventActivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate()
921: @*/
922: PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid)
923: {
924: PetscStageLog stageLog;
925: int stage;
929: PetscLogGetStageLog(&stageLog);
930: PetscStageLogGetCurrent(stageLog, &stage);
931: PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);
932: return(0);
933: }
935: /*MC
936: PetscLogEventSync - Synchronizes the beginning of a user event.
938: Synopsis:
939: #include <petsclog.h>
940: PetscErrorCode PetscLogEventSync(int e,MPI_Comm comm)
942: Collective
944: Input Parameters:
945: + e - integer associated with the event obtained from PetscLogEventRegister()
946: - comm - an MPI communicator
948: Usage:
949: .vb
950: PetscLogEvent USER_EVENT;
951: PetscLogEventRegister("User event",0,&USER_EVENT);
952: PetscLogEventSync(USER_EVENT,PETSC_COMM_WORLD);
953: PetscLogEventBegin(USER_EVENT,0,0,0,0);
954: [code segment to monitor]
955: PetscLogEventEnd(USER_EVENT,0,0,0,0);
956: .ve
958: Notes:
959: This routine should be called only if there is not a
960: PetscObject available to pass to PetscLogEventBegin().
962: Level: developer
964: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd()
966: .keywords: log, event, synchronization
967: M*/
969: /*MC
970: PetscLogEventBegin - Logs the beginning of a user event.
972: Synopsis:
973: #include <petsclog.h>
974: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
976: Not Collective
978: Input Parameters:
979: + e - integer associated with the event obtained from PetscLogEventRegister()
980: - o1,o2,o3,o4 - objects associated with the event, or 0
983: Fortran Synopsis:
984: void PetscLogEventBegin(int e,PetscErrorCode ierr)
986: Usage:
987: .vb
988: PetscLogEvent USER_EVENT;
989: PetscLogDouble user_event_flops;
990: PetscLogEventRegister("User event",0,&USER_EVENT);
991: PetscLogEventBegin(USER_EVENT,0,0,0,0);
992: [code segment to monitor]
993: PetscLogFlops(user_event_flops);
994: PetscLogEventEnd(USER_EVENT,0,0,0,0);
995: .ve
997: Notes:
998: You need to register each integer event with the command
999: PetscLogEventRegister().
1001: Level: intermediate
1003: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
1005: .keywords: log, event, begin
1006: M*/
1008: /*MC
1009: PetscLogEventEnd - Log the end of a user event.
1011: Synopsis:
1012: #include <petsclog.h>
1013: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
1015: Not Collective
1017: Input Parameters:
1018: + e - integer associated with the event obtained with PetscLogEventRegister()
1019: - o1,o2,o3,o4 - objects associated with the event, or 0
1022: Fortran Synopsis:
1023: void PetscLogEventEnd(int e,PetscErrorCode ierr)
1025: Usage:
1026: .vb
1027: PetscLogEvent USER_EVENT;
1028: PetscLogDouble user_event_flops;
1029: PetscLogEventRegister("User event",0,&USER_EVENT,);
1030: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1031: [code segment to monitor]
1032: PetscLogFlops(user_event_flops);
1033: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1034: .ve
1036: Notes:
1037: You should also register each additional integer event with the command
1038: PetscLogEventRegister().
1040: Level: intermediate
1042: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
1044: .keywords: log, event, end
1045: M*/
1047: /*@C
1048: PetscLogEventGetId - Returns the event id when given the event name.
1050: Not Collective
1052: Input Parameter:
1053: . name - The event name
1055: Output Parameter:
1056: . event - The event, or -1 if no event with that name exists
1058: Level: intermediate
1060: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1061: @*/
1062: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1063: {
1064: PetscStageLog stageLog;
1068: PetscLogGetStageLog(&stageLog);
1069: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
1070: return(0);
1071: }
1074: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1075: /*@C
1076: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1077: be read by bin/petscview. This program no longer exists.
1079: Collective on PETSC_COMM_WORLD
1081: Input Parameter:
1082: . name - an optional file name
1084: Usage:
1085: .vb
1086: PetscInitialize(...);
1087: PetscLogDefaultBegin(); or PetscLogAllBegin();
1088: ... code ...
1089: PetscLogDump(filename);
1090: PetscFinalize();
1091: .ve
1093: Notes:
1094: The default file name is
1095: $ Log.<rank>
1096: where <rank> is the processor number. If no name is specified,
1097: this file will be used.
1099: Level: advanced
1101: .keywords: log, dump
1102: .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView()
1103: @*/
1104: PetscErrorCode PetscLogDump(const char sname[])
1105: {
1106: PetscStageLog stageLog;
1107: PetscEventPerfInfo *eventInfo;
1108: FILE *fd;
1109: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1110: PetscLogDouble flops, _TotalTime;
1111: PetscMPIInt rank;
1112: int action, object, curStage;
1113: PetscLogEvent event;
1114: PetscErrorCode ierr;
1117: /* Calculate the total elapsed time */
1118: PetscTime(&_TotalTime);
1119: _TotalTime -= petsc_BaseTime;
1120: /* Open log file */
1121: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1122: if (sname && sname[0]) sprintf(file, "%s.%d", sname, rank);
1123: else sprintf(file, "Log.%d", rank);
1124: PetscFixFilename(file, fname);
1125: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1126: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1127: /* Output totals */
1128: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1129: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1130: /* Output actions */
1131: if (petsc_logActions) {
1132: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1133: for (action = 0; action < petsc_numActions; action++) {
1134: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1135: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1136: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1137: }
1138: }
1139: /* Output objects */
1140: if (petsc_logObjects) {
1141: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1142: for (object = 0; object < petsc_numObjects; object++) {
1143: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1144: if (!petsc_objects[object].name[0]) {
1145: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1146: } else {
1147: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1148: }
1149: if (petsc_objects[object].info[0] != 0) {
1150: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1151: } else {
1152: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1153: }
1154: }
1155: }
1156: /* Output events */
1157: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1158: PetscLogGetStageLog(&stageLog);
1159: PetscIntStackTop(stageLog->stack, &curStage);
1160: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1161: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1162: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1163: else flops = 0.0;
1164: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1165: eventInfo[event].flops, eventInfo[event].time, flops);
1166: }
1167: PetscFClose(PETSC_COMM_WORLD, fd);
1168: return(0);
1169: }
1171: /*
1172: PetscLogView_Detailed - Each process prints the times for its own events
1174: */
1175: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1176: {
1177: PetscStageLog stageLog;
1178: PetscEventPerfInfo *eventInfo = NULL, *stageInfo = NULL;
1179: PetscLogDouble locTotalTime, numRed, maxMem;
1180: int numStages,numEvents,stage,event;
1181: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1182: PetscMPIInt rank,size;
1183: PetscErrorCode ierr;
1186: MPI_Comm_size(comm, &size);
1187: MPI_Comm_rank(comm, &rank);
1188: /* Must preserve reduction count before we go on */
1189: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1190: /* Get the total elapsed time */
1191: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1192: PetscViewerASCIIPrintf(viewer,"size = %d\n",size);
1193: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1194: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1195: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1196: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1197: PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");
1198: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1199: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1200: PetscLogGetStageLog(&stageLog);
1201: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1202: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1203: for (stage=0; stage<numStages; stage++) {
1204: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1205: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1206: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1207: for (event = 0; event < numEvents; event++) {
1208: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1209: }
1210: }
1211: PetscMallocGetMaximumUsage(&maxMem);
1212: PetscViewerASCIIPushSynchronized(viewer);
1213: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1214: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1215: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1216: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1217: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);
1218: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);
1219: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1220: PetscViewerFlush(viewer);
1221: for (stage=0; stage<numStages; stage++) {
1222: stageInfo = &stageLog->stageInfo[stage].perfInfo;
1223: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",
1224: stageLog->stageInfo[stage].name,rank,
1225: stageInfo->time,stageInfo->numMessages,stageInfo->messageLength,stageInfo->numReductions,stageInfo->flops);
1226: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1227: for (event = 0; event < numEvents; event++) {
1228: eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event];
1229: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"syncTime\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g",
1230: stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank,
1231: eventInfo->count,eventInfo->time,eventInfo->syncTime,eventInfo->numMessages,eventInfo->messageLength,eventInfo->numReductions,eventInfo->flops);
1232: if (eventInfo->dof[0] >= 0.) {
1233: PetscInt d, e;
1235: PetscViewerASCIISynchronizedPrintf(viewer, ", \"dof\" : [");
1236: for (d = 0; d < 8; ++d) {
1237: if (d > 0) {PetscViewerASCIISynchronizedPrintf(viewer, ", ");}
1238: PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->dof[d]);
1239: }
1240: PetscViewerASCIISynchronizedPrintf(viewer, "]");
1241: PetscViewerASCIISynchronizedPrintf(viewer, ", \"error\" : [");
1242: for (e = 0; e < 8; ++e) {
1243: if (e > 0) {PetscViewerASCIISynchronizedPrintf(viewer, ", ");}
1244: PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->errors[e]);
1245: }
1246: PetscViewerASCIISynchronizedPrintf(viewer, "]");
1247: }
1248: PetscViewerASCIISynchronizedPrintf(viewer,"}\n");
1249: }
1250: }
1251: PetscViewerFlush(viewer);
1252: PetscViewerASCIIPopSynchronized(viewer);
1253: return(0);
1254: }
1256: static PetscErrorCode PetscLogViewWarnSync(MPI_Comm comm,FILE *fd)
1257: {
1260: if (!PetscLogSyncOn) return(0);
1261: PetscFPrintf(comm, fd, "\n\n");
1262: PetscFPrintf(comm, fd, " ##########################################################\n");
1263: PetscFPrintf(comm, fd, " # #\n");
1264: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1265: PetscFPrintf(comm, fd, " # #\n");
1266: PetscFPrintf(comm, fd, " # This program was run with logging synchronization. #\n");
1267: PetscFPrintf(comm, fd, " # This option provides more meaningful imbalance #\n");
1268: PetscFPrintf(comm, fd, " # figures at the expense of slowing things down and #\n");
1269: PetscFPrintf(comm, fd, " # providing a distorted view of the overall runtime. #\n");
1270: PetscFPrintf(comm, fd, " # #\n");
1271: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1272: return(0);
1273: return(0);
1274: }
1276: static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd)
1277: {
1278: #if defined(PETSC_USE_DEBUG)
1282: PetscFPrintf(comm, fd, "\n\n");
1283: PetscFPrintf(comm, fd, " ##########################################################\n");
1284: PetscFPrintf(comm, fd, " # #\n");
1285: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1286: PetscFPrintf(comm, fd, " # #\n");
1287: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option. #\n");
1288: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1289: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1290: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1291: PetscFPrintf(comm, fd, " # #\n");
1292: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1293: return(0);
1294: #else
1295: return 0;
1296: #endif
1297: }
1299: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1300: {
1301: FILE *fd;
1302: PetscLogDouble zero = 0.0;
1303: PetscStageLog stageLog;
1304: PetscStageInfo *stageInfo = NULL;
1305: PetscEventPerfInfo *eventInfo = NULL;
1306: PetscClassPerfInfo *classInfo;
1307: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1308: const char *name;
1309: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1310: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1311: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1312: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1313: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1314: PetscLogDouble min, max, tot, ratio, avg, x, y;
1315: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratC, totm, totml, totr;
1316: PetscMPIInt minC, maxC;
1317: PetscMPIInt size, rank;
1318: PetscBool *localStageUsed, *stageUsed;
1319: PetscBool *localStageVisible, *stageVisible;
1320: int numStages, localNumEvents, numEvents;
1321: int stage, oclass;
1322: PetscLogEvent event;
1323: PetscErrorCode ierr;
1324: char version[256];
1325: MPI_Comm comm;
1328: PetscObjectGetComm((PetscObject)viewer,&comm);
1329: PetscViewerASCIIGetPointer(viewer,&fd);
1330: MPI_Comm_size(comm, &size);
1331: MPI_Comm_rank(comm, &rank);
1332: /* Get the total elapsed time */
1333: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1335: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1336: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1337: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1338: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1339: PetscLogViewWarnSync(comm,fd);
1340: PetscLogViewWarnDebugging(comm,fd);
1341: PetscGetArchType(arch,sizeof(arch));
1342: PetscGetHostName(hostname,sizeof(hostname));
1343: PetscGetUserName(username,sizeof(username));
1344: PetscGetProgramName(pname,sizeof(pname));
1345: PetscGetDate(date,sizeof(date));
1346: PetscGetVersion(version,sizeof(version));
1347: if (size == 1) {
1348: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1349: } else {
1350: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1351: }
1353: PetscFPrintf(comm, fd, "Using %s\n", version);
1355: /* Must preserve reduction count before we go on */
1356: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1358: /* Calculate summary information */
1359: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1360: /* Time */
1361: MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1362: MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1363: MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1364: avg = tot/((PetscLogDouble) size);
1365: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1366: PetscFPrintf(comm, fd, "Time (sec): %5.3e %7.3f %5.3e\n", max, ratio, avg);
1367: TotalTime = tot;
1368: /* Objects */
1369: avg = (PetscLogDouble) petsc_numObjects;
1370: MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1371: MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1372: MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1373: avg = tot/((PetscLogDouble) size);
1374: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1375: PetscFPrintf(comm, fd, "Objects: %5.3e %7.3f %5.3e\n", max, ratio, avg);
1376: /* Flops */
1377: MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1378: MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1379: MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1380: avg = tot/((PetscLogDouble) size);
1381: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1382: PetscFPrintf(comm, fd, "Flop: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1383: TotalFlops = tot;
1384: /* Flops/sec -- Must talk to Barry here */
1385: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime; else flops = 0.0;
1386: MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1387: MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1388: MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1389: avg = tot/((PetscLogDouble) size);
1390: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1391: PetscFPrintf(comm, fd, "Flop/sec: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1392: /* Memory */
1393: PetscMallocGetMaximumUsage(&mem);
1394: if (mem > 0.0) {
1395: MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1396: MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1397: MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1398: avg = tot/((PetscLogDouble) size);
1399: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1400: PetscFPrintf(comm, fd, "Memory: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1401: }
1402: /* Messages */
1403: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1404: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1405: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1406: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1407: avg = tot/((PetscLogDouble) size);
1408: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1409: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1410: numMessages = tot;
1411: /* Message Lengths */
1412: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1413: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1414: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1415: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1416: if (numMessages != 0) avg = tot/numMessages; else avg = 0.0;
1417: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1418: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1419: messageLength = tot;
1420: /* Reductions */
1421: MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1422: MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1423: MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1424: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1425: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %7.3f\n", max, ratio);
1426: numReductions = red; /* wrong because uses count from process zero */
1427: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1428: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");
1429: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");
1431: /* Get total number of stages --
1432: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1433: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1434: This seems best accomplished by assoicating a communicator with each stage.
1435: */
1436: PetscLogGetStageLog(&stageLog);
1437: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1438: PetscMalloc1(numStages, &localStageUsed);
1439: PetscMalloc1(numStages, &stageUsed);
1440: PetscMalloc1(numStages, &localStageVisible);
1441: PetscMalloc1(numStages, &stageVisible);
1442: if (numStages > 0) {
1443: stageInfo = stageLog->stageInfo;
1444: for (stage = 0; stage < numStages; stage++) {
1445: if (stage < stageLog->numStages) {
1446: localStageUsed[stage] = stageInfo[stage].used;
1447: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1448: } else {
1449: localStageUsed[stage] = PETSC_FALSE;
1450: localStageVisible[stage] = PETSC_TRUE;
1451: }
1452: }
1453: MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1454: MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1455: for (stage = 0; stage < numStages; stage++) {
1456: if (stageUsed[stage]) {
1457: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ------ --- Messages --- -- Message Lengths -- -- Reductions --\n");
1458: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total Count %%Total Avg %%Total Count %%Total \n");
1459: break;
1460: }
1461: }
1462: for (stage = 0; stage < numStages; stage++) {
1463: if (!stageUsed[stage]) continue;
1464: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1465: if (localStageUsed[stage]) {
1466: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1467: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1468: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1469: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1470: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1471: name = stageInfo[stage].name;
1472: } else {
1473: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1474: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1475: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1476: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1477: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1478: name = "";
1479: }
1480: mess *= 0.5; messLen *= 0.5; red /= size;
1481: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1482: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1483: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1484: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1485: if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0;
1486: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1487: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1488: 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",
1489: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1490: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1491: }
1492: }
1494: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1495: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1496: PetscFPrintf(comm, fd, "Phase summary info:\n");
1497: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1498: PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");
1499: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1500: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1501: PetscFPrintf(comm, fd, " AvgLen: average message length (bytes)\n");
1502: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1503: PetscFPrintf(comm, fd, " Global: entire computation\n");
1504: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1505: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");
1506: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1507: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1508: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");
1509: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1511: PetscLogViewWarnDebugging(comm,fd);
1513: /* Report events */
1514: PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage ---- Total\n");
1515: PetscFPrintf(comm, fd," Max Ratio Max Ratio Max Ratio Mess AvgLen Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s\n");
1516: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1518: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1519: for (stage = 0; stage < numStages; stage++) {
1520: if (!stageVisible[stage]) continue;
1521: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1522: if (localStageUsed[stage]) {
1523: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1524: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1525: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1526: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1527: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1528: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1529: } else {
1530: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1531: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1532: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1533: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1534: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1535: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1536: }
1537: mess *= 0.5; messLen *= 0.5; red /= size;
1539: /* Get total number of events in this stage --
1540: Currently, a single processor can register more events than another, but events must all be registered in order,
1541: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1542: on the event ID. This seems best accomplished by associating a communicator with each stage.
1544: Problem: If the event did not happen on proc 1, its name will not be available.
1545: Problem: Event visibility is not implemented
1546: */
1547: if (localStageUsed[stage]) {
1548: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1549: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1550: } else localNumEvents = 0;
1551: MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1552: for (event = 0; event < numEvents; event++) {
1553: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1554: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1555: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; else flopr = 0.0;
1556: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1557: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1558: MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1559: MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1560: MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1561: MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1562: MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1563: MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1564: MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1565: MPI_Allreduce(&eventInfo[event].count, &minC, 1, MPI_INT, MPI_MIN, comm);
1566: MPI_Allreduce(&eventInfo[event].count, &maxC, 1, MPI_INT, MPI_MAX, comm);
1567: name = stageLog->eventLog->eventInfo[event].name;
1568: } else {
1569: flopr = 0.0;
1570: MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1571: MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1572: MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1573: MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1574: MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1575: MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1576: MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1577: MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1578: MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1579: MPI_Allreduce(&ierr, &minC, 1, MPI_INT, MPI_MIN, comm);
1580: MPI_Allreduce(&ierr, &maxC, 1, MPI_INT, MPI_MAX, comm);
1581: name = "";
1582: }
1583: if (mint < 0.0) {
1584: 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);
1585: mint = 0;
1586: }
1587: 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);
1588: totm *= 0.5; totml *= 0.5; totr /= size;
1590: if (maxC != 0) {
1591: if (minC != 0) ratC = ((PetscLogDouble)maxC)/minC;else ratC = 0.0;
1592: if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0;
1593: if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0;
1594: if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0;
1595: if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0;
1596: if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0;
1597: if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0;
1598: if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0;
1599: if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0;
1600: if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0;
1601: if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0;
1602: if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0;
1603: if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0;
1604: if (totm != 0.0) totml /= totm; else totml = 0.0;
1605: if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0;
1606: 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");
1607: PetscFPrintf(comm, fd,
1608: "%-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",
1609: name, maxC, ratC, maxt, ratt, maxf, ratf, totm, totml, totr,
1610: 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed,
1611: 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed,
1612: PetscAbs(flopr)/1.0e6);
1613: }
1614: }
1615: }
1617: /* Memory usage and object creation */
1618: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1619: PetscFPrintf(comm, fd, "\n");
1620: PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");
1622: /* Right now, only stages on the first processor are reported here, meaning only objects associated with
1623: the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then
1624: stats for stages local to processor sets.
1625: */
1626: /* We should figure out the longest object name here (now 20 characters) */
1627: PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");
1628: PetscFPrintf(comm, fd, "Reports information only for process 0.\n");
1629: for (stage = 0; stage < numStages; stage++) {
1630: if (localStageUsed[stage]) {
1631: classInfo = stageLog->stageInfo[stage].classLog->classInfo;
1632: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1633: for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) {
1634: if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) {
1635: PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name,
1636: classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem,
1637: classInfo[oclass].descMem);
1638: }
1639: }
1640: } else {
1641: if (!localStageVisible[stage]) continue;
1642: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1643: }
1644: }
1646: PetscFree(localStageUsed);
1647: PetscFree(stageUsed);
1648: PetscFree(localStageVisible);
1649: PetscFree(stageVisible);
1651: /* Information unrelated to this particular run */
1652: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1653: PetscTime(&y);
1654: PetscTime(&x);
1655: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1656: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1657: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1658: /* MPI information */
1659: if (size > 1) {
1660: MPI_Status status;
1661: PetscMPIInt tag;
1662: MPI_Comm newcomm;
1664: MPI_Barrier(comm);
1665: PetscTime(&x);
1666: MPI_Barrier(comm);
1667: MPI_Barrier(comm);
1668: MPI_Barrier(comm);
1669: MPI_Barrier(comm);
1670: MPI_Barrier(comm);
1671: PetscTime(&y);
1672: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1673: PetscCommDuplicate(comm,&newcomm, &tag);
1674: MPI_Barrier(comm);
1675: if (rank) {
1676: MPI_Recv(NULL, 0, MPI_INT, rank-1, tag, newcomm, &status);
1677: MPI_Send(NULL, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1678: } else {
1679: PetscTime(&x);
1680: MPI_Send(NULL, 0, MPI_INT, 1, tag, newcomm);
1681: MPI_Recv(NULL, 0, MPI_INT, size-1, tag, newcomm, &status);
1682: PetscTime(&y);
1683: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1684: }
1685: PetscCommDestroy(&newcomm);
1686: }
1687: PetscOptionsView(NULL,viewer);
1689: /* Machine and compile information */
1690: #if defined(PETSC_USE_FORTRAN_KERNELS)
1691: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1692: #else
1693: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1694: #endif
1695: #if defined(PETSC_USE_64BIT_INDICES)
1696: PetscFPrintf(comm, fd, "Compiled with 64 bit PetscInt\n");
1697: #elif defined(PETSC_USE___FLOAT128)
1698: PetscFPrintf(comm, fd, "Compiled with 32 bit PetscInt\n");
1699: #endif
1700: #if defined(PETSC_USE_REAL_SINGLE)
1701: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1702: #elif defined(PETSC_USE___FLOAT128)
1703: PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");
1704: #endif
1705: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1706: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1707: #else
1708: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1709: #endif
1710: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1711: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1713: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1714: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1715: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1716: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1717: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1719: /* Cleanup */
1720: PetscFPrintf(comm, fd, "\n");
1721: PetscLogViewWarnDebugging(comm,fd);
1722: return(0);
1723: }
1725: /*@C
1726: PetscLogView - Prints a summary of the logging.
1728: Collective over MPI_Comm
1730: Input Parameter:
1731: . viewer - an ASCII viewer
1733: Options Database Keys:
1734: + -log_view [:filename] - Prints summary of log information
1735: . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file
1736: . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it)
1737: . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation
1738: - -log_trace [filename] - Displays a trace of what each process is doing
1740: Notes:
1741: It is possible to control the logging programatically but we recommend using the options database approach whenever possible
1742: By default the summary is printed to stdout.
1744: Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin()
1746: If PETSc is configured with --with-logging=0 then this functionality is not available
1748: To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current
1749: directory then open filename.xml with your browser. Specific notes for certain browsers
1750: $ Firefox and Internet explorer - simply open the file
1751: $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files
1752: $ Safari - see http://ccm.net/faq/36342-safari-how-to-enable-local-file-access
1753: or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with
1754: your browser.
1755: Alternatively, use the script ${PETSC_DIR}/lib/petsc/bin/petsc-performance-view to automatically open a new browser
1756: window and render the XML log file contents.
1758: The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS
1760: Level: beginner
1762: .keywords: log, dump, print
1763: .seealso: PetscLogDefaultBegin(), PetscLogDump()
1764: @*/
1765: PetscErrorCode PetscLogView(PetscViewer viewer)
1766: {
1767: PetscErrorCode ierr;
1768: PetscBool isascii;
1769: PetscViewerFormat format;
1770: int stage, lastStage;
1771: PetscStageLog stageLog;
1774: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
1775: /* Pop off any stages the user forgot to remove */
1776: lastStage = 0;
1777: PetscLogGetStageLog(&stageLog);
1778: PetscStageLogGetCurrent(stageLog, &stage);
1779: while (stage >= 0) {
1780: lastStage = stage;
1781: PetscStageLogPop(stageLog);
1782: PetscStageLogGetCurrent(stageLog, &stage);
1783: }
1784: PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);
1785: if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII");
1786: PetscViewerGetFormat(viewer,&format);
1787: if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) {
1788: PetscLogView_Default(viewer);
1789: } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) {
1790: PetscLogView_Detailed(viewer);
1791: } else if (format == PETSC_VIEWER_ASCII_XML) {
1792: PetscLogView_Nested(viewer);
1793: }
1794: PetscStageLogPush(stageLog, lastStage);
1795: return(0);
1796: }
1798: /*@C
1799: PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed.
1801: Collective on PETSC_COMM_WORLD
1803: Not normally called by user
1805: Level: intermediate
1807: @*/
1808: PetscErrorCode PetscLogViewFromOptions(void)
1809: {
1810: PetscErrorCode ierr;
1811: PetscViewer viewer;
1812: PetscBool flg;
1813: PetscViewerFormat format;
1816: PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,NULL,"-log_view",&viewer,&format,&flg);
1817: if (flg) {
1818: PetscViewerPushFormat(viewer,format);
1819: PetscLogView(viewer);
1820: PetscViewerPopFormat(viewer);
1821: PetscViewerDestroy(&viewer);
1822: }
1823: return(0);
1824: }
1828: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
1829: /*@C
1830: PetscGetFlops - Returns the number of flops used on this processor
1831: since the program began.
1833: Not Collective
1835: Output Parameter:
1836: flops - number of floating point operations
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: .keywords: log, flops, floating point operations
1847: .seealso: PetscTime(), PetscLogFlops()
1848: @*/
1849: PetscErrorCode PetscGetFlops(PetscLogDouble *flops)
1850: {
1852: *flops = petsc_TotalFlops;
1853: return(0);
1854: }
1856: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1857: {
1859: size_t fullLength;
1860: va_list Argp;
1863: if (!petsc_logObjects) return(0);
1864: va_start(Argp, format);
1865: PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);
1866: va_end(Argp);
1867: return(0);
1868: }
1871: /*MC
1872: PetscLogFlops - Adds floating point operations to the global counter.
1874: Synopsis:
1875: #include <petsclog.h>
1876: PetscErrorCode PetscLogFlops(PetscLogDouble f)
1878: Not Collective
1880: Input Parameter:
1881: . f - flop counter
1884: Usage:
1885: .vb
1886: PetscLogEvent USER_EVENT;
1887: PetscLogEventRegister("User event",0,&USER_EVENT);
1888: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1889: [code segment to monitor]
1890: PetscLogFlops(user_flops)
1891: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1892: .ve
1894: Notes:
1895: A global counter logs all PETSc flop counts. The user can use
1896: PetscLogFlops() to increment this counter to include flops for the
1897: application code.
1899: Level: intermediate
1901: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()
1903: .keywords: log, flops, floating point operations
1904: M*/
1906: /*MC
1907: PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice)
1908: to get accurate timings
1910: Synopsis:
1911: #include <petsclog.h>
1912: void PetscPreLoadBegin(PetscBool flag,char *name);
1914: Not Collective
1916: Input Parameter:
1917: + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
1918: with command line option -preload true or -preload false
1919: - name - name of first stage (lines of code timed separately with -log_view) to
1920: be preloaded
1922: Usage:
1923: .vb
1924: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1925: lines of code
1926: PetscPreLoadStage("second stage");
1927: lines of code
1928: PetscPreLoadEnd();
1929: .ve
1931: Notes:
1932: Only works in C/C++, not Fortran
1934: Flags available within the macro.
1935: + PetscPreLoadingUsed - true if we are or have done preloading
1936: . PetscPreLoadingOn - true if it is CURRENTLY doing preload
1937: . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
1938: - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on
1939: The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin()
1940: and PetscPreLoadEnd()
1942: Level: intermediate
1944: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage()
1946: Concepts: preloading
1947: Concepts: timing^accurate
1948: Concepts: paging^eliminating effects of
1951: M*/
1953: /*MC
1954: PetscPreLoadEnd - End a segment of code that may be preloaded (run twice)
1955: to get accurate timings
1957: Synopsis:
1958: #include <petsclog.h>
1959: void PetscPreLoadEnd(void);
1961: Not Collective
1963: Usage:
1964: .vb
1965: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1966: lines of code
1967: PetscPreLoadStage("second stage");
1968: lines of code
1969: PetscPreLoadEnd();
1970: .ve
1972: Notes:
1973: only works in C/C++ not fortran
1975: Level: intermediate
1977: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage()
1979: M*/
1981: /*MC
1982: PetscPreLoadStage - Start a new segment of code to be timed separately.
1983: to get accurate timings
1985: Synopsis:
1986: #include <petsclog.h>
1987: void PetscPreLoadStage(char *name);
1989: Not Collective
1991: Usage:
1992: .vb
1993: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1994: lines of code
1995: PetscPreLoadStage("second stage");
1996: lines of code
1997: PetscPreLoadEnd();
1998: .ve
2000: Notes:
2001: only works in C/C++ not fortran
2003: Level: intermediate
2005: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd()
2007: M*/
2010: #else /* end of -DPETSC_USE_LOG section */
2012: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
2013: {
2015: return(0);
2016: }
2018: #endif /* PETSC_USE_LOG*/
2021: PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
2022: PetscClassId PETSC_OBJECT_CLASSID = 0;
2024: /*@C
2025: PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code.
2027: Not Collective
2029: Input Parameter:
2030: . name - The class name
2032: Output Parameter:
2033: . oclass - The class id or classid
2035: Level: developer
2037: .keywords: log, class, register
2039: @*/
2040: PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass)
2041: {
2042: #if defined(PETSC_USE_LOG)
2043: PetscStageLog stageLog;
2044: PetscInt stage;
2046: #endif
2049: *oclass = ++PETSC_LARGEST_CLASSID;
2050: #if defined(PETSC_USE_LOG)
2051: PetscLogGetStageLog(&stageLog);
2052: PetscClassRegLogRegister(stageLog->classLog, name, *oclass);
2053: for (stage = 0; stage < stageLog->numStages; stage++) {
2054: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
2055: }
2056: #endif
2057: return(0);
2058: }
2060: #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE)
2061: #include <mpe.h>
2063: PetscBool PetscBeganMPE = PETSC_FALSE;
2065: PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2066: PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2068: /*@C
2069: PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files
2070: and slows the program down.
2072: Collective over PETSC_COMM_WORLD
2074: Options Database Keys:
2075: . -log_mpe - Prints extensive log information
2077: Notes:
2078: A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is
2079: intended for production runs since it logs only flop rates and object
2080: creation (and should not significantly slow the programs).
2082: Level: advanced
2084: Concepts: logging^MPE
2085: Concepts: logging^message passing
2087: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(),
2088: PetscLogEventDeactivate()
2089: @*/
2090: PetscErrorCode PetscLogMPEBegin(void)
2091: {
2095: /* Do MPE initialization */
2096: if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */
2097: PetscInfo(0,"Initializing MPE.\n");
2098: MPE_Init_log();
2100: PetscBeganMPE = PETSC_TRUE;
2101: } else {
2102: PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");
2103: }
2104: PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);
2105: return(0);
2106: }
2108: /*@C
2109: PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot.
2111: Collective over PETSC_COMM_WORLD
2113: Level: advanced
2115: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin()
2116: @*/
2117: PetscErrorCode PetscLogMPEDump(const char sname[])
2118: {
2119: char name[PETSC_MAX_PATH_LEN];
2123: if (PetscBeganMPE) {
2124: PetscInfo(0,"Finalizing MPE.\n");
2125: if (sname) {
2126: PetscStrcpy(name,sname);
2127: } else {
2128: PetscGetProgramName(name,PETSC_MAX_PATH_LEN);
2129: }
2130: MPE_Finish_log(name);
2131: } else {
2132: PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");
2133: }
2134: return(0);
2135: }
2137: #define PETSC_RGB_COLORS_MAX 39
2138: static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {
2139: "OliveDrab: ",
2140: "BlueViolet: ",
2141: "CadetBlue: ",
2142: "CornflowerBlue: ",
2143: "DarkGoldenrod: ",
2144: "DarkGreen: ",
2145: "DarkKhaki: ",
2146: "DarkOliveGreen: ",
2147: "DarkOrange: ",
2148: "DarkOrchid: ",
2149: "DarkSeaGreen: ",
2150: "DarkSlateGray: ",
2151: "DarkTurquoise: ",
2152: "DeepPink: ",
2153: "DarkKhaki: ",
2154: "DimGray: ",
2155: "DodgerBlue: ",
2156: "GreenYellow: ",
2157: "HotPink: ",
2158: "IndianRed: ",
2159: "LavenderBlush: ",
2160: "LawnGreen: ",
2161: "LemonChiffon: ",
2162: "LightCoral: ",
2163: "LightCyan: ",
2164: "LightPink: ",
2165: "LightSalmon: ",
2166: "LightSlateGray: ",
2167: "LightYellow: ",
2168: "LimeGreen: ",
2169: "MediumPurple: ",
2170: "MediumSeaGreen: ",
2171: "MediumSlateBlue:",
2172: "MidnightBlue: ",
2173: "MintCream: ",
2174: "MistyRose: ",
2175: "NavajoWhite: ",
2176: "NavyBlue: ",
2177: "OliveDrab: "
2178: };
2180: /*@C
2181: PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister()
2183: Not collective. Maybe it should be?
2185: Output Parameter
2186: . str - character string representing the color
2188: Level: developer
2190: .keywords: log, mpe , color
2191: .seealso: PetscLogEventRegister
2192: @*/
2193: PetscErrorCode PetscLogMPEGetRGBColor(const char *str[])
2194: {
2195: static int idx = 0;
2198: *str = PetscLogMPERGBColors[idx];
2199: idx = (idx + 1)% PETSC_RGB_COLORS_MAX;
2200: return(0);
2201: }
2203: #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */