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 84 /* Logging functions */ 85 PetscErrorCode (*PetscLogPHC)(PetscObject) = NULL; 86 PetscErrorCode (*PetscLogPHD)(PetscObject) = NULL; 87 PetscErrorCode (*PetscLogPLB)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 88 PetscErrorCode (*PetscLogPLE)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject) = NULL; 89 90 /* Tracing event logging variables */ 91 FILE *petsc_tracefile = NULL; 92 int petsc_tracelevel = 0; 93 const char *petsc_traceblanks = " "; 94 char petsc_tracespace[128] = " "; 95 PetscLogDouble petsc_tracetime = 0.0; 96 static PetscBool PetscLogInitializeCalled = PETSC_FALSE; 97 98 /*---------------------------------------------- General Functions --------------------------------------------------*/ 99 /*@C 100 PetscLogDestroy - Destroys the object and event logging data and resets the global counters. 101 102 Not Collective 103 104 Notes: 105 This routine should not usually be used by programmers. Instead employ 106 PetscLogStagePush() and PetscLogStagePop(). 107 108 Level: developer 109 110 .keywords: log, destroy 111 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogStagePush(), PlogStagePop() 112 @*/ 113 PetscErrorCode PetscLogDestroy(void) 114 { 115 PetscStageLog stageLog; 116 PetscErrorCode ierr; 117 118 PetscFunctionBegin; 119 ierr = PetscFree(petsc_actions);CHKERRQ(ierr); 120 ierr = PetscFree(petsc_objects);CHKERRQ(ierr); 121 ierr = PetscLogNestedEnd();CHKERRQ(ierr); 122 ierr = PetscLogSet(NULL, NULL);CHKERRQ(ierr); 123 124 /* Resetting phase */ 125 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 126 ierr = PetscStageLogDestroy(stageLog);CHKERRQ(ierr); 127 128 petsc_TotalFlops = 0.0; 129 petsc_numActions = 0; 130 petsc_numObjects = 0; 131 petsc_numObjectsDestroyed = 0; 132 petsc_maxActions = 100; 133 petsc_maxObjects = 100; 134 petsc_actions = NULL; 135 petsc_objects = NULL; 136 petsc_logActions = PETSC_FALSE; 137 petsc_logObjects = PETSC_FALSE; 138 petsc_BaseTime = 0.0; 139 petsc_TotalFlops = 0.0; 140 petsc_tmp_flops = 0.0; 141 petsc_send_ct = 0.0; 142 petsc_recv_ct = 0.0; 143 petsc_send_len = 0.0; 144 petsc_recv_len = 0.0; 145 petsc_isend_ct = 0.0; 146 petsc_irecv_ct = 0.0; 147 petsc_isend_len = 0.0; 148 petsc_irecv_len = 0.0; 149 petsc_wait_ct = 0.0; 150 petsc_wait_any_ct = 0.0; 151 petsc_wait_all_ct = 0.0; 152 petsc_sum_of_waits_ct = 0.0; 153 petsc_allreduce_ct = 0.0; 154 petsc_gather_ct = 0.0; 155 petsc_scatter_ct = 0.0; 156 PETSC_LARGEST_EVENT = PETSC_EVENT; 157 PetscLogPHC = NULL; 158 PetscLogPHD = NULL; 159 petsc_tracefile = NULL; 160 petsc_tracelevel = 0; 161 petsc_traceblanks = " "; 162 petsc_tracespace[0] = ' '; petsc_tracespace[1] = 0; 163 petsc_tracetime = 0.0; 164 PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 165 PETSC_OBJECT_CLASSID = 0; 166 petsc_stageLog = 0; 167 PetscLogInitializeCalled = PETSC_FALSE; 168 PetscFunctionReturn(0); 169 } 170 171 /*@C 172 PetscLogSet - Sets the logging functions called at the beginning and ending of every event. 173 174 Not Collective 175 176 Input Parameters: 177 + b - The function called at beginning of event 178 - e - The function called at end of event 179 180 Level: developer 181 182 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogTraceBegin() 183 @*/ 184 PetscErrorCode PetscLogSet(PetscErrorCode (*b)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject), 185 PetscErrorCode (*e)(PetscLogEvent, int, PetscObject, PetscObject, PetscObject, PetscObject)) 186 { 187 PetscFunctionBegin; 188 PetscLogPLB = b; 189 PetscLogPLE = e; 190 PetscFunctionReturn(0); 191 } 192 193 /*------------------------------------------- Initialization Functions ----------------------------------------------*/ 194 /* 195 The data structures for logging are always created even if no logging is turned on. This is so events etc can 196 be registered in the code before the actually logging is turned on. 197 */ 198 PetscErrorCode PetscLogInitialize(void) 199 { 200 int stage; 201 PetscBool opt; 202 PetscErrorCode ierr; 203 204 PetscFunctionBegin; 205 if (PetscLogInitializeCalled) PetscFunctionReturn(0); 206 PetscLogInitializeCalled = PETSC_TRUE; 207 208 ierr = PetscOptionsHasName(NULL,NULL, "-log_exclude_actions", &opt);CHKERRQ(ierr); 209 if (opt) petsc_logActions = PETSC_FALSE; 210 ierr = PetscOptionsHasName(NULL,NULL, "-log_exclude_objects", &opt);CHKERRQ(ierr); 211 if (opt) petsc_logObjects = PETSC_FALSE; 212 if (petsc_logActions) { 213 ierr = PetscMalloc1(petsc_maxActions, &petsc_actions);CHKERRQ(ierr); 214 } 215 if (petsc_logObjects) { 216 ierr = PetscMalloc1(petsc_maxObjects, &petsc_objects);CHKERRQ(ierr); 217 } 218 PetscLogPHC = PetscLogObjCreateDefault; 219 PetscLogPHD = PetscLogObjDestroyDefault; 220 /* Setup default logging structures */ 221 ierr = PetscStageLogCreate(&petsc_stageLog);CHKERRQ(ierr); 222 ierr = PetscStageLogRegister(petsc_stageLog, "Main Stage", &stage);CHKERRQ(ierr); 223 224 /* All processors sync here for more consistent logging */ 225 ierr = MPI_Barrier(PETSC_COMM_WORLD);CHKERRQ(ierr); 226 PetscTime(&petsc_BaseTime); 227 ierr = PetscLogStagePush(stage);CHKERRQ(ierr); 228 PetscFunctionReturn(0); 229 } 230 231 /*@C 232 PetscLogDefaultBegin - Turns on logging of objects and events. This logs flop 233 rates and object creation and should not slow programs down too much. 234 This routine may be called more than once. 235 236 Logically Collective over PETSC_COMM_WORLD 237 238 Options Database Keys: 239 . -log_view [viewertype:filename:viewerformat] - Prints summary of flop and timing information to the 240 screen (for code configured with --with-log=1 (which is the default)) 241 242 Usage: 243 .vb 244 PetscInitialize(...); 245 PetscLogDefaultBegin(); 246 ... code ... 247 PetscLogView(viewer); or PetscLogDump(); 248 PetscFinalize(); 249 .ve 250 251 Notes: 252 PetscLogView(viewer) or PetscLogDump() actually cause the printing of 253 the logging information. 254 255 Level: advanced 256 257 .keywords: log, begin 258 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogTraceBegin() 259 @*/ 260 PetscErrorCode PetscLogDefaultBegin(void) 261 { 262 PetscErrorCode ierr; 263 264 PetscFunctionBegin; 265 ierr = PetscLogSet(PetscLogEventBeginDefault, PetscLogEventEndDefault);CHKERRQ(ierr); 266 PetscFunctionReturn(0); 267 } 268 269 /*@C 270 PetscLogAllBegin - Turns on extensive logging of objects and events. Logs 271 all events. This creates large log files and slows the program down. 272 273 Logically Collective on PETSC_COMM_WORLD 274 275 Options Database Keys: 276 . -log_all - Prints extensive log information 277 278 Usage: 279 .vb 280 PetscInitialize(...); 281 PetscLogAllBegin(); 282 ... code ... 283 PetscLogDump(filename); 284 PetscFinalize(); 285 .ve 286 287 Notes: 288 A related routine is PetscLogDefaultBegin() (with the options key -log), which is 289 intended for production runs since it logs only flop rates and object 290 creation (and shouldn't significantly slow the programs). 291 292 Level: advanced 293 294 .keywords: log, all, begin 295 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogTraceBegin() 296 @*/ 297 PetscErrorCode PetscLogAllBegin(void) 298 { 299 PetscErrorCode ierr; 300 301 PetscFunctionBegin; 302 ierr = PetscLogSet(PetscLogEventBeginComplete, PetscLogEventEndComplete);CHKERRQ(ierr); 303 PetscFunctionReturn(0); 304 } 305 306 /*@ 307 PetscLogTraceBegin - Activates trace logging. Every time a PETSc event 308 begins or ends, the event name is printed. 309 310 Logically Collective on PETSC_COMM_WORLD 311 312 Input Parameter: 313 . file - The file to print trace in (e.g. stdout) 314 315 Options Database Key: 316 . -log_trace [filename] - Activates PetscLogTraceBegin() 317 318 Notes: 319 PetscLogTraceBegin() prints the processor number, the execution time (sec), 320 then "Event begin:" or "Event end:" followed by the event name. 321 322 PetscLogTraceBegin() allows tracing of all PETSc calls, which is useful 323 to determine where a program is hanging without running in the 324 debugger. Can be used in conjunction with the -info option. 325 326 Level: intermediate 327 328 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogView(), PetscLogDefaultBegin() 329 @*/ 330 PetscErrorCode PetscLogTraceBegin(FILE *file) 331 { 332 PetscErrorCode ierr; 333 334 PetscFunctionBegin; 335 petsc_tracefile = file; 336 337 ierr = PetscLogSet(PetscLogEventBeginTrace, PetscLogEventEndTrace);CHKERRQ(ierr); 338 PetscFunctionReturn(0); 339 } 340 341 /*@ 342 PetscLogActions - Determines whether actions are logged for the graphical viewer. 343 344 Not Collective 345 346 Input Parameter: 347 . flag - PETSC_TRUE if actions are to be logged 348 349 Level: intermediate 350 351 Note: Logging of actions continues to consume more memory as the program 352 runs. Long running programs should consider turning this feature off. 353 354 Options Database Keys: 355 . -log_exclude_actions - Turns off actions logging 356 357 .keywords: log, stage, register 358 .seealso: PetscLogStagePush(), PetscLogStagePop() 359 @*/ 360 PetscErrorCode PetscLogActions(PetscBool flag) 361 { 362 PetscFunctionBegin; 363 petsc_logActions = flag; 364 PetscFunctionReturn(0); 365 } 366 367 /*@ 368 PetscLogObjects - Determines whether objects are logged for the graphical viewer. 369 370 Not Collective 371 372 Input Parameter: 373 . flag - PETSC_TRUE if objects are to be logged 374 375 Level: intermediate 376 377 Note: Logging of objects continues to consume more memory as the program 378 runs. Long running programs should consider turning this feature off. 379 380 Options Database Keys: 381 . -log_exclude_objects - Turns off objects logging 382 383 .keywords: log, stage, register 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 .keywords: log, stage, register 408 .seealso: PetscLogStagePush(), PetscLogStagePop() 409 @*/ 410 PetscErrorCode PetscLogStageRegister(const char sname[],PetscLogStage *stage) 411 { 412 PetscStageLog stageLog; 413 PetscLogEvent event; 414 PetscErrorCode ierr; 415 416 PetscFunctionBegin; 417 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 418 ierr = PetscStageLogRegister(stageLog, sname, stage);CHKERRQ(ierr); 419 /* Copy events already changed in the main stage, this sucks */ 420 ierr = PetscEventPerfLogEnsureSize(stageLog->stageInfo[*stage].eventLog, stageLog->eventLog->numEvents);CHKERRQ(ierr); 421 for (event = 0; event < stageLog->eventLog->numEvents; event++) { 422 ierr = PetscEventPerfInfoCopy(&stageLog->stageInfo[0].eventLog->eventInfo[event],&stageLog->stageInfo[*stage].eventLog->eventInfo[event]);CHKERRQ(ierr); 423 } 424 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[*stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 425 PetscFunctionReturn(0); 426 } 427 428 /*@C 429 PetscLogStagePush - This function pushes a stage on the stack. 430 431 Not Collective 432 433 Input Parameter: 434 . stage - The stage on which to log 435 436 Usage: 437 If the option -log_sumary is used to run the program containing the 438 following code, then 2 sets of summary data will be printed during 439 PetscFinalize(). 440 .vb 441 PetscInitialize(int *argc,char ***args,0,0); 442 [stage 0 of code] 443 PetscLogStagePush(1); 444 [stage 1 of code] 445 PetscLogStagePop(); 446 PetscBarrier(...); 447 [more stage 0 of code] 448 PetscFinalize(); 449 .ve 450 451 Notes: 452 Use PetscLogStageRegister() to register a stage. 453 454 Level: intermediate 455 456 .keywords: log, push, stage 457 .seealso: PetscLogStagePop(), PetscLogStageRegister(), PetscBarrier() 458 @*/ 459 PetscErrorCode PetscLogStagePush(PetscLogStage stage) 460 { 461 PetscStageLog stageLog; 462 PetscErrorCode ierr; 463 464 PetscFunctionBegin; 465 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 466 ierr = PetscStageLogPush(stageLog, stage);CHKERRQ(ierr); 467 PetscFunctionReturn(0); 468 } 469 470 /*@C 471 PetscLogStagePop - This function pops a stage from the stack. 472 473 Not Collective 474 475 Usage: 476 If the option -log_sumary is used to run the program containing the 477 following code, then 2 sets of summary data will be printed during 478 PetscFinalize(). 479 .vb 480 PetscInitialize(int *argc,char ***args,0,0); 481 [stage 0 of code] 482 PetscLogStagePush(1); 483 [stage 1 of code] 484 PetscLogStagePop(); 485 PetscBarrier(...); 486 [more stage 0 of code] 487 PetscFinalize(); 488 .ve 489 490 Notes: 491 Use PetscLogStageRegister() to register a stage. 492 493 Level: intermediate 494 495 .keywords: log, pop, stage 496 .seealso: PetscLogStagePush(), PetscLogStageRegister(), PetscBarrier() 497 @*/ 498 PetscErrorCode PetscLogStagePop(void) 499 { 500 PetscStageLog stageLog; 501 PetscErrorCode ierr; 502 503 PetscFunctionBegin; 504 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 505 ierr = PetscStageLogPop(stageLog);CHKERRQ(ierr); 506 PetscFunctionReturn(0); 507 } 508 509 /*@ 510 PetscLogStageSetActive - Determines stage activity for PetscLogEventBegin() and PetscLogEventEnd(). 511 512 Not Collective 513 514 Input Parameters: 515 + stage - The stage 516 - isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE) 517 518 Level: intermediate 519 520 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 521 @*/ 522 PetscErrorCode PetscLogStageSetActive(PetscLogStage stage, PetscBool isActive) 523 { 524 PetscStageLog stageLog; 525 PetscErrorCode ierr; 526 527 PetscFunctionBegin; 528 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 529 ierr = PetscStageLogSetActive(stageLog, stage, isActive);CHKERRQ(ierr); 530 PetscFunctionReturn(0); 531 } 532 533 /*@ 534 PetscLogStageGetActive - Returns stage activity for PetscLogEventBegin() and PetscLogEventEnd(). 535 536 Not Collective 537 538 Input Parameter: 539 . stage - The stage 540 541 Output Parameter: 542 . isActive - The activity flag, PETSC_TRUE for logging, else PETSC_FALSE (defaults to PETSC_TRUE) 543 544 Level: intermediate 545 546 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 547 @*/ 548 PetscErrorCode PetscLogStageGetActive(PetscLogStage stage, PetscBool *isActive) 549 { 550 PetscStageLog stageLog; 551 PetscErrorCode ierr; 552 553 PetscFunctionBegin; 554 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 555 ierr = PetscStageLogGetActive(stageLog, stage, isActive);CHKERRQ(ierr); 556 PetscFunctionReturn(0); 557 } 558 559 /*@ 560 PetscLogStageSetVisible - Determines stage visibility in PetscLogView() 561 562 Not Collective 563 564 Input Parameters: 565 + stage - The stage 566 - isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE) 567 568 Level: intermediate 569 570 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView() 571 @*/ 572 PetscErrorCode PetscLogStageSetVisible(PetscLogStage stage, PetscBool isVisible) 573 { 574 PetscStageLog stageLog; 575 PetscErrorCode ierr; 576 577 PetscFunctionBegin; 578 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 579 ierr = PetscStageLogSetVisible(stageLog, stage, isVisible);CHKERRQ(ierr); 580 PetscFunctionReturn(0); 581 } 582 583 /*@ 584 PetscLogStageGetVisible - Returns stage visibility in PetscLogView() 585 586 Not Collective 587 588 Input Parameter: 589 . stage - The stage 590 591 Output Parameter: 592 . isVisible - The visibility flag, PETSC_TRUE to print, else PETSC_FALSE (defaults to PETSC_TRUE) 593 594 Level: intermediate 595 596 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscLogView() 597 @*/ 598 PetscErrorCode PetscLogStageGetVisible(PetscLogStage stage, PetscBool *isVisible) 599 { 600 PetscStageLog stageLog; 601 PetscErrorCode ierr; 602 603 PetscFunctionBegin; 604 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 605 ierr = PetscStageLogGetVisible(stageLog, stage, isVisible);CHKERRQ(ierr); 606 PetscFunctionReturn(0); 607 } 608 609 /*@C 610 PetscLogStageGetId - Returns the stage id when given the stage name. 611 612 Not Collective 613 614 Input Parameter: 615 . name - The stage name 616 617 Output Parameter: 618 . stage - The stage, , or -1 if no stage with that name exists 619 620 Level: intermediate 621 622 .seealso: PetscLogStagePush(), PetscLogStagePop(), PetscPreLoadBegin(), PetscPreLoadEnd(), PetscPreLoadStage() 623 @*/ 624 PetscErrorCode PetscLogStageGetId(const char name[], PetscLogStage *stage) 625 { 626 PetscStageLog stageLog; 627 PetscErrorCode ierr; 628 629 PetscFunctionBegin; 630 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 631 ierr = PetscStageLogGetStage(stageLog, name, stage);CHKERRQ(ierr); 632 PetscFunctionReturn(0); 633 } 634 635 /*------------------------------------------------ Event Functions --------------------------------------------------*/ 636 /*@C 637 PetscLogEventRegister - Registers an event name for logging operations in an application code. 638 639 Not Collective 640 641 Input Parameter: 642 + name - The name associated with the event 643 - classid - The classid associated to the class for this event, obtain either with 644 PetscClassIdRegister() or use a predefined one such as KSP_CLASSID, SNES_CLASSID, the predefined ones 645 are only available in C code 646 647 Output Parameter: 648 . event - The event id for use with PetscLogEventBegin() and PetscLogEventEnd(). 649 650 Example of Usage: 651 .vb 652 PetscLogEvent USER_EVENT; 653 PetscClassId classid; 654 PetscLogDouble user_event_flops; 655 PetscClassIdRegister("class name",&classid); 656 PetscLogEventRegister("User event name",classid,&USER_EVENT); 657 PetscLogEventBegin(USER_EVENT,0,0,0,0); 658 [code segment to monitor] 659 PetscLogFlops(user_event_flops); 660 PetscLogEventEnd(USER_EVENT,0,0,0,0); 661 .ve 662 663 Notes: 664 PETSc automatically logs library events if the code has been 665 configured with --with-log (which is the default) and 666 -log_view or -log_all is specified. PetscLogEventRegister() is 667 intended for logging user events to supplement this PETSc 668 information. 669 670 PETSc can gather data for use with the utilities Jumpshot 671 (part of the MPICH distribution). If PETSc has been compiled 672 with flag -DPETSC_HAVE_MPE (MPE is an additional utility within 673 MPICH), the user can employ another command line option, -log_mpe, 674 to create a logfile, "mpe.log", which can be visualized 675 Jumpshot. 676 677 The classid is associated with each event so that classes of events 678 can be disabled simultaneously, such as all matrix events. The user 679 can either use an existing classid, such as MAT_CLASSID, or create 680 their own as shown in the example. 681 682 If an existing event with the same name exists, its event handle is 683 returned instead of creating a new event. 684 685 Level: intermediate 686 687 .keywords: log, event, register 688 .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogFlops(), 689 PetscLogEventActivate(), PetscLogEventDeactivate(), PetscClassIdRegister() 690 @*/ 691 PetscErrorCode PetscLogEventRegister(const char name[],PetscClassId classid,PetscLogEvent *event) 692 { 693 PetscStageLog stageLog; 694 int stage; 695 PetscErrorCode ierr; 696 697 PetscFunctionBegin; 698 *event = PETSC_DECIDE; 699 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 700 ierr = PetscEventRegLogGetEvent(stageLog->eventLog, name, event);CHKERRQ(ierr); 701 if (*event > 0) PetscFunctionReturn(0); 702 ierr = PetscEventRegLogRegister(stageLog->eventLog, name, classid, event);CHKERRQ(ierr); 703 for (stage = 0; stage < stageLog->numStages; stage++) { 704 ierr = PetscEventPerfLogEnsureSize(stageLog->stageInfo[stage].eventLog, stageLog->eventLog->numEvents);CHKERRQ(ierr); 705 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 706 } 707 PetscFunctionReturn(0); 708 } 709 710 /*@ 711 PetscLogEventActivate - Indicates that a particular event should be logged. 712 713 Not Collective 714 715 Input Parameter: 716 . event - The event id 717 718 Usage: 719 .vb 720 PetscLogEventDeactivate(VEC_SetValues); 721 [code where you do not want to log VecSetValues()] 722 PetscLogEventActivate(VEC_SetValues); 723 [code where you do want to log VecSetValues()] 724 .ve 725 726 Note: 727 The event may be either a pre-defined PETSc event (found in include/petsclog.h) 728 or an event number obtained with PetscLogEventRegister(). 729 730 Level: advanced 731 732 .keywords: log, event, activate 733 .seealso: PlogEventDeactivate() 734 @*/ 735 PetscErrorCode PetscLogEventActivate(PetscLogEvent event) 736 { 737 PetscStageLog stageLog; 738 int stage; 739 PetscErrorCode ierr; 740 741 PetscFunctionBegin; 742 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 743 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 744 ierr = PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 745 PetscFunctionReturn(0); 746 } 747 748 /*@ 749 PetscLogEventDeactivate - Indicates that a particular event should not be logged. 750 751 Not Collective 752 753 Input Parameter: 754 . event - The event id 755 756 Usage: 757 .vb 758 PetscLogEventDeactivate(VEC_SetValues); 759 [code where you do not want to log VecSetValues()] 760 PetscLogEventActivate(VEC_SetValues); 761 [code where you do want to log VecSetValues()] 762 .ve 763 764 Note: 765 The event may be either a pre-defined PETSc event (found in 766 include/petsclog.h) or an event number obtained with PetscLogEventRegister()). 767 768 Level: advanced 769 770 .keywords: log, event, deactivate 771 .seealso: PlogEventActivate() 772 @*/ 773 PetscErrorCode PetscLogEventDeactivate(PetscLogEvent event) 774 { 775 PetscStageLog stageLog; 776 int stage; 777 PetscErrorCode ierr; 778 779 PetscFunctionBegin; 780 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 781 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 782 ierr = PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 783 PetscFunctionReturn(0); 784 } 785 786 /*@ 787 PetscLogEventSetActiveAll - Sets the event activity in every stage. 788 789 Not Collective 790 791 Input Parameters: 792 + event - The event id 793 - isActive - The activity flag determining whether the event is logged 794 795 Level: advanced 796 797 .keywords: log, event, activate 798 .seealso: PlogEventActivate(),PlogEventDeactivate() 799 @*/ 800 PetscErrorCode PetscLogEventSetActiveAll(PetscLogEvent event, PetscBool isActive) 801 { 802 PetscStageLog stageLog; 803 int stage; 804 PetscErrorCode ierr; 805 806 PetscFunctionBegin; 807 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 808 for (stage = 0; stage < stageLog->numStages; stage++) { 809 if (isActive) { 810 ierr = PetscEventPerfLogActivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 811 } else { 812 ierr = PetscEventPerfLogDeactivate(stageLog->stageInfo[stage].eventLog, event);CHKERRQ(ierr); 813 } 814 } 815 PetscFunctionReturn(0); 816 } 817 818 /*@ 819 PetscLogEventActivateClass - Activates event logging for a PETSc object class. 820 821 Not Collective 822 823 Input Parameter: 824 . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc. 825 826 Level: developer 827 828 .keywords: log, event, activate, class 829 .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventDeactivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate() 830 @*/ 831 PetscErrorCode PetscLogEventActivateClass(PetscClassId classid) 832 { 833 PetscStageLog stageLog; 834 int stage; 835 PetscErrorCode ierr; 836 837 PetscFunctionBegin; 838 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 839 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 840 ierr = PetscEventPerfLogActivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 841 PetscFunctionReturn(0); 842 } 843 844 /*@ 845 PetscLogEventDeactivateClass - Deactivates event logging for a PETSc object class. 846 847 Not Collective 848 849 Input Parameter: 850 . classid - The event class, for example MAT_CLASSID, SNES_CLASSID, etc. 851 852 Level: developer 853 854 .keywords: log, event, deactivate, class 855 .seealso: PetscInfoActivate(),PetscInfo(),PetscInfoAllow(),PetscLogEventActivateClass(), PetscLogEventActivate(),PetscLogEventDeactivate() 856 @*/ 857 PetscErrorCode PetscLogEventDeactivateClass(PetscClassId classid) 858 { 859 PetscStageLog stageLog; 860 int stage; 861 PetscErrorCode ierr; 862 863 PetscFunctionBegin; 864 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 865 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 866 ierr = PetscEventPerfLogDeactivateClass(stageLog->stageInfo[stage].eventLog, stageLog->eventLog, classid);CHKERRQ(ierr); 867 PetscFunctionReturn(0); 868 } 869 870 /*MC 871 PetscLogEventBegin - Logs the beginning of a user event. 872 873 Synopsis: 874 #include <petsclog.h> 875 PetscErrorCode PetscLogEventBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4) 876 877 Not Collective 878 879 Input Parameters: 880 + e - integer associated with the event obtained from PetscLogEventRegister() 881 - o1,o2,o3,o4 - objects associated with the event, or 0 882 883 884 Fortran Synopsis: 885 void PetscLogEventBegin(int e,PetscErrorCode ierr) 886 887 Usage: 888 .vb 889 PetscLogEvent USER_EVENT; 890 PetscLogDouble user_event_flops; 891 PetscLogEventRegister("User event",0,&USER_EVENT); 892 PetscLogEventBegin(USER_EVENT,0,0,0,0); 893 [code segment to monitor] 894 PetscLogFlops(user_event_flops); 895 PetscLogEventEnd(USER_EVENT,0,0,0,0); 896 .ve 897 898 Notes: 899 You need to register each integer event with the command 900 PetscLogEventRegister(). 901 902 Level: intermediate 903 904 .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops() 905 906 .keywords: log, event, begin 907 M*/ 908 909 /*MC 910 PetscLogEventEnd - Log the end of a user event. 911 912 Synopsis: 913 #include <petsclog.h> 914 PetscErrorCode PetscLogEventEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4) 915 916 Not Collective 917 918 Input Parameters: 919 + e - integer associated with the event obtained with PetscLogEventRegister() 920 - o1,o2,o3,o4 - objects associated with the event, or 0 921 922 923 Fortran Synopsis: 924 void PetscLogEventEnd(int e,PetscErrorCode ierr) 925 926 Usage: 927 .vb 928 PetscLogEvent USER_EVENT; 929 PetscLogDouble user_event_flops; 930 PetscLogEventRegister("User event",0,&USER_EVENT,); 931 PetscLogEventBegin(USER_EVENT,0,0,0,0); 932 [code segment to monitor] 933 PetscLogFlops(user_event_flops); 934 PetscLogEventEnd(USER_EVENT,0,0,0,0); 935 .ve 936 937 Notes: 938 You should also register each additional integer event with the command 939 PetscLogEventRegister(). 940 941 Level: intermediate 942 943 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogFlops() 944 945 .keywords: log, event, end 946 M*/ 947 948 /*MC 949 PetscLogEventBarrierBegin - Logs the time in a barrier before an event. 950 951 Synopsis: 952 #include <petsclog.h> 953 PetscErrorCode PetscLogEventBarrierBegin(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm) 954 955 Not Collective 956 957 Input Parameters: 958 . e - integer associated with the event obtained from PetscLogEventRegister() 959 . o1,o2,o3,o4 - objects associated with the event, or 0 960 . comm - communicator the barrier takes place over 961 962 963 Usage: 964 .vb 965 PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm); 966 MPIU_Allreduce() 967 PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm); 968 .ve 969 970 Notes: 971 This is for logging the amount of time spent in a barrier for an event 972 that requires synchronization. 973 974 Additional Notes: 975 Synchronization events always come in pairs; for example, VEC_NormBarrier and 976 VEC_NormComm = VEC_NormBarrier + 1 977 978 Level: advanced 979 980 .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(), 981 PetscLogEventBarrierEnd() 982 983 .keywords: log, event, begin, barrier 984 M*/ 985 986 /*MC 987 PetscLogEventBarrierEnd - Logs the time in a barrier before an event. 988 989 Synopsis: 990 #include <petsclog.h> 991 PetscErrorCode PetscLogEventBarrierEnd(int e,PetscObject o1,PetscObject o2,PetscObject o3,PetscObject o4,MPI_Comm comm) 992 993 Logically Collective on MPI_Comm 994 995 Input Parameters: 996 . e - integer associated with the event obtained from PetscLogEventRegister() 997 . o1,o2,o3,o4 - objects associated with the event, or 0 998 . comm - communicator the barrier takes place over 999 1000 1001 Usage: 1002 .vb 1003 PetscLogEventBarrierBegin(VEC_NormBarrier,0,0,0,0,comm); 1004 MPIU_Allreduce() 1005 PetscLogEventBarrierEnd(VEC_NormBarrier,0,0,0,0,comm); 1006 .ve 1007 1008 Notes: 1009 This is for logging the amount of time spent in a barrier for an event 1010 that requires synchronization. 1011 1012 Additional Notes: 1013 Synchronization events always come in pairs; for example, VEC_NormBarrier and 1014 VEC_NormComm = VEC_NormBarrier + 1 1015 1016 Level: advanced 1017 1018 .seealso: PetscLogEventRegister(), PetscLogEventEnd(), PetscLogFlops(), PetscLogEventBegin(), 1019 PetscLogEventBarrierBegin() 1020 1021 .keywords: log, event, begin, barrier 1022 M*/ 1023 1024 /*@C 1025 PetscLogEventGetId - Returns the event id when given the event name. 1026 1027 Not Collective 1028 1029 Input Parameter: 1030 . name - The event name 1031 1032 Output Parameter: 1033 . event - The event, or -1 if no event with that name exists 1034 1035 Level: intermediate 1036 1037 .seealso: PetscLogEventBegin(), PetscLogEventEnd(), PetscLogStageGetId() 1038 @*/ 1039 PetscErrorCode PetscLogEventGetId(const char name[], PetscLogEvent *event) 1040 { 1041 PetscStageLog stageLog; 1042 PetscErrorCode ierr; 1043 1044 PetscFunctionBegin; 1045 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1046 ierr = PetscEventRegLogGetEvent(stageLog->eventLog, name, event);CHKERRQ(ierr); 1047 PetscFunctionReturn(0); 1048 } 1049 1050 1051 /*------------------------------------------------ Output Functions -------------------------------------------------*/ 1052 /*@C 1053 PetscLogDump - Dumps logs of objects to a file. This file is intended to 1054 be read by bin/petscview. This program no longer exists. 1055 1056 Collective on PETSC_COMM_WORLD 1057 1058 Input Parameter: 1059 . name - an optional file name 1060 1061 Usage: 1062 .vb 1063 PetscInitialize(...); 1064 PetscLogDefaultBegin(); or PetscLogAllBegin(); 1065 ... code ... 1066 PetscLogDump(filename); 1067 PetscFinalize(); 1068 .ve 1069 1070 Notes: 1071 The default file name is 1072 $ Log.<rank> 1073 where <rank> is the processor number. If no name is specified, 1074 this file will be used. 1075 1076 Level: advanced 1077 1078 .keywords: log, dump 1079 .seealso: PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogView() 1080 @*/ 1081 PetscErrorCode PetscLogDump(const char sname[]) 1082 { 1083 PetscStageLog stageLog; 1084 PetscEventPerfInfo *eventInfo; 1085 FILE *fd; 1086 char file[PETSC_MAX_PATH_LEN], fname[PETSC_MAX_PATH_LEN]; 1087 PetscLogDouble flops, _TotalTime; 1088 PetscMPIInt rank; 1089 int action, object, curStage; 1090 PetscLogEvent event; 1091 PetscErrorCode ierr; 1092 1093 PetscFunctionBegin; 1094 /* Calculate the total elapsed time */ 1095 PetscTime(&_TotalTime); 1096 _TotalTime -= petsc_BaseTime; 1097 /* Open log file */ 1098 ierr = MPI_Comm_rank(PETSC_COMM_WORLD, &rank);CHKERRQ(ierr); 1099 if (sname) sprintf(file, "%s.%d", sname, rank); 1100 else sprintf(file, "Log.%d", rank); 1101 ierr = PetscFixFilename(file, fname);CHKERRQ(ierr); 1102 ierr = PetscFOpen(PETSC_COMM_WORLD, fname, "w", &fd);CHKERRQ(ierr); 1103 if ((!rank) && (!fd)) SETERRQ1(PETSC_COMM_SELF,PETSC_ERR_FILE_OPEN, "Cannot open file: %s", fname); 1104 /* Output totals */ 1105 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Total Flop %14e %16.8e\n", petsc_TotalFlops, _TotalTime);CHKERRQ(ierr); 1106 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Clock Resolution %g\n", 0.0);CHKERRQ(ierr); 1107 /* Output actions */ 1108 if (petsc_logActions) { 1109 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Actions accomplished %d\n", petsc_numActions);CHKERRQ(ierr); 1110 for (action = 0; action < petsc_numActions; action++) { 1111 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "%g %d %d %d %d %d %d %g %g %g\n", 1112 petsc_actions[action].time, petsc_actions[action].action, (int)petsc_actions[action].event, (int)petsc_actions[action].classid, petsc_actions[action].id1, 1113 petsc_actions[action].id2, petsc_actions[action].id3, petsc_actions[action].flops, petsc_actions[action].mem, petsc_actions[action].maxmem);CHKERRQ(ierr); 1114 } 1115 } 1116 /* Output objects */ 1117 if (petsc_logObjects) { 1118 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Objects created %d destroyed %d\n", petsc_numObjects, petsc_numObjectsDestroyed);CHKERRQ(ierr); 1119 for (object = 0; object < petsc_numObjects; object++) { 1120 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Parent ID: %d Memory: %d\n", petsc_objects[object].parent, (int) petsc_objects[object].mem);CHKERRQ(ierr); 1121 if (!petsc_objects[object].name[0]) { 1122 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd,"No Name\n");CHKERRQ(ierr); 1123 } else { 1124 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Name: %s\n", petsc_objects[object].name);CHKERRQ(ierr); 1125 } 1126 if (petsc_objects[object].info[0] != 0) { 1127 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "No Info\n");CHKERRQ(ierr); 1128 } else { 1129 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Info: %s\n", petsc_objects[object].info);CHKERRQ(ierr); 1130 } 1131 } 1132 } 1133 /* Output events */ 1134 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "Event log:\n");CHKERRQ(ierr); 1135 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1136 ierr = PetscIntStackTop(stageLog->stack, &curStage);CHKERRQ(ierr); 1137 eventInfo = stageLog->stageInfo[curStage].eventLog->eventInfo; 1138 for (event = 0; event < stageLog->stageInfo[curStage].eventLog->numEvents; event++) { 1139 if (eventInfo[event].time != 0.0) flops = eventInfo[event].flops/eventInfo[event].time; 1140 else flops = 0.0; 1141 ierr = PetscFPrintf(PETSC_COMM_WORLD, fd, "%d %16d %16g %16g %16g\n", event, eventInfo[event].count, 1142 eventInfo[event].flops, eventInfo[event].time, flops);CHKERRQ(ierr); 1143 } 1144 ierr = PetscFClose(PETSC_COMM_WORLD, fd);CHKERRQ(ierr); 1145 PetscFunctionReturn(0); 1146 } 1147 1148 /* 1149 PetscLogView_Detailed - Each process prints the times for its own events 1150 1151 */ 1152 PetscErrorCode PetscLogView_Detailed(PetscViewer viewer) 1153 { 1154 MPI_Comm comm = PetscObjectComm((PetscObject) viewer); 1155 PetscEventPerfInfo *eventInfo = NULL; 1156 PetscLogDouble locTotalTime, numRed, maxMem; 1157 PetscStageLog stageLog; 1158 int numStages,numEvents,stage,event; 1159 PetscMPIInt rank,size; 1160 PetscErrorCode ierr; 1161 1162 PetscFunctionBegin; 1163 ierr = MPI_Comm_size(comm, &size);CHKERRQ(ierr); 1164 ierr = MPI_Comm_rank(comm, &rank);CHKERRQ(ierr); 1165 /* Must preserve reduction count before we go on */ 1166 numRed = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1167 /* Get the total elapsed time */ 1168 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1169 ierr = PetscViewerASCIIPrintf(viewer,"size = %d\n",size);CHKERRQ(ierr); 1170 ierr = PetscViewerASCIIPrintf(viewer,"LocalTimes = {}\n");CHKERRQ(ierr); 1171 ierr = PetscViewerASCIIPrintf(viewer,"LocalFlop = {}\n");CHKERRQ(ierr); 1172 ierr = PetscViewerASCIIPrintf(viewer,"LocalMessageLens = {}\n");CHKERRQ(ierr); 1173 ierr = PetscViewerASCIIPrintf(viewer,"LocalMessages = {}\n");CHKERRQ(ierr); 1174 ierr = PetscViewerASCIIPrintf(viewer,"LocalReductions = {}\n");CHKERRQ(ierr); 1175 ierr = PetscViewerASCIIPrintf(viewer,"LocalObjects = {}\n");CHKERRQ(ierr); 1176 ierr = PetscViewerASCIIPrintf(viewer,"LocalMemory = {}\n");CHKERRQ(ierr); 1177 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1178 ierr = MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1179 ierr = PetscViewerASCIIPrintf(viewer,"Stages = {}\n");CHKERRQ(ierr); 1180 for (stage=0; stage<numStages; stage++) { 1181 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"] = {}\n",stageLog->stageInfo[stage].name);CHKERRQ(ierr); 1182 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"summary\"] = {}\n",stageLog->stageInfo[stage].name);CHKERRQ(ierr); 1183 ierr = MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1184 for (event = 0; event < numEvents; event++) { 1185 ierr = PetscViewerASCIIPrintf(viewer,"Stages[\"%s\"][\"%s\"] = {}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name);CHKERRQ(ierr); 1186 } 1187 } 1188 ierr = PetscViewerASCIIPushSynchronized(viewer);CHKERRQ(ierr); 1189 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalTimes[%d] = %g\n",rank,locTotalTime);CHKERRQ(ierr); 1190 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalFlop[%d] = %g\n",rank,petsc_TotalFlops);CHKERRQ(ierr); 1191 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessageLens[%d] = %g\n",rank,(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len));CHKERRQ(ierr); 1192 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMessages[%d] = %g\n",rank,(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct));CHKERRQ(ierr); 1193 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalReductions[%d] = %g\n",rank,numRed);CHKERRQ(ierr); 1194 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalObjects[%d] = %d\n",rank,petsc_numObjects);CHKERRQ(ierr); 1195 ierr = PetscMallocGetMaximumUsage(&maxMem);CHKERRQ(ierr); 1196 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"LocalMemory[%d] = %g\n",rank,maxMem);CHKERRQ(ierr); 1197 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1198 for (stage=0; stage<numStages; stage++) { 1199 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"summary\"][%d] = {\"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n", 1200 stageLog->stageInfo[stage].name,rank, 1201 stageLog->stageInfo[stage].perfInfo.time,stageLog->stageInfo[stage].perfInfo.numMessages,stageLog->stageInfo[stage].perfInfo.messageLength, 1202 stageLog->stageInfo[stage].perfInfo.numReductions,stageLog->stageInfo[stage].perfInfo.flops);CHKERRQ(ierr); 1203 ierr = MPIU_Allreduce(&stageLog->stageInfo[stage].eventLog->numEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1204 for (event = 0; event < numEvents; event++) { 1205 eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo; 1206 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"Stages[\"%s\"][\"%s\"][%d] = {\"count\" : %D, \"time\" : %g, \"numMessages\" : %g, \"messageLength\" : %g, \"numReductions\" : %g, \"flop\" : %g}\n",stageLog->stageInfo[stage].name,stageLog->eventLog->eventInfo[event].name,rank, 1207 eventInfo[event].count, eventInfo[event].time,eventInfo[event].numMessages, eventInfo[event].messageLength, 1208 eventInfo[event].numReductions,eventInfo[event].flops);CHKERRQ(ierr); 1209 } 1210 } 1211 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1212 ierr = PetscViewerASCIIPopSynchronized(viewer);CHKERRQ(ierr); 1213 PetscFunctionReturn(0); 1214 } 1215 1216 static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd) 1217 { 1218 #if defined(PETSC_USE_DEBUG) 1219 PetscErrorCode ierr; 1220 1221 PetscFunctionBegin; 1222 ierr = PetscFPrintf(comm, fd, "\n\n");CHKERRQ(ierr); 1223 ierr = PetscFPrintf(comm, fd, " ##########################################################\n");CHKERRQ(ierr); 1224 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1225 ierr = PetscFPrintf(comm, fd, " # WARNING!!! #\n");CHKERRQ(ierr); 1226 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1227 ierr = PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");CHKERRQ(ierr); 1228 ierr = PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");CHKERRQ(ierr); 1229 ierr = PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");CHKERRQ(ierr); 1230 ierr = PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");CHKERRQ(ierr); 1231 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1232 ierr = PetscFPrintf(comm, fd, " ##########################################################\n\n\n");CHKERRQ(ierr); 1233 PetscFunctionReturn(0); 1234 #else 1235 return 0; 1236 #endif 1237 } 1238 1239 PetscErrorCode PetscLogView_Default(PetscViewer viewer) 1240 { 1241 FILE *fd; 1242 PetscLogDouble zero = 0.0; 1243 PetscStageLog stageLog; 1244 PetscStageInfo *stageInfo = NULL; 1245 PetscEventPerfInfo *eventInfo = NULL; 1246 PetscClassPerfInfo *classInfo; 1247 char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128]; 1248 const char *name; 1249 PetscLogDouble locTotalTime, TotalTime, TotalFlops; 1250 PetscLogDouble numMessages, messageLength, avgMessLen, numReductions; 1251 PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red; 1252 PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed; 1253 PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed; 1254 PetscLogDouble min, max, tot, ratio, avg, x, y; 1255 PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr; 1256 PetscMPIInt minCt, maxCt; 1257 PetscMPIInt size, rank; 1258 PetscBool *localStageUsed, *stageUsed; 1259 PetscBool *localStageVisible, *stageVisible; 1260 int numStages, localNumEvents, numEvents; 1261 int stage, oclass; 1262 PetscLogEvent event; 1263 PetscErrorCode ierr; 1264 char version[256]; 1265 MPI_Comm comm; 1266 1267 PetscFunctionBegin; 1268 ierr = PetscObjectGetComm((PetscObject)viewer,&comm);CHKERRQ(ierr); 1269 ierr = PetscViewerASCIIGetPointer(viewer,&fd);CHKERRQ(ierr); 1270 ierr = MPI_Comm_size(comm, &size);CHKERRQ(ierr); 1271 ierr = MPI_Comm_rank(comm, &rank);CHKERRQ(ierr); 1272 /* Get the total elapsed time */ 1273 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1274 1275 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1276 ierr = PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");CHKERRQ(ierr); 1277 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1278 ierr = PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");CHKERRQ(ierr); 1279 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1280 ierr = PetscGetArchType(arch,sizeof(arch));CHKERRQ(ierr); 1281 ierr = PetscGetHostName(hostname,sizeof(hostname));CHKERRQ(ierr); 1282 ierr = PetscGetUserName(username,sizeof(username));CHKERRQ(ierr); 1283 ierr = PetscGetProgramName(pname,sizeof(pname));CHKERRQ(ierr); 1284 ierr = PetscGetDate(date,sizeof(date));CHKERRQ(ierr); 1285 ierr = PetscGetVersion(version,sizeof(version));CHKERRQ(ierr); 1286 if (size == 1) { 1287 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); 1288 } else { 1289 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); 1290 } 1291 1292 ierr = PetscFPrintf(comm, fd, "Using %s\n", version);CHKERRQ(ierr); 1293 1294 /* Must preserve reduction count before we go on */ 1295 red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1296 1297 /* Calculate summary information */ 1298 ierr = PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");CHKERRQ(ierr); 1299 /* Time */ 1300 ierr = MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1301 ierr = MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1302 ierr = MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1303 avg = (tot)/((PetscLogDouble) size); 1304 if (min != 0.0) ratio = max/min; 1305 else ratio = 0.0; 1306 ierr = PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1307 TotalTime = tot; 1308 /* Objects */ 1309 avg = (PetscLogDouble) petsc_numObjects; 1310 ierr = MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1311 ierr = MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1312 ierr = MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1313 avg = (tot)/((PetscLogDouble) size); 1314 if (min != 0.0) ratio = max/min; 1315 else ratio = 0.0; 1316 ierr = PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1317 /* Flops */ 1318 ierr = MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1319 ierr = MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1320 ierr = MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1321 avg = (tot)/((PetscLogDouble) size); 1322 if (min != 0.0) ratio = max/min; 1323 else ratio = 0.0; 1324 ierr = PetscFPrintf(comm, fd, "Flop: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1325 TotalFlops = tot; 1326 /* Flops/sec -- Must talk to Barry here */ 1327 if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime; 1328 else flops = 0.0; 1329 ierr = MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1330 ierr = MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1331 ierr = MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1332 avg = (tot)/((PetscLogDouble) size); 1333 if (min != 0.0) ratio = max/min; 1334 else ratio = 0.0; 1335 ierr = PetscFPrintf(comm, fd, "Flop/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1336 /* Memory */ 1337 ierr = PetscMallocGetMaximumUsage(&mem);CHKERRQ(ierr); 1338 if (mem > 0.0) { 1339 ierr = MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1340 ierr = MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1341 ierr = MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1342 avg = (tot)/((PetscLogDouble) size); 1343 if (min != 0.0) ratio = max/min; 1344 else ratio = 0.0; 1345 ierr = PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);CHKERRQ(ierr); 1346 } 1347 /* Messages */ 1348 mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct); 1349 ierr = MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1350 ierr = MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1351 ierr = MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1352 avg = (tot)/((PetscLogDouble) size); 1353 if (min != 0.0) ratio = max/min; 1354 else ratio = 0.0; 1355 ierr = PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1356 numMessages = tot; 1357 /* Message Lengths */ 1358 mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len); 1359 ierr = MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1360 ierr = MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1361 ierr = MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1362 if (numMessages != 0) avg = (tot)/(numMessages); 1363 else avg = 0.0; 1364 if (min != 0.0) ratio = max/min; 1365 else ratio = 0.0; 1366 ierr = PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1367 messageLength = tot; 1368 /* Reductions */ 1369 ierr = MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1370 ierr = MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1371 ierr = MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1372 if (min != 0.0) ratio = max/min; 1373 else ratio = 0.0; 1374 ierr = PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);CHKERRQ(ierr); 1375 numReductions = red; /* wrong because uses count from process zero */ 1376 ierr = PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");CHKERRQ(ierr); 1377 ierr = PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");CHKERRQ(ierr); 1378 ierr = PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");CHKERRQ(ierr); 1379 1380 /* Get total number of stages -- 1381 Currently, a single processor can register more stages than another, but stages must all be registered in order. 1382 We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID. 1383 This seems best accomplished by assoicating a communicator with each stage. 1384 */ 1385 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1386 ierr = MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1387 ierr = PetscMalloc1(numStages, &localStageUsed);CHKERRQ(ierr); 1388 ierr = PetscMalloc1(numStages, &stageUsed);CHKERRQ(ierr); 1389 ierr = PetscMalloc1(numStages, &localStageVisible);CHKERRQ(ierr); 1390 ierr = PetscMalloc1(numStages, &stageVisible);CHKERRQ(ierr); 1391 if (numStages > 0) { 1392 stageInfo = stageLog->stageInfo; 1393 for (stage = 0; stage < numStages; stage++) { 1394 if (stage < stageLog->numStages) { 1395 localStageUsed[stage] = stageInfo[stage].used; 1396 localStageVisible[stage] = stageInfo[stage].perfInfo.visible; 1397 } else { 1398 localStageUsed[stage] = PETSC_FALSE; 1399 localStageVisible[stage] = PETSC_TRUE; 1400 } 1401 } 1402 ierr = MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);CHKERRQ(ierr); 1403 ierr = MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);CHKERRQ(ierr); 1404 for (stage = 0; stage < numStages; stage++) { 1405 if (stageUsed[stage]) { 1406 ierr = PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");CHKERRQ(ierr); 1407 ierr = PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");CHKERRQ(ierr); 1408 break; 1409 } 1410 } 1411 for (stage = 0; stage < numStages; stage++) { 1412 if (!stageUsed[stage]) continue; 1413 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1414 if (localStageUsed[stage]) { 1415 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1416 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1417 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1418 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1419 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1420 name = stageInfo[stage].name; 1421 } else { 1422 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1423 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1424 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1425 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1426 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1427 name = ""; 1428 } 1429 mess *= 0.5; messLen *= 0.5; red /= size; 1430 if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0; 1431 if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0; 1432 /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */ 1433 if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0; 1434 if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0; 1435 if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0; 1436 if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0; 1437 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", 1438 stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops, 1439 mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);CHKERRQ(ierr); 1440 } 1441 } 1442 1443 ierr = PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1444 ierr = PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");CHKERRQ(ierr); 1445 ierr = PetscFPrintf(comm, fd, "Phase summary info:\n");CHKERRQ(ierr); 1446 ierr = PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");CHKERRQ(ierr); 1447 ierr = PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");CHKERRQ(ierr); 1448 ierr = PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");CHKERRQ(ierr); 1449 ierr = PetscFPrintf(comm, fd, " Mess: number of messages sent\n");CHKERRQ(ierr); 1450 ierr = PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");CHKERRQ(ierr); 1451 ierr = PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");CHKERRQ(ierr); 1452 ierr = PetscFPrintf(comm, fd, " Global: entire computation\n");CHKERRQ(ierr); 1453 ierr = PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");CHKERRQ(ierr); 1454 ierr = PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");CHKERRQ(ierr); 1455 ierr = PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");CHKERRQ(ierr); 1456 ierr = PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");CHKERRQ(ierr); 1457 ierr = PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");CHKERRQ(ierr); 1458 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1459 1460 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1461 1462 /* Report events */ 1463 ierr = PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage --- Total\n");CHKERRQ(ierr); 1464 ierr = PetscFPrintf(comm, fd," Max Ratio Max Ratio Max Ratio Mess Avg len Reduct %%T %%F %%M %%L %%R %%T %%F %%M %%L %%R Mflop/s\n");CHKERRQ(ierr); 1465 ierr = PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1466 1467 /* Problem: The stage name will not show up unless the stage executed on proc 1 */ 1468 for (stage = 0; stage < numStages; stage++) { 1469 if (!stageVisible[stage]) continue; 1470 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1471 if (localStageUsed[stage]) { 1472 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1473 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1474 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1475 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1476 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1477 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1478 } else { 1479 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1480 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1481 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1482 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1483 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1484 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1485 } 1486 mess *= 0.5; messLen *= 0.5; red /= size; 1487 1488 /* Get total number of events in this stage -- 1489 Currently, a single processor can register more events than another, but events must all be registered in order, 1490 just like stages. We can removed this requirement if necessary by having a global event numbering and indirection 1491 on the event ID. This seems best accomplished by assoicating a communicator with each stage. 1492 1493 Problem: If the event did not happen on proc 1, its name will not be available. 1494 Problem: Event visibility is not implemented 1495 */ 1496 if (localStageUsed[stage]) { 1497 eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo; 1498 localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents; 1499 } else localNumEvents = 0; 1500 ierr = MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1501 for (event = 0; event < numEvents; event++) { 1502 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1503 if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) { 1504 if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; 1505 else flopr = 0.0; 1506 1507 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1508 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1509 ierr = MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1510 ierr = MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1511 ierr = MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1512 ierr = MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1513 ierr = MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1514 ierr = MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1515 ierr = MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1516 ierr = MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);CHKERRQ(ierr); 1517 ierr = MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1518 name = stageLog->eventLog->eventInfo[event].name; 1519 } else { 1520 flopr = 0.0; 1521 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1522 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1523 ierr = MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1524 ierr = MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1525 ierr = MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1526 ierr = MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1527 ierr = MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1528 ierr = MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1529 ierr = MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1530 ierr = MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);CHKERRQ(ierr); 1531 ierr = MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1532 name = ""; 1533 } 1534 if (mint < 0.0) { 1535 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); 1536 mint = 0; 1537 } 1538 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); 1539 totm *= 0.5; totml *= 0.5; totr /= size; 1540 1541 if (maxCt != 0) { 1542 if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0; 1543 if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0; 1544 if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0; 1545 if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0; 1546 if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0; 1547 if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0; 1548 if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0; 1549 if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0; 1550 if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0; 1551 if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0; 1552 if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0; 1553 if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0; 1554 if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0; 1555 if (totm != 0.0) totml /= totm; else totml = 0.0; 1556 if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0; 1557 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); 1558 ierr = PetscFPrintf(comm, fd, 1559 "%-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\n", 1560 name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr, 1561 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed, 1562 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed, 1563 PetscAbs(flopr)/1.0e6);CHKERRQ(ierr); 1564 } 1565 } 1566 } 1567 1568 /* Memory usage and object creation */ 1569 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1570 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1571 ierr = PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");CHKERRQ(ierr); 1572 1573 /* Right now, only stages on the first processor are reported here, meaning only objects associated with 1574 the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then 1575 stats for stages local to processor sets. 1576 */ 1577 /* We should figure out the longest object name here (now 20 characters) */ 1578 ierr = PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");CHKERRQ(ierr); 1579 ierr = PetscFPrintf(comm, fd, "Reports information only for process 0.\n");CHKERRQ(ierr); 1580 for (stage = 0; stage < numStages; stage++) { 1581 if (localStageUsed[stage]) { 1582 classInfo = stageLog->stageInfo[stage].classLog->classInfo; 1583 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1584 for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) { 1585 if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) { 1586 ierr = PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name, 1587 classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem, 1588 classInfo[oclass].descMem);CHKERRQ(ierr); 1589 } 1590 } 1591 } else { 1592 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1593 } 1594 } 1595 1596 ierr = PetscFree(localStageUsed);CHKERRQ(ierr); 1597 ierr = PetscFree(stageUsed);CHKERRQ(ierr); 1598 ierr = PetscFree(localStageVisible);CHKERRQ(ierr); 1599 ierr = PetscFree(stageVisible);CHKERRQ(ierr); 1600 1601 /* Information unrelated to this particular run */ 1602 ierr = PetscFPrintf(comm, fd, "========================================================================================================================\n");CHKERRQ(ierr); 1603 PetscTime(&y); 1604 PetscTime(&x); 1605 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1606 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1607 ierr = PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);CHKERRQ(ierr); 1608 /* MPI information */ 1609 if (size > 1) { 1610 MPI_Status status; 1611 PetscMPIInt tag; 1612 MPI_Comm newcomm; 1613 1614 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1615 PetscTime(&x); 1616 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1617 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1618 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1619 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1620 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1621 PetscTime(&y); 1622 ierr = PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);CHKERRQ(ierr); 1623 ierr = PetscCommDuplicate(comm,&newcomm, &tag);CHKERRQ(ierr); 1624 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1625 if (rank) { 1626 ierr = MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);CHKERRQ(ierr); 1627 ierr = MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);CHKERRQ(ierr); 1628 } else { 1629 PetscTime(&x); 1630 ierr = MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);CHKERRQ(ierr); 1631 ierr = MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);CHKERRQ(ierr); 1632 PetscTime(&y); 1633 ierr = PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);CHKERRQ(ierr); 1634 } 1635 ierr = PetscCommDestroy(&newcomm);CHKERRQ(ierr); 1636 } 1637 ierr = PetscOptionsView(NULL,viewer);CHKERRQ(ierr); 1638 1639 /* Machine and compile information */ 1640 #if defined(PETSC_USE_FORTRAN_KERNELS) 1641 ierr = PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");CHKERRQ(ierr); 1642 #else 1643 ierr = PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");CHKERRQ(ierr); 1644 #endif 1645 #if defined(PETSC_USE_REAL_SINGLE) 1646 ierr = PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1647 #elif defined(PETSC_USE___FLOAT128) 1648 ierr = PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1649 #endif 1650 1651 #if defined(PETSC_USE_REAL_MAT_SINGLE) 1652 ierr = PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");CHKERRQ(ierr); 1653 #else 1654 ierr = PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");CHKERRQ(ierr); 1655 #endif 1656 ierr = PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n", 1657 (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));CHKERRQ(ierr); 1658 1659 ierr = PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);CHKERRQ(ierr); 1660 ierr = PetscFPrintf(comm, fd, "%s", petscmachineinfo);CHKERRQ(ierr); 1661 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerinfo);CHKERRQ(ierr); 1662 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);CHKERRQ(ierr); 1663 ierr = PetscFPrintf(comm, fd, "%s", petsclinkerinfo);CHKERRQ(ierr); 1664 1665 /* Cleanup */ 1666 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1667 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1668 PetscFunctionReturn(0); 1669 } 1670 1671 /*@C 1672 PetscLogView - Prints a summary of the logging. 1673 1674 Collective over MPI_Comm 1675 1676 Input Parameter: 1677 . viewer - an ASCII viewer 1678 1679 Options Database Keys: 1680 + -log_view [:filename] - Prints summary of log information 1681 . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file 1682 . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it) 1683 . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation 1684 - -log_trace [filename] - Displays a trace of what each process is doing 1685 1686 Notes: 1687 It is possible to control the logging programatically but we recommend using the options database approach whenever possible 1688 By default the summary is printed to stdout. 1689 1690 Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin() 1691 1692 If PETSc is configured with --with-logging=0 then this functionality is not available 1693 1694 To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current 1695 directory then open filename.xml with your browser. Specific notes for certain browsers 1696 $ Firefox and Internet explorer - simply open the file 1697 $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files 1698 $ Safari - see http://ccm.net/faq/36342-safari-how-to-enable-local-file-access 1699 or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with 1700 your browser. 1701 1702 The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS 1703 1704 Level: beginner 1705 1706 .keywords: log, dump, print 1707 .seealso: PetscLogDefaultBegin(), PetscLogDump() 1708 @*/ 1709 PetscErrorCode PetscLogView(PetscViewer viewer) 1710 { 1711 PetscErrorCode ierr; 1712 PetscBool isascii; 1713 PetscViewerFormat format; 1714 int stage, lastStage; 1715 PetscStageLog stageLog; 1716 1717 PetscFunctionBegin; 1718 if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine"); 1719 /* Pop off any stages the user forgot to remove */ 1720 lastStage = 0; 1721 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1722 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 1723 while (stage >= 0) { 1724 lastStage = stage; 1725 ierr = PetscStageLogPop(stageLog);CHKERRQ(ierr); 1726 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 1727 } 1728 ierr = PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);CHKERRQ(ierr); 1729 if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII"); 1730 ierr = PetscViewerGetFormat(viewer,&format);CHKERRQ(ierr); 1731 if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) { 1732 ierr = PetscLogView_Default(viewer);CHKERRQ(ierr); 1733 } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) { 1734 ierr = PetscLogView_Detailed(viewer);CHKERRQ(ierr); 1735 } else if (format == PETSC_VIEWER_ASCII_XML) { 1736 ierr = PetscLogView_Nested(viewer);CHKERRQ(ierr); 1737 } 1738 ierr = PetscStageLogPush(stageLog, lastStage);CHKERRQ(ierr); 1739 PetscFunctionReturn(0); 1740 } 1741 1742 /*@C 1743 PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed. 1744 1745 Collective on PETSC_COMM_WORLD 1746 1747 Not normally called by user 1748 1749 Level: intermediate 1750 1751 @*/ 1752 PetscErrorCode PetscLogViewFromOptions(void) 1753 { 1754 PetscErrorCode ierr; 1755 PetscViewer viewer; 1756 PetscBool flg; 1757 PetscViewerFormat format; 1758 1759 PetscFunctionBegin; 1760 ierr = PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);CHKERRQ(ierr); 1761 if (flg) { 1762 ierr = PetscViewerPushFormat(viewer,format);CHKERRQ(ierr); 1763 ierr = PetscLogView(viewer);CHKERRQ(ierr); 1764 ierr = PetscViewerPopFormat(viewer);CHKERRQ(ierr); 1765 ierr = PetscViewerDestroy(&viewer);CHKERRQ(ierr); 1766 } 1767 PetscFunctionReturn(0); 1768 } 1769 1770 1771 1772 /*----------------------------------------------- Counter Functions -------------------------------------------------*/ 1773 /*@C 1774 PetscGetFlops - Returns the number of flops used on this processor 1775 since the program began. 1776 1777 Not Collective 1778 1779 Output Parameter: 1780 flops - number of floating point operations 1781 1782 Notes: 1783 A global counter logs all PETSc flop counts. The user can use 1784 PetscLogFlops() to increment this counter to include flops for the 1785 application code. 1786 1787 Level: intermediate 1788 1789 .keywords: log, flops, floating point operations 1790 1791 .seealso: PetscTime(), PetscLogFlops() 1792 @*/ 1793 PetscErrorCode PetscGetFlops(PetscLogDouble *flops) 1794 { 1795 PetscFunctionBegin; 1796 *flops = petsc_TotalFlops; 1797 PetscFunctionReturn(0); 1798 } 1799 1800 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 1801 { 1802 PetscErrorCode ierr; 1803 size_t fullLength; 1804 va_list Argp; 1805 1806 PetscFunctionBegin; 1807 if (!petsc_logObjects) PetscFunctionReturn(0); 1808 va_start(Argp, format); 1809 ierr = PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);CHKERRQ(ierr); 1810 va_end(Argp); 1811 PetscFunctionReturn(0); 1812 } 1813 1814 1815 /*MC 1816 PetscLogFlops - Adds floating point operations to the global counter. 1817 1818 Synopsis: 1819 #include <petsclog.h> 1820 PetscErrorCode PetscLogFlops(PetscLogDouble f) 1821 1822 Not Collective 1823 1824 Input Parameter: 1825 . f - flop counter 1826 1827 1828 Usage: 1829 .vb 1830 PetscLogEvent USER_EVENT; 1831 PetscLogEventRegister("User event",0,&USER_EVENT); 1832 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1833 [code segment to monitor] 1834 PetscLogFlops(user_flops) 1835 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1836 .ve 1837 1838 Notes: 1839 A global counter logs all PETSc flop counts. The user can use 1840 PetscLogFlops() to increment this counter to include flops for the 1841 application code. 1842 1843 Level: intermediate 1844 1845 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops() 1846 1847 .keywords: log, flops, floating point operations 1848 M*/ 1849 1850 /*MC 1851 PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice) 1852 to get accurate timings 1853 1854 Synopsis: 1855 #include <petsclog.h> 1856 void PetscPreLoadBegin(PetscBool flag,char *name); 1857 1858 Not Collective 1859 1860 Input Parameter: 1861 + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden 1862 with command line option -preload true or -preload false 1863 - name - name of first stage (lines of code timed separately with -log_view) to 1864 be preloaded 1865 1866 Usage: 1867 .vb 1868 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1869 lines of code 1870 PetscPreLoadStage("second stage"); 1871 lines of code 1872 PetscPreLoadEnd(); 1873 .ve 1874 1875 Notes: 1876 Only works in C/C++, not Fortran 1877 1878 Flags available within the macro. 1879 + PetscPreLoadingUsed - true if we are or have done preloading 1880 . PetscPreLoadingOn - true if it is CURRENTLY doing preload 1881 . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second 1882 - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on 1883 The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin() 1884 and PetscPreLoadEnd() 1885 1886 Level: intermediate 1887 1888 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage() 1889 1890 Concepts: preloading 1891 Concepts: timing^accurate 1892 Concepts: paging^eliminating effects of 1893 1894 1895 M*/ 1896 1897 /*MC 1898 PetscPreLoadEnd - End a segment of code that may be preloaded (run twice) 1899 to get accurate timings 1900 1901 Synopsis: 1902 #include <petsclog.h> 1903 void PetscPreLoadEnd(void); 1904 1905 Not Collective 1906 1907 Usage: 1908 .vb 1909 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1910 lines of code 1911 PetscPreLoadStage("second stage"); 1912 lines of code 1913 PetscPreLoadEnd(); 1914 .ve 1915 1916 Notes: 1917 only works in C/C++ not fortran 1918 1919 Level: intermediate 1920 1921 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage() 1922 1923 M*/ 1924 1925 /*MC 1926 PetscPreLoadStage - Start a new segment of code to be timed separately. 1927 to get accurate timings 1928 1929 Synopsis: 1930 #include <petsclog.h> 1931 void PetscPreLoadStage(char *name); 1932 1933 Not Collective 1934 1935 Usage: 1936 .vb 1937 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1938 lines of code 1939 PetscPreLoadStage("second stage"); 1940 lines of code 1941 PetscPreLoadEnd(); 1942 .ve 1943 1944 Notes: 1945 only works in C/C++ not fortran 1946 1947 Level: intermediate 1948 1949 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd() 1950 1951 M*/ 1952 1953 1954 #else /* end of -DPETSC_USE_LOG section */ 1955 1956 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 1957 { 1958 PetscFunctionBegin; 1959 PetscFunctionReturn(0); 1960 } 1961 1962 #endif /* PETSC_USE_LOG*/ 1963 1964 1965 PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 1966 PetscClassId PETSC_OBJECT_CLASSID = 0; 1967 1968 /*@C 1969 PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code. 1970 1971 Not Collective 1972 1973 Input Parameter: 1974 . name - The class name 1975 1976 Output Parameter: 1977 . oclass - The class id or classid 1978 1979 Level: developer 1980 1981 .keywords: log, class, register 1982 1983 @*/ 1984 PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass) 1985 { 1986 #if defined(PETSC_USE_LOG) 1987 PetscStageLog stageLog; 1988 PetscInt stage; 1989 PetscErrorCode ierr; 1990 #endif 1991 1992 PetscFunctionBegin; 1993 *oclass = ++PETSC_LARGEST_CLASSID; 1994 #if defined(PETSC_USE_LOG) 1995 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1996 ierr = PetscClassRegLogRegister(stageLog->classLog, name, *oclass);CHKERRQ(ierr); 1997 for (stage = 0; stage < stageLog->numStages; stage++) { 1998 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 1999 } 2000 #endif 2001 PetscFunctionReturn(0); 2002 } 2003 2004 #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE) 2005 #include <mpe.h> 2006 2007 PetscBool PetscBeganMPE = PETSC_FALSE; 2008 2009 PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2010 PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2011 2012 /*@C 2013 PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files 2014 and slows the program down. 2015 2016 Collective over PETSC_COMM_WORLD 2017 2018 Options Database Keys: 2019 . -log_mpe - Prints extensive log information 2020 2021 Notes: 2022 A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is 2023 intended for production runs since it logs only flop rates and object 2024 creation (and should not significantly slow the programs). 2025 2026 Level: advanced 2027 2028 Concepts: logging^MPE 2029 Concepts: logging^message passing 2030 2031 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(), 2032 PetscLogEventDeactivate() 2033 @*/ 2034 PetscErrorCode PetscLogMPEBegin(void) 2035 { 2036 PetscErrorCode ierr; 2037 2038 PetscFunctionBegin; 2039 /* Do MPE initialization */ 2040 if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */ 2041 ierr = PetscInfo(0,"Initializing MPE.\n");CHKERRQ(ierr); 2042 ierr = MPE_Init_log();CHKERRQ(ierr); 2043 2044 PetscBeganMPE = PETSC_TRUE; 2045 } else { 2046 ierr = PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");CHKERRQ(ierr); 2047 } 2048 ierr = PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);CHKERRQ(ierr); 2049 PetscFunctionReturn(0); 2050 } 2051 2052 /*@C 2053 PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot. 2054 2055 Collective over PETSC_COMM_WORLD 2056 2057 Level: advanced 2058 2059 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin() 2060 @*/ 2061 PetscErrorCode PetscLogMPEDump(const char sname[]) 2062 { 2063 char name[PETSC_MAX_PATH_LEN]; 2064 PetscErrorCode ierr; 2065 2066 PetscFunctionBegin; 2067 if (PetscBeganMPE) { 2068 ierr = PetscInfo(0,"Finalizing MPE.\n");CHKERRQ(ierr); 2069 if (sname) { 2070 ierr = PetscStrcpy(name,sname);CHKERRQ(ierr); 2071 } else { 2072 ierr = PetscGetProgramName(name,PETSC_MAX_PATH_LEN);CHKERRQ(ierr); 2073 } 2074 ierr = MPE_Finish_log(name);CHKERRQ(ierr); 2075 } else { 2076 ierr = PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");CHKERRQ(ierr); 2077 } 2078 PetscFunctionReturn(0); 2079 } 2080 2081 #define PETSC_RGB_COLORS_MAX 39 2082 static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = { 2083 "OliveDrab: ", 2084 "BlueViolet: ", 2085 "CadetBlue: ", 2086 "CornflowerBlue: ", 2087 "DarkGoldenrod: ", 2088 "DarkGreen: ", 2089 "DarkKhaki: ", 2090 "DarkOliveGreen: ", 2091 "DarkOrange: ", 2092 "DarkOrchid: ", 2093 "DarkSeaGreen: ", 2094 "DarkSlateGray: ", 2095 "DarkTurquoise: ", 2096 "DeepPink: ", 2097 "DarkKhaki: ", 2098 "DimGray: ", 2099 "DodgerBlue: ", 2100 "GreenYellow: ", 2101 "HotPink: ", 2102 "IndianRed: ", 2103 "LavenderBlush: ", 2104 "LawnGreen: ", 2105 "LemonChiffon: ", 2106 "LightCoral: ", 2107 "LightCyan: ", 2108 "LightPink: ", 2109 "LightSalmon: ", 2110 "LightSlateGray: ", 2111 "LightYellow: ", 2112 "LimeGreen: ", 2113 "MediumPurple: ", 2114 "MediumSeaGreen: ", 2115 "MediumSlateBlue:", 2116 "MidnightBlue: ", 2117 "MintCream: ", 2118 "MistyRose: ", 2119 "NavajoWhite: ", 2120 "NavyBlue: ", 2121 "OliveDrab: " 2122 }; 2123 2124 /*@C 2125 PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister() 2126 2127 Not collective. Maybe it should be? 2128 2129 Output Parameter 2130 . str - character string representing the color 2131 2132 Level: developer 2133 2134 .keywords: log, mpe , color 2135 .seealso: PetscLogEventRegister 2136 @*/ 2137 PetscErrorCode PetscLogMPEGetRGBColor(const char *str[]) 2138 { 2139 static int idx = 0; 2140 2141 PetscFunctionBegin; 2142 *str = PetscLogMPERGBColors[idx]; 2143 idx = (idx + 1)% PETSC_RGB_COLORS_MAX; 2144 PetscFunctionReturn(0); 2145 } 2146 2147 #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */ 2148