Feature/cesm timing

[dgergel]

• closes #xxx
• tests passed
• new tests added
• science test figures
• ran uncrustify prior to final commit
• ReleaseNotes entry

See #743 for discussion of what this PR addresses (in part).

[bartnijssen]

I forget how this works. Are debug() statements always written out or only when we specify a certain logging level?

[dgergel]

Not always. Only when we specify a certain logging level, and I believe compiling with the debug flag for an RI case does the same thing, even though we can't do that for an RBR case.

[bartnijssen]

Why do we not have to initialize timers? If that is done as part of timer_start(), then we can also remove timer_init() from:

• vic/drivers/shared_all/include/vic_driver_shared_all.h
• vic/drivers/shared_all/src/timing.c
• tests/unit/shared/test_timing.py (vic_lib.timer_init(timer))

[bartnijssen]

Actually timer_init() is called from timer_start(), so you do not have to call it separately, but you cannot delete it from the other files as I suggest above, so this should be OK.

[bartnijssen]

We could combine timer_init() and timer_start(), but just leave as is for now.

[jhamman]

Just to be clear, the reason we have separate timer_init and timer_start functions is for the CESM driver case where the vic_cesm_run function needs to "continue" a previously initialized timer. I don't think the image driver has a use for the separate functions. And yes, timer_start = timer_init + timer_continue.

[jhamman]

I think we want these to stay as separate functions. Mostly so we can initialize the vic_run timer in vic_init. I used this exact functionality in my last commit.

[bartnijssen]

What would be the use case of running timer_init() without ever calling a timer_start()? Keep in mind that every timer_start() already includes a call to timer_init()?

[dgergel]

@jhamman @bartnijssen the timing tables look good now (for what we're changing in this PR). I'll fix the secs/day columns in a separate PR. For reference:

------------------------------ VIC TIMING PROFILE ------------------------------

  Date                      : Fri Sep  1 18:49:29 2017
  Compiler                  : icc (Intel(R) C++ gcc 4.3 mode)
  Machine                   : r24i4n1
  VIC User                  : gergel
  VIC Version               : unset
  VIC GIT Version           : 5.0.1 February 1, 2017
  VIC_DRIVER                : CESM

  Global Param File         : vic.globalconfig.txt
  Domain File               : /p/work2/projects/rasm/inputdata/share/domains/domain.lnd.wr50a_ar9v4.100920.nc
  Start Date                : 1948-09-01-00000
  Stop Date                 : 0000-00-00
  Nrecs                     : 1
  Model Timestep (seconds)  : 3600
  Snow Timestep (seconds)   : 3600
  Runoff Timestep (seconds) : 3600
  Atmos Timestep (seconds)  : 3600

  MPI Processes             : 64
  OPENMP Threads            : 1
  Total pes active          : 64
  pes per node              : 72

  Overall Metrics
  ---------------
    Model Cost       : 288149 pe-hrs/simulated_year
    Model Throughput : 0.00533057 simulated_years/day

  Timing Table:
|------------|----------------------|----------------------|----------------------|----------------------|
| Timer      | Wall Time (secs)     | CPU Time (secs)      | Wall Time (secs/day) | CPU Time (secs/day)  |
|------------|----------------------|----------------------|----------------------|----------------------|
| Init Time  |              1.68781 |                 0.52 |              40.5075 |                12.48 |
| Run Time   |              1848.57 |              1846.94 |              44365.8 |              44326.6 |
| Final Time |            0.0124612 |                 0.01 |             0.299068 |                 0.24 |
| Total Time |              1850.27 |              1847.47 |              44406.6 |              44339.3 |
|------------|----------------------|----------------------|----------------------|----------------------|
| Force Time |             0.148592 |                 0.18 |               3.5662 |                 4.32 |
| Write Time |              470.665 |               470.31 |              11295.9 |              11287.4 |
|------------|----------------------|----------------------|----------------------|----------------------|


------------------------------ END VIC TIMING PROFILE ------------------------------