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