1 2 /* 3 PETSc code to log object creation and destruction and PETSc events. 4 5 This provides the public API used by the rest of PETSc and by users. 6 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. 9 10 */ 11 #include <petsc/private/logimpl.h> /*I "petscsys.h" I*/ 12 #include <petsc/private/loghandlerimpl.h> 13 #include <petsctime.h> 14 #include <petscviewer.h> 15 #include <petscdevice.h> 16 #include <petsc/private/deviceimpl.h> 17 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 18 #include <../src/sys/perfstubs/timer.h> 19 #endif 20 21 PetscLogEvent PETSC_LARGEST_EVENT = PETSC_EVENT; 22 23 #if defined(PETSC_USE_LOG) 24 #include <petscmachineinfo.h> 25 #include <petscconfiginfo.h> 26 27 #if defined(PETSC_HAVE_THREADSAFETY) 28 29 PetscInt petsc_log_gid = -1; /* Global threadId counter */ 30 PETSC_TLS PetscInt petsc_log_tid = -1; /* Local threadId */ 31 32 /* shared variables */ 33 PetscSpinlock PetscLogSpinLock; 34 PetscHMapEvent eventInfoMap_th = NULL; 35 36 #endif 37 38 /* used in the MPI_XXX() count macros in petsclog.h */ 39 40 /* Action and object logging variables */ 41 Action *petsc_actions = NULL; 42 Object *petsc_objects = NULL; 43 PetscBool petsc_logActions = PETSC_FALSE; 44 PetscBool petsc_logObjects = PETSC_FALSE; 45 int petsc_numActions = 0, petsc_maxActions = 100; 46 int petsc_numObjects = 0, petsc_maxObjects = 100; 47 int petsc_numObjectsDestroyed = 0; 48 49 #include <../src/sys/logging/handler/impls/default/logdefault.h> 50 51 #define PETSC_LOG_HANDLER_HOT_BLANK \ 52 { \ 53 NULL, NULL, NULL, NULL, NULL, NULL \ 54 } 55 #define PETSC_LOG_HANDLERS_BLANK \ 56 { \ 57 PETSC_LOG_HANDLER_HOT_BLANK, PETSC_LOG_HANDLER_HOT_BLANK, PETSC_LOG_HANDLER_HOT_BLANK, PETSC_LOG_HANDLER_HOT_BLANK \ 58 } 59 60 PetscLogHandlerHot PetscLogHandlers[PETSC_LOG_HANDLER_MAX] = PETSC_LOG_HANDLERS_BLANK; 61 62 #undef PETSC_LOG_HANDLERS_BLANK 63 #undef PETSC_LOG_HANDLERS_HOT_BLANK 64 65 /* Global counters */ 66 PetscLogDouble petsc_BaseTime = 0.0; 67 PetscLogDouble petsc_TotalFlops = 0.0; /* The 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 */ 83 84 /* Thread Local storage */ 85 PETSC_TLS PetscLogDouble petsc_TotalFlops_th = 0.0; 86 PETSC_TLS PetscLogDouble petsc_send_ct_th = 0.0; 87 PETSC_TLS PetscLogDouble petsc_recv_ct_th = 0.0; 88 PETSC_TLS PetscLogDouble petsc_send_len_th = 0.0; 89 PETSC_TLS PetscLogDouble petsc_recv_len_th = 0.0; 90 PETSC_TLS PetscLogDouble petsc_isend_ct_th = 0.0; 91 PETSC_TLS PetscLogDouble petsc_irecv_ct_th = 0.0; 92 PETSC_TLS PetscLogDouble petsc_isend_len_th = 0.0; 93 PETSC_TLS PetscLogDouble petsc_irecv_len_th = 0.0; 94 PETSC_TLS PetscLogDouble petsc_wait_ct_th = 0.0; 95 PETSC_TLS PetscLogDouble petsc_wait_any_ct_th = 0.0; 96 PETSC_TLS PetscLogDouble petsc_wait_all_ct_th = 0.0; 97 PETSC_TLS PetscLogDouble petsc_sum_of_waits_ct_th = 0.0; 98 PETSC_TLS PetscLogDouble petsc_allreduce_ct_th = 0.0; 99 PETSC_TLS PetscLogDouble petsc_gather_ct_th = 0.0; 100 PETSC_TLS PetscLogDouble petsc_scatter_ct_th = 0.0; 101 102 #if defined(PETSC_HAVE_DEVICE) 103 PetscLogDouble petsc_ctog_ct = 0.0; /* The total number of CPU to GPU copies */ 104 PetscLogDouble petsc_gtoc_ct = 0.0; /* The total number of GPU to CPU copies */ 105 PetscLogDouble petsc_ctog_sz = 0.0; /* The total size of CPU to GPU copies */ 106 PetscLogDouble petsc_gtoc_sz = 0.0; /* The total size of GPU to CPU copies */ 107 PetscLogDouble petsc_ctog_ct_scalar = 0.0; /* The total number of CPU to GPU copies */ 108 PetscLogDouble petsc_gtoc_ct_scalar = 0.0; /* The total number of GPU to CPU copies */ 109 PetscLogDouble petsc_ctog_sz_scalar = 0.0; /* The total size of CPU to GPU copies */ 110 PetscLogDouble petsc_gtoc_sz_scalar = 0.0; /* The total size of GPU to CPU copies */ 111 PetscLogDouble petsc_gflops = 0.0; /* The flops done on a GPU */ 112 PetscLogDouble petsc_gtime = 0.0; /* The time spent on a GPU */ 113 114 PETSC_TLS PetscLogDouble petsc_ctog_ct_th = 0.0; 115 PETSC_TLS PetscLogDouble petsc_gtoc_ct_th = 0.0; 116 PETSC_TLS PetscLogDouble petsc_ctog_sz_th = 0.0; 117 PETSC_TLS PetscLogDouble petsc_gtoc_sz_th = 0.0; 118 PETSC_TLS PetscLogDouble petsc_ctog_ct_scalar_th = 0.0; 119 PETSC_TLS PetscLogDouble petsc_gtoc_ct_scalar_th = 0.0; 120 PETSC_TLS PetscLogDouble petsc_ctog_sz_scalar_th = 0.0; 121 PETSC_TLS PetscLogDouble petsc_gtoc_sz_scalar_th = 0.0; 122 PETSC_TLS PetscLogDouble petsc_gflops_th = 0.0; 123 PETSC_TLS PetscLogDouble petsc_gtime_th = 0.0; 124 #endif 125 126 #if defined(PETSC_HAVE_THREADSAFETY) 127 PetscErrorCode PetscAddLogDouble(PetscLogDouble *tot, PetscLogDouble *tot_th, PetscLogDouble tmp) 128 { 129 *tot_th += tmp; 130 PetscCall(PetscSpinlockLock(&PetscLogSpinLock)); 131 *tot += tmp; 132 PetscCall(PetscSpinlockUnlock(&PetscLogSpinLock)); 133 return PETSC_SUCCESS; 134 } 135 136 PetscErrorCode PetscAddLogDoubleCnt(PetscLogDouble *cnt, PetscLogDouble *tot, PetscLogDouble *cnt_th, PetscLogDouble *tot_th, PetscLogDouble tmp) 137 { 138 *cnt_th = *cnt_th + 1; 139 *tot_th += tmp; 140 PetscCall(PetscSpinlockLock(&PetscLogSpinLock)); 141 *tot += (PetscLogDouble)(tmp); 142 *cnt += *cnt + 1; 143 PetscCall(PetscSpinlockUnlock(&PetscLogSpinLock)); 144 return PETSC_SUCCESS; 145 } 146 147 PetscInt PetscLogGetTid(void) 148 { 149 if (petsc_log_tid < 0) { 150 PetscCall(PetscSpinlockLock(&PetscLogSpinLock)); 151 petsc_log_tid = ++petsc_log_gid; 152 PetscCall(PetscSpinlockUnlock(&PetscLogSpinLock)); 153 } 154 return petsc_log_tid; 155 } 156 157 #endif 158 159 PetscLogState petsc_log_state = NULL; 160 161 static PetscErrorCode PetscLogTryGetHandler(PetscLogHandlerType type, PetscLogHandler *handler) 162 { 163 PetscFunctionBegin; 164 PetscAssertPointer(handler, 2); 165 *handler = NULL; 166 for (int i = 0; i < PETSC_LOG_HANDLER_MAX; i++) { 167 PetscLogHandler h = PetscLogHandlers[i].handler; 168 if (h) { 169 PetscBool match; 170 171 PetscCall(PetscObjectTypeCompare((PetscObject)h, type, &match)); 172 if (match) { 173 *handler = PetscLogHandlers[i].handler; 174 PetscFunctionReturn(PETSC_SUCCESS); 175 } 176 } 177 } 178 PetscFunctionReturn(PETSC_SUCCESS); 179 } 180 181 /*@ 182 PetscLogGetState - Get the `PetscLogState` for PETSc's global logging, used 183 by all default log handlers (`PetscLogDefaultBegin()`, 184 `PetscLogNestedBegin()`, `PetscLogTraceBegin()`, `PetscLogMPEBegin()`, 185 `PetscLogPerfstubsBegin()`). 186 187 Collective on `PETSC_COMM_WORLD` 188 189 Output Parameter: 190 . state - The `PetscLogState` changed by registrations (such as `PetscLogEventRegister()`) and actions (such as `PetscLogEventBegin()` or `PetscLogStagePush()`) 191 192 Level: developer 193 194 .seealso: [](ch_profiling), `PetscLogState` 195 @*/ 196 PetscErrorCode PetscLogGetState(PetscLogState *state) 197 { 198 PetscFunctionBegin; 199 PetscAssertPointer(state, 1); 200 if (!petsc_log_state) { 201 fprintf(stderr, "PETSC ERROR: Logging has not been enabled.\nYou might have forgotten to call PetscInitialize().\n"); 202 PETSCABORT(MPI_COMM_WORLD, PETSC_ERR_SUP); 203 } 204 *state = petsc_log_state; 205 PetscFunctionReturn(PETSC_SUCCESS); 206 } 207 208 /* Logging functions */ 209 PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL; 210 PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL; 211 PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 212 PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 213 214 /* Tracing event logging variables */ 215 FILE *petsc_tracefile = NULL; 216 int petsc_tracelevel = 0; 217 const char *petsc_traceblanks = " "; 218 char petsc_tracespace[128] = " "; 219 PetscLogDouble petsc_tracetime = 0.0; 220 static PetscBool PetscLogInitializeCalled = PETSC_FALSE; 221 222 static PetscIntStack current_log_event_stack = NULL; 223 224 PETSC_INTERN PetscErrorCode PetscLogInitialize(void) 225 { 226 int stage; 227 PetscBool opt; 228 229 PetscFunctionBegin; 230 if (PetscLogInitializeCalled) PetscFunctionReturn(PETSC_SUCCESS); 231 PetscLogInitializeCalled = PETSC_TRUE; 232 233 PetscCall(PetscIntStackCreate(¤t_log_event_stack)); 234 PetscCall(PetscOptionsHasName(NULL, NULL, "-log_exclude_actions", &opt)); 235 if (opt) petsc_logActions = PETSC_FALSE; 236 PetscCall(PetscOptionsHasName(NULL, NULL, "-log_exclude_objects", &opt)); 237 if (opt) petsc_logObjects = PETSC_FALSE; 238 if (petsc_logActions) PetscCall(PetscMalloc1(petsc_maxActions, &petsc_actions)); 239 if (petsc_logObjects) PetscCall(PetscMalloc1(petsc_maxObjects, &petsc_objects)); 240 PetscLogPHC = PetscLogObjCreateDefault; 241 PetscLogPHD = PetscLogObjDestroyDefault; 242 /* Setup default logging structures */ 243 PetscCall(PetscLogStateCreate(&petsc_log_state)); 244 for (PetscInt i = 0; i < PETSC_LOG_HANDLER_MAX; i++) { 245 if (PetscLogHandlers[i].handler) PetscCall(PetscLogHandlerSetState(PetscLogHandlers[i].handler, petsc_log_state)); 246 } 247 PetscCall(PetscLogStateStageRegister(petsc_log_state, "Main Stage", &stage)); 248 PetscCall(PetscStageLogCreate(&petsc_stageLog)); 249 PetscCall(PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage)); 250 251 PetscCall(PetscSpinlockCreate(&PetscLogSpinLock)); 252 #if defined(PETSC_HAVE_THREADSAFETY) 253 petsc_log_tid = 0; 254 petsc_log_gid = 0; 255 PetscCall(PetscHMapEventCreate(&eventInfoMap_th)); 256 #endif 257 258 /* All processors sync here for more consistent logging */ 259 PetscCallMPI(MPI_Barrier(PETSC_COMM_WORLD)); 260 PetscCall(PetscTime(&petsc_BaseTime)); 261 PetscCall(PetscLogStagePush(stage)); 262 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 263 PetscStackCallExternalVoid("ps_initialize_", ps_initialize_()); 264 #endif 265 PetscFunctionReturn(PETSC_SUCCESS); 266 } 267 268 PETSC_INTERN PetscErrorCode PetscLogFinalize(void) 269 { 270 PetscStageLog stageLog; 271 272 PetscFunctionBegin; 273 for (int i = 0; i < PETSC_LOG_HANDLER_MAX; i++) PetscCall(PetscLogHandlerDestroy(&PetscLogHandlers[i].handler)); 274 PetscCall(PetscArrayzero(PetscLogHandlers, PETSC_LOG_HANDLER_MAX)); 275 PetscCall(PetscLogStateDestroy(&petsc_log_state)); 276 #if defined(PETSC_HAVE_THREADSAFETY) 277 if (eventInfoMap_th) { 278 PetscEventPerfInfo **array; 279 PetscInt n, off = 0; 280 281 PetscCall(PetscHMapEventGetSize(eventInfoMap_th, &n)); 282 PetscCall(PetscMalloc1(n, &array)); 283 PetscCall(PetscHMapEventGetVals(eventInfoMap_th, &off, array)); 284 for (PetscInt i = 0; i < n; i++) PetscCall(PetscFree(array[i])); 285 PetscCall(PetscFree(array)); 286 PetscCall(PetscHMapEventDestroy(&eventInfoMap_th)); 287 } 288 #endif 289 PetscCall(PetscFree(petsc_actions)); 290 PetscCall(PetscFree(petsc_objects)); 291 PetscCall(PetscLogNestedEnd()); 292 PetscCall(PetscLogSet(NULL, NULL)); 293 294 /* Resetting phase */ 295 PetscCall(PetscLogGetStageLog(&stageLog)); 296 PetscCall(PetscStageLogDestroy(stageLog)); 297 PetscCall(PetscIntStackDestroy(current_log_event_stack)); 298 current_log_event_stack = NULL; 299 300 petsc_TotalFlops = 0.0; 301 petsc_numActions = 0; 302 petsc_numObjects = 0; 303 petsc_numObjectsDestroyed = 0; 304 petsc_maxActions = 100; 305 petsc_maxObjects = 100; 306 petsc_actions = NULL; 307 petsc_objects = NULL; 308 petsc_logActions = PETSC_FALSE; 309 petsc_logObjects = PETSC_FALSE; 310 petsc_BaseTime = 0.0; 311 petsc_TotalFlops = 0.0; 312 petsc_send_ct = 0.0; 313 petsc_recv_ct = 0.0; 314 petsc_send_len = 0.0; 315 petsc_recv_len = 0.0; 316 petsc_isend_ct = 0.0; 317 petsc_irecv_ct = 0.0; 318 petsc_isend_len = 0.0; 319 petsc_irecv_len = 0.0; 320 petsc_wait_ct = 0.0; 321 petsc_wait_any_ct = 0.0; 322 petsc_wait_all_ct = 0.0; 323 petsc_sum_of_waits_ct = 0.0; 324 petsc_allreduce_ct = 0.0; 325 petsc_gather_ct = 0.0; 326 petsc_scatter_ct = 0.0; 327 petsc_TotalFlops_th = 0.0; 328 petsc_send_ct_th = 0.0; 329 petsc_recv_ct_th = 0.0; 330 petsc_send_len_th = 0.0; 331 petsc_recv_len_th = 0.0; 332 petsc_isend_ct_th = 0.0; 333 petsc_irecv_ct_th = 0.0; 334 petsc_isend_len_th = 0.0; 335 petsc_irecv_len_th = 0.0; 336 petsc_wait_ct_th = 0.0; 337 petsc_wait_any_ct_th = 0.0; 338 petsc_wait_all_ct_th = 0.0; 339 petsc_sum_of_waits_ct_th = 0.0; 340 petsc_allreduce_ct_th = 0.0; 341 petsc_gather_ct_th = 0.0; 342 petsc_scatter_ct_th = 0.0; 343 344 #if defined(PETSC_HAVE_DEVICE) 345 petsc_ctog_ct = 0.0; 346 petsc_gtoc_ct = 0.0; 347 petsc_ctog_sz = 0.0; 348 petsc_gtoc_sz = 0.0; 349 petsc_gflops = 0.0; 350 petsc_gtime = 0.0; 351 petsc_ctog_ct_th = 0.0; 352 petsc_gtoc_ct_th = 0.0; 353 petsc_ctog_sz_th = 0.0; 354 petsc_gtoc_sz_th = 0.0; 355 petsc_gflops_th = 0.0; 356 petsc_gtime_th = 0.0; 357 #endif 358 359 PETSC_LARGEST_EVENT = PETSC_EVENT; 360 PetscLogPHC = NULL; 361 PetscLogPHD = NULL; 362 petsc_tracefile = NULL; 363 petsc_tracelevel = 0; 364 petsc_traceblanks = " "; 365 petsc_tracespace[0] = ' '; 366 petsc_tracespace[1] = 0; 367 petsc_tracetime = 0.0; 368 PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 369 PETSC_OBJECT_CLASSID = 0; 370 petsc_stageLog = NULL; 371 PetscLogInitializeCalled = PETSC_FALSE; 372 PetscFunctionReturn(PETSC_SUCCESS); 373 } 374 375 static PetscErrorCode PetscLogHandlerCopyToHot(PetscLogHandler h, PetscLogHandlerHot *hot) 376 { 377 PetscFunctionBegin; 378 hot->handler = h; 379 hot->eventBegin = h->ops->eventbegin; 380 hot->eventEnd = h->ops->eventend; 381 hot->eventSync = h->ops->eventsync; 382 hot->objectCreate = h->ops->objectcreate; 383 hot->objectDestroy = h->ops->objectdestroy; 384 PetscFunctionReturn(PETSC_SUCCESS); 385 } 386 387 /*@ 388 PetscLogHandlerStart - Connect a log handler to PETSc's global logging stream and state. 389 390 Logically collective 391 392 Input Parameters: 393 . h - a `PetscLogHandler` 394 395 Level: developer 396 397 Notes: 398 399 Users should only need this if they create their own log handlers: handlers that are started 400 from the command line (such as `-log_view` and `-log_trace`) or from a function like 401 `PetscLogNestedBegin()` will automatically be started. 402 403 There is a limit of `PESC_LOG_HANDLER_MAX` handlers that can be active at one time. 404 405 To disconnect a handler from the global stream call `PetscLogHandlerStop()`. 406 407 When a log handler is started, stages that have already been pushed with `PetscLogStagePush()`, 408 will be pushed for the new log handler, but it will not be informed of any events that are 409 in progress. It is recommended to start any user-defined log handlers immediately following 410 before any user-defined stages are pushed. 411 412 .seealso: [](ch_profiling), `PetscLogHandler`, `PetscLogState`, `PetscLogHandlerStop()` 413 @*/ 414 PetscErrorCode PetscLogHandlerStart(PetscLogHandler h) 415 { 416 PetscFunctionBegin; 417 for (PetscInt i = 0; i < PETSC_LOG_HANDLER_MAX; i++) { 418 if (PetscLogHandlers[i].handler == h) PetscFunctionReturn(PETSC_SUCCESS); 419 } 420 for (PetscInt i = 0; i < PETSC_LOG_HANDLER_MAX; i++) { 421 if (PetscLogHandlers[i].handler == NULL) { 422 PetscCall(PetscObjectReference((PetscObject)h)); 423 PetscCall(PetscLogHandlerCopyToHot(h, &PetscLogHandlers[i])); 424 if (petsc_log_state) { 425 PetscLogStage stack_height; 426 PetscIntStack orig_stack, temp_stack; 427 428 PetscCall(PetscLogHandlerSetState(h, petsc_log_state)); 429 stack_height = petsc_log_state->stage_stack->top + 1; 430 PetscCall(PetscIntStackCreate(&temp_stack)); 431 orig_stack = petsc_log_state->stage_stack; 432 petsc_log_state->stage_stack = temp_stack; 433 petsc_log_state->current_stage = -1; 434 for (int s = 0; s < stack_height; s++) { 435 PetscLogStage stage = (PetscLogStage)orig_stack->stack[s]; 436 PetscCall(PetscLogHandlerStagePush(h, stage)); 437 PetscCall(PetscIntStackPush(temp_stack, stage)); 438 petsc_log_state->current_stage = stage; 439 } 440 PetscCall(PetscIntStackDestroy(temp_stack)); 441 petsc_log_state->stage_stack = orig_stack; 442 } 443 PetscFunctionReturn(PETSC_SUCCESS); 444 } 445 } 446 SETERRQ(PetscObjectComm((PetscObject)h), PETSC_ERR_ARG_WRONGSTATE, "%d log handlers already started, cannot start another", PETSC_LOG_HANDLER_MAX); 447 PetscFunctionReturn(PETSC_SUCCESS); 448 } 449 450 /*@ 451 PetscLogHandlerStop - Disconnect a log handler from PETSc's global logging stream. 452 453 Logically collective 454 455 Input Parameters: 456 . h - a `PetscLogHandler` 457 458 Level: developer 459 460 Note: 461 After `PetscLogHandlerStop()`, the handler can still access the global logging state 462 with `PetscLogHandlerGetState()`, so that it can access the registry when post-processing 463 (for instance, in `PetscLogHandlerView()`), 464 465 When a log handler is stopped, the remaining stages will be popped before it is 466 disconnected from the log stream. 467 468 .seealso: [](ch_profiling), `PetscLogHandler`, `PetscLogState`, `PetscLogHandlerStart()` 469 @*/ 470 PetscErrorCode PetscLogHandlerStop(PetscLogHandler h) 471 { 472 PetscFunctionBegin; 473 for (PetscInt i = 0; i < PETSC_LOG_HANDLER_MAX; i++) { 474 if (PetscLogHandlers[i].handler == h) { 475 if (petsc_log_state) { 476 PetscLogState state; 477 PetscLogStage stack_height; 478 PetscIntStack orig_stack, temp_stack; 479 480 PetscCall(PetscLogHandlerGetState(h, &state)); 481 PetscCheck(state == petsc_log_state, PETSC_COMM_WORLD, PETSC_ERR_ARG_WRONGSTATE, "Called PetscLogHandlerStop() for a PetscLogHander that was not started."); 482 stack_height = petsc_log_state->stage_stack->top + 1; 483 PetscCall(PetscIntStackCreate(&temp_stack)); 484 orig_stack = petsc_log_state->stage_stack; 485 petsc_log_state->stage_stack = temp_stack; 486 for (int s = 0; s < stack_height; s++) { 487 PetscLogStage stage = (PetscLogStage)orig_stack->stack[s]; 488 489 PetscCall(PetscIntStackPush(temp_stack, stage)); 490 } 491 for (int s = 0; s < stack_height; s++) { 492 PetscLogStage stage; 493 PetscBool empty; 494 495 PetscCall(PetscIntStackPop(temp_stack, &stage)); 496 PetscCall(PetscIntStackEmpty(temp_stack, &empty)); 497 if (!empty) { 498 PetscCall(PetscIntStackTop(temp_stack, &petsc_log_state->current_stage)); 499 } else petsc_log_state->current_stage = -1; 500 PetscCall(PetscLogHandlerStagePop(h, stage)); 501 } 502 PetscCall(PetscIntStackDestroy(temp_stack)); 503 petsc_log_state->stage_stack = orig_stack; 504 PetscCall(PetscIntStackTop(petsc_log_state->stage_stack, &petsc_log_state->current_stage)); 505 } 506 PetscCall(PetscArrayzero(&PetscLogHandlers[i], 1)); 507 PetscCall(PetscObjectDereference((PetscObject)h)); 508 } 509 } 510 PetscFunctionReturn(PETSC_SUCCESS); 511 } 512 /*@C 513 PetscLogSet - Sets the logging functions called at the beginning and ending of every event. 514 515 Not Collective 516 517 Input Parameters: 518 + b - The function called at beginning of event 519 - e - The function called at end of event 520 521 Level: developer 522 523 Developer Notes: 524 The default loggers are `PetscLogEventBeginDefault()` and `PetscLogEventEndDefault()`. 525 526 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogDefaultBegin()`, `PetscLogAllBegin()`, `PetscLogTraceBegin()`, `PetscLogEventBeginDefault()`, `PetscLogEventEndDefault()` 527 @*/ 528 PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject), PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject)) 529 { 530 PetscFunctionBegin; 531 PetscLogPLB = b; 532 PetscLogPLE = e; 533 PetscFunctionReturn(PETSC_SUCCESS); 534 } 535 536 /*@C 537 PetscLogIsActive - Check if logging is currently in progress. 538 539 Not Collective 540 541 Output Parameter: 542 . isActive - `PETSC_TRUE` if logging is in progress, `PETSC_FALSE` otherwise 543 544 Level: beginner 545 546 .seealso: [](ch_profiling), `PetscLogDefaultBegin()`, `PetscLogAllBegin()`, `PetscLogSet()` 547 @*/ 548 PetscErrorCode PetscLogIsActive(PetscBool *isActive) 549 { 550 PetscFunctionBegin; 551 *isActive = (PetscLogPLB && PetscLogPLE) ? PETSC_TRUE : PETSC_FALSE; 552 PetscFunctionReturn(PETSC_SUCCESS); 553 } 554 555 static PetscErrorCode PetscLogTypeBegin(PetscLogHandlerType type) 556 { 557 PetscLogHandler handler; 558 559 PetscFunctionBegin; 560 PetscCall(PetscLogTryGetHandler(type, &handler)); 561 if (handler) PetscFunctionReturn(PETSC_SUCCESS); 562 PetscCall(PetscLogHandlerCreate(PETSC_COMM_WORLD, &handler)); 563 PetscCall(PetscLogHandlerSetType(handler, type)); 564 PetscCall(PetscLogHandlerStart(handler)); 565 PetscCall(PetscLogHandlerDestroy(&handler)); 566 PetscFunctionReturn(PETSC_SUCCESS); 567 } 568 569 /*@C 570 PetscLogDefaultBegin - Turns on logging of objects and events using the default logging functions `PetscLogEventBeginDefault()` and `PetscLogEventEndDefault()`. This logs flop 571 rates and object creation and should not slow programs down too much. 572 This routine may be called more than once. 573 574 Logically Collective over `PETSC_COMM_WORLD` 575 576 Options Database Key: 577 . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the 578 screen (for code configured with --with-log=1 (which is the default)) 579 580 Example Usage: 581 .vb 582 PetscInitialize(...); 583 PetscLogDefaultBegin(); 584 ... code ... 585 PetscLogView(viewer); or PetscLogDump(); 586 PetscFinalize(); 587 .ve 588 589 Level: advanced 590 591 Note: 592 `PetscLogView()` or `PetscLogDump()` actually cause the printing of 593 the logging information. 594 595 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogAllBegin()`, `PetscLogView()`, `PetscLogTraceBegin()` 596 @*/ 597 PetscErrorCode PetscLogDefaultBegin(void) 598 { 599 PetscFunctionBegin; 600 PetscCall(PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault)); 601 PetscFunctionReturn(PETSC_SUCCESS); 602 } 603 604 /*@C 605 PetscLogAllBegin - Turns on extensive logging of objects and events. Logs 606 all events. This creates large log files and slows the program down. 607 608 Logically Collective on `PETSC_COMM_WORLD` 609 610 Options Database Key: 611 . -log_all - Prints extensive log information 612 613 Example Usage: 614 .vb 615 PetscInitialize(...); 616 PetscLogAllBegin(); 617 ... code ... 618 PetscLogDump(filename); 619 PetscFinalize(); 620 .ve 621 622 Level: advanced 623 624 Note: 625 A related routine is `PetscLogDefaultBegin()` (with the options key -log_view), which is 626 intended for production runs since it logs only flop rates and object 627 creation (and shouldn't significantly slow the programs). 628 629 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogDefaultBegin()`, `PetscLogTraceBegin()` 630 @*/ 631 PetscErrorCode PetscLogAllBegin(void) 632 { 633 PetscFunctionBegin; 634 PetscCall(PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete)); 635 PetscFunctionReturn(PETSC_SUCCESS); 636 } 637 638 /*@C 639 PetscLogTraceBegin - Activates trace logging. Every time a PETSc event 640 begins or ends, the event name is printed. 641 642 Logically Collective on `PETSC_COMM_WORLD` 643 644 Input Parameter: 645 . file - The file to print trace in (e.g. stdout) 646 647 Options Database Key: 648 . -log_trace [filename] - Activates `PetscLogTraceBegin()` 649 650 Level: intermediate 651 652 Notes: 653 `PetscLogTraceBegin()` prints the processor number, the execution time (sec), 654 then "Event begin:" or "Event end:" followed by the event name. 655 656 `PetscLogTraceBegin()` allows tracing of all PETSc calls, which is useful 657 to determine where a program is hanging without running in the 658 debugger. Can be used in conjunction with the -info option. 659 660 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogAllBegin()`, `PetscLogView()`, `PetscLogDefaultBegin()` 661 @*/ 662 PetscErrorCode PetscLogTraceBegin(FILE *file) 663 { 664 PetscFunctionBegin; 665 petsc_tracefile = file; 666 667 PetscCall(PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace)); 668 PetscFunctionReturn(PETSC_SUCCESS); 669 } 670 671 /*@C 672 PetscLogLegacyCallbacksBegin - Create and start a log handler from callbacks 673 matching the now deprecated function pointers `PetscLogPLB`, `PetscLogPLE`, 674 `PetscLogPHC`, `PetscLogPHD`. 675 676 Logically Collective over `PETSC_COMM_WORLD` 677 678 Input Parameters: 679 + PetscLogPLB - A callback that will be executed by `PetscLogEventBegin()` (or `NULL`) 680 . PetscLogPLE - A callback that will be executed by `PetscLogEventEnd()` (or `NULL`) 681 . PetscLogPHC - A callback that will be executed by `PetscLogObjectCreate()` (or `NULL`) 682 - PetscLogPHD - A callback that will be executed by `PetscLogObjectCreate()` (or `NULL`) 683 684 Calling sequence of `PetscLogPLB`: 685 + e - a `PetscLogEvent` that is beginning 686 . _i - deprecated, unused 687 . o1 - a `PetscObject` associated with `e` (or `NULL`) 688 . o2 - a `PetscObject` associated with `e` (or `NULL`) 689 . o3 - a `PetscObject` associated with `e` (or `NULL`) 690 - o4 - a `PetscObject` associated with `e` (or `NULL`) 691 692 Calling sequence of `PetscLogPLE`: 693 + e - a `PetscLogEvent` that is beginning 694 . _i - deprecated, unused 695 . o1 - a `PetscObject` associated with `e` (or `NULL`) 696 . o2 - a `PetscObject` associated with `e` (or `NULL`) 697 . o3 - a `PetscObject` associated with `e` (or `NULL`) 698 - o4 - a `PetscObject` associated with `e` (or `NULL`) 699 700 Calling sequence of `PetscLogPHC`: 701 . o - a `PetscObject` that has just been created 702 703 Calling sequence of `PetscLogPHD`: 704 . o - a `PetscObject` that is about to be destroyed 705 706 Level: advanced 707 708 Notes: 709 This is for transitioning from the deprecated function `PetscLogSet()` and should not be used in new code. 710 711 This should help migrate external log handlers to use `PetscLogHandler`, but 712 callbacks that depend on the deprecated `PetscLogStage` datatype will have to be 713 updated. 714 715 .seealso: [](ch_profiling), `PetscLogHandler`, `PetscLogHandlerStart()`, `PetscLogState` 716 @*/ 717 PetscErrorCode PetscLogLegacyCallbacksBegin(PetscErrorCode (*PetscLogPLB)(PetscLogEvent e, int _i, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4), PetscErrorCode (*PetscLogPLE)(PetscLogEvent e, int _i, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4), PetscErrorCode (*PetscLogPHC)(PetscObject o), PetscErrorCode (*PetscLogPHD)(PetscObject o)) 718 { 719 PetscLogHandler handler; 720 721 PetscFunctionBegin; 722 PetscCall(PetscLogHandlerCreateLegacy(PETSC_COMM_WORLD, PetscLogPLB, PetscLogPLE, PetscLogPHC, PetscLogPHD, &handler)); 723 PetscCall(PetscLogHandlerStart(handler)); 724 PetscCall(PetscLogHandlerDestroy(&handler)); 725 PetscFunctionReturn(PETSC_SUCCESS); 726 } 727 728 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 729 #include <../src/sys/perfstubs/timer.h> 730 #endif 731 732 /*@C 733 PetscLogPerfstubsBegin - Turns on logging of events using the perfstubs interface. 734 735 Collective over `PETSC_COMM_WORLD` 736 737 Options Database Key: 738 . -log_perfstubs - use an external log handler through the perfstubs interface 739 740 Level: advanced 741 742 .seealso: [](ch_profiling), `PetscLogDefaultBegin()`, `PetscLogEventActivate()` 743 @*/ 744 PetscErrorCode PetscLogPerfstubsBegin(void) 745 { 746 PetscFunctionBegin; 747 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 748 PetscCall(PetscLogTypeBegin(PETSC_LOG_HANDLER_PERFSTUBS)); 749 #else 750 SETERRQ(PETSC_COMM_WORLD, PETSC_ERR_SUP_SYS, "PETSc was configured without perfstubs support, reconfigure with --with-tau-perfstubs"); 751 #endif 752 PetscFunctionReturn(PETSC_SUCCESS); 753 } 754 755 /*@ 756 PetscLogActions - Determines whether actions are logged for the graphical viewer. 757 758 Not Collective 759 760 Input Parameter: 761 . flag - `PETSC_TRUE` if actions are to be logged 762 763 Options Database Key: 764 . -log_exclude_actions - Turns off actions logging 765 766 Level: intermediate 767 768 Note: 769 Logging of actions continues to consume more memory as the program 770 runs. Long running programs should consider turning this feature off. 771 772 .seealso: [](ch_profiling), `PetscLogStagePush()`, `PetscLogStagePop()` 773 @*/ 774 PetscErrorCode PetscLogActions(PetscBool flag) 775 { 776 PetscFunctionBegin; 777 petsc_logActions = flag; 778 PetscFunctionReturn(PETSC_SUCCESS); 779 } 780 781 /*@ 782 PetscLogObjects - Determines whether objects are logged for the graphical viewer. 783 784 Not Collective 785 786 Input Parameter: 787 . flag - `PETSC_TRUE` if objects are to be logged 788 789 Options Database Key: 790 . -log_exclude_objects - Turns off objects logging 791 792 Level: intermediate 793 794 Note: 795 Logging of objects continues to consume more memory as the program 796 runs. Long running programs should consider turning this feature off. 797 798 .seealso: [](ch_profiling), `PetscLogStagePush()`, `PetscLogStagePop()` 799 @*/ 800 PetscErrorCode PetscLogObjects(PetscBool flag) 801 { 802 PetscFunctionBegin; 803 petsc_logObjects = flag; 804 PetscFunctionReturn(PETSC_SUCCESS); 805 } 806 807 /*------------------------------------------------ Stage Functions --------------------------------------------------*/ 808 /*@C 809 PetscLogStageRegister - Attaches a character string name to a logging stage. 810 811 Not Collective 812 813 Input Parameter: 814 . sname - The name to associate with that stage 815 816 Output Parameter: 817 . stage - The stage number 818 819 Level: intermediate 820 821 .seealso: [](ch_profiling), `PetscLogStagePush()`, `PetscLogStagePop()` 822 @*/ 823 PetscErrorCode PetscLogStageRegister(const char sname[], PetscLogStage *stage) 824 { 825 PetscStageLog stageLog; 826 PetscLogEvent event; 827 828 PetscFunctionBegin; 829 PetscCall(PetscLogGetStageLog(&stageLog)); 830 PetscCall(PetscStageLogRegister(stageLog, sname, stage)); 831 /* Copy events already changed in the main stage, this sucks */ 832 PetscCall(PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents)); 833 for (event = 0; event < stageLog->eventLog->numEvents; event++) PetscCall(PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event], &stageLog->stageInfo[*stage].eventLog->eventInfo[event])); 834 PetscCall(PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses)); 835 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 836 if (perfstubs_initialized == PERFSTUBS_SUCCESS) PetscStackCallExternalVoid("ps_timer_create_", stageLog->stageInfo[*stage].timer = ps_timer_create_(sname)); 837 #endif 838 PetscFunctionReturn(PETSC_SUCCESS); 839 } 840 841 /*@C 842 PetscLogStagePush - This function pushes a stage on the logging stack. Events started and stopped until `PetscLogStagePop()` will be associated with the stage 843 844 Not Collective 845 846 Input Parameter: 847 . stage - The stage on which to log 848 849 Example Usage: 850 If the option -log_view is used to run the program containing the 851 following code, then 2 sets of summary data will be printed during 852 PetscFinalize(). 853 .vb 854 PetscInitialize(int *argc,char ***args,0,0); 855 [stage 0 of code] 856 PetscLogStagePush(1); 857 [stage 1 of code] 858 PetscLogStagePop(); 859 PetscBarrier(...); 860 [more stage 0 of code] 861 PetscFinalize(); 862 .ve 863 864 Level: intermediate 865 866 Note: 867 Use `PetscLogStageRegister()` to register a stage. 868 869 .seealso: [](ch_profiling), `PetscLogStagePop()`, `PetscLogStageRegister()`, `PetscBarrier()` 870 @*/ 871 PetscErrorCode PetscLogStagePush(PetscLogStage stage) 872 { 873 PetscStageLog stageLog; 874 875 PetscFunctionBegin; 876 PetscCall(PetscLogGetStageLog(&stageLog)); 877 PetscCall(PetscStageLogPush(stageLog, stage)); 878 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 879 if (perfstubs_initialized == PERFSTUBS_SUCCESS && stageLog->stageInfo[stage].timer != NULL) PetscStackCallExternalVoid("ps_timer_start_", ps_timer_start_(stageLog->stageInfo[stage].timer)); 880 #endif 881 PetscFunctionReturn(PETSC_SUCCESS); 882 } 883 884 /*@C 885 PetscLogStagePop - This function pops a stage from the logging stack that was pushed with `PetscLogStagePush()` 886 887 Not Collective 888 889 Example Usage: 890 If the option -log_view is used to run the program containing the 891 following code, then 2 sets of summary data will be printed during 892 PetscFinalize(). 893 .vb 894 PetscInitialize(int *argc,char ***args,0,0); 895 [stage 0 of code] 896 PetscLogStagePush(1); 897 [stage 1 of code] 898 PetscLogStagePop(); 899 PetscBarrier(...); 900 [more stage 0 of code] 901 PetscFinalize(); 902 .ve 903 904 Level: intermediate 905 906 .seealso: [](ch_profiling), `PetscLogStagePush()`, `PetscLogStageRegister()`, `PetscBarrier()` 907 @*/ 908 PetscErrorCode PetscLogStagePop(void) 909 { 910 PetscStageLog stageLog; 911 912 PetscFunctionBegin; 913 PetscCall(PetscLogGetStageLog(&stageLog)); 914 #if defined(PETSC_HAVE_TAU_PERFSTUBS) 915 if (perfstubs_initialized == PERFSTUBS_SUCCESS && stageLog->stageInfo[stageLog->curStage].timer != NULL) PetscStackCallExternalVoid("ps_timer_stop_", ps_timer_stop_(stageLog->stageInfo[stageLog->curStage].timer)); 916 #endif 917 PetscCall(PetscStageLogPop(stageLog)); 918 PetscFunctionReturn(PETSC_SUCCESS); 919 } 920 921 /*@ 922 PetscLogStageSetActive - Sets if a stage is used for `PetscLogEventBegin()` and `PetscLogEventEnd()`. 923 924 Not Collective 925 926 Input Parameters: 927 + stage - The stage 928 - isActive - The activity flag, `PETSC_TRUE` for logging, else `PETSC_FALSE` (defaults to `PETSC_TRUE`) 929 930 Level: intermediate 931 932 Note: 933 If this is set to `PETSC_FALSE` the logging acts as if the stage did not exist 934 935 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 936 @*/ 937 PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive) 938 { 939 PetscStageLog stageLog; 940 941 PetscFunctionBegin; 942 PetscCall(PetscLogGetStageLog(&stageLog)); 943 PetscCall(PetscStageLogSetActive(stageLog, stage, isActive)); 944 PetscFunctionReturn(PETSC_SUCCESS); 945 } 946 947 /*@ 948 PetscLogStageGetActive - Checks if a stage is used for `PetscLogEventBegin()` and `PetscLogEventEnd()`. 949 950 Not Collective 951 952 Input Parameter: 953 . stage - The stage 954 955 Output Parameter: 956 . isActive - The activity flag, `PETSC_TRUE` for logging, else `PETSC_FALSE` (defaults to `PETSC_TRUE`) 957 958 Level: intermediate 959 960 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 961 @*/ 962 PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive) 963 { 964 PetscStageLog stageLog; 965 966 PetscFunctionBegin; 967 PetscCall(PetscLogGetStageLog(&stageLog)); 968 PetscCall(PetscStageLogGetActive(stageLog, stage, isActive)); 969 PetscFunctionReturn(PETSC_SUCCESS); 970 } 971 972 /*@ 973 PetscLogStageSetVisible - Determines stage visibility in `PetscLogView()` 974 975 Not Collective 976 977 Input Parameters: 978 + stage - The stage 979 - isVisible - The visibility flag, `PETSC_TRUE` to print, else `PETSC_FALSE` (defaults to `PETSC_TRUE`) 980 981 Level: intermediate 982 983 Developer Notes: 984 What does visible mean, needs to be documented. 985 986 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscLogView()` 987 @*/ 988 PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible) 989 { 990 PetscStageLog stageLog; 991 992 PetscFunctionBegin; 993 PetscCall(PetscLogGetStageLog(&stageLog)); 994 PetscCall(PetscStageLogSetVisible(stageLog, stage, isVisible)); 995 PetscFunctionReturn(PETSC_SUCCESS); 996 } 997 998 /*@ 999 PetscLogStageGetVisible - Returns stage visibility in `PetscLogView()` 1000 1001 Not Collective 1002 1003 Input Parameter: 1004 . stage - The stage 1005 1006 Output Parameter: 1007 . isVisible - The visibility flag, `PETSC_TRUE` to print, else `PETSC_FALSE` (defaults to `PETSC_TRUE`) 1008 1009 Level: intermediate 1010 1011 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscLogView()` 1012 @*/ 1013 PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible) 1014 { 1015 PetscStageLog stageLog; 1016 1017 PetscFunctionBegin; 1018 PetscCall(PetscLogGetStageLog(&stageLog)); 1019 PetscCall(PetscStageLogGetVisible(stageLog, stage, isVisible)); 1020 PetscFunctionReturn(PETSC_SUCCESS); 1021 } 1022 1023 /*@C 1024 PetscLogStageGetId - Returns the stage id when given the stage name. 1025 1026 Not Collective 1027 1028 Input Parameter: 1029 . name - The stage name 1030 1031 Output Parameter: 1032 . stage - The stage, , or -1 if no stage with that name exists 1033 1034 Level: intermediate 1035 1036 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 1037 @*/ 1038 PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage) 1039 { 1040 PetscStageLog stageLog; 1041 1042 PetscFunctionBegin; 1043 PetscCall(PetscLogGetStageLog(&stageLog)); 1044 PetscCall(PetscStageLogGetStage(stageLog, name, stage)); 1045 PetscFunctionReturn(PETSC_SUCCESS); 1046 } 1047 1048 /*@C 1049 PetscLogStageGetName - Returns the stage name when given the stage id. 1050 1051 Not Collective 1052 1053 Input Parameter: 1054 . stage - The stage 1055 1056 Output Parameter: 1057 . name - The stage name 1058 1059 Level: intermediate 1060 1061 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogStagePush()`, `PetscLogStagePop()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 1062 @*/ 1063 PetscErrorCode PetscLogStageGetName(PetscLogStage stage, const char **name) 1064 { 1065 PetscLogStageInfo stage_info; 1066 PetscLogState state; 1067 1068 PetscFunctionBegin; 1069 PetscCall(PetscLogGetState(&state)); 1070 PetscCall(PetscLogStateStageGetInfo(state, stage, &stage_info)); 1071 *name = stage_info.name; 1072 PetscFunctionReturn(PETSC_SUCCESS); 1073 } 1074 1075 /*------------------------------------------------ Event Functions --------------------------------------------------*/ 1076 1077 /*@C 1078 PetscLogEventRegister - Registers an event name for logging operations 1079 1080 Not Collective 1081 1082 Input Parameters: 1083 + name - The name associated with the event 1084 - classid - The classid associated to the class for this event, obtain either with 1085 `PetscClassIdRegister()` or use a predefined one such as `KSP_CLASSID`, `SNES_CLASSID`, the predefined ones 1086 are only available in C code 1087 1088 Output Parameter: 1089 . event - The event id for use with `PetscLogEventBegin()` and `PetscLogEventEnd()`. 1090 1091 Example Usage: 1092 .vb 1093 PetscLogEvent USER_EVENT; 1094 PetscClassId classid; 1095 PetscLogDouble user_event_flops; 1096 PetscClassIdRegister("class name",&classid); 1097 PetscLogEventRegister("User event name",classid,&USER_EVENT); 1098 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1099 [code segment to monitor] 1100 PetscLogFlops(user_event_flops); 1101 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1102 .ve 1103 1104 Level: intermediate 1105 1106 Notes: 1107 PETSc automatically logs library events if the code has been 1108 configured with --with-log (which is the default) and 1109 -log_view or -log_all is specified. `PetscLogEventRegister()` is 1110 intended for logging user events to supplement this PETSc 1111 information. 1112 1113 PETSc can gather data for use with the utilities Jumpshot 1114 (part of the MPICH distribution). If PETSc has been compiled 1115 with flag -DPETSC_HAVE_MPE (MPE is an additional utility within 1116 MPICH), the user can employ another command line option, -log_mpe, 1117 to create a logfile, "mpe.log", which can be visualized 1118 Jumpshot. 1119 1120 The classid is associated with each event so that classes of events 1121 can be disabled simultaneously, such as all matrix events. The user 1122 can either use an existing classid, such as `MAT_CLASSID`, or create 1123 their own as shown in the example. 1124 1125 If an existing event with the same name exists, its event handle is 1126 returned instead of creating a new event. 1127 1128 .seealso: [](ch_profiling), `PetscLogStageRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscLogFlops()`, 1129 `PetscLogEventActivate()`, `PetscLogEventDeactivate()`, `PetscClassIdRegister()` 1130 @*/ 1131 PetscErrorCode PetscLogEventRegister(const char name[], PetscClassId classid, PetscLogEvent *event) 1132 { 1133 PetscStageLog stageLog; 1134 int stage; 1135 1136 PetscFunctionBegin; 1137 *event = PETSC_DECIDE; 1138 PetscCall(PetscLogGetStageLog(&stageLog)); 1139 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, name, event)); 1140 if (*event > 0) PetscFunctionReturn(PETSC_SUCCESS); 1141 PetscCall(PetscEventRegLogRegister(stageLog->eventLog, name, classid, event)); 1142 for (stage = 0; stage < stageLog->numStages; stage++) { 1143 PetscCall(PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents)); 1144 PetscCall(PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses)); 1145 } 1146 PetscFunctionReturn(PETSC_SUCCESS); 1147 } 1148 1149 /*@ 1150 PetscLogEventSetCollective - Indicates that a particular event is collective. 1151 1152 Not Collective 1153 1154 Input Parameters: 1155 + event - The event id 1156 - collective - Boolean flag indicating whether a particular event is collective 1157 1158 Level: developer 1159 1160 Notes: 1161 New events returned from `PetscLogEventRegister()` are collective by default. 1162 1163 Collective events are handled specially if the -log_sync is used. In that case the logging saves information about 1164 two parts of the event; the time for all the MPI ranks to synchronize and then the time for the actual computation/communication 1165 to be performed. This option is useful to debug imbalance within the computations or communications 1166 1167 .seealso: [](ch_profiling), `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscLogEventRegister()` 1168 @*/ 1169 PetscErrorCode PetscLogEventSetCollective(PetscLogEvent event, PetscBool collective) 1170 { 1171 PetscStageLog stageLog; 1172 PetscEventRegLog eventRegLog; 1173 1174 PetscFunctionBegin; 1175 PetscCall(PetscLogGetStageLog(&stageLog)); 1176 PetscCall(PetscStageLogGetEventRegLog(stageLog, &eventRegLog)); 1177 PetscCheck(event >= 0 && event <= eventRegLog->numEvents, PETSC_COMM_SELF, PETSC_ERR_ARG_OUTOFRANGE, "Invalid event id"); 1178 eventRegLog->eventInfo[event].collective = collective; 1179 PetscFunctionReturn(PETSC_SUCCESS); 1180 } 1181 1182 /*@ 1183 PetscLogEventIncludeClass - Activates event logging for a PETSc object class in every stage. 1184 1185 Not Collective 1186 1187 Input Parameter: 1188 . classid - The object class, for example `MAT_CLASSID`, `SNES_CLASSID`, etc. 1189 1190 Level: developer 1191 1192 .seealso: [](ch_profiling), `PetscLogEventActivateClass()`, `PetscLogEventDeactivateClass()`, `PetscLogEventActivate()`, `PetscLogEventDeactivate()` 1193 @*/ 1194 PetscErrorCode PetscLogEventIncludeClass(PetscClassId classid) 1195 { 1196 PetscStageLog stageLog; 1197 int stage; 1198 1199 PetscFunctionBegin; 1200 PetscCall(PetscLogGetStageLog(&stageLog)); 1201 for (stage = 0; stage < stageLog->numStages; stage++) PetscCall(PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid)); 1202 PetscFunctionReturn(PETSC_SUCCESS); 1203 } 1204 1205 /*@ 1206 PetscLogEventExcludeClass - Deactivates event logging for a PETSc object class in every stage. 1207 1208 Not Collective 1209 1210 Input Parameter: 1211 . classid - The object class, for example `MAT_CLASSID`, `SNES_CLASSID`, etc. 1212 1213 Level: developer 1214 1215 Note: 1216 If a class is excluded then events associated with that class are not logged. 1217 1218 .seealso: [](ch_profiling), `PetscLogEventDeactivateClass()`, `PetscLogEventActivateClass()`, `PetscLogEventDeactivate()`, `PetscLogEventActivate()` 1219 @*/ 1220 PetscErrorCode PetscLogEventExcludeClass(PetscClassId classid) 1221 { 1222 PetscStageLog stageLog; 1223 int stage; 1224 1225 PetscFunctionBegin; 1226 PetscCall(PetscLogGetStageLog(&stageLog)); 1227 for (stage = 0; stage < stageLog->numStages; stage++) PetscCall(PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid)); 1228 PetscFunctionReturn(PETSC_SUCCESS); 1229 } 1230 1231 /*@ 1232 PetscLogEventActivate - Indicates that a particular event should be logged. 1233 1234 Not Collective 1235 1236 Input Parameter: 1237 . event - The event id 1238 1239 Example Usage: 1240 .vb 1241 PetscLogEventDeactivate(VEC_SetValues); 1242 [code where you do not want to log VecSetValues()] 1243 PetscLogEventActivate(VEC_SetValues); 1244 [code where you do want to log VecSetValues()] 1245 .ve 1246 1247 Level: advanced 1248 1249 Note: 1250 The event may be either a pre-defined PETSc event (found in include/petsclog.h) 1251 or an event number obtained with `PetscLogEventRegister()`. 1252 1253 .seealso: [](ch_profiling), `PlogEventDeactivate()`, `PlogEventDeactivatePush()`, `PetscLogEventDeactivatePop()` 1254 @*/ 1255 PetscErrorCode PetscLogEventActivate(PetscLogEvent event) 1256 { 1257 PetscStageLog stageLog; 1258 int stage; 1259 1260 PetscFunctionBegin; 1261 PetscCall(PetscLogGetStageLog(&stageLog)); 1262 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1263 PetscCall(PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event)); 1264 PetscFunctionReturn(PETSC_SUCCESS); 1265 } 1266 1267 /*@ 1268 PetscLogEventDeactivate - Indicates that a particular event should not be logged. 1269 1270 Not Collective 1271 1272 Input Parameter: 1273 . event - The event id 1274 1275 Example Usage: 1276 .vb 1277 PetscLogEventDeactivate(VEC_SetValues); 1278 [code where you do not want to log VecSetValues()] 1279 PetscLogEventActivate(VEC_SetValues); 1280 [code where you do want to log VecSetValues()] 1281 .ve 1282 1283 Level: advanced 1284 1285 Note: 1286 The event may be either a pre-defined PETSc event (found in 1287 include/petsclog.h) or an event number obtained with `PetscLogEventRegister()`). 1288 1289 .seealso: [](ch_profiling), `PetscLogEventActivate()`, `PetscLogEventDeactivatePush()`, `PetscLogEventDeactivatePop()` 1290 @*/ 1291 PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event) 1292 { 1293 PetscStageLog stageLog; 1294 int stage; 1295 1296 PetscFunctionBegin; 1297 PetscCall(PetscLogGetStageLog(&stageLog)); 1298 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1299 PetscCall(PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event)); 1300 PetscFunctionReturn(PETSC_SUCCESS); 1301 } 1302 1303 /*@ 1304 PetscLogEventDeactivatePush - Indicates that a particular event should not be logged until `PetscLogEventDeactivatePop()` is called 1305 1306 Not Collective 1307 1308 Input Parameter: 1309 . event - The event id 1310 1311 Example Usage: 1312 .vb 1313 PetscLogEventDeactivatePush(VEC_SetValues); 1314 [code where you do not want to log VecSetValues()] 1315 PetscLogEventDeactivatePop(VEC_SetValues); 1316 [code where you do want to log VecSetValues()] 1317 .ve 1318 1319 Level: advanced 1320 1321 Note: 1322 The event may be either a pre-defined PETSc event (found in 1323 include/petsclog.h) or an event number obtained with `PetscLogEventRegister()`). 1324 1325 .seealso: [](ch_profiling), `PetscLogEventActivate()`, `PetscLogEventDeactivatePop()`, `PetscLogEventDeactivate()` 1326 @*/ 1327 PetscErrorCode PetscLogEventDeactivatePush(PetscLogEvent event) 1328 { 1329 PetscStageLog stageLog; 1330 int stage; 1331 1332 PetscFunctionBegin; 1333 PetscCall(PetscLogGetStageLog(&stageLog)); 1334 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1335 PetscCall(PetscEventPerfLogDeactivatePush(stageLog->stageInfo[stage].eventLog, event)); 1336 PetscFunctionReturn(PETSC_SUCCESS); 1337 } 1338 1339 /*@ 1340 PetscLogEventDeactivatePop - Indicates that a particular event should again be logged after the logging was turned off with `PetscLogEventDeactivatePush()` 1341 1342 Not Collective 1343 1344 Input Parameter: 1345 . event - The event id 1346 1347 Example Usage: 1348 .vb 1349 PetscLogEventDeactivatePush(VEC_SetValues); 1350 [code where you do not want to log VecSetValues()] 1351 PetscLogEventDeactivatePop(VEC_SetValues); 1352 [code where you do want to log VecSetValues()] 1353 .ve 1354 1355 Level: advanced 1356 1357 Note: 1358 The event may be either a pre-defined PETSc event (found in 1359 include/petsclog.h) or an event number obtained with `PetscLogEventRegister()`). 1360 1361 .seealso: [](ch_profiling), `PetscLogEventActivate()`, `PetscLogEventDeactivatePush()` 1362 @*/ 1363 PetscErrorCode PetscLogEventDeactivatePop(PetscLogEvent event) 1364 { 1365 PetscStageLog stageLog; 1366 int stage; 1367 1368 PetscFunctionBegin; 1369 PetscCall(PetscLogGetStageLog(&stageLog)); 1370 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1371 PetscCall(PetscEventPerfLogDeactivatePop(stageLog->stageInfo[stage].eventLog, event)); 1372 PetscFunctionReturn(PETSC_SUCCESS); 1373 } 1374 1375 /*@ 1376 PetscLogEventSetActiveAll - Turns on logging of all events 1377 1378 Not Collective 1379 1380 Input Parameters: 1381 + event - The event id 1382 - isActive - The activity flag determining whether the event is logged 1383 1384 Level: advanced 1385 1386 .seealso: [](ch_profiling), `PlogEventActivate()`, `PlogEventDeactivate()` 1387 @*/ 1388 PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive) 1389 { 1390 PetscStageLog stageLog; 1391 int stage; 1392 1393 PetscFunctionBegin; 1394 PetscCall(PetscLogGetStageLog(&stageLog)); 1395 for (stage = 0; stage < stageLog->numStages; stage++) { 1396 if (isActive) { 1397 PetscCall(PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event)); 1398 } else { 1399 PetscCall(PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event)); 1400 } 1401 } 1402 PetscFunctionReturn(PETSC_SUCCESS); 1403 } 1404 1405 /*@ 1406 PetscLogEventActivateClass - Activates event logging for a PETSc object class for the current stage 1407 1408 Not Collective 1409 1410 Input Parameter: 1411 . classid - The event class, for example `MAT_CLASSID`, `SNES_CLASSID`, etc. 1412 1413 Level: developer 1414 1415 .seealso: [](ch_profiling), `PetscLogEventIncludeClass()`, `PetscLogEventExcludeClass()`, `PetscLogEventDeactivateClass()`, `PetscLogEventActivate()`, `PetscLogEventDeactivate()` 1416 @*/ 1417 PetscErrorCode PetscLogEventActivateClass(PetscClassId classid) 1418 { 1419 PetscStageLog stageLog; 1420 int stage; 1421 1422 PetscFunctionBegin; 1423 PetscCall(PetscLogGetStageLog(&stageLog)); 1424 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1425 PetscCall(PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid)); 1426 PetscFunctionReturn(PETSC_SUCCESS); 1427 } 1428 1429 /*@ 1430 PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class for the current stage 1431 1432 Not Collective 1433 1434 Input Parameter: 1435 . classid - The event class, for example `MAT_CLASSID`, `SNES_CLASSID`, etc. 1436 1437 Level: developer 1438 1439 .seealso: [](ch_profiling), `PetscLogEventIncludeClass()`, `PetscLogEventExcludeClass()`, `PetscLogEventActivateClass()`, `PetscLogEventActivate()`, `PetscLogEventDeactivate()` 1440 @*/ 1441 PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid) 1442 { 1443 PetscStageLog stageLog; 1444 int stage; 1445 1446 PetscFunctionBegin; 1447 PetscCall(PetscLogGetStageLog(&stageLog)); 1448 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1449 PetscCall(PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid)); 1450 PetscFunctionReturn(PETSC_SUCCESS); 1451 } 1452 1453 /*MC 1454 PetscLogEventSync - Synchronizes the beginning of a user event. 1455 1456 Synopsis: 1457 #include <petsclog.h> 1458 PetscErrorCode PetscLogEventSync(int e, MPI_Comm comm) 1459 1460 Collective 1461 1462 Input Parameters: 1463 + e - integer associated with the event obtained from PetscLogEventRegister() 1464 - comm - an MPI communicator 1465 1466 Example Usage: 1467 .vb 1468 PetscLogEvent USER_EVENT; 1469 1470 PetscLogEventRegister("User event", 0, &USER_EVENT); 1471 PetscLogEventSync(USER_EVENT, PETSC_COMM_WORLD); 1472 PetscLogEventBegin(USER_EVENT, 0, 0, 0, 0); 1473 [code segment to monitor] 1474 PetscLogEventEnd(USER_EVENT, 0, 0, 0 , 0); 1475 .ve 1476 1477 Level: developer 1478 1479 Note: 1480 This routine should be called only if there is not a `PetscObject` available to pass to 1481 `PetscLogEventBegin()`. 1482 1483 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()` 1484 M*/ 1485 1486 /*MC 1487 PetscLogEventBegin - Logs the beginning of a user event. 1488 1489 Synopsis: 1490 #include <petsclog.h> 1491 PetscErrorCode PetscLogEventBegin(int e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4) 1492 1493 Not Collective 1494 1495 Input Parameters: 1496 + e - integer associated with the event obtained from PetscLogEventRegister() 1497 - o1,o2,o3,o4 - objects associated with the event, or 0 1498 1499 Fortran Synopsis: 1500 void PetscLogEventBegin(int e, PetscErrorCode ierr) 1501 1502 Example Usage: 1503 .vb 1504 PetscLogEvent USER_EVENT; 1505 1506 PetscLogDouble user_event_flops; 1507 PetscLogEventRegister("User event",0, &USER_EVENT); 1508 PetscLogEventBegin(USER_EVENT, 0, 0, 0, 0); 1509 [code segment to monitor] 1510 PetscLogFlops(user_event_flops); 1511 PetscLogEventEnd(USER_EVENT, 0, 0, 0, 0); 1512 .ve 1513 1514 Level: intermediate 1515 1516 Developer Note: 1517 `PetscLogEventBegin()` and `PetscLogEventBegin()` return error codes instead of explicitly 1518 handling the errors that occur in the macro directly because other packages that use this 1519 macros have used them in their own functions or methods that do not return error codes and it 1520 would be disruptive to change the current behavior. 1521 1522 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventEnd()`, `PetscLogFlops()` 1523 M*/ 1524 1525 /*MC 1526 PetscLogEventEnd - Log the end of a user event. 1527 1528 Synopsis: 1529 #include <petsclog.h> 1530 PetscErrorCode PetscLogEventEnd(int e, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4) 1531 1532 Not Collective 1533 1534 Input Parameters: 1535 + e - integer associated with the event obtained with PetscLogEventRegister() 1536 - o1,o2,o3,o4 - objects associated with the event, or 0 1537 1538 Fortran Synopsis: 1539 void PetscLogEventEnd(int e, PetscErrorCode ierr) 1540 1541 Example Usage: 1542 .vb 1543 PetscLogEvent USER_EVENT; 1544 1545 PetscLogDouble user_event_flops; 1546 PetscLogEventRegister("User event", 0, &USER_EVENT); 1547 PetscLogEventBegin(USER_EVENT, 0, 0, 0, 0); 1548 [code segment to monitor] 1549 PetscLogFlops(user_event_flops); 1550 PetscLogEventEnd(USER_EVENT, 0, 0, 0, 0); 1551 .ve 1552 1553 Level: intermediate 1554 1555 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogFlops()` 1556 M*/ 1557 1558 /*@C 1559 PetscLogEventGetId - Returns the event id when given the event name. 1560 1561 Not Collective 1562 1563 Input Parameter: 1564 . name - The event name 1565 1566 Output Parameter: 1567 . event - The event, or -1 if no event with that name exists 1568 1569 Level: intermediate 1570 1571 .seealso: [](ch_profiling), `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscLogStageGetId()` 1572 @*/ 1573 PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event) 1574 { 1575 PetscStageLog stageLog; 1576 1577 PetscFunctionBegin; 1578 PetscCall(PetscLogGetStageLog(&stageLog)); 1579 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, name, event)); 1580 PetscFunctionReturn(PETSC_SUCCESS); 1581 } 1582 1583 /*@C 1584 PetscLogEventGetName - Returns the event name when given the event id. 1585 1586 Not Collective 1587 1588 Input Parameter: 1589 . event - The event 1590 1591 Output Parameter: 1592 . name - The event name 1593 1594 Level: intermediate 1595 1596 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 1597 @*/ 1598 PetscErrorCode PetscLogEventGetName(PetscLogEvent event, const char **name) 1599 { 1600 PetscLogEventInfo event_info; 1601 PetscLogState state; 1602 1603 PetscFunctionBegin; 1604 PetscCall(PetscLogGetState(&state)); 1605 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 1606 *name = event_info.name; 1607 PetscFunctionReturn(PETSC_SUCCESS); 1608 } 1609 1610 /*@ 1611 PetscLogEventsPause - Put event logging into "paused" mode: timers and counters for in-progress events are paused, and any events that happen before logging is resumed with `PetscLogEventsResume()` are logged in the "Main Stage" of execution. 1612 1613 Not collective 1614 1615 Level: advanced 1616 1617 Notes: 1618 When an external library or runtime has is initialized it can involve lots of setup time that skews the statistics of any unrelated running events: this function is intended to isolate such calls in the default log summary (`PetscLogDefaultBegin()`, `PetscLogView()`). 1619 1620 Other log handlers (such as the nested handler, `PetscLogNestedBegin()`) will ignore this function. 1621 1622 .seealso: [](ch_profiling), `PetscLogEventDeactivatePush()`, `PetscLogEventDeactivatePop()`, `PetscLogEventsResume()` 1623 @*/ 1624 PetscErrorCode PetscLogEventsPause(void) 1625 { 1626 PetscLogHandler handler; 1627 1628 PetscFunctionBegin; 1629 PetscCall(PetscLogTryGetHandler(PETSC_LOG_HANDLER_DEFAULT, &handler)); 1630 if (handler) PetscCall(PetscLogHandlerDefaultEventsPause(handler)); 1631 PetscFunctionReturn(PETSC_SUCCESS); 1632 } 1633 1634 /*@ 1635 PetscLogEventsResume - Return logging to normal behavior after it was paused with `PetscLogEventsPause()`. 1636 1637 Not collective 1638 1639 Level: advanced 1640 1641 .seealso: [](ch_profiling), `PetscLogEventDeactivatePush()`, `PetscLogEventDeactivatePop()`, `PetscLogEventsPause()` 1642 @*/ 1643 PetscErrorCode PetscLogEventsResume(void) 1644 { 1645 PetscLogHandler handler; 1646 1647 PetscFunctionBegin; 1648 PetscCall(PetscLogTryGetHandler(PETSC_LOG_HANDLER_DEFAULT, &handler)); 1649 if (handler) PetscCall(PetscLogHandlerDefaultEventsResume(handler)); 1650 PetscFunctionReturn(PETSC_SUCCESS); 1651 } 1652 1653 PetscErrorCode PetscLogPushCurrentEvent_Internal(PetscLogEvent event) 1654 { 1655 PetscFunctionBegin; 1656 if (!PetscDefined(HAVE_THREADSAFETY)) PetscCall(PetscIntStackPush(current_log_event_stack, event)); 1657 PetscFunctionReturn(PETSC_SUCCESS); 1658 } 1659 1660 PetscErrorCode PetscLogPopCurrentEvent_Internal(void) 1661 { 1662 PetscFunctionBegin; 1663 if (!PetscDefined(HAVE_THREADSAFETY)) PetscCall(PetscIntStackPop(current_log_event_stack, NULL)); 1664 PetscFunctionReturn(PETSC_SUCCESS); 1665 } 1666 1667 PetscErrorCode PetscLogGetCurrentEvent_Internal(PetscLogEvent *event) 1668 { 1669 PetscBool empty; 1670 1671 PetscFunctionBegin; 1672 PetscAssertPointer(event, 1); 1673 *event = PETSC_DECIDE; 1674 PetscCall(PetscIntStackEmpty(current_log_event_stack, &empty)); 1675 if (!empty) PetscCall(PetscIntStackTop(current_log_event_stack, event)); 1676 PetscFunctionReturn(PETSC_SUCCESS); 1677 } 1678 1679 PetscErrorCode PetscLogEventPause_Internal(PetscLogEvent event) 1680 { 1681 PetscFunctionBegin; 1682 if (event != PETSC_DECIDE) PetscCall(PetscLogEventEnd(event, NULL, NULL, NULL, NULL)); 1683 PetscFunctionReturn(PETSC_SUCCESS); 1684 } 1685 1686 PetscErrorCode PetscLogEventResume_Internal(PetscLogEvent event) 1687 { 1688 PetscStageLog stageLog; 1689 PetscEventPerfLog eventLog; 1690 int stage; 1691 1692 PetscFunctionBegin; 1693 if (event == PETSC_DECIDE) PetscFunctionReturn(PETSC_SUCCESS); 1694 PetscCall(PetscLogEventBegin(event, NULL, NULL, NULL, NULL)); 1695 PetscCall(PetscLogGetStageLog(&stageLog)); 1696 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 1697 PetscCall(PetscStageLogGetEventPerfLog(stageLog, stage, &eventLog)); 1698 eventLog->eventInfo[event].count--; 1699 PetscFunctionReturn(PETSC_SUCCESS); 1700 } 1701 1702 /*------------------------------------------------ Class Functions --------------------------------------------------*/ 1703 1704 /*MC 1705 PetscLogObjectCreate - Log the creation of a `PetscObject` 1706 1707 Synopsis: 1708 #include <petsclog.h> 1709 PetscErrorCode PetscLogObjectCreate(PetscObject h) 1710 1711 Not Collective 1712 1713 Input Parameters: 1714 . h - A `PetscObject` 1715 1716 Level: developer 1717 1718 Developer Note: 1719 Called internally by PETSc when creating objects: users do not need to call this directly. 1720 1721 .seealso: [](ch_profiling), `PetscLogObjectDestroy()` 1722 M*/ 1723 1724 /*MC 1725 PetscLogObjectDestroy - Logs the destruction of a `PetscObject` 1726 1727 Synopsis: 1728 #include <petsclog.h> 1729 PetscErrorCode PetscLogObjectDestroy(PetscObject h) 1730 1731 Not Collective 1732 1733 Input Parameters: 1734 . h - A `PetscObject` 1735 1736 Level: developer 1737 1738 Developer Note: 1739 Called internally by PETSc when destroying objects: users do not need to call this directly. 1740 1741 .seealso: [](ch_profiling), `PetscLogObjectCreate()` 1742 M*/ 1743 1744 /*@C 1745 PetscLogClassGetClassId - Returns the `PetscClassId` when given the class name. 1746 1747 Not Collective 1748 1749 Input Parameter: 1750 . name - The class name 1751 1752 Output Parameter: 1753 . classid - The `PetscClassId` id, or -1 if no class with that name exists 1754 1755 Level: intermediate 1756 1757 .seealso: [](ch_profiling), `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscLogStageGetId()` 1758 @*/ 1759 PetscErrorCode PetscLogClassGetClassId(const char name[], PetscClassId *classid) 1760 { 1761 PetscLogClass log_class; 1762 PetscLogClassInfo class_info; 1763 PetscLogState state; 1764 1765 PetscFunctionBegin; 1766 PetscCall(PetscLogGetState(&state)); 1767 PetscCall(PetscLogStateGetClassFromName(state, name, &log_class)); 1768 if (log_class < 0) { 1769 *classid = -1; 1770 PetscFunctionReturn(PETSC_SUCCESS); 1771 } 1772 PetscCall(PetscLogStateClassGetInfo(state, log_class, &class_info)); 1773 *classid = class_info.classid; 1774 PetscFunctionReturn(PETSC_SUCCESS); 1775 } 1776 1777 /*@C 1778 PetscLogClassIdGetName - Returns a `PetscClassId`'s name. 1779 1780 Not Collective 1781 1782 Input Parameter: 1783 . classid - A `PetscClassId` 1784 1785 Output Parameter: 1786 . name - The class name 1787 1788 Level: intermediate 1789 1790 .seealso: [](ch_profiling), `PetscLogClassRegister()`, `PetscLogClassBegin()`, `PetscLogClassEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()`, `PetscPreLoadClass()` 1791 @*/ 1792 PetscErrorCode PetscLogClassIdGetName(PetscClassId classid, const char **name) 1793 { 1794 PetscLogClass log_class; 1795 PetscLogClassInfo class_info; 1796 PetscLogState state; 1797 1798 PetscFunctionBegin; 1799 PetscCall(PetscLogGetState(&state)); 1800 PetscCall(PetscLogStateGetClassFromClassId(state, classid, &log_class)); 1801 PetscCall(PetscLogStateClassGetInfo(state, log_class, &class_info)); 1802 *name = class_info.name; 1803 PetscFunctionReturn(PETSC_SUCCESS); 1804 } 1805 1806 /*------------------------------------------------ Output Functions -------------------------------------------------*/ 1807 /*@C 1808 PetscLogDump - Dumps logs of objects to a file. This file is intended to 1809 be read by bin/petscview. This program no longer exists. 1810 1811 Collective on `PETSC_COMM_WORLD` 1812 1813 Input Parameter: 1814 . sname - an optional file name 1815 1816 Example Usage: 1817 .vb 1818 PetscInitialize(...); 1819 PetscLogDefaultBegin(); or PetscLogAllBegin(); 1820 ... code ... 1821 PetscLogDump(filename); 1822 PetscFinalize(); 1823 .ve 1824 1825 Level: advanced 1826 1827 Note: 1828 The default file name is Log.<rank> where <rank> is the MPI process rank. If no name is specified, 1829 this file will be used. 1830 1831 .seealso: [](ch_profiling), `PetscLogDefaultBegin()`, `PetscLogAllBegin()`, `PetscLogView()` 1832 @*/ 1833 PetscErrorCode PetscLogDump(const char sname[]) 1834 { 1835 PetscStageLog stageLog; 1836 PetscEventPerfInfo *eventInfo; 1837 FILE *fd; 1838 char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN]; 1839 PetscLogDouble flops, _TotalTime; 1840 PetscMPIInt rank; 1841 int action, object, curStage; 1842 PetscLogEvent event; 1843 1844 PetscFunctionBegin; 1845 /* Calculate the total elapsed time */ 1846 PetscCall(PetscTime(&_TotalTime)); 1847 _TotalTime -= petsc_BaseTime; 1848 /* Open log file */ 1849 PetscCallMPI(MPI_Comm_rank(PETSC_COMM_WORLD, &rank)); 1850 PetscCall(PetscSNPrintf(file, PETSC_STATIC_ARRAY_LENGTH(file), "%s.%d", sname && sname[0] ? sname : "Log", rank)); 1851 PetscCall(PetscFixFilename(file, fname)); 1852 PetscCall(PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd)); 1853 PetscCheck(!(rank == 0) || !(!fd), PETSC_COMM_SELF, PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname); 1854 /* Output totals */ 1855 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime)); 1856 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0)); 1857 /* Output actions */ 1858 if (petsc_logActions) { 1859 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions)); 1860 for (action = 0; action < petsc_numActions; action++) { 1861 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n", petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1, 1862 petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem)); 1863 } 1864 } 1865 /* Output objects */ 1866 if (petsc_logObjects) { 1867 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed)); 1868 for (object = 0; object < petsc_numObjects; object++) { 1869 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int)petsc_objects[object].mem)); 1870 if (!petsc_objects[object].name[0]) { 1871 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "No Name\n")); 1872 } else { 1873 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name)); 1874 } 1875 if (petsc_objects[object].info[0] != 0) { 1876 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n")); 1877 } else { 1878 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info)); 1879 } 1880 } 1881 } 1882 /* Output events */ 1883 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n")); 1884 PetscCall(PetscLogGetStageLog(&stageLog)); 1885 PetscCall(PetscIntStackTop(stageLog->stack, &curStage)); 1886 eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo; 1887 for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) { 1888 if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops / eventInfo[event].time; 1889 else flops = 0.0; 1890 PetscCall(PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count, eventInfo[event].flops, eventInfo[event].time, flops)); 1891 } 1892 PetscCall(PetscFClose(PETSC_COMM_WORLD, fd)); 1893 PetscFunctionReturn(PETSC_SUCCESS); 1894 } 1895 1896 /* 1897 PetscLogView_Detailed - Each process prints the times for its own events 1898 1899 */ 1900 static PetscErrorCode PetscLogView_Detailed(PetscViewer viewer) 1901 { 1902 PetscStageLog stageLog; 1903 PetscEventPerfInfo *eventInfo = NULL, *stageInfo = NULL; 1904 PetscLogDouble locTotalTime, numRed, maxMem; 1905 int numStages, numEvents, stage, event; 1906 MPI_Comm comm = PetscObjectComm((PetscObject)viewer); 1907 PetscMPIInt rank, size; 1908 1909 PetscFunctionBegin; 1910 PetscCallMPI(MPI_Comm_size(comm, &size)); 1911 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 1912 /* Must preserve reduction count before we go on */ 1913 numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1914 /* Get the total elapsed time */ 1915 PetscCall(PetscTime(&locTotalTime)); 1916 locTotalTime -= petsc_BaseTime; 1917 PetscCall(PetscViewerASCIIPrintf(viewer, "size = %d\n", size)); 1918 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalTimes = {}\n")); 1919 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMessages = {}\n")); 1920 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMessageLens = {}\n")); 1921 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalReductions = {}\n")); 1922 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalFlop = {}\n")); 1923 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalObjects = {}\n")); 1924 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMemory = {}\n")); 1925 PetscCall(PetscLogGetStageLog(&stageLog)); 1926 PetscCallMPI(MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm)); 1927 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages = {}\n")); 1928 for (stage = 0; stage < numStages; stage++) { 1929 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"] = {}\n", stageLog->stageInfo[stage].name)); 1930 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"][\"summary\"] = {}\n", stageLog->stageInfo[stage].name)); 1931 PetscCallMPI(MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm)); 1932 for (event = 0; event < numEvents; event++) PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"][\"%s\"] = {}\n", stageLog->stageInfo[stage].name, stageLog->eventLog->eventInfo[event].name)); 1933 } 1934 PetscCall(PetscMallocGetMaximumUsage(&maxMem)); 1935 PetscCall(PetscViewerASCIIPushSynchronized(viewer)); 1936 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalTimes[%d] = %g\n", rank, locTotalTime)); 1937 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMessages[%d] = %g\n", rank, (petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct))); 1938 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMessageLens[%d] = %g\n", rank, (petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len))); 1939 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalReductions[%d] = %g\n", rank, numRed)); 1940 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalFlop[%d] = %g\n", rank, petsc_TotalFlops)); 1941 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalObjects[%d] = %d\n", rank, petsc_numObjects)); 1942 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMemory[%d] = %g\n", rank, maxMem)); 1943 PetscCall(PetscViewerFlush(viewer)); 1944 for (stage = 0; stage < numStages; stage++) { 1945 stageInfo = &stageLog->stageInfo[stage].perfInfo; 1946 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n", stageLog->stageInfo[stage].name, rank, stageInfo->time, 1947 stageInfo->numMessages, stageInfo->messageLength, stageInfo->numReductions, stageInfo->flops)); 1948 PetscCallMPI(MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm)); 1949 for (event = 0; event < numEvents; event++) { 1950 eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event]; 1951 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %d, \"time\" : %g, \"syncTime\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g", 1952 stageLog->stageInfo[stage].name, stageLog->eventLog->eventInfo[event].name, rank, eventInfo->count, eventInfo->time, eventInfo->syncTime, eventInfo->numMessages, eventInfo->messageLength, eventInfo->numReductions, 1953 eventInfo->flops)); 1954 if (eventInfo->dof[0] >= 0.) { 1955 PetscInt d, e; 1956 1957 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", \"dof\" : [")); 1958 for (d = 0; d < 8; ++d) { 1959 if (d > 0) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", ")); 1960 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->dof[d])); 1961 } 1962 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "]")); 1963 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", \"error\" : [")); 1964 for (e = 0; e < 8; ++e) { 1965 if (e > 0) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", ")); 1966 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->errors[e])); 1967 } 1968 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "]")); 1969 } 1970 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "}\n")); 1971 } 1972 } 1973 PetscCall(PetscViewerFlush(viewer)); 1974 PetscCall(PetscViewerASCIIPopSynchronized(viewer)); 1975 PetscFunctionReturn(PETSC_SUCCESS); 1976 } 1977 1978 /* 1979 PetscLogView_CSV - Each process prints the times for its own events in Comma-Separated Value Format 1980 */ 1981 static PetscErrorCode PetscLogView_CSV(PetscViewer viewer) 1982 { 1983 PetscStageLog stageLog; 1984 PetscEventPerfInfo *eventInfo = NULL; 1985 PetscLogDouble locTotalTime, maxMem; 1986 int numStages, numEvents, stage, event; 1987 MPI_Comm comm = PetscObjectComm((PetscObject)viewer); 1988 PetscMPIInt rank, size; 1989 1990 PetscFunctionBegin; 1991 PetscCallMPI(MPI_Comm_size(comm, &size)); 1992 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 1993 /* Must preserve reduction count before we go on */ 1994 /* Get the total elapsed time */ 1995 PetscCall(PetscTime(&locTotalTime)); 1996 locTotalTime -= petsc_BaseTime; 1997 PetscCall(PetscLogGetStageLog(&stageLog)); 1998 PetscCallMPI(MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm)); 1999 PetscCall(PetscMallocGetMaximumUsage(&maxMem)); 2000 PetscCall(PetscViewerASCIIPushSynchronized(viewer)); 2001 PetscCall(PetscViewerASCIIPrintf(viewer, "Stage Name,Event Name,Rank,Count,Time,Num Messages,Message Length,Num Reductions,FLOP,dof0,dof1,dof2,dof3,dof4,dof5,dof6,dof7,e0,e1,e2,e3,e4,e5,e6,e7,%d\n", size)); 2002 PetscCall(PetscViewerFlush(viewer)); 2003 for (stage = 0; stage < numStages; stage++) { 2004 PetscEventPerfInfo *stageInfo = &stageLog->stageInfo[stage].perfInfo; 2005 2006 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%s,summary,%d,1,%g,%g,%g,%g,%g\n", stageLog->stageInfo[stage].name, rank, stageInfo->time, stageInfo->numMessages, stageInfo->messageLength, stageInfo->numReductions, stageInfo->flops)); 2007 PetscCallMPI(MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm)); 2008 for (event = 0; event < numEvents; event++) { 2009 eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event]; 2010 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%s,%s,%d,%d,%g,%g,%g,%g,%g", stageLog->stageInfo[stage].name, stageLog->eventLog->eventInfo[event].name, rank, eventInfo->count, eventInfo->time, eventInfo->numMessages, eventInfo->messageLength, 2011 eventInfo->numReductions, eventInfo->flops)); 2012 if (eventInfo->dof[0] >= 0.) { 2013 PetscInt d, e; 2014 2015 for (d = 0; d < 8; ++d) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->dof[d])); 2016 for (e = 0; e < 8; ++e) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->errors[e])); 2017 } 2018 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "\n")); 2019 } 2020 } 2021 PetscCall(PetscViewerFlush(viewer)); 2022 PetscCall(PetscViewerASCIIPopSynchronized(viewer)); 2023 PetscFunctionReturn(PETSC_SUCCESS); 2024 } 2025 2026 static PetscErrorCode PetscLogViewWarnSync(MPI_Comm comm, FILE *fd) 2027 { 2028 PetscFunctionBegin; 2029 if (!PetscLogSyncOn) PetscFunctionReturn(PETSC_SUCCESS); 2030 PetscCall(PetscFPrintf(comm, fd, "\n\n")); 2031 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n")); 2032 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2033 PetscCall(PetscFPrintf(comm, fd, " # WARNING!!! #\n")); 2034 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2035 PetscCall(PetscFPrintf(comm, fd, " # This program was run with logging synchronization. #\n")); 2036 PetscCall(PetscFPrintf(comm, fd, " # This option provides more meaningful imbalance #\n")); 2037 PetscCall(PetscFPrintf(comm, fd, " # figures at the expense of slowing things down and #\n")); 2038 PetscCall(PetscFPrintf(comm, fd, " # providing a distorted view of the overall runtime. #\n")); 2039 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2040 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n\n\n")); 2041 PetscFunctionReturn(PETSC_SUCCESS); 2042 } 2043 2044 static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm, FILE *fd) 2045 { 2046 PetscFunctionBegin; 2047 if (PetscDefined(USE_DEBUG)) { 2048 PetscCall(PetscFPrintf(comm, fd, "\n\n")); 2049 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n")); 2050 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2051 PetscCall(PetscFPrintf(comm, fd, " # WARNING!!! #\n")); 2052 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2053 PetscCall(PetscFPrintf(comm, fd, " # This code was compiled with a debugging option. #\n")); 2054 PetscCall(PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n")); 2055 PetscCall(PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n")); 2056 PetscCall(PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n")); 2057 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2058 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n\n\n")); 2059 } 2060 PetscFunctionReturn(PETSC_SUCCESS); 2061 } 2062 2063 static PetscErrorCode PetscLogViewWarnNoGpuAwareMpi(MPI_Comm comm, FILE *fd) 2064 { 2065 #if defined(PETSC_HAVE_DEVICE) 2066 PetscMPIInt size; 2067 PetscBool deviceInitialized = PETSC_FALSE; 2068 2069 PetscFunctionBegin; 2070 PetscCallMPI(MPI_Comm_size(comm, &size)); 2071 for (int i = PETSC_DEVICE_HOST + 1; i < PETSC_DEVICE_MAX; ++i) { 2072 const PetscDeviceType dtype = PetscDeviceTypeCast(i); 2073 if (PetscDeviceInitialized(dtype)) { /* a non-host device was initialized */ 2074 deviceInitialized = PETSC_TRUE; 2075 break; 2076 } 2077 } 2078 /* the last condition says petsc is configured with device but it is a pure CPU run, so don't print misleading warnings */ 2079 if (use_gpu_aware_mpi || size == 1 || !deviceInitialized) PetscFunctionReturn(PETSC_SUCCESS); 2080 PetscCall(PetscFPrintf(comm, fd, "\n\n")); 2081 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n")); 2082 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2083 PetscCall(PetscFPrintf(comm, fd, " # WARNING!!! #\n")); 2084 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2085 PetscCall(PetscFPrintf(comm, fd, " # This code was compiled with GPU support and you've #\n")); 2086 PetscCall(PetscFPrintf(comm, fd, " # created PETSc/GPU objects, but you intentionally #\n")); 2087 PetscCall(PetscFPrintf(comm, fd, " # used -use_gpu_aware_mpi 0, requiring PETSc to copy #\n")); 2088 PetscCall(PetscFPrintf(comm, fd, " # additional data between the GPU and CPU. To obtain #\n")); 2089 PetscCall(PetscFPrintf(comm, fd, " # meaningful timing results on multi-rank runs, use #\n")); 2090 PetscCall(PetscFPrintf(comm, fd, " # GPU-aware MPI instead. #\n")); 2091 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2092 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n\n\n")); 2093 PetscFunctionReturn(PETSC_SUCCESS); 2094 #else 2095 (void)comm; 2096 (void)fd; 2097 return PETSC_SUCCESS; 2098 #endif 2099 } 2100 2101 static PetscErrorCode PetscLogViewWarnGpuTime(MPI_Comm comm, FILE *fd) 2102 { 2103 #if defined(PETSC_HAVE_DEVICE) 2104 PetscFunctionBegin; 2105 if (!PetscLogGpuTimeFlag || petsc_gflops == 0) PetscFunctionReturn(PETSC_SUCCESS); 2106 PetscCall(PetscFPrintf(comm, fd, "\n\n")); 2107 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n")); 2108 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2109 PetscCall(PetscFPrintf(comm, fd, " # WARNING!!! #\n")); 2110 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2111 PetscCall(PetscFPrintf(comm, fd, " # This code was run with -log_view_gpu_time #\n")); 2112 PetscCall(PetscFPrintf(comm, fd, " # This provides accurate timing within the GPU kernels #\n")); 2113 PetscCall(PetscFPrintf(comm, fd, " # but can slow down the entire computation by a #\n")); 2114 PetscCall(PetscFPrintf(comm, fd, " # measurable amount. For fastest runs we recommend #\n")); 2115 PetscCall(PetscFPrintf(comm, fd, " # not using this option. #\n")); 2116 PetscCall(PetscFPrintf(comm, fd, " # #\n")); 2117 PetscCall(PetscFPrintf(comm, fd, " ##########################################################\n\n\n")); 2118 PetscFunctionReturn(PETSC_SUCCESS); 2119 #else 2120 (void)comm; 2121 (void)fd; 2122 return PETSC_SUCCESS; 2123 #endif 2124 } 2125 2126 static PetscErrorCode PetscLogView_Default(PetscViewer viewer) 2127 { 2128 FILE *fd; 2129 PetscLogDouble zero = 0.0; 2130 PetscStageLog stageLog; 2131 PetscStageInfo *stageInfo = NULL; 2132 PetscEventPerfInfo *eventInfo = NULL; 2133 PetscClassPerfInfo *classInfo; 2134 char arch[128], hostname[128], username[128], pname[PETSC_MAX_PATH_LEN], date[128]; 2135 const char *name; 2136 PetscLogDouble locTotalTime, TotalTime, TotalFlops; 2137 PetscLogDouble numMessages, messageLength, avgMessLen, numReductions; 2138 PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red; 2139 PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed; 2140 PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed; 2141 PetscLogDouble min, max, tot, ratio, avg, x, y; 2142 PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratC, totm, totml, totr, mal, malmax, emalmax; 2143 #if defined(PETSC_HAVE_DEVICE) 2144 PetscLogEvent KSP_Solve, SNES_Solve, TS_Step, TAO_Solve; /* These need to be fixed to be some events registered with certain objects */ 2145 PetscLogDouble cct, gct, csz, gsz, gmaxt, gflops, gflopr, fracgflops; 2146 #endif 2147 PetscMPIInt minC, maxC; 2148 PetscMPIInt size, rank; 2149 PetscBool *localStageUsed, *stageUsed; 2150 PetscBool *localStageVisible, *stageVisible; 2151 int numStages, localNumEvents, numEvents; 2152 int stage, oclass; 2153 PetscLogEvent event; 2154 char version[256]; 2155 MPI_Comm comm; 2156 #if defined(PETSC_HAVE_DEVICE) 2157 PetscLogEvent eventid; 2158 PetscInt64 nas = 0x7FF0000000000002; 2159 #endif 2160 2161 PetscFunctionBegin; 2162 PetscCall(PetscFPTrapPush(PETSC_FP_TRAP_OFF)); 2163 PetscCall(PetscObjectGetComm((PetscObject)viewer, &comm)); 2164 PetscCall(PetscViewerASCIIGetPointer(viewer, &fd)); 2165 PetscCallMPI(MPI_Comm_size(comm, &size)); 2166 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 2167 /* Get the total elapsed time */ 2168 PetscCall(PetscTime(&locTotalTime)); 2169 locTotalTime -= petsc_BaseTime; 2170 2171 PetscCall(PetscFPrintf(comm, fd, "****************************************************************************************************************************************************************\n")); 2172 PetscCall(PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 160 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n")); 2173 PetscCall(PetscFPrintf(comm, fd, "****************************************************************************************************************************************************************\n")); 2174 PetscCall(PetscFPrintf(comm, fd, "\n------------------------------------------------------------------ PETSc Performance Summary: ------------------------------------------------------------------\n\n")); 2175 PetscCall(PetscLogViewWarnSync(comm, fd)); 2176 PetscCall(PetscLogViewWarnDebugging(comm, fd)); 2177 PetscCall(PetscLogViewWarnNoGpuAwareMpi(comm, fd)); 2178 PetscCall(PetscLogViewWarnGpuTime(comm, fd)); 2179 PetscCall(PetscGetArchType(arch, sizeof(arch))); 2180 PetscCall(PetscGetHostName(hostname, sizeof(hostname))); 2181 PetscCall(PetscGetUserName(username, sizeof(username))); 2182 PetscCall(PetscGetProgramName(pname, sizeof(pname))); 2183 PetscCall(PetscGetDate(date, sizeof(date))); 2184 PetscCall(PetscGetVersion(version, sizeof(version))); 2185 if (size == 1) { 2186 PetscCall(PetscFPrintf(comm, fd, "%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date)); 2187 } else { 2188 PetscCall(PetscFPrintf(comm, fd, "%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date)); 2189 } 2190 #if defined(PETSC_HAVE_OPENMP) 2191 PetscCall(PetscFPrintf(comm, fd, "Using %" PetscInt_FMT " OpenMP threads\n", PetscNumOMPThreads)); 2192 #endif 2193 PetscCall(PetscFPrintf(comm, fd, "Using %s\n", version)); 2194 2195 /* Must preserve reduction count before we go on */ 2196 red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 2197 2198 /* Calculate summary information */ 2199 PetscCall(PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total\n")); 2200 /* Time */ 2201 PetscCall(MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2202 PetscCall(MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2203 PetscCall(MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2204 avg = tot / ((PetscLogDouble)size); 2205 if (min != 0.0) ratio = max / min; 2206 else ratio = 0.0; 2207 PetscCall(PetscFPrintf(comm, fd, "Time (sec): %5.3e %7.3f %5.3e\n", max, ratio, avg)); 2208 TotalTime = tot; 2209 /* Objects */ 2210 avg = (PetscLogDouble)petsc_numObjects; 2211 PetscCall(MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2212 PetscCall(MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2213 PetscCall(MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2214 avg = tot / ((PetscLogDouble)size); 2215 if (min != 0.0) ratio = max / min; 2216 else ratio = 0.0; 2217 PetscCall(PetscFPrintf(comm, fd, "Objects: %5.3e %7.3f %5.3e\n", max, ratio, avg)); 2218 /* Flops */ 2219 PetscCall(MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2220 PetscCall(MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2221 PetscCall(MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2222 avg = tot / ((PetscLogDouble)size); 2223 if (min != 0.0) ratio = max / min; 2224 else ratio = 0.0; 2225 PetscCall(PetscFPrintf(comm, fd, "Flops: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 2226 TotalFlops = tot; 2227 /* Flops/sec -- Must talk to Barry here */ 2228 if (locTotalTime != 0.0) flops = petsc_TotalFlops / locTotalTime; 2229 else flops = 0.0; 2230 PetscCall(MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2231 PetscCall(MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2232 PetscCall(MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2233 avg = tot / ((PetscLogDouble)size); 2234 if (min != 0.0) ratio = max / min; 2235 else ratio = 0.0; 2236 PetscCall(PetscFPrintf(comm, fd, "Flops/sec: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 2237 /* Memory */ 2238 PetscCall(PetscMallocGetMaximumUsage(&mem)); 2239 if (mem > 0.0) { 2240 PetscCall(MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2241 PetscCall(MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2242 PetscCall(MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2243 avg = tot / ((PetscLogDouble)size); 2244 if (min != 0.0) ratio = max / min; 2245 else ratio = 0.0; 2246 PetscCall(PetscFPrintf(comm, fd, "Memory (bytes): %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 2247 } 2248 /* Messages */ 2249 mess = 0.5 * (petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct); 2250 PetscCall(MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2251 PetscCall(MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2252 PetscCall(MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2253 avg = tot / ((PetscLogDouble)size); 2254 if (min != 0.0) ratio = max / min; 2255 else ratio = 0.0; 2256 PetscCall(PetscFPrintf(comm, fd, "MPI Msg Count: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 2257 numMessages = tot; 2258 /* Message Lengths */ 2259 mess = 0.5 * (petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len); 2260 PetscCall(MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2261 PetscCall(MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2262 PetscCall(MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2263 if (numMessages != 0) avg = tot / numMessages; 2264 else avg = 0.0; 2265 if (min != 0.0) ratio = max / min; 2266 else ratio = 0.0; 2267 PetscCall(PetscFPrintf(comm, fd, "MPI Msg Len (bytes): %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 2268 messageLength = tot; 2269 /* Reductions */ 2270 PetscCall(MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2271 PetscCall(MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2272 PetscCall(MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2273 if (min != 0.0) ratio = max / min; 2274 else ratio = 0.0; 2275 PetscCall(PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %7.3f\n", max, ratio)); 2276 numReductions = red; /* wrong because uses count from process zero */ 2277 PetscCall(PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n")); 2278 PetscCall(PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flops\n")); 2279 PetscCall(PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flops\n")); 2280 2281 /* Get total number of stages -- 2282 Currently, a single processor can register more stages than another, but stages must all be registered in order. 2283 We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID. 2284 This seems best accomplished by assoicating a communicator with each stage. 2285 */ 2286 PetscCall(PetscLogGetStageLog(&stageLog)); 2287 PetscCallMPI(MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm)); 2288 PetscCall(PetscMalloc1(numStages, &localStageUsed)); 2289 PetscCall(PetscMalloc1(numStages, &stageUsed)); 2290 PetscCall(PetscMalloc1(numStages, &localStageVisible)); 2291 PetscCall(PetscMalloc1(numStages, &stageVisible)); 2292 if (numStages > 0) { 2293 stageInfo = stageLog->stageInfo; 2294 for (stage = 0; stage < numStages; stage++) { 2295 if (stage < stageLog->numStages) { 2296 localStageUsed[stage] = stageInfo[stage].used; 2297 localStageVisible[stage] = stageInfo[stage].perfInfo.visible; 2298 } else { 2299 localStageUsed[stage] = PETSC_FALSE; 2300 localStageVisible[stage] = PETSC_TRUE; 2301 } 2302 } 2303 PetscCall(MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm)); 2304 PetscCall(MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm)); 2305 for (stage = 0; stage < numStages; stage++) { 2306 if (stageUsed[stage]) { 2307 PetscCall(PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ------ --- Messages --- -- Message Lengths -- -- Reductions --\n")); 2308 PetscCall(PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total Count %%Total Avg %%Total Count %%Total\n")); 2309 break; 2310 } 2311 } 2312 for (stage = 0; stage < numStages; stage++) { 2313 if (!stageUsed[stage]) continue; 2314 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 2315 if (localStageUsed[stage]) { 2316 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2317 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2318 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2319 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2320 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2321 name = stageInfo[stage].name; 2322 } else { 2323 PetscCall(MPIU_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2324 PetscCall(MPIU_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2325 PetscCall(MPIU_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2326 PetscCall(MPIU_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2327 PetscCall(MPIU_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2328 name = ""; 2329 } 2330 mess *= 0.5; 2331 messLen *= 0.5; 2332 red /= size; 2333 if (TotalTime != 0.0) fracTime = stageTime / TotalTime; 2334 else fracTime = 0.0; 2335 if (TotalFlops != 0.0) fracFlops = flops / TotalFlops; 2336 else fracFlops = 0.0; 2337 /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */ 2338 if (numMessages != 0.0) fracMessages = mess / numMessages; 2339 else fracMessages = 0.0; 2340 if (mess != 0.0) avgMessLen = messLen / mess; 2341 else avgMessLen = 0.0; 2342 if (messageLength != 0.0) fracLength = messLen / messageLength; 2343 else fracLength = 0.0; 2344 if (numReductions != 0.0) fracReductions = red / numReductions; 2345 else fracReductions = 0.0; 2346 PetscCall(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", stage, name, stageTime / size, 100.0 * fracTime, flops, 100.0 * fracFlops, mess, 100.0 * fracMessages, avgMessLen, 100.0 * fracLength, red, 100.0 * fracReductions)); 2347 } 2348 } 2349 2350 PetscCall(PetscFPrintf(comm, fd, "\n------------------------------------------------------------------------------------------------------------------------\n")); 2351 PetscCall(PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n")); 2352 PetscCall(PetscFPrintf(comm, fd, "Phase summary info:\n")); 2353 PetscCall(PetscFPrintf(comm, fd, " Count: number of times phase was executed\n")); 2354 PetscCall(PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n")); 2355 PetscCall(PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n")); 2356 PetscCall(PetscFPrintf(comm, fd, " Mess: number of messages sent\n")); 2357 PetscCall(PetscFPrintf(comm, fd, " AvgLen: average message length (bytes)\n")); 2358 PetscCall(PetscFPrintf(comm, fd, " Reduct: number of global reductions\n")); 2359 PetscCall(PetscFPrintf(comm, fd, " Global: entire computation\n")); 2360 PetscCall(PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n")); 2361 PetscCall(PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n")); 2362 PetscCall(PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n")); 2363 PetscCall(PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n")); 2364 PetscCall(PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n")); 2365 if (PetscLogMemory) { 2366 PetscCall(PetscFPrintf(comm, fd, " Memory usage is summed over all MPI processes, it is given in mega-bytes\n")); 2367 PetscCall(PetscFPrintf(comm, fd, " Malloc Mbytes: Memory allocated and kept during event (sum over all calls to event). May be negative\n")); 2368 PetscCall(PetscFPrintf(comm, fd, " EMalloc Mbytes: extra memory allocated during event and then freed (maximum over all calls to events). Never negative\n")); 2369 PetscCall(PetscFPrintf(comm, fd, " MMalloc Mbytes: Increase in high water mark of allocated memory (sum over all calls to event). Never negative\n")); 2370 PetscCall(PetscFPrintf(comm, fd, " RMI Mbytes: Increase in resident memory (sum over all calls to event)\n")); 2371 } 2372 #if defined(PETSC_HAVE_DEVICE) 2373 PetscCall(PetscFPrintf(comm, fd, " GPU Mflop/s: 10e-6 * (sum of flop on GPU over all processors)/(max GPU time over all processors)\n")); 2374 PetscCall(PetscFPrintf(comm, fd, " CpuToGpu Count: total number of CPU to GPU copies per processor\n")); 2375 PetscCall(PetscFPrintf(comm, fd, " CpuToGpu Size (Mbytes): 10e-6 * (total size of CPU to GPU copies per processor)\n")); 2376 PetscCall(PetscFPrintf(comm, fd, " GpuToCpu Count: total number of GPU to CPU copies per processor\n")); 2377 PetscCall(PetscFPrintf(comm, fd, " GpuToCpu Size (Mbytes): 10e-6 * (total size of GPU to CPU copies per processor)\n")); 2378 PetscCall(PetscFPrintf(comm, fd, " GPU %%F: percent flops on GPU in this event\n")); 2379 #endif 2380 PetscCall(PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n")); 2381 2382 PetscCall(PetscLogViewWarnDebugging(comm, fd)); 2383 2384 /* Report events */ 2385 PetscCall(PetscFPrintf(comm, fd, "Event Count Time (sec) Flop --- Global --- --- Stage ---- Total")); 2386 if (PetscLogMemory) PetscCall(PetscFPrintf(comm, fd, " Malloc EMalloc MMalloc RMI")); 2387 #if defined(PETSC_HAVE_DEVICE) 2388 PetscCall(PetscFPrintf(comm, fd, " GPU - CpuToGpu - - GpuToCpu - GPU")); 2389 #endif 2390 PetscCall(PetscFPrintf(comm, fd, "\n")); 2391 PetscCall(PetscFPrintf(comm, fd, " Max Ratio Max Ratio Max Ratio Mess AvgLen Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s")); 2392 if (PetscLogMemory) PetscCall(PetscFPrintf(comm, fd, " Mbytes Mbytes Mbytes Mbytes")); 2393 #if defined(PETSC_HAVE_DEVICE) 2394 PetscCall(PetscFPrintf(comm, fd, " Mflop/s Count Size Count Size %%F")); 2395 #endif 2396 PetscCall(PetscFPrintf(comm, fd, "\n")); 2397 PetscCall(PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------")); 2398 if (PetscLogMemory) PetscCall(PetscFPrintf(comm, fd, "-----------------------------")); 2399 #if defined(PETSC_HAVE_DEVICE) 2400 PetscCall(PetscFPrintf(comm, fd, "---------------------------------------")); 2401 #endif 2402 PetscCall(PetscFPrintf(comm, fd, "\n")); 2403 2404 #if defined(PETSC_HAVE_DEVICE) 2405 /* this indirect way of accessing these values is needed when PETSc is build with multiple libraries since the symbols are not in libpetscsys */ 2406 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, "TAOSolve", &TAO_Solve)); 2407 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, "TSStep", &TS_Step)); 2408 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, "SNESSolve", &SNES_Solve)); 2409 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, "KSPSolve", &KSP_Solve)); 2410 #endif 2411 2412 /* Problem: The stage name will not show up unless the stage executed on proc 1 */ 2413 for (stage = 0; stage < numStages; stage++) { 2414 if (!stageVisible[stage]) continue; 2415 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 2416 if (localStageUsed[stage]) { 2417 PetscCall(PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name)); 2418 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2419 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2420 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2421 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2422 PetscCall(MPIU_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2423 } else { 2424 PetscCall(PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage)); 2425 PetscCall(MPIU_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2426 PetscCall(MPIU_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2427 PetscCall(MPIU_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2428 PetscCall(MPIU_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2429 PetscCall(MPIU_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2430 } 2431 mess *= 0.5; 2432 messLen *= 0.5; 2433 red /= size; 2434 2435 /* Get total number of events in this stage -- 2436 Currently, a single processor can register more events than another, but events must all be registered in order, 2437 just like stages. We can removed this requirement if necessary by having a global event numbering and indirection 2438 on the event ID. This seems best accomplished by associating a communicator with each stage. 2439 2440 Problem: If the event did not happen on proc 1, its name will not be available. 2441 Problem: Event visibility is not implemented 2442 */ 2443 if (localStageUsed[stage]) { 2444 eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo; 2445 localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents; 2446 } else localNumEvents = 0; 2447 PetscCallMPI(MPI_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm)); 2448 for (event = 0; event < numEvents; event++) { 2449 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 2450 if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) { 2451 if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; 2452 else flopr = 0.0; 2453 PetscCall(MPIU_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2454 PetscCall(MPIU_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2455 PetscCall(MPIU_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2456 PetscCall(MPIU_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2457 PetscCall(MPIU_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2458 PetscCall(MPIU_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2459 PetscCall(MPIU_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2460 PetscCall(MPIU_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2461 PetscCall(MPIU_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2462 PetscCallMPI(MPI_Allreduce(&eventInfo[event].count, &minC, 1, MPI_INT, MPI_MIN, comm)); 2463 PetscCallMPI(MPI_Allreduce(&eventInfo[event].count, &maxC, 1, MPI_INT, MPI_MAX, comm)); 2464 if (PetscLogMemory) { 2465 PetscCall(MPIU_Allreduce(&eventInfo[event].memIncrease, &mem, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2466 PetscCall(MPIU_Allreduce(&eventInfo[event].mallocSpace, &mal, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2467 PetscCall(MPIU_Allreduce(&eventInfo[event].mallocIncrease, &malmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2468 PetscCall(MPIU_Allreduce(&eventInfo[event].mallocIncreaseEvent, &emalmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2469 } 2470 #if defined(PETSC_HAVE_DEVICE) 2471 PetscCall(MPIU_Allreduce(&eventInfo[event].CpuToGpuCount, &cct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2472 PetscCall(MPIU_Allreduce(&eventInfo[event].GpuToCpuCount, &gct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2473 PetscCall(MPIU_Allreduce(&eventInfo[event].CpuToGpuSize, &csz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2474 PetscCall(MPIU_Allreduce(&eventInfo[event].GpuToCpuSize, &gsz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2475 PetscCall(MPIU_Allreduce(&eventInfo[event].GpuFlops, &gflops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2476 PetscCall(MPIU_Allreduce(&eventInfo[event].GpuTime, &gmaxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2477 #endif 2478 name = stageLog->eventLog->eventInfo[event].name; 2479 } else { 2480 int ierr = 0; 2481 2482 flopr = 0.0; 2483 PetscCall(MPIU_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2484 PetscCall(MPIU_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2485 PetscCall(MPIU_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2486 PetscCall(MPIU_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 2487 PetscCall(MPIU_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2488 PetscCall(MPIU_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2489 PetscCall(MPIU_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2490 PetscCall(MPIU_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2491 PetscCall(MPIU_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2492 PetscCallMPI(MPI_Allreduce(&ierr, &minC, 1, MPI_INT, MPI_MIN, comm)); 2493 PetscCallMPI(MPI_Allreduce(&ierr, &maxC, 1, MPI_INT, MPI_MAX, comm)); 2494 if (PetscLogMemory) { 2495 PetscCall(MPIU_Allreduce(&zero, &mem, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2496 PetscCall(MPIU_Allreduce(&zero, &mal, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2497 PetscCall(MPIU_Allreduce(&zero, &malmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2498 PetscCall(MPIU_Allreduce(&zero, &emalmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2499 } 2500 #if defined(PETSC_HAVE_DEVICE) 2501 PetscCall(MPIU_Allreduce(&zero, &cct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2502 PetscCall(MPIU_Allreduce(&zero, &gct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2503 PetscCall(MPIU_Allreduce(&zero, &csz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2504 PetscCall(MPIU_Allreduce(&zero, &gsz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2505 PetscCall(MPIU_Allreduce(&zero, &gflops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 2506 PetscCall(MPIU_Allreduce(&zero, &gmaxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 2507 #endif 2508 name = ""; 2509 } 2510 if (mint < 0.0) { 2511 PetscCall(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)); 2512 mint = 0; 2513 } 2514 PetscCheck(minf >= 0.0, PETSC_COMM_SELF, PETSC_ERR_PLIB, "Minimum flop %g over all processors for %s is negative! Not possible!", minf, name); 2515 /* Put NaN into the time for all events that may not be time accurately since they may happen asynchronously on the GPU */ 2516 #if defined(PETSC_HAVE_DEVICE) 2517 if (!PetscLogGpuTimeFlag && petsc_gflops > 0) { 2518 memcpy(&gmaxt, &nas, sizeof(PetscLogDouble)); 2519 PetscCall(PetscEventRegLogGetEvent(stageLog->eventLog, name, &eventid)); 2520 if (eventid != SNES_Solve && eventid != KSP_Solve && eventid != TS_Step && eventid != TAO_Solve) { 2521 memcpy(&mint, &nas, sizeof(PetscLogDouble)); 2522 memcpy(&maxt, &nas, sizeof(PetscLogDouble)); 2523 } 2524 } 2525 #endif 2526 totm *= 0.5; 2527 totml *= 0.5; 2528 totr /= size; 2529 2530 if (maxC != 0) { 2531 if (minC != 0) ratC = ((PetscLogDouble)maxC) / minC; 2532 else ratC = 0.0; 2533 if (mint != 0.0) ratt = maxt / mint; 2534 else ratt = 0.0; 2535 if (minf != 0.0) ratf = maxf / minf; 2536 else ratf = 0.0; 2537 if (TotalTime != 0.0) fracTime = tott / TotalTime; 2538 else fracTime = 0.0; 2539 if (TotalFlops != 0.0) fracFlops = totf / TotalFlops; 2540 else fracFlops = 0.0; 2541 if (stageTime != 0.0) fracStageTime = tott / stageTime; 2542 else fracStageTime = 0.0; 2543 if (flops != 0.0) fracStageFlops = totf / flops; 2544 else fracStageFlops = 0.0; 2545 if (numMessages != 0.0) fracMess = totm / numMessages; 2546 else fracMess = 0.0; 2547 if (messageLength != 0.0) fracMessLen = totml / messageLength; 2548 else fracMessLen = 0.0; 2549 if (numReductions != 0.0) fracRed = totr / numReductions; 2550 else fracRed = 0.0; 2551 if (mess != 0.0) fracStageMess = totm / mess; 2552 else fracStageMess = 0.0; 2553 if (messLen != 0.0) fracStageMessLen = totml / messLen; 2554 else fracStageMessLen = 0.0; 2555 if (red != 0.0) fracStageRed = totr / red; 2556 else fracStageRed = 0.0; 2557 if (totm != 0.0) totml /= totm; 2558 else totml = 0.0; 2559 if (maxt != 0.0) flopr = totf / maxt; 2560 else flopr = 0.0; 2561 if (fracStageTime > 1.0 || fracStageFlops > 1.0 || fracStageMess > 1.0 || fracStageMessLen > 1.0 || fracStageRed > 1.0) 2562 PetscCall(PetscFPrintf(comm, fd, "%-16s %7d %3.1f %5.4e %3.1f %3.2e %3.1f %2.1e %2.1e %2.1e %2.0f %2.0f %2.0f %2.0f %2.0f Multiple stages %5.0f", name, maxC, ratC, maxt, ratt, maxf, ratf, totm, totml, totr, 100.0 * fracTime, 100.0 * fracFlops, 100.0 * fracMess, 100.0 * fracMessLen, 100.0 * fracRed, PetscAbs(flopr) / 1.0e6)); 2563 else 2564 PetscCall(PetscFPrintf(comm, fd, "%-16s %7d %3.1f %5.4e %3.1f %3.2e %3.1f %2.1e %2.1e %2.1e %2.0f %2.0f %2.0f %2.0f %2.0f %3.0f %2.0f %2.0f %2.0f %2.0f %5.0f", name, maxC, ratC, maxt, ratt, maxf, ratf, totm, totml, totr, 100.0 * fracTime, 100.0 * fracFlops, 100.0 * fracMess, 100.0 * fracMessLen, 100.0 * fracRed, 100.0 * fracStageTime, 100.0 * fracStageFlops, 100.0 * fracStageMess, 100.0 * fracStageMessLen, 100.0 * fracStageRed, PetscAbs(flopr) / 1.0e6)); 2565 if (PetscLogMemory) PetscCall(PetscFPrintf(comm, fd, " %5.0f %5.0f %5.0f %5.0f", mal / 1.0e6, emalmax / 1.0e6, malmax / 1.0e6, mem / 1.0e6)); 2566 #if defined(PETSC_HAVE_DEVICE) 2567 if (totf != 0.0) fracgflops = gflops / totf; 2568 else fracgflops = 0.0; 2569 if (gmaxt != 0.0) gflopr = gflops / gmaxt; 2570 else gflopr = 0.0; 2571 PetscCall(PetscFPrintf(comm, fd, " %5.0f %4.0f %3.2e %4.0f %3.2e % 2.0f", PetscAbs(gflopr) / 1.0e6, cct / size, csz / (1.0e6 * size), gct / size, gsz / (1.0e6 * size), 100.0 * fracgflops)); 2572 #endif 2573 PetscCall(PetscFPrintf(comm, fd, "\n")); 2574 } 2575 } 2576 } 2577 2578 /* Memory usage and object creation */ 2579 PetscCall(PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------")); 2580 if (PetscLogMemory) PetscCall(PetscFPrintf(comm, fd, "-----------------------------")); 2581 #if defined(PETSC_HAVE_DEVICE) 2582 PetscCall(PetscFPrintf(comm, fd, "---------------------------------------")); 2583 #endif 2584 PetscCall(PetscFPrintf(comm, fd, "\n")); 2585 PetscCall(PetscFPrintf(comm, fd, "\n")); 2586 2587 /* Right now, only stages on the first processor are reported here, meaning only objects associated with 2588 the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then 2589 stats for stages local to processor sets. 2590 */ 2591 /* We should figure out the longest object name here (now 20 characters) */ 2592 PetscCall(PetscFPrintf(comm, fd, "Object Type Creations Destructions. Reports information only for process 0.\n")); 2593 for (stage = 0; stage < numStages; stage++) { 2594 if (localStageUsed[stage]) { 2595 classInfo = stageLog->stageInfo[stage].classLog->classInfo; 2596 PetscCall(PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name)); 2597 for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) { 2598 if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) { 2599 PetscCall(PetscFPrintf(comm, fd, "%20s %5d %5d\n", stageLog->classLog->classInfo[oclass].name, classInfo[oclass].creations, classInfo[oclass].destructions)); 2600 } 2601 } 2602 } else { 2603 if (!localStageVisible[stage]) continue; 2604 PetscCall(PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage)); 2605 } 2606 } 2607 2608 PetscCall(PetscFree(localStageUsed)); 2609 PetscCall(PetscFree(stageUsed)); 2610 PetscCall(PetscFree(localStageVisible)); 2611 PetscCall(PetscFree(stageVisible)); 2612 2613 /* Information unrelated to this particular run */ 2614 PetscCall(PetscFPrintf(comm, fd, "========================================================================================================================\n")); 2615 PetscCall(PetscTime(&y)); 2616 PetscCall(PetscTime(&x)); 2617 PetscCall(PetscTime(&y)); 2618 PetscCall(PetscTime(&y)); 2619 PetscCall(PetscTime(&y)); 2620 PetscCall(PetscTime(&y)); 2621 PetscCall(PetscTime(&y)); 2622 PetscCall(PetscTime(&y)); 2623 PetscCall(PetscTime(&y)); 2624 PetscCall(PetscTime(&y)); 2625 PetscCall(PetscTime(&y)); 2626 PetscCall(PetscTime(&y)); 2627 PetscCall(PetscFPrintf(comm, fd, "Average time to get PetscTime(): %g\n", (y - x) / 10.0)); 2628 /* MPI information */ 2629 if (size > 1) { 2630 MPI_Status status; 2631 PetscMPIInt tag; 2632 MPI_Comm newcomm; 2633 2634 PetscCallMPI(MPI_Barrier(comm)); 2635 PetscCall(PetscTime(&x)); 2636 PetscCallMPI(MPI_Barrier(comm)); 2637 PetscCallMPI(MPI_Barrier(comm)); 2638 PetscCallMPI(MPI_Barrier(comm)); 2639 PetscCallMPI(MPI_Barrier(comm)); 2640 PetscCallMPI(MPI_Barrier(comm)); 2641 PetscCall(PetscTime(&y)); 2642 PetscCall(PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y - x) / 5.0)); 2643 PetscCall(PetscCommDuplicate(comm, &newcomm, &tag)); 2644 PetscCallMPI(MPI_Barrier(comm)); 2645 if (rank) { 2646 PetscCallMPI(MPI_Recv(NULL, 0, MPI_INT, rank - 1, tag, newcomm, &status)); 2647 PetscCallMPI(MPI_Send(NULL, 0, MPI_INT, (rank + 1) % size, tag, newcomm)); 2648 } else { 2649 PetscCall(PetscTime(&x)); 2650 PetscCallMPI(MPI_Send(NULL, 0, MPI_INT, 1, tag, newcomm)); 2651 PetscCallMPI(MPI_Recv(NULL, 0, MPI_INT, size - 1, tag, newcomm, &status)); 2652 PetscCall(PetscTime(&y)); 2653 PetscCall(PetscFPrintf(comm, fd, "Average time for zero size MPI_Send(): %g\n", (y - x) / size)); 2654 } 2655 PetscCall(PetscCommDestroy(&newcomm)); 2656 } 2657 PetscCall(PetscOptionsView(NULL, viewer)); 2658 2659 /* Machine and compile information */ 2660 #if defined(PETSC_USE_FORTRAN_KERNELS) 2661 PetscCall(PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n")); 2662 #else 2663 PetscCall(PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n")); 2664 #endif 2665 #if defined(PETSC_USE_64BIT_INDICES) 2666 PetscCall(PetscFPrintf(comm, fd, "Compiled with 64-bit PetscInt\n")); 2667 #elif defined(PETSC_USE___FLOAT128) 2668 PetscCall(PetscFPrintf(comm, fd, "Compiled with 32-bit PetscInt\n")); 2669 #endif 2670 #if defined(PETSC_USE_REAL_SINGLE) 2671 PetscCall(PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n")); 2672 #elif defined(PETSC_USE___FLOAT128) 2673 PetscCall(PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n")); 2674 #endif 2675 #if defined(PETSC_USE_REAL_MAT_SINGLE) 2676 PetscCall(PetscFPrintf(comm, fd, "Compiled with single precision matrices\n")); 2677 #else 2678 PetscCall(PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n")); 2679 #endif 2680 PetscCall(PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n", (int)sizeof(short), (int)sizeof(int), (int)sizeof(long), (int)sizeof(void *), (int)sizeof(PetscScalar), (int)sizeof(PetscInt))); 2681 2682 PetscCall(PetscFPrintf(comm, fd, "Configure options: %s", petscconfigureoptions)); 2683 PetscCall(PetscFPrintf(comm, fd, "%s", petscmachineinfo)); 2684 PetscCall(PetscFPrintf(comm, fd, "%s", petsccompilerinfo)); 2685 PetscCall(PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo)); 2686 PetscCall(PetscFPrintf(comm, fd, "%s", petsclinkerinfo)); 2687 2688 /* Cleanup */ 2689 PetscCall(PetscFPrintf(comm, fd, "\n")); 2690 PetscCall(PetscLogViewWarnNoGpuAwareMpi(comm, fd)); 2691 PetscCall(PetscLogViewWarnDebugging(comm, fd)); 2692 PetscCall(PetscFPTrapPop()); 2693 PetscFunctionReturn(PETSC_SUCCESS); 2694 } 2695 2696 /*@C 2697 PetscLogView - Prints a summary of the logging. 2698 2699 Collective over MPI_Comm 2700 2701 Input Parameter: 2702 . viewer - an ASCII viewer 2703 2704 Options Database Keys: 2705 + -log_view [:filename] - Prints summary of log information 2706 . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file 2707 . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it) 2708 . -log_view :filename.txt:ascii_flamegraph - Saves logging information in a format suitable for visualising as a Flame Graph (see below for how to view it) 2709 . -log_view_memory - Also display memory usage in each event 2710 . -log_view_gpu_time - Also display time in each event for GPU kernels (Note this may slow the computation) 2711 . -log_all - Saves a file Log.rank for each MPI rank with details of each step of the computation 2712 - -log_trace [filename] - Displays a trace of what each process is doing 2713 2714 Level: beginner 2715 2716 Notes: 2717 It is possible to control the logging programmatically but we recommend using the options database approach whenever possible 2718 By default the summary is printed to stdout. 2719 2720 Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin() 2721 2722 If PETSc is configured with --with-logging=0 then this functionality is not available 2723 2724 To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current 2725 directory then open filename.xml with your browser. Specific notes for certain browsers 2726 $ Firefox and Internet explorer - simply open the file 2727 $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files 2728 $ Safari - see https://ccm.net/faq/36342-safari-how-to-enable-local-file-access 2729 or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with 2730 your browser. 2731 Alternatively, use the script ${PETSC_DIR}/lib/petsc/bin/petsc-performance-view to automatically open a new browser 2732 window and render the XML log file contents. 2733 2734 The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS 2735 2736 The Flame Graph output can be visualised using either the original Flame Graph script (https://github.com/brendangregg/FlameGraph) 2737 or using speedscope (https://www.speedscope.app). 2738 Old XML profiles may be converted into this format using the script ${PETSC_DIR}/lib/petsc/bin/xml2flamegraph.py. 2739 2740 .seealso: [](ch_profiling), `PetscLogDefaultBegin()`, `PetscLogDump()` 2741 @*/ 2742 PetscErrorCode PetscLogView(PetscViewer viewer) 2743 { 2744 PetscBool isascii; 2745 PetscViewerFormat format; 2746 int stage, lastStage; 2747 PetscStageLog stageLog; 2748 2749 PetscFunctionBegin; 2750 PetscCheck(PetscLogPLB, PETSC_COMM_SELF, PETSC_ERR_SUP, "Must use -log_view or PetscLogDefaultBegin() before calling this routine"); 2751 /* Pop off any stages the user forgot to remove */ 2752 lastStage = 0; 2753 PetscCall(PetscLogGetStageLog(&stageLog)); 2754 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 2755 while (stage >= 0) { 2756 lastStage = stage; 2757 PetscCall(PetscStageLogPop(stageLog)); 2758 PetscCall(PetscStageLogGetCurrent(stageLog, &stage)); 2759 } 2760 PetscCall(PetscObjectTypeCompare((PetscObject)viewer, PETSCVIEWERASCII, &isascii)); 2761 PetscCheck(isascii, PetscObjectComm((PetscObject)viewer), PETSC_ERR_SUP, "Currently can only view logging to ASCII"); 2762 PetscCall(PetscViewerGetFormat(viewer, &format)); 2763 if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) { 2764 PetscCall(PetscLogView_Default(viewer)); 2765 } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) { 2766 PetscCall(PetscLogView_Detailed(viewer)); 2767 } else if (format == PETSC_VIEWER_ASCII_CSV) { 2768 PetscCall(PetscLogView_CSV(viewer)); 2769 } else if (format == PETSC_VIEWER_ASCII_XML) { 2770 PetscCall(PetscLogView_Nested(viewer)); 2771 } else if (format == PETSC_VIEWER_ASCII_FLAMEGRAPH) { 2772 PetscCall(PetscLogView_Flamegraph(viewer)); 2773 } 2774 PetscCall(PetscStageLogPush(stageLog, lastStage)); 2775 PetscFunctionReturn(PETSC_SUCCESS); 2776 } 2777 2778 /*@C 2779 PetscLogViewFromOptions - Processes command line options to determine if/how a `PetscLog` is to be viewed. 2780 2781 Collective on `PETSC_COMM_WORLD` 2782 2783 Level: developer 2784 2785 .seealso: [](ch_profiling), `PetscLogView()` 2786 @*/ 2787 PetscErrorCode PetscLogViewFromOptions(void) 2788 { 2789 PetscViewer viewer; 2790 PetscBool flg; 2791 PetscViewerFormat format; 2792 2793 PetscFunctionBegin; 2794 PetscCall(PetscOptionsGetViewer(PETSC_COMM_WORLD, NULL, NULL, "-log_view", &viewer, &format, &flg)); 2795 if (flg) { 2796 PetscCall(PetscViewerPushFormat(viewer, format)); 2797 PetscCall(PetscLogView(viewer)); 2798 PetscCall(PetscViewerPopFormat(viewer)); 2799 PetscCall(PetscViewerDestroy(&viewer)); 2800 } 2801 PetscFunctionReturn(PETSC_SUCCESS); 2802 } 2803 2804 /*----------------------------------------------- Counter Functions -------------------------------------------------*/ 2805 /*@C 2806 PetscGetFlops - Returns the number of flops used on this processor 2807 since the program began. 2808 2809 Not Collective 2810 2811 Output Parameter: 2812 . flops - number of floating point operations 2813 2814 Level: intermediate 2815 2816 Notes: 2817 A global counter logs all PETSc flop counts. The user can use 2818 `PetscLogFlops()` to increment this counter to include flops for the 2819 application code. 2820 2821 A separate counter `PetscLogGPUFlops()` logs the flops that occur on any GPU associated with this MPI rank 2822 2823 .seealso: [](ch_profiling), `PetscLogGPUFlops()`, `PetscTime()`, `PetscLogFlops()` 2824 @*/ 2825 PetscErrorCode PetscGetFlops(PetscLogDouble *flops) 2826 { 2827 PetscFunctionBegin; 2828 *flops = petsc_TotalFlops; 2829 PetscFunctionReturn(PETSC_SUCCESS); 2830 } 2831 2832 /*@C 2833 PetscLogObjectState - Record information about an object with the default log handler 2834 2835 Not Collective 2836 2837 Input Parameters: 2838 + obj - the `PetscObject` 2839 . format - a printf-style format string 2840 - ... - printf arguments to format 2841 2842 Level: developer 2843 2844 .seealso: [](ch_profiling), `PetscLogObjectCreate()`, `PetscLogObjectDestroy()` 2845 @*/ 2846 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 2847 { 2848 size_t fullLength; 2849 va_list Argp; 2850 2851 PetscFunctionBegin; 2852 if (!petsc_logObjects) PetscFunctionReturn(PETSC_SUCCESS); 2853 va_start(Argp, format); 2854 PetscCall(PetscVSNPrintf(petsc_objects[obj->id].info, 64, format, &fullLength, Argp)); 2855 va_end(Argp); 2856 PetscFunctionReturn(PETSC_SUCCESS); 2857 } 2858 2859 /*MC 2860 PetscLogFlops - Adds floating point operations to the global counter. 2861 2862 Synopsis: 2863 #include <petsclog.h> 2864 PetscErrorCode PetscLogFlops(PetscLogDouble f) 2865 2866 Not Collective 2867 2868 Input Parameter: 2869 . f - flop counter 2870 2871 Example Usage: 2872 .vb 2873 PetscLogEvent USER_EVENT; 2874 2875 PetscLogEventRegister("User event", 0, &USER_EVENT); 2876 PetscLogEventBegin(USER_EVENT, 0, 0, 0, 0); 2877 [code segment to monitor] 2878 PetscLogFlops(user_flops) 2879 PetscLogEventEnd(USER_EVENT, 0, 0, 0, 0); 2880 .ve 2881 2882 Level: intermediate 2883 2884 Note: 2885 A global counter logs all PETSc flop counts. The user can use PetscLogFlops() to increment 2886 this counter to include flops for the application code. 2887 2888 .seealso: [](ch_profiling), `PetscLogGPUFlops()`, `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscGetFlops()` 2889 M*/ 2890 2891 /*MC 2892 PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice) to get accurate 2893 timings 2894 2895 Synopsis: 2896 #include <petsclog.h> 2897 void PetscPreLoadBegin(PetscBool flag, char *name); 2898 2899 Not Collective 2900 2901 Input Parameters: 2902 + flag - `PETSC_TRUE` to run twice, `PETSC_FALSE` to run once, may be overridden with command 2903 line option `-preload true|false` 2904 - name - name of first stage (lines of code timed separately with `-log_view`) to be preloaded 2905 2906 Example Usage: 2907 .vb 2908 PetscPreLoadBegin(PETSC_TRUE, "first stage"); 2909 // lines of code 2910 PetscPreLoadStage("second stage"); 2911 // lines of code 2912 PetscPreLoadEnd(); 2913 .ve 2914 2915 Level: intermediate 2916 2917 Note: 2918 Only works in C/C++, not Fortran 2919 2920 Flags available within the macro\: 2921 + PetscPreLoadingUsed - `PETSC_TRUE` if we are or have done preloading 2922 . PetscPreLoadingOn - `PETSC_TRUE` if it is CURRENTLY doing preload 2923 . PetscPreLoadIt - `0` for the first computation (with preloading turned off it is only 2924 `0`) `1` for the second 2925 - PetscPreLoadMax - number of times it will do the computation, only one when preloading is 2926 turned on 2927 2928 The first two variables are available throughout the program, the second two only between the 2929 `PetscPreLoadBegin()` and `PetscPreLoadEnd()` 2930 2931 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadEnd()`, `PetscPreLoadStage()` 2932 M*/ 2933 2934 /*MC 2935 PetscPreLoadEnd - End a segment of code that may be preloaded (run twice) to get accurate 2936 timings 2937 2938 Synopsis: 2939 #include <petsclog.h> 2940 void PetscPreLoadEnd(void); 2941 2942 Not Collective 2943 2944 Example Usage: 2945 .vb 2946 PetscPreLoadBegin(PETSC_TRUE, "first stage"); 2947 // lines of code 2948 PetscPreLoadStage("second stage"); 2949 // lines of code 2950 PetscPreLoadEnd(); 2951 .ve 2952 2953 Level: intermediate 2954 2955 Note: 2956 Only works in C/C++ not fortran 2957 2958 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadStage()` 2959 M*/ 2960 2961 /*MC 2962 PetscPreLoadStage - Start a new segment of code to be timed separately to get accurate timings 2963 2964 Synopsis: 2965 #include <petsclog.h> 2966 void PetscPreLoadStage(char *name); 2967 2968 Not Collective 2969 2970 Example Usage: 2971 .vb 2972 PetscPreLoadBegin(PETSC_TRUE,"first stage"); 2973 // lines of code 2974 PetscPreLoadStage("second stage"); 2975 // lines of code 2976 PetscPreLoadEnd(); 2977 .ve 2978 2979 Level: intermediate 2980 2981 Note: 2982 Only works in C/C++ not fortran 2983 2984 .seealso: [](ch_profiling), `PetscLogEventRegister()`, `PetscLogEventBegin()`, `PetscLogEventEnd()`, `PetscPreLoadBegin()`, `PetscPreLoadEnd()` 2985 M*/ 2986 2987 #if PetscDefined(HAVE_DEVICE) 2988 #include <petsc/private/deviceimpl.h> 2989 2990 PetscBool PetscLogGpuTimeFlag = PETSC_FALSE; 2991 2992 /* 2993 This cannot be called by users between PetscInitialize() and PetscFinalize() at any random location in the code 2994 because it will result in timing results that cannot be interpreted. 2995 */ 2996 static PetscErrorCode PetscLogGpuTime_Off(void) 2997 { 2998 PetscLogGpuTimeFlag = PETSC_FALSE; 2999 return PETSC_SUCCESS; 3000 } 3001 3002 /*@C 3003 PetscLogGpuTime - turn on the logging of GPU time for GPU kernels 3004 3005 Options Database Key: 3006 . -log_view_gpu_time - provide the GPU times in the `-log_view` output 3007 3008 Level: advanced 3009 3010 Notes: 3011 Turning on the timing of the GPU kernels can slow down the entire computation and should only 3012 be used when studying the performance of operations on GPU such as vector operations and 3013 matrix-vector operations. 3014 3015 This routine should only be called once near the beginning of the program. Once it is started 3016 it cannot be turned off. 3017 3018 .seealso: [](ch_profiling), `PetscLogView()`, `PetscLogGpuFlops()`, `PetscLogGpuTimeEnd()`, `PetscLogGpuTimeBegin()` 3019 @*/ 3020 PetscErrorCode PetscLogGpuTime(void) 3021 { 3022 if (!PetscLogGpuTimeFlag) PetscCall(PetscRegisterFinalize(PetscLogGpuTime_Off)); 3023 PetscLogGpuTimeFlag = PETSC_TRUE; 3024 return PETSC_SUCCESS; 3025 } 3026 3027 /*@C 3028 PetscLogGpuTimeBegin - Start timer for device 3029 3030 Level: intermediate 3031 3032 Notes: 3033 When CUDA or HIP is enabled, the timer is run on the GPU, it is a separate logging of time 3034 devoted to GPU computations (excluding kernel launch times). 3035 3036 When CUDA or HIP is not available, the timer is run on the CPU, it is a separate logging of 3037 time devoted to GPU computations (including kernel launch times). 3038 3039 There is no need to call WaitForCUDA() or WaitForHIP() between `PetscLogGpuTimeBegin()` and 3040 `PetscLogGpuTimeEnd()` 3041 3042 This timer should NOT include times for data transfers between the GPU and CPU, nor setup 3043 actions such as allocating space. 3044 3045 The regular logging captures the time for data transfers and any CPU activities during the 3046 event. It is used to compute the flop rate on the GPU as it is actively engaged in running a 3047 kernel. 3048 3049 Developer Notes: 3050 The GPU event timer captures the execution time of all the kernels launched in the default 3051 stream by the CPU between `PetscLogGpuTimeBegin()` and `PetsLogGpuTimeEnd()`. 3052 3053 `PetscLogGpuTimeBegin()` and `PetsLogGpuTimeEnd()` insert the begin and end events into the 3054 default stream (stream 0). The device will record a time stamp for the event when it reaches 3055 that event in the stream. The function xxxEventSynchronize() is called in 3056 `PetsLogGpuTimeEnd()` to block CPU execution, but not continued GPU execution, until the 3057 timer event is recorded. 3058 3059 .seealso: [](ch_profiling), `PetscLogView()`, `PetscLogGpuFlops()`, `PetscLogGpuTimeEnd()`, `PetscLogGpuTime()` 3060 @*/ 3061 PetscErrorCode PetscLogGpuTimeBegin(void) 3062 { 3063 PetscFunctionBegin; 3064 if (!PetscLogPLB || !PetscLogGpuTimeFlag) PetscFunctionReturn(PETSC_SUCCESS); 3065 if (PetscDefined(HAVE_DEVICE)) { 3066 PetscDeviceContext dctx; 3067 3068 PetscCall(PetscDeviceContextGetCurrentContext(&dctx)); 3069 PetscCall(PetscDeviceContextBeginTimer_Internal(dctx)); 3070 } else { 3071 PetscCall(PetscTimeSubtract(&petsc_gtime)); 3072 } 3073 PetscFunctionReturn(PETSC_SUCCESS); 3074 } 3075 3076 /*@C 3077 PetscLogGpuTimeEnd - Stop timer for device 3078 3079 Level: intermediate 3080 3081 .seealso: [](ch_profiling), `PetscLogView()`, `PetscLogGpuFlops()`, `PetscLogGpuTimeBegin()` 3082 @*/ 3083 PetscErrorCode PetscLogGpuTimeEnd(void) 3084 { 3085 PetscFunctionBegin; 3086 if (!PetscLogPLE || !PetscLogGpuTimeFlag) PetscFunctionReturn(PETSC_SUCCESS); 3087 if (PetscDefined(HAVE_DEVICE)) { 3088 PetscDeviceContext dctx; 3089 PetscLogDouble elapsed; 3090 3091 PetscCall(PetscDeviceContextGetCurrentContext(&dctx)); 3092 PetscCall(PetscDeviceContextEndTimer_Internal(dctx, &elapsed)); 3093 petsc_gtime += (elapsed / 1000.0); 3094 } else { 3095 PetscCall(PetscTimeAdd(&petsc_gtime)); 3096 } 3097 PetscFunctionReturn(PETSC_SUCCESS); 3098 } 3099 3100 #endif /* end of PETSC_HAVE_DEVICE */ 3101 3102 #else /* end of -DPETSC_USE_LOG section */ 3103 3104 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 3105 { 3106 PetscFunctionBegin; 3107 PetscFunctionReturn(PETSC_SUCCESS); 3108 } 3109 3110 #endif /* PETSC_USE_LOG*/ 3111 3112 PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 3113 PetscClassId PETSC_OBJECT_CLASSID = 0; 3114 3115 /*@C 3116 PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code. 3117 3118 Not Collective 3119 3120 Input Parameter: 3121 . name - The class name 3122 3123 Output Parameter: 3124 . oclass - The class id or classid 3125 3126 Level: developer 3127 3128 .seealso: [](ch_profiling), `PetscLogEventRegister()` 3129 @*/ 3130 PetscErrorCode PetscClassIdRegister(const char name[], PetscClassId *oclass) 3131 { 3132 #if defined(PETSC_USE_LOG) 3133 PetscStageLog stageLog; 3134 PetscInt stage; 3135 #endif 3136 3137 PetscFunctionBegin; 3138 *oclass = ++PETSC_LARGEST_CLASSID; 3139 #if defined(PETSC_USE_LOG) 3140 PetscCall(PetscLogGetStageLog(&stageLog)); 3141 PetscCall(PetscClassRegLogRegister(stageLog->classLog, name, *oclass)); 3142 for (stage = 0; stage < stageLog->numStages; stage++) PetscCall(PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses)); 3143 #endif 3144 PetscFunctionReturn(PETSC_SUCCESS); 3145 } 3146 3147 #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE) 3148 #include <mpe.h> 3149 3150 PetscBool PetscBeganMPE = PETSC_FALSE; 3151 3152 PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject); 3153 PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject); 3154 3155 /*@C 3156 PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files and slows the 3157 program down. 3158 3159 Collective over `PETSC_COMM_WORLD` 3160 3161 Options Database Key: 3162 . -log_mpe - Prints extensive log information 3163 3164 Level: advanced 3165 3166 Note: 3167 A related routine is `PetscLogDefaultBegin()` (with the options key `-log_view`), which is 3168 intended for production runs since it logs only flop rates and object creation (and should 3169 not significantly slow the programs). 3170 3171 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogDefaultBegin()`, `PetscLogAllBegin()`, `PetscLogEventActivate()`, 3172 `PetscLogEventDeactivate()` 3173 @*/ 3174 PetscErrorCode PetscLogMPEBegin(void) 3175 { 3176 PetscFunctionBegin; 3177 /* Do MPE initialization */ 3178 if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */ 3179 PetscCall(PetscInfo(0, "Initializing MPE.\n")); 3180 PetscCall(MPE_Init_log()); 3181 3182 PetscBeganMPE = PETSC_TRUE; 3183 } else { 3184 PetscCall(PetscInfo(0, "MPE already initialized. Not attempting to reinitialize.\n")); 3185 } 3186 PetscCall(PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE)); 3187 PetscFunctionReturn(PETSC_SUCCESS); 3188 } 3189 3190 /*@C 3191 PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot. 3192 3193 Input Parameter: 3194 . sname - The filename to dump to 3195 3196 Collective over `PETSC_COMM_WORLD` 3197 3198 Level: advanced 3199 3200 .seealso: [](ch_profiling), `PetscLogDump()`, `PetscLogAllBegin()`, `PetscLogMPEBegin()` 3201 @*/ 3202 PetscErrorCode PetscLogMPEDump(const char sname[]) 3203 { 3204 char name[PETSC_MAX_PATH_LEN]; 3205 3206 PetscFunctionBegin; 3207 if (PetscBeganMPE) { 3208 PetscCall(PetscInfo(0, "Finalizing MPE.\n")); 3209 if (sname) { 3210 PetscCall(PetscStrncpy(name, sname, sizeof(name))); 3211 } else { 3212 PetscCall(PetscGetProgramName(name, sizeof(name))); 3213 } 3214 PetscCall(MPE_Finish_log(name)); 3215 } else { 3216 PetscCall(PetscInfo(0, "Not finalizing MPE (not started by PETSc).\n")); 3217 } 3218 PetscFunctionReturn(PETSC_SUCCESS); 3219 } 3220 3221 #define PETSC_RGB_COLORS_MAX 39 3222 static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = {"OliveDrab: ", "BlueViolet: ", "CadetBlue: ", "CornflowerBlue: ", "DarkGoldenrod: ", "DarkGreen: ", "DarkKhaki: ", "DarkOliveGreen: ", 3223 "DarkOrange: ", "DarkOrchid: ", "DarkSeaGreen: ", "DarkSlateGray: ", "DarkTurquoise: ", "DeepPink: ", "DarkKhaki: ", "DimGray: ", 3224 "DodgerBlue: ", "GreenYellow: ", "HotPink: ", "IndianRed: ", "LavenderBlush: ", "LawnGreen: ", "LemonChiffon: ", "LightCoral: ", 3225 "LightCyan: ", "LightPink: ", "LightSalmon: ", "LightSlateGray: ", "LightYellow: ", "LimeGreen: ", "MediumPurple: ", "MediumSeaGreen: ", 3226 "MediumSlateBlue:", "MidnightBlue: ", "MintCream: ", "MistyRose: ", "NavajoWhite: ", "NavyBlue: ", "OliveDrab: "}; 3227 3228 /*@C 3229 PetscLogMPEGetRGBColor - This routine returns a rgb color useable with `PetscLogEventRegister()` 3230 3231 Not collective. Maybe it should be? 3232 3233 Output Parameter: 3234 . str - character string representing the color 3235 3236 Level: developer 3237 3238 .seealso: [](ch_profiling), `PetscLogEventRegister()` 3239 @*/ 3240 PetscErrorCode PetscLogMPEGetRGBColor(const char *str[]) 3241 { 3242 static int idx = 0; 3243 3244 PetscFunctionBegin; 3245 *str = PetscLogMPERGBColors[idx]; 3246 idx = (idx + 1) % PETSC_RGB_COLORS_MAX; 3247 PetscFunctionReturn(PETSC_SUCCESS); 3248 } 3249 3250 #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */ 3251