JohannesBuchner / UltraNest

Fit and compare complex models reliably and rapidly. Advanced nested sampling.
https://johannesbuchner.github.io/UltraNest/
Other
143 stars 30 forks source link

Crash when the number of points changes on the latest version #44

Closed SmirnGreg closed 3 years ago

SmirnGreg commented 3 years ago

With the recent version 3.3.2, I am getting an error when the number of living points changes.

What I Did

Z=-4.2(93.28%) | Like=-0.38..-0.01 [-0.3843..-0.3842]*| it/evals=2640/46125 eff=inf% N=400 ^MZ=-4.2(93.85%) | Like=-0.37..-0.01 [-0.3702..-0.3695]*| it/evals=2680/46125 eff=inf% N=400

Mono-modal Volume: ~exp(-7.21)   Expected Volume: exp(-6.75) Quality: ok

   negative degeneracy between $log_{10}(M_{gas}/M_\odot)$ and $Tapering radius, au$: rho=-0.89
   positive degeneracy between $T_{mid}, K$ and $Temperature slope$: rho=0.98
$Tapering radius, au$      :  +3.0e+01|      ******************** ***| +2.0e+02
$log_{10}(M_{gas}/M_\odot)$:      -4.0|         ************* * *    |     -2.0
$Temperature slope$        :      +0.4|******************************|     +0.7
$T_{atm}, K$               :  +2.0e+02| *****************************| +2.0e+03
$T_{mid}, K$               :  +5.0e+01|   ***************************| +4.0e+02

Z=-4.2(94.26%) | Like=-0.35..-0.01 [-0.3535..-0.3530]*| it/evals=2712/47212 eff=249.4940% N=400 ^MZ=-4.2(94.36%) | Like=-0.35..-0.01 [-0.3505..-0.3500]*| it/evals=2720/47212 eff=250.2300% N=400 ^MZ=-4.2(94.60%) | Like=-0.34..-0.01 [-0.3437..-0.3421]*| it/evals=2739/48306 eff=125.5846% N=400 ^MZ=-4.2(94.84%) | Like=-0.33..-0.01 [-0.3341..-0.3340]*| it/evals=2760/48306 eff=126.5475% N=400 ^MZ=-4.2(94.87%) | Like=-0.33..-0.01 [-0.3332..-0.3330]*| it/evals=2763/49391 eff=84.5989% N=400 ^M[ultranest] Explored until L=-0.01
[ultranest] Likelihood function evaluations: 49391
[ultranest] Writing samples and results to disk ...
[ultranest] Writing samples and results to disk ... done
[ultranest]   logZ = -4.278 +- 0
[ultranest] Effective samples strategy satisfied (ESS = 1744.1, need >400)
[ultranest] Posterior uncertainty strategy is satisfied (KL: 0.44+-0.00 nat, need <0.10 nat)
[ultranest] Evidency uncertainty strategy wants 564 minimum live points (dlogz from 0.12 to 0.12, need <0.1)
[ultranest]   logZ error budget: single: 0.08 bs:0.00 tail:0.05 total:0.05 required:<0.10
[ultranest] Widening roots to 798 live points (have 400 already) ...
[ultranest] Sampling 398 live points from prior ...
  File "/cobra/u/smirngre/soft/UltraNest/ultranest/integrator.py", line 2596, in run_iter
  File "/cobra/u/smirngre/soft/UltraNest/ultranest/integrator.py", line 1356, in _widen_roots
  File "<__array_function__ internals>", line 5, in concatenate
ValueError: all the input arrays must have same number of dimensions, but the array at index 0 has 2 dimension(s) and the array at index 398 has 1 dimension(s)

(I am not sure I recreated them in the correct order)

Here is the log as I ran it first for half an hour, then the process was killed by the slurm, and then I resumed. It started fine, but then crashed when the number of living points changed, and crashed again the same way when I restarted.

13:08:10 [ultranest] [DEBUG] ReactiveNestedSampler: dims=5+0, resume=True, log_dir=ultranest, backend=hdf5, vectorized=False, nbootstraps=30, ndraw=128..65536
13:08:53 [ultranest] [INFO] Sampling 400 live points from prior ...
13:10:22 [ultranest] [DEBUG] run_iter dlogz=0.1, dKL=0.1, frac_remain=0.05, Lepsilon=0.0100, min_ess=400
13:10:22 [ultranest] [DEBUG] max_iters=-1, max_ncalls=-1, max_num_improvement_loops=-1, min_num_live_points=400, cluster_num_live_points=40
13:10:22 [ultranest] [DEBUG] minimal_widths_sequence: [(-inf, 400.0), (inf, 400.0)]
13:10:42 [ultranest] [DEBUG] iteration=0, ncalls=520, logz=-inf, remainder_fraction=100.0000%, Lmin=-3503.33, Lmax=-0.55
13:10:42 [ultranest] [DEBUG] iteration=40, ncalls=520, logz=-266.58, remainder_fraction=100.0000%, Lmin=-243.21, Lmax=-0.55
13:10:42 [ultranest] [DEBUG] iteration=80, ncalls=520, logz=-83.38, remainder_fraction=100.0000%, Lmin=-76.16, Lmax=-0.55
13:10:42 [ultranest] [DEBUG] iteration=90, ncalls=520, logz=-66.15, remainder_fraction=100.0000%, Lmin=-58.15, Lmax=-0.55
13:11:02 [ultranest] [DEBUG] iteration=106, ncalls=640, logz=-41.28, remainder_fraction=100.0000%, Lmin=-35.17, Lmax=-0.55
13:11:02 [ultranest] [DEBUG] iteration=120, ncalls=640, logz=-33.22, remainder_fraction=100.0000%, Lmin=-28.08, Lmax=-0.55
13:11:02 [ultranest] [DEBUG] iteration=160, ncalls=640, logz=-28.58, remainder_fraction=100.0000%, Lmin=-24.92, Lmax=-0.55
13:11:23 [ultranest] [DEBUG] iteration=194, ncalls=760, logz=-25.76, remainder_fraction=100.0000%, Lmin=-21.70, Lmax=-0.55
13:11:23 [ultranest] [DEBUG] iteration=200, ncalls=760, logz=-25.23, remainder_fraction=100.0000%, Lmin=-21.21, Lmax=-0.55
13:11:23 [ultranest] [DEBUG] iteration=240, ncalls=760, logz=-22.32, remainder_fraction=100.0000%, Lmin=-18.53, Lmax=-0.55
13:11:43 [ultranest] [DEBUG] iteration=261, ncalls=880, logz=-21.20, remainder_fraction=100.0000%, Lmin=-17.54, Lmax=-0.55
13:11:43 [ultranest] [DEBUG] iteration=280, ncalls=880, logz=-20.25, remainder_fraction=100.0000%, Lmin=-16.54, Lmax=-0.55
13:12:03 [ultranest] [DEBUG] iteration=319, ncalls=1000, logz=-18.45, remainder_fraction=99.9999%, Lmin=-14.92, Lmax=-0.55
13:12:03 [ultranest] [DEBUG] iteration=320, ncalls=1000, logz=-18.41, remainder_fraction=99.9999%, Lmin=-14.84, Lmax=-0.55
13:12:03 [ultranest] [DEBUG] iteration=360, ncalls=1000, logz=-16.73, remainder_fraction=99.9996%, Lmin=-13.00, Lmax=-0.55
13:16:28 [ultranest] [DEBUG] ReactiveNestedSampler: dims=5+0, resume=True, log_dir=ultranest, backend=hdf5, vectorized=False, nbootstraps=30, ndraw=128..65536
13:16:54 [ultranest] [DEBUG] Testing resume consistency: [-1.49171366e+01 -1.22306280e+01  0.00000000e+00  3.29514736e-01
  6.32361044e-01  9.60940081e-01  3.40401888e-01  2.32443817e-01
  8.60175051e+01 -2.73527791e+00  6.88282024e-01  8.12723398e+02
  1.31355336e+02]: u=[0.32951474 0.63236104 0.96094008 0.34040189 0.23244382] -> p=[ 8.60175051e+01 -2.73527791e+00  6.88282024e-01  8.12723398e+02
  1.31355336e+02] -> L=-12.230627982784394
13:17:15 [ultranest] [INFO] Resuming from 822 stored points
13:17:15 [ultranest] [DEBUG] run_iter dlogz=0.1, dKL=0.1, frac_remain=0.05, Lepsilon=0.0100, min_ess=400
13:17:15 [ultranest] [DEBUG] max_iters=-1, max_ncalls=-1, max_num_improvement_loops=-1, min_num_live_points=400, cluster_num_live_points=40
13:17:15 [ultranest] [DEBUG] minimal_widths_sequence: [(-inf, 400.0), (inf, 400.0)]
13:17:47 [ultranest] [DEBUG] iteration=0, ncalls=1000, logz=-inf, remainder_fraction=100.0000%, Lmin=-3503.33, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=40, ncalls=1000, logz=-266.58, remainder_fraction=100.0000%, Lmin=-243.21, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=80, ncalls=1000, logz=-83.38, remainder_fraction=100.0000%, Lmin=-76.16, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=90, ncalls=1000, logz=-66.15, remainder_fraction=100.0000%, Lmin=-58.15, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=120, ncalls=1000, logz=-33.22, remainder_fraction=100.0000%, Lmin=-28.08, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=160, ncalls=1000, logz=-28.58, remainder_fraction=100.0000%, Lmin=-24.92, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=180, ncalls=1000, logz=-27.11, remainder_fraction=100.0000%, Lmin=-22.77, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=200, ncalls=1000, logz=-25.23, remainder_fraction=100.0000%, Lmin=-21.21, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=240, ncalls=1000, logz=-22.32, remainder_fraction=100.0000%, Lmin=-18.53, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:17:47 [ultranest] [DEBUG] iteration=280, ncalls=1000, logz=-20.25, remainder_fraction=100.0000%, Lmin=-16.54, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=320, ncalls=1000, logz=-18.41, remainder_fraction=99.9999%, Lmin=-14.84, Lmax=-0.55
13:17:47 [ultranest] [DEBUG] iteration=360, ncalls=1000, logz=-16.73, remainder_fraction=99.9996%, Lmin=-13.00, Lmax=-0.55
13:18:32 [ultranest] [DEBUG] iteration=374, ncalls=2280, logz=-16.13, remainder_fraction=99.9992%, Lmin=-12.41, Lmax=-0.55
13:18:32 [ultranest] [DEBUG] iteration=400, ncalls=2280, logz=-15.23, remainder_fraction=99.9980%, Lmin=-11.65, Lmax=-0.55
13:18:32 [ultranest] [DEBUG] iteration=440, ncalls=2280, logz=-14.11, remainder_fraction=99.9939%, Lmin=-10.71, Lmax=-0.46
13:18:32 [ultranest] [DEBUG] iteration=480, ncalls=2280, logz=-13.26, remainder_fraction=99.9863%, Lmin=-10.04, Lmax=-0.46
13:18:32 [ultranest] [DEBUG] iteration=520, ncalls=2280, logz=-12.53, remainder_fraction=99.9729%, Lmin=-9.23, Lmax=-0.46
13:18:32 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:18:32 [ultranest] [DEBUG] iteration=560, ncalls=2280, logz=-11.89, remainder_fraction=99.9464%, Lmin=-8.73, Lmax=-0.46
13:18:32 [ultranest] [DEBUG] iteration=600, ncalls=2280, logz=-11.30, remainder_fraction=99.9038%, Lmin=-7.96, Lmax=-0.46
13:18:32 [ultranest] [DEBUG] iteration=640, ncalls=2280, logz=-10.72, remainder_fraction=99.8373%, Lmin=-7.43, Lmax=-0.45
13:18:32 [ultranest] [DEBUG] iteration=680, ncalls=2280, logz=-10.11, remainder_fraction=99.7050%, Lmin=-6.68, Lmax=-0.45
13:18:32 [ultranest] [DEBUG] iteration=720, ncalls=2280, logz=-9.59, remainder_fraction=99.5115%, Lmin=-6.20, Lmax=-0.45
13:18:32 [ultranest] [DEBUG] iteration=760, ncalls=2280, logz=-9.15, remainder_fraction=99.2361%, Lmin=-5.73, Lmax=-0.39
13:19:15 [ultranest] [DEBUG] iteration=764, ncalls=3560, logz=-9.10, remainder_fraction=99.1963%, Lmin=-5.69, Lmax=-0.39
13:19:15 [ultranest] [DEBUG] iteration=800, ncalls=3560, logz=-8.72, remainder_fraction=98.8527%, Lmin=-5.33, Lmax=-0.33
13:19:15 [ultranest] [DEBUG] iteration=840, ncalls=3560, logz=-8.30, remainder_fraction=98.2992%, Lmin=-4.77, Lmax=-0.33
13:19:15 [ultranest] [DEBUG] iteration=880, ncalls=3560, logz=-7.91, remainder_fraction=97.5320%, Lmin=-4.38, Lmax=-0.33
13:19:15 [ultranest] [DEBUG] iteration=920, ncalls=3560, logz=-7.54, remainder_fraction=96.4367%, Lmin=-3.97, Lmax=-0.26
13:19:15 [ultranest] [DEBUG] iteration=960, ncalls=3560, logz=-7.20, remainder_fraction=94.9681%, Lmin=-3.62, Lmax=-0.26
13:19:16 [ultranest] [DEBUG] iteration=1000, ncalls=3560, logz=-6.91, remainder_fraction=93.3339%, Lmin=-3.41, Lmax=-0.26
13:20:00 [ultranest] [DEBUG] iteration=1007, ncalls=4840, logz=-6.86, remainder_fraction=93.0061%, Lmin=-3.34, Lmax=-0.26
13:20:00 [ultranest] [DEBUG] iteration=1040, ncalls=4840, logz=-6.65, remainder_fraction=91.3085%, Lmin=-3.16, Lmax=-0.26
13:20:00 [ultranest] [DEBUG] iteration=1080, ncalls=4840, logz=-6.41, remainder_fraction=89.3956%, Lmin=-2.91, Lmax=-0.21
13:20:00 [ultranest] [DEBUG] iteration=1120, ncalls=4840, logz=-6.21, remainder_fraction=87.2515%, Lmin=-2.80, Lmax=-0.21
13:20:00 [ultranest] [DEBUG] iteration=1160, ncalls=4840, logz=-6.03, remainder_fraction=84.8927%, Lmin=-2.59, Lmax=-0.21
13:20:43 [ultranest] [DEBUG] iteration=1167, ncalls=6120, logz=-6.00, remainder_fraction=84.4594%, Lmin=-2.53, Lmax=-0.21
13:20:43 [ultranest] [DEBUG] iteration=1200, ncalls=6120, logz=-5.86, remainder_fraction=82.1579%, Lmin=-2.38, Lmax=-0.21
13:20:43 [ultranest] [DEBUG] iteration=1240, ncalls=6120, logz=-5.71, remainder_fraction=79.2065%, Lmin=-2.21, Lmax=-0.21
13:20:43 [ultranest] [DEBUG] iteration=1280, ncalls=6120, logz=-5.57, remainder_fraction=75.9271%, Lmin=-2.08, Lmax=-0.21
13:21:27 [ultranest] [DEBUG] iteration=1300, ncalls=7400, logz=-5.50, remainder_fraction=74.1952%, Lmin=-1.99, Lmax=-0.21
13:21:27 [ultranest] [DEBUG] iteration=1320, ncalls=7400, logz=-5.44, remainder_fraction=72.5026%, Lmin=-1.94, Lmax=-0.03
13:21:27 [ultranest] [DEBUG] iteration=1360, ncalls=7400, logz=-5.32, remainder_fraction=68.9207%, Lmin=-1.81, Lmax=-0.03
13:22:10 [ultranest] [DEBUG] iteration=1394, ncalls=8680, logz=-5.23, remainder_fraction=65.9066%, Lmin=-1.72, Lmax=-0.03
13:22:10 [ultranest] [DEBUG] iteration=1400, ncalls=8680, logz=-5.21, remainder_fraction=65.3345%, Lmin=-1.71, Lmax=-0.03
13:22:10 [ultranest] [DEBUG] iteration=1440, ncalls=8680, logz=-5.12, remainder_fraction=61.7966%, Lmin=-1.64, Lmax=-0.03
13:22:54 [ultranest] [DEBUG] iteration=1460, ncalls=9960, logz=-5.08, remainder_fraction=60.2661%, Lmin=-1.60, Lmax=-0.03
13:22:54 [ultranest] [DEBUG] iteration=1480, ncalls=9960, logz=-5.04, remainder_fraction=58.4329%, Lmin=-1.56, Lmax=-0.03
13:22:54 [ultranest] [DEBUG] iteration=1520, ncalls=9960, logz=-4.96, remainder_fraction=55.3254%, Lmin=-1.47, Lmax=-0.03
13:23:38 [ultranest] [DEBUG] iteration=1539, ncalls=11240, logz=-4.93, remainder_fraction=53.9398%, Lmin=-1.43, Lmax=-0.03
13:23:38 [ultranest] [DEBUG] iteration=1560, ncalls=11240, logz=-4.89, remainder_fraction=52.1975%, Lmin=-1.40, Lmax=-0.03
13:23:38 [ultranest] [DEBUG] iteration=1600, ncalls=11240, logz=-4.83, remainder_fraction=48.9275%, Lmin=-1.34, Lmax=-0.03
13:24:21 [ultranest] [DEBUG] iteration=1609, ncalls=12520, logz=-4.81, remainder_fraction=48.1538%, Lmin=-1.32, Lmax=-0.03
13:24:21 [ultranest] [DEBUG] iteration=1640, ncalls=12520, logz=-4.77, remainder_fraction=45.8320%, Lmin=-1.27, Lmax=-0.03
13:25:04 [ultranest] [DEBUG] iteration=1671, ncalls=13800, logz=-4.73, remainder_fraction=43.5299%, Lmin=-1.23, Lmax=-0.03
13:25:04 [ultranest] [DEBUG] iteration=1680, ncalls=13800, logz=-4.72, remainder_fraction=42.9151%, Lmin=-1.23, Lmax=-0.03
13:25:04 [ultranest] [DEBUG] iteration=1710, ncalls=13800, logz=-4.68, remainder_fraction=40.7870%, Lmin=-1.18, Lmax=-0.03
13:25:04 [ultranest] [DEBUG] iteration=1720, ncalls=13800, logz=-4.67, remainder_fraction=40.0820%, Lmin=-1.17, Lmax=-0.03
13:25:50 [ultranest] [DEBUG] iteration=1724, ncalls=15080, logz=-4.67, remainder_fraction=39.8337%, Lmin=-1.17, Lmax=-0.03
13:25:50 [ultranest] [DEBUG] iteration=1760, ncalls=15080, logz=-4.63, remainder_fraction=37.4712%, Lmin=-1.13, Lmax=-0.03
13:26:34 [ultranest] [DEBUG] iteration=1772, ncalls=16360, logz=-4.62, remainder_fraction=36.6409%, Lmin=-1.13, Lmax=-0.03
13:26:34 [ultranest] [DEBUG] iteration=1800, ncalls=16360, logz=-4.59, remainder_fraction=35.0385%, Lmin=-1.10, Lmax=-0.03
13:27:17 [ultranest] [DEBUG] iteration=1829, ncalls=17640, logz=-4.56, remainder_fraction=33.3130%, Lmin=-1.07, Lmax=-0.03
13:27:17 [ultranest] [DEBUG] iteration=1840, ncalls=17640, logz=-4.55, remainder_fraction=32.6755%, Lmin=-1.04, Lmax=-0.03
13:27:17 [ultranest] [DEBUG] iteration=1880, ncalls=17640, logz=-4.52, remainder_fraction=30.6079%, Lmin=-1.00, Lmax=-0.03
13:28:00 [ultranest] [DEBUG] iteration=1882, ncalls=18920, logz=-4.52, remainder_fraction=30.5100%, Lmin=-0.99, Lmax=-0.03
13:28:00 [ultranest] [DEBUG] iteration=1920, ncalls=18920, logz=-4.49, remainder_fraction=28.4986%, Lmin=-0.95, Lmax=-0.03
13:28:44 [ultranest] [DEBUG] iteration=1930, ncalls=20200, logz=-4.49, remainder_fraction=27.9641%, Lmin=-0.93, Lmax=-0.03
13:28:44 [ultranest] [DEBUG] iteration=1960, ncalls=20200, logz=-4.47, remainder_fraction=26.5014%, Lmin=-0.91, Lmax=-0.03
13:29:27 [ultranest] [DEBUG] iteration=1970, ncalls=21480, logz=-4.46, remainder_fraction=26.0679%, Lmin=-0.90, Lmax=-0.03
13:29:27 [ultranest] [DEBUG] iteration=2000, ncalls=21480, logz=-4.44, remainder_fraction=24.6253%, Lmin=-0.87, Lmax=-0.03
13:30:11 [ultranest] [DEBUG] iteration=2015, ncalls=22759, logz=-4.43, remainder_fraction=23.9611%, Lmin=-0.86, Lmax=-0.03
13:30:11 [ultranest] [DEBUG] iteration=2040, ncalls=22759, logz=-4.42, remainder_fraction=22.8879%, Lmin=-0.83, Lmax=-0.03
13:30:55 [ultranest] [DEBUG] iteration=2055, ncalls=24038, logz=-4.41, remainder_fraction=22.1828%, Lmin=-0.81, Lmax=-0.03
13:30:55 [ultranest] [DEBUG] iteration=2080, ncalls=24038, logz=-4.40, remainder_fraction=21.1788%, Lmin=-0.78, Lmax=-0.03
13:31:39 [ultranest] [DEBUG] iteration=2086, ncalls=25318, logz=-4.39, remainder_fraction=20.9364%, Lmin=-0.78, Lmax=-0.03
13:32:24 [ultranest] [DEBUG] iteration=2118, ncalls=26598, logz=-4.38, remainder_fraction=19.6661%, Lmin=-0.74, Lmax=-0.03
13:32:24 [ultranest] [DEBUG] iteration=2120, ncalls=26598, logz=-4.38, remainder_fraction=19.5983%, Lmin=-0.74, Lmax=-0.03
13:33:14 [ultranest] [DEBUG] iteration=2154, ncalls=27878, logz=-4.36, remainder_fraction=18.4066%, Lmin=-0.71, Lmax=-0.01
13:33:14 [ultranest] [DEBUG] iteration=2160, ncalls=27878, logz=-4.36, remainder_fraction=18.1847%, Lmin=-0.71, Lmax=-0.01
13:33:58 [ultranest] [DEBUG] iteration=2176, ncalls=29147, logz=-4.35, remainder_fraction=17.6541%, Lmin=-0.69, Lmax=-0.01
13:33:58 [ultranest] [DEBUG] iteration=2200, ncalls=29147, logz=-4.34, remainder_fraction=16.8117%, Lmin=-0.67, Lmax=-0.01
13:34:41 [ultranest] [DEBUG] iteration=2216, ncalls=30412, logz=-4.34, remainder_fraction=16.3118%, Lmin=-0.65, Lmax=-0.01
13:34:41 [ultranest] [DEBUG] iteration=2240, ncalls=30412, logz=-4.33, remainder_fraction=15.5803%, Lmin=-0.64, Lmax=-0.01
13:34:41 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:35:24 [ultranest] [DEBUG] iteration=2262, ncalls=31675, logz=-4.32, remainder_fraction=14.9475%, Lmin=-0.62, Lmax=-0.01
13:35:24 [ultranest] [DEBUG] iteration=2280, ncalls=31675, logz=-4.31, remainder_fraction=14.3684%, Lmin=-0.60, Lmax=-0.01
13:36:08 [ultranest] [DEBUG] iteration=2313, ncalls=32936, logz=-4.30, remainder_fraction=13.4560%, Lmin=-0.58, Lmax=-0.01
13:36:08 [ultranest] [DEBUG] iteration=2320, ncalls=32936, logz=-4.30, remainder_fraction=13.2576%, Lmin=-0.58, Lmax=-0.01
13:36:50 [ultranest] [DEBUG] iteration=2350, ncalls=34191, logz=-4.29, remainder_fraction=12.4921%, Lmin=-0.56, Lmax=-0.01
13:36:50 [ultranest] [DEBUG] iteration=2360, ncalls=34191, logz=-4.29, remainder_fraction=12.2455%, Lmin=-0.55, Lmax=-0.01
13:37:40 [ultranest] [DEBUG] iteration=2392, ncalls=35445, logz=-4.28, remainder_fraction=11.4913%, Lmin=-0.53, Lmax=-0.01
13:37:40 [ultranest] [DEBUG] iteration=2400, ncalls=35445, logz=-4.28, remainder_fraction=11.3105%, Lmin=-0.52, Lmax=-0.01
13:38:27 [ultranest] [DEBUG] iteration=2430, ncalls=36660, logz=-4.27, remainder_fraction=10.5926%, Lmin=-0.50, Lmax=-0.01
13:38:27 [ultranest] [DEBUG] iteration=2440, ncalls=36660, logz=-4.27, remainder_fraction=10.3732%, Lmin=-0.49, Lmax=-0.01
13:39:08 [ultranest] [DEBUG] iteration=2477, ncalls=37866, logz=-4.26, remainder_fraction=9.5909%, Lmin=-0.48, Lmax=-0.01
13:39:08 [ultranest] [DEBUG] iteration=2480, ncalls=37866, logz=-4.26, remainder_fraction=9.5317%, Lmin=-0.47, Lmax=-0.01
13:39:51 [ultranest] [DEBUG] iteration=2501, ncalls=39058, logz=-4.25, remainder_fraction=9.1052%, Lmin=-0.46, Lmax=-0.01
13:39:51 [ultranest] [DEBUG] iteration=2520, ncalls=39058, logz=-4.25, remainder_fraction=8.7372%, Lmin=-0.45, Lmax=-0.01
13:40:34 [ultranest] [DEBUG] iteration=2532, ncalls=40233, logz=-4.25, remainder_fraction=8.5171%, Lmin=-0.44, Lmax=-0.01
13:41:15 [ultranest] [DEBUG] iteration=2559, ncalls=41408, logz=-4.24, remainder_fraction=8.0396%, Lmin=-0.43, Lmax=-0.01
13:41:15 [ultranest] [DEBUG] iteration=2560, ncalls=41408, logz=-4.24, remainder_fraction=8.0205%, Lmin=-0.43, Lmax=-0.01
13:41:56 [ultranest] [DEBUG] iteration=2590, ncalls=42597, logz=-4.23, remainder_fraction=7.5158%, Lmin=-0.41, Lmax=-0.01
13:41:56 [ultranest] [DEBUG] iteration=2600, ncalls=42597, logz=-4.23, remainder_fraction=7.3461%, Lmin=-0.41, Lmax=-0.01
13:42:36 [ultranest] [DEBUG] iteration=2626, ncalls=43777, logz=-4.23, remainder_fraction=6.9315%, Lmin=-0.39, Lmax=-0.01
13:42:36 [ultranest] [DEBUG] iteration=2640, ncalls=43777, logz=-4.23, remainder_fraction=6.7204%, Lmin=-0.38, Lmax=-0.01
13:43:16 [ultranest] [DEBUG] iteration=2648, ncalls=44943, logz=-4.23, remainder_fraction=6.6011%, Lmin=-0.38, Lmax=-0.01
13:43:58 [ultranest] [DEBUG] iteration=2677, ncalls=46125, logz=-4.22, remainder_fraction=6.1918%, Lmin=-0.37, Lmax=-0.01
13:43:58 [ultranest] [DEBUG] iteration=2680, ncalls=46125, logz=-4.22, remainder_fraction=6.1488%, Lmin=-0.37, Lmax=-0.01
13:44:38 [ultranest] [DEBUG] iteration=2712, ncalls=47272, logz=-4.22, remainder_fraction=5.7368%, Lmin=-0.35, Lmax=-0.01
13:44:38 [ultranest] [DEBUG] iteration=2720, ncalls=47272, logz=-4.21, remainder_fraction=5.6349%, Lmin=-0.35, Lmax=-0.01
13:45:19 [ultranest] [DEBUG] iteration=2733, ncalls=48437, logz=-4.21, remainder_fraction=5.4729%, Lmin=-0.35, Lmax=-0.01
13:50:21 [ultranest] [DEBUG] ReactiveNestedSampler: dims=5+0, resume=True, log_dir=ultranest, backend=hdf5, vectorized=False, nbootstraps=30, ndraw=128..65536
13:51:02 [ultranest] [DEBUG] Testing resume consistency: [-3.71737116e-01 -3.20741040e-01  0.00000000e+00  5.39214878e-01
  3.86956953e-01  6.72768769e-01  8.73180552e-01  6.72118570e-01
  1.21666529e+02 -3.22608609e+00  6.01830631e-01  1.77172499e+03
  2.85241500e+02]: u=[0.53921488 0.38695695 0.67276877 0.87318055 0.67211857] -> p=[ 1.21666529e+02 -3.22608609e+00  6.01830631e-01  1.77172499e+03
  2.85241500e+02] -> L=-0.3207410403537414
13:51:25 [ultranest] [INFO] Resuming from 3618 stored points
13:51:26 [ultranest] [DEBUG] run_iter dlogz=0.1, dKL=0.1, frac_remain=0.05, Lepsilon=0.0100, min_ess=400
13:51:26 [ultranest] [DEBUG] max_iters=-1, max_ncalls=-1, max_num_improvement_loops=-1, min_num_live_points=400, cluster_num_live_points=40
13:51:26 [ultranest] [DEBUG] minimal_widths_sequence: [(-inf, 400.0), (inf, 400.0)]
13:51:31 [ultranest] [DEBUG] iteration=0, ncalls=46125, logz=-inf, remainder_fraction=100.0000%, Lmin=-3503.33, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=40, ncalls=46125, logz=-266.58, remainder_fraction=100.0000%, Lmin=-243.21, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=80, ncalls=46125, logz=-83.38, remainder_fraction=100.0000%, Lmin=-76.16, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=90, ncalls=46125, logz=-66.15, remainder_fraction=100.0000%, Lmin=-58.15, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=120, ncalls=46125, logz=-33.22, remainder_fraction=100.0000%, Lmin=-28.08, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=160, ncalls=46125, logz=-28.58, remainder_fraction=100.0000%, Lmin=-24.92, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=200, ncalls=46125, logz=-25.23, remainder_fraction=100.0000%, Lmin=-21.21, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=240, ncalls=46125, logz=-22.32, remainder_fraction=100.0000%, Lmin=-18.53, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=280, ncalls=46125, logz=-20.25, remainder_fraction=100.0000%, Lmin=-16.54, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=320, ncalls=46125, logz=-18.41, remainder_fraction=99.9999%, Lmin=-14.84, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=360, ncalls=46125, logz=-16.73, remainder_fraction=99.9996%, Lmin=-13.00, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=400, ncalls=46125, logz=-15.23, remainder_fraction=99.9980%, Lmin=-11.65, Lmax=-0.55
13:51:31 [ultranest] [DEBUG] iteration=440, ncalls=46125, logz=-14.11, remainder_fraction=99.9939%, Lmin=-10.71, Lmax=-0.46
13:51:31 [ultranest] [DEBUG] iteration=450, ncalls=46125, logz=-13.87, remainder_fraction=99.9922%, Lmin=-10.49, Lmax=-0.46
13:51:31 [ultranest] [DEBUG] iteration=480, ncalls=46125, logz=-13.26, remainder_fraction=99.9863%, Lmin=-10.04, Lmax=-0.46
13:51:31 [ultranest] [DEBUG] iteration=520, ncalls=46125, logz=-12.53, remainder_fraction=99.9729%, Lmin=-9.23, Lmax=-0.46
13:51:31 [ultranest] [DEBUG] iteration=560, ncalls=46125, logz=-11.89, remainder_fraction=99.9464%, Lmin=-8.73, Lmax=-0.46
13:51:32 [ultranest] [DEBUG] iteration=600, ncalls=46125, logz=-11.30, remainder_fraction=99.9038%, Lmin=-7.96, Lmax=-0.46
13:51:32 [ultranest] [DEBUG] iteration=630, ncalls=46125, logz=-10.86, remainder_fraction=99.8564%, Lmin=-7.59, Lmax=-0.45
13:51:32 [ultranest] [DEBUG] iteration=640, ncalls=46125, logz=-10.72, remainder_fraction=99.8373%, Lmin=-7.43, Lmax=-0.45
13:51:32 [ultranest] [DEBUG] iteration=680, ncalls=46125, logz=-10.11, remainder_fraction=99.7050%, Lmin=-6.68, Lmax=-0.45
13:51:32 [ultranest] [DEBUG] iteration=720, ncalls=46125, logz=-9.59, remainder_fraction=99.5115%, Lmin=-6.20, Lmax=-0.45
13:51:32 [ultranest] [DEBUG] iteration=760, ncalls=46125, logz=-9.15, remainder_fraction=99.2361%, Lmin=-5.73, Lmax=-0.39
13:51:32 [ultranest] [DEBUG] iteration=800, ncalls=46125, logz=-8.72, remainder_fraction=98.8527%, Lmin=-5.33, Lmax=-0.33
13:51:32 [ultranest] [DEBUG] iteration=840, ncalls=46125, logz=-8.30, remainder_fraction=98.2992%, Lmin=-4.77, Lmax=-0.33
13:51:32 [ultranest] [DEBUG] iteration=880, ncalls=46125, logz=-7.91, remainder_fraction=97.5320%, Lmin=-4.38, Lmax=-0.33
13:51:32 [ultranest] [DEBUG] iteration=920, ncalls=46125, logz=-7.54, remainder_fraction=96.4367%, Lmin=-3.97, Lmax=-0.26
13:51:32 [ultranest] [DEBUG] iteration=960, ncalls=46125, logz=-7.20, remainder_fraction=94.9681%, Lmin=-3.62, Lmax=-0.26
13:51:32 [ultranest] [DEBUG] iteration=990, ncalls=46125, logz=-6.98, remainder_fraction=93.7590%, Lmin=-3.44, Lmax=-0.26
13:51:32 [ultranest] [DEBUG] iteration=1000, ncalls=46125, logz=-6.91, remainder_fraction=93.3339%, Lmin=-3.41, Lmax=-0.26
13:51:32 [ultranest] [DEBUG] iteration=1040, ncalls=46125, logz=-6.65, remainder_fraction=91.3085%, Lmin=-3.16, Lmax=-0.26
13:51:32 [ultranest] [DEBUG] iteration=1080, ncalls=46125, logz=-6.41, remainder_fraction=89.3956%, Lmin=-2.91, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1120, ncalls=46125, logz=-6.21, remainder_fraction=87.2515%, Lmin=-2.80, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1160, ncalls=46125, logz=-6.03, remainder_fraction=84.8927%, Lmin=-2.59, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1170, ncalls=46125, logz=-5.99, remainder_fraction=84.2771%, Lmin=-2.50, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1200, ncalls=46125, logz=-5.86, remainder_fraction=82.1579%, Lmin=-2.38, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1240, ncalls=46125, logz=-5.71, remainder_fraction=79.2065%, Lmin=-2.21, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1280, ncalls=46125, logz=-5.57, remainder_fraction=75.9271%, Lmin=-2.08, Lmax=-0.21
13:51:32 [ultranest] [DEBUG] iteration=1320, ncalls=46125, logz=-5.44, remainder_fraction=72.5026%, Lmin=-1.94, Lmax=-0.03
13:51:32 [ultranest] [DEBUG] iteration=1360, ncalls=46125, logz=-5.32, remainder_fraction=68.9207%, Lmin=-1.81, Lmax=-0.03
13:51:32 [ultranest] [DEBUG] iteration=1400, ncalls=46125, logz=-5.21, remainder_fraction=65.3345%, Lmin=-1.71, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1440, ncalls=46125, logz=-5.12, remainder_fraction=61.7966%, Lmin=-1.64, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1480, ncalls=46125, logz=-5.04, remainder_fraction=58.4329%, Lmin=-1.56, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1520, ncalls=46125, logz=-4.96, remainder_fraction=55.3254%, Lmin=-1.47, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1560, ncalls=46125, logz=-4.89, remainder_fraction=52.1975%, Lmin=-1.40, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1600, ncalls=46125, logz=-4.83, remainder_fraction=48.9275%, Lmin=-1.34, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1640, ncalls=46125, logz=-4.77, remainder_fraction=45.8320%, Lmin=-1.27, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1680, ncalls=46125, logz=-4.72, remainder_fraction=42.9151%, Lmin=-1.23, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1720, ncalls=46125, logz=-4.67, remainder_fraction=40.0820%, Lmin=-1.17, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1760, ncalls=46125, logz=-4.63, remainder_fraction=37.4712%, Lmin=-1.13, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1800, ncalls=46125, logz=-4.59, remainder_fraction=35.0385%, Lmin=-1.10, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1840, ncalls=46125, logz=-4.55, remainder_fraction=32.6755%, Lmin=-1.04, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1880, ncalls=46125, logz=-4.52, remainder_fraction=30.6079%, Lmin=-1.00, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1890, ncalls=46125, logz=-4.51, remainder_fraction=30.0433%, Lmin=-0.99, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1920, ncalls=46125, logz=-4.49, remainder_fraction=28.4986%, Lmin=-0.95, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=1960, ncalls=46125, logz=-4.47, remainder_fraction=26.5014%, Lmin=-0.91, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=2000, ncalls=46125, logz=-4.44, remainder_fraction=24.6253%, Lmin=-0.87, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=2040, ncalls=46125, logz=-4.42, remainder_fraction=22.8879%, Lmin=-0.83, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:51:33 [ultranest] [DEBUG] iteration=2080, ncalls=46125, logz=-4.40, remainder_fraction=21.1788%, Lmin=-0.78, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=2120, ncalls=46125, logz=-4.38, remainder_fraction=19.5983%, Lmin=-0.74, Lmax=-0.03
13:51:33 [ultranest] [DEBUG] iteration=2160, ncalls=46125, logz=-4.36, remainder_fraction=18.1847%, Lmin=-0.71, Lmax=-0.01
13:51:33 [ultranest] [DEBUG] iteration=2200, ncalls=46125, logz=-4.34, remainder_fraction=16.8117%, Lmin=-0.67, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2240, ncalls=46125, logz=-4.33, remainder_fraction=15.5803%, Lmin=-0.64, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:51:34 [ultranest] [DEBUG] iteration=2280, ncalls=46125, logz=-4.31, remainder_fraction=14.3684%, Lmin=-0.60, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2320, ncalls=46125, logz=-4.30, remainder_fraction=13.2576%, Lmin=-0.58, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2360, ncalls=46125, logz=-4.29, remainder_fraction=12.2455%, Lmin=-0.55, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2400, ncalls=46125, logz=-4.28, remainder_fraction=11.3105%, Lmin=-0.52, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2430, ncalls=46125, logz=-4.27, remainder_fraction=10.5926%, Lmin=-0.50, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2440, ncalls=46125, logz=-4.27, remainder_fraction=10.3732%, Lmin=-0.49, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2480, ncalls=46125, logz=-4.26, remainder_fraction=9.5317%, Lmin=-0.47, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
13:51:34 [ultranest] [DEBUG] iteration=2520, ncalls=46125, logz=-4.25, remainder_fraction=8.7372%, Lmin=-0.45, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2560, ncalls=46125, logz=-4.24, remainder_fraction=8.0205%, Lmin=-0.43, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2600, ncalls=46125, logz=-4.23, remainder_fraction=7.3461%, Lmin=-0.41, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2640, ncalls=46125, logz=-4.23, remainder_fraction=6.7204%, Lmin=-0.38, Lmax=-0.01
13:51:34 [ultranest] [DEBUG] iteration=2680, ncalls=46125, logz=-4.22, remainder_fraction=6.1488%, Lmin=-0.37, Lmax=-0.01
13:52:16 [ultranest] [DEBUG] iteration=2712, ncalls=47212, logz=-4.22, remainder_fraction=5.7368%, Lmin=-0.35, Lmax=-0.01
13:52:17 [ultranest] [DEBUG] iteration=2720, ncalls=47212, logz=-4.21, remainder_fraction=5.6371%, Lmin=-0.35, Lmax=-0.01
13:52:57 [ultranest] [DEBUG] iteration=2739, ncalls=48306, logz=-4.21, remainder_fraction=5.4041%, Lmin=-0.34, Lmax=-0.01
13:52:57 [ultranest] [DEBUG] iteration=2760, ncalls=48306, logz=-4.21, remainder_fraction=5.1617%, Lmin=-0.33, Lmax=-0.01
13:53:35 [ultranest] [DEBUG] iteration=2763, ncalls=49391, logz=-4.21, remainder_fraction=5.1266%, Lmin=-0.33, Lmax=-0.01
13:53:35 [ultranest] [INFO] Explored until L=-0.01
13:53:35 [ultranest] [INFO] Likelihood function evaluations: 49391
13:53:37 [ultranest] [INFO] Writing samples and results to disk ...
13:53:37 [ultranest] [INFO] Writing samples and results to disk ... done
13:53:37 [ultranest] [DEBUG] did a run_iter pass!
13:53:37 [ultranest] [INFO]   logZ = -4.278 +- 0
13:53:37 [ultranest] [INFO] Effective samples strategy satisfied (ESS = 1744.1, need >400)
13:53:37 [ultranest] [INFO] Posterior uncertainty strategy is satisfied (KL: 0.44+-0.00 nat, need <0.10 nat)
13:53:37 [ultranest] [DEBUG]   conservative estimate says at least 564 live points are needed to reach dlogz goal
13:53:37 [ultranest] [DEBUG]   number of live points vary between 399 and 399, most (1647/1648 iterations) have 398
13:53:37 [ultranest] [INFO] Evidency uncertainty strategy wants 564 minimum live points (dlogz from 0.12 to 0.12, need <0.1)
13:53:37 [ultranest] [INFO]   logZ error budget: single: 0.08 bs:0.00 tail:0.05 total:0.05 required:<0.10
13:53:37 [ultranest] [INFO] Widening roots to 798 live points (have 400 already) ...
13:53:37 [ultranest] [INFO] Sampling 398 live points from prior ...
14:09:28 [ultranest] [DEBUG] ReactiveNestedSampler: dims=5+0, resume=True, log_dir=ultranest, backend=hdf5, vectorized=False, nbootstraps=30, ndraw=128..65536
14:10:10 [ultranest] [DEBUG] Testing resume consistency: [-3.33182397e-01 -2.00685384e-01  0.00000000e+00  4.24530696e-01
  5.48873217e-01  6.50689786e-01  3.33540057e-01  5.45923457e-01
  1.02170218e+02 -2.90225357e+00  5.95206936e-01  8.00372102e+02
  2.41073210e+02]: u=[0.4245307  0.54887322 0.65068979 0.33354006 0.54592346] -> p=[ 1.02170218e+02 -2.90225357e+00  5.95206936e-01  8.00372102e+02
  2.41073210e+02] -> L=-0.20068538434380567
14:10:44 [ultranest] [INFO] Resuming from 3695 stored points
14:10:44 [ultranest] [DEBUG] run_iter dlogz=0.1, dKL=0.1, frac_remain=0.05, Lepsilon=0.0100, min_ess=400
14:10:44 [ultranest] [DEBUG] max_iters=-1, max_ncalls=-1, max_num_improvement_loops=-1, min_num_live_points=400, cluster_num_live_points=40
14:10:44 [ultranest] [DEBUG] minimal_widths_sequence: [(-inf, 400.0), (inf, 400.0)]
14:10:54 [ultranest] [DEBUG] iteration=0, ncalls=49391, logz=-inf, remainder_fraction=100.0000%, Lmin=-3503.33, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=40, ncalls=49391, logz=-266.58, remainder_fraction=100.0000%, Lmin=-243.21, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=80, ncalls=49391, logz=-83.38, remainder_fraction=100.0000%, Lmin=-76.16, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=90, ncalls=49391, logz=-66.15, remainder_fraction=100.0000%, Lmin=-58.15, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=120, ncalls=49391, logz=-33.22, remainder_fraction=100.0000%, Lmin=-28.08, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=160, ncalls=49391, logz=-28.58, remainder_fraction=100.0000%, Lmin=-24.92, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=180, ncalls=49391, logz=-27.11, remainder_fraction=100.0000%, Lmin=-22.77, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=200, ncalls=49391, logz=-25.23, remainder_fraction=100.0000%, Lmin=-21.21, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=240, ncalls=49391, logz=-22.32, remainder_fraction=100.0000%, Lmin=-18.53, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=280, ncalls=49391, logz=-20.25, remainder_fraction=100.0000%, Lmin=-16.54, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=320, ncalls=49391, logz=-18.41, remainder_fraction=99.9999%, Lmin=-14.84, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=360, ncalls=49391, logz=-16.73, remainder_fraction=99.9996%, Lmin=-13.00, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=400, ncalls=49391, logz=-15.23, remainder_fraction=99.9980%, Lmin=-11.65, Lmax=-0.55
14:10:55 [ultranest] [DEBUG] iteration=440, ncalls=49391, logz=-14.11, remainder_fraction=99.9939%, Lmin=-10.71, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=450, ncalls=49391, logz=-13.87, remainder_fraction=99.9922%, Lmin=-10.49, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=480, ncalls=49391, logz=-13.26, remainder_fraction=99.9863%, Lmin=-10.04, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=520, ncalls=49391, logz=-12.53, remainder_fraction=99.9729%, Lmin=-9.23, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=560, ncalls=49391, logz=-11.89, remainder_fraction=99.9464%, Lmin=-8.73, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=600, ncalls=49391, logz=-11.30, remainder_fraction=99.9038%, Lmin=-7.96, Lmax=-0.46
14:10:55 [ultranest] [DEBUG] iteration=640, ncalls=49391, logz=-10.72, remainder_fraction=99.8373%, Lmin=-7.43, Lmax=-0.45
14:10:55 [ultranest] [DEBUG] iteration=680, ncalls=49391, logz=-10.11, remainder_fraction=99.7050%, Lmin=-6.68, Lmax=-0.45
14:10:55 [ultranest] [DEBUG] iteration=720, ncalls=49391, logz=-9.59, remainder_fraction=99.5115%, Lmin=-6.20, Lmax=-0.45
14:10:55 [ultranest] [DEBUG] iteration=760, ncalls=49391, logz=-9.15, remainder_fraction=99.2361%, Lmin=-5.73, Lmax=-0.39
14:10:55 [ultranest] [DEBUG] iteration=800, ncalls=49391, logz=-8.72, remainder_fraction=98.8527%, Lmin=-5.33, Lmax=-0.33
14:10:55 [ultranest] [DEBUG] iteration=840, ncalls=49391, logz=-8.30, remainder_fraction=98.2992%, Lmin=-4.77, Lmax=-0.33
14:10:55 [ultranest] [DEBUG] iteration=880, ncalls=49391, logz=-7.91, remainder_fraction=97.5320%, Lmin=-4.38, Lmax=-0.33
14:10:55 [ultranest] [DEBUG] iteration=900, ncalls=49391, logz=-7.72, remainder_fraction=97.0265%, Lmin=-4.18, Lmax=-0.33
14:10:55 [ultranest] [DEBUG] iteration=920, ncalls=49391, logz=-7.54, remainder_fraction=96.4367%, Lmin=-3.97, Lmax=-0.26
14:10:56 [ultranest] [DEBUG] iteration=960, ncalls=49391, logz=-7.20, remainder_fraction=94.9681%, Lmin=-3.62, Lmax=-0.26
14:10:56 [ultranest] [DEBUG] iteration=1000, ncalls=49391, logz=-6.91, remainder_fraction=93.3339%, Lmin=-3.41, Lmax=-0.26
14:10:56 [ultranest] [DEBUG] iteration=1040, ncalls=49391, logz=-6.65, remainder_fraction=91.3085%, Lmin=-3.16, Lmax=-0.26
14:10:56 [ultranest] [DEBUG] iteration=1080, ncalls=49391, logz=-6.41, remainder_fraction=89.3956%, Lmin=-2.91, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1120, ncalls=49391, logz=-6.21, remainder_fraction=87.2515%, Lmin=-2.80, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1160, ncalls=49391, logz=-6.03, remainder_fraction=84.8927%, Lmin=-2.59, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1170, ncalls=49391, logz=-5.99, remainder_fraction=84.2771%, Lmin=-2.50, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1200, ncalls=49391, logz=-5.86, remainder_fraction=82.1579%, Lmin=-2.38, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1240, ncalls=49391, logz=-5.71, remainder_fraction=79.2065%, Lmin=-2.21, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1280, ncalls=49391, logz=-5.57, remainder_fraction=75.9271%, Lmin=-2.08, Lmax=-0.21
14:10:56 [ultranest] [DEBUG] iteration=1320, ncalls=49391, logz=-5.44, remainder_fraction=72.5026%, Lmin=-1.94, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1360, ncalls=49391, logz=-5.32, remainder_fraction=68.9207%, Lmin=-1.81, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1400, ncalls=49391, logz=-5.21, remainder_fraction=65.3345%, Lmin=-1.71, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1440, ncalls=49391, logz=-5.12, remainder_fraction=61.7966%, Lmin=-1.64, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1480, ncalls=49391, logz=-5.04, remainder_fraction=58.4329%, Lmin=-1.56, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1520, ncalls=49391, logz=-4.96, remainder_fraction=55.3254%, Lmin=-1.47, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1560, ncalls=49391, logz=-4.89, remainder_fraction=52.1975%, Lmin=-1.40, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1600, ncalls=49391, logz=-4.83, remainder_fraction=48.9275%, Lmin=-1.34, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1640, ncalls=49391, logz=-4.77, remainder_fraction=45.8320%, Lmin=-1.27, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1680, ncalls=49391, logz=-4.72, remainder_fraction=42.9151%, Lmin=-1.23, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1720, ncalls=49391, logz=-4.67, remainder_fraction=40.0820%, Lmin=-1.17, Lmax=-0.03
14:10:56 [ultranest] [DEBUG] iteration=1760, ncalls=49391, logz=-4.63, remainder_fraction=37.4712%, Lmin=-1.13, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1800, ncalls=49391, logz=-4.59, remainder_fraction=35.0385%, Lmin=-1.10, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1840, ncalls=49391, logz=-4.55, remainder_fraction=32.6755%, Lmin=-1.04, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1880, ncalls=49391, logz=-4.52, remainder_fraction=30.6079%, Lmin=-1.00, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1890, ncalls=49391, logz=-4.51, remainder_fraction=30.0433%, Lmin=-0.99, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1920, ncalls=49391, logz=-4.49, remainder_fraction=28.4986%, Lmin=-0.95, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=1960, ncalls=49391, logz=-4.47, remainder_fraction=26.5014%, Lmin=-0.91, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=2000, ncalls=49391, logz=-4.44, remainder_fraction=24.6253%, Lmin=-0.87, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=2040, ncalls=49391, logz=-4.42, remainder_fraction=22.8879%, Lmin=-0.83, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=2080, ncalls=49391, logz=-4.40, remainder_fraction=21.1788%, Lmin=-0.78, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=2120, ncalls=49391, logz=-4.38, remainder_fraction=19.5983%, Lmin=-0.74, Lmax=-0.03
14:10:57 [ultranest] [DEBUG] iteration=2160, ncalls=49391, logz=-4.36, remainder_fraction=18.1847%, Lmin=-0.71, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2200, ncalls=49391, logz=-4.34, remainder_fraction=16.8117%, Lmin=-0.67, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2240, ncalls=49391, logz=-4.33, remainder_fraction=15.5803%, Lmin=-0.64, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
14:10:57 [ultranest] [DEBUG] iteration=2280, ncalls=49391, logz=-4.31, remainder_fraction=14.3684%, Lmin=-0.60, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2320, ncalls=49391, logz=-4.30, remainder_fraction=13.2576%, Lmin=-0.58, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2360, ncalls=49391, logz=-4.29, remainder_fraction=12.2455%, Lmin=-0.55, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2400, ncalls=49391, logz=-4.28, remainder_fraction=11.3105%, Lmin=-0.52, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2430, ncalls=49391, logz=-4.27, remainder_fraction=10.5926%, Lmin=-0.50, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2440, ncalls=49391, logz=-4.27, remainder_fraction=10.3732%, Lmin=-0.49, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2480, ncalls=49391, logz=-4.26, remainder_fraction=9.5317%, Lmin=-0.47, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] clustering found some stray points [need_accept=False] (array([1, 2]), array([399,   1]))
14:10:57 [ultranest] [DEBUG] iteration=2520, ncalls=49391, logz=-4.25, remainder_fraction=8.7372%, Lmin=-0.45, Lmax=-0.01
14:10:57 [ultranest] [DEBUG] iteration=2560, ncalls=49391, logz=-4.24, remainder_fraction=8.0205%, Lmin=-0.43, Lmax=-0.01
14:10:58 [ultranest] [DEBUG] iteration=2600, ncalls=49391, logz=-4.23, remainder_fraction=7.3461%, Lmin=-0.41, Lmax=-0.01
14:10:58 [ultranest] [DEBUG] iteration=2640, ncalls=49391, logz=-4.23, remainder_fraction=6.7204%, Lmin=-0.38, Lmax=-0.01
14:10:58 [ultranest] [DEBUG] iteration=2680, ncalls=49391, logz=-4.22, remainder_fraction=6.1488%, Lmin=-0.37, Lmax=-0.01
14:10:58 [ultranest] [DEBUG] iteration=2720, ncalls=49391, logz=-4.21, remainder_fraction=5.6371%, Lmin=-0.35, Lmax=-0.01
14:10:58 [ultranest] [DEBUG] iteration=2760, ncalls=49391, logz=-4.21, remainder_fraction=5.1617%, Lmin=-0.33, Lmax=-0.01
14:10:58 [ultranest] [INFO] Explored until L=-0.01
14:10:58 [ultranest] [INFO] Likelihood function evaluations: 49391
14:10:59 [ultranest] [INFO] Writing samples and results to disk ...
14:11:00 [ultranest] [INFO] Writing samples and results to disk ... done
14:11:00 [ultranest] [DEBUG] did a run_iter pass!
14:11:00 [ultranest] [INFO]   logZ = -4.074 +- 0
14:11:00 [ultranest] [INFO] Effective samples strategy satisfied (ESS = 1744.1, need >400)
14:11:00 [ultranest] [INFO] Posterior uncertainty strategy is satisfied (KL: 0.44+-0.00 nat, need <0.10 nat)
14:11:00 [ultranest] [INFO] Evidency uncertainty strategy is satisfied (dlogz=0.05, need <0.1)
14:11:00 [ultranest] [INFO]   logZ error budget: single: 0.08 bs:0.00 tail:0.05 total:0.05 required:<0.10
14:11:00 [ultranest] [INFO] Widening roots to 798 live points (have 400 already) ...
14:11:00 [ultranest] [INFO] Sampling 398 live points from prior ...

Same happened with 0190fcce version (after #43 was merged)

I will try on 3.3.0 as well, but I will have to limit the number of nodes to avoid #42 bug, so it will take longer...

JohannesBuchner commented 3 years ago

Do you use vectorized=True?

If so, can you double check that your transform function returns a 2d array when called with one live point, i.e.,

transform(np.random.uniform(size=(1, ndim)).shape == (1, nparams)

It seems recv_samplesv in this line https://github.com/JohannesBuchner/UltraNest/blob/master/ultranest/integrator.py#L1356 has inconsistent dimensionality (can you print it?).

SmirnGreg commented 3 years ago
  1. I don't, I have vectorized=False as in default call of ReactiveNestedSampler
  2. Here is my transform function
    class UltraNestFitter():
    ...
    def rescale(self, cube):
        params = np.empty_like(cube)
        for i, parameter in enumerate(self.parameters):
            params[i] = cube[i] * (parameter.max - parameter.min) + parameter.min
        return params

    It is a method which is passed as transform=self.rescale. It is adopted from

    def my_prior_transform(cube):
    params = cube.copy()
    lo = 400
    hi = 800
    params[0] = cube[0] * (hi - lo) + lo

    From your examples.

This is a corresponding test. Transform works for both 1d and 2d arrays. Should it return 2d arrays when it is called from one point? I missed that.

def test_transform_function():
    parameters = [
        Parameter("a", min=10, max=20),
        Parameter("b", min=-5, max=15)
    ]
    fitter = UltraNestFitter(
        lnprob=lambda params: -((params[0] - 15) ** 2 + params[1] ** 2),
        parameters=parameters,
        log_dir="transform_test"
    )
    assert pytest.approx(fitter.transform(np.array([0.5, 0.2]))) == [15, -1]
    assert pytest.approx(fitter.transform(np.array([0.4, 0.8]))) == [14, 11]
    assert pytest.approx(fitter.transform(np.array([[0.5, 0.4], [0.2, 0.8]]))) == np.array([[15, 14], [-1, 11]])
    assert pytest.approx(fitter.transform([0.5, 0.2])) == [15, -1]

    assert fitter.transform(np.random.uniform(size=(2, 1))).shape == (2, 1)
    assert fitter.transform(np.random.uniform(size=(1, 2))).shape == (1, 2)

In this test, the last line will fail with

    def rescale(self, cube):
        params = np.empty_like(cube)
        for i, parameter in enumerate(self.parameters):
>           params[i] = cube[i] * (parameter.max - parameter.min) + parameter.min
E           IndexError: index 1 is out of bounds for axis 0 with size 1
JohannesBuchner commented 3 years ago

No, that's fine, the function is vectorized (with a loop) here: https://github.com/JohannesBuchner/UltraNest/blob/master/ultranest/integrator.py#L459

That's a really odd bug. can you print recv_samplesv, num_live_points_todo, and other variables?

JohannesBuchner commented 3 years ago

I tried to reproduce with:

PYTHONPATH=. mpiexec -np 12 python3 examples/testloggamma.py --reactive --x_dim 2 --num_live_points=81

which goes into this part of the code:

[ultranest] Widening roots to 160 live points (have 81 already) ...
[ultranest] Sampling 40 live points from prior ...

I was not able to reproduce the crash however.

SmirnGreg commented 3 years ago

The new run crashed immediately.

I added to integrator.py around line 1350

            if self.use_mpi:
                recv_samples = self.comm.gather(active_u, root=0)
                recv_samplesv = self.comm.gather(active_v, root=0)
                recv_likes = self.comm.gather(active_logl, root=0)
                recv_samples = self.comm.bcast(recv_samples, root=0)
                recv_samplesv = self.comm.bcast(recv_samplesv, root=0)
                recv_likes = self.comm.bcast(recv_likes, root=0)
                with open(f"log_{self.mpi_rank}.txt", 'a') as fff:
                    print(f"{self.mpi_rank}: TEST #44:\nrecv_samples=%s\nrecv_samplesv=%s\nu=%s\nv=%s\n\n" % (recv_samples, recv_samplesv, active_u, active_v), file=fff)
                    print(num_live_points_todo, num_live_points_missing, "\n\n\n\n\n\n\n", file=fff)
                active_u = np.concatenate(recv_samples, axis=0)
                active_v = np.concatenate(recv_samplesv, axis=0)
                active_logl = np.concatenate(recv_likes, axis=0)

I attach logs from rank0, rank1, and rank1000 > min_num_living_points log_0.txt log_1.txt log_1000.txt

SmirnGreg commented 3 years ago

When I had just 2 nodes and 80 cores, this worked fine. Seems that the issue happens when the core has nothing to do and broadcasts an empty array..? I am new to mpi and still suffer reading the mpi code 😕 log_0.txt log_1.txt log_79.txt

JohannesBuchner commented 3 years ago

OK, I see what the problem is.

Some nodes have one or more points and call for them, and they produce 2d arrays for active_v, as expected

Some nodes receive no work. They still call transform(), which is a vectorized wrapper call of the user-defined tranform function. It is defined here: https://github.com/JohannesBuchner/UltraNest/blob/6461f108e4527b36ad461c245b62d919da6429d5/ultranest/utils.py#L127 That function does a loop over the proposed points, calls the user transform, and returns the list of results, transformed into a numpy array.

The numpy array is 2d if there is one point or more, but there is a problem when this function is called with an empty list of points. Then np.asarray cannot figure out the dimensionality it is supposed to produce, so it makes np.array([], dtype=float).

JohannesBuchner commented 3 years ago

Here are two solutions I can think of:

a) we make vectorize() aware what array shape should be returned. That would be vectorize().reshape((-1, nparams)) for where self.transform is assigned.

b) we change the code here before concatenate to strip away empty arrays. That is, active_v = np.concatenate([v for v in recv_samplesv if v.size > 0], axis=0)

This scenario of being short of points is not occuring in other places of the code base.

I'm slightly leaning towards b).

SmirnGreg commented 3 years ago

active_v = np.concatenate([v for v in recv_samplesv if v], axis=0) is more pythonic, as empty collections are falsy and non-empty are truthy. I will check it with this patch now.

PS I forgot numpy is not pythonic =/

In [1]: import numpy as np

In [2]: a = np.array([1,2,3])

In [3]: bool(a)
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
<ipython-input-3-39666bfb5ad8> in <module>
----> 1 bool(a)

ValueError: The truth value of an array with more than one element is ambiguous. Use a.any() or a.all()
JohannesBuchner commented 3 years ago

IIRC numpy will complain that the truth of an array with multiple values is undefined.

JohannesBuchner commented 3 years ago

Actually, I think a better patch would be:

num_live_points_todo = ...

if num_live_points_todo > 0:
            active_u = np.random.uniform(size=(num_live_points_todo, self.x_dim))
            active_v = self.transform(active_u)
            active_logl = self.loglike(active_v)
else:
            active_u = np.empty((0, self.x_dim))
            active_v = np.empty((0, self.num_params))
            active_logl = np.empty((0,))

I imagine there could be transforms and loglikelihoods that involve some setup cost, and the above avoids calling them.

While the list comprehension would be pythonic and nice, doing such loops in python can be slow if there are thousands of arrays involved. The above makes my hack on the concatenate input obsolete.

SmirnGreg commented 3 years ago

Will you commit this yourself? I agree this is better.

JohannesBuchner commented 3 years ago

I still cannot reproduce the bug, so if you can make a (new) PR and test that it solves the problem, that would be better.

JohannesBuchner commented 3 years ago

closed via #45