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