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 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 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 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 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 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 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 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 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 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 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() 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 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 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 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