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