1 const char help[] = "How to create a log handler using the PetscLogHandler interface";
2
3 #include <petscsys.h>
4 #include <petsc/private/hashmapi.h> // use PetscHMapI: a PetscInt -> PetscInt hashmap
5 #include <petsctime.h> // use PetscTimeSubtract() and PetscTimeAdd()
6 #include <petscviewer.h>
7 #include <petsc/private/loghandlerimpl.h> // use the struct _p_PetscLogHandler behind PetscLogHandler
8
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.
12
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. */
18
19 #define PETSCLOGHANDLEREX7 "ex7"
20
21 typedef struct _HandlerCtx *HandlerCtx;
22
23 struct _HandlerCtx {
24 PetscHMapI running;
25 PetscInt num_objects_created;
26 PetscInt num_objects_destroyed;
27 };
28
HandlerCtxCreate(HandlerCtx * ctx_p)29 static PetscErrorCode HandlerCtxCreate(HandlerCtx *ctx_p)
30 {
31 HandlerCtx ctx;
32
33 PetscFunctionBegin;
34 PetscCall(PetscNew(ctx_p));
35 ctx = *ctx_p;
36 PetscCall(PetscHMapICreate(&ctx->running));
37 PetscFunctionReturn(PETSC_SUCCESS);
38 }
39
HandlerCtxDestroy(HandlerCtx * ctx_p)40 static PetscErrorCode HandlerCtxDestroy(HandlerCtx *ctx_p)
41 {
42 HandlerCtx ctx;
43
44 PetscFunctionBegin;
45 ctx = *ctx_p;
46 *ctx_p = NULL;
47 PetscCall(PetscHMapIDestroy(&ctx->running));
48 PetscCall(PetscFree(ctx));
49 PetscFunctionReturn(PETSC_SUCCESS);
50 }
51
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)
60
PetscLogHandlerEventBegin_Ex7(PetscLogHandler h,PetscLogEvent e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)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;
68
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");
74
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 }
83
PetscLogHandlerEventEnd_Ex7(PetscLogHandler h,PetscLogEvent e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4)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;
90
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 }
101
PetscLogHandlerEventSync_Ex7(PetscLogHandler h,PetscLogEvent e,MPI_Comm comm)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;
107
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 }
117
PetscLogHandlerObjectCreate_Ex7(PetscLogHandler h,PetscObject obj)118 static PetscErrorCode PetscLogHandlerObjectCreate_Ex7(PetscLogHandler h, PetscObject obj)
119 {
120 HandlerCtx ctx;
121
122 PetscFunctionBegin;
123 ctx = (HandlerCtx)h->data;
124 ctx->num_objects_created++;
125 PetscFunctionReturn(PETSC_SUCCESS);
126 }
127
PetscLogHandlerObjectDestroy_Ex7(PetscLogHandler h,PetscObject obj)128 static PetscErrorCode PetscLogHandlerObjectDestroy_Ex7(PetscLogHandler h, PetscObject obj)
129 {
130 HandlerCtx ctx;
131
132 PetscFunctionBegin;
133 ctx = (HandlerCtx)h->data;
134 ctx->num_objects_destroyed++;
135 PetscFunctionReturn(PETSC_SUCCESS);
136 }
137
PetscLogHandlerStagePush_Ex7(PetscLogHandler h,PetscLogStage new_stage)138 static PetscErrorCode PetscLogHandlerStagePush_Ex7(PetscLogHandler h, PetscLogStage new_stage)
139 {
140 PetscLogStage old_stage;
141 PetscLogStageInfo new_info;
142 PetscLogState state;
143
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 }
157
PetscLogHandlerStagePop_Ex7(PetscLogHandler h,PetscLogStage old_stage)158 static PetscErrorCode PetscLogHandlerStagePop_Ex7(PetscLogHandler h, PetscLogStage old_stage)
159 {
160 PetscLogStage new_stage;
161 PetscLogStageInfo old_info;
162 PetscLogState state;
163
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;
170
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 }
178
PetscLogHandlerView_Ex7(PetscLogHandler h,PetscViewer viewer)179 static PetscErrorCode PetscLogHandlerView_Ex7(PetscLogHandler h, PetscViewer viewer)
180 {
181 PetscBool is_ascii;
182
183 PetscFunctionBegin;
184 PetscCall(PetscObjectTypeCompare((PetscObject)viewer, PETSCVIEWERASCII, &is_ascii));
185 if (is_ascii) {
186 HandlerCtx ctx;
187 PetscInt num_entries;
188
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 }
196
197 // An example of overloading one of the methods defined using PetscObjectComposeFunction()
PetscLogHandlerLogObjectState_Ex7(PetscLogHandler h,PetscObject obj,const char format[],va_list argp)198 static PetscErrorCode PetscLogHandlerLogObjectState_Ex7(PetscLogHandler h, PetscObject obj, const char format[], va_list argp)
199 {
200 const char *name;
201
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 }
209
PetscLogHandlerDestroy_Ex7(PetscLogHandler h)210 static PetscErrorCode PetscLogHandlerDestroy_Ex7(PetscLogHandler h)
211 {
212 HandlerCtx ctx;
213
214 PetscFunctionBegin;
215 ctx = (HandlerCtx)h->data;
216 PetscCall(HandlerCtxDestroy(&ctx));
217 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerLogObjectState_C", NULL));
218 PetscFunctionReturn(PETSC_SUCCESS);
219 }
220
PetscLogHandlerCreate_Ex7(PetscLogHandler handler)221 static PetscErrorCode PetscLogHandlerCreate_Ex7(PetscLogHandler handler)
222 {
223 HandlerCtx ctx;
224
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 }
240
main(int argc,char ** argv)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;
250
251 PetscCall(PetscInitialize(&argc, &argv, NULL, help));
252 PetscCall(PetscLogHandlerRegister(PETSCLOGHANDLEREX7, PetscLogHandlerCreate_Ex7));
253
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));
259
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));
264
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));
279
280 PetscCall(PetscLogHandlerStop(h));
281 PetscCall(PetscLogHandlerView(h, PETSC_VIEWER_STDOUT_WORLD));
282 PetscCall(PetscLogHandlerDestroy(&h));
283 PetscCall(PetscFinalize());
284 return 0;
285 }
286
287 /*TEST
288
289 test:
290 requires: defined(PETSC_USE_LOG)
291 suffix: 0
292 filter: sed -E "s/:[^:]+:/:time_removed:/g"
293
294 TEST*/
295