Belos: Belos_Tpetra_Timers broken

[jennloe]

Bug Report

@trilinos/belos I recently tried the CMake option Belos_Tpetra_Timers=ON in attempt to get more detailed timings. The option did nothing, even though it is used here in lines 444 and 502:

Trilinos/packages/belos/tpetra/src/BelosMultiVecTraits_Tpetra.hpp

Line 444 in 62ff542

#ifdef HAVE_BELOS_TPETRA_TIMERS

I believe the Belos CMakeLists.txt has defined the option incorrectly??

Trilinos/packages/belos/CMakeLists.txt

Lines 52 to 55 in 62ff542

	${PACKAGE_NAME}_Tpetra_Timers
	HAVE_BELOS_TPETRA_TIMERS
	"Add timers to Belos::MultiVecTraits for Tpetra::MultiVector operations."
	NO )

[jhux2]

I believe the Belos CMakeLists.txt has defined the option incorrectly??

The option syntax looks correct.

[hkthorn]

@jennloe Can you add #include "BelosConfigDefs.hpp" in the file BelosMultiVecTraits_Tpetra.hpp?

[jennloe]

@hkthorn I'll try that now.

[jennloe]

That didn't do it @hkthorn. I'll look again in the morning.

[cgcgcg]

@jennloe Two things you might want to check. Either the code doesn't get compiled or it doesn't get executed. I'd test the first by putting some random garbage in there to check that things between the pragmas is included. And if that's the case, add a print statement or fire up the debugger. Is it possible that your are using Tpetra via the Thyra layer?

[jhux2]

In addition to what @cgcgcg suggested, you could also put a print in CMakeLists.txt to check how the option is being processed. Something like

IF (${PACKAGE_NAME}_Tpetra_Timers)
  message(STATUS "Tpetra timers enabled)
ELSE()
  message(STATUS "Tpetra timers disabled")
ENDIF()

[hkthorn]

@jennloe Which solver are you looking at? These timers are only for MvTransMv and MvTimesMatAddMv, which is not used by every solver. For instance, when I enable the timers I can see something from the pseudo-block GMRES solver:

==============================================================================================
                                            TimeMonitor results over 2 processors

Timer Name                                        MinOverProcs     MeanOverProcs     MaxOverProcs      MeanOverCallCounts    
-----------------------------------------------------------------------------------------------------------------------------
Belos: ICGS[2]: Ortho (Inner Product)             0.02514 (582)    0.02522 (582)     0.02531 (582)     4.334e-05 (582)       
Belos: ICGS[2]: Ortho (Norm)                      0.00189 (297)    0.001914 (297)    0.001938 (297)    6.444e-06 (297)       
Belos: ICGS[2]: Ortho (Update)                    0.02045 (582)    0.02055 (582)     0.02065 (582)     3.53e-05 (582)        
Belos: ICGS[2]: Orthogonalization                 0.05454 (297)    0.05455 (297)     0.05457 (297)     0.0001837 (297)       
Belos: Operation Op*x                             0.01047 (298)    0.01061 (298)     0.01074 (298)     3.559e-05 (298)       
Belos: Operation Prec*x                           0 (0)            0 (0)             0 (0)             0 (0)                 
Belos: PseudoBlockGmresSolMgr total solve time    0.09987 (1)      0.09988 (1)       0.0999 (1)        0.09988 (1)           
Belos::MVT::MvTimesMatAddMv                       0.02006 (588)    0.02019 (588)     0.02032 (588)     3.434e-05 (588)       
Belos::MVT::MvTransMv                             0.02451 (582)    0.02456 (582)     0.02461 (582)     4.22e-05 (582)        
==============================================================================================

However, the CG-based solvers do not use MvTransMv unless the option for "Fold Convergence Detection Into Allreduce" is true or the block size is greater than 1.

[hkthorn]

@jennloe If the CG solver is what you are looking at, additional timers can be added for MvNorm, MvAddMv, MvDot, and MvAssign that gives more timing information. As an example below:

                                         TimeMonitor results over 2 processors

Timer Name                               MinOverProcs       MeanOverProcs      MaxOverProcs       MeanOverCallCounts    
------------------------------------------------------------------------------------------------------------------------
Belos: BlockCGSolMgr total solve time    0.06261 (1)        0.06265 (1)        0.06269 (1)        0.06265 (1)           
Belos: ICGS[2]: Ortho (Inner Product)    0 (0)              0 (0)              0 (0)              0 (0)                 
Belos: ICGS[2]: Ortho (Norm)             0 (0)              0 (0)              0 (0)              0 (0)                 
Belos: ICGS[2]: Ortho (Update)           0 (0)              0 (0)              0 (0)              0 (0)                 
Belos: ICGS[2]: Orthogonalization        0 (0)              0 (0)              0 (0)              0 (0)                 
Belos: Operation Op*x                    0.03727 (827)      0.03733 (827)      0.03739 (827)      4.514e-05 (827)       
Belos: Operation Prec*x                  0 (0)              0 (0)              0 (0)              0 (0)                 
Belos::MVT::MvAddMv                      0.004965 (2479)    0.005034 (2479)    0.005103 (2479)    2.031e-06 (2479)      
Belos::MVT::MvAssign                     0.000882 (829)     0.0008945 (829)    0.000907 (829)     1.079e-06 (829)       
Belos::MVT::MvDot                        0.01081 (1653)     0.01088 (1653)     0.01094 (1653)     6.579e-06 (1653)      
------------------------------------------------------------------------------------------------------------------------
Belos::MVT::MvNorm                       0.004908 (828)     0.004979 (828)     0.00505 (828)      6.013e-06 (828)       
==============================================================================================