Many test failures/errors on Python 3.4b1

[cgohlke]

Using tables-3.0.0 on Windows with Python 3.4b1 64 bit, numpy-MKL-1.8.0, and numexpr-2.2.2, tables.test() fails badly. Note that numpy and numexpr pass all tests on Python 3.4, and also tables on Python 3.3 passes all tests using the exactly the same compiler, compiler options, and C libraries. Looks like files are not getting closed.

-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
PyTables version:  3.0.0
HDF5 version:      1.8.11
NumPy version:     1.8.0
Numexpr version:   2.2.2 (using VML/MKL 11.1.1)
Zlib version:      1.2.8 (in Python interpreter)
LZO version:       2.06 (Aug 12 2011)
BZIP2 version:     1.0.6 (6-Sept-2010)
Blosc version:     1.2.3 (2013-05-17)
Cython version:    0.19.2
Python version:    3.4.0b1 (v3.4.0b1:3405dc9a6afa, Nov 24 2013, 19:18:21) [MSC v.1600 64 bit (AMD64)]
Byte-ordering:     little
Detected cores:    8
Default encoding:  utf-8
-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=

............EE..............................................................................................................................................................................E..E....................FE.....FEFE.FE...............EEEEEEEEEEEE..FE....EEEEFEFEFE...............................................................................................................................................X:\Python34\lib\site-packages\tables\utils.py:150: DeprecationWarning: The Windows bytes API has been deprecated, use Unicode filenames instead
  if not os.access(filename, os.F_OK):
X:\Python34\lib\genericpath.py:30: DeprecationWarning: The Windows bytes API has been deprecated, use Unicode filenames instead
  st = os.stat(path)
X:\Python34\lib\site-packages\tables\utils.py:154: DeprecationWarning: The Windows bytes API has been deprecated, use Unicode filenames instead
  if not os.access(filename, os.R_OK):
.............................EE......EE.EE.................X:\Python34\lib\site-packages\tables\conditions.py:447: DeprecationWarning: using `oa_ndim == 0` when `op_axes` is NULL is deprecated. Use `oa_ndim == -1` or the MultiNew iterator for NumPy <1.8 compatibility
  return func(*args)
E........................FEEEFEEEFEEEFEFEFEFEFEFEFEFEFEEEEFEFEFEEEEFEFEFFFFF.......FEFEFE.FEFEFE.FEFEFE.FEFEFE.FEFE..FEFEFE...FEFEFE..........E................................................................................EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE...........................EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE........................................................................................EEEE...............................................EEEEE............................EEE...EE.EEEEEEEEEEEEEEE.................FEE.........................EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE.EEEE...EEEE............................................................................................EEEEEEEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEEEEE.EEEEEEE........EEFEFEFEFEFEFEFEFEFEFE..FEFEEFEFEFEFEFEFEFE..FEFEFEFEFEFEFEFEFEFE..FEFEEFEFEFEFEFEFEFE...................................................................................................................................................................................................................EEEEEEEEEEEEEEEEEEEEE..............EEEEEEE..............EEEEEEE....................................................................................................................................................................................EEEE....EE.....................................EEEEEEEEEEEEEEEEEEEE....................EEEEE.....................................................................................................................................................................................FEEEEE................................................................................................................................................................................................................................................E..EEEE........................EEEEEEEEEEEEEEEEEEEEFEEEFEFEFE.................FEFEFEFEFEFEFEFEFEFEFEEFEFEFEFEFEFE.EEEEEFEFEFEFEEEFEFEFEEEEEEEEFEEEFEFEFEEEEEEFEFEFEFEFEFEFEFEFFFFFFFFFFFFFFFFFFFFFEFEFEFEFEFEFEFEFEFEFE.FEFEFEFE.......................................EEEE...EEEE...................FE..........EE.......................................................FFFE......FFFE.EEEEEEEE..EE...FFF.FFF.FFFFFFFFFFFFFFFFEE......EEEFEFE.EEEEEEEEEEEEE...EEEE..............EE............................................................................................................................................................................................................................................................................FEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFE........................................FEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFE........................................FEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEFEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE........................................EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE.....................................................EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEX:\Python34\lib\site-packages\tables\expression.py:460: DeprecationWarning: using `oa_ndim == 0` when `op_axes` is NULL is deprecated. Use `oa_ndim == -1` or the MultiNew iterator for NumPy <1.8 compatibility
X:\Python34\lib\site-packages\tables\expression.py:616: DeprecationWarning: using `oa_ndim == 0` when `op_axes` is NULL is deprecated. Use `oa_ndim == -1` or the MultiNew iterator for NumPy <1.8 compatibility
X:\Python34\lib\site-packages\tables\expression.py:628: DeprecationWarning: using a non-integer number instead of an integer will result in an error in the future
.....EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE.
======================================================================
ERROR: test10c_copyAttributes (tables.tests.test_attributes.NotCloseCreate)
Checking copying attributes during group copies
----------------------------------------------------------------------
Traceback (most recent call last):
  File "X:\Python34\lib\site-packages\tables\tests\test_attributes.py", line 51, in tearDown
    self.fileh.close()
  File "X:\Python34\lib\site-packages\tables\file.py", line 2486, in close
    self.root._f_close()
  File "X:\Python34\lib\site-packages\tables\group.py", line 955, in _f_close
    self._g_close_descendents()
  File "X:\Python34\lib\site-packages\tables\group.py", line 903, in _g_close_descendents
    lambda path: alivenodes[path])
  File "X:\Python34\lib\site-packages\tables\group.py", line 884, in closenodes
    node._f_close()
AttributeError: 'NoneType' object has no attribute '_f_close'

<snip>

======================================================================
ERROR: test_l0320 (tables.tests.common.SIMO3TDTestCase)
Testing ``c_float16``.test_l0320
----------------------------------------------------------------------
Traceback (most recent call last):
  File "X:\Python34\lib\site-packages\tables\tests\common.py", line 154, in newmethod
    return oldmethod(self, *args, **kwargs)
  File "X:\Python34\lib\site-packages\tables\tests\test_queries.py", line 374, in test_method
    self.createIndexes(colname, ncolname, 'c_idxextra')
  File "X:\Python34\lib\site-packages\tables\tests\test_queries.py", line 270, in createIndexes
    _blocksizes=small_blocksizes, _testmode=True)
  File "X:\Python34\lib\site-packages\tables\table.py", line 3628, in create_index
    tmp_dir, _blocksizes, _verbose)
  File "X:\Python34\lib\site-packages\tables\table.py", line 389, in _column__create_index
    blocksizes=blocksizes)
  File "X:\Python34\lib\site-packages\tables\index.py", line 400, in __init__
    super(Index, self).__init__(parentnode, name, title, new, filters)
  File "X:\Python34\lib\site-packages\tables\group.py", line 241, in __init__
    super(Group, self).__init__(parentnode, name, _log)
  File "X:\Python34\lib\site-packages\tables\node.py", line 275, in __init__
    self._g_post_init_hook()
  File "X:\Python34\lib\site-packages\tables\index.py", line 554, in _g_post_init_hook
    self.create_temp()
  File "X:\Python34\lib\site-packages\tables\index.py", line 1015, in create_temp
    ".tmp", "pytables-", self.tmp_dir)
  File "X:\Python34\lib\tempfile.py", line 268, in mkstemp
    return _mkstemp_inner(dir, prefix, suffix, flags)
  File "X:\Python34\lib\tempfile.py", line 198, in _mkstemp_inner
    fd = _os.open(file, flags, 0o600)
OSError: [Errno 24] Too many open files: 'C:\\Users\\gohlke\\AppData\\Local\\Temp\\pytables-dkgr7if4.tmp'

<snip>

======================================================================
ERROR: test11a (tables.tests.test_indexvalues.MINSV3aTestCase)
Checking selecting values from an Index via read_coordinates()
----------------------------------------------------------------------
Traceback (most recent call last):
  File "X:\Python34\lib\site-packages\tables\tests\test_indexvalues.py", line 53, in setUp
  File "X:\Python34\lib\site-packages\tables\file.py", line 251, in open_file
    return File(filename, mode, title, root_uep, filters, **kwargs)
  File "X:\Python34\lib\site-packages\tables\file.py", line 527, in __init__
    self._g_new(filename, mode, **params)
  File "hdf5extension.pyx", line 463, in tables.hdf5extension.File._g_new (tables\hdf5extension.c:4421)
tables.exceptions.HDF5ExtError: HDF5 error back trace

  File "..\..\hdf5-1.8.11\src\H5F.c", line 1500, in H5Fcreate
    unable to create file
  File "..\..\hdf5-1.8.11\src\H5F.c", line 1282, in H5F_open
    unable to open file: time = Fri Dec 06 15:51:39 2013
, name = 'C:\Users\gohlke\AppData\Local\Temp\tmp5ox45gfw.h5', tent_flags = 13
  File "..\..\hdf5-1.8.11\src\H5FD.c", line 987, in H5FD_open
    open failed
  File "..\..\hdf5-1.8.11\src\H5FDsec2.c", line 343, in H5FD_sec2_open
    unable to open file: name = 'C:\Users\gohlke\AppData\Local\Temp\tmp5ox45gfw.h5', errno = 24, error message = 'Too many open files', flags = 13, o_flags = 302

End of HDF5 error back trace

Unable to open/create file 'C:\Users\gohlke\AppData\Local\Temp\tmp5ox45gfw.h5'

<snip>

======================================================================
FAIL: test07d_renameLeaf (tables.tests.test_basics.NodeCacheOpenFile)
Checking renaming a Group under a nested group
----------------------------------------------------------------------
Traceback (most recent call last):
  File "X:\Python34\lib\site-packages\tables\tests\common.py", line 154, in newmethod
    return oldmethod(self, *args, **kwargs)
  File "X:\Python34\lib\site-packages\tables\tests\test_basics.py", line 580, in test07d_renameLeaf
    node = fileh.root.agroup.anarray3
  File "X:\Python34\lib\site-packages\tables\group.py", line 813, in __getattr__
    return self._f_get_child(name)
  File "X:\Python34\lib\site-packages\tables\group.py", line 686, in _f_get_child
    return self._v_file._get_node(childPath)
  File "X:\Python34\lib\site-packages\tables\file.py", line 1302, in _get_node
    "stale weak reference to dead node ``%s``" % nodePath
AssertionError: stale weak reference to dead node ``/agroup``

<snip>

----------------------------------------------------------------------
Ran 5392 tests in 66.252s

FAILED (failures=796, errors=2904)
Closing remaining open files: C:\Users\gohlke\AppData\Local\Temp\pytables-kqser216.tmp... Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "X:\Python34\lib\site-packages\tables\group.py", line 884, in closenodes
AttributeError: 'NoneType' object has no attribute '_f_close'

[avalentino]

Thanks @cgohlke, I will give it a look ASAP.

[avalentino]

OK, IMO this is a serious bug that is triggered by the new object finalization strategy (see [1], [2]) introduced in Python 3.4.
In particular our node cache machinery relies on the fact that a node can be safely resurrected within the __del__ method and that the __del__ method can be run several times (any time that the object is about to be destroyed).

If my understanding is correct, with the new finalization scheme implemented in Python 3.4 "an object's finalizer is always called exactly once, even if it was resurrected afterwards".

If my understanding of the problem is correct we need a complete redesign of the node cache, the new implementation should not rely on the __del__ method at all.

I made some attempt to use the weak ref callbacks [4] instead of the __del__ method nut with no luck.

Any help/hint to fix this issue is very welcome.

[1] http://docs.python.org/3.4/whatsnew/3.4.html#pep-442-safe-object-finalization
[2] http://www.python.org/dev/peps/pep-0442/
[3] http://www.python.org/dev/peps/pep-0442/#predictability
[4] http://docs.python.org/3.4/library/weakref.html#weakref.ref

[scopatz]

Hi @avalentino, I agree that this is a major issue. It is probably worth a version v3.1 once it is fixed. Have you put your attempts to tackle this somewhere. Weak refs were what sprang to mind immediately for me too and I agree that we need to move away from del now that the semantics have changed. The importance of this should not be understated.

[avalentino]

Hi @scopatz,

Hi @avalentino, I agree that this is a major issue. It is probably worth a version v3.1 once it is fixed.

I totally agree.
Unfortunately at the moment I do not have a clear idea about how to fix the issue.

Have you put your attempts to tackle this somewhere. Weak refs were what sprang to mind immediately for me too and I agree that we need to move away from del now that the semantics have changed. The importance of this should not be understated.

Well, the idea is to add a callback to weakrefs stored in the File._aliveNodes dictionary so that the callback can take in charge of moving nodes to the File._deadNodes dictionary before they are deleted (in this case the __del__ should not be called until the object is actually destroyed).

Unfortunately it seems that we cannot rely on the fact that the weakref callback is called before the object finalizer, the __del__ method, (see [1]) even if PEP 442 seems to ensure it (see [2]).

A solution like the one described above would have, if we are able to get a working version, would have a relatively small impact on the code.

[1] https://gist.github.com/avalentino/8103133
[2] http://www.python.org/dev/peps/pep-0442/#disposal-of-cyclic-isolates

[avalentino]

Closed by #311.