Merge lp:~albertog/siesta/4.0-json-time into lp:siesta/4.0

[Alberto Garcia]

When using the tree-timer, a 'time.json' file in JSON format is written.
This file can be used by third-party scripts to process timing data.

Also, add a new intermediate timing section for 'siesta_analysis'.

[Alberto Garcia (albertog)]

I forgot to add that this has been prompted by the need to set up a benchmarking workflow in AiiDA. The Siesta plugin now processes the timing information in the time.json file.

[Nick Papior (nickpapior)]

I have made a merge request that tries to solve some of the things I have remarked below.

Note they are comments/remarks. I however think the logic is easier by not having two optional arguments.

[Alberto Garcia (albertog)]

Dear Nick,

Thank you for reviewing this.
My comments:

— I did not want to introduce another dependency for m_io. This write operation is very localized in time, so there is no need to reserve
a unit in the way of m_io.
- My json schema is not perfect: the “info nodes: time, calls, and %, are logically also children of the section objects, but conceptually different (they are “leaf info” instead of tree branches. So with a view to a future scripting capability of the json file, I put the “_” in front to clearly mark them as different. This is obviously not fool-proof.
- I agree that we do not need two different optional arguments.

Let me know if you agree, and I will just merge the interface simplification from your changes.

  Best regards,

  Alberto

> On 19 Feb 2018, at 09:21, Nick Papior <email address hidden> wrote:
>
> I have made a merge request that tries to solve some of the things I have remarked below.
>
> Note they are comments/remarks. I however think the logic is easier by not having two optional arguments.
>
> Diff comments:
>
>>
>> === modified file 'Src/timer_tree.f90'
>> --- Src/timer_tree.f90 2016-01-25 16:00:16 +0000
>> +++ Src/timer_tree.f90 2018-02-15 15:48:27 +0000
>> @@ -266,31 +269,71 @@
>> enddo
>> p%data%totTime = globaltime + 1.0e-6_dp
>>
>> + json_output = .true.
>> + call get_unit_number(js_lun)
>> + open(unit=js_lun,file="time.json",form="formatted", &
>> + action="write",position="rewind")
>> +
>> write(*,"(/,a20,T30,a6,a12,a8)") "Section","Calls","Walltime","%"
>> - call walk_tree(p,0)
>>
>> + write(js_lun,*) '{'
>> + call walk_tree(p,0,json=json_output,js_lun=js_lun)
>> + write(js_lun,*) '}'
>> + if (json_output) close(js_lun)
>> +
>> end subroutine timer_report_global
>>
>> !------------------------------------------------
>> - recursive subroutine walk_tree(p,level,maxlevel)
>> + recursive subroutine walk_tree(p,level,maxlevel,json,js_lun)
>> type(section_t), intent(in),target :: p
>> integer, intent(in) :: level
>> integer, intent(in), optional:: maxlevel
>> + logical, intent(in), optional:: json
>> + integer, intent(in), optional:: js_lun
>>
>> integer :: i
>> - character(len=40) fmtstr
>> + character(len=40) fmtstr, fmt_json, fmt_json_head
>> + logical :: json_output
>>
>> + json_output = .false.
>> + if (present(json)) then
>> + json_output = json
>> + if (.not. present(js_lun)) then
>> + call die("Need a js_lun for json timer output")
>> + endif
>> + endif
>> if (present(maxlevel)) then
>> if (level > maxlevel) RETURN
>> endif
>> pd => p%data
>> write(fmtstr,"(a,i0,a1,a)") "(", level+1, "x", ",a20,T30,i6,f12.3,f8.2)"
>> +
>> write(*,fmtstr) pd%name, pd%nCalls, &
>> pd%totTime, 100*pd%totTime/globaltime
>> + if (json_output) then
>> + write(fmt_json,"(a,i0,a1,a)") "(",2*level+1,"x",",a,i0,a,f12.3,a,f8.2)"
>> + write(fmt_json_head,"(a,i0,a)") "(", 2*level+1, "x,a)"
>> + write(js_lun,fmt=fmt_json,advance="no") &
>> + '"' // trim(pd%name) // '": { "_calls": ', pd%nCalls, &
>> ...

[Nick Papior (nickpapior)]

Dear Alberto,

m_io: no worries. I wouldn't mind having that dependency, but your call.
tree vs branch: I see, perhaps we could mark them with "leaf_calls" which clarifies this?

Agreed! ;)

review: Approve

[lp:~albertog/siesta/4.0-json-time]

559. By Alberto Garcia on 2018-02-19

Use only the presence of json unit as signal to dump JSON

(Thanks to Nick Papior)

We keep the get_unit_number internal routine for now, to avoid
an extra dependency on m_io.

[Nick Papior (nickpapior)]

@Alberto, should I merge in this branch, or will you?

[Alberto Garcia (albertog)]

I will merge it shortly.

----- El 20 de Feb 2018, a las 21:15, Nick Rubner Papior <email address hidden> escribió:

| @Alberto, should I merge in this branch, or will you?
| --
| https://code.launchpad.net/~albertog/siesta/4.0-json-time/+merge/337797
| You are the owner of lp:~albertog/siesta/4.0-json-time.

=== modified file 'Docs/siesta.tex'
--- Docs/siesta.tex	2017-12-28 13:00:52 +0000
+++ Docs/siesta.tex	2018-02-19 13:31:01 +0000
@@ -6595,7 +6595,12 @@
 \index{UseTreeTimer@{\bf UseTreeTimer}}
 
 Enable an experimental timer which is based on wall time on the master
-node and is aware of the tree-structure of the timed sections.
+node and is aware of the tree-structure of the timed sections. At the
+end of the program, a report is generated in the output file, and a
+{\tt time.json} file in JSON format is also
+written. \index{JSON timing report@{\bf JSON timing report}}
+This file can be
+used by third-party scripts to process timing data.
 
 {\it Default value:} {\tt .false.}
 
 
=== modified file 'Src/siesta_analysis.F'
--- Src/siesta_analysis.F	2017-10-04 09:48:27 +0000
+++ Src/siesta_analysis.F	2018-02-19 13:31:01 +0000
@@ -94,6 +94,8 @@
          endif
       endif
 
+      call timer( 'siesta_analysis', 1 )
+      
 !     All the comments below assume that this compatibility option
 !     is not used.
 !     Note also that full compatibility cannot be guaranteed
@@ -456,6 +458,8 @@
 !   -- Set xa to xa_last at the top of this file. Write any "next iter" coordinate file
 !      in 'siesta_move'
 
+      call timer( 'siesta_analysis', 2 )
+
 !--------------------------------------------------------------------------- END
       END subroutine siesta_analysis
       END module m_siesta_analysis
 
=== modified file 'Src/timer_tree.f90'
--- Src/timer_tree.f90	2016-01-25 16:00:16 +0000
+++ Src/timer_tree.f90	2018-02-19 13:31:01 +0000
@@ -218,9 +218,10 @@
   end subroutine timer_all_off
 
   !------------------------------------------------
-  subroutine timer_report(secname)
+  subroutine timer_report(secname,file_unit)
     character(len=*), optional    :: secname
-
+    integer, intent(in), optional :: file_unit
+    
     integer :: i, loc
     logical :: full
 
@@ -253,7 +254,7 @@
   !------------------------------------------------
   subroutine timer_report_global()
 
-    integer :: i
+    integer :: i, js_lun
     type(times_t), pointer :: qd
 
     p => global_section
@@ -266,31 +267,68 @@
     enddo
     p%data%totTime = globaltime + 1.0e-6_dp
 
+    ! Open JSON
+    call get_unit_number(js_lun)
+    open(unit=js_lun, file="time.json", form="formatted", &
+        action="write",position="rewind")
+    
     write(*,"(/,a20,T30,a6,a12,a8)") "Section","Calls","Walltime","%"
-    call walk_tree(p,0)
-
+    ! Due to border logic we need this top-level wrapping
+    write(js_lun,"(a)") "{"
+    call walk_tree(p,0, js_lun=js_lun)
+    write(js_lun,"(a)") "}"
+    
+    close(js_lun)
+    
   end subroutine timer_report_global
 
   !------------------------------------------------
-  recursive subroutine walk_tree(p,level,maxlevel)
+  recursive subroutine walk_tree(p,level,maxlevel,js_lun)
     type(section_t), intent(in),target  :: p
     integer, intent(in)          :: level
     integer, intent(in), optional:: maxlevel
+    integer, intent(in), optional:: js_lun
 
     integer :: i
-    character(len=40) fmtstr
+    character(len=64) fmtstr, fmt_json, fmt_json_head
+    logical :: json_output
 
+    ! Determine whether we should output JSON
+    ! If the unit is there, we output to JSON as well
+    json_output = present(js_lun)
+    
     if (present(maxlevel)) then
        if (level > maxlevel) RETURN
-    endif
+    end if
+
     pd => p%data
     write(fmtstr,"(a,i0,a1,a)") "(", level+1, "x", ",a20,T30,i6,f12.3,f8.2)"
-    write(*,fmtstr) pd%name, pd%nCalls,  &
-                    pd%totTime, 100*pd%totTime/globaltime
+    
+    write(*,fmtstr) pd%name, pd%nCalls, pd%totTime, 100*pd%totTime/globaltime
+    if (json_output) then
+       write(fmt_json,"(a,i0,a1,a)") "(",2*level+1,"x",",a,i0,a,f12.3,a,f8.2)"
+       write(fmt_json_head,"(a,i0,a)") "(", 2*level+1, "x,a)"
+       write(js_lun,fmt=fmt_json,advance="no") &
+           '"' // trim(pd%name) // '": { "_calls": ', pd%nCalls,   &
+                                      ', "_time": ', pd%totTime,   &
+                                      ', "_%": ', 100*pd%totTime/globaltime
+    end if
     if (p%nchildren /= 0) then
+       if (json_output) write(js_lun,"(a)") ","
        do i=1,p%nchildren
-          call walk_tree(p%child(i),level+1,maxlevel)
+          call walk_tree(p%child(i),level+1,maxlevel, js_lun)
+          if (json_output) then
+             if (i < p%nchildren) then
+                write(js_lun,fmt="(a)") ','
+             else
+                write(js_lun,*)  ! just new line
+             endif
+          endif
        enddo
+       ! End the parent section with an indented '}'
+       if (json_output) write(js_lun,fmt=fmt_json_head,advance="no") "}"
+    else
+       if (json_output) write(js_lun,fmt="(a)",advance="no") "}"
     endif
 
   end subroutine walk_tree
@@ -353,4 +391,18 @@
     endif
   end subroutine current_time
 
+subroutine get_unit_number(lun)
+integer, intent(out) :: lun
+
+logical :: used
+integer :: iostat
+
+do lun= 10, 99
+   inquire(unit=lun, opened=used, iostat=iostat)
+   if (iostat .ne. 0) used = .true.
+   if (.not. used) return
+enddo
+call die("Cannot get unit for timer output")
+end subroutine get_unit_number
+
 end module m_timer_tree
 
=== modified file 'version.info'
--- version.info	2018-02-19 08:15:36 +0000
+++ version.info	2018-02-19 13:31:01 +0000
@@ -1,1 +1,7 @@
+<<<<<<< TREE
 siesta-4.0--557
+=======
+siesta-4.0--555--json-time-4
+
+
+>>>>>>> MERGE-SOURCE