- first working version

src/Distributed/MpiRouter.f90

@@ -1,6 +1,7 @@
 module MpiRouterModule
   use RouterBaseModule
   use KindModule, only: I4B, LGP
+  use CpuTimerModule, only: g_timer
   use STLVecIntModule
   use SimVariablesModule, only: proc_id, nr_procs
   use SimStagesModule, only: STG_TO_STR

src/Distributed/MpiRunControl.F90

@@ -9,7 +9,8 @@ module MpiRunControlModule
   use MpiWorldModule
   use SimVariablesModule, only: proc_id, nr_procs
   use SimStagesModule
-  use KindModule, only: I4B, LGP
+  use CpuTimerModule
+  use KindModule, only: I4B, LGP, DP
   use STLVecIntModule
   use NumericalSolutionModule
   use RunControlModule, only: RunControlType
@@ -42,13 +43,25 @@ end function create_mpi_run_control
 
   subroutine mpi_ctrl_start(this)
     use ErrorUtilModule, only: pstop_alternative
+    ! local
+    integer(I4B) :: tmr_init_par
 
     class(MpiRunControlType) :: this
     ! local
     integer :: ierr
     character(len=*), parameter :: petsc_db_file = '.petscrc'
     logical(LGP) :: petsc_db_exists, wait_dbg, is_parallel_mode
     type(MpiWorldType), pointer :: mpi_world
+    procedure(timer_func_iface), pointer :: tmr_func => null()
+
+    ! add timed section for parallel stuff and start timers
+    tmr_func => mpi_walltime
+    call set_timer_func(tmr_func)
+    call g_timer%initialize()
+    tmr_init_par = g_timer%add_section("Init parallel", SECTION_INIT)
+    call g_timer%start(SECTION_RUN)
+    call g_timer%start(SECTION_INIT)
+    call g_timer%start(tmr_init_par)
 
     ! set mpi abort function
     pstop_alternative => mpi_stop
@@ -101,6 +114,9 @@ subroutine mpi_ctrl_start(this)
     ! possibly wait to attach debugger here
     if (wait_dbg) call this%wait_for_debugger()
 
+    ! done with parallel pre-work
+    call g_timer%stop(tmr_init_par)
+
     ! start everything else by calling parent
     call this%RunControlType%start()
 
@@ -128,6 +144,11 @@ subroutine mpi_ctrl_finish(this)
     class(MpiRunControlType) :: this
     ! local
     integer :: ierr
+    integer(I4B) :: tmr_final_par
+
+    ! timer
+    tmr_final_par = g_timer%add_section("Finalize parallel", SECTION_FINALIZE)
+    call g_timer%start(tmr_final_par)
 
     ! finish mpi
 #if defined(__WITH_PETSC__)
@@ -142,6 +163,8 @@ subroutine mpi_ctrl_finish(this)
 
     pstop_alternative => null()
 
+    call g_timer%stop(tmr_final_par)
+
     ! finish everything else by calling parent
     call this%RunControlType%finish()
 
@@ -271,4 +294,14 @@ subroutine mpi_ctrl_after_con_cr(this)
 
   end subroutine mpi_ctrl_after_con_cr
 
+  subroutine mpi_walltime(walltime)
+    real(DP), intent(inout) :: walltime
+    ! local
+    integer :: ierr
+
+    walltime = MPI_Wtime()
+    call CHECK_MPI(ierr)
+
+  end subroutine mpi_walltime
+
 end module MpiRunControlModule

src/RunControl.f90

@@ -5,6 +5,7 @@ module RunControlModule
   use MapperModule
   use ListsModule, only: basesolutionlist
   use NumericalSolutionModule, only: NumericalSolutionType
+  use CpuTimerModule
   implicit none
   private
 
@@ -38,6 +39,13 @@ end function create_seq_run_control
   subroutine ctrl_start(this)
     class(RunControlType) :: this
 
+    ! initialize and start timers, if not done so in the derived class
+    if (.not. g_timer%is_initialized()) then
+      call g_timer%initialize()
+      call g_timer%start(SECTION_RUN)
+      call g_timer%start(SECTION_INIT)
+    end if
+
     allocate (this%virtual_data_mgr)
 
   end subroutine ctrl_start
@@ -56,6 +64,11 @@ subroutine ctrl_finish(this)
     call mem_write_usage(iout)
     call mem_da()
     call elapsed_time(iout, 1)
+
+    ! stop and print timings
+    call g_timer%stop(SECTION_RUN)
+    call g_timer%print_timings()
+
     call final_message()
 
   end subroutine ctrl_finish

src/Solution/NumericalSolution.f90

@@ -4,6 +4,7 @@ module NumericalSolutionModule
   use KindModule, only: DP, I4B, LGP
   use ErrorUtilModule, only: pstop
   use TimerModule, only: code_timer
+  use CpuTimerModule
   use ConstantsModule, only: LINELENGTH, LENSOLUTIONNAME, LENPAKLOC, &
                              DPREC, DZERO, DEM20, DEM15, DEM6, &
                              DEM4, DEM3, DEM2, DEM1, DHALF, DONETHIRD, &
@@ -128,6 +129,13 @@ module NumericalSolutionModule
     real(DP), pointer :: ptcdel0 => null() !< initial PTC delta value
     real(DP), pointer :: ptcexp => null() !< PTC exponent
     !
+    ! -- timer
+    integer(I4B) :: tmr_prep_solve !< timer - prepare solve
+    integer(I4B) :: tmr_solve !< timer - solve
+    integer(I4B) :: tmr_final_solve !< timer - finalize solve
+    integer(I4B) :: tmr_formulate !< timer - formulate
+    integer(I4B) :: tmr_linsolve !< timer - linear solve
+    !
     ! -- adaptive time step
     real(DP), pointer :: atsfrac => null() !< adaptive time step faction
     !
@@ -426,6 +434,7 @@ subroutine sln_df(this)
     integer(I4B), allocatable, dimension(:) :: rowmaxnnz
     integer(I4B) :: ncol, irow_start, irow_end
     integer(I4B) :: mod_offset
+    character(len=LEN_SECTION_TITLE) :: sec_title
     !
     ! -- set sol id and determine nr. of equation in this solution
     do i = 1, this%modellist%Count()
@@ -493,6 +502,18 @@ subroutine sln_df(this)
     !
     ! -- Assign connections, fill ia/ja, map connections
     call this%sln_connect()
+
+    ! add timers
+    write(sec_title,'(a,i0,a)') "Prepare solve (", this%id, ")"
+    this%tmr_prep_solve = g_timer%add_section(sec_title, SECTION_DO_TSTP)
+    write(sec_title,'(a,i0,a)') "Solve (", this%id, ")"
+    this%tmr_solve = g_timer%add_section(sec_title, SECTION_DO_TSTP)
+    write(sec_title,'(a,i0,a)') "Finalize solve (", this%id, ")"
+    this%tmr_final_solve = g_timer%add_section(sec_title, SECTION_DO_TSTP)
+
+    this%tmr_formulate = g_timer%add_section("Formulate", this%tmr_solve)
+    this%tmr_linsolve = g_timer%add_section("Linear solve", this%tmr_solve)
+
   end subroutine sln_df
 
   !> @ brief Allocate and read data
@@ -1421,6 +1442,9 @@ subroutine prepareSolve(this)
     class(NumericalExchangeType), pointer :: cp => null()
     class(NumericalModelType), pointer :: mp => null()
 
+    ! start timer
+    call g_timer%start(this%tmr_prep_solve)
+
     ! synchronize for AD
     call this%synchronize(STG_BFR_EXG_AD, this%synchronize_ctx)
 
@@ -1439,6 +1463,9 @@ subroutine prepareSolve(this)
     ! advance solution
     call this%sln_ad()
 
+    ! stop timer
+    call g_timer%stop(this%tmr_prep_solve)
+
   end subroutine prepareSolve
 
   !> @ brief Build and solve the simulation
@@ -1493,6 +1520,10 @@ subroutine solve(this, kiter)
     real(DP) :: ttsoln
     real(DP) :: dpak
     real(DP) :: outer_hncg
+
+    ! start timer
+    call g_timer%start(this%tmr_solve)
+
     !
     ! -- initialize local variables
     icsv0 = max(1, this%itertot_sim + 1)
@@ -1546,6 +1577,7 @@ subroutine solve(this, kiter)
     end if
     !
     call code_timer(0, ttform, this%ttform)
+    call g_timer%start(this%tmr_formulate)
     !
     ! -- (re)build the solution matrix
     call this%sln_buildsystem(kiter, inewton=1)
@@ -1559,10 +1591,13 @@ subroutine solve(this, kiter)
       call mp%model_nr(kiter, this%system_matrix, 1)
     end do
     call code_timer(1, ttform, this%ttform)
+    call g_timer%stop(this%tmr_formulate)
     !
     ! -- linear solve
     call code_timer(0, ttsoln, this%ttsoln)
+    call g_timer%start(this%tmr_linsolve)
     call this%sln_ls(kiter, kstp, kper, iter, iptc, ptcf)
+    call g_timer%stop(this%tmr_linsolve)
     call code_timer(1, ttsoln, this%ttsoln)
     !
     ! -- increment counters storing the total number of linear and
@@ -1795,6 +1830,9 @@ subroutine solve(this, kiter)
                                         kiter, iter, icsv0, kcsv0)
     end if
 
+    ! stop timer
+    call g_timer%stop(this%tmr_solve)
+
   end subroutine solve
 
   !> @ brief finalize a solution
@@ -1821,6 +1859,10 @@ subroutine finalizeSolve(this, kiter, isgcnvg, isuppress_output)
     character(len=*), parameter :: fmtcnvg = &
       "(1X, I0, ' CALLS TO NUMERICAL SOLUTION ', 'IN TIME STEP ', I0, &
       &' STRESS PERIOD ',I0,/1X,I0,' TOTAL ITERATIONS')"
+
+    ! start timer
+    call g_timer%start(this%tmr_final_solve)
+
     !
     ! -- finalize the outer iteration table
     if (this%iprims > 0) then
@@ -1881,6 +1923,9 @@ subroutine finalizeSolve(this, kiter, isgcnvg, isuppress_output)
       call cp%exg_bd(isgcnvg, isuppress_output, this%id)
     end do
 
+    ! stop timer
+    call g_timer%stop(this%tmr_final_solve)
+
   end subroutine finalizeSolve
 
   ! helper routine to calculate coefficients and setup the solution matrix