Print timing information to standard output.
Prints a full breakdown of timing information if state%print_full_timers
is true, otherwise just prints the total time.
| Type | Intent | Optional | Attributes | Name | ||
|---|---|---|---|---|---|---|
| type(gs2_program_state_type), | intent(in) | :: | state |
Program state information, needed to print |
||
| type(gs2_timers_type), | intent(in) | :: | timers |
Timing information |
subroutine print_times(state, timers)
use run_parameters, only: save_timer_statistics
use mp, only: proc0, min_reduce, max_reduce, sum_reduce, job
use mp, only: get_mp_times
use redistribute, only: get_redist_times
use fft_work, only: time_fft
use fields_arrays, only: time_field, time_field_mpi
use fields_arrays, only: time_field_invert, time_field_invert_mpi
use fields_arrays, only: time_dump_response, time_read_response
use gs2_reinit, only: time_reinit
use le_derivatives, only: time_vspace_derivatives, time_vspace_derivatives_mpi
use nonlinear_terms, only: time_add_explicit_terms, time_add_explicit_terms_mpi
use nonlinear_terms, only: time_add_explicit_terms_field
#ifdef GS2_EXPERIMENTAL_ENABLE_MEMORY_USAGE
use memory_usage, only: print_memory_usage
#endif
implicit none
!> Program state information, needed to print
type(gs2_program_state_type), intent(in) :: state
!> Timing information
type(gs2_timers_type), intent(in) :: timers
real :: mp_total, mp_over, mp_coll, mp_ptp, mp_sync
real :: redist_total, redist_mpi, redist_copy
if (save_timer_statistics) call write_time_parallel_statistics(timers)
if (.not. proc0) return
if (state%print_full_timers) then
call get_mp_times(mp_total, mp_over, mp_coll, mp_ptp, mp_sync)
call get_redist_times(redist_total, redist_mpi, redist_copy)
!Blank line to force separation from other outputs
write(*, '("")')
write(*, '(" ", a)') formatted_time("Initialization", timers%init(1))
write(*, '("(", a, ")")') formatted_time("field matrix invert", time_field_invert(1))
write(*, '("(", a, ")")') formatted_time("field matrix invert mpi", time_field_invert_mpi)
write(*, '("(", a, ")")') formatted_time("field matrix dump", time_dump_response(1))
write(*, '("(", a, ")")') formatted_time("field matrix read", time_read_response(1))
write(*, '(" ", a)') formatted_time("Advance steps", timers%advance(1))
#ifdef WITH_EIG
write(*, '(" ", a)') formatted_time("Eigensolver", timers%eigval(1))
#endif
write(*, '("(", a, ")")') formatted_time("field solve", time_field(1))
write(*, '("(", a, ")")') formatted_time("field solve mpi", time_field_mpi)
write(*, '("(", a, ")")') formatted_time("collisions", time_vspace_derivatives(1))
write(*, '("(", a, ")")') formatted_time("collisions mpi", time_vspace_derivatives_mpi)
write(*, '("(", a, ")")') formatted_time("explicit/nl", time_add_explicit_terms(1))
write(*, '("(", a, ")")') formatted_time("explicit/nl mpi", time_add_explicit_terms_mpi)
write(*, '("(", a, ")")') formatted_time("explicit/nl fft", time_fft(1))
write(*, '("(", a, ")")') formatted_time("explicit/nl fields", time_add_explicit_terms_field(1))
write(*, '("(", a, ")")') formatted_time("diagnostics", timers%diagnostics(1))
write(*, '(" ", a)') formatted_time("Re-initialize", time_reinit(1))
write(*, '(" ", a)') formatted_time("Redistribute", redist_total)
write(*, '("(", a, ")")') formatted_time("redistribute mpi", redist_mpi)
write(*, '("(", a, ")")') formatted_time("redistribute copy", redist_copy)
write(*, '(" ", a)') formatted_time("Finishing", timers%finish(1))
write(*, '(" ", a)') formatted_time("MPI" ,mp_total)
write(*, '("(", a, ")")') formatted_time("Overheads", mp_over)
write(*, '("(", a, ")")') formatted_time("Collectives", mp_coll)
write(*, '("(", a, ")")') formatted_time("PTP", mp_ptp)
write(*, '("(", a, ")")') formatted_time("Sync", mp_sync)
write(*, '(" total from timer is:", 0pf9.2, " min", /)') timers%total(1) / 60.
else
if (state%external_job_id >= 0) then
write(*, '(a, i0, ", ")', advance="no") " External job ID: ", state%external_job_id
end if
if (state%list) then
write(*, '(a, i0, ", ")', advance="no") " Job ID: ", job
end if
write(*, '("Total from timer is:", 0pf9.2," min")') state%timers%total(1)/60.
endif
#ifdef GS2_EXPERIMENTAL_ENABLE_MEMORY_USAGE
call print_memory_usage
#endif
contains
!> Print a single formatted timer line
character(len=46) function formatted_time(name, timer)
!> Name of the timer
character(len=*), intent(in) :: name
!> Time in seconds
real, intent(in) :: timer
write(formatted_time, "(a, T25, 0pf9.3, ' min', T40, 2pf5.1, ' %')") name, timer / 60., timer/timers%total(1)
end function formatted_time
end subroutine print_times