From 5f4112b04e4f70b6f781fccfc078ed61007fc768 Mon Sep 17 00:00:00 2001 From: Dusan Jovic Date: Tue, 1 Apr 2025 14:06:10 +0000 Subject: [PATCH 1/3] Add ufs_tracing --- model/src/CMakeLists.txt | 1 + model/src/wav_comp_nuopc.F90 | 26 ++++++++++++++++++++++++++ 2 files changed, 27 insertions(+) diff --git a/model/src/CMakeLists.txt b/model/src/CMakeLists.txt index 8e2f3b52d5..925c91b50a 100644 --- a/model/src/CMakeLists.txt +++ b/model/src/CMakeLists.txt @@ -154,6 +154,7 @@ if(UFS_CAP) target_sources(ww3_lib PRIVATE ${cap_src}) target_link_libraries(ww3_lib PUBLIC esmf) + target_link_libraries(ww3_lib PUBLIC ufs_utils) # Don't build executables when building WW3 ESMF library set(programs "") endif() diff --git a/model/src/wav_comp_nuopc.F90 b/model/src/wav_comp_nuopc.F90 index 78f65202e3..abd61a3c25 100644 --- a/model/src/wav_comp_nuopc.F90 +++ b/model/src/wav_comp_nuopc.F90 @@ -59,6 +59,7 @@ module wav_comp_nuopc use shr_is_restart_fh_mod , only : init_is_restart_fh, is_restart_fh, is_restart_fh_type #endif use constants , only : is_esmf_component + use ufs_trace_mod implicit none private ! except @@ -104,6 +105,7 @@ module wav_comp_nuopc character(*), parameter :: u_FILE_u = & !< a character string for an ESMF log message __FILE__ + integer :: mype = -1 !=============================================================================== contains !=============================================================================== @@ -120,10 +122,19 @@ subroutine SetServices(gcomp, rc) integer, intent(out) :: rc character(len=*),parameter :: subname=trim(modName)//':(SetServices) ' + type(ESMF_VM) :: vm rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + call ESMF_GridCompGet(gcomp, vm=vm,rc=rc) + if (ChkErr(rc,__LINE__,u_FILE_u)) return + call ESMF_VMGet(vm, localpet=mype, rc=rc) + if (ChkErr(rc,__LINE__,u_FILE_u)) return + + if (mype == 0) call ufs_trace_init() + if (mype == 0) call ufs_trace("wave", "SetServices", "B") + ! the NUOPC gcomp component will register the generic methods call NUOPC_CompDerive(gcomp, model_routine_SS, rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return @@ -164,6 +175,7 @@ subroutine SetServices(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "SetServices", "E") end subroutine SetServices !=============================================================================== @@ -188,12 +200,14 @@ subroutine InitializeP0(gcomp, importState, exportState, clock, rc) !------------------------------------------------------------------------------- rc = ESMF_SUCCESS + if (mype == 0) call ufs_trace("wave", "InitializeP0", "B") ! Switch to IPDv01 by filtering all other phaseMap entries call NUOPC_CompFilterPhaseMap(gcomp, ESMF_METHOD_INITIALIZE, acceptStringList=(/"IPDv01p"/), rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return + if (mype == 0) call ufs_trace("wave", "InitializeP0", "E") end subroutine InitializeP0 !=============================================================================== @@ -237,6 +251,7 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) character(len=*), parameter :: subname=trim(modName)//':(InitializeAdvertise) ' !------------------------------------------------------------------------------- + if (mype == 0) call ufs_trace("wave", "InitializeAdvertise", "B") call ufs_settimer(wtime) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) @@ -391,6 +406,7 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "InitializeAdvertise", "E") end subroutine InitializeAdvertise !======================================================================== @@ -494,6 +510,7 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "InitializeRealize", "B") call ufs_settimer(wtime) !-------------------------------------------------------------------- @@ -993,6 +1010,7 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "InitializeRealize", "E") end subroutine InitializeRealize !=============================================================================== @@ -1033,6 +1051,7 @@ subroutine DataInitialize(gcomp, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "DataInitialize", "B") call NUOPC_ModelGet(gcomp, exportState=exportState, rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return @@ -1086,6 +1105,7 @@ subroutine DataInitialize(gcomp, rc) if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "DataInitialize", "E") end subroutine DataInitialize !===================================================================== @@ -1136,6 +1156,7 @@ subroutine ModelAdvance(gcomp, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "ModelAdvance", "B") !------------ ! query the Component for its importState, exportState and clock @@ -1262,6 +1283,7 @@ subroutine ModelAdvance(gcomp, rc) if (root_task) call ufs_logtimer(nu_timer,time,tod,'ModelAdvance time: ',runtimelog,wtime) call ufs_settimer(wtime) + if (mype == 0) call ufs_trace("wave", "ModelAdvance", "E") end subroutine ModelAdvance !=============================================================================== @@ -1309,6 +1331,7 @@ subroutine ModelSetRunClock(gcomp, rc) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "ModelSetRunClock", "B") ! query the Component for its clocks call NUOPC_ModelGet(gcomp, driverClock=dclock, modelClock=mclock, rc=rc) @@ -1458,6 +1481,7 @@ subroutine ModelSetRunClock(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "ModelSetRunClock", "E") end subroutine ModelSetRunClock !=============================================================================== @@ -1482,6 +1506,7 @@ subroutine ModelFinalize(gcomp, rc) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) + if (mype == 0) call ufs_trace("wave", "ModelFinalize", "B") if ( root_task ) then write(nds(1),F91) @@ -1492,6 +1517,7 @@ subroutine ModelFinalize(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) if(root_task) call ufs_logtimer(nu_timer,timen,tod,'ModelFinalize time: ',runtimelog,wtime) + if (mype == 0) call ufs_trace("wave", "ModelFinalize", "E") end subroutine ModelFinalize !=============================================================================== From f5d17a6f1da4cfcbcc46876b43cdcaaa57910fcf Mon Sep 17 00:00:00 2001 From: Dusan Jovic Date: Wed, 10 Sep 2025 13:50:10 +0000 Subject: [PATCH 2/3] Conditional compilation of ufs_tracing --- model/src/wav_comp_nuopc.F90 | 34 ++++++++++++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/model/src/wav_comp_nuopc.F90 b/model/src/wav_comp_nuopc.F90 index bac687ee62..b3ef15e520 100644 --- a/model/src/wav_comp_nuopc.F90 +++ b/model/src/wav_comp_nuopc.F90 @@ -52,7 +52,9 @@ module wav_comp_nuopc #ifndef W3_CESMCOUPLED use shr_is_restart_fh_mod , only : init_is_restart_fh, is_restart_fh, is_restart_fh_type #endif +#ifdef UFS_TRACING use ufs_trace_mod +#endif implicit none private ! except @@ -124,8 +126,10 @@ subroutine SetServices(gcomp, rc) call ESMF_VMGet(vm, localpet=mype, rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return +#ifdef UFS_TRACING if (mype == 0) call ufs_trace_init() if (mype == 0) call ufs_trace("wave", "SetServices", "B") +#endif ! the NUOPC gcomp component will register the generic methods call NUOPC_CompDerive(gcomp, model_routine_SS, rc=rc) @@ -167,7 +171,9 @@ subroutine SetServices(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "SetServices", "E") +#endif end subroutine SetServices !=============================================================================== @@ -192,14 +198,18 @@ subroutine InitializeP0(gcomp, importState, exportState, clock, rc) !------------------------------------------------------------------------------- rc = ESMF_SUCCESS +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeP0", "B") +#endif ! Switch to IPDv01 by filtering all other phaseMap entries call NUOPC_CompFilterPhaseMap(gcomp, ESMF_METHOD_INITIALIZE, acceptStringList=(/"IPDv01p"/), rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeP0", "E") +#endif end subroutine InitializeP0 !=============================================================================== @@ -277,7 +287,9 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) character(len=*), parameter :: subname=trim(modName)//':(InitializeAdvertise) ' !------------------------------------------------------------------------------- +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeAdvertise", "B") +#endif call ufs_settimer(wtime) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) @@ -696,7 +708,9 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeAdvertise", "E") +#endif end subroutine InitializeAdvertise !======================================================================== @@ -767,7 +781,9 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeRealize", "B") +#endif call ufs_settimer(wtime) @@ -942,7 +958,9 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "InitializeRealize", "E") +#endif end subroutine InitializeRealize !=============================================================================== @@ -979,7 +997,9 @@ subroutine DataInitialize(gcomp, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "DataInitialize", "B") +#endif call NUOPC_ModelGet(gcomp, exportState=exportState, rc=rc) if (ChkErr(rc,__LINE__,u_FILE_u)) return @@ -1033,7 +1053,9 @@ subroutine DataInitialize(gcomp, rc) if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "DataInitialize", "E") +#endif end subroutine DataInitialize !===================================================================== @@ -1082,7 +1104,9 @@ subroutine ModelAdvance(gcomp, rc) rc = ESMF_SUCCESS if (dbug_flag > 5) call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelAdvance", "B") +#endif !------------ ! query the Component for its importState, exportState and clock @@ -1193,7 +1217,9 @@ subroutine ModelAdvance(gcomp, rc) if (root_task) call ufs_logtimer(nu_timer,time,tod,'ModelAdvance time: ',runtimelog,wtime) call ufs_settimer(wtime) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelAdvance", "E") +#endif end subroutine ModelAdvance !=============================================================================== @@ -1240,7 +1266,9 @@ subroutine ModelSetRunClock(gcomp, rc) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelSetRunClock", "B") +#endif ! query the Component for its clocks call NUOPC_ModelGet(gcomp, driverClock=dclock, modelClock=mclock, rc=rc) @@ -1389,7 +1417,9 @@ subroutine ModelSetRunClock(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelSetRunClock", "E") +#endif end subroutine ModelSetRunClock !=============================================================================== @@ -1414,7 +1444,9 @@ subroutine ModelFinalize(gcomp, rc) rc = ESMF_SUCCESS call ESMF_LogWrite(trim(subname)//' called', ESMF_LOGMSG_INFO) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelFinalize", "B") +#endif if ( root_task ) then write(nds(1),F91) @@ -1425,7 +1457,9 @@ subroutine ModelFinalize(gcomp, rc) call ESMF_LogWrite(trim(subname)//' done', ESMF_LOGMSG_INFO) if(root_task) call ufs_logtimer(nu_timer,timen,tod,'ModelFinalize time: ',runtimelog,wtime) +#ifdef UFS_TRACING if (mype == 0) call ufs_trace("wave", "ModelFinalize", "E") +#endif end subroutine ModelFinalize !=============================================================================== From 158544c95bb7e5dc3aec3f448d65210cb623cec0 Mon Sep 17 00:00:00 2001 From: Dusan Jovic Date: Fri, 12 Sep 2025 20:09:17 +0000 Subject: [PATCH 3/3] Rename ufs_tracing target --- model/src/CMakeLists.txt | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/model/src/CMakeLists.txt b/model/src/CMakeLists.txt index 24b3b83a73..af0cad79f6 100644 --- a/model/src/CMakeLists.txt +++ b/model/src/CMakeLists.txt @@ -152,7 +152,9 @@ if(UFS_CAP) target_sources(ww3_lib PRIVATE ${cap_src}) target_link_libraries(ww3_lib PUBLIC esmf) - target_link_libraries(ww3_lib PUBLIC ufs_utils) + if(UFS_TRACING) + target_link_libraries(ww3_lib PUBLIC ufs_tracing) + endif() # Don't build executables when building WW3 ESMF library set(programs "") endif()