1 #include <petscviewer.h> 2 #include <petscdevice.h> 3 #include <petsc/private/logimpl.h> /*I "petscsys.h" I*/ 4 #include <petsc/private/loghandlerimpl.h> 5 #include <petsc/private/deviceimpl.h> 6 #include <petscconfiginfo.h> 7 #include <petscmachineinfo.h> 8 #include "logdefault.h" 9 10 static PetscErrorCode PetscEventPerfInfoInit(PetscEventPerfInfo *eventInfo) 11 { 12 PetscFunctionBegin; 13 PetscCall(PetscMemzero(eventInfo, sizeof(*eventInfo))); 14 eventInfo->visible = PETSC_TRUE; 15 eventInfo->id = -1; 16 eventInfo->dof[0] = -1.0; 17 eventInfo->dof[1] = -1.0; 18 eventInfo->dof[2] = -1.0; 19 eventInfo->dof[3] = -1.0; 20 eventInfo->dof[4] = -1.0; 21 eventInfo->dof[5] = -1.0; 22 eventInfo->dof[6] = -1.0; 23 eventInfo->dof[7] = -1.0; 24 eventInfo->errors[0] = -1.0; 25 eventInfo->errors[1] = -1.0; 26 eventInfo->errors[2] = -1.0; 27 eventInfo->errors[3] = -1.0; 28 eventInfo->errors[4] = -1.0; 29 eventInfo->errors[5] = -1.0; 30 eventInfo->errors[6] = -1.0; 31 eventInfo->errors[7] = -1.0; 32 PetscFunctionReturn(PETSC_SUCCESS); 33 } 34 35 static PetscErrorCode PetscEventPerfInfoTic_Internal(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event, PetscBool resume) 36 { 37 PetscFunctionBegin; 38 if (resume) { 39 eventInfo->timeTmp -= time; 40 eventInfo->flopsTmp -= petsc_TotalFlops_th; 41 } else { 42 eventInfo->timeTmp = -time; 43 eventInfo->flopsTmp = -petsc_TotalFlops_th; 44 } 45 eventInfo->numMessages -= petsc_irecv_ct_th + petsc_isend_ct_th + petsc_recv_ct_th + petsc_send_ct_th; 46 eventInfo->messageLength -= petsc_irecv_len_th + petsc_isend_len_th + petsc_recv_len_th + petsc_send_len_th; 47 eventInfo->numReductions -= petsc_allreduce_ct_th + petsc_gather_ct_th + petsc_scatter_ct_th; 48 #if defined(PETSC_HAVE_DEVICE) 49 eventInfo->CpuToGpuCount -= petsc_ctog_ct_th; 50 eventInfo->GpuToCpuCount -= petsc_gtoc_ct_th; 51 eventInfo->CpuToGpuSize -= petsc_ctog_sz_th; 52 eventInfo->GpuToCpuSize -= petsc_gtoc_sz_th; 53 eventInfo->GpuFlops -= petsc_gflops_th; 54 eventInfo->GpuTime -= petsc_gtime; 55 #endif 56 if (logMemory) { 57 PetscLogDouble usage; 58 PetscCall(PetscMemoryGetCurrentUsage(&usage)); 59 eventInfo->memIncrease -= usage; 60 PetscCall(PetscMallocGetCurrentUsage(&usage)); 61 eventInfo->mallocSpace -= usage; 62 PetscCall(PetscMallocGetMaximumUsage(&usage)); 63 eventInfo->mallocIncrease -= usage; 64 PetscCall(PetscMallocPushMaximumUsage(event)); 65 } 66 PetscFunctionReturn(PETSC_SUCCESS); 67 } 68 69 static PetscErrorCode PetscEventPerfInfoTic(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event) 70 { 71 PetscFunctionBegin; 72 PetscCall(PetscEventPerfInfoTic_Internal(eventInfo, time, logMemory, event, PETSC_FALSE)); 73 PetscFunctionReturn(PETSC_SUCCESS); 74 } 75 76 static PetscErrorCode PetscEventPerfInfoResume(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event) 77 { 78 PetscFunctionBegin; 79 PetscCall(PetscEventPerfInfoTic_Internal(eventInfo, time, logMemory, event, PETSC_TRUE)); 80 PetscFunctionReturn(PETSC_SUCCESS); 81 } 82 83 static PetscErrorCode PetscEventPerfInfoToc_Internal(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event, PetscBool pause) 84 { 85 PetscFunctionBegin; 86 eventInfo->timeTmp += time; 87 eventInfo->flopsTmp += petsc_TotalFlops_th; 88 if (!pause) { 89 eventInfo->time += eventInfo->timeTmp; 90 eventInfo->time2 += eventInfo->timeTmp * eventInfo->timeTmp; 91 eventInfo->flops += eventInfo->flopsTmp; 92 eventInfo->flops2 += eventInfo->flopsTmp * eventInfo->flopsTmp; 93 } 94 eventInfo->numMessages += petsc_irecv_ct_th + petsc_isend_ct_th + petsc_recv_ct_th + petsc_send_ct_th; 95 eventInfo->messageLength += petsc_irecv_len_th + petsc_isend_len_th + petsc_recv_len + petsc_send_len_th; 96 eventInfo->numReductions += petsc_allreduce_ct_th + petsc_gather_ct_th + petsc_scatter_ct_th; 97 #if defined(PETSC_HAVE_DEVICE) 98 eventInfo->CpuToGpuCount += petsc_ctog_ct_th; 99 eventInfo->GpuToCpuCount += petsc_gtoc_ct_th; 100 eventInfo->CpuToGpuSize += petsc_ctog_sz_th; 101 eventInfo->GpuToCpuSize += petsc_gtoc_sz_th; 102 eventInfo->GpuFlops += petsc_gflops_th; 103 eventInfo->GpuTime += petsc_gtime; 104 #endif 105 if (logMemory) { 106 PetscLogDouble usage, musage; 107 PetscCall(PetscMemoryGetCurrentUsage(&usage)); /* the comments below match the column labels printed in PetscLogView_Default() */ 108 eventInfo->memIncrease += usage; /* RMI */ 109 PetscCall(PetscMallocGetCurrentUsage(&usage)); 110 eventInfo->mallocSpace += usage; /* Malloc */ 111 PetscCall(PetscMallocPopMaximumUsage(event, &musage)); 112 eventInfo->mallocIncreaseEvent = PetscMax(musage - usage, eventInfo->mallocIncreaseEvent); /* EMalloc */ 113 PetscCall(PetscMallocGetMaximumUsage(&usage)); 114 eventInfo->mallocIncrease += usage; /* MMalloc */ 115 } 116 PetscFunctionReturn(PETSC_SUCCESS); 117 } 118 119 static PetscErrorCode PetscEventPerfInfoToc(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event) 120 { 121 PetscFunctionBegin; 122 PetscCall(PetscEventPerfInfoToc_Internal(eventInfo, time, logMemory, event, PETSC_FALSE)); 123 PetscFunctionReturn(PETSC_SUCCESS); 124 } 125 126 static PetscErrorCode PetscEventPerfInfoPause(PetscEventPerfInfo *eventInfo, PetscLogDouble time, PetscBool logMemory, int event) 127 { 128 PetscFunctionBegin; 129 PetscCall(PetscEventPerfInfoToc_Internal(eventInfo, time, logMemory, event, PETSC_TRUE)); 130 PetscFunctionReturn(PETSC_SUCCESS); 131 } 132 133 static PetscErrorCode PetscEventPerfInfoAdd_Internal(const PetscEventPerfInfo *eventInfo, PetscEventPerfInfo *outInfo) 134 { 135 PetscFunctionBegin; 136 outInfo->count += eventInfo->count; 137 outInfo->time += eventInfo->time; 138 outInfo->time2 += eventInfo->time2; 139 outInfo->flops += eventInfo->flops; 140 outInfo->flops2 += eventInfo->flops2; 141 outInfo->numMessages += eventInfo->numMessages; 142 outInfo->messageLength += eventInfo->messageLength; 143 outInfo->numReductions += eventInfo->numReductions; 144 #if defined(PETSC_HAVE_DEVICE) 145 outInfo->CpuToGpuCount += eventInfo->CpuToGpuCount; 146 outInfo->GpuToCpuCount += eventInfo->GpuToCpuCount; 147 outInfo->CpuToGpuSize += eventInfo->CpuToGpuSize; 148 outInfo->GpuToCpuSize += eventInfo->GpuToCpuSize; 149 outInfo->GpuFlops += eventInfo->GpuFlops; 150 outInfo->GpuTime += eventInfo->GpuTime; 151 #endif 152 outInfo->memIncrease += eventInfo->memIncrease; 153 outInfo->mallocSpace += eventInfo->mallocSpace; 154 outInfo->mallocIncreaseEvent += eventInfo->mallocIncreaseEvent; 155 outInfo->mallocIncrease += eventInfo->mallocIncrease; 156 PetscFunctionReturn(PETSC_SUCCESS); 157 } 158 159 PETSC_LOG_RESIZABLE_ARRAY(EventPerfArray, PetscEventPerfInfo, PetscLogEvent, PetscEventPerfInfoInit, NULL, NULL) 160 161 /* --- PetscClassPerf --- */ 162 163 typedef struct { 164 int creations; /* The number of objects of this class created */ 165 int destructions; /* The number of objects of this class destroyed */ 166 PetscLogDouble mem; /* The total memory allocated by objects of this class; this is completely wrong and should possibly be removed */ 167 PetscLogDouble descMem; /* The total memory allocated by descendents of these objects; this is completely wrong and should possibly be removed */ 168 } PetscClassPerf; 169 170 static PetscErrorCode PetscClassPerfInit(PetscClassPerf *classInfo) 171 { 172 PetscFunctionBegin; 173 PetscCall(PetscMemzero(classInfo, sizeof(*classInfo))); 174 PetscFunctionReturn(PETSC_SUCCESS); 175 } 176 177 PETSC_LOG_RESIZABLE_ARRAY(ClassPerfArray, PetscClassPerf, PetscLogClass, PetscClassPerfInit, NULL, NULL) 178 179 /* --- PetscStagePerf --- */ 180 181 typedef struct _PetscStagePerf { 182 PetscBool used; /* The stage was pushed on this processor */ 183 PetscEventPerfInfo perfInfo; /* The stage performance information */ 184 PetscLogEventPerfArray eventLog; /* The event information for this stage */ 185 PetscLogClassPerfArray classLog; /* The class information for this stage */ 186 } PetscStagePerf; 187 188 static PetscErrorCode PetscStageInfoInit(PetscStagePerf *stageInfo) 189 { 190 PetscFunctionBegin; 191 PetscCall(PetscMemzero(stageInfo, sizeof(*stageInfo))); 192 PetscCall(PetscLogEventPerfArrayCreate(128, &stageInfo->eventLog)); 193 PetscCall(PetscLogClassPerfArrayCreate(128, &stageInfo->classLog)); 194 PetscCall(PetscEventPerfInfoInit(&stageInfo->perfInfo)); 195 PetscFunctionReturn(PETSC_SUCCESS); 196 } 197 198 static PetscErrorCode PetscStageInfoReset(PetscStagePerf *stageInfo) 199 { 200 PetscFunctionBegin; 201 PetscCall(PetscLogEventPerfArrayDestroy(&stageInfo->eventLog)); 202 PetscCall(PetscLogClassPerfArrayDestroy(&stageInfo->classLog)); 203 PetscFunctionReturn(PETSC_SUCCESS); 204 } 205 206 PETSC_LOG_RESIZABLE_ARRAY(StageInfoArray, PetscStagePerf, PetscLogStage, PetscStageInfoInit, PetscStageInfoReset, NULL) 207 208 /* --- Action --- */ 209 210 /* The structure for action logging */ 211 typedef enum { 212 PETSC_LOG_ACTION_CREATE, 213 PETSC_LOG_ACTION_DESTROY, 214 PETSC_LOG_ACTION_BEGIN, 215 PETSC_LOG_ACTION_END, 216 } PetscLogActionType; 217 218 typedef struct _Action { 219 PetscLogActionType action; /* The type of execution */ 220 PetscLogEvent event; /* The event number */ 221 PetscClassId classid; /* The event class id */ 222 PetscLogDouble time; /* The time of occurrence */ 223 PetscLogDouble flops; /* The cumulative flops */ 224 PetscLogDouble mem; /* The current memory usage */ 225 PetscLogDouble maxmem; /* The maximum memory usage */ 226 PetscObjectId id1, id2, id3; /* The ids of associated objects */ 227 } Action; 228 229 PETSC_LOG_RESIZABLE_ARRAY(ActionArray, Action, PetscLogEvent, NULL, NULL, NULL) 230 231 /* --- Object --- */ 232 233 /* The structure for object logging */ 234 typedef struct _Object { 235 PetscObject obj; /* The associated PetscObject */ 236 int parent; /* The parent id */ 237 PetscLogDouble mem; /* The memory associated with the object */ 238 char name[64]; /* The object name */ 239 char info[64]; /* The information string */ 240 } Object; 241 242 PETSC_LOG_RESIZABLE_ARRAY(ObjectArray, Object, PetscObject, NULL, NULL, NULL) 243 244 /* Map from (threadid,stage,event) to perfInfo data struct */ 245 #include <petsc/private/hashmapijk.h> 246 247 PETSC_HASH_MAP(HMapEvent, PetscHashIJKKey, PetscEventPerfInfo *, PetscHashIJKKeyHash, PetscHashIJKKeyEqual, NULL) 248 249 typedef struct _n_PetscLogHandler_Default *PetscLogHandler_Default; 250 struct _n_PetscLogHandler_Default { 251 PetscLogStageInfoArray stages; 252 PetscSpinlock lock; 253 PetscLogActionArray petsc_actions; 254 PetscLogObjectArray petsc_objects; 255 PetscBool petsc_logActions; 256 PetscBool petsc_logObjects; 257 int petsc_numObjectsCreated; 258 int petsc_numObjectsDestroyed; 259 PetscHMapEvent eventInfoMap_th; 260 int pause_depth; 261 PetscBool use_threadsafe; 262 }; 263 264 /* --- PetscLogHandler_Default --- */ 265 266 static PetscErrorCode PetscLogHandlerContextCreate_Default(PetscLogHandler_Default *def_p) 267 { 268 PetscLogHandler_Default def; 269 270 PetscFunctionBegin; 271 PetscCall(PetscNew(def_p)); 272 def = *def_p; 273 PetscCall(PetscLogStageInfoArrayCreate(8, &def->stages)); 274 PetscCall(PetscLogActionArrayCreate(64, &def->petsc_actions)); 275 PetscCall(PetscLogObjectArrayCreate(64, &def->petsc_objects)); 276 PetscCall(PetscSpinlockCreate(&def->lock)); 277 278 PetscCall(PetscOptionsGetBool(NULL, NULL, "-log_include_actions", &def->petsc_logActions, NULL)); 279 PetscCall(PetscOptionsGetBool(NULL, NULL, "-log_include_objects", &def->petsc_logObjects, NULL)); 280 PetscCall(PetscOptionsGetBool(NULL, NULL, "-log_handler_default_use_threadsafe_events", &def->use_threadsafe, NULL)); 281 if (PetscDefined(HAVE_THREADSAFETY) || def->use_threadsafe) PetscCall(PetscHMapEventCreate(&def->eventInfoMap_th)); 282 PetscFunctionReturn(PETSC_SUCCESS); 283 } 284 285 static PetscErrorCode PetscLogHandlerDestroy_Default(PetscLogHandler h) 286 { 287 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 288 289 PetscFunctionBegin; 290 PetscCall(PetscLogStageInfoArrayDestroy(&def->stages)); 291 PetscCall(PetscLogActionArrayDestroy(&def->petsc_actions)); 292 PetscCall(PetscLogObjectArrayDestroy(&def->petsc_objects)); 293 PetscCall(PetscSpinlockDestroy(&def->lock)); 294 if (def->eventInfoMap_th) { 295 PetscEventPerfInfo **array; 296 PetscInt n, off = 0; 297 298 PetscCall(PetscHMapEventGetSize(def->eventInfoMap_th, &n)); 299 PetscCall(PetscMalloc1(n, &array)); 300 PetscCall(PetscHMapEventGetVals(def->eventInfoMap_th, &off, array)); 301 for (PetscInt i = 0; i < n; i++) PetscCall(PetscFree(array[i])); 302 PetscCall(PetscFree(array)); 303 PetscCall(PetscHMapEventDestroy(&def->eventInfoMap_th)); 304 } 305 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerGetEventPerfInfo_C", NULL)); 306 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerGetStagePerfInfo_C", NULL)); 307 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerSetLogActions_C", NULL)); 308 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerSetLogObjects_C", NULL)); 309 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerLogObjectState_C", NULL)); 310 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerGetNumObjects_C", NULL)); 311 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerEventDeactivatePush_C", NULL)); 312 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerEventDeactivatePop_C", NULL)); 313 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerEventsPause_C", NULL)); 314 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerEventsResume_C", NULL)); 315 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerDump_C", NULL)); 316 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerStageSetVisible_C", NULL)); 317 PetscCall(PetscObjectComposeFunction((PetscObject)h, "PetscLogHandlerStageGetVisible_C", NULL)); 318 PetscCall(PetscFree(def)); 319 PetscFunctionReturn(PETSC_SUCCESS); 320 } 321 322 static PetscErrorCode PetscLogHandlerDefaultGetStageInfo(PetscLogHandler handler, PetscLogStage stage, PetscStagePerf **stage_info_p) 323 { 324 PetscStagePerf *stage_info = NULL; 325 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 326 327 PetscFunctionBegin; 328 PetscCall(PetscLogStageInfoArrayResize(def->stages, stage + 1)); 329 PetscCall(PetscLogStageInfoArrayGetRef(def->stages, stage, &stage_info)); 330 *stage_info_p = stage_info; 331 PetscFunctionReturn(PETSC_SUCCESS); 332 } 333 334 static PetscErrorCode PetscLogHandlerGetEventPerfInfo_Default(PetscLogHandler handler, PetscLogStage stage, PetscLogEvent event, PetscEventPerfInfo **event_info_p) 335 { 336 PetscEventPerfInfo *event_info = NULL; 337 PetscStagePerf *stage_info = NULL; 338 PetscLogEventPerfArray event_log; 339 340 PetscFunctionBegin; 341 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(handler->state, &stage)); 342 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage, &stage_info)); 343 event_log = stage_info->eventLog; 344 PetscCall(PetscLogEventPerfArrayResize(event_log, event + 1)); 345 PetscCall(PetscLogEventPerfArrayGetRef(event_log, event, &event_info)); 346 event_info->id = event; 347 *event_info_p = event_info; 348 PetscFunctionReturn(PETSC_SUCCESS); 349 } 350 351 static PetscErrorCode PetscLogHandlerGetStagePerfInfo_Default(PetscLogHandler handler, PetscLogStage stage, PetscEventPerfInfo **stage_info_p) 352 { 353 PetscStagePerf *stage_perf_info = NULL; 354 355 PetscFunctionBegin; 356 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(handler->state, &stage)); 357 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage, &stage_perf_info)); 358 *stage_info_p = &stage_perf_info->perfInfo; 359 PetscFunctionReturn(PETSC_SUCCESS); 360 } 361 362 static PetscErrorCode PetscLogHandlerDefaultGetClassPerf(PetscLogHandler handler, PetscLogStage stage, PetscLogClass clss, PetscClassPerf **class_info) 363 { 364 PetscLogClassPerfArray class_log; 365 PetscStagePerf *stage_info; 366 367 PetscFunctionBegin; 368 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage, &stage_info)); 369 class_log = stage_info->classLog; 370 PetscCall(PetscLogClassPerfArrayResize(class_log, clss + 1)); 371 PetscCall(PetscLogClassPerfArrayGetRef(class_log, clss, class_info)); 372 PetscFunctionReturn(PETSC_SUCCESS); 373 } 374 375 static PetscErrorCode PetscLogHandlerObjectCreate_Default(PetscLogHandler h, PetscObject obj) 376 { 377 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 378 PetscLogState state; 379 PetscLogStage stage; 380 PetscClassPerf *classInfo; 381 int oclass = 0; 382 383 PetscFunctionBegin; 384 PetscCall(PetscLogHandlerGetState(h, &state)); 385 PetscCall(PetscSpinlockLock(&def->lock)); 386 /* Record stage info */ 387 PetscCall(PetscLogStateGetCurrentStage(state, &stage)); 388 PetscCall(PetscLogStateGetClassFromClassId(state, obj->classid, &oclass)); 389 PetscCall(PetscLogHandlerDefaultGetClassPerf(h, stage, oclass, &classInfo)); 390 classInfo->creations++; 391 /* Record the creation action */ 392 if (def->petsc_logActions) { 393 Action new_action; 394 395 PetscCall(PetscTime(&new_action.time)); 396 new_action.time -= petsc_BaseTime; 397 new_action.action = PETSC_LOG_ACTION_CREATE; 398 new_action.event = -1; 399 new_action.classid = obj->classid; 400 new_action.id1 = obj->id; 401 new_action.id2 = -1; 402 new_action.id3 = -1; 403 new_action.flops = petsc_TotalFlops; 404 PetscCall(PetscMallocGetCurrentUsage(&new_action.mem)); 405 PetscCall(PetscMallocGetMaximumUsage(&new_action.maxmem)); 406 PetscCall(PetscLogActionArrayPush(def->petsc_actions, new_action)); 407 } 408 /* We don't just use obj->id to count all objects that are created 409 because PetscLogHandlers are objects and PetscLogObjectDestroy() will not 410 be called for them: the number of objects created and destroyed as counted 411 here and below would have an imbalance */ 412 def->petsc_numObjectsCreated++; 413 /* Record the object */ 414 if (def->petsc_logObjects) { 415 Object new_object; 416 PetscInt objid; 417 418 new_object.parent = -1; 419 new_object.obj = obj; 420 new_object.mem = 0; 421 422 PetscCall(PetscMemzero(new_object.name, sizeof(new_object.name))); 423 PetscCall(PetscMemzero(new_object.info, sizeof(new_object.info))); 424 PetscAssert(obj->id >= 1, PETSC_COMM_SELF, PETSC_ERR_PLIB, "Object ids from PetscObjectNewId_Internal() start at 1"); 425 PetscCall(PetscIntCast(obj->id, &objid)); 426 PetscCall(PetscLogObjectArrayResize(def->petsc_objects, objid)); 427 PetscCall(PetscLogObjectArraySet(def->petsc_objects, objid - 1, new_object)); 428 } 429 PetscCall(PetscSpinlockUnlock(&def->lock)); 430 PetscFunctionReturn(PETSC_SUCCESS); 431 } 432 433 static PetscErrorCode PetscLogHandlerObjectDestroy_Default(PetscLogHandler h, PetscObject obj) 434 { 435 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 436 PetscLogState state; 437 PetscLogStage stage; 438 PetscClassPerf *classInfo; 439 int oclass = 0; 440 441 PetscFunctionBegin; 442 PetscCall(PetscLogHandlerGetState(h, &state)); 443 /* Record stage info */ 444 PetscCall(PetscSpinlockLock(&def->lock)); 445 PetscCall(PetscLogStateGetCurrentStage(state, &stage)); 446 if (stage >= 0) { 447 /* stage < 0 can happen if the log summary is output before some things are destroyed */ 448 PetscCall(PetscLogStateGetClassFromClassId(state, obj->classid, &oclass)); 449 PetscCall(PetscLogHandlerDefaultGetClassPerf(h, stage, oclass, &classInfo)); 450 classInfo->destructions++; 451 } 452 /* Cannot Credit all ancestors with your memory because they may have already been destroyed*/ 453 def->petsc_numObjectsDestroyed++; 454 /* Dynamically enlarge logging structures */ 455 /* Record the destruction action */ 456 if (def->petsc_logActions) { 457 Action new_action; 458 459 PetscCall(PetscTime(&new_action.time)); 460 new_action.time -= petsc_BaseTime; 461 new_action.event = -1; 462 new_action.action = PETSC_LOG_ACTION_DESTROY; 463 new_action.classid = obj->classid; 464 new_action.id1 = obj->id; 465 new_action.id2 = -1; 466 new_action.id3 = -1; 467 new_action.flops = petsc_TotalFlops; 468 PetscCall(PetscMallocGetCurrentUsage(&new_action.mem)); 469 PetscCall(PetscMallocGetMaximumUsage(&new_action.maxmem)); 470 PetscCall(PetscLogActionArrayPush(def->petsc_actions, new_action)); 471 } 472 if (def->petsc_logObjects) { 473 Object *obj_entry = NULL; 474 PetscInt objid; 475 476 PetscAssert(obj->id >= 1, PETSC_COMM_SELF, PETSC_ERR_PLIB, "Object ids from PetscObjectNewId_Internal() start at 1"); 477 PetscCall(PetscIntCast(obj->id - 1, &objid)); 478 PetscCall(PetscLogObjectArrayGetRef(def->petsc_objects, objid, &obj_entry)); 479 if (obj->name) PetscCall(PetscStrncpy(obj_entry->name, obj->name, 64)); 480 obj_entry->obj = NULL; 481 } 482 PetscCall(PetscSpinlockUnlock(&def->lock)); 483 PetscFunctionReturn(PETSC_SUCCESS); 484 } 485 486 static PetscErrorCode PetscLogHandlerEventSync_Default(PetscLogHandler h, PetscLogEvent event, MPI_Comm comm) 487 { 488 PetscLogState state; 489 PetscLogEventInfo event_info; 490 PetscEventPerfInfo *event_perf_info; 491 int stage; 492 PetscLogDouble time = 0.0; 493 494 PetscFunctionBegin; 495 if (!PetscLogSyncOn || comm == MPI_COMM_NULL) PetscFunctionReturn(PETSC_SUCCESS); 496 PetscCall(PetscLogHandlerGetState(h, &state)); 497 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 498 if (!event_info.collective) PetscFunctionReturn(PETSC_SUCCESS); 499 PetscCall(PetscLogStateGetCurrentStage(state, &stage)); 500 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info)); 501 if (event_perf_info->depth > 0) PetscFunctionReturn(PETSC_SUCCESS); 502 503 PetscCall(PetscTimeSubtract(&time)); 504 PetscCallMPI(MPI_Barrier(comm)); 505 PetscCall(PetscTimeAdd(&time)); 506 event_perf_info->syncTime += time; 507 PetscFunctionReturn(PETSC_SUCCESS); 508 } 509 510 static PetscErrorCode PetscLogGetStageEventPerfInfo_threaded(PetscLogHandler_Default def, PetscLogStage stage, PetscLogEvent event, PetscEventPerfInfo **eventInfo) 511 { 512 PetscEventPerfInfo *leventInfo = NULL; 513 PetscHashIJKKey key; 514 515 PetscFunctionBegin; 516 #if PetscDefined(HAVE_THREADSAFETY) 517 key.i = PetscLogGetTid(); 518 #else 519 key.i = 0; 520 #endif 521 key.j = stage; 522 key.k = event; 523 PetscCall(PetscSpinlockLock(&def->lock)); 524 PetscCall(PetscHMapEventGet(def->eventInfoMap_th, key, &leventInfo)); 525 if (!leventInfo) { 526 PetscCall(PetscNew(&leventInfo)); 527 leventInfo->id = event; 528 PetscCall(PetscHMapEventSet(def->eventInfoMap_th, key, leventInfo)); 529 } 530 PetscCall(PetscSpinlockUnlock(&def->lock)); 531 *eventInfo = leventInfo; 532 PetscFunctionReturn(PETSC_SUCCESS); 533 } 534 535 static PetscErrorCode PetscLogHandlerEventBegin_Default(PetscLogHandler h, PetscLogEvent event, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4) 536 { 537 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 538 PetscEventPerfInfo *event_perf_info = NULL; 539 PetscLogEventInfo event_info; 540 PetscLogDouble time; 541 PetscLogState state; 542 PetscLogStage stage; 543 544 PetscFunctionBegin; 545 PetscCall(PetscLogHandlerGetState(h, &state)); 546 if (PetscDefined(USE_DEBUG)) { 547 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 548 if (PetscUnlikely(o1)) PetscValidHeader(o1, 3); 549 if (PetscUnlikely(o2)) PetscValidHeader(o2, 4); 550 if (PetscUnlikely(o3)) PetscValidHeader(o3, 5); 551 if (PetscUnlikely(o4)) PetscValidHeader(o4, 6); 552 if (event_info.collective && o1) { 553 PetscInt64 b1[2], b2[2]; 554 555 b1[0] = -o1->cidx; 556 b1[1] = o1->cidx; 557 PetscCallMPI(MPIU_Allreduce(b1, b2, 2, MPIU_INT64, MPI_MAX, PetscObjectComm(o1))); 558 PetscCheck(-b2[0] == b2[1], PETSC_COMM_SELF, PETSC_ERR_PLIB, "Collective event %s not called collectively %" PetscInt64_FMT " != %" PetscInt64_FMT, event_info.name, -b2[0], b2[1]); 559 } 560 } 561 /* Synchronization */ 562 PetscCall(PetscLogHandlerEventSync_Default(h, event, PetscObjectComm(o1))); 563 PetscCall(PetscLogStateGetCurrentStage(state, &stage)); 564 if (def->pause_depth > 0) stage = 0; // in pause-mode, all events run on the main stage 565 if (PetscDefined(HAVE_THREADSAFETY) || def->use_threadsafe) { 566 PetscCall(PetscLogGetStageEventPerfInfo_threaded(def, stage, event, &event_perf_info)); 567 if (event_perf_info->depth == 0) PetscCall(PetscEventPerfInfoInit(event_perf_info)); 568 } else { 569 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info)); 570 } 571 PetscCheck(event_perf_info->depth >= 0, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Trying to begin a paused event, this is not allowed"); 572 event_perf_info->depth++; 573 /* Check for double counting */ 574 if (event_perf_info->depth > 1) PetscFunctionReturn(PETSC_SUCCESS); 575 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 576 /* Log the performance info */ 577 event_perf_info->count++; 578 PetscCall(PetscTime(&time)); 579 PetscCall(PetscEventPerfInfoTic(event_perf_info, time, PetscLogMemory, event)); 580 if (def->petsc_logActions) { 581 PetscLogDouble curTime; 582 Action new_action; 583 584 PetscCall(PetscTime(&curTime)); 585 new_action.time = curTime - petsc_BaseTime; 586 new_action.action = PETSC_LOG_ACTION_BEGIN; 587 new_action.event = event; 588 new_action.classid = event_info.classid; 589 new_action.id1 = o1 ? o1->id : -1; 590 new_action.id2 = o2 ? o2->id : -1; 591 new_action.id3 = o3 ? o3->id : -1; 592 new_action.flops = petsc_TotalFlops; 593 PetscCall(PetscMallocGetCurrentUsage(&new_action.mem)); 594 PetscCall(PetscMallocGetMaximumUsage(&new_action.maxmem)); 595 PetscCall(PetscLogActionArrayPush(def->petsc_actions, new_action)); 596 } 597 PetscFunctionReturn(PETSC_SUCCESS); 598 } 599 600 static PetscErrorCode PetscLogHandlerEventEnd_Default(PetscLogHandler h, PetscLogEvent event, PetscObject o1, PetscObject o2, PetscObject o3, PetscObject o4) 601 { 602 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 603 PetscEventPerfInfo *event_perf_info = NULL; 604 PetscLogDouble time; 605 PetscLogState state; 606 int stage; 607 PetscLogEventInfo event_info; 608 609 PetscFunctionBegin; 610 PetscCall(PetscLogHandlerGetState(h, &state)); 611 if (PetscDefined(USE_DEBUG)) { 612 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 613 if (PetscUnlikely(o1)) PetscValidHeader(o1, 3); 614 if (PetscUnlikely(o2)) PetscValidHeader(o2, 4); 615 if (PetscUnlikely(o3)) PetscValidHeader(o3, 5); 616 if (PetscUnlikely(o4)) PetscValidHeader(o4, 6); 617 if (event_info.collective && o1) { 618 PetscInt64 b1[2], b2[2]; 619 620 b1[0] = -o1->cidx; 621 b1[1] = o1->cidx; 622 PetscCallMPI(MPIU_Allreduce(b1, b2, 2, MPIU_INT64, MPI_MAX, PetscObjectComm(o1))); 623 PetscCheck(-b2[0] == b2[1], PETSC_COMM_SELF, PETSC_ERR_PLIB, "Collective event %s not called collectively %" PetscInt64_FMT " != %" PetscInt64_FMT, event_info.name, -b2[0], b2[1]); 624 } 625 } 626 if (def->petsc_logActions) { 627 PetscLogDouble curTime; 628 Action new_action; 629 630 PetscCall(PetscLogStateEventGetInfo(state, event, &event_info)); 631 PetscCall(PetscTime(&curTime)); 632 new_action.time = curTime - petsc_BaseTime; 633 new_action.action = PETSC_LOG_ACTION_END; 634 new_action.event = event; 635 new_action.classid = event_info.classid; 636 new_action.id1 = o1 ? o1->id : -1; 637 new_action.id2 = o2 ? o2->id : -2; 638 new_action.id3 = o3 ? o3->id : -3; 639 new_action.flops = petsc_TotalFlops; 640 PetscCall(PetscMallocGetCurrentUsage(&new_action.mem)); 641 PetscCall(PetscMallocGetMaximumUsage(&new_action.maxmem)); 642 PetscCall(PetscLogActionArrayPush(def->petsc_actions, new_action)); 643 } 644 PetscCall(PetscLogStateGetCurrentStage(state, &stage)); 645 if (def->pause_depth > 0) stage = 0; // all events run on the main stage in pause-mode 646 if (PetscDefined(HAVE_THREADSAFETY) || def->use_threadsafe) { 647 PetscCall(PetscLogGetStageEventPerfInfo_threaded(def, stage, event, &event_perf_info)); 648 } else { 649 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info)); 650 } 651 PetscCheck(event_perf_info->depth > 0, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Trying to end paused event, not allowed"); 652 event_perf_info->depth--; 653 /* Check for double counting */ 654 if (event_perf_info->depth > 0) PetscFunctionReturn(PETSC_SUCCESS); 655 else PetscCheck(event_perf_info->depth == 0, PETSC_COMM_SELF, PETSC_ERR_ARG_WRONGSTATE, "Logging event had unbalanced begin/end pairs"); 656 657 /* Log performance info */ 658 PetscCall(PetscTime(&time)); 659 PetscCall(PetscEventPerfInfoToc(event_perf_info, time, PetscLogMemory, event)); 660 if (PetscDefined(HAVE_THREADSAFETY) || def->use_threadsafe) { 661 PetscEventPerfInfo *event_perf_info_global; 662 PetscCall(PetscSpinlockLock(&def->lock)); 663 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info_global)); 664 PetscCall(PetscEventPerfInfoAdd_Internal(event_perf_info, event_perf_info_global)); 665 PetscCall(PetscSpinlockUnlock(&def->lock)); 666 } 667 PetscFunctionReturn(PETSC_SUCCESS); 668 } 669 670 static PetscErrorCode PetscLogHandlerEventDeactivatePush_Default(PetscLogHandler h, PetscLogStage stage, PetscLogEvent event) 671 { 672 PetscEventPerfInfo *event_perf_info; 673 674 PetscFunctionBegin; 675 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(h->state, &stage)); 676 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info)); 677 event_perf_info->depth++; 678 PetscFunctionReturn(PETSC_SUCCESS); 679 } 680 681 static PetscErrorCode PetscLogHandlerEventDeactivatePop_Default(PetscLogHandler h, PetscLogStage stage, PetscLogEvent event) 682 { 683 PetscEventPerfInfo *event_perf_info; 684 685 PetscFunctionBegin; 686 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(h->state, &stage)); 687 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(h, stage, event, &event_perf_info)); 688 event_perf_info->depth--; 689 PetscFunctionReturn(PETSC_SUCCESS); 690 } 691 692 static PetscErrorCode PetscLogHandlerEventsPause_Default(PetscLogHandler h) 693 { 694 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 695 PetscLogDouble time; 696 PetscInt num_stages; 697 698 PetscFunctionBegin; 699 if (def->pause_depth++ > 0) PetscFunctionReturn(PETSC_SUCCESS); 700 PetscCall(PetscLogStageInfoArrayGetSize(def->stages, &num_stages, NULL)); 701 PetscCall(PetscTime(&time)); 702 /* Pause stages in reverse of the order they were pushed */ 703 for (PetscInt stage = num_stages - 1; stage >= 0; stage--) { 704 PetscStagePerf *stage_info = NULL; 705 PetscInt num_events; 706 707 PetscCall(PetscLogStageInfoArrayGetRef(def->stages, stage, &stage_info)); 708 PetscCall(PetscLogEventPerfArrayGetSize(stage_info->eventLog, &num_events, NULL)); 709 /* Pause events in reverse of the order they were pushed */ 710 for (PetscInt event = num_events - 1; event >= 0; event--) { 711 PetscEventPerfInfo *event_info = NULL; 712 PetscCall(PetscLogEventPerfArrayGetRef(stage_info->eventLog, event, &event_info)); 713 if (event_info->depth > 0) { 714 event_info->depth *= -1; 715 PetscCall(PetscEventPerfInfoPause(event_info, time, PetscLogMemory, event)); 716 } 717 } 718 if (stage > 0 && stage_info->perfInfo.depth > 0) { 719 stage_info->perfInfo.depth *= -1; 720 PetscCall(PetscEventPerfInfoPause(&stage_info->perfInfo, time, PetscLogMemory, -(stage + 2))); 721 } 722 } 723 PetscFunctionReturn(PETSC_SUCCESS); 724 } 725 726 static PetscErrorCode PetscLogHandlerEventsResume_Default(PetscLogHandler h) 727 { 728 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 729 PetscLogDouble time; 730 PetscInt num_stages; 731 732 PetscFunctionBegin; 733 if (--def->pause_depth > 0) PetscFunctionReturn(PETSC_SUCCESS); 734 PetscCall(PetscLogStageInfoArrayGetSize(def->stages, &num_stages, NULL)); 735 PetscCall(PetscTime(&time)); 736 /* Unpause stages in the same order they were pushed */ 737 for (PetscInt stage = 0; stage < num_stages; stage++) { 738 PetscStagePerf *stage_info = NULL; 739 PetscInt num_events; 740 741 PetscCall(PetscLogStageInfoArrayGetRef(def->stages, stage, &stage_info)); 742 PetscCall(PetscLogEventPerfArrayGetSize(stage_info->eventLog, &num_events, NULL)); 743 /* Unpause events in the same order they were pushed */ 744 for (PetscInt event = 0; event < num_events; event++) { 745 PetscEventPerfInfo *event_info = NULL; 746 PetscCall(PetscLogEventPerfArrayGetRef(stage_info->eventLog, event, &event_info)); 747 if (event_info->depth < 0) { 748 event_info->depth *= -1; 749 PetscCall(PetscEventPerfInfoResume(event_info, time, PetscLogMemory, event)); 750 } 751 } 752 if (stage > 0 && stage_info->perfInfo.depth < 0) { 753 stage_info->perfInfo.depth *= -1; 754 PetscCall(PetscEventPerfInfoResume(&stage_info->perfInfo, time, PetscLogMemory, -(stage + 2))); 755 } 756 } 757 PetscFunctionReturn(PETSC_SUCCESS); 758 } 759 760 static PetscErrorCode PetscLogHandlerStagePush_Default(PetscLogHandler h, PetscLogStage new_stage) 761 { 762 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 763 PetscLogDouble time; 764 PetscLogState state; 765 PetscLogStage current_stage; 766 PetscStagePerf *new_stage_info; 767 768 PetscFunctionBegin; 769 if (def->pause_depth > 0) PetscFunctionReturn(PETSC_SUCCESS); 770 PetscCall(PetscLogHandlerGetState(h, &state)); 771 current_stage = state->current_stage; 772 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, new_stage, &new_stage_info)); 773 PetscCall(PetscTime(&time)); 774 775 /* Record flops/time of previous stage */ 776 if (current_stage >= 0) { 777 if (PetscBTLookup(state->active, current_stage)) { 778 PetscStagePerf *current_stage_info; 779 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, current_stage, ¤t_stage_info)); 780 PetscCall(PetscEventPerfInfoToc(¤t_stage_info->perfInfo, time, PetscLogMemory, -(current_stage + 2))); 781 } 782 } 783 new_stage_info->used = PETSC_TRUE; 784 new_stage_info->perfInfo.count++; 785 new_stage_info->perfInfo.depth++; 786 /* Subtract current quantities so that we obtain the difference when we pop */ 787 if (PetscBTLookup(state->active, new_stage)) PetscCall(PetscEventPerfInfoTic(&new_stage_info->perfInfo, time, PetscLogMemory, -(new_stage + 2))); 788 PetscFunctionReturn(PETSC_SUCCESS); 789 } 790 791 static PetscErrorCode PetscLogHandlerStagePop_Default(PetscLogHandler h, PetscLogStage old_stage) 792 { 793 PetscLogHandler_Default def = (PetscLogHandler_Default)h->data; 794 PetscLogStage current_stage; 795 PetscStagePerf *old_stage_info; 796 PetscLogState state; 797 PetscLogDouble time; 798 799 PetscFunctionBegin; 800 if (def->pause_depth > 0) PetscFunctionReturn(PETSC_SUCCESS); 801 PetscCall(PetscLogHandlerGetState(h, &state)); 802 current_stage = state->current_stage; 803 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, old_stage, &old_stage_info)); 804 PetscCall(PetscTime(&time)); 805 old_stage_info->perfInfo.depth--; 806 if (PetscBTLookup(state->active, old_stage)) PetscCall(PetscEventPerfInfoToc(&old_stage_info->perfInfo, time, PetscLogMemory, -(old_stage + 2))); 807 if (current_stage >= 0) { 808 if (PetscBTLookup(state->active, current_stage)) { 809 PetscStagePerf *current_stage_info; 810 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, current_stage, ¤t_stage_info)); 811 PetscCall(PetscEventPerfInfoTic(¤t_stage_info->perfInfo, time, PetscLogMemory, -(current_stage + 2))); 812 } 813 } 814 PetscFunctionReturn(PETSC_SUCCESS); 815 } 816 817 static PetscErrorCode PetscLogHandlerStageSetVisible_Default(PetscLogHandler h, PetscLogStage stage, PetscBool is_visible) 818 { 819 PetscStagePerf *stage_info; 820 821 PetscFunctionBegin; 822 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(h->state, &stage)); 823 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, stage, &stage_info)); 824 stage_info->perfInfo.visible = is_visible; 825 PetscFunctionReturn(PETSC_SUCCESS); 826 } 827 828 static PetscErrorCode PetscLogHandlerStageGetVisible_Default(PetscLogHandler h, PetscLogStage stage, PetscBool *is_visible) 829 { 830 PetscStagePerf *stage_info; 831 832 PetscFunctionBegin; 833 if (stage < 0) PetscCall(PetscLogStateGetCurrentStage(h->state, &stage)); 834 PetscCall(PetscLogHandlerDefaultGetStageInfo(h, stage, &stage_info)); 835 *is_visible = stage_info->perfInfo.visible; 836 PetscFunctionReturn(PETSC_SUCCESS); 837 } 838 839 static PetscErrorCode PetscLogHandlerSetLogActions_Default(PetscLogHandler handler, PetscBool flag) 840 { 841 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 842 843 PetscFunctionBegin; 844 def->petsc_logActions = flag; 845 PetscFunctionReturn(PETSC_SUCCESS); 846 } 847 848 static PetscErrorCode PetscLogHandlerSetLogObjects_Default(PetscLogHandler handler, PetscBool flag) 849 { 850 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 851 852 PetscFunctionBegin; 853 def->petsc_logObjects = flag; 854 PetscFunctionReturn(PETSC_SUCCESS); 855 } 856 857 static PetscErrorCode PetscLogHandlerLogObjectState_Default(PetscLogHandler handler, PetscObject obj, const char format[], va_list Argp) 858 { 859 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 860 size_t fullLength; 861 862 PetscFunctionBegin; 863 if (def->petsc_logObjects) { 864 Object *obj_entry = NULL; 865 PetscInt objid; 866 867 PetscCall(PetscIntCast(obj->id - 1, &objid)); 868 PetscCall(PetscLogObjectArrayGetRef(def->petsc_objects, objid, &obj_entry)); 869 PetscCall(PetscVSNPrintf(obj_entry->info, 64, format, &fullLength, Argp)); 870 } 871 PetscFunctionReturn(PETSC_SUCCESS); 872 } 873 874 static PetscErrorCode PetscLogHandlerGetNumObjects_Default(PetscLogHandler handler, PetscInt *num_objects) 875 { 876 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 877 878 PetscFunctionBegin; 879 PetscCall(PetscLogObjectArrayGetSize(def->petsc_objects, num_objects, NULL)); 880 PetscFunctionReturn(PETSC_SUCCESS); 881 } 882 883 static PetscErrorCode PetscLogHandlerDump_Default(PetscLogHandler handler, const char sname[]) 884 { 885 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 886 FILE *fd; 887 char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN]; 888 PetscLogDouble flops, _TotalTime; 889 PetscMPIInt rank; 890 int curStage; 891 PetscLogState state; 892 PetscInt num_events; 893 PetscLogEvent event; 894 895 PetscFunctionBegin; 896 /* Calculate the total elapsed time */ 897 PetscCall(PetscTime(&_TotalTime)); 898 _TotalTime -= petsc_BaseTime; 899 /* Open log file */ 900 PetscCallMPI(MPI_Comm_rank(PetscObjectComm((PetscObject)handler), &rank)); 901 PetscCall(PetscSNPrintf(file, PETSC_STATIC_ARRAY_LENGTH(file), "%s.%d", sname && sname[0] ? sname : "Log", rank)); 902 PetscCall(PetscFixFilename(file, fname)); 903 PetscCall(PetscFOpen(PETSC_COMM_SELF, fname, "w", &fd)); 904 PetscCheck(!(rank == 0) || !(!fd), PETSC_COMM_SELF, PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname); 905 /* Output totals */ 906 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime)); 907 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Clock Resolution %g\n", 0.0)); 908 /* Output actions */ 909 if (def->petsc_logActions) { 910 PetscInt num_actions; 911 PetscCall(PetscLogActionArrayGetSize(def->petsc_actions, &num_actions, NULL)); 912 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Actions accomplished %" PetscInt_FMT "\n", num_actions)); 913 for (int a = 0; a < num_actions; a++) { 914 Action *action; 915 916 PetscCall(PetscLogActionArrayGetRef(def->petsc_actions, a, &action)); 917 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "%g %d %d %d %" PetscInt64_FMT " %" PetscInt64_FMT " %" PetscInt64_FMT " %g %g %g\n", action->time, action->action, action->event, action->classid, action->id1, action->id2, action->id3, action->flops, 918 action->mem, action->maxmem)); 919 } 920 } 921 /* Output objects */ 922 if (def->petsc_logObjects) { 923 PetscInt num_objects; 924 925 PetscCall(PetscLogObjectArrayGetSize(def->petsc_objects, &num_objects, NULL)); 926 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Objects created %d destroyed %d\n", def->petsc_numObjectsCreated, def->petsc_numObjectsDestroyed)); 927 for (int o = 0; o < num_objects; o++) { 928 Object *object = NULL; 929 930 PetscCall(PetscLogObjectArrayGetRef(def->petsc_objects, o, &object)); 931 if (object->parent != -1) continue; // object with this id wasn't logged, probably a PetscLogHandler 932 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Parent ID: %d Memory: %d\n", object->parent, (int)object->mem)); 933 if (!object->name[0]) { 934 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "No Name\n")); 935 } else { 936 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Name: %s\n", object->name)); 937 } 938 if (!object->info[0]) { 939 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "No Info\n")); 940 } else { 941 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Info: %s\n", object->info)); 942 } 943 } 944 } 945 /* Output events */ 946 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "Event log:\n")); 947 PetscCall(PetscLogHandlerGetState(handler, &state)); 948 PetscCall(PetscLogStateGetNumEvents(state, &num_events)); 949 PetscCall(PetscLogStateGetCurrentStage(state, &curStage)); 950 for (event = 0; event < num_events; event++) { 951 PetscEventPerfInfo *event_info; 952 953 PetscCall(PetscLogHandlerGetEventPerfInfo_Default(handler, curStage, event, &event_info)); 954 if (event_info->time != 0.0) flops = event_info->flops / event_info->time; 955 else flops = 0.0; 956 PetscCall(PetscFPrintf(PETSC_COMM_SELF, fd, "%d %16d %16g %16g %16g\n", event, event_info->count, event_info->flops, event_info->time, flops)); 957 } 958 PetscCall(PetscFClose(PETSC_COMM_SELF, fd)); 959 PetscFunctionReturn(PETSC_SUCCESS); 960 } 961 962 /* 963 PetscLogView_Detailed - Each process prints the times for its own events 964 965 */ 966 static PetscErrorCode PetscLogHandlerView_Default_Detailed(PetscLogHandler handler, PetscViewer viewer) 967 { 968 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 969 PetscLogDouble locTotalTime, numRed, maxMem; 970 PetscInt numStages, numEvents; 971 MPI_Comm comm = PetscObjectComm((PetscObject)viewer); 972 PetscMPIInt rank, size; 973 PetscLogGlobalNames global_stages, global_events; 974 PetscLogState state; 975 PetscEventPerfInfo zero_info; 976 977 PetscFunctionBegin; 978 PetscCall(PetscLogHandlerGetState(handler, &state)); 979 PetscCallMPI(MPI_Comm_size(comm, &size)); 980 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 981 /* Must preserve reduction count before we go on */ 982 numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 983 /* Get the total elapsed time */ 984 PetscCall(PetscTime(&locTotalTime)); 985 locTotalTime -= petsc_BaseTime; 986 PetscCall(PetscViewerASCIIPrintf(viewer, "size = %d\n", size)); 987 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalTimes = {}\n")); 988 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMessages = {}\n")); 989 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMessageLens = {}\n")); 990 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalReductions = {}\n")); 991 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalFlop = {}\n")); 992 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalObjects = {}\n")); 993 PetscCall(PetscViewerASCIIPrintf(viewer, "LocalMemory = {}\n")); 994 PetscCall(PetscLogRegistryCreateGlobalStageNames(comm, state->registry, &global_stages)); 995 PetscCall(PetscLogRegistryCreateGlobalEventNames(comm, state->registry, &global_events)); 996 PetscCall(PetscLogGlobalNamesGetSize(global_stages, NULL, &numStages)); 997 PetscCall(PetscLogGlobalNamesGetSize(global_events, NULL, &numEvents)); 998 PetscCall(PetscMemzero(&zero_info, sizeof(zero_info))); 999 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages = {}\n")); 1000 for (PetscInt stage = 0; stage < numStages; stage++) { 1001 PetscInt stage_id; 1002 const char *stage_name; 1003 1004 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1005 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1006 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"] = {}\n", stage_name)); 1007 PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"][\"summary\"] = {}\n", stage_name)); 1008 for (PetscInt event = 0; event < numEvents; event++) { 1009 PetscEventPerfInfo *eventInfo = &zero_info; 1010 PetscBool is_zero = PETSC_FALSE; 1011 PetscInt event_id; 1012 const char *event_name; 1013 1014 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_events, event, &event_id)); 1015 PetscCall(PetscLogGlobalNamesGlobalGetName(global_events, event, &event_name)); 1016 if (event_id >= 0 && stage_id >= 0) PetscCall(PetscLogHandlerGetEventPerfInfo_Default(handler, stage_id, event_id, &eventInfo)); 1017 is_zero = eventInfo->count == 0 ? PETSC_TRUE : PETSC_FALSE; 1018 PetscCallMPI(MPIU_Allreduce(MPI_IN_PLACE, &is_zero, 1, MPI_C_BOOL, MPI_LAND, comm)); 1019 if (!is_zero) PetscCall(PetscViewerASCIIPrintf(viewer, "Stages[\"%s\"][\"%s\"] = {}\n", stage_name, event_name)); 1020 } 1021 } 1022 PetscCall(PetscMallocGetMaximumUsage(&maxMem)); 1023 PetscCall(PetscViewerASCIIPushSynchronized(viewer)); 1024 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalTimes[%d] = %g\n", rank, locTotalTime)); 1025 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMessages[%d] = %g\n", rank, petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct)); 1026 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMessageLens[%d] = %g\n", rank, petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len)); 1027 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalReductions[%d] = %g\n", rank, numRed)); 1028 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalFlop[%d] = %g\n", rank, petsc_TotalFlops)); 1029 { 1030 PetscInt num_objects; 1031 1032 PetscCall(PetscLogObjectArrayGetSize(def->petsc_objects, &num_objects, NULL)); 1033 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalObjects[%d] = %" PetscInt_FMT "\n", rank, num_objects)); 1034 } 1035 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "LocalMemory[%d] = %g\n", rank, maxMem)); 1036 PetscCall(PetscViewerFlush(viewer)); 1037 for (PetscInt stage = 0; stage < numStages; stage++) { 1038 PetscEventPerfInfo *stage_perf_info = &zero_info; 1039 PetscInt stage_id; 1040 const char *stage_name; 1041 1042 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1043 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1044 if (stage_id >= 0) { 1045 PetscStagePerf *stage_info; 1046 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage_id, &stage_info)); 1047 stage_perf_info = &stage_info->perfInfo; 1048 } 1049 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n", stage_name, rank, stage_perf_info->time, 1050 stage_perf_info->numMessages, stage_perf_info->messageLength, stage_perf_info->numReductions, stage_perf_info->flops)); 1051 for (PetscInt event = 0; event < numEvents; event++) { 1052 PetscEventPerfInfo *eventInfo = &zero_info; 1053 PetscBool is_zero = PETSC_FALSE; 1054 PetscInt event_id; 1055 const char *event_name; 1056 1057 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_events, event, &event_id)); 1058 PetscCall(PetscLogGlobalNamesGlobalGetName(global_events, event, &event_name)); 1059 if (event_id >= 0 && stage_id >= 0) PetscCall(PetscLogHandlerGetEventPerfInfo_Default(handler, stage_id, event_id, &eventInfo)); 1060 is_zero = eventInfo->count == 0 ? PETSC_TRUE : PETSC_FALSE; 1061 PetscCall(PetscMemcmp(eventInfo, &zero_info, sizeof(zero_info), &is_zero)); 1062 PetscCallMPI(MPIU_Allreduce(MPI_IN_PLACE, &is_zero, 1, MPI_C_BOOL, MPI_LAND, comm)); 1063 if (!is_zero) { 1064 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %d, \"time\" : %g, \"syncTime\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g", stage_name, event_name, rank, 1065 eventInfo->count, eventInfo->time, eventInfo->syncTime, eventInfo->numMessages, eventInfo->messageLength, eventInfo->numReductions, eventInfo->flops)); 1066 if (eventInfo->dof[0] >= 0.) { 1067 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", \"dof\" : [")); 1068 for (PetscInt d = 0; d < 8; ++d) { 1069 if (d > 0) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", ")); 1070 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->dof[d])); 1071 } 1072 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "]")); 1073 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", \"error\" : [")); 1074 for (PetscInt e = 0; e < 8; ++e) { 1075 if (e > 0) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ", ")); 1076 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->errors[e])); 1077 } 1078 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "]")); 1079 } 1080 } 1081 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "}\n")); 1082 } 1083 } 1084 PetscCall(PetscViewerFlush(viewer)); 1085 PetscCall(PetscViewerASCIIPopSynchronized(viewer)); 1086 PetscCall(PetscLogGlobalNamesDestroy(&global_events)); 1087 PetscCall(PetscLogGlobalNamesDestroy(&global_stages)); 1088 PetscFunctionReturn(PETSC_SUCCESS); 1089 } 1090 1091 /* 1092 PetscLogView_CSV - Each process prints the times for its own events in Comma-Separated Value Format 1093 */ 1094 static PetscErrorCode PetscLogHandlerView_Default_CSV(PetscLogHandler handler, PetscViewer viewer) 1095 { 1096 PetscLogDouble locTotalTime, maxMem; 1097 PetscInt numStages, numEvents, stage, event; 1098 MPI_Comm comm = PetscObjectComm((PetscObject)viewer); 1099 PetscMPIInt rank, size; 1100 PetscLogGlobalNames global_stages, global_events; 1101 PetscLogState state; 1102 PetscEventPerfInfo zero_info; 1103 1104 PetscFunctionBegin; 1105 PetscCall(PetscLogHandlerGetState(handler, &state)); 1106 PetscCallMPI(MPI_Comm_size(comm, &size)); 1107 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 1108 /* Must preserve reduction count before we go on */ 1109 /* Get the total elapsed time */ 1110 PetscCall(PetscTime(&locTotalTime)); 1111 locTotalTime -= petsc_BaseTime; 1112 PetscCall(PetscMallocGetMaximumUsage(&maxMem)); 1113 PetscCall(PetscLogRegistryCreateGlobalStageNames(comm, state->registry, &global_stages)); 1114 PetscCall(PetscLogRegistryCreateGlobalEventNames(comm, state->registry, &global_events)); 1115 PetscCall(PetscLogGlobalNamesGetSize(global_stages, NULL, &numStages)); 1116 PetscCall(PetscLogGlobalNamesGetSize(global_events, NULL, &numEvents)); 1117 PetscCall(PetscMemzero(&zero_info, sizeof(zero_info))); 1118 PetscCall(PetscViewerASCIIPushSynchronized(viewer)); 1119 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)); 1120 PetscCall(PetscViewerFlush(viewer)); 1121 for (stage = 0; stage < numStages; stage++) { 1122 PetscEventPerfInfo *stage_perf_info; 1123 PetscInt stage_id; 1124 const char *stage_name; 1125 1126 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1127 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1128 stage_perf_info = &zero_info; 1129 if (stage_id >= 0) { 1130 PetscStagePerf *stage_info; 1131 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage_id, &stage_info)); 1132 stage_perf_info = &stage_info->perfInfo; 1133 } 1134 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%s,summary,%d,1,%g,%g,%g,%g,%g\n", stage_name, rank, stage_perf_info->time, stage_perf_info->numMessages, stage_perf_info->messageLength, stage_perf_info->numReductions, stage_perf_info->flops)); 1135 for (event = 0; event < numEvents; event++) { 1136 PetscEventPerfInfo *eventInfo = &zero_info; 1137 PetscBool is_zero = PETSC_FALSE; 1138 PetscInt event_id; 1139 const char *event_name; 1140 1141 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_events, event, &event_id)); 1142 PetscCall(PetscLogGlobalNamesGlobalGetName(global_events, event, &event_name)); 1143 if (event_id >= 0 && stage_id >= 0) PetscCall(PetscLogHandlerGetEventPerfInfo_Default(handler, stage_id, event_id, &eventInfo)); 1144 PetscCall(PetscMemcmp(eventInfo, &zero_info, sizeof(zero_info), &is_zero)); 1145 PetscCallMPI(MPIU_Allreduce(MPI_IN_PLACE, &is_zero, 1, MPI_C_BOOL, MPI_LAND, comm)); 1146 if (!is_zero) { 1147 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "%s,%s,%d,%d,%g,%g,%g,%g,%g", stage_name, event_name, rank, eventInfo->count, eventInfo->time, eventInfo->numMessages, eventInfo->messageLength, eventInfo->numReductions, eventInfo->flops)); 1148 if (eventInfo->dof[0] >= 0.) { 1149 for (PetscInt d = 0; d < 8; ++d) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->dof[d])); 1150 for (PetscInt e = 0; e < 8; ++e) PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->errors[e])); 1151 } 1152 } 1153 PetscCall(PetscViewerASCIISynchronizedPrintf(viewer, "\n")); 1154 } 1155 } 1156 PetscCall(PetscViewerFlush(viewer)); 1157 PetscCall(PetscViewerASCIIPopSynchronized(viewer)); 1158 PetscCall(PetscLogGlobalNamesDestroy(&global_stages)); 1159 PetscCall(PetscLogGlobalNamesDestroy(&global_events)); 1160 PetscFunctionReturn(PETSC_SUCCESS); 1161 } 1162 1163 static PetscErrorCode PetscLogViewWarnSync(PetscViewer viewer) 1164 { 1165 PetscFunctionBegin; 1166 if (!PetscLogSyncOn) PetscFunctionReturn(PETSC_SUCCESS); 1167 PetscCall(PetscViewerASCIIPrintf(viewer, "\n\n")); 1168 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n")); 1169 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1170 PetscCall(PetscViewerASCIIPrintf(viewer, " # WARNING!!! #\n")); 1171 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1172 PetscCall(PetscViewerASCIIPrintf(viewer, " # This program was run with logging synchronization. #\n")); 1173 PetscCall(PetscViewerASCIIPrintf(viewer, " # This option provides more meaningful imbalance #\n")); 1174 PetscCall(PetscViewerASCIIPrintf(viewer, " # figures at the expense of slowing things down and #\n")); 1175 PetscCall(PetscViewerASCIIPrintf(viewer, " # providing a distorted view of the overall runtime. #\n")); 1176 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1177 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n\n\n")); 1178 PetscFunctionReturn(PETSC_SUCCESS); 1179 } 1180 1181 static PetscErrorCode PetscLogViewWarnDebugging(PetscViewer viewer) 1182 { 1183 PetscFunctionBegin; 1184 if (PetscDefined(USE_DEBUG)) { 1185 PetscCall(PetscViewerASCIIPrintf(viewer, "\n\n")); 1186 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n")); 1187 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1188 PetscCall(PetscViewerASCIIPrintf(viewer, " # WARNING!!! #\n")); 1189 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1190 PetscCall(PetscViewerASCIIPrintf(viewer, " # This code was compiled with a debugging option. #\n")); 1191 PetscCall(PetscViewerASCIIPrintf(viewer, " # To get timing results run ./configure #\n")); 1192 PetscCall(PetscViewerASCIIPrintf(viewer, " # using --with-debugging=no, the performance will #\n")); 1193 PetscCall(PetscViewerASCIIPrintf(viewer, " # be generally two or three times faster. #\n")); 1194 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1195 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n\n\n")); 1196 } 1197 PetscFunctionReturn(PETSC_SUCCESS); 1198 } 1199 1200 static PetscErrorCode PetscLogViewWarnNoGpuAwareMpi(PetscViewer viewer) 1201 { 1202 #if defined(PETSC_HAVE_DEVICE) 1203 PetscMPIInt size; 1204 PetscBool deviceInitialized = PETSC_FALSE; 1205 1206 PetscFunctionBegin; 1207 PetscCallMPI(MPI_Comm_size(PetscObjectComm((PetscObject)viewer), &size)); 1208 for (int i = PETSC_DEVICE_HOST + 1; i < PETSC_DEVICE_MAX; ++i) { 1209 const PetscDeviceType dtype = PetscDeviceTypeCast(i); 1210 if (PetscDeviceInitialized(dtype)) { /* a non-host device was initialized */ 1211 deviceInitialized = PETSC_TRUE; 1212 break; 1213 } 1214 } 1215 /* the last condition says PETSc is configured with device but it is a pure CPU run, so don't print misleading warnings */ 1216 if (use_gpu_aware_mpi || size == 1 || !deviceInitialized) PetscFunctionReturn(PETSC_SUCCESS); 1217 PetscCall(PetscViewerASCIIPrintf(viewer, "\n\n")); 1218 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n")); 1219 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1220 PetscCall(PetscViewerASCIIPrintf(viewer, " # WARNING!!! #\n")); 1221 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1222 PetscCall(PetscViewerASCIIPrintf(viewer, " # This code was compiled with GPU support and you've #\n")); 1223 PetscCall(PetscViewerASCIIPrintf(viewer, " # created PETSc/GPU objects, but you intentionally #\n")); 1224 PetscCall(PetscViewerASCIIPrintf(viewer, " # used -use_gpu_aware_mpi 0, requiring PETSc to copy #\n")); 1225 PetscCall(PetscViewerASCIIPrintf(viewer, " # additional data between the GPU and CPU. To obtain #\n")); 1226 PetscCall(PetscViewerASCIIPrintf(viewer, " # meaningful timing results on multi-rank runs, use #\n")); 1227 PetscCall(PetscViewerASCIIPrintf(viewer, " # GPU-aware MPI instead. #\n")); 1228 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1229 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n\n\n")); 1230 PetscFunctionReturn(PETSC_SUCCESS); 1231 #else 1232 return PETSC_SUCCESS; 1233 #endif 1234 } 1235 1236 static PetscErrorCode PetscLogViewWarnGpuTime(PetscViewer viewer) 1237 { 1238 #if defined(PETSC_HAVE_DEVICE) && !defined(PETSC_HAVE_KOKKOS_WITHOUT_GPU) 1239 1240 PetscFunctionBegin; 1241 if (!PetscLogGpuTimeFlag || petsc_gflops == 0) PetscFunctionReturn(PETSC_SUCCESS); 1242 PetscCall(PetscViewerASCIIPrintf(viewer, "\n\n")); 1243 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n")); 1244 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1245 PetscCall(PetscViewerASCIIPrintf(viewer, " # WARNING!!! #\n")); 1246 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1247 PetscCall(PetscViewerASCIIPrintf(viewer, " # This code was run with -log_view_gpu_time #\n")); 1248 PetscCall(PetscViewerASCIIPrintf(viewer, " # This provides accurate timing within the GPU kernels #\n")); 1249 PetscCall(PetscViewerASCIIPrintf(viewer, " # but can slow down the entire computation by a #\n")); 1250 PetscCall(PetscViewerASCIIPrintf(viewer, " # measurable amount. For fastest runs we recommend #\n")); 1251 PetscCall(PetscViewerASCIIPrintf(viewer, " # not using this option. #\n")); 1252 PetscCall(PetscViewerASCIIPrintf(viewer, " # #\n")); 1253 PetscCall(PetscViewerASCIIPrintf(viewer, " ##########################################################\n\n\n")); 1254 PetscFunctionReturn(PETSC_SUCCESS); 1255 #else 1256 return PETSC_SUCCESS; 1257 #endif 1258 } 1259 1260 PETSC_INTERN int PetscGlobalArgc; 1261 PETSC_INTERN char **PetscGlobalArgs; 1262 1263 static PetscErrorCode PetscLogHandlerView_Default_Info(PetscLogHandler handler, PetscViewer viewer) 1264 { 1265 PetscLogHandler_Default def = (PetscLogHandler_Default)handler->data; 1266 char arch[128], hostname[128], username[128], pname[PETSC_MAX_PATH_LEN], date[128]; 1267 PetscLogDouble locTotalTime, TotalTime, TotalFlops; 1268 PetscLogDouble numMessages, messageLength, avgMessLen, numReductions; 1269 PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red; 1270 PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed; 1271 PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed; 1272 PetscLogDouble min, max, tot, ratio, avg, x, y; 1273 PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratC, totm, totml, totr, mal, malmax, emalmax; 1274 #if defined(PETSC_HAVE_DEVICE) 1275 PetscLogEvent KSP_Solve, SNES_Solve, TS_Step, TAO_Solve; /* These need to be fixed to be some events registered with certain objects */ 1276 PetscLogDouble cct, gct, csz, gsz, gmaxt, gflops, gflopr, fracgflops; 1277 #endif 1278 PetscMPIInt minC, maxC; 1279 PetscMPIInt size, rank; 1280 PetscBool *localStageUsed, *stageUsed; 1281 PetscBool *localStageVisible, *stageVisible; 1282 PetscInt numStages, numEvents; 1283 int stage, oclass; 1284 PetscLogEvent event; 1285 char version[256]; 1286 MPI_Comm comm; 1287 #if defined(PETSC_HAVE_DEVICE) && !defined(PETSC_HAVE_KOKKOS_WITHOUT_GPU) 1288 PetscInt64 nas = 0x7FF0000000000002; 1289 #endif 1290 PetscLogGlobalNames global_stages, global_events; 1291 PetscEventPerfInfo zero_info; 1292 PetscLogState state; 1293 1294 PetscFunctionBegin; 1295 PetscCall(PetscLogHandlerGetState(handler, &state)); 1296 PetscCall(PetscFPTrapPush(PETSC_FP_TRAP_OFF)); 1297 PetscCall(PetscObjectGetComm((PetscObject)viewer, &comm)); 1298 PetscCallMPI(MPI_Comm_size(comm, &size)); 1299 PetscCallMPI(MPI_Comm_rank(comm, &rank)); 1300 /* Get the total elapsed time */ 1301 PetscCall(PetscTime(&locTotalTime)); 1302 locTotalTime -= petsc_BaseTime; 1303 1304 PetscCall(PetscViewerASCIIPrintf(viewer, "****************************************************************************************************************************************************************\n")); 1305 PetscCall(PetscViewerASCIIPrintf(viewer, "*** WIDEN YOUR WINDOW TO 160 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n")); 1306 PetscCall(PetscViewerASCIIPrintf(viewer, "****************************************************************************************************************************************************************\n")); 1307 PetscCall(PetscViewerASCIIPrintf(viewer, "\n------------------------------------------------------------------ PETSc Performance Summary: ------------------------------------------------------------------\n\n")); 1308 PetscCall(PetscLogViewWarnSync(viewer)); 1309 PetscCall(PetscLogViewWarnDebugging(viewer)); 1310 PetscCall(PetscLogViewWarnNoGpuAwareMpi(viewer)); 1311 PetscCall(PetscLogViewWarnGpuTime(viewer)); 1312 PetscCall(PetscGetArchType(arch, sizeof(arch))); 1313 PetscCall(PetscGetHostName(hostname, sizeof(hostname))); 1314 PetscCall(PetscGetUserName(username, sizeof(username))); 1315 PetscCall(PetscGetProgramName(pname, sizeof(pname))); 1316 PetscCall(PetscGetDate(date, sizeof(date))); 1317 PetscCall(PetscGetVersion(version, sizeof(version))); 1318 1319 #if defined(PETSC_HAVE_CUPM) 1320 const char *cupm = PetscDefined(HAVE_CUDA) ? "CUDA" : "HIP"; 1321 if (PetscDeviceCUPMRuntimeArch) 1322 PetscCall(PetscViewerASCIIPrintf(viewer, "%s on a %s named %s with %d process%s and %s architecture %d, by %s on %s\n", pname, arch, hostname, size, size > 1 ? "es" : "", cupm, PetscDeviceCUPMRuntimeArch, username, date)); 1323 else 1324 #endif 1325 PetscCall(PetscViewerASCIIPrintf(viewer, "%s on a %s named %s with %d process%s, by %s on %s\n", pname, arch, hostname, size, size > 1 ? "es" : "", username, date)); 1326 1327 #if defined(PETSC_HAVE_OPENMP) 1328 PetscCall(PetscViewerASCIIPrintf(viewer, "Using %" PetscInt_FMT " OpenMP threads\n", PetscNumOMPThreads)); 1329 #endif 1330 PetscCall(PetscViewerASCIIPrintf(viewer, "Using %s\n", version)); 1331 1332 /* Must preserve reduction count before we go on */ 1333 red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1334 1335 /* Calculate summary information */ 1336 PetscCall(PetscViewerASCIIPrintf(viewer, "\n Max Max/Min Avg Total\n")); 1337 /* Time */ 1338 PetscCallMPI(MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1339 PetscCallMPI(MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1340 PetscCallMPI(MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1341 avg = tot / ((PetscLogDouble)size); 1342 if (min != 0.0) ratio = max / min; 1343 else ratio = 0.0; 1344 PetscCall(PetscViewerASCIIPrintf(viewer, "Time (sec): %5.3e %7.3f %5.3e\n", max, ratio, avg)); 1345 TotalTime = tot; 1346 /* Objects */ 1347 { 1348 PetscInt num_objects; 1349 1350 PetscCall(PetscLogObjectArrayGetSize(def->petsc_objects, &num_objects, NULL)); 1351 avg = (PetscLogDouble)num_objects; 1352 } 1353 PetscCallMPI(MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1354 PetscCallMPI(MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1355 PetscCallMPI(MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1356 avg = tot / ((PetscLogDouble)size); 1357 if (min != 0.0) ratio = max / min; 1358 else ratio = 0.0; 1359 PetscCall(PetscViewerASCIIPrintf(viewer, "Objects: %5.3e %7.3f %5.3e\n", max, ratio, avg)); 1360 /* Flops */ 1361 PetscCallMPI(MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1362 PetscCallMPI(MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1363 PetscCallMPI(MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1364 avg = tot / ((PetscLogDouble)size); 1365 if (min != 0.0) ratio = max / min; 1366 else ratio = 0.0; 1367 PetscCall(PetscViewerASCIIPrintf(viewer, "Flops: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 1368 TotalFlops = tot; 1369 /* Flops/sec -- Must talk to Barry here */ 1370 if (locTotalTime != 0.0) flops = petsc_TotalFlops / locTotalTime; 1371 else flops = 0.0; 1372 PetscCallMPI(MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1373 PetscCallMPI(MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1374 PetscCallMPI(MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1375 avg = tot / ((PetscLogDouble)size); 1376 if (min != 0.0) ratio = max / min; 1377 else ratio = 0.0; 1378 PetscCall(PetscViewerASCIIPrintf(viewer, "Flops/sec: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 1379 /* Memory */ 1380 PetscCall(PetscMallocGetMaximumUsage(&mem)); 1381 if (mem > 0.0) { 1382 PetscCallMPI(MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1383 PetscCallMPI(MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1384 PetscCallMPI(MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1385 avg = tot / ((PetscLogDouble)size); 1386 if (min != 0.0) ratio = max / min; 1387 else ratio = 0.0; 1388 PetscCall(PetscViewerASCIIPrintf(viewer, "Memory (bytes): %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 1389 } 1390 /* Messages */ 1391 mess = 0.5 * (petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct); 1392 PetscCallMPI(MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1393 PetscCallMPI(MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1394 PetscCallMPI(MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1395 avg = tot / ((PetscLogDouble)size); 1396 if (min != 0.0) ratio = max / min; 1397 else ratio = 0.0; 1398 PetscCall(PetscViewerASCIIPrintf(viewer, "MPI Msg Count: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 1399 numMessages = tot; 1400 /* Message Lengths */ 1401 mess = 0.5 * (petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len); 1402 PetscCallMPI(MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1403 PetscCallMPI(MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1404 PetscCallMPI(MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1405 if (numMessages != 0) avg = tot / numMessages; 1406 else avg = 0.0; 1407 if (min != 0.0) ratio = max / min; 1408 else ratio = 0.0; 1409 PetscCall(PetscViewerASCIIPrintf(viewer, "MPI Msg Len (bytes): %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot)); 1410 messageLength = tot; 1411 /* Reductions */ 1412 PetscCallMPI(MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1413 PetscCallMPI(MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1414 PetscCallMPI(MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1415 if (min != 0.0) ratio = max / min; 1416 else ratio = 0.0; 1417 PetscCall(PetscViewerASCIIPrintf(viewer, "MPI Reductions: %5.3e %7.3f\n", max, ratio)); 1418 numReductions = red; /* wrong because uses count from process zero */ 1419 PetscCall(PetscViewerASCIIPrintf(viewer, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n")); 1420 PetscCall(PetscViewerASCIIPrintf(viewer, " e.g., VecAXPY() for real vectors of length N --> 2N flops\n")); 1421 PetscCall(PetscViewerASCIIPrintf(viewer, " and VecAXPY() for complex vectors of length N --> 8N flops\n")); 1422 1423 PetscCall(PetscLogRegistryCreateGlobalStageNames(comm, state->registry, &global_stages)); 1424 PetscCall(PetscLogRegistryCreateGlobalEventNames(comm, state->registry, &global_events)); 1425 PetscCall(PetscLogGlobalNamesGetSize(global_stages, NULL, &numStages)); 1426 PetscCall(PetscLogGlobalNamesGetSize(global_events, NULL, &numEvents)); 1427 PetscCall(PetscMemzero(&zero_info, sizeof(zero_info))); 1428 PetscCall(PetscMalloc1(numStages, &localStageUsed)); 1429 PetscCall(PetscMalloc1(numStages, &stageUsed)); 1430 PetscCall(PetscMalloc1(numStages, &localStageVisible)); 1431 PetscCall(PetscMalloc1(numStages, &stageVisible)); 1432 if (numStages > 0) { 1433 for (stage = 0; stage < numStages; stage++) { 1434 PetscInt stage_id; 1435 1436 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1437 if (stage_id >= 0) { 1438 PetscStagePerf *stage_info; 1439 1440 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage, &stage_info)); 1441 localStageUsed[stage] = stage_info->used; 1442 localStageVisible[stage] = stage_info->perfInfo.visible; 1443 } else { 1444 localStageUsed[stage] = PETSC_FALSE; 1445 localStageVisible[stage] = PETSC_TRUE; 1446 } 1447 } 1448 PetscCallMPI(MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPI_C_BOOL, MPI_LOR, comm)); 1449 PetscCallMPI(MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPI_C_BOOL, MPI_LAND, comm)); 1450 for (stage = 0; stage < numStages; stage++) { 1451 if (stageUsed[stage] && stageVisible[stage]) { 1452 PetscCall(PetscViewerASCIIPrintf(viewer, "\nSummary of Stages: ----- Time ------ ----- Flop ------ --- Messages --- -- Message Lengths -- -- Reductions --\n")); 1453 PetscCall(PetscViewerASCIIPrintf(viewer, " Avg %%Total Avg %%Total Count %%Total Avg %%Total Count %%Total\n")); 1454 break; 1455 } 1456 } 1457 for (stage = 0; stage < numStages; stage++) { 1458 PetscInt stage_id; 1459 PetscEventPerfInfo *stage_info; 1460 const char *stage_name; 1461 1462 if (!(stageUsed[stage] && stageVisible[stage])) continue; 1463 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1464 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1465 stage_info = &zero_info; 1466 if (localStageUsed[stage]) { 1467 PetscStagePerf *stage_perf_info; 1468 1469 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage, &stage_perf_info)); 1470 stage_info = &stage_perf_info->perfInfo; 1471 } 1472 PetscCallMPI(MPIU_Allreduce(&stage_info->time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1473 PetscCallMPI(MPIU_Allreduce(&stage_info->flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1474 PetscCallMPI(MPIU_Allreduce(&stage_info->numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1475 PetscCallMPI(MPIU_Allreduce(&stage_info->messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1476 PetscCallMPI(MPIU_Allreduce(&stage_info->numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1477 mess *= 0.5; 1478 messLen *= 0.5; 1479 red /= size; 1480 if (TotalTime != 0.0) fracTime = stageTime / TotalTime; 1481 else fracTime = 0.0; 1482 if (TotalFlops != 0.0) fracFlops = flops / TotalFlops; 1483 else fracFlops = 0.0; 1484 /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */ 1485 if (numMessages != 0.0) fracMessages = mess / numMessages; 1486 else fracMessages = 0.0; 1487 if (mess != 0.0) avgMessLen = messLen / mess; 1488 else avgMessLen = 0.0; 1489 if (messageLength != 0.0) fracLength = messLen / messageLength; 1490 else fracLength = 0.0; 1491 if (numReductions != 0.0) fracReductions = red / numReductions; 1492 else fracReductions = 0.0; 1493 PetscCall(PetscViewerASCIIPrintf(viewer, "%2d: %15s: %6.4e %5.1f%% %6.4e %5.1f%% %5.3e %5.1f%% %5.3e %5.1f%% %5.3e %5.1f%%\n", stage, stage_name, stageTime / size, 100.0 * fracTime, flops, 100.0 * fracFlops, mess, 100.0 * fracMessages, avgMessLen, 100.0 * fracLength, red, 100.0 * fracReductions)); 1494 } 1495 } 1496 1497 PetscCall(PetscViewerASCIIPrintf(viewer, "\n------------------------------------------------------------------------------------------------------------------------\n")); 1498 PetscCall(PetscViewerASCIIPrintf(viewer, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n")); 1499 PetscCall(PetscViewerASCIIPrintf(viewer, "Phase summary info:\n")); 1500 PetscCall(PetscViewerASCIIPrintf(viewer, " Count: number of times phase was executed\n")); 1501 PetscCall(PetscViewerASCIIPrintf(viewer, " Time and Flop: Max - maximum over all processes\n")); 1502 PetscCall(PetscViewerASCIIPrintf(viewer, " Ratio - ratio of maximum to minimum over all processes\n")); 1503 PetscCall(PetscViewerASCIIPrintf(viewer, " Mess: number of messages sent\n")); 1504 PetscCall(PetscViewerASCIIPrintf(viewer, " AvgLen: average message length (bytes)\n")); 1505 PetscCall(PetscViewerASCIIPrintf(viewer, " Reduct: number of global reductions\n")); 1506 PetscCall(PetscViewerASCIIPrintf(viewer, " Global: entire computation\n")); 1507 PetscCall(PetscViewerASCIIPrintf(viewer, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n")); 1508 PetscCall(PetscViewerASCIIPrintf(viewer, " %%T - percent time in this phase %%F - percent flop in this phase\n")); 1509 PetscCall(PetscViewerASCIIPrintf(viewer, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n")); 1510 PetscCall(PetscViewerASCIIPrintf(viewer, " %%R - percent reductions in this phase\n")); 1511 PetscCall(PetscViewerASCIIPrintf(viewer, " Total Mflop/s: 1e-6 * (sum of flop over all processes)/(max time over all processes)\n")); 1512 if (PetscLogMemory) { 1513 PetscCall(PetscViewerASCIIPrintf(viewer, " Memory usage is summed over all MPI processes, it is given in mega-bytes\n")); 1514 PetscCall(PetscViewerASCIIPrintf(viewer, " Malloc Mbytes: Memory allocated and kept during event (sum over all calls to event). May be negative\n")); 1515 PetscCall(PetscViewerASCIIPrintf(viewer, " EMalloc Mbytes: extra memory allocated during event and then freed (maximum over all calls to events). Never negative\n")); 1516 PetscCall(PetscViewerASCIIPrintf(viewer, " MMalloc Mbytes: Increase in high water mark of allocated memory (sum over all calls to event). Never negative\n")); 1517 PetscCall(PetscViewerASCIIPrintf(viewer, " RMI Mbytes: Increase in resident memory (sum over all calls to event)\n")); 1518 } 1519 #if defined(PETSC_HAVE_DEVICE) 1520 PetscCall(PetscViewerASCIIPrintf(viewer, " GPU Mflop/s: 1e-6 * (sum of flop on GPU over all processes)/(max GPU time over all processes)\n")); 1521 PetscCall(PetscViewerASCIIPrintf(viewer, " CpuToGpu Count: total number of CPU to GPU copies per processor\n")); 1522 PetscCall(PetscViewerASCIIPrintf(viewer, " CpuToGpu Size (Mbytes): 1e-6 * (total size of CPU to GPU copies per processor)\n")); 1523 PetscCall(PetscViewerASCIIPrintf(viewer, " GpuToCpu Count: total number of GPU to CPU copies per processor\n")); 1524 PetscCall(PetscViewerASCIIPrintf(viewer, " GpuToCpu Size (Mbytes): 1e-6 * (total size of GPU to CPU copies per processor)\n")); 1525 PetscCall(PetscViewerASCIIPrintf(viewer, " GPU %%F: percent flops on GPU in this event\n")); 1526 #endif 1527 PetscCall(PetscViewerASCIIPrintf(viewer, "------------------------------------------------------------------------------------------------------------------------\n")); 1528 1529 PetscCall(PetscLogViewWarnDebugging(viewer)); 1530 1531 /* Report events */ 1532 PetscCall(PetscViewerASCIIPrintf(viewer, "Event Count Time (sec) Flop --- Global --- --- Stage ---- Total")); 1533 if (PetscLogMemory) PetscCall(PetscViewerASCIIPrintf(viewer, " Malloc EMalloc MMalloc RMI")); 1534 #if defined(PETSC_HAVE_DEVICE) 1535 PetscCall(PetscViewerASCIIPrintf(viewer, " GPU - CpuToGpu - - GpuToCpu - GPU")); 1536 #endif 1537 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1538 PetscCall(PetscViewerASCIIPrintf(viewer, " Max Ratio Max Ratio Max Ratio Mess AvgLen Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s")); 1539 if (PetscLogMemory) PetscCall(PetscViewerASCIIPrintf(viewer, " Mbytes Mbytes Mbytes Mbytes")); 1540 #if defined(PETSC_HAVE_DEVICE) 1541 PetscCall(PetscViewerASCIIPrintf(viewer, " Mflop/s Count Size Count Size %%F")); 1542 #endif 1543 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1544 PetscCall(PetscViewerASCIIPrintf(viewer, "------------------------------------------------------------------------------------------------------------------------")); 1545 if (PetscLogMemory) PetscCall(PetscViewerASCIIPrintf(viewer, "-----------------------------")); 1546 #if defined(PETSC_HAVE_DEVICE) 1547 PetscCall(PetscViewerASCIIPrintf(viewer, "---------------------------------------")); 1548 #endif 1549 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1550 1551 #if defined(PETSC_HAVE_DEVICE) 1552 /* this indirect way of accessing these values is needed when PETSc is build with multiple libraries since the symbols are not in libpetscsys */ 1553 PetscCall(PetscLogStateGetEventFromName(state, "TaoSolve", &TAO_Solve)); 1554 PetscCall(PetscLogStateGetEventFromName(state, "TSStep", &TS_Step)); 1555 PetscCall(PetscLogStateGetEventFromName(state, "SNESSolve", &SNES_Solve)); 1556 PetscCall(PetscLogStateGetEventFromName(state, "KSPSolve", &KSP_Solve)); 1557 #endif 1558 1559 for (stage = 0; stage < numStages; stage++) { 1560 PetscInt stage_id; 1561 PetscEventPerfInfo *stage_info; 1562 const char *stage_name; 1563 1564 if (!(stageVisible[stage] && stageUsed[stage])) continue; 1565 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_stages, stage, &stage_id)); 1566 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1567 PetscCall(PetscViewerASCIIPrintf(viewer, "\n--- Event Stage %d: %s\n\n", stage, stage_name)); 1568 stage_info = &zero_info; 1569 if (localStageUsed[stage]) { 1570 PetscStagePerf *stage_perf_info; 1571 1572 PetscCall(PetscLogHandlerDefaultGetStageInfo(handler, stage_id, &stage_perf_info)); 1573 stage_info = &stage_perf_info->perfInfo; 1574 } 1575 PetscCallMPI(MPIU_Allreduce(&stage_info->time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1576 PetscCallMPI(MPIU_Allreduce(&stage_info->flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1577 PetscCallMPI(MPIU_Allreduce(&stage_info->numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1578 PetscCallMPI(MPIU_Allreduce(&stage_info->messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1579 PetscCallMPI(MPIU_Allreduce(&stage_info->numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1580 mess *= 0.5; 1581 messLen *= 0.5; 1582 red /= size; 1583 1584 for (event = 0; event < numEvents; event++) { 1585 PetscInt event_id; 1586 PetscEventPerfInfo *event_info = &zero_info; 1587 PetscBool is_zero = PETSC_FALSE; 1588 const char *event_name; 1589 1590 PetscCall(PetscLogGlobalNamesGlobalGetLocal(global_events, event, &event_id)); 1591 PetscCall(PetscLogGlobalNamesGlobalGetName(global_events, event, &event_name)); 1592 if (event_id >= 0 && stage_id >= 0) PetscCall(PetscLogHandlerGetEventPerfInfo_Default(handler, stage_id, event_id, &event_info)); 1593 PetscCall(PetscMemcmp(event_info, &zero_info, sizeof(zero_info), &is_zero)); 1594 PetscCallMPI(MPIU_Allreduce(MPI_IN_PLACE, &is_zero, 1, MPI_C_BOOL, MPI_LAND, comm)); 1595 if (!is_zero) { 1596 flopr = event_info->flops; 1597 PetscCallMPI(MPIU_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1598 PetscCallMPI(MPIU_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1599 PetscCallMPI(MPIU_Allreduce(&event_info->flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1600 PetscCallMPI(MPIU_Allreduce(&event_info->time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm)); 1601 PetscCallMPI(MPIU_Allreduce(&event_info->time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1602 PetscCallMPI(MPIU_Allreduce(&event_info->time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1603 PetscCallMPI(MPIU_Allreduce(&event_info->numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1604 PetscCallMPI(MPIU_Allreduce(&event_info->messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1605 PetscCallMPI(MPIU_Allreduce(&event_info->numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1606 PetscCallMPI(MPIU_Allreduce(&event_info->count, &minC, 1, MPI_INT, MPI_MIN, comm)); 1607 PetscCallMPI(MPIU_Allreduce(&event_info->count, &maxC, 1, MPI_INT, MPI_MAX, comm)); 1608 if (PetscLogMemory) { 1609 PetscCallMPI(MPIU_Allreduce(&event_info->memIncrease, &mem, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1610 PetscCallMPI(MPIU_Allreduce(&event_info->mallocSpace, &mal, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1611 PetscCallMPI(MPIU_Allreduce(&event_info->mallocIncrease, &malmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1612 PetscCallMPI(MPIU_Allreduce(&event_info->mallocIncreaseEvent, &emalmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1613 } 1614 #if defined(PETSC_HAVE_DEVICE) 1615 PetscCallMPI(MPIU_Allreduce(&event_info->CpuToGpuCount, &cct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1616 PetscCallMPI(MPIU_Allreduce(&event_info->GpuToCpuCount, &gct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1617 PetscCallMPI(MPIU_Allreduce(&event_info->CpuToGpuSize, &csz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1618 PetscCallMPI(MPIU_Allreduce(&event_info->GpuToCpuSize, &gsz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1619 PetscCallMPI(MPIU_Allreduce(&event_info->GpuFlops, &gflops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm)); 1620 PetscCallMPI(MPIU_Allreduce(&event_info->GpuTime, &gmaxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm)); 1621 #endif 1622 if (mint < 0.0) { 1623 PetscCall(PetscViewerASCIIPrintf(viewer, "WARNING!!! Minimum time %g over all processes 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, event_name)); 1624 mint = 0; 1625 } 1626 PetscCheck(minf >= 0.0, PETSC_COMM_SELF, PETSC_ERR_PLIB, "Minimum flop %g over all processes for %s is negative! Not possible!", minf, event_name); 1627 #if defined(PETSC_HAVE_DEVICE) && !defined(PETSC_HAVE_KOKKOS_WITHOUT_GPU) 1628 /* Put NaN into the time for all events that may not be time accurately since they may happen asynchronously on the GPU */ 1629 if (!PetscLogGpuTimeFlag && petsc_gflops > 0) { 1630 memcpy(&gmaxt, &nas, sizeof(PetscLogDouble)); 1631 if (event_id != SNES_Solve && event_id != KSP_Solve && event_id != TS_Step && event_id != TAO_Solve) { 1632 memcpy(&mint, &nas, sizeof(PetscLogDouble)); 1633 memcpy(&maxt, &nas, sizeof(PetscLogDouble)); 1634 } 1635 } 1636 #endif 1637 totm *= 0.5; 1638 totml *= 0.5; 1639 totr /= size; 1640 1641 if (maxC != 0) { 1642 if (minC != 0) ratC = ((PetscLogDouble)maxC) / minC; 1643 else ratC = 0.0; 1644 if (mint != 0.0) ratt = maxt / mint; 1645 else ratt = 0.0; 1646 if (minf != 0.0) ratf = maxf / minf; 1647 else ratf = 0.0; 1648 if (TotalTime != 0.0) fracTime = tott / TotalTime; 1649 else fracTime = 0.0; 1650 if (TotalFlops != 0.0) fracFlops = totf / TotalFlops; 1651 else fracFlops = 0.0; 1652 if (stageTime != 0.0) fracStageTime = tott / stageTime; 1653 else fracStageTime = 0.0; 1654 if (flops != 0.0) fracStageFlops = totf / flops; 1655 else fracStageFlops = 0.0; 1656 if (numMessages != 0.0) fracMess = totm / numMessages; 1657 else fracMess = 0.0; 1658 if (messageLength != 0.0) fracMessLen = totml / messageLength; 1659 else fracMessLen = 0.0; 1660 if (numReductions != 0.0) fracRed = totr / numReductions; 1661 else fracRed = 0.0; 1662 if (mess != 0.0) fracStageMess = totm / mess; 1663 else fracStageMess = 0.0; 1664 if (messLen != 0.0) fracStageMessLen = totml / messLen; 1665 else fracStageMessLen = 0.0; 1666 if (red != 0.0) fracStageRed = totr / red; 1667 else fracStageRed = 0.0; 1668 if (totm != 0.0) totml /= totm; 1669 else totml = 0.0; 1670 if (maxt != 0.0) flopr = totf / maxt; 1671 else flopr = 0.0; 1672 if (fracStageTime > 1.0 || fracStageFlops > 1.0 || fracStageMess > 1.0 || fracStageMessLen > 1.0 || fracStageRed > 1.0) { 1673 if (PetscIsNanReal(maxt)) 1674 PetscCall(PetscViewerASCIIPrintf(viewer, "%-16s %7d %3.1f n/a n/a %3.2e %3.1f %2.1e %2.1e %2.1e %2.0f %2.0f %2.0f %2.0f %2.0f Multiple stages n/a", event_name, maxC, ratC, maxf, ratf, totm, totml, totr, 100.0 * fracTime, 100.0 * fracFlops, 100.0 * fracMess, 100.0 * fracMessLen, 100.0 * fracRed)); 1675 else 1676 PetscCall(PetscViewerASCIIPrintf(viewer, "%-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", event_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)); 1677 } else { 1678 if (PetscIsNanReal(maxt)) { // when maxt, ratt, flopr are NaN (i.e., run with GPUs but without -log_view_gpu_time), replace the confusing "nan" with "n/a" 1679 PetscCall(PetscViewerASCIIPrintf(viewer, "%-16s %7d %3.1f n/a n/a %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 n/a", event_name, maxC, ratC, 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)); 1680 } else { 1681 PetscCall(PetscViewerASCIIPrintf(viewer, "%-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", event_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)); 1682 } 1683 } 1684 if (PetscLogMemory) PetscCall(PetscViewerASCIIPrintf(viewer, " %5.0f %5.0f %5.0f %5.0f", mal / 1.0e6, emalmax / 1.0e6, malmax / 1.0e6, mem / 1.0e6)); 1685 #if defined(PETSC_HAVE_DEVICE) 1686 if (totf != 0.0) fracgflops = gflops / totf; 1687 else fracgflops = 0.0; 1688 if (gmaxt != 0.0) gflopr = gflops / gmaxt; 1689 else gflopr = 0.0; 1690 if (PetscIsNanReal(gflopr)) { 1691 PetscCall(PetscViewerASCIIPrintf(viewer, " n/a %4.0f %3.2e %4.0f %3.2e % 2.0f", cct / size, csz / (1.0e6 * size), gct / size, gsz / (1.0e6 * size), 100.0 * fracgflops)); 1692 } else { 1693 PetscCall(PetscViewerASCIIPrintf(viewer, " %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)); 1694 } 1695 #endif 1696 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1697 } 1698 } 1699 } 1700 } 1701 1702 /* Memory usage and object creation */ 1703 PetscCall(PetscViewerASCIIPrintf(viewer, "------------------------------------------------------------------------------------------------------------------------")); 1704 if (PetscLogMemory) PetscCall(PetscViewerASCIIPrintf(viewer, "-----------------------------")); 1705 #if defined(PETSC_HAVE_DEVICE) 1706 PetscCall(PetscViewerASCIIPrintf(viewer, "---------------------------------------")); 1707 #endif 1708 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1709 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1710 1711 /* Right now, only stages on the first processor are reported here, meaning only objects associated with 1712 the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then 1713 stats for stages local to processor sets. 1714 */ 1715 /* We should figure out the longest object name here (now 20 characters) */ 1716 PetscCall(PetscViewerASCIIPrintf(viewer, "Object Type Creations Destructions. Reports information only for process 0.\n")); 1717 for (stage = 0; stage < numStages; stage++) { 1718 const char *stage_name; 1719 1720 PetscCall(PetscLogGlobalNamesGlobalGetName(global_stages, stage, &stage_name)); 1721 PetscCall(PetscViewerASCIIPrintf(viewer, "\n--- Event Stage %d: %s\n\n", stage, stage_name)); 1722 if (localStageUsed[stage]) { 1723 PetscInt num_classes; 1724 1725 PetscCall(PetscLogStateGetNumClasses(state, &num_classes)); 1726 for (oclass = 0; oclass < num_classes; oclass++) { 1727 PetscClassPerf *class_perf_info; 1728 1729 PetscCall(PetscLogHandlerDefaultGetClassPerf(handler, stage, oclass, &class_perf_info)); 1730 if (class_perf_info->creations > 0 || class_perf_info->destructions > 0) { 1731 PetscLogClassInfo class_reg_info; 1732 PetscBool flg = PETSC_FALSE; 1733 1734 PetscCall(PetscLogStateClassGetInfo(state, oclass, &class_reg_info)); 1735 if (stage == 0 && oclass == num_classes - 1) { 1736 if (PetscGlobalArgc == 0 && PetscGlobalArgs == NULL) { 1737 PetscCall(PetscStrcmp(class_reg_info.name, "Viewer", &flg)); 1738 if (flg && class_perf_info->creations == PetscLogNumViewersCreated && class_perf_info->destructions == PetscLogNumViewersDestroyed) continue; 1739 } 1740 } 1741 PetscCall(PetscViewerASCIIPrintf(viewer, "%20s %5d %5d\n", class_reg_info.name, class_perf_info->creations, class_perf_info->destructions)); 1742 } 1743 } 1744 } 1745 } 1746 1747 PetscCall(PetscFree(localStageUsed)); 1748 PetscCall(PetscFree(stageUsed)); 1749 PetscCall(PetscFree(localStageVisible)); 1750 PetscCall(PetscFree(stageVisible)); 1751 PetscCall(PetscLogGlobalNamesDestroy(&global_stages)); 1752 PetscCall(PetscLogGlobalNamesDestroy(&global_events)); 1753 1754 /* Information unrelated to this particular run */ 1755 PetscCall(PetscViewerASCIIPrintf(viewer, "========================================================================================================================\n")); 1756 PetscCall(PetscTime(&y)); 1757 PetscCall(PetscTime(&x)); 1758 PetscCall(PetscTime(&y)); 1759 PetscCall(PetscTime(&y)); 1760 PetscCall(PetscTime(&y)); 1761 PetscCall(PetscTime(&y)); 1762 PetscCall(PetscTime(&y)); 1763 PetscCall(PetscTime(&y)); 1764 PetscCall(PetscTime(&y)); 1765 PetscCall(PetscTime(&y)); 1766 PetscCall(PetscTime(&y)); 1767 PetscCall(PetscTime(&y)); 1768 PetscCall(PetscViewerASCIIPrintf(viewer, "Average time to get PetscTime(): %g\n", (y - x) / 10.0)); 1769 /* MPI information */ 1770 if (size > 1) { 1771 MPI_Status status; 1772 PetscMPIInt tag; 1773 MPI_Comm newcomm; 1774 1775 PetscCallMPI(MPI_Barrier(comm)); 1776 PetscCall(PetscTime(&x)); 1777 PetscCallMPI(MPI_Barrier(comm)); 1778 PetscCallMPI(MPI_Barrier(comm)); 1779 PetscCallMPI(MPI_Barrier(comm)); 1780 PetscCallMPI(MPI_Barrier(comm)); 1781 PetscCallMPI(MPI_Barrier(comm)); 1782 PetscCall(PetscTime(&y)); 1783 PetscCall(PetscViewerASCIIPrintf(viewer, "Average time for MPI_Barrier(): %g\n", (y - x) / 5.0)); 1784 PetscCall(PetscCommDuplicate(comm, &newcomm, &tag)); 1785 PetscCallMPI(MPI_Barrier(comm)); 1786 if (rank) { 1787 PetscCallMPI(MPI_Recv(NULL, 0, MPI_INT, rank - 1, tag, newcomm, &status)); 1788 PetscCallMPI(MPI_Send(NULL, 0, MPI_INT, (rank + 1) % size, tag, newcomm)); 1789 } else { 1790 PetscCall(PetscTime(&x)); 1791 PetscCallMPI(MPI_Send(NULL, 0, MPI_INT, 1, tag, newcomm)); 1792 PetscCallMPI(MPI_Recv(NULL, 0, MPI_INT, size - 1, tag, newcomm, &status)); 1793 PetscCall(PetscTime(&y)); 1794 PetscCall(PetscViewerASCIIPrintf(viewer, "Average time for zero size MPI_Send(): %g\n", (y - x) / size)); 1795 } 1796 PetscCall(PetscCommDestroy(&newcomm)); 1797 } 1798 PetscCall(PetscOptionsView(NULL, viewer)); 1799 1800 /* Machine and compile information */ 1801 if (PetscDefined(USE_FORTRAN_KERNELS)) { 1802 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with FORTRAN kernels\n")); 1803 } else { 1804 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled without FORTRAN kernels\n")); 1805 } 1806 if (PetscDefined(USE_64BIT_INDICES)) { 1807 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with 64-bit PetscInt\n")); 1808 } else if (PetscDefined(USE___FLOAT128)) { 1809 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with 32-bit PetscInt\n")); 1810 } 1811 if (PetscDefined(USE_REAL_SINGLE)) { 1812 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with single precision PetscScalar and PetscReal\n")); 1813 } else if (PetscDefined(USE___FLOAT128)) { 1814 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with 128 bit precision PetscScalar and PetscReal\n")); 1815 } 1816 if (PetscDefined(USE_REAL_MAT_SINGLE)) { 1817 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with single precision matrices\n")); 1818 } else { 1819 PetscCall(PetscViewerASCIIPrintf(viewer, "Compiled with full precision matrices (default)\n")); 1820 } 1821 PetscCall(PetscViewerASCIIPrintf(viewer, "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))); 1822 1823 PetscCall(PetscViewerASCIIPrintf(viewer, "Configure options: %s", petscconfigureoptions)); 1824 PetscCall(PetscViewerASCIIPrintf(viewer, "%s", petscmachineinfo)); 1825 PetscCall(PetscViewerASCIIPrintf(viewer, "%s", petsccompilerinfo)); 1826 PetscCall(PetscViewerASCIIPrintf(viewer, "%s", petsccompilerflagsinfo)); 1827 PetscCall(PetscViewerASCIIPrintf(viewer, "%s", petsclinkerinfo)); 1828 1829 /* Cleanup */ 1830 PetscCall(PetscViewerASCIIPrintf(viewer, "\n")); 1831 PetscCall(PetscLogViewWarnNoGpuAwareMpi(viewer)); 1832 PetscCall(PetscLogViewWarnDebugging(viewer)); 1833 PetscCall(PetscFPTrapPop()); 1834 PetscFunctionReturn(PETSC_SUCCESS); 1835 } 1836 1837 static PetscErrorCode PetscLogHandlerView_Default(PetscLogHandler handler, PetscViewer viewer) 1838 { 1839 PetscViewerFormat format; 1840 1841 PetscFunctionBegin; 1842 PetscCall(PetscViewerGetFormat(viewer, &format)); 1843 if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) { 1844 PetscCall(PetscLogHandlerView_Default_Info(handler, viewer)); 1845 } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) { 1846 PetscCall(PetscLogHandlerView_Default_Detailed(handler, viewer)); 1847 } else if (format == PETSC_VIEWER_ASCII_CSV) { 1848 PetscCall(PetscLogHandlerView_Default_CSV(handler, viewer)); 1849 } 1850 PetscFunctionReturn(PETSC_SUCCESS); 1851 } 1852 1853 /*MC 1854 PETSCLOGHANDLERDEFAULT - PETSCLOGHANDLERDEFAULT = "default" - A `PetscLogHandler` that collects data for PETSc 1855 default profiling log viewers (`PetscLogView()` and `PetscLogDump()`). A log handler of this type is 1856 created and started (`PetscLogHandlerStart()`) by `PetscLogDefaultBegin()`. 1857 1858 Options Database Keys: 1859 + -log_include_actions - include a growing list of actions (event beginnings and endings, object creations and destructions) in `PetscLogDump()` (`PetscLogActions()`). 1860 - -log_include_objects - include a growing list of object creations and destructions in `PetscLogDump()` (`PetscLogObjects()`). 1861 1862 Level: developer 1863 1864 .seealso: [](ch_profiling), `PetscLogHandler` 1865 M*/ 1866 1867 PETSC_INTERN PetscErrorCode PetscLogHandlerCreate_Default(PetscLogHandler handler) 1868 { 1869 PetscFunctionBegin; 1870 PetscCall(PetscLogHandlerContextCreate_Default((PetscLogHandler_Default *)&handler->data)); 1871 handler->ops->destroy = PetscLogHandlerDestroy_Default; 1872 handler->ops->eventbegin = PetscLogHandlerEventBegin_Default; 1873 handler->ops->eventend = PetscLogHandlerEventEnd_Default; 1874 handler->ops->eventsync = PetscLogHandlerEventSync_Default; 1875 handler->ops->objectcreate = PetscLogHandlerObjectCreate_Default; 1876 handler->ops->objectdestroy = PetscLogHandlerObjectDestroy_Default; 1877 handler->ops->stagepush = PetscLogHandlerStagePush_Default; 1878 handler->ops->stagepop = PetscLogHandlerStagePop_Default; 1879 handler->ops->view = PetscLogHandlerView_Default; 1880 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerGetEventPerfInfo_C", PetscLogHandlerGetEventPerfInfo_Default)); 1881 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerGetStagePerfInfo_C", PetscLogHandlerGetStagePerfInfo_Default)); 1882 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerSetLogActions_C", PetscLogHandlerSetLogActions_Default)); 1883 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerSetLogObjects_C", PetscLogHandlerSetLogObjects_Default)); 1884 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerLogObjectState_C", PetscLogHandlerLogObjectState_Default)); 1885 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerGetNumObjects_C", PetscLogHandlerGetNumObjects_Default)); 1886 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerEventDeactivatePush_C", PetscLogHandlerEventDeactivatePush_Default)); 1887 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerEventDeactivatePop_C", PetscLogHandlerEventDeactivatePop_Default)); 1888 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerEventsPause_C", PetscLogHandlerEventsPause_Default)); 1889 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerEventsResume_C", PetscLogHandlerEventsResume_Default)); 1890 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerDump_C", PetscLogHandlerDump_Default)); 1891 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerStageSetVisible_C", PetscLogHandlerStageSetVisible_Default)); 1892 PetscCall(PetscObjectComposeFunction((PetscObject)handler, "PetscLogHandlerStageGetVisible_C", PetscLogHandlerStageGetVisible_Default)); 1893 PetscFunctionReturn(PETSC_SUCCESS); 1894 } 1895