1 2 /* 3 PETSc code to log object creation and destruction and PETSc events. 4 5 This provides the public API used by the rest of PETSc and by users. 6 7 These routines use a private API that is not used elsewhere in PETSc and is not 8 accessible to users. The private API is defined in logimpl.h and the utils directory. 9 10 */ 11 #include <petsc/private/logimpl.h> /*I "petscsys.h" I*/ 12 #include <petsctime.h> 13 #include <petscviewer.h> 14 15 PetscErrorCode PetscLogObjectParent(PetscObject p,PetscObject c) 16 { 17 if (!c || !p) return 0; 18 c->parent = p; 19 c->parentid = p->id; 20 return 0; 21 } 22 23 /*@C 24 PetscLogObjectMemory - Adds to an object a count of additional amount of memory that is used by the object. 25 26 Not collective. 27 28 Input Parameters: 29 + obj - the PETSc object 30 - mem - the amount of memory that is being added to the object 31 32 Level: developer 33 34 Developer Notes: 35 Currently we do not always do a good job of associating all memory allocations with an object. 36 37 .seealso: PetscFinalize(), PetscInitializeFortran(), PetscGetArgs(), PetscInitializeNoArguments() 38 39 @*/ 40 PetscErrorCode PetscLogObjectMemory(PetscObject p,PetscLogDouble m) 41 { 42 if (!p) return 0; 43 p->mem += m; 44 return 0; 45 } 46 47 PetscLogEvent PETSC_LARGEST_EVENT = PETSC_EVENT; 48 49 #if defined(PETSC_USE_LOG) 50 #include <petscmachineinfo.h> 51 #include <petscconfiginfo.h> 52 53 /* used in the MPI_XXX() count macros in petsclog.h */ 54 55 /* Action and object logging variables */ 56 Action *petsc_actions = NULL; 57 Object *petsc_objects = NULL; 58 PetscBool petsc_logActions = PETSC_FALSE; 59 PetscBool petsc_logObjects = PETSC_FALSE; 60 int petsc_numActions = 0, petsc_maxActions = 100; 61 int petsc_numObjects = 0, petsc_maxObjects = 100; 62 int petsc_numObjectsDestroyed = 0; 63 64 /* Global counters */ 65 PetscLogDouble petsc_BaseTime = 0.0; 66 PetscLogDouble petsc_TotalFlops = 0.0; /* The number of flops */ 67 PetscLogDouble petsc_tmp_flops = 0.0; /* The incremental number of flops */ 68 PetscLogDouble petsc_send_ct = 0.0; /* The number of sends */ 69 PetscLogDouble petsc_recv_ct = 0.0; /* The number of receives */ 70 PetscLogDouble petsc_send_len = 0.0; /* The total length of all sent messages */ 71 PetscLogDouble petsc_recv_len = 0.0; /* The total length of all received messages */ 72 PetscLogDouble petsc_isend_ct = 0.0; /* The number of immediate sends */ 73 PetscLogDouble petsc_irecv_ct = 0.0; /* The number of immediate receives */ 74 PetscLogDouble petsc_isend_len = 0.0; /* The total length of all immediate send messages */ 75 PetscLogDouble petsc_irecv_len = 0.0; /* The total length of all immediate receive messages */ 76 PetscLogDouble petsc_wait_ct = 0.0; /* The number of waits */ 77 PetscLogDouble petsc_wait_any_ct = 0.0; /* The number of anywaits */ 78 PetscLogDouble petsc_wait_all_ct = 0.0; /* The number of waitalls */ 79 PetscLogDouble petsc_sum_of_waits_ct = 0.0; /* The total number of waits */ 80 PetscLogDouble petsc_allreduce_ct = 0.0; /* The number of reductions */ 81 PetscLogDouble petsc_gather_ct = 0.0; /* The number of gathers and gathervs */ 82 PetscLogDouble petsc_scatter_ct = 0.0; /* The number of scatters and scattervs */ 83 #if defined(PETSC_HAVE_DEVICE) 84 PetscLogDouble petsc_ctog_ct = 0.0; /* The total number of CPU to GPU copies */ 85 PetscLogDouble petsc_gtoc_ct = 0.0; /* The total number of GPU to CPU copies */ 86 PetscLogDouble petsc_ctog_sz = 0.0; /* The total size of CPU to GPU copies */ 87 PetscLogDouble petsc_gtoc_sz = 0.0; /* The total size of GPU to CPU copies */ 88 PetscLogDouble petsc_ctog_ct_scalar = 0.0; /* The total number of CPU to GPU copies */ 89 PetscLogDouble petsc_gtoc_ct_scalar = 0.0; /* The total number of GPU to CPU copies */ 90 PetscLogDouble petsc_ctog_sz_scalar = 0.0; /* The total size of CPU to GPU copies */ 91 PetscLogDouble petsc_gtoc_sz_scalar = 0.0; /* The total size of GPU to CPU copies */ 92 PetscLogDouble petsc_gflops = 0.0; /* The flops done on a GPU */ 93 PetscLogDouble petsc_gtime = 0.0; /* The time spent on a GPU */ 94 95 #if defined(PETSC_USE_DEBUG) 96 PetscBool petsc_gtime_inuse = PETSC_FALSE; 97 #endif 98 #endif 99 100 /* Logging functions */ 101 PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL; 102 PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL; 103 PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 104 PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 105 106 /* Tracing event logging variables */ 107 FILE *petsc_tracefile = NULL; 108 int petsc_tracelevel = 0; 109 const char *petsc_traceblanks = " "; 110 char petsc_tracespace[128] = " "; 111 PetscLogDouble petsc_tracetime = 0.0; 112 static PetscBool PetscLogInitializeCalled = PETSC_FALSE; 113 114 PETSC_INTERN PetscErrorCode PetscLogInitialize(void) 115 { 116 int stage; 117 PetscBool opt; 118 PetscErrorCode ierr; 119 120 PetscFunctionBegin; 121 if (PetscLogInitializeCalled) PetscFunctionReturn(0); 122 PetscLogInitializeCalled = PETSC_TRUE; 123 124 ierr = PetscOptionsHasName(NULL,NULL, "-log_exclude_actions", &opt);CHKERRQ(ierr); 125 if (opt) petsc_logActions = PETSC_FALSE; 126 ierr = PetscOptionsHasName(NULL,NULL, "-log_exclude_objects", &opt);CHKERRQ(ierr); 127 if (opt) petsc_logObjects = PETSC_FALSE; 128 if (petsc_logActions) { 129 ierr = PetscMalloc1(petsc_maxActions, &petsc_actions);CHKERRQ(ierr); 130 } 131 if (petsc_logObjects) { 132 ierr = PetscMalloc1(petsc_maxObjects, &petsc_objects);CHKERRQ(ierr); 133 } 134 PetscLogPHC = PetscLogObjCreateDefault; 135 PetscLogPHD = PetscLogObjDestroyDefault; 136 /* Setup default logging structures */ 137 ierr = PetscStageLogCreate(&petsc_stageLog);CHKERRQ(ierr); 138 ierr = PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);CHKERRQ(ierr); 139 140 /* All processors sync here for more consistent logging */ 141 ierr = MPI_Barrier(PETSC_COMM_WORLD);CHKERRMPI(ierr); 142 PetscTime(&petsc_BaseTime); 143 ierr = PetscLogStagePush(stage);CHKERRQ(ierr); 144 PetscFunctionReturn(0); 145 } 146 147 PETSC_INTERN PetscErrorCode PetscLogFinalize(void) 148 { 149 PetscStageLog stageLog; 150 PetscErrorCode ierr; 151 152 PetscFunctionBegin; 153 ierr = PetscFree(petsc_actions);CHKERRQ(ierr); 154 ierr = PetscFree(petsc_objects);CHKERRQ(ierr); 155 ierr = PetscLogNestedEnd();CHKERRQ(ierr); 156 ierr = PetscLogSet(NULL, NULL);CHKERRQ(ierr); 157 158 /* Resetting phase */ 159 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 160 ierr = PetscStageLogDestroy(stageLog);CHKERRQ(ierr); 161 162 petsc_TotalFlops = 0.0; 163 petsc_numActions = 0; 164 petsc_numObjects = 0; 165 petsc_numObjectsDestroyed = 0; 166 petsc_maxActions = 100; 167 petsc_maxObjects = 100; 168 petsc_actions = NULL; 169 petsc_objects = NULL; 170 petsc_logActions = PETSC_FALSE; 171 petsc_logObjects = PETSC_FALSE; 172 petsc_BaseTime = 0.0; 173 petsc_TotalFlops = 0.0; 174 petsc_tmp_flops = 0.0; 175 petsc_send_ct = 0.0; 176 petsc_recv_ct = 0.0; 177 petsc_send_len = 0.0; 178 petsc_recv_len = 0.0; 179 petsc_isend_ct = 0.0; 180 petsc_irecv_ct = 0.0; 181 petsc_isend_len = 0.0; 182 petsc_irecv_len = 0.0; 183 petsc_wait_ct = 0.0; 184 petsc_wait_any_ct = 0.0; 185 petsc_wait_all_ct = 0.0; 186 petsc_sum_of_waits_ct = 0.0; 187 petsc_allreduce_ct = 0.0; 188 petsc_gather_ct = 0.0; 189 petsc_scatter_ct = 0.0; 190 #if defined(PETSC_HAVE_DEVICE) 191 petsc_ctog_ct = 0.0; 192 petsc_gtoc_ct = 0.0; 193 petsc_ctog_sz = 0.0; 194 petsc_gtoc_sz = 0.0; 195 petsc_gflops = 0.0; 196 petsc_gtime = 0.0; 197 #endif 198 PETSC_LARGEST_EVENT = PETSC_EVENT; 199 PetscLogPHC = NULL; 200 PetscLogPHD = NULL; 201 petsc_tracefile = NULL; 202 petsc_tracelevel = 0; 203 petsc_traceblanks = " "; 204 petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0; 205 petsc_tracetime = 0.0; 206 PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 207 PETSC_OBJECT_CLASSID = 0; 208 petsc_stageLog = NULL; 209 PetscLogInitializeCalled = PETSC_FALSE; 210 PetscFunctionReturn(0); 211 } 212 213 /*@C 214 PetscLogSet - Sets the logging functions called at the beginning and ending of every event. 215 216 Not Collective 217 218 Input Parameters: 219 + b - The function called at beginning of event 220 - e - The function called at end of event 221 222 Level: developer 223 224 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogTraceBegin() 225 @*/ 226 PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject), 227 PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject)) 228 { 229 PetscFunctionBegin; 230 PetscLogPLB = b; 231 PetscLogPLE = e; 232 PetscFunctionReturn(0); 233 } 234 235 /*@C 236 PetscLogDefaultBegin - Turns on logging of objects and events. This logs flop 237 rates and object creation and should not slow programs down too much. 238 This routine may be called more than once. 239 240 Logically Collective over PETSC_COMM_WORLD 241 242 Options Database Keys: 243 . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the 244 screen (for code configured with --with-log=1 (which is the default)) 245 246 Usage: 247 .vb 248 PetscInitialize(...); 249 PetscLogDefaultBegin(); 250 ... code ... 251 PetscLogView(viewer); or PetscLogDump(); 252 PetscFinalize(); 253 .ve 254 255 Notes: 256 PetscLogView(viewer) or PetscLogDump() actually cause the printing of 257 the logging information. 258 259 Level: advanced 260 261 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin() 262 @*/ 263 PetscErrorCode PetscLogDefaultBegin(void) 264 { 265 PetscErrorCode ierr; 266 267 PetscFunctionBegin; 268 ierr = PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);CHKERRQ(ierr); 269 PetscFunctionReturn(0); 270 } 271 272 /*@C 273 PetscLogAllBegin - Turns on extensive logging of objects and events. Logs 274 all events. This creates large log files and slows the program down. 275 276 Logically Collective on PETSC_COMM_WORLD 277 278 Options Database Keys: 279 . -log_all - Prints extensive log information 280 281 Usage: 282 .vb 283 PetscInitialize(...); 284 PetscLogAllBegin(); 285 ... code ... 286 PetscLogDump(filename); 287 PetscFinalize(); 288 .ve 289 290 Notes: 291 A related routine is PetscLogDefaultBegin() (with the options key -log), which is 292 intended for production runs since it logs only flop rates and object 293 creation (and shouldn't significantly slow the programs). 294 295 Level: advanced 296 297 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogTraceBegin() 298 @*/ 299 PetscErrorCode PetscLogAllBegin(void) 300 { 301 PetscErrorCode ierr; 302 303 PetscFunctionBegin; 304 ierr = PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);CHKERRQ(ierr); 305 PetscFunctionReturn(0); 306 } 307 308 /*@C 309 PetscLogTraceBegin - Activates trace logging. Every time a PETSc event 310 begins or ends, the event name is printed. 311 312 Logically Collective on PETSC_COMM_WORLD 313 314 Input Parameter: 315 . file - The file to print trace in (e.g. stdout) 316 317 Options Database Key: 318 . -log_trace [filename] - Activates PetscLogTraceBegin() 319 320 Notes: 321 PetscLogTraceBegin() prints the processor number, the execution time (sec), 322 then "Event begin:" or "Event end:" followed by the event name. 323 324 PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful 325 to determine where a program is hanging without running in the 326 debugger. Can be used in conjunction with the -info option. 327 328 Level: intermediate 329 330 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogDefaultBegin() 331 @*/ 332 PetscErrorCode PetscLogTraceBegin(FILE *file) 333 { 334 PetscErrorCode ierr; 335 336 PetscFunctionBegin; 337 petsc_tracefile = file; 338 339 ierr = PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);CHKERRQ(ierr); 340 PetscFunctionReturn(0); 341 } 342 343 /*@ 344 PetscLogActions - Determines whether actions are logged for the graphical viewer. 345 346 Not Collective 347 348 Input Parameter: 349 . flag - PETSC_TRUE if actions are to be logged 350 351 Level: intermediate 352 353 Note: Logging of actions continues to consume more memory as the program 354 runs. Long running programs should consider turning this feature off. 355 356 Options Database Keys: 357 . -log_exclude_actions - Turns off actions logging 358 359 .seealso: PetscLogStagePush(), PetscLogStagePop() 360 @*/ 361 PetscErrorCode PetscLogActions(PetscBool flag) 362 { 363 PetscFunctionBegin; 364 petsc_logActions = flag; 365 PetscFunctionReturn(0); 366 } 367 368 /*@ 369 PetscLogObjects - Determines whether objects are logged for the graphical viewer. 370 371 Not Collective 372 373 Input Parameter: 374 . flag - PETSC_TRUE if objects are to be logged 375 376 Level: intermediate 377 378 Note: Logging of objects continues to consume more memory as the program 379 runs. Long running programs should consider turning this feature off. 380 381 Options Database Keys: 382 . -log_exclude_objects - Turns off objects logging 383 384 .seealso: PetscLogStagePush(), PetscLogStagePop() 385 @*/ 386 PetscErrorCode PetscLogObjects(PetscBool flag) 387 { 388 PetscFunctionBegin; 389 petsc_logObjects = flag; 390 PetscFunctionReturn(0); 391 } 392 393 /*------------------------------------------------ Stage Functions --------------------------------------------------*/ 394 /*@C 395 PetscLogStageRegister - Attaches a character string name to a logging stage. 396 397 Not Collective 398 399 Input Parameter: 400 . sname - The name to associate with that stage 401 402 Output Parameter: 403 . stage - The stage number 404 405 Level: intermediate 406 407 .seealso: PetscLogStagePush(), PetscLogStagePop() 408 @*/ 409 PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage) 410 { 411 PetscStageLog stageLog; 412 PetscLogEvent event; 413 PetscErrorCode ierr; 414 415 PetscFunctionBegin; 416 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 417 ierr = PetscStageLogRegister(stageLog, sname, stage);CHKERRQ(ierr); 418 /* Copy events already changed in the main stage, this sucks */ 419 ierr = PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);CHKERRQ(ierr); 420 for (event = 0; event < stageLog->eventLog->numEvents; event++) { 421 ierr = PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);CHKERRQ(ierr); 422 } 423 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 424 PetscFunctionReturn(0); 425 } 426 427 /*@C 428 PetscLogStagePush - This function pushes a stage on the stack. 429 430 Not Collective 431 432 Input Parameter: 433 . stage - The stage on which to log 434 435 Usage: 436 If the option -log_sumary is used to run the program containing the 437 following code, then 2 sets of summary data will be printed during 438 PetscFinalize(). 439 .vb 440 PetscInitialize(int *argc,char ***args,0,0); 441 [stage 0 of code] 442 PetscLogStagePush(1); 443 [stage 1 of code] 444 PetscLogStagePop(); 445 PetscBarrier(...); 446 [more stage 0 of code] 447 PetscFinalize(); 448 .ve 449 450 Notes: 451 Use PetscLogStageRegister() to register a stage. 452 453 Level: intermediate 454 455 .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier() 456 @*/ 457 PetscErrorCode PetscLogStagePush(PetscLogStage stage) 458 { 459 PetscStageLog stageLog; 460 PetscErrorCode ierr; 461 462 PetscFunctionBegin; 463 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 464 ierr = PetscStageLogPush(stageLog, stage);CHKERRQ(ierr); 465 PetscFunctionReturn(0); 466 } 467 468 /*@C 469 PetscLogStagePop - This function pops a stage from the stack. 470 471 Not Collective 472 473 Usage: 474 If the option -log_sumary is used to run the program containing the 475 following code, then 2 sets of summary data will be printed during 476 PetscFinalize(). 477 .vb 478 PetscInitialize(int *argc,char ***args,0,0); 479 [stage 0 of code] 480 PetscLogStagePush(1); 481 [stage 1 of code] 482 PetscLogStagePop(); 483 PetscBarrier(...); 484 [more stage 0 of code] 485 PetscFinalize(); 486 .ve 487 488 Notes: 489 Use PetscLogStageRegister() to register a stage. 490 491 Level: intermediate 492 493 .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier() 494 @*/ 495 PetscErrorCode PetscLogStagePop(void) 496 { 497 PetscStageLog stageLog; 498 PetscErrorCode ierr; 499 500 PetscFunctionBegin; 501 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 502 ierr = PetscStageLogPop(stageLog);CHKERRQ(ierr); 503 PetscFunctionReturn(0); 504 } 505 506 /*@ 507 PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd(). 508 509 Not Collective 510 511 Input Parameters: 512 + stage - The stage 513 - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE) 514 515 Level: intermediate 516 517 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 518 @*/ 519 PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive) 520 { 521 PetscStageLog stageLog; 522 PetscErrorCode ierr; 523 524 PetscFunctionBegin; 525 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 526 ierr = PetscStageLogSetActive(stageLog, stage, isActive);CHKERRQ(ierr); 527 PetscFunctionReturn(0); 528 } 529 530 /*@ 531 PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd(). 532 533 Not Collective 534 535 Input Parameter: 536 . stage - The stage 537 538 Output Parameter: 539 . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE) 540 541 Level: intermediate 542 543 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 544 @*/ 545 PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive) 546 { 547 PetscStageLog stageLog; 548 PetscErrorCode ierr; 549 550 PetscFunctionBegin; 551 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 552 ierr = PetscStageLogGetActive(stageLog, stage, isActive);CHKERRQ(ierr); 553 PetscFunctionReturn(0); 554 } 555 556 /*@ 557 PetscLogStageSetVisible - Determines stage visibility in PetscLogView() 558 559 Not Collective 560 561 Input Parameters: 562 + stage - The stage 563 - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE) 564 565 Level: intermediate 566 567 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView() 568 @*/ 569 PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible) 570 { 571 PetscStageLog stageLog; 572 PetscErrorCode ierr; 573 574 PetscFunctionBegin; 575 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 576 ierr = PetscStageLogSetVisible(stageLog, stage, isVisible);CHKERRQ(ierr); 577 PetscFunctionReturn(0); 578 } 579 580 /*@ 581 PetscLogStageGetVisible - Returns stage visibility in PetscLogView() 582 583 Not Collective 584 585 Input Parameter: 586 . stage - The stage 587 588 Output Parameter: 589 . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE) 590 591 Level: intermediate 592 593 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView() 594 @*/ 595 PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible) 596 { 597 PetscStageLog stageLog; 598 PetscErrorCode ierr; 599 600 PetscFunctionBegin; 601 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 602 ierr = PetscStageLogGetVisible(stageLog, stage, isVisible);CHKERRQ(ierr); 603 PetscFunctionReturn(0); 604 } 605 606 /*@C 607 PetscLogStageGetId - Returns the stage id when given the stage name. 608 609 Not Collective 610 611 Input Parameter: 612 . name - The stage name 613 614 Output Parameter: 615 . stage - The stage, , or -1 if no stage with that name exists 616 617 Level: intermediate 618 619 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 620 @*/ 621 PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage) 622 { 623 PetscStageLog stageLog; 624 PetscErrorCode ierr; 625 626 PetscFunctionBegin; 627 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 628 ierr = PetscStageLogGetStage(stageLog, name, stage);CHKERRQ(ierr); 629 PetscFunctionReturn(0); 630 } 631 632 /*------------------------------------------------ Event Functions --------------------------------------------------*/ 633 /*@C 634 PetscLogEventRegister - Registers an event name for logging operations in an application code. 635 636 Not Collective 637 638 Input Parameters: 639 + name - The name associated with the event 640 - classid - The classid associated to the class for this event, obtain either with 641 PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones 642 are only available in C code 643 644 Output Parameter: 645 . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd(). 646 647 Example of Usage: 648 .vb 649 PetscLogEvent USER_EVENT; 650 PetscClassId classid; 651 PetscLogDouble user_event_flops; 652 PetscClassIdRegister("class name",&classid); 653 PetscLogEventRegister("User event name",classid,&USER_EVENT); 654 PetscLogEventBegin(USER_EVENT,0,0,0,0); 655 [code segment to monitor] 656 PetscLogFlops(user_event_flops); 657 PetscLogEventEnd(USER_EVENT,0,0,0,0); 658 .ve 659 660 Notes: 661 PETSc automatically logs library events if the code has been 662 configured with --with-log (which is the default) and 663 -log_view or -log_all is specified. PetscLogEventRegister() is 664 intended for logging user events to supplement this PETSc 665 information. 666 667 PETSc can gather data for use with the utilities Jumpshot 668 (part of the MPICH distribution). If PETSc has been compiled 669 with flag -DPETSC_HAVE_MPE (MPE is an additional utility within 670 MPICH), the user can employ another command line option, -log_mpe, 671 to create a logfile, "mpe.log", which can be visualized 672 Jumpshot. 673 674 The classid is associated with each event so that classes of events 675 can be disabled simultaneously, such as all matrix events. The user 676 can either use an existing classid, such as MAT_CLASSID, or create 677 their own as shown in the example. 678 679 If an existing event with the same name exists, its event handle is 680 returned instead of creating a new event. 681 682 Level: intermediate 683 684 .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), 685 PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister() 686 @*/ 687 PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event) 688 { 689 PetscStageLog stageLog; 690 int stage; 691 PetscErrorCode ierr; 692 693 PetscFunctionBegin; 694 *event = PETSC_DECIDE; 695 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 696 ierr = PetscEventRegLogGetEvent(stageLog->eventLog, name, event);CHKERRQ(ierr); 697 if (*event > 0) PetscFunctionReturn(0); 698 ierr = PetscEventRegLogRegister(stageLog->eventLog, name, classid, event);CHKERRQ(ierr); 699 for (stage = 0; stage < stageLog->numStages; stage++) { 700 ierr = PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);CHKERRQ(ierr); 701 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 702 } 703 PetscFunctionReturn(0); 704 } 705 706 /*@ 707 PetscLogEventSetCollective - Indicates that a particular event is collective. 708 709 Not Collective 710 711 Input Parameters: 712 + event - The event id 713 - collective - Bolean flag indicating whether a particular event is collective 714 715 Note: 716 New events returned from PetscLogEventRegister() are collective by default. 717 718 Level: developer 719 720 .seealso: PetscLogEventRegister() 721 @*/ 722 PetscErrorCode PetscLogEventSetCollective(PetscLogEvent event,PetscBool collective) 723 { 724 PetscStageLog stageLog; 725 PetscEventRegLog eventRegLog; 726 PetscErrorCode ierr; 727 728 PetscFunctionBegin; 729 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 730 ierr = PetscStageLogGetEventRegLog(stageLog,&eventRegLog);CHKERRQ(ierr); 731 if (event < 0 || event > eventRegLog->numEvents) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_ARG_OUTOFRANGE,"Invalid event id"); 732 eventRegLog->eventInfo[event].collective = collective; 733 PetscFunctionReturn(0); 734 } 735 736 /*@ 737 PetscLogEventIncludeClass - Activates event logging for a PETSc object class in every stage. 738 739 Not Collective 740 741 Input Parameter: 742 . classid - The object class, for example MAT_CLASSID, SNES_CLASSID, etc. 743 744 Level: developer 745 746 .seealso: PetscLogEventActivateClass(),PetscLogEventDeactivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate() 747 @*/ 748 PetscErrorCode PetscLogEventIncludeClass(PetscClassId classid) 749 { 750 PetscStageLog stageLog; 751 int stage; 752 PetscErrorCode ierr; 753 754 PetscFunctionBegin; 755 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 756 for (stage = 0; stage < stageLog->numStages; stage++) { 757 ierr = PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 758 } 759 PetscFunctionReturn(0); 760 } 761 762 /*@ 763 PetscLogEventExcludeClass - Deactivates event logging for a PETSc object class in every stage. 764 765 Not Collective 766 767 Input Parameter: 768 . classid - The object class, for example MAT_CLASSID, SNES_CLASSID, etc. 769 770 Level: developer 771 772 .seealso: PetscLogEventDeactivateClass(),PetscLogEventActivateClass(),PetscLogEventDeactivate(),PetscLogEventActivate() 773 @*/ 774 PetscErrorCode PetscLogEventExcludeClass(PetscClassId classid) 775 { 776 PetscStageLog stageLog; 777 int stage; 778 PetscErrorCode ierr; 779 780 PetscFunctionBegin; 781 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 782 for (stage = 0; stage < stageLog->numStages; stage++) { 783 ierr = PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 784 } 785 PetscFunctionReturn(0); 786 } 787 788 /*@ 789 PetscLogEventActivate - Indicates that a particular event should be logged. 790 791 Not Collective 792 793 Input Parameter: 794 . event - The event id 795 796 Usage: 797 .vb 798 PetscLogEventDeactivate(VEC_SetValues); 799 [code where you do not want to log VecSetValues()] 800 PetscLogEventActivate(VEC_SetValues); 801 [code where you do want to log VecSetValues()] 802 .ve 803 804 Note: 805 The event may be either a pre-defined PETSc event (found in include/petsclog.h) 806 or an event number obtained with PetscLogEventRegister(). 807 808 Level: advanced 809 810 .seealso: PlogEventDeactivate(), PlogEventDeactivatePush(), PetscLogEventDeactivatePop() 811 @*/ 812 PetscErrorCode PetscLogEventActivate(PetscLogEvent event) 813 { 814 PetscStageLog stageLog; 815 int stage; 816 PetscErrorCode ierr; 817 818 PetscFunctionBegin; 819 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 820 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 821 ierr = PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 822 PetscFunctionReturn(0); 823 } 824 825 /*@ 826 PetscLogEventDeactivate - Indicates that a particular event should not be logged. 827 828 Not Collective 829 830 Input Parameter: 831 . event - The event id 832 833 Usage: 834 .vb 835 PetscLogEventDeactivate(VEC_SetValues); 836 [code where you do not want to log VecSetValues()] 837 PetscLogEventActivate(VEC_SetValues); 838 [code where you do want to log VecSetValues()] 839 .ve 840 841 Note: 842 The event may be either a pre-defined PETSc event (found in 843 include/petsclog.h) or an event number obtained with PetscLogEventRegister()). 844 845 Level: advanced 846 847 .seealso: PetscLogEventActivate(), PetscLogEventDeactivatePush(), PetscLogEventDeactivatePop() 848 @*/ 849 PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event) 850 { 851 PetscStageLog stageLog; 852 int stage; 853 PetscErrorCode ierr; 854 855 PetscFunctionBegin; 856 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 857 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 858 ierr = PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 859 PetscFunctionReturn(0); 860 } 861 862 /*@ 863 PetscLogEventDeactivatePush - Indicates that a particular event should not be logged. 864 865 Not Collective 866 867 Input Parameter: 868 . event - The event id 869 870 Usage: 871 .vb 872 PetscLogEventDeactivatePush(VEC_SetValues); 873 [code where you do not want to log VecSetValues()] 874 PetscLogEventDeactivatePop(VEC_SetValues); 875 [code where you do want to log VecSetValues()] 876 .ve 877 878 Note: 879 The event may be either a pre-defined PETSc event (found in 880 include/petsclog.h) or an event number obtained with PetscLogEventRegister()). 881 882 Level: advanced 883 884 .seealso: PetscLogEventActivate(), PetscLogEventDeactivatePop() 885 @*/ 886 PetscErrorCode PetscLogEventDeactivatePush(PetscLogEvent event) 887 { 888 PetscStageLog stageLog; 889 int stage; 890 PetscErrorCode ierr; 891 892 PetscFunctionBegin; 893 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 894 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 895 ierr = PetscEventPerfLogDeactivatePush(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 896 PetscFunctionReturn(0); 897 } 898 899 /*@ 900 PetscLogEventDeactivatePop - Indicates that a particular event shouldbe logged. 901 902 Not Collective 903 904 Input Parameter: 905 . event - The event id 906 907 Usage: 908 .vb 909 PetscLogEventDeactivatePush(VEC_SetValues); 910 [code where you do not want to log VecSetValues()] 911 PetscLogEventDeactivatePop(VEC_SetValues); 912 [code where you do want to log VecSetValues()] 913 .ve 914 915 Note: 916 The event may be either a pre-defined PETSc event (found in 917 include/petsclog.h) or an event number obtained with PetscLogEventRegister()). 918 919 Level: advanced 920 921 .seealso: PetscLogEventActivate(), PetscLogEventDeactivatePush() 922 @*/ 923 PetscErrorCode PetscLogEventDeactivatePop(PetscLogEvent event) 924 { 925 PetscStageLog stageLog; 926 int stage; 927 PetscErrorCode ierr; 928 929 PetscFunctionBegin; 930 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 931 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 932 ierr = PetscEventPerfLogDeactivatePop(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 933 PetscFunctionReturn(0); 934 } 935 936 /*@ 937 PetscLogEventSetActiveAll - Sets the event activity in every stage. 938 939 Not Collective 940 941 Input Parameters: 942 + event - The event id 943 - isActive - The activity flag determining whether the event is logged 944 945 Level: advanced 946 947 .seealso: PlogEventActivate(),PlogEventDeactivate() 948 @*/ 949 PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive) 950 { 951 PetscStageLog stageLog; 952 int stage; 953 PetscErrorCode ierr; 954 955 PetscFunctionBegin; 956 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 957 for (stage = 0; stage < stageLog->numStages; stage++) { 958 if (isActive) { 959 ierr = PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 960 } else { 961 ierr = PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 962 } 963 } 964 PetscFunctionReturn(0); 965 } 966 967 /*@ 968 PetscLogEventActivateClass - Activates event logging for a PETSc object class. 969 970 Not Collective 971 972 Input Parameter: 973 . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc. 974 975 Level: developer 976 977 .seealso: PetscLogEventDeactivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate() 978 @*/ 979 PetscErrorCode PetscLogEventActivateClass(PetscClassId classid) 980 { 981 PetscStageLog stageLog; 982 int stage; 983 PetscErrorCode ierr; 984 985 PetscFunctionBegin; 986 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 987 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 988 ierr = PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 989 PetscFunctionReturn(0); 990 } 991 992 /*@ 993 PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class. 994 995 Not Collective 996 997 Input Parameter: 998 . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc. 999 1000 Level: developer 1001 1002 .seealso: PetscLogEventActivateClass(),PetscLogEventActivate(),PetscLogEventDeactivate() 1003 @*/ 1004 PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid) 1005 { 1006 PetscStageLog stageLog; 1007 int stage; 1008 PetscErrorCode ierr; 1009 1010 PetscFunctionBegin; 1011 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1012 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 1013 ierr = PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 1014 PetscFunctionReturn(0); 1015 } 1016 1017 /*MC 1018 PetscLogEventSync - Synchronizes the beginning of a user event. 1019 1020 Synopsis: 1021 #include <petsclog.h> 1022 PetscErrorCode PetscLogEventSync(int e,MPI_Comm comm) 1023 1024 Collective 1025 1026 Input Parameters: 1027 + e - integer associated with the event obtained from PetscLogEventRegister() 1028 - comm - an MPI communicator 1029 1030 Usage: 1031 .vb 1032 PetscLogEvent USER_EVENT; 1033 PetscLogEventRegister("User event",0,&USER_EVENT); 1034 PetscLogEventSync(USER_EVENT,PETSC_COMM_WORLD); 1035 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1036 [code segment to monitor] 1037 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1038 .ve 1039 1040 Notes: 1041 This routine should be called only if there is not a 1042 PetscObject available to pass to PetscLogEventBegin(). 1043 1044 Level: developer 1045 1046 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd() 1047 1048 M*/ 1049 1050 /*MC 1051 PetscLogEventBegin - Logs the beginning of a user event. 1052 1053 Synopsis: 1054 #include <petsclog.h> 1055 PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4) 1056 1057 Not Collective 1058 1059 Input Parameters: 1060 + e - integer associated with the event obtained from PetscLogEventRegister() 1061 - o1,o2,o3,o4 - objects associated with the event, or 0 1062 1063 Fortran Synopsis: 1064 void PetscLogEventBegin(int e,PetscErrorCode ierr) 1065 1066 Usage: 1067 .vb 1068 PetscLogEvent USER_EVENT; 1069 PetscLogDouble user_event_flops; 1070 PetscLogEventRegister("User event",0,&USER_EVENT); 1071 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1072 [code segment to monitor] 1073 PetscLogFlops(user_event_flops); 1074 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1075 .ve 1076 1077 Notes: 1078 You need to register each integer event with the command 1079 PetscLogEventRegister(). 1080 1081 Level: intermediate 1082 1083 .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops() 1084 1085 M*/ 1086 1087 /*MC 1088 PetscLogEventEnd - Log the end of a user event. 1089 1090 Synopsis: 1091 #include <petsclog.h> 1092 PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4) 1093 1094 Not Collective 1095 1096 Input Parameters: 1097 + e - integer associated with the event obtained with PetscLogEventRegister() 1098 - o1,o2,o3,o4 - objects associated with the event, or 0 1099 1100 Fortran Synopsis: 1101 void PetscLogEventEnd(int e,PetscErrorCode ierr) 1102 1103 Usage: 1104 .vb 1105 PetscLogEvent USER_EVENT; 1106 PetscLogDouble user_event_flops; 1107 PetscLogEventRegister("User event",0,&USER_EVENT,); 1108 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1109 [code segment to monitor] 1110 PetscLogFlops(user_event_flops); 1111 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1112 .ve 1113 1114 Notes: 1115 You should also register each additional integer event with the command 1116 PetscLogEventRegister(). 1117 1118 Level: intermediate 1119 1120 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops() 1121 1122 M*/ 1123 1124 /*@C 1125 PetscLogEventGetId - Returns the event id when given the event name. 1126 1127 Not Collective 1128 1129 Input Parameter: 1130 . name - The event name 1131 1132 Output Parameter: 1133 . event - The event, or -1 if no event with that name exists 1134 1135 Level: intermediate 1136 1137 .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId() 1138 @*/ 1139 PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event) 1140 { 1141 PetscStageLog stageLog; 1142 PetscErrorCode ierr; 1143 1144 PetscFunctionBegin; 1145 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1146 ierr = PetscEventRegLogGetEvent(stageLog->eventLog, name, event);CHKERRQ(ierr); 1147 PetscFunctionReturn(0); 1148 } 1149 1150 /*------------------------------------------------ Output Functions -------------------------------------------------*/ 1151 /*@C 1152 PetscLogDump - Dumps logs of objects to a file. This file is intended to 1153 be read by bin/petscview. This program no longer exists. 1154 1155 Collective on PETSC_COMM_WORLD 1156 1157 Input Parameter: 1158 . name - an optional file name 1159 1160 Usage: 1161 .vb 1162 PetscInitialize(...); 1163 PetscLogDefaultBegin(); or PetscLogAllBegin(); 1164 ... code ... 1165 PetscLogDump(filename); 1166 PetscFinalize(); 1167 .ve 1168 1169 Notes: 1170 The default file name is 1171 $ Log.<rank> 1172 where <rank> is the processor number. If no name is specified, 1173 this file will be used. 1174 1175 Level: advanced 1176 1177 .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView() 1178 @*/ 1179 PetscErrorCode PetscLogDump(const char sname[]) 1180 { 1181 PetscStageLog stageLog; 1182 PetscEventPerfInfo *eventInfo; 1183 FILE *fd; 1184 char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN]; 1185 PetscLogDouble flops, _TotalTime; 1186 PetscMPIInt rank; 1187 int action, object, curStage; 1188 PetscLogEvent event; 1189 PetscErrorCode ierr; 1190 1191 PetscFunctionBegin; 1192 /* Calculate the total elapsed time */ 1193 PetscTime(&_TotalTime); 1194 _TotalTime -= petsc_BaseTime; 1195 /* Open log file */ 1196 ierr = MPI_Comm_rank(PETSC_COMM_WORLD, &rank);CHKERRMPI(ierr); 1197 if (sname && sname[0]) sprintf(file, "%s.%d", sname, rank); 1198 else sprintf(file, "Log.%d", rank); 1199 ierr = PetscFixFilename(file, fname);CHKERRQ(ierr); 1200 ierr = PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);CHKERRQ(ierr); 1201 if ((rank == 0) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname); 1202 /* Output totals */ 1203 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);CHKERRQ(ierr); 1204 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);CHKERRQ(ierr); 1205 /* Output actions */ 1206 if (petsc_logActions) { 1207 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);CHKERRQ(ierr); 1208 for (action = 0; action < petsc_numActions; action++) { 1209 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n", 1210 petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1, 1211 petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);CHKERRQ(ierr); 1212 } 1213 } 1214 /* Output objects */ 1215 if (petsc_logObjects) { 1216 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);CHKERRQ(ierr); 1217 for (object = 0; object < petsc_numObjects; object++) { 1218 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);CHKERRQ(ierr); 1219 if (!petsc_objects[object].name[0]) { 1220 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");CHKERRQ(ierr); 1221 } else { 1222 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);CHKERRQ(ierr); 1223 } 1224 if (petsc_objects[object].info[0] != 0) { 1225 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");CHKERRQ(ierr); 1226 } else { 1227 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);CHKERRQ(ierr); 1228 } 1229 } 1230 } 1231 /* Output events */ 1232 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");CHKERRQ(ierr); 1233 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1234 ierr = PetscIntStackTop(stageLog->stack, &curStage);CHKERRQ(ierr); 1235 eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo; 1236 for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) { 1237 if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time; 1238 else flops = 0.0; 1239 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count, 1240 eventInfo[event].flops, eventInfo[event].time, flops);CHKERRQ(ierr); 1241 } 1242 ierr = PetscFClose(PETSC_COMM_WORLD, fd);CHKERRQ(ierr); 1243 PetscFunctionReturn(0); 1244 } 1245 1246 /* 1247 PetscLogView_Detailed - Each process prints the times for its own events 1248 1249 */ 1250 PetscErrorCode PetscLogView_Detailed(PetscViewer viewer) 1251 { 1252 PetscStageLog stageLog; 1253 PetscEventPerfInfo *eventInfo = NULL, *stageInfo = NULL; 1254 PetscLogDouble locTotalTime, numRed, maxMem; 1255 int numStages,numEvents,stage,event; 1256 MPI_Comm comm = PetscObjectComm((PetscObject) viewer); 1257 PetscMPIInt rank,size; 1258 PetscErrorCode ierr; 1259 1260 PetscFunctionBegin; 1261 ierr = MPI_Comm_size(comm, &size);CHKERRMPI(ierr); 1262 ierr = MPI_Comm_rank(comm, &rank);CHKERRMPI(ierr); 1263 /* Must preserve reduction count before we go on */ 1264 numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1265 /* Get the total elapsed time */ 1266 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1267 ierr = PetscViewerASCIIPrintf(viewer,"size = %d\n",size);CHKERRQ(ierr); 1268 ierr = PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");CHKERRQ(ierr); 1269 ierr = PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");CHKERRQ(ierr); 1270 ierr = PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");CHKERRQ(ierr); 1271 ierr = PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");CHKERRQ(ierr); 1272 ierr = PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");CHKERRQ(ierr); 1273 ierr = PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");CHKERRQ(ierr); 1274 ierr = PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");CHKERRQ(ierr); 1275 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1276 ierr = MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1277 ierr = PetscViewerASCIIPrintf(viewer,"Stages = {}\n");CHKERRQ(ierr); 1278 for (stage=0; stage<numStages; stage++) { 1279 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);CHKERRQ(ierr); 1280 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);CHKERRQ(ierr); 1281 ierr = MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1282 for (event = 0; event < numEvents; event++) { 1283 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);CHKERRQ(ierr); 1284 } 1285 } 1286 ierr = PetscMallocGetMaximumUsage(&maxMem);CHKERRQ(ierr); 1287 ierr = PetscViewerASCIIPushSynchronized(viewer);CHKERRQ(ierr); 1288 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);CHKERRQ(ierr); 1289 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));CHKERRQ(ierr); 1290 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));CHKERRQ(ierr); 1291 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);CHKERRQ(ierr); 1292 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);CHKERRQ(ierr); 1293 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);CHKERRQ(ierr); 1294 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);CHKERRQ(ierr); 1295 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1296 for (stage=0; stage<numStages; stage++) { 1297 stageInfo = &stageLog->stageInfo[stage].perfInfo; 1298 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n", 1299 stageLog->stageInfo[stage].name,rank, 1300 stageInfo->time,stageInfo->numMessages,stageInfo->messageLength,stageInfo->numReductions,stageInfo->flops);CHKERRQ(ierr); 1301 ierr = MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1302 for (event = 0; event < numEvents; event++) { 1303 eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event]; 1304 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"syncTime\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g", 1305 stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank, 1306 eventInfo->count,eventInfo->time,eventInfo->syncTime,eventInfo->numMessages,eventInfo->messageLength,eventInfo->numReductions,eventInfo->flops);CHKERRQ(ierr); 1307 if (eventInfo->dof[0] >= 0.) { 1308 PetscInt d, e; 1309 1310 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", \"dof\" : [");CHKERRQ(ierr); 1311 for (d = 0; d < 8; ++d) { 1312 if (d > 0) {ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", ");CHKERRQ(ierr);} 1313 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->dof[d]);CHKERRQ(ierr); 1314 } 1315 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "]");CHKERRQ(ierr); 1316 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", \"error\" : [");CHKERRQ(ierr); 1317 for (e = 0; e < 8; ++e) { 1318 if (e > 0) {ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", ");CHKERRQ(ierr);} 1319 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo->errors[e]);CHKERRQ(ierr); 1320 } 1321 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "]");CHKERRQ(ierr); 1322 } 1323 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"}\n");CHKERRQ(ierr); 1324 } 1325 } 1326 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1327 ierr = PetscViewerASCIIPopSynchronized(viewer);CHKERRQ(ierr); 1328 PetscFunctionReturn(0); 1329 } 1330 1331 /* 1332 PetscLogView_CSV - Each process prints the times for its own events in Comma-Separated Value Format 1333 */ 1334 PetscErrorCode PetscLogView_CSV(PetscViewer viewer) 1335 { 1336 PetscStageLog stageLog; 1337 PetscEventPerfInfo *eventInfo = NULL; 1338 PetscLogDouble locTotalTime, maxMem; 1339 int numStages,numEvents,stage,event; 1340 MPI_Comm comm = PetscObjectComm((PetscObject) viewer); 1341 PetscMPIInt rank,size; 1342 PetscErrorCode ierr; 1343 1344 PetscFunctionBegin; 1345 ierr = MPI_Comm_size(comm, &size);CHKERRMPI(ierr); 1346 ierr = MPI_Comm_rank(comm, &rank);CHKERRMPI(ierr); 1347 /* Must preserve reduction count before we go on */ 1348 /* Get the total elapsed time */ 1349 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1350 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1351 ierr = MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1352 ierr = PetscMallocGetMaximumUsage(&maxMem);CHKERRQ(ierr); 1353 ierr = PetscViewerASCIIPushSynchronized(viewer);CHKERRQ(ierr); 1354 ierr = 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); 1355 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1356 for (stage=0; stage<numStages; stage++) { 1357 PetscEventPerfInfo *stageInfo = &stageLog->stageInfo[stage].perfInfo; 1358 1359 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"%s,summary,%d,1,%g,%g,%g,%g,%g\n", 1360 stageLog->stageInfo[stage].name,rank,stageInfo->time,stageInfo->numMessages,stageInfo->messageLength,stageInfo->numReductions,stageInfo->flops);CHKERRQ(ierr); 1361 ierr = MPI_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1362 for (event = 0; event < numEvents; event++) { 1363 eventInfo = &stageLog->stageInfo[stage].eventLog->eventInfo[event]; 1364 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"%s,%s,%d,%D,%g,%g,%g,%g,%g",stageLog->stageInfo[stage].name, 1365 stageLog->eventLog->eventInfo[event].name,rank,eventInfo->count,eventInfo->time,eventInfo->numMessages, 1366 eventInfo->messageLength,eventInfo->numReductions,eventInfo->flops);CHKERRQ(ierr); 1367 if (eventInfo->dof[0] >= 0.) { 1368 PetscInt d, e; 1369 1370 for (d = 0; d < 8; ++d) { 1371 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->dof[d]);CHKERRQ(ierr); 1372 } 1373 for (e = 0; e < 8; ++e) { 1374 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ",%g", eventInfo->errors[e]);CHKERRQ(ierr); 1375 } 1376 } 1377 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"\n");CHKERRQ(ierr); 1378 } 1379 } 1380 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1381 ierr = PetscViewerASCIIPopSynchronized(viewer);CHKERRQ(ierr); 1382 PetscFunctionReturn(0); 1383 } 1384 1385 static PetscErrorCode PetscLogViewWarnSync(MPI_Comm comm,FILE *fd) 1386 { 1387 PetscErrorCode ierr; 1388 PetscFunctionBegin; 1389 if (!PetscLogSyncOn) PetscFunctionReturn(0); 1390 ierr = PetscFPrintf(comm, fd, "\n\n");CHKERRQ(ierr); 1391 ierr = PetscFPrintf(comm, fd, " ##########################################################\n");CHKERRQ(ierr); 1392 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1393 ierr = PetscFPrintf(comm, fd, " # WARNING!!! #\n");CHKERRQ(ierr); 1394 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1395 ierr = PetscFPrintf(comm, fd, " # This program was run with logging synchronization. #\n");CHKERRQ(ierr); 1396 ierr = PetscFPrintf(comm, fd, " # This option provides more meaningful imbalance #\n");CHKERRQ(ierr); 1397 ierr = PetscFPrintf(comm, fd, " # figures at the expense of slowing things down and #\n");CHKERRQ(ierr); 1398 ierr = PetscFPrintf(comm, fd, " # providing a distorted view of the overall runtime. #\n");CHKERRQ(ierr); 1399 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1400 ierr = PetscFPrintf(comm, fd, " ##########################################################\n\n\n");CHKERRQ(ierr); 1401 PetscFunctionReturn(0); 1402 } 1403 1404 static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd) 1405 { 1406 PetscErrorCode ierr; 1407 1408 PetscFunctionBegin; 1409 if (PetscDefined(USE_DEBUG)) { 1410 ierr = PetscFPrintf(comm, fd, "\n\n");CHKERRQ(ierr); 1411 ierr = PetscFPrintf(comm, fd, " ##########################################################\n");CHKERRQ(ierr); 1412 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1413 ierr = PetscFPrintf(comm, fd, " # WARNING!!! #\n");CHKERRQ(ierr); 1414 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1415 ierr = PetscFPrintf(comm, fd, " # This code was compiled with a debugging option. #\n");CHKERRQ(ierr); 1416 ierr = PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");CHKERRQ(ierr); 1417 ierr = PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");CHKERRQ(ierr); 1418 ierr = PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");CHKERRQ(ierr); 1419 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1420 ierr = PetscFPrintf(comm, fd, " ##########################################################\n\n\n");CHKERRQ(ierr); 1421 } 1422 PetscFunctionReturn(0); 1423 } 1424 1425 static PetscErrorCode PetscLogViewWarnNoGpuAwareMpi(MPI_Comm comm,FILE *fd) 1426 { 1427 #if defined(PETSC_HAVE_DEVICE) 1428 PetscErrorCode ierr; 1429 PetscMPIInt size; 1430 1431 PetscFunctionBegin; 1432 ierr = MPI_Comm_size(comm, &size);CHKERRMPI(ierr); 1433 if (use_gpu_aware_mpi || size == 1 || !PetscCreatedGpuObjects) PetscFunctionReturn(0); 1434 ierr = PetscFPrintf(comm, fd, "\n\n");CHKERRQ(ierr); 1435 ierr = PetscFPrintf(comm, fd, " ##########################################################\n");CHKERRQ(ierr); 1436 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1437 ierr = PetscFPrintf(comm, fd, " # WARNING!!! #\n");CHKERRQ(ierr); 1438 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1439 ierr = PetscFPrintf(comm, fd, " # This code was compiled with GPU support and you've #\n");CHKERRQ(ierr); 1440 ierr = PetscFPrintf(comm, fd, " # created PETSc/GPU objects, but you intentionally used #\n");CHKERRQ(ierr); 1441 ierr = PetscFPrintf(comm, fd, " # -use_gpu_aware_mpi 0, such that PETSc had to copy data #\n");CHKERRQ(ierr); 1442 ierr = PetscFPrintf(comm, fd, " # from GPU to CPU for communication. To get meaningfull #\n");CHKERRQ(ierr); 1443 ierr = PetscFPrintf(comm, fd, " # timing results, please use GPU-aware MPI instead. #\n");CHKERRQ(ierr); 1444 ierr = PetscFPrintf(comm, fd, " ##########################################################\n\n\n");CHKERRQ(ierr); 1445 PetscFunctionReturn(0); 1446 #else 1447 return 0; 1448 #endif 1449 } 1450 1451 PetscErrorCode PetscLogView_Default(PetscViewer viewer) 1452 { 1453 FILE *fd; 1454 PetscLogDouble zero = 0.0; 1455 PetscStageLog stageLog; 1456 PetscStageInfo *stageInfo = NULL; 1457 PetscEventPerfInfo *eventInfo = NULL; 1458 PetscClassPerfInfo *classInfo; 1459 char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128]; 1460 const char *name; 1461 PetscLogDouble locTotalTime, TotalTime, TotalFlops; 1462 PetscLogDouble numMessages, messageLength, avgMessLen, numReductions; 1463 PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red; 1464 PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed; 1465 PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed; 1466 PetscLogDouble min, max, tot, ratio, avg, x, y; 1467 PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratC, totm, totml, totr, mal, malmax, emalmax; 1468 #if defined(PETSC_HAVE_DEVICE) 1469 PetscLogDouble cct, gct, csz, gsz, gmaxt, gflops, gflopr, fracgflops; 1470 #endif 1471 PetscMPIInt minC, maxC; 1472 PetscMPIInt size, rank; 1473 PetscBool *localStageUsed, *stageUsed; 1474 PetscBool *localStageVisible, *stageVisible; 1475 int numStages, localNumEvents, numEvents; 1476 int stage, oclass; 1477 PetscLogEvent event; 1478 PetscErrorCode ierr; 1479 char version[256]; 1480 MPI_Comm comm; 1481 1482 PetscFunctionBegin; 1483 ierr = PetscObjectGetComm((PetscObject)viewer,&comm);CHKERRQ(ierr); 1484 ierr = PetscViewerASCIIGetPointer(viewer,&fd);CHKERRQ(ierr); 1485 ierr = MPI_Comm_size(comm, &size);CHKERRMPI(ierr); 1486 ierr = MPI_Comm_rank(comm, &rank);CHKERRMPI(ierr); 1487 /* Get the total elapsed time */ 1488 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1489 1490 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1491 ierr = PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");CHKERRQ(ierr); 1492 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1493 ierr = PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");CHKERRQ(ierr); 1494 ierr = PetscLogViewWarnSync(comm,fd);CHKERRQ(ierr); 1495 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1496 ierr = PetscLogViewWarnNoGpuAwareMpi(comm,fd);CHKERRQ(ierr); 1497 ierr = PetscGetArchType(arch,sizeof(arch));CHKERRQ(ierr); 1498 ierr = PetscGetHostName(hostname,sizeof(hostname));CHKERRQ(ierr); 1499 ierr = PetscGetUserName(username,sizeof(username));CHKERRQ(ierr); 1500 ierr = PetscGetProgramName(pname,sizeof(pname));CHKERRQ(ierr); 1501 ierr = PetscGetDate(date,sizeof(date));CHKERRQ(ierr); 1502 ierr = PetscGetVersion(version,sizeof(version));CHKERRQ(ierr); 1503 if (size == 1) { 1504 ierr = PetscFPrintf(comm,fd,"%s on a %s named %s with %d processor, by %s %s\n", pname, arch, hostname, size, username, date);CHKERRQ(ierr); 1505 } else { 1506 ierr = PetscFPrintf(comm,fd,"%s on a %s named %s with %d processors, by %s %s\n", pname, arch, hostname, size, username, date);CHKERRQ(ierr); 1507 } 1508 #if defined(PETSC_HAVE_OPENMP) 1509 ierr = PetscFPrintf(comm,fd,"Using %D OpenMP threads\n", PetscNumOMPThreads);CHKERRQ(ierr); 1510 #endif 1511 ierr = PetscFPrintf(comm, fd, "Using %s\n", version);CHKERRQ(ierr); 1512 1513 /* Must preserve reduction count before we go on */ 1514 red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1515 1516 /* Calculate summary information */ 1517 ierr = PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total\n");CHKERRQ(ierr); 1518 /* Time */ 1519 ierr = MPI_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1520 ierr = MPI_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1521 ierr = MPI_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1522 avg = tot/((PetscLogDouble) size); 1523 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1524 ierr = PetscFPrintf(comm, fd, "Time (sec): %5.3e %7.3f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1525 TotalTime = tot; 1526 /* Objects */ 1527 avg = (PetscLogDouble) petsc_numObjects; 1528 ierr = MPI_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1529 ierr = MPI_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1530 ierr = MPI_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1531 avg = tot/((PetscLogDouble) size); 1532 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1533 ierr = PetscFPrintf(comm, fd, "Objects: %5.3e %7.3f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1534 /* Flops */ 1535 ierr = MPI_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1536 ierr = MPI_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1537 ierr = MPI_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1538 avg = tot/((PetscLogDouble) size); 1539 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1540 ierr = PetscFPrintf(comm, fd, "Flop: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1541 TotalFlops = tot; 1542 /* Flops/sec -- Must talk to Barry here */ 1543 if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime; else flops = 0.0; 1544 ierr = MPI_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1545 ierr = MPI_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1546 ierr = MPI_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1547 avg = tot/((PetscLogDouble) size); 1548 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1549 ierr = PetscFPrintf(comm, fd, "Flop/sec: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1550 /* Memory */ 1551 ierr = PetscMallocGetMaximumUsage(&mem);CHKERRQ(ierr); 1552 if (mem > 0.0) { 1553 ierr = MPI_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1554 ierr = MPI_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1555 ierr = MPI_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1556 avg = tot/((PetscLogDouble) size); 1557 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1558 ierr = PetscFPrintf(comm, fd, "Memory: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1559 } 1560 /* Messages */ 1561 mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct); 1562 ierr = MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1563 ierr = MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1564 ierr = MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1565 avg = tot/((PetscLogDouble) size); 1566 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1567 ierr = PetscFPrintf(comm, fd, "MPI Messages: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1568 numMessages = tot; 1569 /* Message Lengths */ 1570 mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len); 1571 ierr = MPI_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1572 ierr = MPI_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1573 ierr = MPI_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1574 if (numMessages != 0) avg = tot/numMessages; else avg = 0.0; 1575 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1576 ierr = PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %7.3f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1577 messageLength = tot; 1578 /* Reductions */ 1579 ierr = MPI_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1580 ierr = MPI_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1581 ierr = MPI_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1582 if (min != 0.0) ratio = max/min; else ratio = 0.0; 1583 ierr = PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %7.3f\n", max, ratio);CHKERRQ(ierr); 1584 numReductions = red; /* wrong because uses count from process zero */ 1585 ierr = PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");CHKERRQ(ierr); 1586 ierr = PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");CHKERRQ(ierr); 1587 ierr = PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");CHKERRQ(ierr); 1588 1589 /* Get total number of stages -- 1590 Currently, a single processor can register more stages than another, but stages must all be registered in order. 1591 We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID. 1592 This seems best accomplished by assoicating a communicator with each stage. 1593 */ 1594 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1595 ierr = MPI_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1596 ierr = PetscMalloc1(numStages, &localStageUsed);CHKERRQ(ierr); 1597 ierr = PetscMalloc1(numStages, &stageUsed);CHKERRQ(ierr); 1598 ierr = PetscMalloc1(numStages, &localStageVisible);CHKERRQ(ierr); 1599 ierr = PetscMalloc1(numStages, &stageVisible);CHKERRQ(ierr); 1600 if (numStages > 0) { 1601 stageInfo = stageLog->stageInfo; 1602 for (stage = 0; stage < numStages; stage++) { 1603 if (stage < stageLog->numStages) { 1604 localStageUsed[stage] = stageInfo[stage].used; 1605 localStageVisible[stage] = stageInfo[stage].perfInfo.visible; 1606 } else { 1607 localStageUsed[stage] = PETSC_FALSE; 1608 localStageVisible[stage] = PETSC_TRUE; 1609 } 1610 } 1611 ierr = MPI_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);CHKERRMPI(ierr); 1612 ierr = MPI_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);CHKERRMPI(ierr); 1613 for (stage = 0; stage < numStages; stage++) { 1614 if (stageUsed[stage]) { 1615 ierr = PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ------ --- Messages --- -- Message Lengths -- -- Reductions --\n");CHKERRQ(ierr); 1616 ierr = PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total Count %%Total Avg %%Total Count %%Total\n");CHKERRQ(ierr); 1617 break; 1618 } 1619 } 1620 for (stage = 0; stage < numStages; stage++) { 1621 if (!stageUsed[stage]) continue; 1622 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 1623 if (localStageUsed[stage]) { 1624 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1625 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1626 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1627 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1628 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1629 name = stageInfo[stage].name; 1630 } else { 1631 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1632 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1633 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1634 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1635 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1636 name = ""; 1637 } 1638 mess *= 0.5; messLen *= 0.5; red /= size; 1639 if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0; 1640 if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0; 1641 /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */ 1642 if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0; 1643 if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0; 1644 if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0; 1645 if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0; 1646 ierr = PetscFPrintf(comm, fd, "%2d: %15s: %6.4e %5.1f%% %6.4e %5.1f%% %5.3e %5.1f%% %5.3e %5.1f%% %5.3e %5.1f%%\n", 1647 stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops, 1648 mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);CHKERRQ(ierr); 1649 } 1650 } 1651 1652 ierr = PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1653 ierr = PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");CHKERRQ(ierr); 1654 ierr = PetscFPrintf(comm, fd, "Phase summary info:\n");CHKERRQ(ierr); 1655 ierr = PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");CHKERRQ(ierr); 1656 ierr = PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");CHKERRQ(ierr); 1657 ierr = PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");CHKERRQ(ierr); 1658 ierr = PetscFPrintf(comm, fd, " Mess: number of messages sent\n");CHKERRQ(ierr); 1659 ierr = PetscFPrintf(comm, fd, " AvgLen: average message length (bytes)\n");CHKERRQ(ierr); 1660 ierr = PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");CHKERRQ(ierr); 1661 ierr = PetscFPrintf(comm, fd, " Global: entire computation\n");CHKERRQ(ierr); 1662 ierr = PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");CHKERRQ(ierr); 1663 ierr = PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");CHKERRQ(ierr); 1664 ierr = PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");CHKERRQ(ierr); 1665 ierr = PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");CHKERRQ(ierr); 1666 ierr = PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");CHKERRQ(ierr); 1667 if (PetscLogMemory) { 1668 ierr = PetscFPrintf(comm, fd, " Malloc Mbytes: Memory allocated and kept during event (sum over all calls to event)\n");CHKERRQ(ierr); 1669 ierr = PetscFPrintf(comm, fd, " EMalloc Mbytes: extra memory allocated during event and then freed (maximum over all calls to events)\n");CHKERRQ(ierr); 1670 ierr = PetscFPrintf(comm, fd, " MMalloc Mbytes: Increase in high water mark of allocated memory (sum over all calls to event)\n");CHKERRQ(ierr); 1671 ierr = PetscFPrintf(comm, fd, " RMI Mbytes: Increase in resident memory (sum over all calls to event)\n");CHKERRQ(ierr); 1672 } 1673 #if defined(PETSC_HAVE_DEVICE) 1674 ierr = PetscFPrintf(comm, fd, " GPU Mflop/s: 10e-6 * (sum of flop on GPU over all processors)/(max GPU time over all processors)\n");CHKERRQ(ierr); 1675 ierr = PetscFPrintf(comm, fd, " CpuToGpu Count: total number of CPU to GPU copies per processor\n");CHKERRQ(ierr); 1676 ierr = PetscFPrintf(comm, fd, " CpuToGpu Size (Mbytes): 10e-6 * (total size of CPU to GPU copies per processor)\n");CHKERRQ(ierr); 1677 ierr = PetscFPrintf(comm, fd, " GpuToCpu Count: total number of GPU to CPU copies per processor\n");CHKERRQ(ierr); 1678 ierr = PetscFPrintf(comm, fd, " GpuToCpu Size (Mbytes): 10e-6 * (total size of GPU to CPU copies per processor)\n");CHKERRQ(ierr); 1679 ierr = PetscFPrintf(comm, fd, " GPU %%F: percent flops on GPU in this event\n");CHKERRQ(ierr); 1680 #endif 1681 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1682 1683 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1684 1685 /* Report events */ 1686 ierr = PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage ---- Total");CHKERRQ(ierr); 1687 if (PetscLogMemory) { 1688 ierr = PetscFPrintf(comm, fd," Malloc EMalloc MMalloc RMI");CHKERRQ(ierr); 1689 } 1690 #if defined(PETSC_HAVE_DEVICE) 1691 ierr = PetscFPrintf(comm, fd," GPU - CpuToGpu - - GpuToCpu - GPU");CHKERRQ(ierr); 1692 #endif 1693 ierr = PetscFPrintf(comm, fd,"\n");CHKERRQ(ierr); 1694 ierr = PetscFPrintf(comm, fd," Max Ratio Max Ratio Max Ratio Mess AvgLen Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s");CHKERRQ(ierr); 1695 if (PetscLogMemory) { 1696 ierr = PetscFPrintf(comm, fd," Mbytes Mbytes Mbytes Mbytes");CHKERRQ(ierr); 1697 } 1698 #if defined(PETSC_HAVE_DEVICE) 1699 ierr = PetscFPrintf(comm, fd," Mflop/s Count Size Count Size %%F");CHKERRQ(ierr); 1700 #endif 1701 ierr = PetscFPrintf(comm, fd,"\n");CHKERRQ(ierr); 1702 ierr = PetscFPrintf(comm, fd,"------------------------------------------------------------------------------------------------------------------------");CHKERRQ(ierr); 1703 if (PetscLogMemory) { 1704 ierr = PetscFPrintf(comm, fd,"-----------------------------");CHKERRQ(ierr); 1705 } 1706 #if defined(PETSC_HAVE_DEVICE) 1707 ierr = PetscFPrintf(comm, fd,"---------------------------------------");CHKERRQ(ierr); 1708 #endif 1709 ierr = PetscFPrintf(comm, fd,"\n");CHKERRQ(ierr); 1710 1711 /* Problem: The stage name will not show up unless the stage executed on proc 1 */ 1712 for (stage = 0; stage < numStages; stage++) { 1713 if (!stageVisible[stage]) continue; 1714 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 1715 if (localStageUsed[stage]) { 1716 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1717 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1718 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1719 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1720 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1721 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1722 } else { 1723 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1724 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1725 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1726 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1727 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1728 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1729 } 1730 mess *= 0.5; messLen *= 0.5; red /= size; 1731 1732 /* Get total number of events in this stage -- 1733 Currently, a single processor can register more events than another, but events must all be registered in order, 1734 just like stages. We can removed this requirement if necessary by having a global event numbering and indirection 1735 on the event ID. This seems best accomplished by associating a communicator with each stage. 1736 1737 Problem: If the event did not happen on proc 1, its name will not be available. 1738 Problem: Event visibility is not implemented 1739 */ 1740 if (localStageUsed[stage]) { 1741 eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo; 1742 localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents; 1743 } else localNumEvents = 0; 1744 ierr = MPI_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1745 for (event = 0; event < numEvents; event++) { 1746 /* CANNOT use MPI_Allreduce() since it might fail the line number check */ 1747 if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) { 1748 if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; else flopr = 0.0; 1749 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1750 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1751 ierr = MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1752 ierr = MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1753 ierr = MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1754 ierr = MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1755 ierr = MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1756 ierr = MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1757 ierr = MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1758 ierr = MPI_Allreduce(&eventInfo[event].count, &minC, 1, MPI_INT, MPI_MIN, comm);CHKERRMPI(ierr); 1759 ierr = MPI_Allreduce(&eventInfo[event].count, &maxC, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1760 if (PetscLogMemory) { 1761 ierr = MPI_Allreduce(&eventInfo[event].memIncrease, &mem, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1762 ierr = MPI_Allreduce(&eventInfo[event].mallocSpace, &mal, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1763 ierr = MPI_Allreduce(&eventInfo[event].mallocIncrease, &malmax,1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1764 ierr = MPI_Allreduce(&eventInfo[event].mallocIncreaseEvent, &emalmax,1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1765 } 1766 #if defined(PETSC_HAVE_DEVICE) 1767 ierr = MPI_Allreduce(&eventInfo[event].CpuToGpuCount, &cct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1768 ierr = MPI_Allreduce(&eventInfo[event].GpuToCpuCount, &gct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1769 ierr = MPI_Allreduce(&eventInfo[event].CpuToGpuSize, &csz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1770 ierr = MPI_Allreduce(&eventInfo[event].GpuToCpuSize, &gsz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1771 ierr = MPI_Allreduce(&eventInfo[event].GpuFlops, &gflops,1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1772 ierr = MPI_Allreduce(&eventInfo[event].GpuTime, &gmaxt ,1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1773 #endif 1774 name = stageLog->eventLog->eventInfo[event].name; 1775 } else { 1776 flopr = 0.0; 1777 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1778 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1779 ierr = MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1780 ierr = MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRMPI(ierr); 1781 ierr = MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1782 ierr = MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1783 ierr = MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1784 ierr = MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1785 ierr = MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1786 ierr = MPI_Allreduce(&ierr, &minC, 1, MPI_INT, MPI_MIN, comm);CHKERRMPI(ierr); 1787 ierr = MPI_Allreduce(&ierr, &maxC, 1, MPI_INT, MPI_MAX, comm);CHKERRMPI(ierr); 1788 if (PetscLogMemory) { 1789 ierr = MPI_Allreduce(&zero, &mem, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1790 ierr = MPI_Allreduce(&zero, &mal, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1791 ierr = MPI_Allreduce(&zero, &malmax, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1792 ierr = MPI_Allreduce(&zero, &emalmax,1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1793 } 1794 #if defined(PETSC_HAVE_DEVICE) 1795 ierr = MPI_Allreduce(&zero, &cct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1796 ierr = MPI_Allreduce(&zero, &gct, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1797 ierr = MPI_Allreduce(&zero, &csz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1798 ierr = MPI_Allreduce(&zero, &gsz, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1799 ierr = MPI_Allreduce(&zero, &gflops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRMPI(ierr); 1800 ierr = MPI_Allreduce(&zero, &gmaxt , 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRMPI(ierr); 1801 #endif 1802 name = ""; 1803 } 1804 if (mint < 0.0) { 1805 ierr = PetscFPrintf(comm, fd, "WARNING!!! Minimum time %g over all processors for %s is negative! This happens\n on some machines whose times cannot handle too rapid calls.!\n artificially changing minimum to zero.\n",mint,name); 1806 mint = 0; 1807 } 1808 if (minf < 0.0) SETERRQ2(PETSC_COMM_SELF,PETSC_ERR_PLIB,"Minimum flop %g over all processors for %s is negative! Not possible!",minf,name); 1809 totm *= 0.5; totml *= 0.5; totr /= size; 1810 1811 if (maxC != 0) { 1812 if (minC != 0) ratC = ((PetscLogDouble)maxC)/minC;else ratC = 0.0; 1813 if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0; 1814 if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0; 1815 if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0; 1816 if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0; 1817 if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0; 1818 if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0; 1819 if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0; 1820 if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0; 1821 if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0; 1822 if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0; 1823 if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0; 1824 if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0; 1825 if (totm != 0.0) totml /= totm; else totml = 0.0; 1826 if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0; 1827 if (fracStageTime > 1.00) {ierr = PetscFPrintf(comm, fd,"Warning -- total time of event greater than time of entire stage -- something is wrong with the timer\n");CHKERRQ(ierr);} 1828 ierr = PetscFPrintf(comm, fd, 1829 "%-16s %7d%4.1f %5.4e%4.1f %3.2e%4.1f %2.1e %2.1e %2.1e%3.0f%3.0f%3.0f%3.0f%3.0f %3.0f%3.0f%3.0f%3.0f%3.0f %5.0f", 1830 name, maxC, ratC, maxt, ratt, maxf, ratf, totm, totml, totr, 1831 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed, 1832 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed, 1833 PetscAbs(flopr)/1.0e6);CHKERRQ(ierr); 1834 if (PetscLogMemory) { 1835 ierr = PetscFPrintf(comm, fd," %5.0f %5.0f %5.0f %5.0f",mal/1.0e6,emalmax/1.0e6,malmax/1.0e6,mem/1.0e6);CHKERRQ(ierr); 1836 } 1837 #if defined(PETSC_HAVE_DEVICE) 1838 if (totf != 0.0) fracgflops = gflops/totf; else fracgflops = 0.0; 1839 if (gmaxt != 0.0) gflopr = gflops/gmaxt; else gflopr = 0.0; 1840 ierr = PetscFPrintf(comm, fd," %5.0f %4.0f %3.2e %4.0f %3.2e% 3.0f",PetscAbs(gflopr)/1.0e6,cct/size,csz/(1.0e6*size),gct/size,gsz/(1.0e6*size),100.0*fracgflops);CHKERRQ(ierr); 1841 #endif 1842 ierr = PetscFPrintf(comm, fd,"\n");CHKERRQ(ierr); 1843 } 1844 } 1845 } 1846 1847 /* Memory usage and object creation */ 1848 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------");CHKERRQ(ierr); 1849 if (PetscLogMemory) { 1850 ierr = PetscFPrintf(comm, fd, "-----------------------------");CHKERRQ(ierr); 1851 } 1852 #if defined(PETSC_HAVE_DEVICE) 1853 ierr = PetscFPrintf(comm, fd, "---------------------------------------");CHKERRQ(ierr); 1854 #endif 1855 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1856 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1857 ierr = PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");CHKERRQ(ierr); 1858 1859 /* Right now, only stages on the first processor are reported here, meaning only objects associated with 1860 the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then 1861 stats for stages local to processor sets. 1862 */ 1863 /* We should figure out the longest object name here (now 20 characters) */ 1864 ierr = PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");CHKERRQ(ierr); 1865 ierr = PetscFPrintf(comm, fd, "Reports information only for process 0.\n");CHKERRQ(ierr); 1866 for (stage = 0; stage < numStages; stage++) { 1867 if (localStageUsed[stage]) { 1868 classInfo = stageLog->stageInfo[stage].classLog->classInfo; 1869 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1870 for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) { 1871 if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) { 1872 ierr = PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name, 1873 classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem, 1874 classInfo[oclass].descMem);CHKERRQ(ierr); 1875 } 1876 } 1877 } else { 1878 if (!localStageVisible[stage]) continue; 1879 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1880 } 1881 } 1882 1883 ierr = PetscFree(localStageUsed);CHKERRQ(ierr); 1884 ierr = PetscFree(stageUsed);CHKERRQ(ierr); 1885 ierr = PetscFree(localStageVisible);CHKERRQ(ierr); 1886 ierr = PetscFree(stageVisible);CHKERRQ(ierr); 1887 1888 /* Information unrelated to this particular run */ 1889 ierr = PetscFPrintf(comm, fd, "========================================================================================================================\n");CHKERRQ(ierr); 1890 PetscTime(&y); 1891 PetscTime(&x); 1892 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1893 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1894 ierr = PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);CHKERRQ(ierr); 1895 /* MPI information */ 1896 if (size > 1) { 1897 MPI_Status status; 1898 PetscMPIInt tag; 1899 MPI_Comm newcomm; 1900 1901 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1902 PetscTime(&x); 1903 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1904 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1905 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1906 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1907 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1908 PetscTime(&y); 1909 ierr = PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);CHKERRQ(ierr); 1910 ierr = PetscCommDuplicate(comm,&newcomm, &tag);CHKERRQ(ierr); 1911 ierr = MPI_Barrier(comm);CHKERRMPI(ierr); 1912 if (rank) { 1913 ierr = MPI_Recv(NULL, 0, MPI_INT, rank-1, tag, newcomm, &status);CHKERRMPI(ierr); 1914 ierr = MPI_Send(NULL, 0, MPI_INT, (rank+1)%size, tag, newcomm);CHKERRMPI(ierr); 1915 } else { 1916 PetscTime(&x); 1917 ierr = MPI_Send(NULL, 0, MPI_INT, 1, tag, newcomm);CHKERRMPI(ierr); 1918 ierr = MPI_Recv(NULL, 0, MPI_INT, size-1, tag, newcomm, &status);CHKERRMPI(ierr); 1919 PetscTime(&y); 1920 ierr = PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);CHKERRQ(ierr); 1921 } 1922 ierr = PetscCommDestroy(&newcomm);CHKERRQ(ierr); 1923 } 1924 ierr = PetscOptionsView(NULL,viewer);CHKERRQ(ierr); 1925 1926 /* Machine and compile information */ 1927 #if defined(PETSC_USE_FORTRAN_KERNELS) 1928 ierr = PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");CHKERRQ(ierr); 1929 #else 1930 ierr = PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");CHKERRQ(ierr); 1931 #endif 1932 #if defined(PETSC_USE_64BIT_INDICES) 1933 ierr = PetscFPrintf(comm, fd, "Compiled with 64 bit PetscInt\n");CHKERRQ(ierr); 1934 #elif defined(PETSC_USE___FLOAT128) 1935 ierr = PetscFPrintf(comm, fd, "Compiled with 32 bit PetscInt\n");CHKERRQ(ierr); 1936 #endif 1937 #if defined(PETSC_USE_REAL_SINGLE) 1938 ierr = PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1939 #elif defined(PETSC_USE___FLOAT128) 1940 ierr = PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1941 #endif 1942 #if defined(PETSC_USE_REAL_MAT_SINGLE) 1943 ierr = PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");CHKERRQ(ierr); 1944 #else 1945 ierr = PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");CHKERRQ(ierr); 1946 #endif 1947 ierr = PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n", 1948 (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));CHKERRQ(ierr); 1949 1950 ierr = PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);CHKERRQ(ierr); 1951 ierr = PetscFPrintf(comm, fd, "%s", petscmachineinfo);CHKERRQ(ierr); 1952 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerinfo);CHKERRQ(ierr); 1953 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);CHKERRQ(ierr); 1954 ierr = PetscFPrintf(comm, fd, "%s", petsclinkerinfo);CHKERRQ(ierr); 1955 1956 /* Cleanup */ 1957 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1958 ierr = PetscLogViewWarnNoGpuAwareMpi(comm,fd);CHKERRQ(ierr); 1959 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1960 PetscFunctionReturn(0); 1961 } 1962 1963 /*@C 1964 PetscLogView - Prints a summary of the logging. 1965 1966 Collective over MPI_Comm 1967 1968 Input Parameter: 1969 . viewer - an ASCII viewer 1970 1971 Options Database Keys: 1972 + -log_view [:filename] - Prints summary of log information 1973 . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file 1974 . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it) 1975 . -log_view :filename.txt:ascii_flamegraph - Saves logging information in a format suitable for visualising as a Flame Graph (see below for how to view it) 1976 . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation 1977 - -log_trace [filename] - Displays a trace of what each process is doing 1978 1979 Notes: 1980 It is possible to control the logging programatically but we recommend using the options database approach whenever possible 1981 By default the summary is printed to stdout. 1982 1983 Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin() 1984 1985 If PETSc is configured with --with-logging=0 then this functionality is not available 1986 1987 To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current 1988 directory then open filename.xml with your browser. Specific notes for certain browsers 1989 $ Firefox and Internet explorer - simply open the file 1990 $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files 1991 $ Safari - see https://ccm.net/faq/36342-safari-how-to-enable-local-file-access 1992 or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with 1993 your browser. 1994 Alternatively, use the script ${PETSC_DIR}/lib/petsc/bin/petsc-performance-view to automatically open a new browser 1995 window and render the XML log file contents. 1996 1997 The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS 1998 1999 The Flame Graph output can be visualised using either the original Flame Graph script (https://github.com/brendangregg/FlameGraph) 2000 or using speedscope (https://www.speedscope.app). 2001 Old XML profiles may be converted into this format using the script ${PETSC_DIR}/lib/petsc/bin/xml2flamegraph.py. 2002 2003 Level: beginner 2004 2005 .seealso: PetscLogDefaultBegin(), PetscLogDump() 2006 @*/ 2007 PetscErrorCode PetscLogView(PetscViewer viewer) 2008 { 2009 PetscErrorCode ierr; 2010 PetscBool isascii; 2011 PetscViewerFormat format; 2012 int stage, lastStage; 2013 PetscStageLog stageLog; 2014 2015 PetscFunctionBegin; 2016 if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine"); 2017 /* Pop off any stages the user forgot to remove */ 2018 lastStage = 0; 2019 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 2020 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 2021 while (stage >= 0) { 2022 lastStage = stage; 2023 ierr = PetscStageLogPop(stageLog);CHKERRQ(ierr); 2024 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 2025 } 2026 ierr = PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);CHKERRQ(ierr); 2027 if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII"); 2028 ierr = PetscViewerGetFormat(viewer,&format);CHKERRQ(ierr); 2029 if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) { 2030 ierr = PetscLogView_Default(viewer);CHKERRQ(ierr); 2031 } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) { 2032 ierr = PetscLogView_Detailed(viewer);CHKERRQ(ierr); 2033 } else if (format == PETSC_VIEWER_ASCII_CSV) { 2034 ierr = PetscLogView_CSV(viewer);CHKERRQ(ierr); 2035 } else if (format == PETSC_VIEWER_ASCII_XML) { 2036 ierr = PetscLogView_Nested(viewer);CHKERRQ(ierr); 2037 } else if (format == PETSC_VIEWER_ASCII_FLAMEGRAPH) { 2038 ierr = PetscLogView_Flamegraph(viewer);CHKERRQ(ierr); 2039 } 2040 ierr = PetscStageLogPush(stageLog, lastStage);CHKERRQ(ierr); 2041 PetscFunctionReturn(0); 2042 } 2043 2044 /*@C 2045 PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed. 2046 2047 Collective on PETSC_COMM_WORLD 2048 2049 Not normally called by user 2050 2051 Level: intermediate 2052 2053 @*/ 2054 PetscErrorCode PetscLogViewFromOptions(void) 2055 { 2056 PetscErrorCode ierr; 2057 PetscViewer viewer; 2058 PetscBool flg; 2059 PetscViewerFormat format; 2060 2061 PetscFunctionBegin; 2062 ierr = PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,NULL,"-log_view",&viewer,&format,&flg);CHKERRQ(ierr); 2063 if (flg) { 2064 ierr = PetscViewerPushFormat(viewer,format);CHKERRQ(ierr); 2065 ierr = PetscLogView(viewer);CHKERRQ(ierr); 2066 ierr = PetscViewerPopFormat(viewer);CHKERRQ(ierr); 2067 ierr = PetscViewerDestroy(&viewer);CHKERRQ(ierr); 2068 } 2069 PetscFunctionReturn(0); 2070 } 2071 2072 /*----------------------------------------------- Counter Functions -------------------------------------------------*/ 2073 /*@C 2074 PetscGetFlops - Returns the number of flops used on this processor 2075 since the program began. 2076 2077 Not Collective 2078 2079 Output Parameter: 2080 flops - number of floating point operations 2081 2082 Notes: 2083 A global counter logs all PETSc flop counts. The user can use 2084 PetscLogFlops() to increment this counter to include flops for the 2085 application code. 2086 2087 Level: intermediate 2088 2089 .seealso: PetscTime(), PetscLogFlops() 2090 @*/ 2091 PetscErrorCode PetscGetFlops(PetscLogDouble *flops) 2092 { 2093 PetscFunctionBegin; 2094 *flops = petsc_TotalFlops; 2095 PetscFunctionReturn(0); 2096 } 2097 2098 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 2099 { 2100 PetscErrorCode ierr; 2101 size_t fullLength; 2102 va_list Argp; 2103 2104 PetscFunctionBegin; 2105 if (!petsc_logObjects) PetscFunctionReturn(0); 2106 va_start(Argp, format); 2107 ierr = PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);CHKERRQ(ierr); 2108 va_end(Argp); 2109 PetscFunctionReturn(0); 2110 } 2111 2112 /*MC 2113 PetscLogFlops - Adds floating point operations to the global counter. 2114 2115 Synopsis: 2116 #include <petsclog.h> 2117 PetscErrorCode PetscLogFlops(PetscLogDouble f) 2118 2119 Not Collective 2120 2121 Input Parameter: 2122 . f - flop counter 2123 2124 Usage: 2125 .vb 2126 PetscLogEvent USER_EVENT; 2127 PetscLogEventRegister("User event",0,&USER_EVENT); 2128 PetscLogEventBegin(USER_EVENT,0,0,0,0); 2129 [code segment to monitor] 2130 PetscLogFlops(user_flops) 2131 PetscLogEventEnd(USER_EVENT,0,0,0,0); 2132 .ve 2133 2134 Notes: 2135 A global counter logs all PETSc flop counts. The user can use 2136 PetscLogFlops() to increment this counter to include flops for the 2137 application code. 2138 2139 Level: intermediate 2140 2141 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops() 2142 2143 M*/ 2144 2145 /*MC 2146 PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice) 2147 to get accurate timings 2148 2149 Synopsis: 2150 #include <petsclog.h> 2151 void PetscPreLoadBegin(PetscBool flag,char *name); 2152 2153 Not Collective 2154 2155 Input Parameters: 2156 + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden 2157 with command line option -preload true or -preload false 2158 - name - name of first stage (lines of code timed separately with -log_view) to 2159 be preloaded 2160 2161 Usage: 2162 .vb 2163 PetscPreLoadBegin(PETSC_TRUE,"first stage); 2164 lines of code 2165 PetscPreLoadStage("second stage"); 2166 lines of code 2167 PetscPreLoadEnd(); 2168 .ve 2169 2170 Notes: 2171 Only works in C/C++, not Fortran 2172 2173 Flags available within the macro. 2174 + PetscPreLoadingUsed - true if we are or have done preloading 2175 . PetscPreLoadingOn - true if it is CURRENTLY doing preload 2176 . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second 2177 - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on 2178 The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin() 2179 and PetscPreLoadEnd() 2180 2181 Level: intermediate 2182 2183 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage() 2184 2185 M*/ 2186 2187 /*MC 2188 PetscPreLoadEnd - End a segment of code that may be preloaded (run twice) 2189 to get accurate timings 2190 2191 Synopsis: 2192 #include <petsclog.h> 2193 void PetscPreLoadEnd(void); 2194 2195 Not Collective 2196 2197 Usage: 2198 .vb 2199 PetscPreLoadBegin(PETSC_TRUE,"first stage); 2200 lines of code 2201 PetscPreLoadStage("second stage"); 2202 lines of code 2203 PetscPreLoadEnd(); 2204 .ve 2205 2206 Notes: 2207 only works in C/C++ not fortran 2208 2209 Level: intermediate 2210 2211 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage() 2212 2213 M*/ 2214 2215 /*MC 2216 PetscPreLoadStage - Start a new segment of code to be timed separately. 2217 to get accurate timings 2218 2219 Synopsis: 2220 #include <petsclog.h> 2221 void PetscPreLoadStage(char *name); 2222 2223 Not Collective 2224 2225 Usage: 2226 .vb 2227 PetscPreLoadBegin(PETSC_TRUE,"first stage); 2228 lines of code 2229 PetscPreLoadStage("second stage"); 2230 lines of code 2231 PetscPreLoadEnd(); 2232 .ve 2233 2234 Notes: 2235 only works in C/C++ not fortran 2236 2237 Level: intermediate 2238 2239 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd() 2240 2241 M*/ 2242 2243 #if defined(PETSC_HAVE_DEVICE) 2244 2245 #if defined(PETSC_HAVE_CUDA) 2246 #include <petscdevice.h> 2247 PETSC_EXTERN cudaEvent_t petsc_gputimer_begin; 2248 PETSC_EXTERN cudaEvent_t petsc_gputimer_end; 2249 #endif 2250 2251 #if defined(PETSC_HAVE_HIP) 2252 #include <petscdevice.h> 2253 PETSC_EXTERN hipEvent_t petsc_gputimer_begin; 2254 PETSC_EXTERN hipEvent_t petsc_gputimer_end; 2255 #endif 2256 2257 /*-------------------------------------------- GPU event Functions ----------------------------------------------*/ 2258 /*@C 2259 PetscLogGpuTimeBegin - Start timer for device 2260 2261 Notes: 2262 When CUDA or HIP is enabled, the timer is run on the GPU, it is a separate logging of time devoted to GPU computations (excluding kernel launch times). 2263 When CUDA or HIP is not available, the timer is run on the CPU, it is a separate logging of time devoted to GPU computations (including kernel launch times). 2264 There is no need to call WaitForCUDA() or WaitForHIP() between PetscLogGpuTimeBegin and PetscLogGpuTimeEnd 2265 This timer should NOT include times for data transfers between the GPU and CPU, nor setup actions such as allocating space. 2266 The regular logging captures the time for data transfers and any CPU activites during the event 2267 It is used to compute the flop rate on the GPU as it is actively engaged in running a kernel. 2268 2269 Developer Notes: 2270 The GPU event timer captures the execution time of all the kernels launched in the default stream by the CPU between PetscLogGpuTimeBegin() and PetsLogGpuTimeEnd(). 2271 PetscLogGpuTimeBegin() and PetsLogGpuTimeEnd() insert the begin and end events into the default stream (stream 0). The device will record a time stamp for the event when it reaches that event in the stream. The function xxxEventSynchronize() is called in PetsLogGpuTimeEnd() to block CPU execution, but not continued GPU excution, until the timer event is recorded. 2272 2273 Level: intermediate 2274 2275 .seealso: PetscLogView(), PetscLogGpuFlops(), PetscLogGpuTimeEnd() 2276 @*/ 2277 PetscErrorCode PetscLogGpuTimeBegin(void) 2278 { 2279 #if defined(PETSC_HAVE_CUDA) 2280 cudaError_t cerr; 2281 #elif defined(PETSC_HAVE_HIP) 2282 hipError_t cerr; 2283 #else 2284 PetscErrorCode ierr; 2285 #endif 2286 PetscFunctionBegin; 2287 #if defined(PETSC_USE_DEBUG) 2288 if (petsc_gtime_inuse) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_PLIB,"Forgot to call PetscLogGpuTimeEnd()?"); 2289 petsc_gtime_inuse = PETSC_TRUE; 2290 #endif 2291 if (!PetscLogPLB) PetscFunctionReturn(0); 2292 #if defined(PETSC_HAVE_CUDA) 2293 cerr = cudaEventRecord(petsc_gputimer_begin,PetscDefaultCudaStream);CHKERRCUDA(cerr); 2294 #elif defined(PETSC_HAVE_HIP) 2295 cerr = hipEventRecord(petsc_gputimer_begin,PetscDefaultHipStream);CHKERRHIP(cerr); 2296 #else 2297 ierr = PetscTimeSubtract(&petsc_gtime);CHKERRQ(ierr); 2298 #endif 2299 PetscFunctionReturn(0); 2300 } 2301 2302 /*@C 2303 PetscLogGpuTimeEnd - Stop timer for device 2304 2305 Level: intermediate 2306 2307 .seealso: PetscLogView(), PetscLogGpuFlops(), PetscLogGpuTimeBegin() 2308 @*/ 2309 PetscErrorCode PetscLogGpuTimeEnd(void) 2310 { 2311 #if defined(PETSC_HAVE_CUDA) 2312 float gtime; 2313 cudaError_t cerr; 2314 #elif defined(PETSC_HAVE_HIP) 2315 float gtime; 2316 hipError_t cerr; 2317 #else 2318 PetscErrorCode ierr; 2319 #endif 2320 PetscFunctionBegin; 2321 #if defined(PETSC_USE_DEBUG) 2322 if (!petsc_gtime_inuse) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_PLIB,"Forgot to call PetscLogGpuTimeBegin()?"); 2323 petsc_gtime_inuse = PETSC_FALSE; 2324 #endif 2325 if (!PetscLogPLE) PetscFunctionReturn(0); 2326 #if defined(PETSC_HAVE_CUDA) 2327 cerr = cudaEventRecord(petsc_gputimer_end,PetscDefaultCudaStream);CHKERRCUDA(cerr); 2328 cerr = cudaEventSynchronize(petsc_gputimer_end);CHKERRCUDA(cerr); 2329 cerr = cudaEventElapsedTime(>ime,petsc_gputimer_begin,petsc_gputimer_end);CHKERRCUDA(cerr); 2330 petsc_gtime += (PetscLogDouble)gtime/1000.0; /* convert milliseconds to seconds */ 2331 #elif defined(PETSC_HAVE_HIP) 2332 cerr = hipEventRecord(petsc_gputimer_end,PetscDefaultHipStream);CHKERRHIP(cerr); 2333 cerr = hipEventSynchronize(petsc_gputimer_end);CHKERRHIP(cerr); 2334 cerr = hipEventElapsedTime(>ime,petsc_gputimer_begin,petsc_gputimer_end);CHKERRHIP(cerr); 2335 petsc_gtime += (PetscLogDouble)gtime/1000.0; /* convert milliseconds to seconds */ 2336 #else 2337 ierr = PetscTimeAdd(&petsc_gtime);CHKERRQ(ierr); 2338 #endif 2339 PetscFunctionReturn(0); 2340 } 2341 #endif /* end of PETSC_HAVE_DEVICE */ 2342 2343 #else /* end of -DPETSC_USE_LOG section */ 2344 2345 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 2346 { 2347 PetscFunctionBegin; 2348 PetscFunctionReturn(0); 2349 } 2350 2351 #endif /* PETSC_USE_LOG*/ 2352 2353 PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 2354 PetscClassId PETSC_OBJECT_CLASSID = 0; 2355 2356 /*@C 2357 PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code. 2358 2359 Not Collective 2360 2361 Input Parameter: 2362 . name - The class name 2363 2364 Output Parameter: 2365 . oclass - The class id or classid 2366 2367 Level: developer 2368 2369 @*/ 2370 PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass) 2371 { 2372 #if defined(PETSC_USE_LOG) 2373 PetscStageLog stageLog; 2374 PetscInt stage; 2375 PetscErrorCode ierr; 2376 #endif 2377 2378 PetscFunctionBegin; 2379 *oclass = ++PETSC_LARGEST_CLASSID; 2380 #if defined(PETSC_USE_LOG) 2381 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 2382 ierr = PetscClassRegLogRegister(stageLog->classLog, name, *oclass);CHKERRQ(ierr); 2383 for (stage = 0; stage < stageLog->numStages; stage++) { 2384 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 2385 } 2386 #endif 2387 PetscFunctionReturn(0); 2388 } 2389 2390 #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE) 2391 #include <mpe.h> 2392 2393 PetscBool PetscBeganMPE = PETSC_FALSE; 2394 2395 PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2396 PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2397 2398 /*@C 2399 PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files 2400 and slows the program down. 2401 2402 Collective over PETSC_COMM_WORLD 2403 2404 Options Database Keys: 2405 . -log_mpe - Prints extensive log information 2406 2407 Notes: 2408 A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is 2409 intended for production runs since it logs only flop rates and object 2410 creation (and should not significantly slow the programs). 2411 2412 Level: advanced 2413 2414 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(), 2415 PetscLogEventDeactivate() 2416 @*/ 2417 PetscErrorCode PetscLogMPEBegin(void) 2418 { 2419 PetscErrorCode ierr; 2420 2421 PetscFunctionBegin; 2422 /* Do MPE initialization */ 2423 if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */ 2424 ierr = PetscInfo(0,"Initializing MPE.\n");CHKERRQ(ierr); 2425 ierr = MPE_Init_log();CHKERRQ(ierr); 2426 2427 PetscBeganMPE = PETSC_TRUE; 2428 } else { 2429 ierr = PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");CHKERRQ(ierr); 2430 } 2431 ierr = PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);CHKERRQ(ierr); 2432 PetscFunctionReturn(0); 2433 } 2434 2435 /*@C 2436 PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot. 2437 2438 Collective over PETSC_COMM_WORLD 2439 2440 Level: advanced 2441 2442 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin() 2443 @*/ 2444 PetscErrorCode PetscLogMPEDump(const char sname[]) 2445 { 2446 char name[PETSC_MAX_PATH_LEN]; 2447 PetscErrorCode ierr; 2448 2449 PetscFunctionBegin; 2450 if (PetscBeganMPE) { 2451 ierr = PetscInfo(0,"Finalizing MPE.\n");CHKERRQ(ierr); 2452 if (sname) { 2453 ierr = PetscStrcpy(name,sname);CHKERRQ(ierr); 2454 } else { 2455 ierr = PetscGetProgramName(name,sizeof(name));CHKERRQ(ierr); 2456 } 2457 ierr = MPE_Finish_log(name);CHKERRQ(ierr); 2458 } else { 2459 ierr = PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");CHKERRQ(ierr); 2460 } 2461 PetscFunctionReturn(0); 2462 } 2463 2464 #define PETSC_RGB_COLORS_MAX 39 2465 static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = { 2466 "OliveDrab: ", 2467 "BlueViolet: ", 2468 "CadetBlue: ", 2469 "CornflowerBlue: ", 2470 "DarkGoldenrod: ", 2471 "DarkGreen: ", 2472 "DarkKhaki: ", 2473 "DarkOliveGreen: ", 2474 "DarkOrange: ", 2475 "DarkOrchid: ", 2476 "DarkSeaGreen: ", 2477 "DarkSlateGray: ", 2478 "DarkTurquoise: ", 2479 "DeepPink: ", 2480 "DarkKhaki: ", 2481 "DimGray: ", 2482 "DodgerBlue: ", 2483 "GreenYellow: ", 2484 "HotPink: ", 2485 "IndianRed: ", 2486 "LavenderBlush: ", 2487 "LawnGreen: ", 2488 "LemonChiffon: ", 2489 "LightCoral: ", 2490 "LightCyan: ", 2491 "LightPink: ", 2492 "LightSalmon: ", 2493 "LightSlateGray: ", 2494 "LightYellow: ", 2495 "LimeGreen: ", 2496 "MediumPurple: ", 2497 "MediumSeaGreen: ", 2498 "MediumSlateBlue:", 2499 "MidnightBlue: ", 2500 "MintCream: ", 2501 "MistyRose: ", 2502 "NavajoWhite: ", 2503 "NavyBlue: ", 2504 "OliveDrab: " 2505 }; 2506 2507 /*@C 2508 PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister() 2509 2510 Not collective. Maybe it should be? 2511 2512 Output Parameter: 2513 . str - character string representing the color 2514 2515 Level: developer 2516 2517 .seealso: PetscLogEventRegister 2518 @*/ 2519 PetscErrorCode PetscLogMPEGetRGBColor(const char *str[]) 2520 { 2521 static int idx = 0; 2522 2523 PetscFunctionBegin; 2524 *str = PetscLogMPERGBColors[idx]; 2525 idx = (idx + 1)% PETSC_RGB_COLORS_MAX; 2526 PetscFunctionReturn(0); 2527 } 2528 2529 #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */ 2530