CPNest resuming on python3.6

[GregoryAshton]

In the bilby development CI, we are finding that basic examples using cpnest are breaking on python3.6 with

17:29 bilby INFO    : Using sampler Cpnest with kwargs {'verbose': 1, 'nthreads': 1, 'nlive': 100, 'maxmcmc': 1000, 'seed': None, 'poolsize': 100, 'nhamiltonian': 0, 'resume': True, 'output': 'outdir/cpnest_label/', 'proposals': None, 'n_periodic_checkpoint': 8000}
2020-01-13, 17:29:59 - CPNest  : Setting verbosity to 1
2020-01-13, 17:29:59 - CPNest  : Running with 1 parallel threads
CPNEST: populate samplers: 100%|████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 100/100 [00:00<00:00, 106.83it/s]
CPNEST: populate samplers:  77%|███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████▊                                                  | 77/100 [00:00<00:04,  5.20it/s]
2020-01-13, 17:30:00 - CPNest  : Checkpointing nested sampling
======================================================================
ERROR: test_run_cpnest (__main__.TestRunningSamplers)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "test/sampler_test.py", line 529, in test_run_cpnest
    nlive=100, save=False, checkpoint=False)
  File "/home/user1/anaconda3/envs/python36/lib/python3.6/site-packages/bilby-0.6.3-py3.6.egg/bilby/core/sampler/__init__.py", line 176, in run_sampler
    result = sampler.run_sampler()
  File "/home/user1/anaconda3/envs/python36/lib/python3.6/site-packages/bilby-0.6.3-py3.6.egg/bilby/core/sampler/cpnest.py", line 108, in run_sampler
    out.run()
  File "/home/user1/anaconda3/envs/python36/lib/python3.6/site-packages/cpnest/cpnest.py", line 199, in run
    self.NS.nested_sampling_loop()
  File "/home/user1/anaconda3/envs/python36/lib/python3.6/site-packages/cpnest/NestedSampling.py", line 330, in nested_sampling_loop
    self.checkpoint()
  File "/home/user1/anaconda3/envs/python36/lib/python3.6/site-packages/cpnest/NestedSampling.py", line 370, in checkpoint
    pickle.dump(self, f)
TypeError: can't pickle _thread.RLock objects

The same example pass with python 3.7 which leads me to believe this isn't an issue with the bilby implementation or the specific example. It seems to be that the CPNest checkpoint fails, but only in python3.6.

[GregoryAshton]

I should have added. This was run on current master a57812b and the released 0.9.8 with the issue appearing identical in both.

[GregoryAshton]

Passing resume=False resolved the issue temporarily.

[ColmTalbot]

This looks relevant https://stackoverflow.com/a/46423924/11020396

You need to change from queue import Queue to from multiprocessing import Queue.

The root reason is the former Queue is designed for threading module Queue while the latter is for multiprocessing.Process module.

[ColmTalbot]

I dug a little deeper into this and it looks like the logger being pickled might be causing this.

I've added a slightly modified version of what's being pickled below (I just removed a bunch of the live points). The data saved for the logger includes the manager which is removed for all the other classes.

Related SO question: https://stackoverflow.com/questions/3375443/how-to-pickle-loggers

In [11]: self.__getstate__()                                                                                                                                                                        
Out[11]: 
{'logger': <CPNestLogger CPNest (INFO)>,
 'prior_sampling': False,
 'seed': 1234,
 'verbose': 2,
 'acceptance': 0.9956521739130435,
 'accepted': 229,
 'rejected': 1,
 'queue_counter': 0,
 'Nlive': 100,
 'params': [LivePoint(['mass_ratio', 'chirp_mass'], d=array('d', [0.5044459070714788, 25.189222721103352]), logL=516.638862, logP=-2.197225),
  LivePoint(['mass_ratio', 'chirp_mass'], d=array('d', [0.6277911070445525, 24.83662655837443]), logL=4030.564187, logP=-2.197225)],
 'n_periodic_checkpoint': 8000,
 'tolerance': 0.1,
 'condition': 4853.510433987368,
 'worst': array([0]),
 'iteration': 232,
 'nested_samples': [LivePoint(['mass_ratio', 'chirp_mass'], d=array('d', [0.9312303026289579, 25.037352392441207]), logL=-12397.401774, logP=-2.197225),
  LivePoint(['mass_ratio', 'chirp_mass'], d=array('d', [0.39083762526445087, 20.842072513752964]), logL=-630.415436, logP=-2.197225)],
 'logZ': None,
 'state': <cpnest.NestedSampling._NSintegralState at 0x1c1dceac88>,
 'output_folder': 'outdir/cpnest_fast_tutorial/',
 'output_file': 'outdir/cpnest_fast_tutorial/chain_100_1234.txt',
 'evidence_file': 'outdir/cpnest_fast_tutorial/chain_100_1234.txt_evidence.txt',
 'resume_file': 'outdir/cpnest_fast_tutorial/nested_sampler_resume.pkl',
 'initialised': True,
 'jumps': 72,
 'llmax': 4218.639557259948,
 'llmin': -630.4154357670313}

In [12]: self.__getstate__()['logger'].__dict__                                                                                                                                                     
Out[12]: 
{'filters': [],
 'name': 'CPNest',
 'level': 20,
 'parent': <RootLogger root (WARNING)>,
 'propagate': True,
 'handlers': [<StreamHandler <stderr> (INFO)>,
  <FileHandler /Users/ctal0001/modules/bilby/examples/gw_examples/injection_examples/outdir/cpnest_fast_tutorial/cpnest.log (INFO)>],
 'disabled': False,
 '_cache': {},
 'fmt': '%(asctime)s - %(name)-8s: %(message)s',
 'date_fmt': '%Y-%m-%d, %H:%M:%S',
 'levels': ['CRITICAL', 'WARNING', 'INFO', 'DEBUG'],
 'manager': <logging.Manager at 0x104e927f0>}