Actual source code: eventlog.c
petsc-3.10.5 2019-03-28
2: /*
3: This defines part of the private API for logging performance information. It is intended to be used only by the
4: PETSc PetscLog...() interface and not elsewhere, nor by users. Hence the prototypes for these functions are NOT
5: in the public PETSc include files.
7: */
8: #include <petsc/private/logimpl.h>
10: PetscBool PetscLogSyncOn = PETSC_FALSE;
12: /*----------------------------------------------- Creation Functions -------------------------------------------------*/
13: /* Note: these functions do not have prototypes in a public directory, so they are considered "internal" and not exported. */
15: /*@C
16: PetscEventRegLogCreate - This creates a PetscEventRegLog object.
18: Not collective
20: Input Parameter:
21: . eventLog - The PetscEventRegLog
23: Level: developer
25: .keywords: log, event, create
26: .seealso: PetscEventRegLogDestroy(), PetscStageLogCreate()
27: @*/
28: PetscErrorCode PetscEventRegLogCreate(PetscEventRegLog *eventLog)
29: {
30: PetscEventRegLog l;
31: PetscErrorCode ierr;
34: PetscNew(&l);
35: l->numEvents = 0;
36: l->maxEvents = 100;
37: PetscMalloc1(l->maxEvents,&l->eventInfo);
38: *eventLog = l;
39: return(0);
40: }
42: /*@C
43: PetscEventRegLogDestroy - This destroys a PetscEventRegLog object.
45: Not collective
47: Input Paramter:
48: . eventLog - The PetscEventRegLog
50: Level: developer
52: .keywords: log, event, destroy
53: .seealso: PetscEventRegLogCreate()
54: @*/
55: PetscErrorCode PetscEventRegLogDestroy(PetscEventRegLog eventLog)
56: {
57: int e;
61: for (e = 0; e < eventLog->numEvents; e++) {
62: PetscFree(eventLog->eventInfo[e].name);
63: }
64: PetscFree(eventLog->eventInfo);
65: PetscFree(eventLog);
66: return(0);
67: }
69: /*@C
70: PetscEventPerfLogCreate - This creates a PetscEventPerfLog object.
72: Not collective
74: Input Parameter:
75: . eventLog - The PetscEventPerfLog
77: Level: developer
79: .keywords: log, event, create
80: .seealso: PetscEventPerfLogDestroy(), PetscStageLogCreate()
81: @*/
82: PetscErrorCode PetscEventPerfLogCreate(PetscEventPerfLog *eventLog)
83: {
84: PetscEventPerfLog l;
85: PetscErrorCode ierr;
88: PetscNew(&l);
89: l->numEvents = 0;
90: l->maxEvents = 100;
91: PetscMalloc1(l->maxEvents,&l->eventInfo);
92: *eventLog = l;
93: return(0);
94: }
96: /*@C
97: PetscEventPerfLogDestroy - This destroys a PetscEventPerfLog object.
99: Not collective
101: Input Paramter:
102: . eventLog - The PetscEventPerfLog
104: Level: developer
106: .keywords: log, event, destroy
107: .seealso: PetscEventPerfLogCreate()
108: @*/
109: PetscErrorCode PetscEventPerfLogDestroy(PetscEventPerfLog eventLog)
110: {
114: PetscFree(eventLog->eventInfo);
115: PetscFree(eventLog);
116: return(0);
117: }
119: /*------------------------------------------------ General Functions -------------------------------------------------*/
120: /*@C
121: PetscEventPerfInfoClear - This clears a PetscEventPerfInfo object.
123: Not collective
125: Input Paramter:
126: . eventInfo - The PetscEventPerfInfo
128: Level: developer
130: .keywords: log, event, destroy
131: .seealso: PetscEventPerfLogCreate()
132: @*/
133: PetscErrorCode PetscEventPerfInfoClear(PetscEventPerfInfo *eventInfo)
134: {
136: eventInfo->id = -1;
137: eventInfo->active = PETSC_TRUE;
138: eventInfo->visible = PETSC_TRUE;
139: eventInfo->depth = 0;
140: eventInfo->count = 0;
141: eventInfo->flops = 0.0;
142: eventInfo->flops2 = 0.0;
143: eventInfo->flopsTmp = 0.0;
144: eventInfo->time = 0.0;
145: eventInfo->time2 = 0.0;
146: eventInfo->timeTmp = 0.0;
147: eventInfo->syncTime = 0.0;
148: eventInfo->numMessages = 0.0;
149: eventInfo->messageLength = 0.0;
150: eventInfo->numReductions = 0.0;
151: return(0);
152: }
154: /*@C
155: PetscEventPerfInfoCopy - Copy the activity and visibility data in eventInfo to outInfo
157: Not collective
159: Input Paramter:
160: . eventInfo - The input PetscEventPerfInfo
162: Output Paramter:
163: . outInfo - The output PetscEventPerfInfo
165: Level: developer
167: .keywords: log, event, copy
168: .seealso: PetscEventPerfInfoClear()
169: @*/
170: PetscErrorCode PetscEventPerfInfoCopy(PetscEventPerfInfo *eventInfo,PetscEventPerfInfo *outInfo)
171: {
173: outInfo->id = eventInfo->id;
174: outInfo->active = eventInfo->active;
175: outInfo->visible = eventInfo->visible;
176: return(0);
177: }
179: /*@C
180: PetscEventPerfLogEnsureSize - This ensures that a PetscEventPerfLog is at least of a certain size.
182: Not collective
184: Input Paramters:
185: + eventLog - The PetscEventPerfLog
186: - size - The size
188: Level: developer
190: .keywords: log, event, size, ensure
191: .seealso: PetscEventPerfLogCreate()
192: @*/
193: PetscErrorCode PetscEventPerfLogEnsureSize(PetscEventPerfLog eventLog,int size)
194: {
195: PetscEventPerfInfo *eventInfo;
196: PetscErrorCode ierr;
199: while (size > eventLog->maxEvents) {
200: PetscMalloc1(eventLog->maxEvents*2,&eventInfo);
201: PetscMemcpy(eventInfo,eventLog->eventInfo,eventLog->maxEvents * sizeof(PetscEventPerfInfo));
202: PetscFree(eventLog->eventInfo);
203: eventLog->eventInfo = eventInfo;
204: eventLog->maxEvents *= 2;
205: }
206: while (eventLog->numEvents < size) {
207: PetscEventPerfInfoClear(&eventLog->eventInfo[eventLog->numEvents++]);
208: }
209: return(0);
210: }
212: #if defined(PETSC_HAVE_MPE)
213: #include <mpe.h>
214: PETSC_INTERN PetscErrorCode PetscLogMPEGetRGBColor(const char*[]);
215: PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
216: {
217: PetscErrorCode ierr;
220: MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_begin,0,NULL);
221: return(0);
222: }
224: PetscErrorCode PetscLogEventEndMPE(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
225: {
226: PetscErrorCode ierr;
229: MPE_Log_event(petsc_stageLog->eventLog->eventInfo[event].mpe_id_end,0,NULL);
230: return(0);
231: }
232: #endif
234: /*--------------------------------------------- Registration Functions ----------------------------------------------*/
235: /*@C
236: PetscEventRegLogRegister - Registers an event for logging operations in an application code.
238: Not Collective
240: Input Parameters:
241: + eventLog - The PetscEventLog
242: . ename - The name associated with the event
243: - classid - The classid associated to the class for this event
245: Output Parameter:
246: . event - The event
248: Example of Usage:
249: .vb
250: int USER_EVENT;
251: PetscLogDouble user_event_flops;
252: PetscLogEventRegister("User event name",0,&USER_EVENT);
253: PetscLogEventBegin(USER_EVENT,0,0,0,0);
254: [code segment to monitor]
255: PetscLogFlops(user_event_flops);
256: PetscLogEventEnd(USER_EVENT,0,0,0,0);
257: .ve
259: Notes:
261: PETSc can gather data for use with the utilities Jumpshot
262: (part of the MPICH distribution). If PETSc has been compiled
263: with flag -DPETSC_HAVE_MPE (MPE is an additional utility within
264: MPICH), the user can employ another command line option, -log_mpe,
265: to create a logfile, "mpe.log", which can be visualized
266: Jumpshot.
268: Level: developer
270: .keywords: log, event, register
271: .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(),
272: PetscEventLogActivate(), PetscEventLogDeactivate()
273: @*/
274: PetscErrorCode PetscEventRegLogRegister(PetscEventRegLog eventLog,const char ename[],PetscClassId classid,PetscLogEvent *event)
275: {
276: PetscEventRegInfo *eventInfo;
277: char *str;
278: int e;
279: PetscErrorCode ierr;
284: /* Should check classid I think */
285: e = eventLog->numEvents++;
286: if (eventLog->numEvents > eventLog->maxEvents) {
287: PetscMalloc1(eventLog->maxEvents*2,&eventInfo);
288: PetscMemcpy(eventInfo,eventLog->eventInfo,eventLog->maxEvents * sizeof(PetscEventRegInfo));
289: PetscFree(eventLog->eventInfo);
290: eventLog->eventInfo = eventInfo;
291: eventLog->maxEvents *= 2;
292: }
293: PetscStrallocpy(ename,&str);
295: eventLog->eventInfo[e].name = str;
296: eventLog->eventInfo[e].classid = classid;
297: eventLog->eventInfo[e].collective = PETSC_TRUE;
298: #if defined(PETSC_HAVE_MPE)
299: if (PetscLogPLB == PetscLogEventBeginMPE) {
300: const char *color;
301: PetscMPIInt rank;
302: int beginID,endID;
304: beginID = MPE_Log_get_event_number();
305: endID = MPE_Log_get_event_number();
307: eventLog->eventInfo[e].mpe_id_begin = beginID;
308: eventLog->eventInfo[e].mpe_id_end = endID;
310: MPI_Comm_rank(PETSC_COMM_WORLD,&rank);
311: if (!rank) {
312: PetscLogMPEGetRGBColor(&color);
313: MPE_Describe_state(beginID,endID,str,(char*)color);
314: }
315: }
316: #endif
317: *event = e;
318: return(0);
319: }
321: /*---------------------------------------------- Activation Functions -----------------------------------------------*/
322: /*@C
323: PetscEventPerfLogActivate - Indicates that a particular event should be logged.
325: Not Collective
327: Input Parameters:
328: + eventLog - The PetscEventPerfLog
329: - event - The event
331: Usage:
332: .vb
333: PetscEventPerfLogDeactivate(log, VEC_SetValues);
334: [code where you do not want to log VecSetValues()]
335: PetscEventPerfLogActivate(log, VEC_SetValues);
336: [code where you do want to log VecSetValues()]
337: .ve
339: Note:
340: The event may be either a pre-defined PETSc event (found in
341: include/petsclog.h) or an event number obtained with PetscEventRegLogRegister().
343: Level: developer
345: .keywords: log, event, activate
346: .seealso: PetscEventPerfLogDeactivate()
347: @*/
348: PetscErrorCode PetscEventPerfLogActivate(PetscEventPerfLog eventLog,PetscLogEvent event)
349: {
351: eventLog->eventInfo[event].active = PETSC_TRUE;
352: return(0);
353: }
355: /*@C
356: PetscEventPerfLogDeactivate - Indicates that a particular event should not be logged.
358: Not Collective
360: Input Parameters:
361: + eventLog - The PetscEventPerfLog
362: - event - The event
364: Usage:
365: .vb
366: PetscEventPerfLogDeactivate(log, VEC_SetValues);
367: [code where you do not want to log VecSetValues()]
368: PetscEventPerfLogActivate(log, VEC_SetValues);
369: [code where you do want to log VecSetValues()]
370: .ve
372: Note:
373: The event may be either a pre-defined PETSc event (found in
374: include/petsclog.h) or an event number obtained with PetscEventRegLogRegister().
376: Level: developer
378: .keywords: log, event, activate
379: .seealso: PetscEventPerfLogActivate()
380: @*/
381: PetscErrorCode PetscEventPerfLogDeactivate(PetscEventPerfLog eventLog,PetscLogEvent event)
382: {
384: eventLog->eventInfo[event].active = PETSC_FALSE;
385: return(0);
386: }
388: /*@C
389: PetscEventPerfLogActivateClass - Activates event logging for a PETSc object class.
391: Not Collective
393: Input Parameters:
394: + eventLog - The PetscEventPerfLog
395: . eventRegLog - The PetscEventRegLog
396: - classid - The class id, for example MAT_CLASSID, SNES_CLASSID,
398: Level: developer
400: .seealso: PetscEventPerfLogDeactivateClass(), PetscEventPerfLogActivate(), PetscEventPerfLogDeactivate()
401: @*/
402: PetscErrorCode PetscEventPerfLogActivateClass(PetscEventPerfLog eventLog,PetscEventRegLog eventRegLog,PetscClassId classid)
403: {
404: int e;
407: for (e = 0; e < eventLog->numEvents; e++) {
408: int c = eventRegLog->eventInfo[e].classid;
409: if (c == classid) eventLog->eventInfo[e].active = PETSC_TRUE;
410: }
411: return(0);
412: }
414: /*@C
415: PetscEventPerfLogDeactivateClass - Deactivates event logging for a PETSc object class.
417: Not Collective
419: Input Parameters:
420: + eventLog - The PetscEventPerfLog
421: . eventRegLog - The PetscEventRegLog
422: - classid - The class id, for example MAT_CLASSID, SNES_CLASSID,
424: Level: developer
426: .seealso: PetscEventPerfLogDeactivateClass(), PetscEventPerfLogDeactivate(), PetscEventPerfLogActivate()
427: @*/
428: PetscErrorCode PetscEventPerfLogDeactivateClass(PetscEventPerfLog eventLog,PetscEventRegLog eventRegLog,PetscClassId classid)
429: {
430: int e;
433: for (e = 0; e < eventLog->numEvents; e++) {
434: int c = eventRegLog->eventInfo[e].classid;
435: if (c == classid) eventLog->eventInfo[e].active = PETSC_FALSE;
436: }
437: return(0);
438: }
440: /*------------------------------------------------ Query Functions --------------------------------------------------*/
441: /*@C
442: PetscEventRegLogGetEvent - This function returns the event id given the event name.
444: Not Collective
446: Input Parameters:
447: + eventLog - The PetscEventRegLog
448: - name - The stage name
450: Output Parameter:
451: . event - The event id, or -1 if not found
453: Level: developer
455: .keywords: log, stage
456: .seealso: PetscEventRegLogRegister()
457: @*/
458: PetscErrorCode PetscEventRegLogGetEvent(PetscEventRegLog eventLog,const char name[],PetscLogEvent *event)
459: {
460: PetscBool match;
461: int e;
467: *event = -1;
468: for (e = 0; e < eventLog->numEvents; e++) {
469: PetscStrcasecmp(eventLog->eventInfo[e].name,name,&match);
470: if (match) {
471: *event = e;
472: break;
473: }
474: }
475: return(0);
476: }
478: /*@C
479: PetscEventPerfLogSetVisible - This function determines whether an event is printed during PetscLogView()
481: Not Collective
483: Input Parameters:
484: + eventLog - The PetscEventPerfLog
485: . event - The event to log
486: - isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)
488: Database Options:
489: . -log_view - Activates log summary
491: Level: developer
493: .keywords: log, visible, event
494: .seealso: PetscEventPerfLogGetVisible(), PetscEventRegLogRegister(), PetscStageLogGetEventLog()
495: @*/
496: PetscErrorCode PetscEventPerfLogSetVisible(PetscEventPerfLog eventLog,PetscLogEvent event,PetscBool isVisible)
497: {
499: eventLog->eventInfo[event].visible = isVisible;
500: return(0);
501: }
503: /*@C
504: PetscEventPerfLogGetVisible - This function returns whether an event is printed during PetscLogView()
506: Not Collective
508: Input Parameters:
509: + eventLog - The PetscEventPerfLog
510: - event - The event id to log
512: Output Parameter:
513: . isVisible - The visibility flag, PETSC_TRUE for printing, otherwise PETSC_FALSE (default is PETSC_TRUE)
515: Database Options:
516: . -log_view - Activates log summary
518: Level: developer
520: .keywords: log, visible, event
521: .seealso: PetscEventPerfLogSetVisible(), PetscEventRegLogRegister(), PetscStageLogGetEventLog()
522: @*/
523: PetscErrorCode PetscEventPerfLogGetVisible(PetscEventPerfLog eventLog,PetscLogEvent event,PetscBool *isVisible)
524: {
527: *isVisible = eventLog->eventInfo[event].visible;
528: return(0);
529: }
531: /*@C
532: PetscLogEventGetPerfInfo - Return the performance information about the given event in the given stage
534: Input Parameters:
535: + stage - The stage number or PETSC_DETERMINE for the current stage
536: - event - The event number
538: Output Parameters:
539: . info - This structure is filled with the performance information
541: Level: Intermediate
543: .seealso: PetscLogEventGetFlops()
544: @*/
545: PetscErrorCode PetscLogEventGetPerfInfo(int stage,PetscLogEvent event,PetscEventPerfInfo *info)
546: {
547: PetscStageLog stageLog;
548: PetscEventPerfLog eventLog = NULL;
549: PetscErrorCode ierr;
553: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
554: PetscLogGetStageLog(&stageLog);
555: if (stage < 0) {PetscStageLogGetCurrent(stageLog,&stage);}
556: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
557: *info = eventLog->eventInfo[event];
558: return(0);
559: }
561: PetscErrorCode PetscLogEventGetFlops(PetscLogEvent event,PetscLogDouble *flops)
562: {
563: PetscStageLog stageLog;
564: PetscEventPerfLog eventLog = NULL;
565: int stage;
566: PetscErrorCode ierr;
569: if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine");
570: PetscLogGetStageLog(&stageLog);
571: PetscStageLogGetCurrent(stageLog,&stage);
572: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
573: *flops = eventLog->eventInfo[event].flops;
574: return(0);
575: }
577: PetscErrorCode PetscLogEventZeroFlops(PetscLogEvent event)
578: {
579: PetscStageLog stageLog;
580: PetscEventPerfLog eventLog = NULL;
581: int stage;
582: PetscErrorCode ierr;
585: PetscLogGetStageLog(&stageLog);
586: PetscStageLogGetCurrent(stageLog,&stage);
587: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
589: eventLog->eventInfo[event].flops = 0.0;
590: eventLog->eventInfo[event].flops2 = 0.0;
591: eventLog->eventInfo[event].flopsTmp = 0.0;
592: return(0);
593: }
595: PetscErrorCode PetscLogEventSynchronize(PetscLogEvent event,MPI_Comm comm)
596: {
597: PetscStageLog stageLog;
598: PetscEventRegLog eventRegLog;
599: PetscEventPerfLog eventLog = NULL;
600: int stage;
601: PetscLogDouble time = 0.0;
602: PetscErrorCode ierr;
605: if (!PetscLogSyncOn || comm == MPI_COMM_NULL) return(0);
606: PetscLogGetStageLog(&stageLog);
607: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
608: if (!eventRegLog->eventInfo[event].collective) return(0);
609: PetscStageLogGetCurrent(stageLog,&stage);
610: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
612: PetscTimeSubtract(&time);
613: MPI_Barrier(comm);
614: PetscTimeAdd(&time);
615: eventLog->eventInfo[event].syncTime += time;
616: return(0);
617: }
619: PetscErrorCode PetscLogEventBeginDefault(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
620: {
621: PetscStageLog stageLog;
622: PetscEventPerfLog eventLog = NULL;
623: int stage;
624: PetscErrorCode ierr;
627: PetscLogGetStageLog(&stageLog);
628: PetscStageLogGetCurrent(stageLog,&stage);
629: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
630: /* Check for double counting */
631: eventLog->eventInfo[event].depth++;
632: if (eventLog->eventInfo[event].depth > 1) return(0);
633: /* Log the performance info */
634: PetscLogEventSynchronize(event,PetscObjectComm(o1));
635: eventLog->eventInfo[event].count++;
636: eventLog->eventInfo[event].timeTmp = 0.0;
637: PetscTimeSubtract(&eventLog->eventInfo[event].timeTmp);
638: eventLog->eventInfo[event].flopsTmp = 0.0;
639: eventLog->eventInfo[event].flopsTmp -= petsc_TotalFlops;
640: eventLog->eventInfo[event].numMessages -= petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct;
641: eventLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
642: eventLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
643: return(0);
644: }
646: PetscErrorCode PetscLogEventEndDefault(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
647: {
648: PetscStageLog stageLog;
649: PetscEventPerfLog eventLog = NULL;
650: int stage;
651: PetscErrorCode ierr;
654: PetscLogGetStageLog(&stageLog);
655: PetscStageLogGetCurrent(stageLog,&stage);
656: PetscStageLogGetEventPerfLog(stageLog,stage,&eventLog);
657: /* Check for double counting */
658: eventLog->eventInfo[event].depth--;
659: if (eventLog->eventInfo[event].depth > 0) return(0);
660: else if (eventLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE,"Logging event had unbalanced begin/end pairs");
661: /* Log performance info */
662: PetscTimeAdd(&eventLog->eventInfo[event].timeTmp);
663: eventLog->eventInfo[event].time += eventLog->eventInfo[event].timeTmp;
664: eventLog->eventInfo[event].time2 += eventLog->eventInfo[event].timeTmp*eventLog->eventInfo[event].timeTmp;
665: eventLog->eventInfo[event].flopsTmp += petsc_TotalFlops;
666: eventLog->eventInfo[event].flops += eventLog->eventInfo[event].flopsTmp;
667: eventLog->eventInfo[event].flops2 += eventLog->eventInfo[event].flopsTmp*eventLog->eventInfo[event].flopsTmp;
668: eventLog->eventInfo[event].numMessages += petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct;
669: eventLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
670: eventLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
671: return(0);
672: }
674: PetscErrorCode PetscLogEventBeginComplete(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
675: {
676: PetscStageLog stageLog;
677: PetscEventRegLog eventRegLog;
678: PetscEventPerfLog eventPerfLog = NULL;
679: Action *tmpAction;
680: PetscLogDouble start,end;
681: PetscLogDouble curTime;
682: int stage;
683: PetscErrorCode ierr;
686: /* Dynamically enlarge logging structures */
687: if (petsc_numActions >= petsc_maxActions) {
688: PetscTime(&start);
689: PetscMalloc1(petsc_maxActions*2,&tmpAction);
690: PetscMemcpy(tmpAction,petsc_actions,petsc_maxActions * sizeof(Action));
691: PetscFree(petsc_actions);
693: petsc_actions = tmpAction;
694: petsc_maxActions *= 2;
695: PetscTime(&end);
696: petsc_BaseTime += (end - start);
697: }
698: /* Record the event */
699: PetscLogGetStageLog(&stageLog);
700: PetscStageLogGetCurrent(stageLog,&stage);
701: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
702: PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
703: PetscTime(&curTime);
704: if (petsc_logActions) {
705: petsc_actions[petsc_numActions].time = curTime - petsc_BaseTime;
706: petsc_actions[petsc_numActions].action = ACTIONBEGIN;
707: petsc_actions[petsc_numActions].event = event;
708: petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
709: if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
710: else petsc_actions[petsc_numActions].id1 = -1;
711: if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
712: else petsc_actions[petsc_numActions].id2 = -1;
713: if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
714: else petsc_actions[petsc_numActions].id3 = -1;
715: petsc_actions[petsc_numActions].flops = petsc_TotalFlops;
717: PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
718: PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
719: petsc_numActions++;
720: }
721: /* Check for double counting */
722: eventPerfLog->eventInfo[event].depth++;
723: if (eventPerfLog->eventInfo[event].depth > 1) return(0);
724: /* Log the performance info */
725: eventPerfLog->eventInfo[event].count++;
726: eventPerfLog->eventInfo[event].time -= curTime;
727: eventPerfLog->eventInfo[event].flops -= petsc_TotalFlops;
728: eventPerfLog->eventInfo[event].numMessages -= petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct;
729: eventPerfLog->eventInfo[event].messageLength -= petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
730: eventPerfLog->eventInfo[event].numReductions -= petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
731: return(0);
732: }
734: PetscErrorCode PetscLogEventEndComplete(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
735: {
736: PetscStageLog stageLog;
737: PetscEventRegLog eventRegLog;
738: PetscEventPerfLog eventPerfLog = NULL;
739: Action *tmpAction;
740: PetscLogDouble start,end;
741: PetscLogDouble curTime;
742: int stage;
743: PetscErrorCode ierr;
746: /* Dynamically enlarge logging structures */
747: if (petsc_numActions >= petsc_maxActions) {
748: PetscTime(&start);
749: PetscMalloc1(petsc_maxActions*2,&tmpAction);
750: PetscMemcpy(tmpAction,petsc_actions,petsc_maxActions * sizeof(Action));
751: PetscFree(petsc_actions);
753: petsc_actions = tmpAction;
754: petsc_maxActions *= 2;
755: PetscTime(&end);
756: petsc_BaseTime += (end - start);
757: }
758: /* Record the event */
759: PetscLogGetStageLog(&stageLog);
760: PetscStageLogGetCurrent(stageLog,&stage);
761: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
762: PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
763: PetscTime(&curTime);
764: if (petsc_logActions) {
765: petsc_actions[petsc_numActions].time = curTime - petsc_BaseTime;
766: petsc_actions[petsc_numActions].action = ACTIONEND;
767: petsc_actions[petsc_numActions].event = event;
768: petsc_actions[petsc_numActions].classid = eventRegLog->eventInfo[event].classid;
769: if (o1) petsc_actions[petsc_numActions].id1 = o1->id;
770: else petsc_actions[petsc_numActions].id1 = -1;
771: if (o2) petsc_actions[petsc_numActions].id2 = o2->id;
772: else petsc_actions[petsc_numActions].id2 = -1;
773: if (o3) petsc_actions[petsc_numActions].id3 = o3->id;
774: else petsc_actions[petsc_numActions].id3 = -1;
775: petsc_actions[petsc_numActions].flops = petsc_TotalFlops;
777: PetscMallocGetCurrentUsage(&petsc_actions[petsc_numActions].mem);
778: PetscMallocGetMaximumUsage(&petsc_actions[petsc_numActions].maxmem);
779: petsc_numActions++;
780: }
781: /* Check for double counting */
782: eventPerfLog->eventInfo[event].depth--;
783: if (eventPerfLog->eventInfo[event].depth > 0) return(0);
784: else if (eventPerfLog->eventInfo[event].depth < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE,"Logging event had unbalanced begin/end pairs");
785: /* Log the performance info */
786: eventPerfLog->eventInfo[event].count++;
787: eventPerfLog->eventInfo[event].time += curTime;
788: eventPerfLog->eventInfo[event].flops += petsc_TotalFlops;
789: eventPerfLog->eventInfo[event].numMessages += petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct;
790: eventPerfLog->eventInfo[event].messageLength += petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len;
791: eventPerfLog->eventInfo[event].numReductions += petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct;
792: return(0);
793: }
795: PetscErrorCode PetscLogEventBeginTrace(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
796: {
797: PetscStageLog stageLog;
798: PetscEventRegLog eventRegLog;
799: PetscEventPerfLog eventPerfLog = NULL;
800: PetscLogDouble cur_time;
801: PetscMPIInt rank;
802: int stage,err;
803: PetscErrorCode ierr;
806: if (!petsc_tracetime) PetscTime(&petsc_tracetime);
808: petsc_tracelevel++;
809: MPI_Comm_rank(PETSC_COMM_WORLD,&rank);
810: PetscLogGetStageLog(&stageLog);
811: PetscStageLogGetCurrent(stageLog,&stage);
812: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
813: PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
814: /* Check for double counting */
815: eventPerfLog->eventInfo[event].depth++;
816: if (eventPerfLog->eventInfo[event].depth > 1) return(0);
817: /* Log performance info */
818: PetscTime(&cur_time);
819: PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile,"%s[%d] %g Event begin: %s\n",petsc_tracespace,rank,cur_time-petsc_tracetime,eventRegLog->eventInfo[event].name);
820: PetscStrncpy(petsc_tracespace,petsc_traceblanks,2*petsc_tracelevel);
822: petsc_tracespace[2*petsc_tracelevel] = 0;
824: err = fflush(petsc_tracefile);
825: if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
826: return(0);
827: }
829: PetscErrorCode PetscLogEventEndTrace(PetscLogEvent event,int t,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)
830: {
831: PetscStageLog stageLog;
832: PetscEventRegLog eventRegLog;
833: PetscEventPerfLog eventPerfLog = NULL;
834: PetscLogDouble cur_time;
835: int stage,err;
836: PetscMPIInt rank;
837: PetscErrorCode ierr;
840: petsc_tracelevel--;
841: MPI_Comm_rank(PETSC_COMM_WORLD,&rank);
842: PetscLogGetStageLog(&stageLog);
843: PetscStageLogGetCurrent(stageLog,&stage);
844: PetscStageLogGetEventRegLog(stageLog,&eventRegLog);
845: PetscStageLogGetEventPerfLog(stageLog,stage,&eventPerfLog);
846: /* Check for double counting */
847: eventPerfLog->eventInfo[event].depth--;
848: if (eventPerfLog->eventInfo[event].depth > 0) return(0);
849: else if (eventPerfLog->eventInfo[event].depth < 0 || petsc_tracelevel < 0) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_WRONGSTATE,"Logging event had unbalanced begin/end pairs");
851: /* Log performance info */
852: if (petsc_tracelevel) {
853: PetscStrncpy(petsc_tracespace,petsc_traceblanks,2*petsc_tracelevel);
854: }
855: petsc_tracespace[2*petsc_tracelevel] = 0;
856: PetscTime(&cur_time);
857: PetscFPrintf(PETSC_COMM_SELF,petsc_tracefile,"%s[%d] %g Event end: %s\n",petsc_tracespace,rank,cur_time-petsc_tracetime,eventRegLog->eventInfo[event].name);
858: err = fflush(petsc_tracefile);
859: if (err) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SYS,"fflush() failed on file");
860: return(0);
861: }