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