Actual source code: ex7.c
1: const char help[] = "How to create a log handler using the PetscLogHandler interface";
3: #include <petscsys.h>
4: #include <petsc/private/hashmapi.h>
5: #include <petsctime.h>
6: #include <petscviewer.h>
7: #include <petsc/private/loghandlerimpl.h>
9: /* Log handlers that use the PetscLogHandler interface get their information
10: from the PetscLogState available to each handler and the user-defined
11: context pointer. Compare this example to src/sys/tutorials/ex6.c.
13: A logging event can be started multiple times before it stops: for example,
14: a linear solve may involve a subsolver, so PetscLogEventBegin() can be
15: called for the event KSP_Solve multiple times before a call to
16: PetscLogEventEnd(). The user defined handler in this example shows how many
17: times an event is running. */
19: #define PETSCLOGHANDLEREX7 "ex7"
21: typedef struct _HandlerCtx *HandlerCtx;
23: struct _HandlerCtx {
24: PetscHMapI running;
25: PetscInt num_objects_created;
26: PetscInt num_objects_destroyed;
27: };
29: static PetscErrorCode HandlerCtxCreate(HandlerCtx *ctx_p)
30: {
31: HandlerCtx ctx;
33: PetscFunctionBegin;
34: PetscCall(PetscNew(ctx_p));
35: ctx = *ctx_p;
36: PetscCall(PetscHMapICreate(&ctx->running));
37: PetscFunctionReturn(PETSC_SUCCESS);
38: }
40: static PetscErrorCode HandlerCtxDestroy(HandlerCtx *ctx_p)
41: {
42: HandlerCtx ctx;
44: PetscFunctionBegin;
45: ctx = *ctx_p;
46: *ctx_p = NULL;
47: PetscCall(PetscHMapIDestroy(&ctx->running));
48: PetscCall(PetscFree(ctx));
49: PetscFunctionReturn(PETSC_SUCCESS);
50: }
52: #define PrintData(format_string, ...) \
53: do { \
54: PetscMPIInt _rank; \
55: PetscLogDouble _time; \
56: PetscCallMPI(MPI_Comm_rank(PETSC_COMM_WORLD, &_rank)); \
57: PetscCall(PetscTime(&_time)); \
58: PetscCall(PetscPrintf(PETSC_COMM_SELF, "[%d:%-7g:%-33s] " format_string, _rank, _time, PETSC_FUNCTION_NAME, __VA_ARGS__)); \
59: } while (0)
61: static PetscErrorCode PetscLogHandlerEventBegin_Ex7(PetscLogHandler h, PetscLogEvent e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
62: {
63: HandlerCtx ctx;
64: PetscInt count;
65: PetscLogState state;
66: PetscLogEventInfo event_info;
67: PetscBool is_active;
69: PetscFunctionBegin;
70: // This callback will only be invoked if the event is active
71: PetscCall(PetscLogHandlerGetState(h, &state));
72: PetscCall(PetscLogStateEventGetActive(state, PETSC_DEFAULT, e, &is_active));
73: PetscAssert(is_active, PETSC_COMM_SELF, PETSC_ERR_PLIB, "Event handler called for inactive event");
75: ctx = (HandlerCtx)h->data;
76: PetscCall(PetscHMapIGetWithDefault(ctx->running, e, 0, &count));
77: count += 1;
78: PetscCall(PetscLogStateEventGetInfo(state, e, &event_info));
79: PrintData("Event \"%s\" started: now running %" PetscInt_FMT " times\n", event_info.name, count);
80: PetscCall(PetscHMapISet(ctx->running, e, count));
81: PetscFunctionReturn(PETSC_SUCCESS);
82: }
84: static PetscErrorCode PetscLogHandlerEventEnd_Ex7(PetscLogHandler h, PetscLogEvent e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4)
85: {
86: HandlerCtx ctx;
87: PetscInt count;
88: PetscLogState state;
89: PetscLogEventInfo event_info;
91: PetscFunctionBegin;
92: ctx = (HandlerCtx)h->data;
93: PetscCall(PetscLogHandlerGetState(h, &state));
94: PetscCall(PetscHMapIGetWithDefault(ctx->running, e, 0, &count));
95: count -= 1;
96: PetscCall(PetscLogStateEventGetInfo(state, e, &event_info));
97: PrintData("Event \"%s\" stopped: now running %" PetscInt_FMT " times\n", event_info.name, count);
98: PetscCall(PetscHMapISet(ctx->running, e, count));
99: PetscFunctionReturn(PETSC_SUCCESS);
100: }
102: static PetscErrorCode PetscLogHandlerEventSync_Ex7(PetscLogHandler h, PetscLogEvent e, MPI_Comm comm)
103: {
104: PetscLogState state;
105: PetscLogEventInfo event_info;
106: PetscLogDouble time = 0.0;
108: PetscFunctionBegin;
109: PetscCall(PetscTimeSubtract(&time));
110: PetscCallMPI(MPI_Barrier(comm));
111: PetscCall(PetscTimeAdd(&time));
112: PetscCall(PetscLogHandlerGetState(h, &state));
113: PetscCall(PetscLogStateEventGetInfo(state, e, &event_info));
114: PrintData("Event \"%s\" synced: took %g seconds\n", event_info.name, time);
115: PetscFunctionReturn(PETSC_SUCCESS);
116: }
118: static PetscErrorCode PetscLogHandlerObjectCreate_Ex7(PetscLogHandler h, PetscObject obj)
119: {
120: HandlerCtx ctx;
122: PetscFunctionBegin;
123: ctx = (HandlerCtx)h->data;
124: ctx->num_objects_created++;
125: PetscFunctionReturn(PETSC_SUCCESS);
126: }
128: static PetscErrorCode PetscLogHandlerObjectDestroy_Ex7(PetscLogHandler h, PetscObject obj)
129: {
130: HandlerCtx ctx;
132: PetscFunctionBegin;
133: ctx = (HandlerCtx)h->data;
134: ctx->num_objects_destroyed++;
135: PetscFunctionReturn(PETSC_SUCCESS);
136: }
138: static PetscErrorCode PetscLogHandlerStagePush_Ex7(PetscLogHandler h, PetscLogStage new_stage)
139: {
140: PetscLogStage old_stage;
141: PetscLogStageInfo new_info;
142: PetscLogState state;
144: PetscFunctionBegin;
145: PetscCall(PetscLogHandlerGetState(h, &state));
146: PetscCall(PetscLogStateStageGetInfo(state, new_stage, &new_info));
147: PetscCall(PetscLogStateGetCurrentStage(state, &old_stage));
148: if (old_stage >= 0) {
149: PetscLogStageInfo old_info;
150: PetscCall(PetscLogStateStageGetInfo(state, old_stage, &old_info));
151: PrintData("Pushing stage stage \"%s\" (replacing \"%s\")\n", new_info.name, old_info.name);
152: } else {
153: PrintData("Pushing initial stage \"%s\"\n", new_info.name);
154: }
155: PetscFunctionReturn(PETSC_SUCCESS);
156: }
158: static PetscErrorCode PetscLogHandlerStagePop_Ex7(PetscLogHandler h, PetscLogStage old_stage)
159: {
160: PetscLogStage new_stage;
161: PetscLogStageInfo old_info;
162: PetscLogState state;
164: PetscFunctionBegin;
165: PetscCall(PetscLogHandlerGetState(h, &state));
166: PetscCall(PetscLogStateStageGetInfo(state, old_stage, &old_info));
167: PetscCall(PetscLogStateGetCurrentStage(state, &new_stage));
168: if (new_stage >= 0) {
169: PetscLogStageInfo new_info;
171: PetscCall(PetscLogStateStageGetInfo(state, new_stage, &new_info));
172: PrintData("Popping stage \"%s\" (back to \"%s\")\n", old_info.name, new_info.name);
173: } else {
174: PrintData("Popping initial stage \"%s\"\n", old_info.name);
175: }
176: PetscFunctionReturn(PETSC_SUCCESS);
177: }
179: static PetscErrorCode PetscLogHandlerView_Ex7(PetscLogHandler h, PetscViewer viewer)
180: {
181: PetscBool is_ascii;
183: PetscFunctionBegin;
184: PetscCall(PetscObjectTypeCompare((PetscObject)viewer, PETSCVIEWERASCII, &is_ascii));
185: if (is_ascii) {
186: HandlerCtx ctx;
187: PetscInt num_entries;
189: ctx = (HandlerCtx)h->data;
190: PetscCall(PetscHMapIGetSize(ctx->running, &num_entries));
191: PetscCall(PetscViewerASCIIPrintf(viewer, "%" PetscInt_FMT " events were seen by the handler\n", num_entries));
192: PetscCall(PetscViewerASCIIPrintf(viewer, "%" PetscInt_FMT " object(s) were created and %" PetscInt_FMT " object(s) were destroyed\n", ctx->num_objects_created, ctx->num_objects_destroyed));
193: }
194: PetscFunctionReturn(PETSC_SUCCESS);
195: }
197: // An example of overloading one of the methods defined using PetscObjectComposeFunction()
198: static PetscErrorCode PetscLogHandlerLogObjectState_Ex7(PetscLogHandler h, PetscObject obj, const char format[], va_list argp)
199: {
200: const char *name;
202: PetscFunctionBegin;
203: PetscCall(PetscObjectGetName(obj, &name));
204: PrintData("Logged state for \"%s\": ", name);
205: PetscCall(PetscVFPrintf(PETSC_STDOUT, format, argp));
206: PetscCall(PetscPrintf(PETSC_COMM_SELF, "\n"));
207: PetscFunctionReturn(PETSC_SUCCESS);
208: }
210: static PetscErrorCode PetscLogHandlerDestroy_Ex7(PetscLogHandler h)
211: {
212: HandlerCtx ctx;
214: PetscFunctionBegin;
215: ctx = (HandlerCtx)h->data;
216: PetscCall(HandlerCtxDestroy(&ctx));
217: PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerLogObjectState_C", NULL));
218: PetscFunctionReturn(PETSC_SUCCESS);
219: }
221: static PetscErrorCode PetscLogHandlerCreate_Ex7(PetscLogHandler handler)
222: {
223: HandlerCtx ctx;
225: PetscFunctionBegin;
226: PetscCall(HandlerCtxCreate(&ctx));
227: handler->data = (void *)ctx;
228: handler->ops->destroy = PetscLogHandlerDestroy_Ex7;
229: handler->ops->view = PetscLogHandlerView_Ex7;
230: handler->ops->eventbegin = PetscLogHandlerEventBegin_Ex7;
231: handler->ops->eventend = PetscLogHandlerEventEnd_Ex7;
232: handler->ops->eventsync = PetscLogHandlerEventSync_Ex7;
233: handler->ops->objectcreate = PetscLogHandlerObjectCreate_Ex7;
234: handler->ops->objectdestroy = PetscLogHandlerObjectDestroy_Ex7;
235: handler->ops->stagepush = PetscLogHandlerStagePush_Ex7;
236: handler->ops->stagepop = PetscLogHandlerStagePop_Ex7;
237: PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerLogObjectState_C", PetscLogHandlerLogObjectState_Ex7));
238: PetscFunctionReturn(PETSC_SUCCESS);
239: }
241: int main(int argc, char **argv)
242: {
243: PetscClassId user_classid;
244: PetscLogEvent event_1, event_2;
245: PetscLogStage stage_1;
246: PetscContainer user_object;
247: PetscLogHandler h;
248: PetscLogDouble time;
249: PetscLogHandlerType type;
251: PetscCall(PetscInitialize(&argc, &argv, NULL, help));
252: PetscCall(PetscLogHandlerRegister(PETSCLOGHANDLEREX7, PetscLogHandlerCreate_Ex7));
254: PetscCall(PetscLogHandlerCreate(PETSC_COMM_WORLD, &h));
255: PetscCall(PetscLogHandlerSetType(h, PETSCLOGHANDLEREX7));
256: PetscCall(PetscLogHandlerGetType(h, &type));
257: PetscCall(PetscPrintf(PETSC_COMM_WORLD, "Log handler type is: %s\n", type));
258: PetscCall(PetscLogHandlerStart(h));
260: PetscCall(PetscClassIdRegister("User class", &user_classid));
261: PetscCall(PetscLogEventRegister("Event 1", user_classid, &event_1));
262: PetscCall(PetscLogEventRegister("Event 2", user_classid, &event_2));
263: PetscCall(PetscLogStageRegister("Stage 1", &stage_1));
265: PetscCall(PetscLogEventBegin(event_1, NULL, NULL, NULL, NULL));
266: PetscCall(PetscLogStagePush(stage_1));
267: PetscCall(PetscLogEventBegin(event_2, NULL, NULL, NULL, NULL));
268: PetscCall(PetscLogEventSync(event_1, PETSC_COMM_WORLD));
269: PetscCall(PetscLogEventBegin(event_1, NULL, NULL, NULL, NULL));
270: PetscCall(PetscTime(&time));
271: PetscCall(PetscContainerCreate(PETSC_COMM_SELF, &user_object));
272: PetscCall(PetscObjectSetName((PetscObject)user_object, "User Container"));
273: PetscCall(PetscLogHandlerLogObjectState(h, (PetscObject)user_object, "Created at %e", time));
274: PetscCall(PetscContainerDestroy(&user_object));
275: PetscCall(PetscLogEventEnd(event_1, NULL, NULL, NULL, NULL));
276: PetscCall(PetscLogEventEnd(event_2, NULL, NULL, NULL, NULL));
277: PetscCall(PetscLogStagePop());
278: PetscCall(PetscLogEventEnd(event_1, NULL, NULL, NULL, NULL));
280: PetscCall(PetscLogHandlerStop(h));
281: PetscCall(PetscLogHandlerView(h, PETSC_VIEWER_STDOUT_WORLD));
282: PetscCall(PetscLogHandlerDestroy(&h));
283: PetscCall(PetscFinalize());
284: return 0;
285: }
287: /*TEST
289: test:
290: requires: defined(PETSC_USE_LOG)
291: suffix: 0
292: filter: sed -E "s/:[^:]+:/:time_removed:/g"
294: TEST*/