E3sm: SMS_D_Ln1.ne30_ne30.FC5AV1C-L issues (cori-knl, edison, titan)

[ndkeen]

With master as of today, this test is failing. Which looks very similar to https://github.com/E3SM-Project/E3SM/issues/2131

 554: forrtl: severe (153): allocatable array or pointer is not allocated
 554: Image              PC                Routine            Line        Source
 554: e3sm.exe           000000000C06905C  Unknown               Unknown  Unknown
 554: e3sm.exe           000000000193C157  rrtmg_state_mp_rr         236  rrtmg_state.F90
 554: e3sm.exe           0000000000E2CFEF  radiation_mp_radi        1425  radiation.F90
 554: e3sm.exe           0000000000D44A4C  physpkg_mp_tphysb        2709  physpkg.F90
 554: e3sm.exe           0000000000D108B7  physpkg_mp_phys_r        1034  physpkg.F90
 554: e3sm.exe           000000000A50C3E3  Unknown               Unknown  Unknown
 554: e3sm.exe           000000000A4C3CC0  Unknown               Unknown  Unknown
 554: e3sm.exe           000000000A4C2F1A  Unknown               Unknown  Unknown

Which is a familiar error as that is something I've been trying to deal with in the past that only happens with ne120 F cases

Attempts so far to narrow down:
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_gnu pass
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_gnu7 pass
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_intel fail
SMS_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_intel pass

[ndkeen]

I ran 3 mores tests that all passed. One with forcing 1 thread, the others reducing the number of total MPI tasks. The jobs above used 41 nodes.

SMS_D_PMx1_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_intel pass  (22 nodes)
SMS_D_PS_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_intel pass (21 nodes)
SMS_D_PT_Ln1.ne30_ne30.FC5AV1C-L.cori-knl_intel pass (5 nodes)

[ndkeen]

On next, however, I ran the test and it fails, but with different error:

1225: forrtl: error (73): floating divide by zero
1225: Image              PC                Routine            Line        Source
1225: e3sm.exe           0000000004C9045E  Unknown               Unknown  Unknown
1225: e3sm.exe           000000000454DCB0  Unknown               Unknown  Unknown
1225: e3sm.exe           00000000019A3BD5  clubb_intr_mp_clu        1580  clubb_intr.F90
1225: e3sm.exe           000000000061B734  physpkg_mp_tphysb        2483  physpkg.F90
1225: e3sm.exe           0000000000613D92  physpkg_mp_phys_r        1034  physpkg.F90
1225: e3sm.exe           00000000004F43B7  cam_comp_mp_cam_r         250  cam_comp.F90
1225: e3sm.exe           00000000004E93DF  atm_comp_mct_mp_a         341  atm_comp_mct.F90
1225: e3sm.exe           000000000042C82F  component_mod_mp_         267  component_mod.F90
1225: e3sm.exe           00000000004208BD  cime_comp_mod_mp_        1959  cime_comp_mod.F90
1225: e3sm.exe           000000000042969C  MAIN__                     92  cime_driver.F90

And, line 1580 of clubb_intr.F90 does not have any division, so this must be something weird.

[rljacob]

So only fails with debugging and only above a certain number of nodes?

[ndkeen]

Yes, and, sigh, it doesn't always fail. I tried it again and it passed. Cori down today.

[singhbalwinder]

Thanks @ndkeen for running these tests to narrow down the issue. If it is not reproducible, it makes it harder to track. Generally errors like these occur due to memory issues or it can also be due to some node issue. The line in the first error is deallocating a variable:
https://github.com/E3SM-Project/E3SM/blob/ae34b6121f2cc0692414b1a3e0d079cba2b1d476/components/cam/src/physics/rrtmg/rrtmg_state.F90#L236

From the code it looks like pointer rstate is pointed to an allocated variable and it is deallocated in the end in rrtmg/radiation.F90. It looks like a legitimate code. I will try to find more about it once Cori is back.

[oksanaguba]

The error looks similar to what i had in homme due to some race condition. So i took a look at rrtmg_state. I saw no threading regions, so, this is not relevant to my issues. But i have a question about using deallocate and nullify together: from googling, it seems that deallocate (if allocate was called on the same variable) will do both, free memory and disassociate the pointer. Could then call to nullify cause an error?

[singhbalwinder]

Thanks @oksanaguba. In that case a deallocate should suffice. From my reading of the code, the intention here is to deallocate space as well as nullify the pointer (a deallocate would do both). What puzzles me is that the error occurs when we deallocate space with a error message allocatable array or pointer is not allocated, it is not when we nullify it.

I read online and found an example which is very similar to the given code. Following is from the web page: http://www.personal.psu.edu/jhm/f90/statements/nullify.html

"Even though you could cause yourself problems through the careless use of the nullify statement, there are times you absolutely need to use it. The nullify statement is necessary when trying to deallocate pointer arrays that were not created through the use of an allocate statement. For example, in the next few lines of code an allocatable array called green is created and then the pointer p2 is set to point at this array. Later, when an attempt is made to deallocate p2, the computer will actually try to deallocate the array green. In the case of our compiler, this results in an error message, due to the indirect attempt at deallocation.
```program wrong_array
implicit none
real, allocatable :: green(:,:)
real, pointer, dimension(:,:) :: p2
allocate green(6,7)
P2 => green
deallocate (p2)

To prevent the problems that this can cause, replace the DEALLOCATE statement with

    nullify (p2)

`` " From the above, it seems like we should just usenullify` but then the space pointed to by the pointer is not deallocated. In rrtmg/radiation.F90, space is allocated by line:
https://github.com/E3SM-Project/E3SM/blob/ae34b6121f2cc0692414b1a3e0d079cba2b1d476/components/cam/src/physics/rrtmg/radiation.F90#L1052

That is, space is allocated and a pointer is pointed to that space.

[ndkeen]

I also ran a set of tests on edison:

SMS_D_Ln1.ne30_ne30.FC5AV1C-L.edison_gnu.20180710_150808_e0jpx6               fail
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.edison_gnu7.20180710_150808_e0jpx6              fail
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel.20180710_150808_e0jpx6             pass
SMS_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel18.20180710_150808_e0jpx6           fail   (div-by-zero)
SMS_Ln1.ne30_ne30.FC5AV1C-L.edison_intel.20180710_150808_e0jpx6               pass  

[worleyph]

For what its worth, the failures on Titan when using the Intel compiler and DEBUG=TRUE are in the routine derived_phys (in components/cam/src/dynamics/se/dp_coupling.F90), called during phase 2 of the atmosphere initialization. The code in which the failures occur is:

do lchnk = begchunk,endchunk
   ncol = get_ncols_p(lchnk)
   do k=1,nlev
      do i=1,ncol
         phys_state(lchnk)%pint(i,k)=hyai(k)*ps0+hybi(k)*phys_state(lchnk)%ps(i)
         phys_state(lchnk)%pmid(i,k)=hyam(k)*ps0+hybm(k)*phys_state(lchnk)%ps(i)
      end do
      call shr_vmath_log(phys_state(lchnk)%pint(1:ncol,k),phys_state(lchnk)%lnpint(1:ncol,k),ncol)
      call shr_vmath_log(phys_state(lchnk)%pmid(1:ncol,k),phys_state(lchnk)%lnpmid(1:ncol,k),ncol)
   end do
 ...

(first chunk for each process, and all processes appear to by dying in this section of the code).

I assume that the failure is in shr_vmath_log, and I will try to verify that next. This appears to be different than the deallocate/nullify error discussed above.

[worleyph]

Modifying shr_vmath_log (commenting out vdln() and calling log() instead):

 #if (defined CPRINTEL)
 !pw   call vdln(n, X, Y)
 !pw++
    Y = log(X)
 !pw--
    return
 #endif

eliminated the failure and the job completed one day of simulation successfully. Note that I did not run the test SMS_D_Ln1.ne30_ne30.FC5AV1C-L, but rather the underlying case:

 --res ne30_ne30 --compset FC5AV1C-L --machine titan --compiler intel

with DEBUG set to TRUE in env_build.xml.

I have yet to look at the values in the arguments to vdln. I will try to get to that tomorrow.

[ndkeen]

Thanks Pat. Sounds like a different issue.

I also tried fewer MPI's and forcing 1 thread on edison:

SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_gnu       pass
SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_gnu7      pass 
SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel    pass 
SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel18   fail 

The fail for intel18 does look to be the same as the error that I see with intel18 and the default PE layout:

471:  (seq_timemgr_clockInit)  WARNING: Stop time too short, not all components will 
471:  be advanced and restarts won't be written
471: forrtl: error (73): floating divide by zero
471: Image              PC                Routine            Line        Source             
471: e3sm.exe           000000000B551F0E  Unknown               Unknown  Unknown
471: e3sm.exe           000000000AE10470  Unknown               Unknown  Unknown
471: e3sm.exe           000000000B60E9F6  Unknown               Unknown  Unknown
471: e3sm.exe           000000000228B27A  coordinate_system         386  coordinate_systems_mod.F90
471: e3sm.exe           000000000228B982  coordinate_system         526  coordinate_systems_mod.F90
471: e3sm.exe           000000000228B9EF  coordinate_system         539  coordinate_systems_mod.F90
471: e3sm.exe           00000000022A7C32  cube_mod_mp_coord         158  cube_mod.F90
471: e3sm.exe           00000000022A79FD  cube_mod_mp_cube_         128  cube_mod.F90
471: e3sm.exe           000000000321B0B1  prim_driver_base_         407  prim_driver_base.F90
471: e3sm.exe           00000000024628D7  dyn_comp_mp_dyn_i         153  dyn_comp.F90
471: e3sm.exe           0000000000A65CE9  inital_mp_cam_ini          31  inital.F90
471: e3sm.exe           0000000000819F50  cam_comp_mp_cam_i         159  cam_comp.F90
471: e3sm.exe           00000000007E7284  atm_comp_mct_mp_a         260  atm_comp_mct.F90
471: e3sm.exe           0000000000456215  component_mod_mp_         267  component_mod.F90
471: e3sm.exe           000000000041C142  cime_comp_mod_mp_        1175  cime_comp_mod.F90
471: e3sm.exe           000000000044C083  MAIN__                     92  cime_driver.F90
471: e3sm.exe           000000000040A80E  Unknown               Unknown  Unknown

Also note that the intel18 version I'm using on edison is 18.0.2.199, which is the latest. On Cori, the intel18 we use is 18.0.1.163.

[singhbalwinder]

Thanks @worleyph and @ndk. Would you please check if the SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel18 fail is a failure in radiation or clubb? Also, is it reproducible?

[worleyph]

I checked the values being sent to vdln() (or log() ). All processes are dying the first time that vdln() is called from dervied_phys in d_p_coupling, and all processes are computing log() for the same values:

 ncol copies of 10.0000003197544 .

I don't see anything wrong with the input (fwiw). This looks more like an MKL issue on Titan than a a code issue?

[singhbalwinder]

I also must add that we saw this issue with multiple compiler versions from Intel 15 to intel 18 (thanks to @sarats) on Titan. Therefore MKL has this issue with all the intel compiler versions that we tried. It would be nice to produce a small program which replicates this issue to get some guidance from Intel folks. But, I am not sure if it worth our time as Intel on Titan is not officially supported by E3SM.

[worleyph]

@singhbalwinder , I have a reproducer (10 line code). (Yay me). I'll clean it up and submit it to the OLCF some time in the near future. I want to figure out which of the debug flags is important, since the reproducer does not fail when compiled with the defaults (same as we see with E3SM).

[sarats]

@worleyph Nice debugging. Can you send me the reproducer also when it is ready? I was about to write my small test and saw your message in time ;)

[singhbalwinder]

You are awesome @worleyph ! The default debug flags on Titan are: -O0 -g -check uninit -check bounds -check pointers -fpe0 -check noarg_temp_created. I tested by removing fpe0 and it still failed, so it must be one of the -check uninit or -check pointers as the error if floating overflow. It could also be a combination of lower optimizations (O0) and a particular flag. With your 10 line reproducer, I think it will be mch easier to find that out.

[worleyph]

Simple enough to put in-line:

 program vdln_test
   real*8 x(12), y(12)
   integer cnt, i

   cnt = 12
   do i=1,cnt
      x(i) = 10.0000003197544
   enddo

   call vdln(cnt,x,y)
   write(6,*) y
 end

Works when compiled as

 ftn vdln_test.F90 -mkl=cluster

and fails when compiled with

 ftn vdln_test.F90 -mkl=cluster -convert big_endian \
                              -assume byterecl -ftz -traceback \
                              -assume realloc_lhs -fp-model source \
                              -O0 -g -check uninit -check bounds \
                              -check pointers -fpe0 -check noarg_temp_created -free

This is with

 source /opt/modules/default/init/csh
 module load python/2.7.9
 module unload subversion
 module load subversion/1.9.3
 module unload cmake
 module load cmake3/3.6.0
 module rm PrgEnv-pgi PrgEnv-cray PrgEnv-gnu PrgEnv-pathscale
 module load PrgEnv-intel
 module rm intel cray-libsci cray-mpich atp
 module load intel/18.0.0.128 cray-mpich/7.6.3 atp/2.1.1
 module rm cray-netcdf cray-netcdf-hdf5parallel
 module load cray-netcdf/4.4.1.1.3 cray-parallel-netcdf/1.8.1.3

[worleyph]

Fun Fact: the failure occurs if only specify -fpe0, BUT also requires that the vector length is >= 10. For <10 it works fine even with -fpe0. I'll submit the bug report in a few minutes and cc @sarats and @singhbalwinder .

[ndkeen]

The div-by-zero failure above was with intel18 on edison and is likely the same as this issue https://github.com/E3SM-Project/E3SM/issues/2380. On edison, we use the latest version (18.0.2.199). I don't think it will fail with 18.0.1.163. It will probably also pass when I slightly adjust the flags (as in go from fp-model consistent to fp-model strict -- which I'm trying now).

I'm also trying the test again on cori, but if it really is an intermittent failure...

[ndkeen]

I retried the test that failed with intel 18.0.2.199 and used -fp-model strict instead of -fp-model consistent. It passed. SMS_P675x1_D_Ln1.ne30_ne30.FC5AV1C-L.edison_intel18. So I think this version of Intel18 has a particular problem and is unrelated to the other issues. Which are apparently not always failing.

[ndkeen]

Running this again with master from Nov 6th and the test completes. Closing.

Referencing this issue though:
https://github.com/E3SM-Project/E3SM/issues/3142