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",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 if (eventInfo[event].dof >= 0.) { 1210 PetscInt e; 1211 1212 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", \"dof\" : %.0g", eventInfo[event].dof);CHKERRQ(ierr); 1213 ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", \"error\" : [");CHKERRQ(ierr); 1214 for (e = 0; e < 8; ++e) { 1215 if (e > 0) {ierr = PetscViewerASCIISynchronizedPrintf(viewer, ", ");CHKERRQ(ierr);} 1216 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "%g", eventInfo[event].errors[e]);CHKERRQ(ierr); 1217 } 1218 ierr = PetscViewerASCIISynchronizedPrintf(viewer, "]");CHKERRQ(ierr); 1219 } 1220 ierr = PetscViewerASCIISynchronizedPrintf(viewer,"}\n");CHKERRQ(ierr); 1221 } 1222 } 1223 ierr = PetscViewerFlush(viewer);CHKERRQ(ierr); 1224 ierr = PetscViewerASCIIPopSynchronized(viewer);CHKERRQ(ierr); 1225 PetscFunctionReturn(0); 1226 } 1227 1228 static PetscErrorCode PetscLogViewWarnDebugging(MPI_Comm comm,FILE *fd) 1229 { 1230 #if defined(PETSC_USE_DEBUG) 1231 PetscErrorCode ierr; 1232 1233 PetscFunctionBegin; 1234 ierr = PetscFPrintf(comm, fd, "\n\n");CHKERRQ(ierr); 1235 ierr = PetscFPrintf(comm, fd, " ##########################################################\n");CHKERRQ(ierr); 1236 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1237 ierr = PetscFPrintf(comm, fd, " # WARNING!!! #\n");CHKERRQ(ierr); 1238 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1239 ierr = PetscFPrintf(comm, fd, " # This code was compiled with a debugging option, #\n");CHKERRQ(ierr); 1240 ierr = PetscFPrintf(comm, fd, " # To get timing results run ./configure #\n");CHKERRQ(ierr); 1241 ierr = PetscFPrintf(comm, fd, " # using --with-debugging=no, the performance will #\n");CHKERRQ(ierr); 1242 ierr = PetscFPrintf(comm, fd, " # be generally two or three times faster. #\n");CHKERRQ(ierr); 1243 ierr = PetscFPrintf(comm, fd, " # #\n");CHKERRQ(ierr); 1244 ierr = PetscFPrintf(comm, fd, " ##########################################################\n\n\n");CHKERRQ(ierr); 1245 PetscFunctionReturn(0); 1246 #else 1247 return 0; 1248 #endif 1249 } 1250 1251 PetscErrorCode PetscLogView_Default(PetscViewer viewer) 1252 { 1253 FILE *fd; 1254 PetscLogDouble zero = 0.0; 1255 PetscStageLog stageLog; 1256 PetscStageInfo *stageInfo = NULL; 1257 PetscEventPerfInfo *eventInfo = NULL; 1258 PetscClassPerfInfo *classInfo; 1259 char arch[128],hostname[128],username[128],pname[PETSC_MAX_PATH_LEN],date[128]; 1260 const char *name; 1261 PetscLogDouble locTotalTime, TotalTime, TotalFlops; 1262 PetscLogDouble numMessages, messageLength, avgMessLen, numReductions; 1263 PetscLogDouble stageTime, flops, flopr, mem, mess, messLen, red; 1264 PetscLogDouble fracTime, fracFlops, fracMessages, fracLength, fracReductions, fracMess, fracMessLen, fracRed; 1265 PetscLogDouble fracStageTime, fracStageFlops, fracStageMess, fracStageMessLen, fracStageRed; 1266 PetscLogDouble min, max, tot, ratio, avg, x, y; 1267 PetscLogDouble minf, maxf, totf, ratf, mint, maxt, tott, ratt, ratCt, totm, totml, totr; 1268 PetscMPIInt minCt, maxCt; 1269 PetscMPIInt size, rank; 1270 PetscBool *localStageUsed, *stageUsed; 1271 PetscBool *localStageVisible, *stageVisible; 1272 int numStages, localNumEvents, numEvents; 1273 int stage, oclass; 1274 PetscLogEvent event; 1275 PetscErrorCode ierr; 1276 char version[256]; 1277 MPI_Comm comm; 1278 1279 PetscFunctionBegin; 1280 ierr = PetscObjectGetComm((PetscObject)viewer,&comm);CHKERRQ(ierr); 1281 ierr = PetscViewerASCIIGetPointer(viewer,&fd);CHKERRQ(ierr); 1282 ierr = MPI_Comm_size(comm, &size);CHKERRQ(ierr); 1283 ierr = MPI_Comm_rank(comm, &rank);CHKERRQ(ierr); 1284 /* Get the total elapsed time */ 1285 PetscTime(&locTotalTime); locTotalTime -= petsc_BaseTime; 1286 1287 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1288 ierr = PetscFPrintf(comm, fd, "*** WIDEN YOUR WINDOW TO 120 CHARACTERS. Use 'enscript -r -fCourier9' to print this document ***\n");CHKERRQ(ierr); 1289 ierr = PetscFPrintf(comm, fd, "************************************************************************************************************************\n");CHKERRQ(ierr); 1290 ierr = PetscFPrintf(comm, fd, "\n---------------------------------------------- PETSc Performance Summary: ----------------------------------------------\n\n");CHKERRQ(ierr); 1291 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1292 ierr = PetscGetArchType(arch,sizeof(arch));CHKERRQ(ierr); 1293 ierr = PetscGetHostName(hostname,sizeof(hostname));CHKERRQ(ierr); 1294 ierr = PetscGetUserName(username,sizeof(username));CHKERRQ(ierr); 1295 ierr = PetscGetProgramName(pname,sizeof(pname));CHKERRQ(ierr); 1296 ierr = PetscGetDate(date,sizeof(date));CHKERRQ(ierr); 1297 ierr = PetscGetVersion(version,sizeof(version));CHKERRQ(ierr); 1298 if (size == 1) { 1299 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); 1300 } else { 1301 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); 1302 } 1303 1304 ierr = PetscFPrintf(comm, fd, "Using %s\n", version);CHKERRQ(ierr); 1305 1306 /* Must preserve reduction count before we go on */ 1307 red = petsc_allreduce_ct + petsc_gather_ct + petsc_scatter_ct; 1308 1309 /* Calculate summary information */ 1310 ierr = PetscFPrintf(comm, fd, "\n Max Max/Min Avg Total \n");CHKERRQ(ierr); 1311 /* Time */ 1312 ierr = MPIU_Allreduce(&locTotalTime, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1313 ierr = MPIU_Allreduce(&locTotalTime, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1314 ierr = MPIU_Allreduce(&locTotalTime, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1315 avg = (tot)/((PetscLogDouble) size); 1316 if (min != 0.0) ratio = max/min; 1317 else ratio = 0.0; 1318 ierr = PetscFPrintf(comm, fd, "Time (sec): %5.3e %10.5f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1319 TotalTime = tot; 1320 /* Objects */ 1321 avg = (PetscLogDouble) petsc_numObjects; 1322 ierr = MPIU_Allreduce(&avg, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1323 ierr = MPIU_Allreduce(&avg, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1324 ierr = MPIU_Allreduce(&avg, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1325 avg = (tot)/((PetscLogDouble) size); 1326 if (min != 0.0) ratio = max/min; 1327 else ratio = 0.0; 1328 ierr = PetscFPrintf(comm, fd, "Objects: %5.3e %10.5f %5.3e\n", max, ratio, avg);CHKERRQ(ierr); 1329 /* Flops */ 1330 ierr = MPIU_Allreduce(&petsc_TotalFlops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1331 ierr = MPIU_Allreduce(&petsc_TotalFlops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1332 ierr = MPIU_Allreduce(&petsc_TotalFlops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1333 avg = (tot)/((PetscLogDouble) size); 1334 if (min != 0.0) ratio = max/min; 1335 else ratio = 0.0; 1336 ierr = PetscFPrintf(comm, fd, "Flop: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1337 TotalFlops = tot; 1338 /* Flops/sec -- Must talk to Barry here */ 1339 if (locTotalTime != 0.0) flops = petsc_TotalFlops/locTotalTime; 1340 else flops = 0.0; 1341 ierr = MPIU_Allreduce(&flops, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1342 ierr = MPIU_Allreduce(&flops, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1343 ierr = MPIU_Allreduce(&flops, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1344 avg = (tot)/((PetscLogDouble) size); 1345 if (min != 0.0) ratio = max/min; 1346 else ratio = 0.0; 1347 ierr = PetscFPrintf(comm, fd, "Flop/sec: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1348 /* Memory */ 1349 ierr = PetscMallocGetMaximumUsage(&mem);CHKERRQ(ierr); 1350 if (mem > 0.0) { 1351 ierr = MPIU_Allreduce(&mem, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1352 ierr = MPIU_Allreduce(&mem, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1353 ierr = MPIU_Allreduce(&mem, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1354 avg = (tot)/((PetscLogDouble) size); 1355 if (min != 0.0) ratio = max/min; 1356 else ratio = 0.0; 1357 ierr = PetscFPrintf(comm, fd, "Memory: %5.3e %10.5f %5.3e\n", max, ratio, tot);CHKERRQ(ierr); 1358 } 1359 /* Messages */ 1360 mess = 0.5*(petsc_irecv_ct + petsc_isend_ct + petsc_recv_ct + petsc_send_ct); 1361 ierr = MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1362 ierr = MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1363 ierr = MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1364 avg = (tot)/((PetscLogDouble) size); 1365 if (min != 0.0) ratio = max/min; 1366 else ratio = 0.0; 1367 ierr = PetscFPrintf(comm, fd, "MPI Messages: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1368 numMessages = tot; 1369 /* Message Lengths */ 1370 mess = 0.5*(petsc_irecv_len + petsc_isend_len + petsc_recv_len + petsc_send_len); 1371 ierr = MPIU_Allreduce(&mess, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1372 ierr = MPIU_Allreduce(&mess, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1373 ierr = MPIU_Allreduce(&mess, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1374 if (numMessages != 0) avg = (tot)/(numMessages); 1375 else avg = 0.0; 1376 if (min != 0.0) ratio = max/min; 1377 else ratio = 0.0; 1378 ierr = PetscFPrintf(comm, fd, "MPI Message Lengths: %5.3e %10.5f %5.3e %5.3e\n", max, ratio, avg, tot);CHKERRQ(ierr); 1379 messageLength = tot; 1380 /* Reductions */ 1381 ierr = MPIU_Allreduce(&red, &min, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1382 ierr = MPIU_Allreduce(&red, &max, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1383 ierr = MPIU_Allreduce(&red, &tot, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1384 if (min != 0.0) ratio = max/min; 1385 else ratio = 0.0; 1386 ierr = PetscFPrintf(comm, fd, "MPI Reductions: %5.3e %10.5f\n", max, ratio);CHKERRQ(ierr); 1387 numReductions = red; /* wrong because uses count from process zero */ 1388 ierr = PetscFPrintf(comm, fd, "\nFlop counting convention: 1 flop = 1 real number operation of type (multiply/divide/add/subtract)\n");CHKERRQ(ierr); 1389 ierr = PetscFPrintf(comm, fd, " e.g., VecAXPY() for real vectors of length N --> 2N flop\n");CHKERRQ(ierr); 1390 ierr = PetscFPrintf(comm, fd, " and VecAXPY() for complex vectors of length N --> 8N flop\n");CHKERRQ(ierr); 1391 1392 /* Get total number of stages -- 1393 Currently, a single processor can register more stages than another, but stages must all be registered in order. 1394 We can removed this requirement if necessary by having a global stage numbering and indirection on the stage ID. 1395 This seems best accomplished by assoicating a communicator with each stage. 1396 */ 1397 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1398 ierr = MPIU_Allreduce(&stageLog->numStages, &numStages, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1399 ierr = PetscMalloc1(numStages, &localStageUsed);CHKERRQ(ierr); 1400 ierr = PetscMalloc1(numStages, &stageUsed);CHKERRQ(ierr); 1401 ierr = PetscMalloc1(numStages, &localStageVisible);CHKERRQ(ierr); 1402 ierr = PetscMalloc1(numStages, &stageVisible);CHKERRQ(ierr); 1403 if (numStages > 0) { 1404 stageInfo = stageLog->stageInfo; 1405 for (stage = 0; stage < numStages; stage++) { 1406 if (stage < stageLog->numStages) { 1407 localStageUsed[stage] = stageInfo[stage].used; 1408 localStageVisible[stage] = stageInfo[stage].perfInfo.visible; 1409 } else { 1410 localStageUsed[stage] = PETSC_FALSE; 1411 localStageVisible[stage] = PETSC_TRUE; 1412 } 1413 } 1414 ierr = MPIU_Allreduce(localStageUsed, stageUsed, numStages, MPIU_BOOL, MPI_LOR, comm);CHKERRQ(ierr); 1415 ierr = MPIU_Allreduce(localStageVisible, stageVisible, numStages, MPIU_BOOL, MPI_LAND, comm);CHKERRQ(ierr); 1416 for (stage = 0; stage < numStages; stage++) { 1417 if (stageUsed[stage]) { 1418 ierr = PetscFPrintf(comm, fd, "\nSummary of Stages: ----- Time ------ ----- Flop ----- --- Messages --- -- Message Lengths -- -- Reductions --\n");CHKERRQ(ierr); 1419 ierr = PetscFPrintf(comm, fd, " Avg %%Total Avg %%Total counts %%Total Avg %%Total counts %%Total \n");CHKERRQ(ierr); 1420 break; 1421 } 1422 } 1423 for (stage = 0; stage < numStages; stage++) { 1424 if (!stageUsed[stage]) continue; 1425 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1426 if (localStageUsed[stage]) { 1427 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1428 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1429 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1430 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1431 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1432 name = stageInfo[stage].name; 1433 } else { 1434 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1435 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1436 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1437 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1438 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1439 name = ""; 1440 } 1441 mess *= 0.5; messLen *= 0.5; red /= size; 1442 if (TotalTime != 0.0) fracTime = stageTime/TotalTime; else fracTime = 0.0; 1443 if (TotalFlops != 0.0) fracFlops = flops/TotalFlops; else fracFlops = 0.0; 1444 /* Talk to Barry if (stageTime != 0.0) flops = (size*flops)/stageTime; else flops = 0.0; */ 1445 if (numMessages != 0.0) fracMessages = mess/numMessages; else fracMessages = 0.0; 1446 if (mess != 0.0) avgMessLen = messLen/mess; else avgMessLen = 0.0; 1447 if (messageLength != 0.0) fracLength = messLen/messageLength; else fracLength = 0.0; 1448 if (numReductions != 0.0) fracReductions = red/numReductions; else fracReductions = 0.0; 1449 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", 1450 stage, name, stageTime/size, 100.0*fracTime, flops, 100.0*fracFlops, 1451 mess, 100.0*fracMessages, avgMessLen, 100.0*fracLength, red, 100.0*fracReductions);CHKERRQ(ierr); 1452 } 1453 } 1454 1455 ierr = PetscFPrintf(comm, fd,"\n------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1456 ierr = PetscFPrintf(comm, fd, "See the 'Profiling' chapter of the users' manual for details on interpreting output.\n");CHKERRQ(ierr); 1457 ierr = PetscFPrintf(comm, fd, "Phase summary info:\n");CHKERRQ(ierr); 1458 ierr = PetscFPrintf(comm, fd, " Count: number of times phase was executed\n");CHKERRQ(ierr); 1459 ierr = PetscFPrintf(comm, fd, " Time and Flop: Max - maximum over all processors\n");CHKERRQ(ierr); 1460 ierr = PetscFPrintf(comm, fd, " Ratio - ratio of maximum to minimum over all processors\n");CHKERRQ(ierr); 1461 ierr = PetscFPrintf(comm, fd, " Mess: number of messages sent\n");CHKERRQ(ierr); 1462 ierr = PetscFPrintf(comm, fd, " Avg. len: average message length (bytes)\n");CHKERRQ(ierr); 1463 ierr = PetscFPrintf(comm, fd, " Reduct: number of global reductions\n");CHKERRQ(ierr); 1464 ierr = PetscFPrintf(comm, fd, " Global: entire computation\n");CHKERRQ(ierr); 1465 ierr = PetscFPrintf(comm, fd, " Stage: stages of a computation. Set stages with PetscLogStagePush() and PetscLogStagePop().\n");CHKERRQ(ierr); 1466 ierr = PetscFPrintf(comm, fd, " %%T - percent time in this phase %%F - percent flop in this phase\n");CHKERRQ(ierr); 1467 ierr = PetscFPrintf(comm, fd, " %%M - percent messages in this phase %%L - percent message lengths in this phase\n");CHKERRQ(ierr); 1468 ierr = PetscFPrintf(comm, fd, " %%R - percent reductions in this phase\n");CHKERRQ(ierr); 1469 ierr = PetscFPrintf(comm, fd, " Total Mflop/s: 10e-6 * (sum of flop over all processors)/(max time over all processors)\n");CHKERRQ(ierr); 1470 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1471 1472 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1473 1474 /* Report events */ 1475 ierr = PetscFPrintf(comm, fd,"Event Count Time (sec) Flop --- Global --- --- Stage --- Total\n");CHKERRQ(ierr); 1476 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); 1477 ierr = PetscFPrintf(comm,fd,"------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1478 1479 /* Problem: The stage name will not show up unless the stage executed on proc 1 */ 1480 for (stage = 0; stage < numStages; stage++) { 1481 if (!stageVisible[stage]) continue; 1482 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1483 if (localStageUsed[stage]) { 1484 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1485 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.time, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1486 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.flops, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1487 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numMessages, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1488 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.messageLength, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1489 ierr = MPI_Allreduce(&stageInfo[stage].perfInfo.numReductions, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1490 } else { 1491 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1492 ierr = MPI_Allreduce(&zero, &stageTime, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1493 ierr = MPI_Allreduce(&zero, &flops, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1494 ierr = MPI_Allreduce(&zero, &mess, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1495 ierr = MPI_Allreduce(&zero, &messLen, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1496 ierr = MPI_Allreduce(&zero, &red, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1497 } 1498 mess *= 0.5; messLen *= 0.5; red /= size; 1499 1500 /* Get total number of events in this stage -- 1501 Currently, a single processor can register more events than another, but events must all be registered in order, 1502 just like stages. We can removed this requirement if necessary by having a global event numbering and indirection 1503 on the event ID. This seems best accomplished by assoicating a communicator with each stage. 1504 1505 Problem: If the event did not happen on proc 1, its name will not be available. 1506 Problem: Event visibility is not implemented 1507 */ 1508 if (localStageUsed[stage]) { 1509 eventInfo = stageLog->stageInfo[stage].eventLog->eventInfo; 1510 localNumEvents = stageLog->stageInfo[stage].eventLog->numEvents; 1511 } else localNumEvents = 0; 1512 ierr = MPIU_Allreduce(&localNumEvents, &numEvents, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1513 for (event = 0; event < numEvents; event++) { 1514 /* CANNOT use MPIU_Allreduce() since it might fail the line number check */ 1515 if (localStageUsed[stage] && (event < stageLog->stageInfo[stage].eventLog->numEvents) && (eventInfo[event].depth == 0)) { 1516 if ((eventInfo[event].count > 0) && (eventInfo[event].time > 0.0)) flopr = eventInfo[event].flops; 1517 else flopr = 0.0; 1518 1519 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1520 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1521 ierr = MPI_Allreduce(&eventInfo[event].flops, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1522 ierr = MPI_Allreduce(&eventInfo[event].time, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1523 ierr = MPI_Allreduce(&eventInfo[event].time, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1524 ierr = MPI_Allreduce(&eventInfo[event].time, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1525 ierr = MPI_Allreduce(&eventInfo[event].numMessages, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1526 ierr = MPI_Allreduce(&eventInfo[event].messageLength, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1527 ierr = MPI_Allreduce(&eventInfo[event].numReductions, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1528 ierr = MPI_Allreduce(&eventInfo[event].count, &minCt, 1, MPI_INT, MPI_MIN, comm);CHKERRQ(ierr); 1529 ierr = MPI_Allreduce(&eventInfo[event].count, &maxCt, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1530 name = stageLog->eventLog->eventInfo[event].name; 1531 } else { 1532 flopr = 0.0; 1533 ierr = MPI_Allreduce(&flopr, &minf, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1534 ierr = MPI_Allreduce(&flopr, &maxf, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1535 ierr = MPI_Allreduce(&zero, &totf, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1536 ierr = MPI_Allreduce(&zero, &mint, 1, MPIU_PETSCLOGDOUBLE, MPI_MIN, comm);CHKERRQ(ierr); 1537 ierr = MPI_Allreduce(&zero, &maxt, 1, MPIU_PETSCLOGDOUBLE, MPI_MAX, comm);CHKERRQ(ierr); 1538 ierr = MPI_Allreduce(&zero, &tott, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1539 ierr = MPI_Allreduce(&zero, &totm, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1540 ierr = MPI_Allreduce(&zero, &totml, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1541 ierr = MPI_Allreduce(&zero, &totr, 1, MPIU_PETSCLOGDOUBLE, MPI_SUM, comm);CHKERRQ(ierr); 1542 ierr = MPI_Allreduce(&ierr, &minCt, 1, MPI_INT, MPI_MIN, comm);CHKERRQ(ierr); 1543 ierr = MPI_Allreduce(&ierr, &maxCt, 1, MPI_INT, MPI_MAX, comm);CHKERRQ(ierr); 1544 name = ""; 1545 } 1546 if (mint < 0.0) { 1547 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); 1548 mint = 0; 1549 } 1550 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); 1551 totm *= 0.5; totml *= 0.5; totr /= size; 1552 1553 if (maxCt != 0) { 1554 if (minCt != 0) ratCt = ((PetscLogDouble) maxCt)/minCt; else ratCt = 0.0; 1555 if (mint != 0.0) ratt = maxt/mint; else ratt = 0.0; 1556 if (minf != 0.0) ratf = maxf/minf; else ratf = 0.0; 1557 if (TotalTime != 0.0) fracTime = tott/TotalTime; else fracTime = 0.0; 1558 if (TotalFlops != 0.0) fracFlops = totf/TotalFlops; else fracFlops = 0.0; 1559 if (stageTime != 0.0) fracStageTime = tott/stageTime; else fracStageTime = 0.0; 1560 if (flops != 0.0) fracStageFlops = totf/flops; else fracStageFlops = 0.0; 1561 if (numMessages != 0.0) fracMess = totm/numMessages; else fracMess = 0.0; 1562 if (messageLength != 0.0) fracMessLen = totml/messageLength; else fracMessLen = 0.0; 1563 if (numReductions != 0.0) fracRed = totr/numReductions; else fracRed = 0.0; 1564 if (mess != 0.0) fracStageMess = totm/mess; else fracStageMess = 0.0; 1565 if (messLen != 0.0) fracStageMessLen = totml/messLen; else fracStageMessLen = 0.0; 1566 if (red != 0.0) fracStageRed = totr/red; else fracStageRed = 0.0; 1567 if (totm != 0.0) totml /= totm; else totml = 0.0; 1568 if (maxt != 0.0) flopr = totf/maxt; else flopr = 0.0; 1569 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); 1570 ierr = PetscFPrintf(comm, fd, 1571 "%-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", 1572 name, maxCt, ratCt, maxt, ratt, maxf, ratf, totm, totml, totr, 1573 100.0*fracTime, 100.0*fracFlops, 100.0*fracMess, 100.0*fracMessLen, 100.0*fracRed, 1574 100.0*fracStageTime, 100.0*fracStageFlops, 100.0*fracStageMess, 100.0*fracStageMessLen, 100.0*fracStageRed, 1575 PetscAbs(flopr)/1.0e6);CHKERRQ(ierr); 1576 } 1577 } 1578 } 1579 1580 /* Memory usage and object creation */ 1581 ierr = PetscFPrintf(comm, fd, "------------------------------------------------------------------------------------------------------------------------\n");CHKERRQ(ierr); 1582 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1583 ierr = PetscFPrintf(comm, fd, "Memory usage is given in bytes:\n\n");CHKERRQ(ierr); 1584 1585 /* Right now, only stages on the first processor are reported here, meaning only objects associated with 1586 the global communicator, or MPI_COMM_SELF for proc 1. We really should report global stats and then 1587 stats for stages local to processor sets. 1588 */ 1589 /* We should figure out the longest object name here (now 20 characters) */ 1590 ierr = PetscFPrintf(comm, fd, "Object Type Creations Destructions Memory Descendants' Mem.\n");CHKERRQ(ierr); 1591 ierr = PetscFPrintf(comm, fd, "Reports information only for process 0.\n");CHKERRQ(ierr); 1592 for (stage = 0; stage < numStages; stage++) { 1593 if (localStageUsed[stage]) { 1594 classInfo = stageLog->stageInfo[stage].classLog->classInfo; 1595 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: %s\n\n", stage, stageInfo[stage].name);CHKERRQ(ierr); 1596 for (oclass = 0; oclass < stageLog->stageInfo[stage].classLog->numClasses; oclass++) { 1597 if ((classInfo[oclass].creations > 0) || (classInfo[oclass].destructions > 0)) { 1598 ierr = PetscFPrintf(comm, fd, "%20s %5d %5d %11.0f %g\n", stageLog->classLog->classInfo[oclass].name, 1599 classInfo[oclass].creations, classInfo[oclass].destructions, classInfo[oclass].mem, 1600 classInfo[oclass].descMem);CHKERRQ(ierr); 1601 } 1602 } 1603 } else { 1604 ierr = PetscFPrintf(comm, fd, "\n--- Event Stage %d: Unknown\n\n", stage);CHKERRQ(ierr); 1605 } 1606 } 1607 1608 ierr = PetscFree(localStageUsed);CHKERRQ(ierr); 1609 ierr = PetscFree(stageUsed);CHKERRQ(ierr); 1610 ierr = PetscFree(localStageVisible);CHKERRQ(ierr); 1611 ierr = PetscFree(stageVisible);CHKERRQ(ierr); 1612 1613 /* Information unrelated to this particular run */ 1614 ierr = PetscFPrintf(comm, fd, "========================================================================================================================\n");CHKERRQ(ierr); 1615 PetscTime(&y); 1616 PetscTime(&x); 1617 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1618 PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); PetscTime(&y); 1619 ierr = PetscFPrintf(comm,fd,"Average time to get PetscTime(): %g\n", (y-x)/10.0);CHKERRQ(ierr); 1620 /* MPI information */ 1621 if (size > 1) { 1622 MPI_Status status; 1623 PetscMPIInt tag; 1624 MPI_Comm newcomm; 1625 1626 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1627 PetscTime(&x); 1628 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1629 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1630 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1631 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1632 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1633 PetscTime(&y); 1634 ierr = PetscFPrintf(comm, fd, "Average time for MPI_Barrier(): %g\n", (y-x)/5.0);CHKERRQ(ierr); 1635 ierr = PetscCommDuplicate(comm,&newcomm, &tag);CHKERRQ(ierr); 1636 ierr = MPI_Barrier(comm);CHKERRQ(ierr); 1637 if (rank) { 1638 ierr = MPI_Recv(0, 0, MPI_INT, rank-1, tag, newcomm, &status);CHKERRQ(ierr); 1639 ierr = MPI_Send(0, 0, MPI_INT, (rank+1)%size, tag, newcomm);CHKERRQ(ierr); 1640 } else { 1641 PetscTime(&x); 1642 ierr = MPI_Send(0, 0, MPI_INT, 1, tag, newcomm);CHKERRQ(ierr); 1643 ierr = MPI_Recv(0, 0, MPI_INT, size-1, tag, newcomm, &status);CHKERRQ(ierr); 1644 PetscTime(&y); 1645 ierr = PetscFPrintf(comm,fd,"Average time for zero size MPI_Send(): %g\n", (y-x)/size);CHKERRQ(ierr); 1646 } 1647 ierr = PetscCommDestroy(&newcomm);CHKERRQ(ierr); 1648 } 1649 ierr = PetscOptionsView(NULL,viewer);CHKERRQ(ierr); 1650 1651 /* Machine and compile information */ 1652 #if defined(PETSC_USE_FORTRAN_KERNELS) 1653 ierr = PetscFPrintf(comm, fd, "Compiled with FORTRAN kernels\n");CHKERRQ(ierr); 1654 #else 1655 ierr = PetscFPrintf(comm, fd, "Compiled without FORTRAN kernels\n");CHKERRQ(ierr); 1656 #endif 1657 #if defined(PETSC_USE_REAL_SINGLE) 1658 ierr = PetscFPrintf(comm, fd, "Compiled with single precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1659 #elif defined(PETSC_USE___FLOAT128) 1660 ierr = PetscFPrintf(comm, fd, "Compiled with 128 bit precision PetscScalar and PetscReal\n");CHKERRQ(ierr); 1661 #endif 1662 1663 #if defined(PETSC_USE_REAL_MAT_SINGLE) 1664 ierr = PetscFPrintf(comm, fd, "Compiled with single precision matrices\n");CHKERRQ(ierr); 1665 #else 1666 ierr = PetscFPrintf(comm, fd, "Compiled with full precision matrices (default)\n");CHKERRQ(ierr); 1667 #endif 1668 ierr = PetscFPrintf(comm, fd, "sizeof(short) %d sizeof(int) %d sizeof(long) %d sizeof(void*) %d sizeof(PetscScalar) %d sizeof(PetscInt) %d\n", 1669 (int) sizeof(short), (int) sizeof(int), (int) sizeof(long), (int) sizeof(void*),(int) sizeof(PetscScalar),(int) sizeof(PetscInt));CHKERRQ(ierr); 1670 1671 ierr = PetscFPrintf(comm, fd, "Configure options: %s",petscconfigureoptions);CHKERRQ(ierr); 1672 ierr = PetscFPrintf(comm, fd, "%s", petscmachineinfo);CHKERRQ(ierr); 1673 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerinfo);CHKERRQ(ierr); 1674 ierr = PetscFPrintf(comm, fd, "%s", petsccompilerflagsinfo);CHKERRQ(ierr); 1675 ierr = PetscFPrintf(comm, fd, "%s", petsclinkerinfo);CHKERRQ(ierr); 1676 1677 /* Cleanup */ 1678 ierr = PetscFPrintf(comm, fd, "\n");CHKERRQ(ierr); 1679 ierr = PetscLogViewWarnDebugging(comm,fd);CHKERRQ(ierr); 1680 PetscFunctionReturn(0); 1681 } 1682 1683 /*@C 1684 PetscLogView - Prints a summary of the logging. 1685 1686 Collective over MPI_Comm 1687 1688 Input Parameter: 1689 . viewer - an ASCII viewer 1690 1691 Options Database Keys: 1692 + -log_view [:filename] - Prints summary of log information 1693 . -log_view :filename.py:ascii_info_detail - Saves logging information from each process as a Python file 1694 . -log_view :filename.xml:ascii_xml - Saves a summary of the logging information in a nested format (see below for how to view it) 1695 . -log_all - Saves a file Log.rank for each MPI process with details of each step of the computation 1696 - -log_trace [filename] - Displays a trace of what each process is doing 1697 1698 Notes: 1699 It is possible to control the logging programatically but we recommend using the options database approach whenever possible 1700 By default the summary is printed to stdout. 1701 1702 Before calling this routine you must have called either PetscLogDefaultBegin() or PetscLogNestedBegin() 1703 1704 If PETSc is configured with --with-logging=0 then this functionality is not available 1705 1706 To view the nested XML format filename.xml first copy ${PETSC_DIR}/share/petsc/xml/performance_xml2html.xsl to the current 1707 directory then open filename.xml with your browser. Specific notes for certain browsers 1708 $ Firefox and Internet explorer - simply open the file 1709 $ Google Chrome - you must start up Chrome with the option --allow-file-access-from-files 1710 $ Safari - see http://ccm.net/faq/36342-safari-how-to-enable-local-file-access 1711 or one can use the package http://xmlsoft.org/XSLT/xsltproc2.html to translate the xml file to html and then open it with 1712 your browser. 1713 1714 The nested XML format was kindly donated by Koos Huijssen and Christiaan M. Klaij MARITIME RESEARCH INSTITUTE NETHERLANDS 1715 1716 Level: beginner 1717 1718 .keywords: log, dump, print 1719 .seealso: PetscLogDefaultBegin(), PetscLogDump() 1720 @*/ 1721 PetscErrorCode PetscLogView(PetscViewer viewer) 1722 { 1723 PetscErrorCode ierr; 1724 PetscBool isascii; 1725 PetscViewerFormat format; 1726 int stage, lastStage; 1727 PetscStageLog stageLog; 1728 1729 PetscFunctionBegin; 1730 if (!PetscLogPLB) SETERRQ(PETSC_COMM_SELF,PETSC_ERR_SUP,"Must use -log_view or PetscLogDefaultBegin() before calling this routine"); 1731 /* Pop off any stages the user forgot to remove */ 1732 lastStage = 0; 1733 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 1734 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 1735 while (stage >= 0) { 1736 lastStage = stage; 1737 ierr = PetscStageLogPop(stageLog);CHKERRQ(ierr); 1738 ierr = PetscStageLogGetCurrent(stageLog, &stage);CHKERRQ(ierr); 1739 } 1740 ierr = PetscObjectTypeCompare((PetscObject)viewer,PETSCVIEWERASCII,&isascii);CHKERRQ(ierr); 1741 if (!isascii) SETERRQ(PetscObjectComm((PetscObject)viewer),PETSC_ERR_SUP,"Currently can only view logging to ASCII"); 1742 ierr = PetscViewerGetFormat(viewer,&format);CHKERRQ(ierr); 1743 if (format == PETSC_VIEWER_DEFAULT || format == PETSC_VIEWER_ASCII_INFO) { 1744 ierr = PetscLogView_Default(viewer);CHKERRQ(ierr); 1745 } else if (format == PETSC_VIEWER_ASCII_INFO_DETAIL) { 1746 ierr = PetscLogView_Detailed(viewer);CHKERRQ(ierr); 1747 } else if (format == PETSC_VIEWER_ASCII_XML) { 1748 ierr = PetscLogView_Nested(viewer);CHKERRQ(ierr); 1749 } 1750 ierr = PetscStageLogPush(stageLog, lastStage);CHKERRQ(ierr); 1751 PetscFunctionReturn(0); 1752 } 1753 1754 /*@C 1755 PetscLogViewFromOptions - Processes command line options to determine if/how a PetscLog is to be viewed. 1756 1757 Collective on PETSC_COMM_WORLD 1758 1759 Not normally called by user 1760 1761 Level: intermediate 1762 1763 @*/ 1764 PetscErrorCode PetscLogViewFromOptions(void) 1765 { 1766 PetscErrorCode ierr; 1767 PetscViewer viewer; 1768 PetscBool flg; 1769 PetscViewerFormat format; 1770 1771 PetscFunctionBegin; 1772 ierr = PetscOptionsGetViewer(PETSC_COMM_WORLD,NULL,"-log_view",&viewer,&format,&flg);CHKERRQ(ierr); 1773 if (flg) { 1774 ierr = PetscViewerPushFormat(viewer,format);CHKERRQ(ierr); 1775 ierr = PetscLogView(viewer);CHKERRQ(ierr); 1776 ierr = PetscViewerPopFormat(viewer);CHKERRQ(ierr); 1777 ierr = PetscViewerDestroy(&viewer);CHKERRQ(ierr); 1778 } 1779 PetscFunctionReturn(0); 1780 } 1781 1782 1783 1784 /*----------------------------------------------- Counter Functions -------------------------------------------------*/ 1785 /*@C 1786 PetscGetFlops - Returns the number of flops used on this processor 1787 since the program began. 1788 1789 Not Collective 1790 1791 Output Parameter: 1792 flops - number of floating point operations 1793 1794 Notes: 1795 A global counter logs all PETSc flop counts. The user can use 1796 PetscLogFlops() to increment this counter to include flops for the 1797 application code. 1798 1799 Level: intermediate 1800 1801 .keywords: log, flops, floating point operations 1802 1803 .seealso: PetscTime(), PetscLogFlops() 1804 @*/ 1805 PetscErrorCode PetscGetFlops(PetscLogDouble *flops) 1806 { 1807 PetscFunctionBegin; 1808 *flops = petsc_TotalFlops; 1809 PetscFunctionReturn(0); 1810 } 1811 1812 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 1813 { 1814 PetscErrorCode ierr; 1815 size_t fullLength; 1816 va_list Argp; 1817 1818 PetscFunctionBegin; 1819 if (!petsc_logObjects) PetscFunctionReturn(0); 1820 va_start(Argp, format); 1821 ierr = PetscVSNPrintf(petsc_objects[obj->id].info, 64,format,&fullLength, Argp);CHKERRQ(ierr); 1822 va_end(Argp); 1823 PetscFunctionReturn(0); 1824 } 1825 1826 1827 /*MC 1828 PetscLogFlops - Adds floating point operations to the global counter. 1829 1830 Synopsis: 1831 #include <petsclog.h> 1832 PetscErrorCode PetscLogFlops(PetscLogDouble f) 1833 1834 Not Collective 1835 1836 Input Parameter: 1837 . f - flop counter 1838 1839 1840 Usage: 1841 .vb 1842 PetscLogEvent USER_EVENT; 1843 PetscLogEventRegister("User event",0,&USER_EVENT); 1844 PetscLogEventBegin(USER_EVENT,0,0,0,0); 1845 [code segment to monitor] 1846 PetscLogFlops(user_flops) 1847 PetscLogEventEnd(USER_EVENT,0,0,0,0); 1848 .ve 1849 1850 Notes: 1851 A global counter logs all PETSc flop counts. The user can use 1852 PetscLogFlops() to increment this counter to include flops for the 1853 application code. 1854 1855 Level: intermediate 1856 1857 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscGetFlops() 1858 1859 .keywords: log, flops, floating point operations 1860 M*/ 1861 1862 /*MC 1863 PetscPreLoadBegin - Begin a segment of code that may be preloaded (run twice) 1864 to get accurate timings 1865 1866 Synopsis: 1867 #include <petsclog.h> 1868 void PetscPreLoadBegin(PetscBool flag,char *name); 1869 1870 Not Collective 1871 1872 Input Parameter: 1873 + flag - PETSC_TRUE to run twice, PETSC_FALSE to run once, may be overridden 1874 with command line option -preload true or -preload false 1875 - name - name of first stage (lines of code timed separately with -log_view) to 1876 be preloaded 1877 1878 Usage: 1879 .vb 1880 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1881 lines of code 1882 PetscPreLoadStage("second stage"); 1883 lines of code 1884 PetscPreLoadEnd(); 1885 .ve 1886 1887 Notes: 1888 Only works in C/C++, not Fortran 1889 1890 Flags available within the macro. 1891 + PetscPreLoadingUsed - true if we are or have done preloading 1892 . PetscPreLoadingOn - true if it is CURRENTLY doing preload 1893 . PetscPreLoadIt - 0 for the first computation (with preloading turned off it is only 0) 1 for the second 1894 - PetscPreLoadMax - number of times it will do the computation, only one when preloading is turned on 1895 The first two variables are available throughout the program, the second two only between the PetscPreLoadBegin() 1896 and PetscPreLoadEnd() 1897 1898 Level: intermediate 1899 1900 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadEnd(), PetscPreLoadStage() 1901 1902 Concepts: preloading 1903 Concepts: timing^accurate 1904 Concepts: paging^eliminating effects of 1905 1906 1907 M*/ 1908 1909 /*MC 1910 PetscPreLoadEnd - End a segment of code that may be preloaded (run twice) 1911 to get accurate timings 1912 1913 Synopsis: 1914 #include <petsclog.h> 1915 void PetscPreLoadEnd(void); 1916 1917 Not Collective 1918 1919 Usage: 1920 .vb 1921 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1922 lines of code 1923 PetscPreLoadStage("second stage"); 1924 lines of code 1925 PetscPreLoadEnd(); 1926 .ve 1927 1928 Notes: 1929 only works in C/C++ not fortran 1930 1931 Level: intermediate 1932 1933 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadStage() 1934 1935 M*/ 1936 1937 /*MC 1938 PetscPreLoadStage - Start a new segment of code to be timed separately. 1939 to get accurate timings 1940 1941 Synopsis: 1942 #include <petsclog.h> 1943 void PetscPreLoadStage(char *name); 1944 1945 Not Collective 1946 1947 Usage: 1948 .vb 1949 PetscPreLoadBegin(PETSC_TRUE,"first stage); 1950 lines of code 1951 PetscPreLoadStage("second stage"); 1952 lines of code 1953 PetscPreLoadEnd(); 1954 .ve 1955 1956 Notes: 1957 only works in C/C++ not fortran 1958 1959 Level: intermediate 1960 1961 .seealso: PetscLogEventRegister(), PetscLogEventBegin(), PetscLogEventEnd(), PetscPreLoadBegin(), PetscPreLoadEnd() 1962 1963 M*/ 1964 1965 1966 #else /* end of -DPETSC_USE_LOG section */ 1967 1968 PetscErrorCode PetscLogObjectState(PetscObject obj, const char format[], ...) 1969 { 1970 PetscFunctionBegin; 1971 PetscFunctionReturn(0); 1972 } 1973 1974 #endif /* PETSC_USE_LOG*/ 1975 1976 1977 PetscClassId PETSC_LARGEST_CLASSID = PETSC_SMALLEST_CLASSID; 1978 PetscClassId PETSC_OBJECT_CLASSID = 0; 1979 1980 /*@C 1981 PetscClassIdRegister - Registers a new class name for objects and logging operations in an application code. 1982 1983 Not Collective 1984 1985 Input Parameter: 1986 . name - The class name 1987 1988 Output Parameter: 1989 . oclass - The class id or classid 1990 1991 Level: developer 1992 1993 .keywords: log, class, register 1994 1995 @*/ 1996 PetscErrorCode PetscClassIdRegister(const char name[],PetscClassId *oclass) 1997 { 1998 #if defined(PETSC_USE_LOG) 1999 PetscStageLog stageLog; 2000 PetscInt stage; 2001 PetscErrorCode ierr; 2002 #endif 2003 2004 PetscFunctionBegin; 2005 *oclass = ++PETSC_LARGEST_CLASSID; 2006 #if defined(PETSC_USE_LOG) 2007 ierr = PetscLogGetStageLog(&stageLog);CHKERRQ(ierr); 2008 ierr = PetscClassRegLogRegister(stageLog->classLog, name, *oclass);CHKERRQ(ierr); 2009 for (stage = 0; stage < stageLog->numStages; stage++) { 2010 ierr = PetscClassPerfLogEnsureSize(stageLog->stageInfo[stage].classLog, stageLog->classLog->numClasses);CHKERRQ(ierr); 2011 } 2012 #endif 2013 PetscFunctionReturn(0); 2014 } 2015 2016 #if defined(PETSC_USE_LOG) && defined(PETSC_HAVE_MPE) 2017 #include <mpe.h> 2018 2019 PetscBool PetscBeganMPE = PETSC_FALSE; 2020 2021 PETSC_INTERN PetscErrorCode PetscLogEventBeginMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2022 PETSC_INTERN PetscErrorCode PetscLogEventEndMPE(PetscLogEvent,int,PetscObject,PetscObject,PetscObject,PetscObject); 2023 2024 /*@C 2025 PetscLogMPEBegin - Turns on MPE logging of events. This creates large log files 2026 and slows the program down. 2027 2028 Collective over PETSC_COMM_WORLD 2029 2030 Options Database Keys: 2031 . -log_mpe - Prints extensive log information 2032 2033 Notes: 2034 A related routine is PetscLogDefaultBegin() (with the options key -log_view), which is 2035 intended for production runs since it logs only flop rates and object 2036 creation (and should not significantly slow the programs). 2037 2038 Level: advanced 2039 2040 Concepts: logging^MPE 2041 Concepts: logging^message passing 2042 2043 .seealso: PetscLogDump(), PetscLogDefaultBegin(), PetscLogAllBegin(), PetscLogEventActivate(), 2044 PetscLogEventDeactivate() 2045 @*/ 2046 PetscErrorCode PetscLogMPEBegin(void) 2047 { 2048 PetscErrorCode ierr; 2049 2050 PetscFunctionBegin; 2051 /* Do MPE initialization */ 2052 if (!MPE_Initialized_logging()) { /* This function exists in mpich 1.1.2 and higher */ 2053 ierr = PetscInfo(0,"Initializing MPE.\n");CHKERRQ(ierr); 2054 ierr = MPE_Init_log();CHKERRQ(ierr); 2055 2056 PetscBeganMPE = PETSC_TRUE; 2057 } else { 2058 ierr = PetscInfo(0,"MPE already initialized. Not attempting to reinitialize.\n");CHKERRQ(ierr); 2059 } 2060 ierr = PetscLogSet(PetscLogEventBeginMPE, PetscLogEventEndMPE);CHKERRQ(ierr); 2061 PetscFunctionReturn(0); 2062 } 2063 2064 /*@C 2065 PetscLogMPEDump - Dumps the MPE logging info to file for later use with Jumpshot. 2066 2067 Collective over PETSC_COMM_WORLD 2068 2069 Level: advanced 2070 2071 .seealso: PetscLogDump(), PetscLogAllBegin(), PetscLogMPEBegin() 2072 @*/ 2073 PetscErrorCode PetscLogMPEDump(const char sname[]) 2074 { 2075 char name[PETSC_MAX_PATH_LEN]; 2076 PetscErrorCode ierr; 2077 2078 PetscFunctionBegin; 2079 if (PetscBeganMPE) { 2080 ierr = PetscInfo(0,"Finalizing MPE.\n");CHKERRQ(ierr); 2081 if (sname) { 2082 ierr = PetscStrcpy(name,sname);CHKERRQ(ierr); 2083 } else { 2084 ierr = PetscGetProgramName(name,PETSC_MAX_PATH_LEN);CHKERRQ(ierr); 2085 } 2086 ierr = MPE_Finish_log(name);CHKERRQ(ierr); 2087 } else { 2088 ierr = PetscInfo(0,"Not finalizing MPE (not started by PETSc).\n");CHKERRQ(ierr); 2089 } 2090 PetscFunctionReturn(0); 2091 } 2092 2093 #define PETSC_RGB_COLORS_MAX 39 2094 static const char *PetscLogMPERGBColors[PETSC_RGB_COLORS_MAX] = { 2095 "OliveDrab: ", 2096 "BlueViolet: ", 2097 "CadetBlue: ", 2098 "CornflowerBlue: ", 2099 "DarkGoldenrod: ", 2100 "DarkGreen: ", 2101 "DarkKhaki: ", 2102 "DarkOliveGreen: ", 2103 "DarkOrange: ", 2104 "DarkOrchid: ", 2105 "DarkSeaGreen: ", 2106 "DarkSlateGray: ", 2107 "DarkTurquoise: ", 2108 "DeepPink: ", 2109 "DarkKhaki: ", 2110 "DimGray: ", 2111 "DodgerBlue: ", 2112 "GreenYellow: ", 2113 "HotPink: ", 2114 "IndianRed: ", 2115 "LavenderBlush: ", 2116 "LawnGreen: ", 2117 "LemonChiffon: ", 2118 "LightCoral: ", 2119 "LightCyan: ", 2120 "LightPink: ", 2121 "LightSalmon: ", 2122 "LightSlateGray: ", 2123 "LightYellow: ", 2124 "LimeGreen: ", 2125 "MediumPurple: ", 2126 "MediumSeaGreen: ", 2127 "MediumSlateBlue:", 2128 "MidnightBlue: ", 2129 "MintCream: ", 2130 "MistyRose: ", 2131 "NavajoWhite: ", 2132 "NavyBlue: ", 2133 "OliveDrab: " 2134 }; 2135 2136 /*@C 2137 PetscLogMPEGetRGBColor - This routine returns a rgb color useable with PetscLogEventRegister() 2138 2139 Not collective. Maybe it should be? 2140 2141 Output Parameter 2142 . str - character string representing the color 2143 2144 Level: developer 2145 2146 .keywords: log, mpe , color 2147 .seealso: PetscLogEventRegister 2148 @*/ 2149 PetscErrorCode PetscLogMPEGetRGBColor(const char *str[]) 2150 { 2151 static int idx = 0; 2152 2153 PetscFunctionBegin; 2154 *str = PetscLogMPERGBColors[idx]; 2155 idx = (idx + 1)% PETSC_RGB_COLORS_MAX; 2156 PetscFunctionReturn(0); 2157 } 2158 2159 #endif /* PETSC_USE_LOG && PETSC_HAVE_MPE */ 2160