-
Notifications
You must be signed in to change notification settings - Fork 155
Add UFS tracing instrumentation to nuopc/cmeps driver #1075
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 17 commits
f124914
5e57a89
cf01f33
513f8d1
ff7fd76
ea4582b
4411a15
dce7176
473f258
feb4c7b
90ed252
31921b1
01024e6
5278e39
c90ee5a
f888f31
d69a94d
5671194
ad16178
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -59,6 +59,9 @@ module ice_comp_nuopc | |||||||||||||||||||||||||||||||||||||||||||||||||
| #ifndef 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 | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -117,6 +120,7 @@ module ice_comp_nuopc | |||||||||||||||||||||||||||||||||||||||||||||||||
| character(*), parameter :: u_FILE_u = & | ||||||||||||||||||||||||||||||||||||||||||||||||||
| __FILE__ | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| integer :: mype = -1 | ||||||||||||||||||||||||||||||||||||||||||||||||||
| !======================================================================= | ||||||||||||||||||||||||||||||||||||||||||||||||||
| contains | ||||||||||||||||||||||||||||||||||||||||||||||||||
| !=============================================================================== | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -128,12 +132,23 @@ subroutine SetServices(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| integer, intent(out) :: rc | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| ! Local variables | ||||||||||||||||||||||||||||||||||||||||||||||||||
| type(ESMF_VM) :: vm | ||||||||||||||||||||||||||||||||||||||||||||||||||
| character(len=*),parameter :: subname=trim(modName)//':(SetServices) ' | ||||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| rc = ESMF_SUCCESS | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(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 | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
Comment on lines
+148
to
+151
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Are these used anywhere?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. to set mype (before my_task and master_task are available in InitializeAdvertise) |
||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace_init() | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. We should remain consistent with the rest of the code and check: if (my_task == master_task)
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yes, I thought the same. But, the tracing starts before my_task and master_task are available in InitializeAdvertise
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Can we call init_grid1 before this phase?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Maybe not (?) as I think But, it's more that conflicts with the intent to start the tracing as soon as possible in all subcomponents (before calling much else) towards getting the fullest timeline of the run. And for this to be "unobtrusive" fwiw, I think master_task and mype==0 are really the same since
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I guess these lines could be moved up to SetServices from InitializeAdvertise if there is really strong preference CICE/cicecore/drivers/nuopc/cmeps/ice_comp_nuopc.F90 Lines 346 to 368 in fa682b3
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think it is not guaranteed on all systems that master_task = 0. Does the call to ufs_trace_init really have to happen at this phase? I realize there are often issues with circular dependencies. I feel like the tracing doesn't need to happen before the scatter and PE decomposition.
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think it's just easier to trace fully than "be smart" about what needs to be traced One example where accounting/separating the different phases was found to be very useful was in trying to reduce GFS initialization time (ufs-community/ufs-weather-model#2831). Like removing some advertised fields from FV3 reduced InitializeAdvertise (top to bottom) |
||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "SetServices", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| ! 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 | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -169,6 +184,9 @@ subroutine SetServices(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(subname//' done', ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "SetServices", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine SetServices | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| !=============================================================================== | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -187,6 +205,9 @@ subroutine InitializeP0(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| rc = ESMF_SUCCESS | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeP0", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| ! Switch to IPDv01 by filtering all other phaseMap entries | ||||||||||||||||||||||||||||||||||||||||||||||||||
| call NUOPC_CompFilterPhaseMap(gcomp, ESMF_METHOD_INITIALIZE, & | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -201,6 +222,9 @@ subroutine InitializeP0(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| write(logmsg,*) profile_memory | ||||||||||||||||||||||||||||||||||||||||||||||||||
| call ESMF_LogWrite('CICE_cap:ProfileMemory = '//trim(logmsg), ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeP0", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine InitializeP0 | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| !=============================================================================== | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -256,6 +280,10 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| character(len=*), parameter :: subname=trim(modName)//':(InitializeAdvertise) ' | ||||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeAdvertise", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| call ufs_settimer(wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| call NUOPC_CompAttributeGet(gcomp, name="ScalarFieldName", value=cvalue, isPresent=isPresent, isSet=isSet, rc=rc) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -766,6 +794,9 @@ subroutine InitializeAdvertise(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| call t_stopf ('cice_init_total') | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mastertask) call ufs_logtimer(nu_timer,msec,'InitializeAdvertise time: ',runtimelog,wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeAdvertise", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine InitializeAdvertise | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| !=============================================================================== | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -799,6 +830,10 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| rc = ESMF_SUCCESS | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeRealize", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(subname//' called', ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| call ufs_settimer(wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -1000,6 +1035,9 @@ subroutine InitializeRealize(gcomp, importState, exportState, clock, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| call flush_fileunit(nu_diag) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mastertask) call ufs_logtimer(nu_timer,msec,'InitializeRealize time: ',runtimelog,wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "InitializeRealize", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine InitializeRealize | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| !=============================================================================== | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -1048,6 +1086,9 @@ subroutine ModelAdvance(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| rc = ESMF_SUCCESS | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "ModelAdvance", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mastertask) call ufs_logtimer(nu_timer,msec,'ModelAdvance time since last step: ',runtimelog,wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| call ufs_settimer(wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -1288,6 +1329,9 @@ subroutine ModelAdvance(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(subname//' done', ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mastertask) call ufs_logtimer(nu_timer,msec,'ModelAdvance time: ',runtimelog,wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "ModelAdvance", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| call ufs_settimer(wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine ModelAdvance | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -1442,6 +1486,9 @@ subroutine ModelFinalize(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| !-------------------------------- | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| rc = ESMF_SUCCESS | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "ModelFinalize", "B") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
| call ufs_settimer(wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(subname//' called', ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (my_task == master_task) then | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
@@ -1452,6 +1499,9 @@ subroutine ModelFinalize(gcomp, rc) | |||||||||||||||||||||||||||||||||||||||||||||||||
| if (dbug > 5) call ESMF_LogWrite(subname//' done', ESMF_LOGMSG_INFO) | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| if(mastertask) call ufs_logtimer(nu_timer,msec,'ModelFinalize time: ',runtimelog,wtime) | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #ifdef UFS_TRACING | ||||||||||||||||||||||||||||||||||||||||||||||||||
| if (mype == 0) call ufs_trace("cice", "ModelFinalize", "E") | ||||||||||||||||||||||||||||||||||||||||||||||||||
| #endif | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
| end subroutine ModelFinalize | ||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||

There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There is already my_task available in the code.