NCAR / pynio

PyNIO is a multi-format data I/O package with a NetCDF-style interface
http://www.pyngl.ucar.edu/Nio.shtml
Apache License 2.0
116 stars 37 forks source link

grib2_codetables not closing -> too many open files exception #1

Closed mogismog closed 8 years ago

mogismog commented 8 years ago

Hi all,

We've been doing some work on grib2 files with xarray, and I think I've found a strange error that traces back to PyNIO. While I can't really go into great detail on the specifics regarding the work, I think I can be general enough about the error.

Basically, we're opening up several days worth of proprietary grib2 files, but some of the variables within the grib file aren't listed in the code table, resulting in this warning:

warning: Entry (250) not found in code table file /.../PyNIO/ncarg/grib2_codetables/centers.table warning: Entry (250) not found in code table file /.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table

After 2430 iterations (every time!), PyNIO is convinced the previously accessed (or any) codetables are neither valid nor exist:

warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.16.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.16.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table.

Unfortunately, we do not create these grib2 files in house, so it isn't quite as easy as simply fixing the processing of the grib2 file. Editing the specific code table used would also fix the problem, but this seems like an underlying issue with how NclGRIB2.c handles fields that aren't an entry within the referenced grib table. As it turns out, the grib2 code tables are never closed:

In [6]: for i in xrange(10000): ...: f = Nio.open_file(fname) ...: f.close() ...: del(f)

fatal: NclGRIB2: codetable directory "/.../PyNIO/ncarg/grib2_codetables" invalid fatal:Could not open () In [9]: p = psutil.Process(os.getpid()) In [10]: open_files = [f for f in p.open_files() if 'PyNIO' in f.path] In [11]: len(open_files) Out[11]: 4856 In [12]: open_files[0] Out[12]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table', fd=5) In [13]: open_files[1] Out[13]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/centers.table', fd=6) In [14]: open_files[-1] Out[14]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table', fd=4863)

This is confirmed by trying to import/open/do much of anything else in the same iPython session:

In [15]: import pandas as pd ERROR: Internal Python error in the inspect module. Below is the traceback from this internal error.

Traceback (most recent call last): File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 1118, in get_records File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 300, in wrapped File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 345, in _fixed_getinnerframes File "/.../lib/python2.7/inspect.py", line 1049, in getinnerframes File "/.../lib/python2.7/inspect.py", line 1009, in getframeinfo File "/.../lib/python2.7/inspect.py", line 454, in getsourcefile File "/.../lib/python2.7/inspect.py", line 483, in getmodule File "/.../lib/python2.7/inspect.py", line 467, in getabsfile File "/.../lib/python2.7/posixpath.py", line 364, in abspath OSError: [Errno 24] Too many open files

This is a shot in the dark, but I suspect this is a result of a missing (void) fclose(fp) here for when an entry isn't found in the table: https://github.com/yyr/pynio/blob/master/libsrc/NclGRIB2.c#L7979, though I'm not the best at reading C and I haven't looked too much into it tbqh.

If this, in fact, is the issue, I could throw together a PR to resolve this issue.

For reference: OS X 10.11.3, installed via Conda, tried both 1.4.3 on the ncar channel and the 1.5 beta.

Thanks!

Edit: For further reference, I tried closing the files like so, but the error persisted:

p = psutil.Process(os.getpid())
fds = [f.fd for f in p.open_files() if 'PyNIO' in f.path]
for f in fds:
    print f
    os.close(f)
david-ian-brown commented 8 years ago

Hi Francisco, Thanks for the report. You may have put your finger on the problem. It does look like there is a missing fclose after line 7979. If you want put together a PR that would be fine, or we can fix and test it here. It would be good to get this done soon. -dave

On Tue, Apr 19, 2016 at 3:43 PM, Francisco Alvarez <notifications@github.com

wrote:

Hi all,

We've been doing some work on grib2 files with xarray, and I think I've found a strange error that traces back to PyNIO. While I can't really go into great detail on the specifics regarding the work, I think I can be general enough about the error.

Basically, we're opening up several days worth of proprietary grib2 files, but some of the variables within the grib file aren't listed in the code table, resulting in this warning:

warning: Entry (250) not found in code table file /.../PyNIO/ncarg/grib2_codetables/centers.table warning: Entry (250) not found in code table file /.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table

After 2430 iterations (every time!), PyNIO is convinced the previously accessed (or any) codetables are neither valid nor exist:

warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.16.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.16.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.5.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/0/0.0.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/3/3.1.table" not a valid GRIB2 code table. warning: NclGRIB2: codetable file "/.../PyNIO/ncarg/grib2_codetables/ncep/1/1.3.table" not a valid GRIB2 code table.

Unfortunately, we do not create these grib2 files in house, so it isn't quite as easy as simply fixing the processing of the grib2 file. Editing the specific code table used would also fix the problem, but this seems like an underlying issue with how NclGRIB2.c handles fields that aren't an entry within the referenced grib table. As it turns out, the grib2 code tables are never closed:

In [6]: for i in xrange(10000): ...: f = Nio.open_file(fname) ...: f.close() ...: del(f)

fatal: NclGRIB2: codetable directory "/.../PyNIO/ncarg/grib2_codetables" invalid fatal:Could not open ()

In [9]: p = psutil.Process(os.getpid())

In [10]: open_files = [f for f in p.open_files() if 'PyNIO' in f.path]

In [11]: len(open_files) Out[11]: 4856

In [12]: open_files[0] Out[12]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table', fd=5)

In [13]: open_files[1] Out[13]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/centers.table', fd=6)

In [14]: open_files[-1] Out[14]: popenfile(path='/.../PyNIO/ncarg/grib2_codetables/ncep/4/4.2.0.1.table', fd=4863)

This is confirmed by trying to import/open/do much of anything else in the same iPython session:

In [15]: import pandas as pd ERROR: Internal Python error in the inspect module. Below is the traceback from this internal error.

Traceback (most recent call last): File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 1118, in get_records File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 300, in wrapped File "/.../lib/python2.7/site-packages/IPython/core/ultratb.py", line 345, in _fixed_getinnerframes File "/.../lib/python2.7/inspect.py", line 1049, in getinnerframes File "/.../lib/python2.7/inspect.py", line 1009, in getframeinfo File "/.../lib/python2.7/inspect.py", line 454, in getsourcefile File "/.../lib/python2.7/inspect.py", line 483, in getmodule File "/.../lib/python2.7/inspect.py", line 467, in getabsfile File "/.../lib/python2.7/posixpath.py", line 364, in abspath OSError: [Errno 24] Too many open files

This is a shot in the dark, but I suspect this is a result of a missing (void) fclose(fp) here for when an entry isn't found in the table: https://github.com/yyr/pynio/blob/master/libsrc/NclGRIB2.c#L7979, though I'm not the best at reading C and I haven't looked too much into it tbqh.

If this, in fact, is the issue, I could throw together a PR to resolve this issue.

For reference: OS X 10.11.3, installed via Conda, tried both 1.4.3 on the ncar channel and the 1.5 beta.

Thanks!

— You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub https://github.com/NCAR/pynio/issues/1

mogismog commented 8 years ago

@david-ian-brown I can put something together and put a PR up tonight from my personal machine.

Thanks!

david-ian-brown commented 8 years ago

Hi Francisco,

Just FYI we have noticed that the repository you have pointed us to is quite out of date. We have an official github PyNIO repository at under the name "ncar": https://github.com/ncar/pynio/blob/master/libsrc/NclGRIB2.c#L8495

Note the line number change for the code you are pointing to. -dave

On Tue, Apr 19, 2016 at 4:03 PM, Francisco Alvarez <notifications@github.com

wrote:

@david-ian-brown https://github.com/david-ian-brown I can put something together and put a PR up tonight from my personal machine.

Thanks!

— You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub https://github.com/NCAR/pynio/issues/1#issuecomment-212147777

mogismog commented 8 years ago

Oops, you're right! Thanks for the heads up!

khallock commented 8 years ago

Merged pull request #2.

Thanks, Francisco!