parPE example: steadystate model - minibatch optimization

This example demonstrates some basic use of the mini-batch optimizer in parPE.

Prerequisites

The prerequisites mention in parpeExampleSteadystateBasic.ipynb also apply to this notebook.

[10]:
import amici
import os
import sys
import numpy as np
import pandas as pd
import matplotlib.pyplot as plt
import h5py
from importlib import reload

# set paths
parpe_source_root = os.path.abspath('../../../')
parpe_build_root = os.path.join(parpe_source_root, 'build')

model_source_dir = f'{parpe_build_root}/examples/parpeamici/steadystate/steadystate_scaled-prefix/src/steadystate_scaled/model_steadystate_scaled'
example_binary_dir = f'{parpe_build_root}/examples/parpeamici/steadystate/'
example_data_dir = f'{parpe_build_root}/examples/parpeamici/steadystate/steadystate_scaled-prefix/src/steadystate_scaled'
optimization_options_py = f'{parpe_source_root}/misc/optimizationOptions.py'

# MPI launcher and options
mpiexec = "mpiexec -n 4 --allow-run-as-root --oversubscribe"

# load parpe module from source tree
sys.path.insert(0, os.path.join(parpe_source_root, 'python'))
import parpe
[11]:
# rebuild example
!cd {parpe_build_root} && make
-- Found Git: /usr/bin/git (found version "2.25.1")
-- Building version parPE-v0.4.3-43-gdc50b-dirty
[  0%] Built target get_version
[ 10%] Built target parpecommon
Scanning dependencies of target parpeoptimization
[ 11%] Building CXX object src/parpeoptimization/CMakeFiles/parpeoptimization.dir/optimizationResultWriter.cpp.o
[ 12%] Linking CXX static library libparpeoptimization-dbg.a
[ 21%] Built target parpeoptimization
[ 25%] Built target parpeloadbalancer
Scanning dependencies of target parpeamici
[ 26%] Building CXX object src/parpeamici/CMakeFiles/parpeamici.dir/optimizationApplication.cpp.o
[ 27%] Linking CXX static library libparpeamici-dbg.a
[ 37%] Built target parpeamici
[ 39%] Built target parpe
[ 45%] Built target unittests_common
[ 50%] Built target unittests_loadbalancer
[ 51%] Linking CXX executable unittests_optimization
[ 58%] Built target unittests_optimization
Setting up virtual environment...
[ 58%] Built target setup_venv
[ 59%] Creating test data using hierarchicalOptimizationTest.py
...
----------------------------------------------------------------------
Ran 3 tests in 0.001s

OK
[ 59%] Built target prepare_test_hierarchical_optimization
[ 60%] Linking CXX executable unittests_amici
[ 67%] Built target unittests_amici
[ 69%] Built target example_loadbalancer
[ 70%] Performing build step for 'steadystate_scaled'
[ 90%] Built target model_steadystate_scaled
[ 94%] Built target simulate_model_steadystate_scaled
[ 96%] Built target model_steadystate_scaled_swig_compilation
[100%] Built target _model_steadystate_scaled
[ 72%] No install step for 'steadystate_scaled'
[ 73%] No test step for 'steadystate_scaled'
[ 74%] Completed 'steadystate_scaled'
[ 81%] Built target steadystate_scaled
[ 82%] Linking CXX executable example_steadystate
[ 84%] Built target example_steadystate
[ 86%] Linking CXX executable example_steadystate_multi
[ 88%] Built target example_steadystate_multi
[ 89%] Linking CXX executable example_steadystate_multi_simulator
[ 92%] Built target example_steadystate_multi_simulator
[ 93%] Linking CXX executable test_steadystate
[100%] Built target test_steadystate
[12]:
# run make test to generated all output files required below
# !cd {parpe_build_root} && make test

Mini-batch optimization

[13]:
hdf5_file_minibatch = f'{example_data_dir}/example_data_minibatch.h5'
!cp {example_data_dir}/example_data.h5 {hdf5FileMinibatch}

# Generic options:
# One optimizer run
!{optimization_options_py} {hdf5_file_minibatch} -s numStarts 1
# Hierarchical optimization not yet supported with minibatch (#118)
!{optimization_options_py} {hdf5_file_minibatch} -s hierarchicalOptimization 0
# Do not repeat on failure
!{optimization_options_py} {hdf5_file_minibatch} -s retryOptimization 0

# Mini-batch options:
# Select mini-batch optimizer
!{optimization_options_py} {hdf5_file_minibatch} -s optimizer 10
# Set number of epochs
!{optimization_options_py} {hdf5_file_minibatch} -s minibatch/maxEpochs 40
# Set batch-size
!{optimization_options_py} {hdf5_file_minibatch} -s minibatch/batchSize 2
# Set parameter updating scheme
!{optimization_options_py} {hdf5_file_minibatch} -s minibatch/parameterUpdater Vanilla
# Set learning rate
!{optimization_options_py} {hdf5_file_minibatch} -s minibatch/startLearningRate 1e-5
!{optimization_options_py} {hdf5_file_minibatch} -s minibatch/endLearningRate 1e-5

# Print settings
!{optimization_options_py} {hdf5_file_minibatch}
                hierarchicalOptimization            0
                               numStarts            1
                               optimizer           10
                       retryOptimization            0
                ceres/max_num_iterations          100
                         fmincon/GradObj        b'on'
                     fmincon/MaxFunEvals   10000000.0
                         fmincon/MaxIter          100
                          fmincon/TolFun            0
                            fmincon/TolX        1e-08
                       fmincon/algorithm b'interior-point'
                         fmincon/display      b'iter'
                   ipopt/acceptable_iter            1
         ipopt/acceptable_obj_change_tol        1e-05
                    ipopt/acceptable_tol        1e-05
             ipopt/hessian_approximation b'limited-memory'
        ipopt/limited_memory_update_type      b'bfgs'
                          ipopt/max_iter           20
                               ipopt/tol        1e-09
   ipopt/watchdog_shortened_iter_trigger            0
                     minibatch/batchSize            2
               minibatch/endLearningRate        1e-05
                     minibatch/maxEpochs           40
              minibatch/parameterUpdater   b'Vanilla'
             minibatch/startLearningRate        1e-05
                          toms611/mxfcal  100000000.0
[14]:
# Optional
!{parpe_source_root}/misc/selectStartingPoints.py {hdf5_file_minibatch} 9 # select starting point
Creating starting point backup in /optimizationOptions/randomStartsBackup
Selecting starting points [9]
[22]:
!PARPE_MAX_SIMULATIONS_PER_PACKAGE=1 PARPE_NO_DEBUG=1 \
    {mpiexec} {example_binary_dir}/example_steadystate_multi \
        --mpi -o deleteme-minibatch/ {hdf5_file_minibatch}
[2020-06-24 18:03:20] [INF] [0:140270737766336/dweindl-ThinkPad-L480] Running with 4 MPI processes.
[2020-06-24 18:03:20] [INF] [0:140270737766336/dweindl-ThinkPad-L480] Reading random initial theta 0 from /optimizationOptions/randomStarts
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e0b1] iter: 0 cost: 3554.69 time_iter: wall: 0.0476933s cpu: 0.0854863s time_optim: wall: 0.0476936s cpu: 0.0854863s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e1b1] iter: 1 cost: 2584.42 time_iter: wall: 0.0437777s cpu: 0.0775371s time_optim: wall: 0.0914716s cpu: 0.163023s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e2b1] iter: 2 cost: 1628.43 time_iter: wall: 0.0415349s cpu: 0.0745043s time_optim: wall: 0.133007s cpu: 0.237528s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e3b1] iter: 3 cost: 1628.3 time_iter: wall: 0.0422477s cpu: 0.0746888s time_optim: wall: 0.175255s cpu: 0.312217s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e4b1] iter: 4 cost: 2584.01 time_iter: wall: 0.0575522s cpu: 0.097932s time_optim: wall: 0.232807s cpu: 0.410149s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e5b1] iter: 5 cost: 2583.87 time_iter: wall: 0.048339s cpu: 0.0843479s time_optim: wall: 0.281147s cpu: 0.494496s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e6b1] iter: 6 cost: 2598.01 time_iter: wall: 0.0445327s cpu: 0.0791551s time_optim: wall: 0.325679s cpu: 0.573652s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e7b1] iter: 7 cost: 2576.16 time_iter: wall: 0.0442095s cpu: 0.078626s time_optim: wall: 0.369889s cpu: 0.652278s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e8b1] iter: 8 cost: 2597.73 time_iter: wall: 0.0499246s cpu: 0.0864627s time_optim: wall: 0.419814s cpu: 0.73874s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e9b1] iter: 9 cost: 2575.88 time_iter: wall: 0.0454407s cpu: 0.0816869s time_optim: wall: 0.465255s cpu: 0.820427s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e10b1] iter: 10 cost: 2583.17 time_iter: wall: 0.0545201s cpu: 0.0869733s time_optim: wall: 0.519775s cpu: 0.907401s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e11b1] iter: 11 cost: 2575.6 time_iter: wall: 0.0554565s cpu: 0.0902942s time_optim: wall: 0.575232s cpu: 0.997695s
[2020-06-24 18:03:20] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e12b1] iter: 12 cost: 1627.08 time_iter: wall: 0.0570406s cpu: 0.090515s time_optim: wall: 0.632273s cpu: 1.08821s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e13b1] iter: 13 cost: 3552.87 time_iter: wall: 0.0568286s cpu: 0.0945186s time_optim: wall: 0.689102s cpu: 1.18273s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e14b1] iter: 14 cost: 2582.62 time_iter: wall: 0.0467445s cpu: 0.082892s time_optim: wall: 0.735847s cpu: 1.26562s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e15b1] iter: 15 cost: 2596.78 time_iter: wall: 0.06091s cpu: 0.0964501s time_optim: wall: 0.796757s cpu: 1.36207s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e16b1] iter: 16 cost: 2596.65 time_iter: wall: 0.0507164s cpu: 0.0857777s time_optim: wall: 0.847473s cpu: 1.44785s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e17b1] iter: 17 cost: 2574.77 time_iter: wall: 0.0572344s cpu: 0.0915431s time_optim: wall: 0.904708s cpu: 1.53939s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e18b1] iter: 18 cost: 2574.63 time_iter: wall: 0.0548787s cpu: 0.0869427s time_optim: wall: 0.959587s cpu: 1.62633s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e19b1] iter: 19 cost: 2581.92 time_iter: wall: 0.0569721s cpu: 0.0896724s time_optim: wall: 1.01656s cpu: 1.71601s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e20b1] iter: 20 cost: 2581.78 time_iter: wall: 0.0576468s cpu: 0.0908332s time_optim: wall: 1.07421s cpu: 1.80684s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e21b1] iter: 21 cost: 2603.39 time_iter: wall: 0.0577943s cpu: 0.0928978s time_optim: wall: 1.132s cpu: 1.89974s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e22b1] iter: 22 cost: 2603.25 time_iter: wall: 0.0454081s cpu: 0.0805325s time_optim: wall: 1.17741s cpu: 1.98027s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e23b1] iter: 23 cost: 2573.93 time_iter: wall: 0.0424495s cpu: 0.0757748s time_optim: wall: 1.21986s cpu: 2.05604s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e24b1] iter: 24 cost: 2581.22 time_iter: wall: 0.0432327s cpu: 0.0768418s time_optim: wall: 1.26309s cpu: 2.13289s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e25b1] iter: 25 cost: 2602.84 time_iter: wall: 0.0578171s cpu: 0.0913525s time_optim: wall: 1.32091s cpu: 2.22424s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e26b1] iter: 26 cost: 3551.05 time_iter: wall: 0.0428939s cpu: 0.0763334s time_optim: wall: 1.3638s cpu: 2.30057s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e27b1] iter: 27 cost: 1625.04 time_iter: wall: 0.0448466s cpu: 0.0784589s time_optim: wall: 1.40865s cpu: 2.37903s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e28b1] iter: 28 cost: 1624.91 time_iter: wall: 0.0442186s cpu: 0.0786546s time_optim: wall: 1.45287s cpu: 2.45769s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e29b1] iter: 29 cost: 2573.11 time_iter: wall: 0.0588466s cpu: 0.0917757s time_optim: wall: 1.51172s cpu: 2.54946s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e30b1] iter: 30 cost: 2594.74 time_iter: wall: 0.0570472s cpu: 0.0894142s time_optim: wall: 1.56876s cpu: 2.63888s
[2020-06-24 18:03:21] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e31b1] iter: 31 cost: 2594.61 time_iter: wall: 0.0437171s cpu: 0.0783228s time_optim: wall: 1.61248s cpu: 2.7172s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e32b1] iter: 32 cost: 1624.37 time_iter: wall: 0.0439255s cpu: 0.0783519s time_optim: wall: 1.65641s cpu: 2.79555s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e33b1] iter: 33 cost: 2572.55 time_iter: wall: 0.0425016s cpu: 0.0756871s time_optim: wall: 1.69891s cpu: 2.87124s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e34b1] iter: 34 cost: 2594.2 time_iter: wall: 0.0439749s cpu: 0.0782568s time_optim: wall: 1.74288s cpu: 2.94949s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e35b1] iter: 35 cost: 1623.97 time_iter: wall: 0.0482329s cpu: 0.08319s time_optim: wall: 1.79112s cpu: 3.03268s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e36b1] iter: 36 cost: 2601.35 time_iter: wall: 0.0563434s cpu: 0.0899884s time_optim: wall: 1.84746s cpu: 3.12267s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e37b1] iter: 37 cost: 2593.79 time_iter: wall: 0.0568368s cpu: 0.0906086s time_optim: wall: 1.9043s cpu: 3.21328s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e38b1] iter: 38 cost: 2593.66 time_iter: wall: 0.0575143s cpu: 0.0902695s time_optim: wall: 1.96181s cpu: 3.30355s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0e39b1] iter: 39 cost: 2579.14 time_iter: wall: 0.0555223s cpu: 0.0883681s time_optim: wall: 2.01733s cpu: 3.39192s
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0] Number of epochs exceeded.
[2020-06-24 18:03:22] [INF] [0:140270251255552/dweindl-ThinkPad-L480] [o0] Optimizer status 1, final llh: 2.586261e+03, time: wall: 2.059439 cpu: 3.479924.
[2020-06-24 18:03:24] [INF] [0:140270737766336/dweindl-ThinkPad-L480] Walltime on master: 4.300712s, CPU time of all processes: 17.190522s
[2020-06-24 18:03:24] [INF] [0:140270737766336/dweindl-ThinkPad-L480] Sent termination signal to workers.
[23]:
filename = 'deleteme-minibatch/_rank00000.h5'
with h5py.File(filename, 'r') as f:
    trajectory = f['/multistarts/0/iterCostFunCost'][:]
for start in range(trajectory.shape[0]):
    plt.plot(trajectory[start])
    plt.gca().set_xlabel("Function evaluation")
    plt.gca().set_ylabel("Cost")
#trajectory
../_images/example_notebooks_parpeExampleSteadystateMinibatch_8_0.png

Compare learning rates

[25]:
learningRates = np.logspace(-2, -5, 4)
for i, learningRate in enumerate(learningRates):
    curInputFile = "example-data-minibatch-rate-%d.h5" % i
    outprefix = "deleteme-minibatch-rate-%d/" % i
    !cp {hdf5FileMinibatch} {curInputFile}
    !{optimizationOptionsPy} {curInputFile} -s minibatch/startLearningRate learningRate
    !{optimizationOptionsPy} {curInputFile} -s minibatch/endLearningRate 1e-5
    !PARPE_MAX_SIMULATIONS_PER_PACKAGE=1 PARPE_NO_DEBUG=1 \
            {mpiexec} {example_binary_dir}/example_steadystate_multi \
                --mpi -o {outprefix} {hdf5FileMinibatch}
[2020-06-24 18:04:11] [INF] [0:140128563488704/dweindl-ThinkPad-L480] Running with 4 MPI processes.
[2020-06-24 18:04:11] [INF] [0:140128563488704/dweindl-ThinkPad-L480] Reading random initial theta 0 from /optimizationOptions/randomStarts
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e0b1] iter: 0 cost: 1628.7 time_iter: wall: 0.0651095s cpu: 0.101819s time_optim: wall: 0.0651098s cpu: 0.101819s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e1b1] iter: 1 cost: 1628.57 time_iter: wall: 0.0477085s cpu: 0.0842107s time_optim: wall: 0.112819s cpu: 0.18603s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e2b1] iter: 2 cost: 2598.55 time_iter: wall: 0.0467025s cpu: 0.081893s time_optim: wall: 0.159521s cpu: 0.267923s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e3b1] iter: 3 cost: 2584.15 time_iter: wall: 0.0488849s cpu: 0.0847768s time_optim: wall: 0.208406s cpu: 0.3527s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e4b1] iter: 4 cost: 2598.28 time_iter: wall: 0.0470017s cpu: 0.0824214s time_optim: wall: 0.255408s cpu: 0.435121s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e5b1] iter: 5 cost: 3553.99 time_iter: wall: 0.0471031s cpu: 0.082031s time_optim: wall: 0.302512s cpu: 0.517152s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e6b1] iter: 6 cost: 2598.01 time_iter: wall: 0.0443932s cpu: 0.0794086s time_optim: wall: 0.346905s cpu: 0.596561s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e7b1] iter: 7 cost: 2597.87 time_iter: wall: 0.0585004s cpu: 0.0935554s time_optim: wall: 0.405406s cpu: 0.690116s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e8b1] iter: 8 cost: 3553.57 time_iter: wall: 0.0474411s cpu: 0.082477s time_optim: wall: 0.452847s cpu: 0.772593s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e9b1] iter: 9 cost: 2583.31 time_iter: wall: 0.0491929s cpu: 0.0852675s time_optim: wall: 0.50204s cpu: 0.857861s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e10b1] iter: 10 cost: 3553.3 time_iter: wall: 0.0506385s cpu: 0.0866106s time_optim: wall: 0.552679s cpu: 0.944471s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e11b1] iter: 11 cost: 2583.04 time_iter: wall: 0.0505453s cpu: 0.0842736s time_optim: wall: 0.603224s cpu: 1.02874s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e12b1] iter: 12 cost: 2597.19 time_iter: wall: 0.0515001s cpu: 0.0877196s time_optim: wall: 0.654725s cpu: 1.11646s
[2020-06-24 18:04:11] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e13b1] iter: 13 cost: 1626.95 time_iter: wall: 0.0516208s cpu: 0.088255s time_optim: wall: 0.706346s cpu: 1.20472s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e14b1] iter: 14 cost: 2575.19 time_iter: wall: 0.0522611s cpu: 0.0872468s time_optim: wall: 0.758607s cpu: 1.29197s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e15b1] iter: 15 cost: 2604.21 time_iter: wall: 0.0539821s cpu: 0.0892329s time_optim: wall: 0.812589s cpu: 1.3812s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e16b1] iter: 16 cost: 2596.65 time_iter: wall: 0.0486306s cpu: 0.0838493s time_optim: wall: 0.86122s cpu: 1.46505s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e17b1] iter: 17 cost: 3552.32 time_iter: wall: 0.0468001s cpu: 0.0833688s time_optim: wall: 0.90802s cpu: 1.54842s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e18b1] iter: 18 cost: 3552.18 time_iter: wall: 0.0461051s cpu: 0.0819807s time_optim: wall: 0.954126s cpu: 1.6304s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e19b1] iter: 19 cost: 3552.04 time_iter: wall: 0.0565551s cpu: 0.0897935s time_optim: wall: 1.01068s cpu: 1.72019s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e20b1] iter: 20 cost: 2596.11 time_iter: wall: 0.0578384s cpu: 0.0915457s time_optim: wall: 1.06852s cpu: 1.81174s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e21b1] iter: 21 cost: 2603.4 time_iter: wall: 0.0575343s cpu: 0.0936316s time_optim: wall: 1.12605s cpu: 1.90537s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e22b1] iter: 22 cost: 1625.73 time_iter: wall: 0.0576452s cpu: 0.0938341s time_optim: wall: 1.1837s cpu: 1.9992s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e23b1] iter: 23 cost: 2595.7 time_iter: wall: 0.0573879s cpu: 0.0921114s time_optim: wall: 1.24109s cpu: 2.09131s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e24b1] iter: 24 cost: 1625.46 time_iter: wall: 0.0561392s cpu: 0.0893061s time_optim: wall: 1.29723s cpu: 2.18062s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e25b1] iter: 25 cost: 2595.43 time_iter: wall: 0.0546376s cpu: 0.0916923s time_optim: wall: 1.35187s cpu: 2.27231s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e26b1] iter: 26 cost: 2602.72 time_iter: wall: 0.0581859s cpu: 0.0912279s time_optim: wall: 1.41005s cpu: 2.36354s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e27b1] iter: 27 cost: 2602.58 time_iter: wall: 0.0470694s cpu: 0.0836855s time_optim: wall: 1.45712s cpu: 2.44723s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e28b1] iter: 28 cost: 2573.25 time_iter: wall: 0.0480904s cpu: 0.0840095s time_optim: wall: 1.50521s cpu: 2.53124s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e29b1] iter: 29 cost: 2602.31 time_iter: wall: 0.0588577s cpu: 0.103163s time_optim: wall: 1.56407s cpu: 2.6344s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e30b1] iter: 30 cost: 2594.75 time_iter: wall: 0.058872s cpu: 0.0957537s time_optim: wall: 1.62294s cpu: 2.73015s
[2020-06-24 18:04:12] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e31b1] iter: 31 cost: 2594.61 time_iter: wall: 0.057997s cpu: 0.0920542s time_optim: wall: 1.68094s cpu: 2.82221s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e32b1] iter: 32 cost: 2572.7 time_iter: wall: 0.0587806s cpu: 0.0933812s time_optim: wall: 1.73972s cpu: 2.91559s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e33b1] iter: 33 cost: 1624.24 time_iter: wall: 0.0493689s cpu: 0.0846965s time_optim: wall: 1.78909s cpu: 3.00028s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e34b1] iter: 34 cost: 1624.11 time_iter: wall: 0.0479775s cpu: 0.0844509s time_optim: wall: 1.83707s cpu: 3.08474s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e35b1] iter: 35 cost: 2594.07 time_iter: wall: 0.0559033s cpu: 0.0929584s time_optim: wall: 1.89297s cpu: 3.17769s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e36b1] iter: 36 cost: 2579.57 time_iter: wall: 0.0611445s cpu: 0.108288s time_optim: wall: 1.95411s cpu: 3.28598s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e37b1] iter: 37 cost: 2593.8 time_iter: wall: 0.0492099s cpu: 0.0865385s time_optim: wall: 2.00332s cpu: 3.37252s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e38b1] iter: 38 cost: 1623.57 time_iter: wall: 0.0489464s cpu: 0.0848573s time_optim: wall: 2.05227s cpu: 3.45738s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0e39b1] iter: 39 cost: 2600.95 time_iter: wall: 0.0451686s cpu: 0.079828s time_optim: wall: 2.09744s cpu: 3.53721s
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0] Number of epochs exceeded.
[2020-06-24 18:04:13] [INF] [0:140128139867904/dweindl-ThinkPad-L480] [o0] Optimizer status 1, final llh: 2.586273e+03, time: wall: 2.148572 cpu: 3.630505.
[2020-06-24 18:04:15] [INF] [0:140128563488704/dweindl-ThinkPad-L480] Walltime on master: 4.318119s, CPU time of all processes: 16.971442s
[2020-06-24 18:04:15] [INF] [0:140128563488704/dweindl-ThinkPad-L480] Sent termination signal to workers.
[2020-06-24 18:04:18] [INF] [0:140040514709440/dweindl-ThinkPad-L480] Running with 4 MPI processes.
[2020-06-24 18:04:18] [INF] [0:140040514709440/dweindl-ThinkPad-L480] Reading random initial theta 0 from /optimizationOptions/randomStarts
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e0b1] iter: 0 cost: 1628.7 time_iter: wall: 0.0620374s cpu: 0.0965123s time_optim: wall: 0.0620377s cpu: 0.0965123s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e1b1] iter: 1 cost: 2606.12 time_iter: wall: 0.0619933s cpu: 0.0968211s time_optim: wall: 0.124031s cpu: 0.193333s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e2b1] iter: 2 cost: 1628.43 time_iter: wall: 0.062497s cpu: 0.0970936s time_optim: wall: 0.186528s cpu: 0.290427s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e3b1] iter: 3 cost: 2584.15 time_iter: wall: 0.0628173s cpu: 0.0975342s time_optim: wall: 0.249346s cpu: 0.387961s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e4b1] iter: 4 cost: 2576.57 time_iter: wall: 0.0630493s cpu: 0.102265s time_optim: wall: 0.312428s cpu: 0.490226s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e5b1] iter: 5 cost: 2598.14 time_iter: wall: 0.0627134s cpu: 0.10023s time_optim: wall: 0.375142s cpu: 0.590456s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e6b1] iter: 6 cost: 2605.44 time_iter: wall: 0.0462647s cpu: 0.0822424s time_optim: wall: 0.421407s cpu: 0.672698s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e7b1] iter: 7 cost: 2576.15 time_iter: wall: 0.0446779s cpu: 0.0798674s time_optim: wall: 0.466085s cpu: 0.752566s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e8b1] iter: 8 cost: 2605.16 time_iter: wall: 0.0459914s cpu: 0.0820788s time_optim: wall: 0.512076s cpu: 0.834645s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e9b1] iter: 9 cost: 2605.03 time_iter: wall: 0.0460034s cpu: 0.0822501s time_optim: wall: 0.55808s cpu: 0.916895s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e10b1] iter: 10 cost: 2583.17 time_iter: wall: 0.0485059s cpu: 0.086197s time_optim: wall: 0.606586s cpu: 1.00309s
[2020-06-24 18:04:18] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e11b1] iter: 11 cost: 2583.03 time_iter: wall: 0.0455353s cpu: 0.0812845s time_optim: wall: 0.652122s cpu: 1.08438s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e12b1] iter: 12 cost: 2575.46 time_iter: wall: 0.0487622s cpu: 0.0848217s time_optim: wall: 0.700884s cpu: 1.1692s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e13b1] iter: 13 cost: 2597.05 time_iter: wall: 0.0459065s cpu: 0.0815944s time_optim: wall: 0.746791s cpu: 1.25079s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e14b1] iter: 14 cost: 2575.18 time_iter: wall: 0.0538032s cpu: 0.0896016s time_optim: wall: 0.800594s cpu: 1.34039s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e15b1] iter: 15 cost: 3552.59 time_iter: wall: 0.0570818s cpu: 0.090847s time_optim: wall: 0.857676s cpu: 1.43124s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e16b1] iter: 16 cost: 2604.07 time_iter: wall: 0.0582828s cpu: 0.0929545s time_optim: wall: 0.915959s cpu: 1.5242s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e17b1] iter: 17 cost: 2603.93 time_iter: wall: 0.0572582s cpu: 0.0936604s time_optim: wall: 0.973218s cpu: 1.61786s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e18b1] iter: 18 cost: 3552.17 time_iter: wall: 0.0604522s cpu: 0.0956316s time_optim: wall: 1.03367s cpu: 1.71349s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e19b1] iter: 19 cost: 2574.49 time_iter: wall: 0.0533441s cpu: 0.0905578s time_optim: wall: 1.08701s cpu: 1.80405s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e20b1] iter: 20 cost: 1625.99 time_iter: wall: 0.0601746s cpu: 0.0969461s time_optim: wall: 1.14719s cpu: 1.90099s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e21b1] iter: 21 cost: 2574.21 time_iter: wall: 0.0592998s cpu: 0.105119s time_optim: wall: 1.20649s cpu: 2.00611s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e22b1] iter: 22 cost: 1625.72 time_iter: wall: 0.0596036s cpu: 0.0961369s time_optim: wall: 1.26609s cpu: 2.10225s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e23b1] iter: 23 cost: 2573.94 time_iter: wall: 0.0591221s cpu: 0.0945617s time_optim: wall: 1.32522s cpu: 2.19681s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e24b1] iter: 24 cost: 2595.56 time_iter: wall: 0.0595344s cpu: 0.0985397s time_optim: wall: 1.38475s cpu: 2.29535s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e25b1] iter: 25 cost: 2581.08 time_iter: wall: 0.0579072s cpu: 0.0970798s time_optim: wall: 1.44266s cpu: 2.39243s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e26b1] iter: 26 cost: 2602.71 time_iter: wall: 0.0517033s cpu: 0.0917851s time_optim: wall: 1.49436s cpu: 2.48421s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e27b1] iter: 27 cost: 2573.38 time_iter: wall: 0.0583215s cpu: 0.102639s time_optim: wall: 1.55268s cpu: 2.58685s
[2020-06-24 18:04:19] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e28b1] iter: 28 cost: 3550.77 time_iter: wall: 0.0573798s cpu: 0.0999289s time_optim: wall: 1.61006s cpu: 2.68678s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e29b1] iter: 29 cost: 1624.78 time_iter: wall: 0.055416s cpu: 0.0946081s time_optim: wall: 1.66548s cpu: 2.78139s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e30b1] iter: 30 cost: 2594.74 time_iter: wall: 0.0597373s cpu: 0.0974391s time_optim: wall: 1.72522s cpu: 2.87883s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e31b1] iter: 31 cost: 2602.03 time_iter: wall: 0.059422s cpu: 0.0976637s time_optim: wall: 1.78464s cpu: 2.97649s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e32b1] iter: 32 cost: 2594.47 time_iter: wall: 0.0603956s cpu: 0.096248s time_optim: wall: 1.84504s cpu: 3.07274s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e33b1] iter: 33 cost: 2579.97 time_iter: wall: 0.059686s cpu: 0.0955575s time_optim: wall: 1.90472s cpu: 3.1683s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e34b1] iter: 34 cost: 3549.94 time_iter: wall: 0.059981s cpu: 0.0954454s time_optim: wall: 1.9647s cpu: 3.26374s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e35b1] iter: 35 cost: 1623.97 time_iter: wall: 0.0601407s cpu: 0.0941339s time_optim: wall: 2.02484s cpu: 3.35788s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e36b1] iter: 36 cost: 2572.14 time_iter: wall: 0.0590763s cpu: 0.0937153s time_optim: wall: 2.08392s cpu: 3.45159s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e37b1] iter: 37 cost: 3549.52 time_iter: wall: 0.0544017s cpu: 0.0886217s time_optim: wall: 2.13832s cpu: 3.54021s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e38b1] iter: 38 cost: 2571.86 time_iter: wall: 0.0442645s cpu: 0.079001s time_optim: wall: 2.18259s cpu: 3.61922s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0e39b1] iter: 39 cost: 2593.52 time_iter: wall: 0.0511828s cpu: 0.0884544s time_optim: wall: 2.23377s cpu: 3.70767s
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0] Number of epochs exceeded.
[2020-06-24 18:04:20] [INF] [0:140040025929472/dweindl-ThinkPad-L480] [o0] Optimizer status 1, final llh: 2.586263e+03, time: wall: 2.275734 cpu: 3.796501.
[2020-06-24 18:04:22] [INF] [0:140040514709440/dweindl-ThinkPad-L480] Walltime on master: 4.291548s, CPU time of all processes: 17.236513s
[2020-06-24 18:04:22] [INF] [0:140040514709440/dweindl-ThinkPad-L480] Sent termination signal to workers.
[2020-06-24 18:04:25] [INF] [0:139861087696832/dweindl-ThinkPad-L480] Running with 4 MPI processes.
[2020-06-24 18:04:25] [INF] [0:139861087696832/dweindl-ThinkPad-L480] Reading random initial theta 0 from /optimizationOptions/randomStarts
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e0b1] iter: 0 cost: 2598.82 time_iter: wall: 0.0622845s cpu: 0.0999832s time_optim: wall: 0.0622848s cpu: 0.0999832s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e1b1] iter: 1 cost: 2606.12 time_iter: wall: 0.0630269s cpu: 0.102431s time_optim: wall: 0.125312s cpu: 0.202415s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e2b1] iter: 2 cost: 2598.55 time_iter: wall: 0.0628939s cpu: 0.099197s time_optim: wall: 0.188206s cpu: 0.301612s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e3b1] iter: 3 cost: 2598.41 time_iter: wall: 0.0632113s cpu: 0.0997596s time_optim: wall: 0.251418s cpu: 0.401371s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e4b1] iter: 4 cost: 2598.27 time_iter: wall: 0.0630509s cpu: 0.100739s time_optim: wall: 0.314469s cpu: 0.50211s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e5b1] iter: 5 cost: 2583.86 time_iter: wall: 0.0630902s cpu: 0.0993292s time_optim: wall: 0.37756s cpu: 0.601439s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e6b1] iter: 6 cost: 2583.72 time_iter: wall: 0.0641154s cpu: 0.106232s time_optim: wall: 0.441675s cpu: 0.707671s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e7b1] iter: 7 cost: 2597.86 time_iter: wall: 0.063322s cpu: 0.104737s time_optim: wall: 0.504998s cpu: 0.812409s
[2020-06-24 18:04:25] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e8b1] iter: 8 cost: 1627.61 time_iter: wall: 0.0602295s cpu: 0.10042s time_optim: wall: 0.565227s cpu: 0.912828s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e9b1] iter: 9 cost: 1627.48 time_iter: wall: 0.0614533s cpu: 0.100033s time_optim: wall: 0.626681s cpu: 1.01286s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e10b1] iter: 10 cost: 1627.35 time_iter: wall: 0.0613093s cpu: 0.0965668s time_optim: wall: 0.68799s cpu: 1.10943s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e11b1] iter: 11 cost: 2597.32 time_iter: wall: 0.0610382s cpu: 0.100296s time_optim: wall: 0.749029s cpu: 1.20972s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e12b1] iter: 12 cost: 3553.01 time_iter: wall: 0.0620061s cpu: 0.0983909s time_optim: wall: 0.811035s cpu: 1.30811s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e13b1] iter: 13 cost: 2597.05 time_iter: wall: 0.0660115s cpu: 0.118999s time_optim: wall: 0.877047s cpu: 1.42711s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e14b1] iter: 14 cost: 2582.61 time_iter: wall: 0.0636964s cpu: 0.111761s time_optim: wall: 0.940744s cpu: 1.53888s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e15b1] iter: 15 cost: 3552.59 time_iter: wall: 0.0719714s cpu: 0.111735s time_optim: wall: 1.01272s cpu: 1.65061s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e16b1] iter: 16 cost: 2582.34 time_iter: wall: 0.0763708s cpu: 0.11809s time_optim: wall: 1.08909s cpu: 1.7687s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e17b1] iter: 17 cost: 2574.77 time_iter: wall: 0.0676391s cpu: 0.114936s time_optim: wall: 1.15673s cpu: 1.88364s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e18b1] iter: 18 cost: 1626.27 time_iter: wall: 0.0677754s cpu: 0.120742s time_optim: wall: 1.2245s cpu: 2.00438s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e19b1] iter: 19 cost: 2596.24 time_iter: wall: 0.0628398s cpu: 0.101457s time_optim: wall: 1.28734s cpu: 2.10583s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e20b1] iter: 20 cost: 3551.9 time_iter: wall: 0.0641185s cpu: 0.111732s time_optim: wall: 1.35146s cpu: 2.21757s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e21b1] iter: 21 cost: 2574.22 time_iter: wall: 0.0664898s cpu: 0.12155s time_optim: wall: 1.41795s cpu: 2.33912s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e22b1] iter: 22 cost: 3551.62 time_iter: wall: 0.0676231s cpu: 0.121595s time_optim: wall: 1.48557s cpu: 2.46071s
[2020-06-24 18:04:26] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e23b1] iter: 23 cost: 2573.94 time_iter: wall: 0.0675655s cpu: 0.121896s time_optim: wall: 1.55314s cpu: 2.58261s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e24b1] iter: 24 cost: 2595.56 time_iter: wall: 0.0685067s cpu: 0.122986s time_optim: wall: 1.62165s cpu: 2.70559s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e25b1] iter: 25 cost: 1625.32 time_iter: wall: 0.0680839s cpu: 0.123413s time_optim: wall: 1.68973s cpu: 2.82901s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e26b1] iter: 26 cost: 3551.06 time_iter: wall: 0.0672257s cpu: 0.122315s time_optim: wall: 1.75696s cpu: 2.95132s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e27b1] iter: 27 cost: 3550.93 time_iter: wall: 0.066949s cpu: 0.121663s time_optim: wall: 1.82391s cpu: 3.07299s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e28b1] iter: 28 cost: 2580.68 time_iter: wall: 0.0670295s cpu: 0.122009s time_optim: wall: 1.89094s cpu: 3.195s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e29b1] iter: 29 cost: 2602.31 time_iter: wall: 0.0672325s cpu: 0.122463s time_optim: wall: 1.95817s cpu: 3.31746s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e30b1] iter: 30 cost: 2594.75 time_iter: wall: 0.0673297s cpu: 0.122729s time_optim: wall: 2.0255s cpu: 3.44019s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e31b1] iter: 31 cost: 3550.37 time_iter: wall: 0.0686383s cpu: 0.125382s time_optim: wall: 2.09414s cpu: 3.56557s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e32b1] iter: 32 cost: 2601.9 time_iter: wall: 0.0725371s cpu: 0.127239s time_optim: wall: 2.16667s cpu: 3.69281s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e33b1] iter: 33 cost: 2594.34 time_iter: wall: 0.0698901s cpu: 0.127167s time_optim: wall: 2.23656s cpu: 3.81997s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e34b1] iter: 34 cost: 2579.84 time_iter: wall: 0.0696602s cpu: 0.127001s time_optim: wall: 2.30623s cpu: 3.94698s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e35b1] iter: 35 cost: 3549.81 time_iter: wall: 0.0690396s cpu: 0.125777s time_optim: wall: 2.37527s cpu: 4.07275s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e36b1] iter: 36 cost: 2572.15 time_iter: wall: 0.0686984s cpu: 0.125473s time_optim: wall: 2.44396s cpu: 4.19823s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e37b1] iter: 37 cost: 2572.01 time_iter: wall: 0.0689723s cpu: 0.126265s time_optim: wall: 2.51294s cpu: 4.32449s
[2020-06-24 18:04:27] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e38b1] iter: 38 cost: 3549.39 time_iter: wall: 0.0690215s cpu: 0.126387s time_optim: wall: 2.58196s cpu: 4.45088s
[2020-06-24 18:04:28] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0e39b1] iter: 39 cost: 2593.53 time_iter: wall: 0.0673973s cpu: 0.122811s time_optim: wall: 2.64936s cpu: 4.57369s
[2020-06-24 18:04:28] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0] Number of epochs exceeded.
[2020-06-24 18:04:28] [INF] [0:139860668487424/dweindl-ThinkPad-L480] [o0] Optimizer status 1, final llh: 2.586273e+03, time: wall: 2.705125 cpu: 4.687131.
[2020-06-24 18:04:29] [INF] [0:139861087696832/dweindl-ThinkPad-L480] Walltime on master: 4.296504s, CPU time of all processes: 17.140153s
[2020-06-24 18:04:29] [INF] [0:139861087696832/dweindl-ThinkPad-L480] Sent termination signal to workers.
[2020-06-24 18:04:32] [INF] [0:139846431197120/dweindl-ThinkPad-L480] Running with 4 MPI processes.
[2020-06-24 18:04:32] [INF] [0:139846431197120/dweindl-ThinkPad-L480] Reading random initial theta 0 from /optimizationOptions/randomStarts
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e0b1] iter: 0 cost: 2606.26 time_iter: wall: 0.0724632s cpu: 0.128046s time_optim: wall: 0.0724636s cpu: 0.128046s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e1b1] iter: 1 cost: 2576.99 time_iter: wall: 0.0686715s cpu: 0.119099s time_optim: wall: 0.141135s cpu: 0.247144s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e2b1] iter: 2 cost: 2584.28 time_iter: wall: 0.0659187s cpu: 0.107962s time_optim: wall: 0.207054s cpu: 0.355107s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e3b1] iter: 3 cost: 2605.84 time_iter: wall: 0.0734749s cpu: 0.122744s time_optim: wall: 0.280529s cpu: 0.477851s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e4b1] iter: 4 cost: 2584 time_iter: wall: 0.0733659s cpu: 0.129842s time_optim: wall: 0.353896s cpu: 0.607693s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e5b1] iter: 5 cost: 2576.43 time_iter: wall: 0.0822124s cpu: 0.138493s time_optim: wall: 0.436108s cpu: 0.746185s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e6b1] iter: 6 cost: 1627.88 time_iter: wall: 0.0684215s cpu: 0.117872s time_optim: wall: 0.50453s cpu: 0.864057s
[2020-06-24 18:04:32] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e7b1] iter: 7 cost: 3553.71 time_iter: wall: 0.0669413s cpu: 0.113626s time_optim: wall: 0.571471s cpu: 0.977683s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e8b1] iter: 8 cost: 2576.02 time_iter: wall: 0.0643325s cpu: 0.112588s time_optim: wall: 0.635804s cpu: 1.09027s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e9b1] iter: 9 cost: 1627.48 time_iter: wall: 0.0634549s cpu: 0.10862s time_optim: wall: 0.699259s cpu: 1.19889s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e10b1] iter: 10 cost: 2604.89 time_iter: wall: 0.0794393s cpu: 0.122471s time_optim: wall: 0.778699s cpu: 1.32136s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e11b1] iter: 11 cost: 2604.75 time_iter: wall: 0.078345s cpu: 0.131707s time_optim: wall: 0.857044s cpu: 1.45307s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e12b1] iter: 12 cost: 3553.01 time_iter: wall: 0.0711897s cpu: 0.118781s time_optim: wall: 0.928234s cpu: 1.57185s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e13b1] iter: 13 cost: 2582.75 time_iter: wall: 0.0768808s cpu: 0.125589s time_optim: wall: 1.00512s cpu: 1.69744s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e14b1] iter: 14 cost: 2604.35 time_iter: wall: 0.0849613s cpu: 0.127864s time_optim: wall: 1.09008s cpu: 1.8253s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e15b1] iter: 15 cost: 2582.47 time_iter: wall: 0.0600042s cpu: 0.106648s time_optim: wall: 1.15008s cpu: 1.93195s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e16b1] iter: 16 cost: 2604.07 time_iter: wall: 0.0570566s cpu: 0.101367s time_optim: wall: 1.20714s cpu: 2.03332s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e17b1] iter: 17 cost: 2582.19 time_iter: wall: 0.0716678s cpu: 0.116911s time_optim: wall: 1.27881s cpu: 2.15023s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e18b1] iter: 18 cost: 2582.05 time_iter: wall: 0.0645508s cpu: 0.113642s time_optim: wall: 1.34336s cpu: 2.26387s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e19b1] iter: 19 cost: 1626.13 time_iter: wall: 0.0627529s cpu: 0.108511s time_optim: wall: 1.40611s cpu: 2.37238s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e20b1] iter: 20 cost: 2581.78 time_iter: wall: 0.064229s cpu: 0.105655s time_optim: wall: 1.47034s cpu: 2.47804s
[2020-06-24 18:04:33] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e21b1] iter: 21 cost: 2574.21 time_iter: wall: 0.0626647s cpu: 0.104949s time_optim: wall: 1.533s cpu: 2.58298s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e22b1] iter: 22 cost: 2581.5 time_iter: wall: 0.0644101s cpu: 0.115989s time_optim: wall: 1.59742s cpu: 2.69897s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e23b1] iter: 23 cost: 2595.69 time_iter: wall: 0.0647155s cpu: 0.118407s time_optim: wall: 1.66213s cpu: 2.81738s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e24b1] iter: 24 cost: 2595.55 time_iter: wall: 0.0649485s cpu: 0.119045s time_optim: wall: 1.72708s cpu: 2.93643s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e25b1] iter: 25 cost: 2573.65 time_iter: wall: 0.066019s cpu: 0.120768s time_optim: wall: 1.7931s cpu: 3.05719s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e26b1] iter: 26 cost: 2580.94 time_iter: wall: 0.0654555s cpu: 0.114922s time_optim: wall: 1.85855s cpu: 3.17212s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e27b1] iter: 27 cost: 3550.91 time_iter: wall: 0.0661213s cpu: 0.108651s time_optim: wall: 1.92468s cpu: 3.28077s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e28b1] iter: 28 cost: 2595.01 time_iter: wall: 0.0608098s cpu: 0.101498s time_optim: wall: 1.98549s cpu: 3.38226s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e29b1] iter: 29 cost: 2580.52 time_iter: wall: 0.0558579s cpu: 0.100219s time_optim: wall: 2.04134s cpu: 3.48248s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e30b1] iter: 30 cost: 2572.96 time_iter: wall: 0.0576749s cpu: 0.0964017s time_optim: wall: 2.09902s cpu: 3.57888s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e31b1] iter: 31 cost: 2602.02 time_iter: wall: 0.0658728s cpu: 0.116765s time_optim: wall: 2.16489s cpu: 3.69565s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e32b1] iter: 32 cost: 3550.21 time_iter: wall: 0.0657637s cpu: 0.110906s time_optim: wall: 2.23066s cpu: 3.80656s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e33b1] iter: 33 cost: 1624.23 time_iter: wall: 0.0642731s cpu: 0.102772s time_optim: wall: 2.29493s cpu: 3.90933s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e34b1] iter: 34 cost: 3549.94 time_iter: wall: 0.064435s cpu: 0.105091s time_optim: wall: 2.35937s cpu: 4.01442s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e35b1] iter: 35 cost: 2594.06 time_iter: wall: 0.0647286s cpu: 0.110586s time_optim: wall: 2.42409s cpu: 4.125s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e36b1] iter: 36 cost: 3549.66 time_iter: wall: 0.0652132s cpu: 0.113212s time_optim: wall: 2.48931s cpu: 4.23822s
[2020-06-24 18:04:34] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e37b1] iter: 37 cost: 2579.42 time_iter: wall: 0.0674677s cpu: 0.114828s time_optim: wall: 2.55678s cpu: 4.35304s
[2020-06-24 18:04:35] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e38b1] iter: 38 cost: 1623.56 time_iter: wall: 0.0658553s cpu: 0.114328s time_optim: wall: 2.62263s cpu: 4.46737s
[2020-06-24 18:04:35] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0e39b1] iter: 39 cost: 1623.43 time_iter: wall: 0.0654116s cpu: 0.112918s time_optim: wall: 2.68804s cpu: 4.58029s
[2020-06-24 18:04:35] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0] Number of epochs exceeded.
[2020-06-24 18:04:35] [INF] [0:139846005810944/dweindl-ThinkPad-L480] [o0] Optimizer status 1, final llh: 2.586267e+03, time: wall: 2.752903 cpu: 4.703666.
[2020-06-24 18:04:36] [INF] [0:139846431197120/dweindl-ThinkPad-L480] Walltime on master: 4.303210s, CPU time of all processes: 16.887346s
[2020-06-24 18:04:36] [INF] [0:139846431197120/dweindl-ThinkPad-L480] Sent termination signal to workers.
[26]:
fig, axs = plt.subplots(nrows=len(learningRates) + 1, figsize=(10, 20))
for i, learningRate in enumerate(learningRates):
    filename = "deleteme-minibatch-rate-%d/_rank00000.h5" % i
    with h5py.File(filename, 'r') as f:
        trajectory = f['/multistarts/0/iterCostFunCost'][:]
    for start in range(trajectory.shape[0]):
        # Individual plot + overlay
        for ax in (axs[i], axs[-1]):
            ax.plot(trajectory[start], label="r%f-s%d"%(learningRate, start), color="C%d"%i)
            ax.set_xlabel("Function evaluation")
            ax.set_ylabel("Cost")
            ax.set_title("Comparison of learning rates")
            ax.legend()
plt.subplots_adjust(hspace=0.5)
../_images/example_notebooks_parpeExampleSteadystateMinibatch_11_0.png