/proc/meminfo left open by functions module (GNU/Linux)

[sadielbartholomew]

Running the test test_dsg.py I notice a ResourceWarning implying a file has been destroyed without first being closed:

Run date: 2020-06-17 02:30:50.310417
Platform: Linux-4.15.0-54-generic-x86_64-with-debian-buster-sid
HDF5 library: 1.10.4
netcdf library: 4.6.3
udunits2 library: /home/sadie/anaconda3/lib/libudunits2.so.0
python: 3.7.6 /home/sadie/anaconda3/bin/python
netCDF4: 1.5.3 /home/sadie/anaconda3/lib/python3.7/site-packages/netCDF4/__init__.py
cftime: 1.1.3 /home/sadie/anaconda3/lib/python3.7/site-packages/cftime/__init__.py
numpy: 1.18.1 /home/sadie/anaconda3/lib/python3.7/site-packages/numpy/__init__.py
psutil: 5.7.0 /home/sadie/anaconda3/lib/python3.7/site-packages/psutil/__init__.py
scipy: 1.4.1 /home/sadie/anaconda3/lib/python3.7/site-packages/scipy/__init__.py
matplotlib: 3.1.3 /home/sadie/anaconda3/lib/python3.7/site-packages/matplotlib/__init__.py
ESMF: 8.0.1 /home/sadie/anaconda3/lib/python3.7/site-packages/ESMF/__init__.py
cfdm: 1.8.5 /home/sadie/cfdm/cfdm/__init__.py
cfunits: 3.2.7 /home/sadie/anaconda3/lib/python3.7/site-packages/cfunits/__init__.py
cfplot: 3.0.6 /home/sadie/anaconda3/lib/python3.7/site-packages/cfplot/__init__.py
cf: 3.5.1 /home/sadie/cf-python/cf/__init__.py

test_DSG_contiguous (__main__.DSGTest) ... ok
test_DSG_create_contiguous (__main__.DSGTest) ... ok
test_DSG_indexed (__main__.DSGTest) ... <string>:6: DeprecationWarning: `np.alen` is deprecated, use `len` instead
ok
test_DSG_indexed_contiguous (__main__.DSGTest) ... ok

----------------------------------------------------------------------
Ran 4 tests in 3.571s

OK
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name='/proc/meminfo' mode='r' encoding='UTF-8'>

With investigation (grep) the origin is not from the test module but the code itself & the functions module which is the only module that does IO on the proc/meminfo file as provided in the warning (so this could potentially lead to problems in usage of cf). It is indeed opened but not closed there:

cf-python/cf/functions.py

Line 96 in d8fd3c7

_meminfo_file = open('/proc/meminfo', 'r', 1)

Naively I would think popping in a close() on the file after it has been used in the subsequent _free_memory() function would be the simple fix, but trying to close it in a few obvious locations do not work, as the code still wants to use it after that point; both the commented line & the uncommented line in turn:

diff --git a/cf/functions.py b/cf/functions.py
index e16b6108b..ff36add24 100644
--- a/cf/functions.py
+++ b/cf/functions.py
@@ -139,8 +139,11 @@ if _linux:
 
         free_bytes = free_KiB * 1024
 
+        #_meminfo_file.close()
+
         return free_bytes
 
+    _meminfo_file.close()
 
 else:
     # ----------------------------------------------------------------

leading to:

Traceback (most recent call last):
  File "test_dsg.py", line 9, in <module>
    import cf
  File "/home/sadie/cf-python/cf/__init__.py", line 219, in <module>
    from .mixin import Coordinate
  File "/home/sadie/cf-python/cf/mixin/__init__.py", line 2, in <module>
    from .propertiesdata       import (PropertiesData,
  File "/home/sadie/cf-python/cf/mixin/propertiesdata.py", line 14, in <module>
    from ..timeduration import TimeDuration
  File "/home/sadie/cf-python/cf/timeduration.py", line 31, in <module>
    _one_year = Data(1, 'calendar_years')
  File "/home/sadie/cf-python/cf/data/data.py", line 676, in __init__
    check_free_memory=check_free_memory)
  File "/home/sadie/cf-python/cf/data/data.py", line 748, in _set_partition_matrix
    if check_free_memory and FREE_MEMORY() < FM_THRESHOLD():
  File "/home/sadie/cf-python/cf/functions.py", line 192, in FREE_MEMORY
    return _free_memory()
  File "/home/sadie/cf-python/cf/functions.py", line 130, in _free_memory
    _meminfo_file.seek(0)
ValueError: I/O operation on closed file.

I was wondering about the right approach to deal with the closing of proc/meminfo, given it clearly needs to be done at a point when it will no longer need to be read & that precise point isn't fully obvious to me, but mostly because I am wary there may be complications, in particular looking at this comment:

cf-python/cf/functions.py

Lines 90 to 93 in d8fd3c7

	# Opening /proc/meminfo once per PE here rather than in
	# _free_memory each time it is called works with MPI on
	# Debian-based systems, which otherwise throw an error that there
	# is no such file or directory when run on multiple PEs.

Ideally we could use the with context manager to solve this & there is in fact a comment suggesting this has been considered:

cf-python/cf/functions.py

Line 126 in d8fd3c7

# with open('/proc/meminfo', 'r', 1) as _meminfo_file:

@davidhassell when you have time to consider this please could you advise on how best to handle this file?

[davidhassell]

Thanks, @sadielbartholomew. PR #89 might be what is required. It looks like it works for me on the command line, though I wasn't getting the error. Could you try it?

The background is that this function is called a huge number of times, more or less every single time a Data object is accessed, and is a key part in the LAMA memory management. Closing and opening the file every time caused a notable dip in performance.

[sadielbartholomew]

Thanks for the very quick response & insight. I'll try out your branch in a moment.

Closing and opening the file every time caused a notable dip in performance.

That makes sense! So as per your PR I see it only needs to be closed it after it has been used for the final time i.e. on exit.

this function is called a huge number of times, more or less every single time a Data object is accessed

That certainly explains why I throwing in a call to close in the places I tried failed. And makes me glad I asked you about it instead of going on to try to fix it in some way that could have made everything slow or downright broken! 😬

though I wasn't getting the error

I was wondering if there was some reason I had only noticed it now, as don't recall having seen it earlier than about a week ago during the releases. I noticed this while looking into the GH Actions workflow (have some question on that actually so will tag you on that PR) & it doesn't seem to appear there either.

Doing a little digging, it seems ResourceWarnings can be hidden by default, so if you try python -X dev test_dsg.py you may see it (I certainly see some other warning & info messages with -X dev which I've just learnt about & noted as a useful tool for future)? Either way I'll check your branch now.

I was using Python 3.8 but I've checked & it also applies to 3.7 so the Python version probably isn't influencing in some subtle way, as with one theory I had.