Actual source code: plog.c
petsc-3.10.5 2019-03-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: PetscLogEventBegin - Logs the beginning of a user event.
938: Synopsis:
939: #include <petsclog.h>
940: PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
942: Not Collective
944: Input Parameters:
945: + e - integer associated with the event obtained from PetscLogEventRegister()
946: - o1,o2,o3,o4 - objects associated with the event, or 0
949: Fortran Synopsis:
950: void PetscLogEventBegin(int e,PetscErrorCode ierr)
952: Usage:
953: .vb
954: PetscLogEvent USER_EVENT;
955: PetscLogDouble user_event_flops;
956: PetscLogEventRegister("User event",0,&USER_EVENT);
957: PetscLogEventBegin(USER_EVENT,0,0,0,0);
958: [code segment to monitor]
959: PetscLogFlops(user_event_flops);
960: PetscLogEventEnd(USER_EVENT,0,0,0,0);
961: .ve
963: Notes:
964: You need to register each integer event with the command
965: PetscLogEventRegister().
967: Level: intermediate
969: .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops()
971: .keywords: log, event, begin
972: M*/
974: /*MC
975: PetscLogEventEnd - Log the end of a user event.
977: Synopsis:
978: #include <petsclog.h>
979: PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
981: Not Collective
983: Input Parameters:
984: + e - integer associated with the event obtained with PetscLogEventRegister()
985: - o1,o2,o3,o4 - objects associated with the event, or 0
988: Fortran Synopsis:
989: void PetscLogEventEnd(int e,PetscErrorCode ierr)
991: Usage:
992: .vb
993: PetscLogEvent USER_EVENT;
994: PetscLogDouble user_event_flops;
995: PetscLogEventRegister("User event",0,&USER_EVENT,);
996: PetscLogEventBegin(USER_EVENT,0,0,0,0);
997: [code segment to monitor]
998: PetscLogFlops(user_event_flops);
999: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1000: .ve
1002: Notes:
1003: You should also register each additional integer event with the command
1004: PetscLogEventRegister().
1006: Level: intermediate
1008: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops()
1010: .keywords: log, event, end
1011: M*/
1013: /*@C
1014: PetscLogEventGetId - Returns the event id when given the event name.
1016: Not Collective
1018: Input Parameter:
1019: . name - The event name
1021: Output Parameter:
1022: . event - The event, or -1 if no event with that name exists
1024: Level: intermediate
1026: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId()
1027: @*/
1028: PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event)
1029: {
1030: PetscStageLog stageLog;
1034: PetscLogGetStageLog(&stageLog);
1035: PetscEventRegLogGetEvent(stageLog->eventLog, name, event);
1036: return(0);
1037: }
1040: /*------------------------------------------------ Output Functions -------------------------------------------------*/
1041: /*@C
1042: PetscLogDump - Dumps logs of objects to a file. This file is intended to
1043: be read by bin/petscview. This program no longer exists.
1045: Collective on PETSC_COMM_WORLD
1047: Input Parameter:
1048: . name - an optional file name
1050: Usage:
1051: .vb
1052: PetscInitialize(...);
1053: PetscLogDefaultBegin(); or PetscLogAllBegin();
1054: ... code ...
1055: PetscLogDump(filename);
1056: PetscFinalize();
1057: .ve
1059: Notes:
1060: The default file name is
1061: $ Log.<rank>
1062: where <rank> is the processor number. If no name is specified,
1063: this file will be used.
1065: Level: advanced
1067: .keywords: log, dump
1068: .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView()
1069: @*/
1070: PetscErrorCode PetscLogDump(const char sname[])
1071: {
1072: PetscStageLog stageLog;
1073: PetscEventPerfInfo *eventInfo;
1074: FILE *fd;
1075: char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN];
1076: PetscLogDouble flops, _TotalTime;
1077: PetscMPIInt rank;
1078: int action, object, curStage;
1079: PetscLogEvent event;
1080: PetscErrorCode ierr;
1083: /* Calculate the total elapsed time */
1084: PetscTime(&_TotalTime);
1085: _TotalTime -= petsc_BaseTime;
1086: /* Open log file */
1087: MPI_Comm_rank(PETSC_COMM_WORLD, &rank);
1088: if (sname && sname[0]) sprintf(file, "%s.%d", sname, rank);
1089: else sprintf(file, "Log.%d", rank);
1090: PetscFixFilename(file, fname);
1091: PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);
1092: if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname);
1093: /* Output totals */
1094: PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);
1095: PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);
1096: /* Output actions */
1097: if (petsc_logActions) {
1098: PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);
1099: for (action = 0; action < petsc_numActions; action++) {
1100: PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n",
1101: petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1,
1102: petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);
1103: }
1104: }
1105: /* Output objects */
1106: if (petsc_logObjects) {
1107: PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);
1108: for (object = 0; object < petsc_numObjects; object++) {
1109: PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);
1110: if (!petsc_objects[object].name[0]) {
1111: PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");
1112: } else {
1113: PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);
1114: }
1115: if (petsc_objects[object].info[0] != 0) {
1116: PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");
1117: } else {
1118: PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);
1119: }
1120: }
1121: }
1122: /* Output events */
1123: PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");
1124: PetscLogGetStageLog(&stageLog);
1125: PetscIntStackTop(stageLog->stack, &curStage);
1126: eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo;
1127: for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) {
1128: if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time;
1129: else flops = 0.0;
1130: PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count,
1131: eventInfo[event].flops, eventInfo[event].time, flops);
1132: }
1133: PetscFClose(PETSC_COMM_WORLD, fd);
1134: return(0);
1135: }
1137: /*
1138: PetscLogView_Detailed - Each process prints the times for its own events
1140: */
1141: PetscErrorCode PetscLogView_Detailed(PetscViewer viewer)
1142: {
1143: PetscStageLog stageLog;
1144: PetscEventPerfInfo *eventInfo = NULL, *stageInfo = NULL;
1145: PetscLogDouble locTotalTime, numRed, maxMem;
1146: int numStages,numEvents,stage,event;
1147: MPI_Comm comm = PetscObjectComm((PetscObject) viewer);
1148: PetscMPIInt rank,size;
1149: PetscErrorCode ierr;
1152: MPI_Comm_size(comm, &size);
1153: MPI_Comm_rank(comm, &rank);
1154: /* Must preserve reduction count before we go on */
1155: numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1156: /* Get the total elapsed time */
1157: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1158: PetscViewerASCIIPrintf(viewer,"size = %d\n",size);
1159: PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");
1160: PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");
1161: PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");
1162: PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");
1163: PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");
1164: PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");
1165: PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");
1166: PetscLogGetStageLog(&stageLog);
1167: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1168: PetscViewerASCIIPrintf(viewer,"Stages = {}\n");
1169: for (stage=0; stage<numStages; stage++) {
1170: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);
1171: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);
1172: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1173: for (event = 0; event < numEvents; event++) {
1174: PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);
1175: }
1176: }
1177: PetscMallocGetMaximumUsage(&maxMem);
1178: PetscViewerASCIIPushSynchronized(viewer);
1179: PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);
1180: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));
1181: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));
1182: PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);
1183: PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);
1184: PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);
1185: PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);
1186: PetscViewerFlush(viewer);
1187: for (stage=0; stage<numStages; stage++) {
1188: stageInfo = &stageLog->stageInfo[stage].perfInfo;
1189: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",
1190: stageLog->stageInfo[stage].name,rank,
1191: stageInfo->time,stageInfo->numMessages,stageInfo->messageLength,stageInfo->numReductions,stageInfo->flops);
1192: MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1193: for (event = 0; event < numEvents; event++) {
1194: eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event];
1195: PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"syncTime\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",
1196: stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank,
1197: eventInfo->count,eventInfo->time,eventInfo->syncTime,eventInfo->numMessages,eventInfo->messageLength,eventInfo->numReductions,eventInfo->flops);
1198: }
1199: }
1200: PetscViewerFlush(viewer);
1201: PetscViewerASCIIPopSynchronized(viewer);
1202: return(0);
1203: }
1205: static PetscErrorCode PetscLogViewWarnSync(MPI_Comm comm,FILE *fd)
1206: {
1209: if (!PetscLogSyncOn) return(0);
1210: PetscFPrintf(comm, fd, "\n\n");
1211: PetscFPrintf(comm, fd, " ##########################################################\n");
1212: PetscFPrintf(comm, fd, " # #\n");
1213: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1214: PetscFPrintf(comm, fd, " # #\n");
1215: PetscFPrintf(comm, fd, " # This program was run with logging synchronization. #\n");
1216: PetscFPrintf(comm, fd, " # This option provides more meaningful imbalance #\n");
1217: PetscFPrintf(comm, fd, " # figures at the expense of slowing things down and #\n");
1218: PetscFPrintf(comm, fd, " # providing a distorted view of the overall runtime. #\n");
1219: PetscFPrintf(comm, fd, " # #\n");
1220: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1221: return(0);
1222: return(0);
1223: }
1225: static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd)
1226: {
1227: #if defined(PETSC_USE_DEBUG)
1231: PetscFPrintf(comm, fd, "\n\n");
1232: PetscFPrintf(comm, fd, " ##########################################################\n");
1233: PetscFPrintf(comm, fd, " # #\n");
1234: PetscFPrintf(comm, fd, " # WARNING!!! #\n");
1235: PetscFPrintf(comm, fd, " # #\n");
1236: PetscFPrintf(comm, fd, " # This code was compiled with a debugging option. #\n");
1237: PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");
1238: PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");
1239: PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");
1240: PetscFPrintf(comm, fd, " # #\n");
1241: PetscFPrintf(comm, fd, " ##########################################################\n\n\n");
1242: return(0);
1243: #else
1244: return 0;
1245: #endif
1246: }
1248: PetscErrorCode PetscLogView_Default(PetscViewer viewer)
1249: {
1250: FILE *fd;
1251: PetscLogDouble zero = 0.0;
1252: PetscStageLog stageLog;
1253: PetscStageInfo *stageInfo = NULL;
1254: PetscEventPerfInfo *eventInfo = NULL;
1255: PetscClassPerfInfo *classInfo;
1256: char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128];
1257: const char *name;
1258: PetscLogDouble locTotalTime, TotalTime, TotalFlops;
1259: PetscLogDouble numMessages, messageLength, avgMessLen, numReductions;
1260: PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red;
1261: PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed;
1262: PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed;
1263: PetscLogDouble min, max, tot, ratio, avg, x, y;
1264: PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratC, totm, totml, totr;
1265: PetscMPIInt minC, maxC;
1266: PetscMPIInt size, rank;
1267: PetscBool *localStageUsed, *stageUsed;
1268: PetscBool *localStageVisible, *stageVisible;
1269: int numStages, localNumEvents, numEvents;
1270: int stage, oclass;
1271: PetscLogEvent event;
1272: PetscErrorCode ierr;
1273: char version[256];
1274: MPI_Comm comm;
1277: PetscObjectGetComm((PetscObject)viewer,&comm);
1278: PetscViewerASCIIGetPointer(viewer,&fd);
1279: MPI_Comm_size(comm, &size);
1280: MPI_Comm_rank(comm, &rank);
1281: /* Get the total elapsed time */
1282: PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime;
1284: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1285: PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");
1286: PetscFPrintf(comm, fd, "************************************************************************************************************************\n");
1287: PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");
1288: PetscLogViewWarnSync(comm,fd);
1289: PetscLogViewWarnDebugging(comm,fd);
1290: PetscGetArchType(arch,sizeof(arch));
1291: PetscGetHostName(hostname,sizeof(hostname));
1292: PetscGetUserName(username,sizeof(username));
1293: PetscGetProgramName(pname,sizeof(pname));
1294: PetscGetDate(date,sizeof(date));
1295: PetscGetVersion(version,sizeof(version));
1296: if (size == 1) {
1297: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);
1298: } else {
1299: PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);
1300: }
1302: PetscFPrintf(comm, fd, "Using %s\n", version);
1304: /* Must preserve reduction count before we go on */
1305: red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
1307: /* Calculate summary information */
1308: PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");
1309: /* Time */
1310: MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1311: MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1312: MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1313: avg = tot/((PetscLogDouble) size);
1314: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1315: PetscFPrintf(comm, fd, "Time (sec): %5.3e %7.3f %5.3e\n", max, ratio, avg);
1316: TotalTime = tot;
1317: /* Objects */
1318: avg = (PetscLogDouble) petsc_numObjects;
1319: MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1320: MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1321: MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1322: avg = tot/((PetscLogDouble) size);
1323: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1324: PetscFPrintf(comm, fd, "Objects: %5.3e %7.3f %5.3e\n", max, ratio, avg);
1325: /* Flops */
1326: MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1327: MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1328: MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1329: avg = tot/((PetscLogDouble) size);
1330: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1331: PetscFPrintf(comm, fd, "Flop: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1332: TotalFlops = tot;
1333: /* Flops/sec -- Must talk to Barry here */
1334: if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime; else flops = 0.0;
1335: MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1336: MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1337: MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1338: avg = tot/((PetscLogDouble) size);
1339: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1340: PetscFPrintf(comm, fd, "Flop/sec: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1341: /* Memory */
1342: PetscMallocGetMaximumUsage(&mem);
1343: if (mem > 0.0) {
1344: MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1345: MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1346: MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1347: avg = tot/((PetscLogDouble) size);
1348: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1349: PetscFPrintf(comm, fd, "Memory: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1350: }
1351: /* Messages */
1352: mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct);
1353: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1354: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1355: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1356: avg = tot/((PetscLogDouble) size);
1357: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1358: PetscFPrintf(comm, fd, "MPI Messages: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1359: numMessages = tot;
1360: /* Message Lengths */
1361: mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len);
1362: MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1363: MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1364: MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1365: if (numMessages != 0) avg = tot/numMessages; else avg = 0.0;
1366: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1367: PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);
1368: messageLength = tot;
1369: /* Reductions */
1370: MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);
1371: MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);
1372: MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1373: if (min != 0.0) ratio = max/min; else ratio = 0.0;
1374: PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %7.3f\n", max, ratio);
1375: numReductions = red; /* wrong because uses count from process zero */
1376: PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");
1377: PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");
1378: PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");
1380: /* Get total number of stages --
1381: Currently, a single processor can register more stages than another, but stages must all be registered in order.
1382: We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID.
1383: This seems best accomplished by assoicating a communicator with each stage.
1384: */
1385: PetscLogGetStageLog(&stageLog);
1386: MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);
1387: PetscMalloc1(numStages, &localStageUsed);
1388: PetscMalloc1(numStages, &stageUsed);
1389: PetscMalloc1(numStages, &localStageVisible);
1390: PetscMalloc1(numStages, &stageVisible);
1391: if (numStages > 0) {
1392: stageInfo = stageLog->stageInfo;
1393: for (stage = 0; stage < numStages; stage++) {
1394: if (stage < stageLog->numStages) {
1395: localStageUsed[stage] = stageInfo[stage].used;
1396: localStageVisible[stage] = stageInfo[stage].perfInfo.visible;
1397: } else {
1398: localStageUsed[stage] = PETSC_FALSE;
1399: localStageVisible[stage] = PETSC_TRUE;
1400: }
1401: }
1402: MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);
1403: MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);
1404: for (stage = 0; stage < numStages; stage++) {
1405: if (stageUsed[stage]) {
1406: PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ------ --- Messages --- -- Message Lengths -- -- Reductions --\n");
1407: PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total Count %%Total Avg %%Total Count %%Total \n");
1408: break;
1409: }
1410: }
1411: for (stage = 0; stage < numStages; stage++) {
1412: if (!stageUsed[stage]) continue;
1413: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1414: if (localStageUsed[stage]) {
1415: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1416: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1417: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1418: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1419: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1420: name = stageInfo[stage].name;
1421: } else {
1422: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1423: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1424: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1425: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1426: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1427: name = "";
1428: }
1429: mess *= 0.5; messLen *= 0.5; red /= size;
1430: if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0;
1431: if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0;
1432: /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */
1433: if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0;
1434: if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0;
1435: if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0;
1436: if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0;
1437: 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",
1438: stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops,
1439: mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);
1440: }
1441: }
1443: PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");
1444: PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");
1445: PetscFPrintf(comm, fd, "Phase summary info:\n");
1446: PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");
1447: PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");
1448: PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");
1449: PetscFPrintf(comm, fd, " Mess: number of messages sent\n");
1450: PetscFPrintf(comm, fd, " AvgLen: average message length (bytes)\n");
1451: PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");
1452: PetscFPrintf(comm, fd, " Global: entire computation\n");
1453: PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");
1454: PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");
1455: PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");
1456: PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");
1457: PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");
1458: PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");
1460: PetscLogViewWarnDebugging(comm,fd);
1462: /* Report events */
1463: PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage ---- Total\n");
1464: 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");
1465: PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");
1467: /* Problem: The stage name will not show up unless the stage executed on proc 1 */
1468: for (stage = 0; stage < numStages; stage++) {
1469: if (!stageVisible[stage]) continue;
1470: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1471: if (localStageUsed[stage]) {
1472: PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);
1473: MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1474: MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1475: MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1476: MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1477: MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1478: } else {
1479: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1480: MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1481: MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1482: MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1483: MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1484: MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);
1485: }
1486: mess *= 0.5; messLen *= 0.5; red /= size;
1488: /* Get total number of events in this stage --
1489: Currently, a single processor can register more events than another, but events must all be registered in order,
1490: just like stages. We can removed this requirement if necessary by having a global event numbering and indirection
1491: on the event ID. This seems best accomplished by associating a communicator with each stage.
1493: Problem: If the event did not happen on proc 1, its name will not be available.
1494: Problem: Event visibility is not implemented
1495: */
1496: if (localStageUsed[stage]) {
1497: eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo;
1498: localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents;
1499: } else localNumEvents = 0;
1500: MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);
1501: for (event = 0; event < numEvents; event++) {
1502: /* CANNOT use MPIU_Allreduce() since it might fail the line number check */
1503: if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) {
1504: if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; 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, &minC, 1, MPI_INT, MPI_MIN, comm);
1515: MPI_Allreduce(&eventInfo[event].count, &maxC, 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, &minC, 1, MPI_INT, MPI_MIN, comm);
1529: MPI_Allreduce(&ierr, &maxC, 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 (maxC != 0) {
1540: if (minC != 0) ratC = ((PetscLogDouble)maxC)/minC;else ratC = 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, maxC, ratC, 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: PetscAbs(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: if (!localStageVisible[stage]) continue;
1591: PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);
1592: }
1593: }
1595: PetscFree(localStageUsed);
1596: PetscFree(stageUsed);
1597: PetscFree(localStageVisible);
1598: PetscFree(stageVisible);
1600: /* Information unrelated to this particular run */
1601: PetscFPrintf(comm, fd, "========================================================================================================================\n");
1602: PetscTime(&y);
1603: PetscTime(&x);
1604: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1605: PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y);
1606: PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);
1607: /* MPI information */
1608: if (size > 1) {
1609: MPI_Status status;
1610: PetscMPIInt tag;
1611: MPI_Comm newcomm;
1613: MPI_Barrier(comm);
1614: PetscTime(&x);
1615: MPI_Barrier(comm);
1616: MPI_Barrier(comm);
1617: MPI_Barrier(comm);
1618: MPI_Barrier(comm);
1619: MPI_Barrier(comm);
1620: PetscTime(&y);
1621: PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);
1622: PetscCommDuplicate(comm,&newcomm, &tag);
1623: MPI_Barrier(comm);
1624: if (rank) {
1625: MPI_Recv(NULL, 0, MPI_INT, rank-1, tag, newcomm, &status);
1626: MPI_Send(NULL, 0, MPI_INT, (rank+1)%size, tag, newcomm);
1627: } else {
1628: PetscTime(&x);
1629: MPI_Send(NULL, 0, MPI_INT, 1, tag, newcomm);
1630: MPI_Recv(NULL, 0, MPI_INT, size-1, tag, newcomm, &status);
1631: PetscTime(&y);
1632: PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);
1633: }
1634: PetscCommDestroy(&newcomm);
1635: }
1636: PetscOptionsView(NULL,viewer);
1638: /* Machine and compile information */
1639: #if defined(PETSC_USE_FORTRAN_KERNELS)
1640: PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");
1641: #else
1642: PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");
1643: #endif
1644: #if defined(PETSC_USE_64BIT_INDICES)
1645: PetscFPrintf(comm, fd, "Compiled with 64 bit PetscInt\n");
1646: #elif defined(PETSC_USE___FLOAT128)
1647: PetscFPrintf(comm, fd, "Compiled with 32 bit PetscInt\n");
1648: #endif
1649: #if defined(PETSC_USE_REAL_SINGLE)
1650: PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");
1651: #elif defined(PETSC_USE___FLOAT128)
1652: PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");
1653: #endif
1654: #if defined(PETSC_USE_REAL_MAT_SINGLE)
1655: PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");
1656: #else
1657: PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");
1658: #endif
1659: PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n",
1660: (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));
1662: PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);
1663: PetscFPrintf(comm, fd, "%s", petscmachineinfo);
1664: PetscFPrintf(comm, fd, "%s", petsccompilerinfo);
1665: PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);
1666: PetscFPrintf(comm, fd, "%s", petsclinkerinfo);
1668: /* Cleanup */
1669: PetscFPrintf(comm, fd, "\n");
1670: PetscLogViewWarnDebugging(comm,fd);
1671: return(0);
1672: }
1674: /*@C
1675: PetscLogView - Prints a summary of the logging.
1677: Collective over MPI_Comm
1679: Input Parameter:
1680: . viewer - an ASCII viewer
1682: Options Database Keys:
1683: + -log_view [:filename] - Prints summary of log information
1684: . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file
1685: . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it)
1686: . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation
1687: - -log_trace [filename] - Displays a trace of what each process is doing
1689: Notes:
1690: It is possible to control the logging programatically but we recommend using the options database approach whenever possible
1691: By default the summary is printed to stdout.
1693: Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin()
1695: If PETSc is configured with --with-logging=0 then this functionality is not available
1697: To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current
1698: directory then open filename.xml with your browser. Specific notes for certain browsers
1699: $ Firefox and Internet explorer - simply open the file
1700: $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files
1701: $ Safari - see http://ccm.net/faq/36342-safari-how-to-enable-local-file-access
1702: or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with
1703: your browser.
1705: The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS
1707: Level: beginner
1709: .keywords: log, dump, print
1710: .seealso: PetscLogDefaultBegin(), PetscLogDump()
1711: @*/
1712: PetscErrorCode PetscLogView(PetscViewer viewer)
1713: {
1714: PetscErrorCode ierr;
1715: PetscBool isascii;
1716: PetscViewerFormat format;
1717: int stage, lastStage;
1718: PetscStageLog stageLog;
1721: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
1722: /* Pop off any stages the user forgot to remove */
1723: lastStage = 0;
1724: PetscLogGetStageLog(&stageLog);
1725: PetscStageLogGetCurrent(stageLog, &stage);
1726: while (stage >= 0) {
1727: lastStage = stage;
1728: PetscStageLogPop(stageLog);
1729: PetscStageLogGetCurrent(stageLog, &stage);
1730: }
1731: PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);
1732: if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII");
1733: PetscViewerGetFormat(viewer,&format);
1734: if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) {
1735: PetscLogView_Default(viewer);
1736: } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) {
1737: PetscLogView_Detailed(viewer);
1738: } else if (format == PETSC_VIEWER_ASCII_XML) {
1739: PetscLogView_Nested(viewer);
1740: }
1741: PetscStageLogPush(stageLog, lastStage);
1742: return(0);
1743: }
1745: /*@C
1746: PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed.
1748: Collective on PETSC_COMM_WORLD
1750: Not normally called by user
1752: Level: intermediate
1754: @*/
1755: PetscErrorCode PetscLogViewFromOptions(void)
1756: {
1757: PetscErrorCode ierr;
1758: PetscViewer viewer;
1759: PetscBool flg;
1760: PetscViewerFormat format;
1763: PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);
1764: if (flg) {
1765: PetscViewerPushFormat(viewer,format);
1766: PetscLogView(viewer);
1767: PetscViewerPopFormat(viewer);
1768: PetscViewerDestroy(&viewer);
1769: }
1770: return(0);
1771: }
1775: /*----------------------------------------------- Counter Functions -------------------------------------------------*/
1776: /*@C
1777: PetscGetFlops - Returns the number of flops used on this processor
1778: since the program began.
1780: Not Collective
1782: Output Parameter:
1783: flops - number of floating point operations
1785: Notes:
1786: A global counter logs all PETSc flop counts. The user can use
1787: PetscLogFlops() to increment this counter to include flops for the
1788: application code.
1790: Level: intermediate
1792: .keywords: log, flops, floating point operations
1794: .seealso: PetscTime(), PetscLogFlops()
1795: @*/
1796: PetscErrorCode PetscGetFlops(PetscLogDouble *flops)
1797: {
1799: *flops = petsc_TotalFlops;
1800: return(0);
1801: }
1803: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1804: {
1806: size_t fullLength;
1807: va_list Argp;
1810: if (!petsc_logObjects) return(0);
1811: va_start(Argp, format);
1812: PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);
1813: va_end(Argp);
1814: return(0);
1815: }
1818: /*MC
1819: PetscLogFlops - Adds floating point operations to the global counter.
1821: Synopsis:
1822: #include <petsclog.h>
1823: PetscErrorCode PetscLogFlops(PetscLogDouble f)
1825: Not Collective
1827: Input Parameter:
1828: . f - flop counter
1831: Usage:
1832: .vb
1833: PetscLogEvent USER_EVENT;
1834: PetscLogEventRegister("User event",0,&USER_EVENT);
1835: PetscLogEventBegin(USER_EVENT,0,0,0,0);
1836: [code segment to monitor]
1837: PetscLogFlops(user_flops)
1838: PetscLogEventEnd(USER_EVENT,0,0,0,0);
1839: .ve
1841: Notes:
1842: A global counter logs all PETSc flop counts. The user can use
1843: PetscLogFlops() to increment this counter to include flops for the
1844: application code.
1846: Level: intermediate
1848: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops()
1850: .keywords: log, flops, floating point operations
1851: M*/
1853: /*MC
1854: PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice)
1855: to get accurate timings
1857: Synopsis:
1858: #include <petsclog.h>
1859: void PetscPreLoadBegin(PetscBool flag,char *name);
1861: Not Collective
1863: Input Parameter:
1864: + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden
1865: with command line option -preload true or -preload false
1866: - name - name of first stage (lines of code timed separately with -log_view) to
1867: be preloaded
1869: Usage:
1870: .vb
1871: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1872: lines of code
1873: PetscPreLoadStage("second stage");
1874: lines of code
1875: PetscPreLoadEnd();
1876: .ve
1878: Notes:
1879: Only works in C/C++, not Fortran
1881: Flags available within the macro.
1882: + PetscPreLoadingUsed - true if we are or have done preloading
1883: . PetscPreLoadingOn - true if it is CURRENTLY doing preload
1884: . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second
1885: - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on
1886: The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin()
1887: and PetscPreLoadEnd()
1889: Level: intermediate
1891: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage()
1893: Concepts: preloading
1894: Concepts: timing^accurate
1895: Concepts: paging^eliminating effects of
1898: M*/
1900: /*MC
1901: PetscPreLoadEnd - End a segment of code that may be preloaded (run twice)
1902: to get accurate timings
1904: Synopsis:
1905: #include <petsclog.h>
1906: void PetscPreLoadEnd(void);
1908: Not Collective
1910: Usage:
1911: .vb
1912: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1913: lines of code
1914: PetscPreLoadStage("second stage");
1915: lines of code
1916: PetscPreLoadEnd();
1917: .ve
1919: Notes:
1920: only works in C/C++ not fortran
1922: Level: intermediate
1924: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage()
1926: M*/
1928: /*MC
1929: PetscPreLoadStage - Start a new segment of code to be timed separately.
1930: to get accurate timings
1932: Synopsis:
1933: #include <petsclog.h>
1934: void PetscPreLoadStage(char *name);
1936: Not Collective
1938: Usage:
1939: .vb
1940: PetscPreLoadBegin(PETSC_TRUE,"first stage);
1941: lines of code
1942: PetscPreLoadStage("second stage");
1943: lines of code
1944: PetscPreLoadEnd();
1945: .ve
1947: Notes:
1948: only works in C/C++ not fortran
1950: Level: intermediate
1952: .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd()
1954: M*/
1957: #else /* end of -DPETSC_USE_LOG section */
1959: PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...)
1960: {
1962: return(0);
1963: }
1965: #endif /* PETSC_USE_LOG*/
1968: PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID;
1969: PetscClassId PETSC_OBJECT_CLASSID = 0;
1971: /*@C
1972: PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code.
1974: Not Collective
1976: Input Parameter:
1977: . name - The class name
1979: Output Parameter:
1980: . oclass - The class id or classid
1982: Level: developer
1984: .keywords: log, class, register
1986: @*/
1987: PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass)
1988: {
1989: #if defined(PETSC_USE_LOG)
1990: PetscStageLog stageLog;
1991: PetscInt stage;
1993: #endif
1996: *oclass = ++PETSC_LARGEST_CLASSID;
1997: #if defined(PETSC_USE_LOG)
1998: PetscLogGetStageLog(&stageLog);
1999: PetscClassRegLogRegister(stageLog->classLog, name, *oclass);
2000: for (stage = 0; stage < stageLog->numStages; stage++) {
2001: PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);
2002: }
2003: #endif
2004: return(0);
2005: }
2007: #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE)
2008: #include <mpe.h>
2010: PetscBool PetscBeganMPE = PETSC_FALSE;
2012: PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2013: PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject);
2015: /*@C
2016: PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files
2017: and slows the program down.
2019: Collective over PETSC_COMM_WORLD
2021: Options Database Keys:
2022: . -log_mpe - Prints extensive log information
2024: Notes:
2025: A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is
2026: intended for production runs since it logs only flop rates and object
2027: creation (and should not significantly slow the programs).
2029: Level: advanced
2031: Concepts: logging^MPE
2032: Concepts: logging^message passing
2034: .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(),
2035: PetscLogEventDeactivate()
2036: @*/
2037: PetscErrorCode PetscLogMPEBegin(void)
2038: {
2042: /* Do MPE initialization */
2043: if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */
2044: PetscInfo(0,"Initializing MPE.\n");
2045: MPE_Init_log();
2047: PetscBeganMPE = PETSC_TRUE;
2048: } else {
2049: PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");
2050: }
2051: PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);
2052: return(0);
2053: }
2055: /*@C
2056: PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot.
2058: Collective over PETSC_COMM_WORLD
2060: Level: advanced
2062: .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin()
2063: @*/
2064: PetscErrorCode PetscLogMPEDump(const char sname[])
2065: {
2066: char name[PETSC_MAX_PATH_LEN];
2070: if (PetscBeganMPE) {
2071: PetscInfo(0,"Finalizing MPE.\n");
2072: if (sname) {
2073: PetscStrcpy(name,sname);
2074: } else {
2075: PetscGetProgramName(name,PETSC_MAX_PATH_LEN);
2076: }
2077: MPE_Finish_log(name);
2078: } else {
2079: PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");
2080: }
2081: return(0);
2082: }
2084: #define PETSC_RGB_COLORS_MAX 39
2085: static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {
2086: "OliveDrab: ",
2087: "BlueViolet: ",
2088: "CadetBlue: ",
2089: "CornflowerBlue: ",
2090: "DarkGoldenrod: ",
2091: "DarkGreen: ",
2092: "DarkKhaki: ",
2093: "DarkOliveGreen: ",
2094: "DarkOrange: ",
2095: "DarkOrchid: ",
2096: "DarkSeaGreen: ",
2097: "DarkSlateGray: ",
2098: "DarkTurquoise: ",
2099: "DeepPink: ",
2100: "DarkKhaki: ",
2101: "DimGray: ",
2102: "DodgerBlue: ",
2103: "GreenYellow: ",
2104: "HotPink: ",
2105: "IndianRed: ",
2106: "LavenderBlush: ",
2107: "LawnGreen: ",
2108: "LemonChiffon: ",
2109: "LightCoral: ",
2110: "LightCyan: ",
2111: "LightPink: ",
2112: "LightSalmon: ",
2113: "LightSlateGray: ",
2114: "LightYellow: ",
2115: "LimeGreen: ",
2116: "MediumPurple: ",
2117: "MediumSeaGreen: ",
2118: "MediumSlateBlue:",
2119: "MidnightBlue: ",
2120: "MintCream: ",
2121: "MistyRose: ",
2122: "NavajoWhite: ",
2123: "NavyBlue: ",
2124: "OliveDrab: "
2125: };
2127: /*@C
2128: PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister()
2130: Not collective. Maybe it should be?
2132: Output Parameter
2133: . str - character string representing the color
2135: Level: developer
2137: .keywords: log, mpe , color
2138: .seealso: PetscLogEventRegister
2139: @*/
2140: PetscErrorCode PetscLogMPEGetRGBColor(const char *str[])
2141: {
2142: static int idx = 0;
2145: *str = PetscLogMPERGBColors[idx];
2146: idx = (idx + 1)% PETSC_RGB_COLORS_MAX;
2147: return(0);
2148: }
2150: #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */