Index: NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/lib_mpp.F90
===================================================================
--- NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/lib_mpp.F90	(revision 10170)
+++ NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/lib_mpp.F90	(revision 10172)
@@ -170,5 +170,8 @@
    INTEGER, PUBLIC                               ::   n_sequence = 0               !: # of communicated arrays
    LOGICAL                                       ::   l_comm_report_done = .false. !: print report only once
-
+   
+   ! timing summary report
+   REAL(wp), PUBLIC ::  waiting_time = 0._wp, compute_time = 0._wp, elapsed_time = 0._wp
+   
    REAL(wp), DIMENSION(:), ALLOCATABLE, SAVE ::   tampon   ! buffer in case of bsend
 
@@ -1609,4 +1612,26 @@
       !
    END SUBROUTINE mpp_lnk_2d_icb
+
+   
+   SUBROUTINE tic_tac (l_tic)
+
+    LOGICAL, INTENT(IN) :: l_tic
+    REAL(wp), SAVE :: tic_wt, tic_ct = 0._wp
+
+    IF( ncom_stp <= nit000 ) RETURN
+    IF( ncom_stp == nitend ) RETURN
+    
+#if defined key_mpp_mpi
+    IF ( l_tic ) THEN
+       tic_wt = MPI_Wtime()                                                        ! start count tic->tac (waiting time)
+       IF ( tic_ct > 0.0_wp ) compute_time = compute_time + MPI_Wtime() - tic_ct   ! cumulate count tac->tic
+    ELSE
+       waiting_time = waiting_time + MPI_Wtime() - tic_wt                          ! cumulate count tic->tac
+       tic_ct = MPI_Wtime()                                                        ! start count tac->tic (waiting time)
+    ENDIF
+#endif
+    
+   END SUBROUTINE tic_tac
+
    
 #else
Index: NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_lnk_generic.h90
===================================================================
--- NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_lnk_generic.h90	(revision 10170)
+++ NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_lnk_generic.h90	(revision 10172)
@@ -205,4 +205,6 @@
       ENDIF
       !
+      IF( ln_timing ) CALL tic_tac(.TRUE.)
+      !
       SELECT CASE ( nbondi )
       CASE ( -1 )
@@ -223,4 +225,7 @@
       END SELECT
       !
+      IF( ln_timing ) CALL tic_tac(.FALSE.)
+      !
+      !
       !                           ! Write Dirichlet lateral conditions
       iihom = nlci-nn_hls
@@ -281,4 +286,6 @@
       imigr = nn_hls * jpi * ipk * ipl * ipf
       !
+      IF( ln_timing ) CALL tic_tac(.TRUE.)
+      ! 
       SELECT CASE ( nbondj )
       CASE ( -1 )
@@ -299,4 +306,5 @@
       END SELECT
       !
+      IF( ln_timing ) CALL tic_tac(.FALSE.)
       !                           ! Write Dirichlet lateral conditions
       ijhom = nlcj-nn_hls
Index: NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_nfd_generic.h90
===================================================================
--- NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_nfd_generic.h90	(revision 10170)
+++ NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/LBC/mpp_nfd_generic.h90	(revision 10172)
@@ -116,4 +116,6 @@
             END DO
          END DO
+         !
+         IF( ln_timing ) CALL tic_tac(.TRUE.)
          !
          DO jr = 1, nsndto
@@ -167,4 +169,7 @@
             END DO
          ENDIF
+         !
+         IF( ln_timing ) CALL tic_tac(.FALSE.)
+         !
          DO jf = 1, ipf
             CALL lbc_nfd_nogather( ztabl(:,:,:,:,jf), ztabr(:,:,:,:,jf), cd_nat LBC_ARG, psgn LBC_ARG )   ! North fold boundary condition
@@ -195,6 +200,10 @@
          IF ( jpni*jpnj /= jpnij ) ztab(:,:,:,:,:)=0._wp
          !
+         IF( ln_timing ) CALL tic_tac(.TRUE.)
+         !
          CALL MPI_ALLGATHER( znorthloc  , itaille, MPI_DOUBLE_PRECISION,                &
             &                znorthgloio, itaille, MPI_DOUBLE_PRECISION, ncomm_north, ierr )
+         !
+         IF( ln_timing ) CALL tic_tac(.FALSE.)
          !
          DO jr = 1, ndim_rank_north         ! recover the global north array
Index: NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/nemogcm.F90
===================================================================
--- NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/nemogcm.F90	(revision 10170)
+++ NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/nemogcm.F90	(revision 10172)
@@ -102,4 +102,8 @@
    CHARACTER(lc) ::   cform_aaa="( /, 'AAAAAAAA', / ) "     ! flag for output listing
 
+#if defined key_mpp_mpi
+   INCLUDE 'mpif.h'
+#endif
+
    !!----------------------------------------------------------------------
    !! NEMO/OCE 4.0 , NEMO Consortium (2018)
@@ -184,6 +188,8 @@
          !
          DO WHILE( istp <= nitend .AND. nstop == 0 )
-#if   defined key_mpp_mpi
+#if defined key_mpp_mpi
             ncom_stp = istp
+            IF ( istp == ( nit000 + 1 ) ) elapsed_time = MPI_Wtime()
+            IF ( istp ==         nitend ) elapsed_time = MPI_Wtime() - elapsed_time
 #endif
             CALL stp        ( istp ) 
Index: NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/timing.F90
===================================================================
--- NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/timing.F90	(revision 10170)
+++ NEMO/branches/2018/dev_r10164_HPC09_ESIWACE_PREP_MERGE/src/OCE/timing.F90	(revision 10172)
@@ -38,5 +38,7 @@
    TYPE timer
       CHARACTER(LEN=20)  :: cname
-   	  REAL(wp)  :: t_cpu, t_clock, tsum_cpu, tsum_clock, tmax_cpu, tmax_clock, tmin_cpu, tmin_clock, tsub_cpu, tsub_clock
+      CHARACTER(LEN=20)  :: surname
+      INTEGER :: rank
+      REAL(wp)  :: t_cpu, t_clock, tsum_cpu, tsum_clock, tmax_cpu, tmax_clock, tmin_cpu, tmin_clock, tsub_cpu, tsub_clock
       INTEGER :: ncount, ncount_max, ncount_rate  
       INTEGER :: niter
@@ -49,7 +51,7 @@
    TYPE alltimer
       CHARACTER(LEN=20), DIMENSION(:), POINTER :: cname => NULL()
-   	  REAL(wp), DIMENSION(:), POINTER :: tsum_cpu   => NULL()
-   	  REAL(wp), DIMENSION(:), POINTER :: tsum_clock => NULL()
-   	  INTEGER, DIMENSION(:), POINTER :: niter => NULL()
+      REAL(wp), DIMENSION(:), POINTER :: tsum_cpu   => NULL()
+      REAL(wp), DIMENSION(:), POINTER :: tsum_clock => NULL()
+      INTEGER, DIMENSION(:), POINTER :: niter => NULL()
       TYPE(alltimer), POINTER :: next => NULL()
       TYPE(alltimer), POINTER :: prev => NULL()
@@ -58,4 +60,6 @@
    TYPE(timer), POINTER :: s_timer_root => NULL()
    TYPE(timer), POINTER :: s_timer      => NULL()
+   TYPE(timer), POINTER :: s_timer_old      => NULL()
+
    TYPE(timer), POINTER :: s_wrk        => NULL()
    REAL(wp) :: t_overclock, t_overcpu
@@ -90,14 +94,18 @@
       CHARACTER(len=*), INTENT(in) :: cdinfo
       !
-       
-      ! Create timing structure at first call
-      IF( .NOT. l_initdone ) THEN
-         CALL timing_ini_var(cdinfo)
+       IF(ASSOCIATED(s_timer) ) s_timer_old => s_timer
+       !
+      ! Create timing structure at first call of the routine 
+       CALL timing_ini_var(cdinfo)
+   !   write(*,*) 'after inivar ', s_timer%cname
+
+      ! ici timing_ini_var a soit retrouve s_timer et fait return soit ajoute un maillon
+      ! maintenant on regarde si le call d'avant corrsspond a un parent ou si il est ferme
+      IF( .NOT. s_timer_old%l_tdone ) THEN      
+         s_timer%parent_section => s_timer_old
       ELSE
-         s_timer => s_timer_root
-         DO WHILE( TRIM(s_timer%cname) /= TRIM(cdinfo) ) 
-            IF( ASSOCIATED(s_timer%next) ) s_timer => s_timer%next
-         END DO
-      ENDIF         
+         s_timer%parent_section => NULL()
+      ENDIF    
+
       s_timer%l_tdone = .FALSE.
       s_timer%niter = s_timer%niter + 1
@@ -114,4 +122,6 @@
       CALL SYSTEM_CLOCK(COUNT = s_timer%ncount)
 #endif
+!      write(*,*) 'end of start ', s_timer%cname
+
       !
    END SUBROUTINE timing_start
@@ -127,5 +137,5 @@
       !
       INTEGER  :: ifinal_count, iperiods    
-      REAL(wp) :: zcpu_end, zmpitime
+      REAL(wp) :: zcpu_end, zmpitime,zcpu_raw,zclock_raw
       !
       s_wrk => NULL()
@@ -140,30 +150,38 @@
       CALL CPU_TIME( zcpu_end )
 
-      s_timer => s_timer_root
-      DO WHILE( TRIM(s_timer%cname) /= TRIM(cdinfo) ) 
-         IF( ASSOCIATED(s_timer%next) ) s_timer => s_timer%next
-      END DO
+!!$      IF(associated(s_timer%parent_section))then
+!!$        write(*,*) s_timer%cname,' <-- ', s_timer%parent_section%cname
+!!$      ENDIF  
+
+ !     No need to search ... : s_timer has the last value defined in start
+ !     s_timer => s_timer_root
+ !     DO WHILE( TRIM(s_timer%cname) /= TRIM(cdinfo) ) 
+ !        IF( ASSOCIATED(s_timer%next) ) s_timer => s_timer%next
+ !     END DO
  
       ! CPU time correction
-      s_timer%t_cpu  = zcpu_end - s_timer%t_cpu - t_overcpu - s_timer%tsub_cpu
-  
+      zcpu_raw = zcpu_end - s_timer%t_cpu - t_overcpu ! total time including child
+      s_timer%t_cpu  = zcpu_raw - s_timer%tsub_cpu
+  !    IF(s_timer%cname==trim('lbc_lnk_2d'))  write(*,*) s_timer%tsub_cpu,zcpu_end
+
       ! clock time correction
 #if defined key_mpp_mpi
-      s_timer%t_clock = zmpitime - s_timer%t_clock - t_overclock - s_timer%tsub_clock
+      zclock_raw = zmpitime - s_timer%t_clock - t_overclock ! total time including child
+      s_timer%t_clock = zclock_raw - t_overclock - s_timer%tsub_clock
 #else
       iperiods = ifinal_count - s_timer%ncount
       IF( ifinal_count < s_timer%ncount )  &
-          iperiods = iperiods + s_timer%ncount_max 
-      s_timer%t_clock  = REAL(iperiods) / s_timer%ncount_rate - t_overclock - s_timer%tsub_clock
+         iperiods = iperiods + s_timer%ncount_max 
+         zclock_raw = REAL(iperiods) / s_timer%ncount_rate !- t_overclock   
+         s_timer%t_clock  = zclock_raw - s_timer%tsub_clock
 #endif
+ !     IF(s_timer%cname==trim('lbc_lnk_2d')) write(*,*) zclock_raw , s_timer%tsub_clock
       
       ! Correction of parent section
       IF( .NOT. PRESENT(csection) ) THEN
-         s_wrk => s_timer
-         DO WHILE ( ASSOCIATED(s_wrk%parent_section ) )
-            s_wrk => s_wrk%parent_section
-            s_wrk%tsub_cpu   = s_wrk%tsub_cpu   + s_timer%t_cpu 
-            s_wrk%tsub_clock = s_wrk%tsub_clock + s_timer%t_clock              
-         END DO
+         IF ( ASSOCIATED(s_timer%parent_section ) ) THEN
+            s_timer%parent_section%tsub_cpu   = zcpu_raw   + s_timer%parent_section%tsub_cpu 
+            s_timer%parent_section%tsub_clock = zclock_raw + s_timer%parent_section%tsub_clock             
+         ENDIF
       ENDIF
             
@@ -186,4 +204,10 @@
       s_timer%l_tdone = .TRUE.
       !
+      !
+      ! we come back
+      IF ( ASSOCIATED(s_timer%parent_section ) ) s_timer => s_timer%parent_section
+     
+!      write(*,*) 'end of stop ', s_timer%cname
+
    END SUBROUTINE timing_stop
  
@@ -211,5 +235,5 @@
          WRITE(numtime,*) '                             NEMO team'
          WRITE(numtime,*) '                  Ocean General Circulation Model'
-         WRITE(numtime,*) '                        version 4.0  (2018) '
+         WRITE(numtime,*) '                        version 3.6  (2015) '
          WRITE(numtime,*)
          WRITE(numtime,*) '                        Timing Informations '
@@ -239,4 +263,8 @@
       t_overcpu = t_overcpu - zdum        
       t_overclock = t_overcpu + t_overclock        
+      WRITE(*,*) 't_overcpu ', t_overcpu
+      WRITE(*,*) 't_overclock ', t_overclock
+      t_overcpu = 0.
+      t_overclock = 0.    
 
       ! Timing on date and time
@@ -263,7 +291,11 @@
       TYPE(timer), POINTER :: s_temp
       INTEGER :: idum, iperiods, icode
+      INTEGER :: ji
       LOGICAL :: ll_ord, ll_averep
       CHARACTER(len=120) :: clfmt            
-      
+      REAL(wp), DIMENSION(:), ALLOCATABLE ::   timing_glob
+      REAL(wp) ::   zsypd   ! simulated years per day (Balaji 2017)
+      REAL(wp) ::   zperc
+
       ll_averep = .TRUE.
     
@@ -272,5 +304,9 @@
       t_cpu(2)   = t_cpu(2)    - t_cpu(1)   - t_overcpu
 #if defined key_mpp_mpi
+      WRITE(*,*) 't_overclock ', t_overclock
+      WRITE(*,*) 't_elaps(1) ', t_elaps(1)
+      WRITE(*,*) 'MPI_WTIME() ', MPI_WTIME()
       t_elaps(2) = MPI_WTIME() - t_elaps(1) - t_overclock
+      WRITE(*,*) 't_elaps(2) ', t_elaps(2)
 #else
       CALL SYSTEM_CLOCK(COUNT = nfinal_count)
@@ -340,4 +376,28 @@
       &       ctime(2)(1:2), ctime(2)(3:4), ctime(2)(5:6),   &
       &       czone(1:3),    czone(4:5)
+
+#if defined key_mpp_mpi
+      ALLOCATE(timing_glob(3*jpnij), stat=icode)
+      CALL MPI_GATHER( (/compute_time, waiting_time, elapsed_time/), 3, MPI_DOUBLE_PRECISION,   &
+         &                                              timing_glob, 3, MPI_DOUBLE_PRECISION, 0, MPI_COMM_OCE, icode)
+      IF( narea == 1 ) THEN
+         WRITE(numtime,*) ' '
+         WRITE(numtime,*) ' Report on time spent on waiting MPI messages '
+         WRITE(numtime,*) '    total timing measured between nit000+1 and nitend-1 '
+         WRITE(numtime,*) '    warning: includes restarts writing time if output before nitend... '
+         WRITE(numtime,*) ' '
+         DO ji = 1, jpnij
+            zperc = timing_glob(3*ji-1) + timing_glob(3*ji-2)
+            IF (zperc /= 0. ) zperc = timing_glob(3*ji-1) / zperc * 100.
+            WRITE(numtime,'(A20,F11.6,            A34,I8)') 'Computing time : ',timing_glob(3*ji-2), ' on MPI rank : ', ji
+            WRITE(numtime,'(A20,F11.6,A2, F4.1,A3,A25,I8)') 'Waiting   time : ',timing_glob(3*ji-1)   &
+               &                                                         , ' (',      zperc,' %)',   ' on MPI rank : ', ji
+            zsypd = rn_rdt * REAL(nitend-nit000-1, wp) / (timing_glob(3*ji) * 365.)
+            WRITE(numtime,'(A20,F11.6,A7,F10.3,A2,A15,I8)') 'Total     time : ',timing_glob(3*ji  )   &
+               &                                                         , ' (SYPD: ', zsypd, ')',   ' on MPI rank : ', ji
+         END DO
+      ENDIF
+      DEALLOCATE(timing_glob)
+#endif      
 
       IF( lwriter ) CLOSE(numtime) 
@@ -459,4 +519,5 @@
          sl_timer_ave_root%next => NULL()
          sl_timer_ave_root%prev => NULL()
+         ALLOCATE(sl_timer_ave)
          sl_timer_ave => sl_timer_ave_root            
       ENDIF 
@@ -490,6 +551,4 @@
          s_timer => s_timer%next
       END DO      
-
-         WRITE(*,*) 'ARPDBG: timing: done gathers'
       
       IF( narea == 1 ) THEN    
@@ -514,6 +573,4 @@
             sl_timer_glob => sl_timer_glob%next                                
          END DO
-
-         WRITE(*,*) 'ARPDBG: timing: done computing stats'
       
          ! reorder the averaged list by CPU time      
@@ -567,9 +624,4 @@
       ENDIF
       !
-      DEALLOCATE(sl_timer_glob_root%cname     , &
-                 sl_timer_glob_root%tsum_cpu  , &
-                 sl_timer_glob_root%tsum_clock, &
-                 sl_timer_glob_root%niter)
-      !
       DEALLOCATE(sl_timer_glob_root)
       !                  
@@ -676,14 +728,39 @@
          s_timer => s_timer_root
          !
+         ALLOCATE(s_wrk)
          s_wrk => NULL()
-         
+         !
+         ALLOCATE(s_timer_old)
+         s_timer_old%cname       = cdinfo
+         s_timer_old%t_cpu      = 0._wp
+         s_timer_old%t_clock    = 0._wp
+         s_timer_old%tsum_cpu   = 0._wp
+         s_timer_old%tsum_clock = 0._wp
+         s_timer_old%tmax_cpu   = 0._wp
+         s_timer_old%tmax_clock = 0._wp
+         s_timer_old%tmin_cpu   = 0._wp
+         s_timer_old%tmin_clock = 0._wp
+         s_timer_old%tsub_cpu   = 0._wp
+         s_timer_old%tsub_clock = 0._wp
+         s_timer_old%ncount      = 0
+         s_timer_old%ncount_rate = 0
+         s_timer_old%ncount_max  = 0
+         s_timer_old%niter       = 0
+         s_timer_old%l_tdone  = .TRUE.
+         s_timer_old%next => NULL()
+         s_timer_old%prev => NULL()
+
       ELSE
          s_timer => s_timer_root
          ! case of already existing area (typically inside a loop)
+   !         write(*,*) 'in ini_var for routine : ', cdinfo
          DO WHILE( ASSOCIATED(s_timer) ) 
-            IF( TRIM(s_timer%cname) .EQ. TRIM(cdinfo) ) RETURN
+            IF( TRIM(s_timer%cname) .EQ. TRIM(cdinfo) ) THEN
+ !             write(*,*) 'in ini_var for routine : ', cdinfo,' we return'           
+               RETURN ! cdinfo is already in the chain
+            ENDIF
             s_timer => s_timer%next
          END DO
-         
+
          ! end of the chain
          s_timer => s_timer_root
@@ -691,6 +768,10 @@
             s_timer => s_timer%next
          END DO
-          
-         ALLOCATE(s_timer%next)      
+
+    !     write(*,*) 'after search', s_timer%cname
+         ! cdinfo is not part of the chain so we add it with initialisation          
+          ALLOCATE(s_timer%next)
+    !     write(*,*) 'after allocation of next'
+  
          s_timer%next%cname       = cdinfo
          s_timer%next%t_cpu      = 0._wp
@@ -713,17 +794,7 @@
          s_timer%next%next => NULL()
          s_timer => s_timer%next
-
-         ! are we inside a section
-         s_wrk => s_timer%prev
-         ll_section = .FALSE.
-         DO WHILE( ASSOCIATED(s_wrk) .AND. .NOT. ll_section )
-            IF( .NOT. s_wrk%l_tdone ) THEN
-               ll_section = .TRUE.
-               s_timer%parent_section => s_wrk 
-            ENDIF
-            s_wrk => s_wrk%prev
-         END DO 
-      ENDIF         
-      !
+      ENDIF 
+      !    write(*,*) 'after allocation'
+     !
    END SUBROUTINE timing_ini_var
 
@@ -738,5 +809,5 @@
 !      IF(lwp) WRITE(numout,*) 'timing_reset : instrumented routines for timing'
 !      IF(lwp) WRITE(numout,*) '~~~~~~~~~~~~'
-!      CALL timing_list(s_timer_root)
+      CALL timing_list(s_timer_root)
 !      WRITE(numout,*)
       !
