You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
Large memory footprint in astropy.io.votable.parse_single_table #8946
Looking at the memory footprint, I saw that python was taking ~12 GB during the read and I cancelled the kernel (this is within a Jupyter notebook). Here's my screenshot showing the memory usage:
While I know that there is a significant python overhead, it still seems like a lot of memory to read only 2 columns (out of 96). By my math, the (minimum) possible size is 2/96*1 GB ~ 0.02 GB
Since I am new to both astropy and votables, perhaps I am doing something incorrectly. Happy to provide further info or help debug, as necessary. In case there is something inherently wrong with the file itself, here's a dropbox link to the file.
The system activity monitor had the memory usage roughly constant at 11.6 GB for the ~20 mins that I let the code run (the read did not complete, that's why the last two lines were not executed). The function memory profile accounts for less than 1 GB.
I am not sure how to include the memory profile for all the called functions, but it seems that the excessive memory is coming from some function within the votable routines.
Thanks for reporting this. Sounds like a bug, perhaps due to memory leak. 🤔
To profile the underlying calls, for the memory part, might need to call them directly, which is not very fun. For the performance part, might have to fall back to cProfile.
Thanks @pllim. Since topcat read in the file just fine, I can confirm that this is indeed a bug within astropy and not something peculiar about the file.
Finally got around to downloading this file. I just fired up volint and immediately I see one of the CPU at 100% capacity (probably expected, though the CPU switches from one to the other once in a while) and memory use quickly ramped up to about over 20 GB and one point (whaaaat?) and then ramp down a bit and is staying much or less around 16-17 GB. 😱 Given how long you reported that it takes to parse the file (20 mins), I am gonna have to kill this job. Something is obviously not right...
When I kill the job, here is the traceback it spitted out before it died:
File ".../bin/volint", line 11, in <module>
load_entry_point('astropy==4.0.dev25415', 'console_scripts', 'volint')()
File ".../astropy/io/votable/volint.py", line 18, in main
table.validate(args.filename[0])
File ".../astropy/io/votable/table.py", line 283, in validate
votable = parse(content_buffer, verify='warn', filename=filename)
File ".../astropy/utils/decorators.py", line 521, in wrapper
return function(*args, **kwargs)
File ".../astropy/io/votable/table.py", line 167, in parse
config=config, pos=(1, 1)).parse(iterator, config)
File ".../astropy/io/votable/tree.py", line 3391, in parse
iterator, tag, data, config, pos)
File ".../astropy/io/votable/tree.py", line 3320, in _add_resource
resource.parse(self, iterator, config)
File ".../astropy/io/votable/tree.py", line 3142, in parse
iterator, tag, data, config, pos)
File ".../astropy/io/votable/tree.py", line 3093, in _add_table
table.parse(iterator, config)
File ".../astropy/io/votable/tree.py", line 2396, in parse
2, iterator, colnumbers, fields, config, pos)
File ".../astropy/io/votable/tree.py", line 2631, in _parse_binary
value, value_mask = binparse(careful_read)
File ".../astropy/io/votable/converters.py", line 649, in binparse
return result[0], self.is_null(result[0])
This appears to be a BINARY2 format.
Note to self: What is this undocumented _debug_python_based_parser option in table.py? 🤔
Thanks! However, something isn't quite right. The file isn't binary anymore. And while the parsing is instantaneous this time without using much memory, the table looks invalid.
Going back to the 1GB file, I ran this, walked away, came back an hour later, and amazingly it finished. Just posting this here for future reference. So for sure it did not get stuck in a loop somewhere, just eats up lots of memory and takes up to an hour to parse. 😱
$ volint async_20190630210155.vot
Validation report for async_20190630210155.vot
5: W35: 'value' attribute required for INFO elements
<INFO name="QUERY" value=""><![CDATA[select * from gaiadr2.gaia_sou...
^
6: W35: 'value' attribute required for INFO elements
<INFO name="CAPTION" value=""><![CDATA[How to cite and acknowledge ...
^
7: W35: 'value' attribute required for INFO elements
<INFO name="PAGE" value=""></INFO>
^
8: W35: 'value' attribute required for INFO elements
<INFO name="PAGE_SIZE" value=""></INFO>
^
10: W35: 'value' attribute required for INFO elements
<INFO name="JOBNAME" value=""></INFO>
^
47: W06: Invalid UCD 'arith.ratio': Secondary word 'arith.ratio' is
not valid as a primary word
<FIELD datatype="float" name="parallax_over_error" ucd="arith.ratio">
^
50: W50: Invalid unit string 'mas.yr**-1'
<FIELD datatype="double" name="pmra" ucd="pos.pm;pos.eq.ra" unit="m...
^
53: W50: Invalid unit string 'mas.yr**-1'
<FIELD datatype="double" name="pmra_error" ucd="stat.error;pos.pm;p...
^
56: W50: Invalid unit string 'mas.yr**-1'
<FIELD datatype="double" name="pmdec" ucd="pos.pm;pos.eq.dec" unit=...
^
59: W50: Invalid unit string 'mas.yr**-1'
<FIELD datatype="double" name="pmdec_error" ucd="stat.error;pos.pm;...
^
122: W50: Invalid unit string 'mas**-2'
<FIELD datatype="float" name="astrometric_weight_al" ucd="stat.weig...
^
125: W50: Invalid unit string 'um**-1'
<FIELD datatype="double" name="astrometric_pseudo_colour" ucd="em.w...
^
128: W06: Invalid UCD 'em.wavenumber;stat.error': Primary word
'stat.error' is not valid as a secondary word
<FIELD datatype="double" name="astrometric_pseudo_colour_error" ucd...
^
128: W50: Invalid unit string 'um**-1'
<FIELD datatype="double" name="astrometric_pseudo_colour_error" ucd...
^
140: W06: Invalid UCD 'pos.errorEllipse;stat.max': Secondary word
'pos.errorEllipse' is not valid as a primary word
<FIELD datatype="float" name="astrometric_sigma5d_max" ucd="pos.err...
^
155: W50: Invalid unit string ''electron'.s**-1'
<FIELD datatype="double" name="phot_g_mean_flux" ucd="phot.flux;sta...
^
158: W50: Invalid unit string ''electron'.s**-1'
<FIELD datatype="double" name="phot_g_mean_flux_error" ucd="stat.er...
^
161: W06: Invalid UCD 'arith.ratio': Secondary word 'arith.ratio' is
not valid as a primary word
<FIELD datatype="float" name="phot_g_mean_flux_over_error" ucd="ari...
^
170: W50: Invalid unit string ''electron'.s**-1' (suppressing further
warnings of this type...)
<FIELD datatype="double" name="phot_bp_mean_flux" ucd="phot.flux;st...
^
176: W06: Invalid UCD 'arith.ratio': Secondary word 'arith.ratio' is
not valid as a primary word
<FIELD datatype="float" name="phot_bp_mean_flux_over_error" ucd="ar...
^
191: W06: Invalid UCD 'arith.ratio': Secondary word 'arith.ratio' is
not valid as a primary word
<FIELD datatype="float" name="phot_rp_mean_flux_over_error" ucd="ar...
^
203: W06: Invalid UCD 'phot.color': Unknown word 'phot.color'
<FIELD datatype="float" name="bp_rp" ucd="phot.color" unit="mag">
^
206: W06: Invalid UCD 'phot.color': Unknown word 'phot.color'
<FIELD datatype="float" name="bp_g" ucd="phot.color" unit="mag">
^
209: W06: Invalid UCD 'phot.color': Unknown word 'phot.color'
<FIELD datatype="float" name="g_rp" ucd="phot.color" unit="mag">
^
281: W06: Invalid UCD 'phys.size.radius;stat.error': Primary word
'stat.error' is not valid as a secondary word (suppressing further
warnings of this type...)
<FIELD datatype="float" name="radius_percentile_lower" ucd="phys.si...
^
After having spent time spelunking in the io.votable C internals due to a different issue, I revisited this issue, using the original file (2.5 GB uncompressed, Gaia DR2) and current main branch.
File is 3,000,000 rows x 96 columns, BINARY2. Big! But not crazy big. Should fit into laptop memory, but doesn't.
Today, on astropy main branch, speed is OK today; memory is not.
Parsing takes ~40 us per row and scales linearly with number of rows, so a little over 2 minutes for this file. Peak memory is about 16 GB, more than 6 times the file size, and passing columns= does not reduce. The hour-long runs reported above were likely memory swapping/paging on laptops? My laptop here has a bit more memory than standard, but it also started swapping the full size file, so I made smaller sized versions of the same file for testing - 1%, 5%, 10%, etc. Same columns, fewer rows in the binary data section.
The cause of the huge memory usage is mostly in iterparse.c, as @pllim found. endElement builds the end tag event's text from a shared buffer but never empties it. Every enclosing end tag that follows then gets its own copy of the last element's text. For a BINARY2 table, , and each carry another full copy of the 2.4 GB stream.
A toy example is below, showing this using the event iterator and logging the events between tags. If we look at the end tags only:
The pure-Python parser does roughly the same, so moving from the default fast parser to the python one doesn't help.
So fixing both of these would help reduce memory.
There's probably some smaller memory redundancies to add to this:
Decoding makes an extra copy first. _get_binary_data_stream decodes the stream with base64.b64decode(text.encode("ascii")). This step makes a copy of all 2.4 GB in order to turn the text into bytes. There's a one-liner to do this without making a copy.
The result table is copied as it grows. This 2.4 GB input file doesn't say how many rows it has (the optional nrows attribute on TABLE). Typical of VOT query results. So the result array starts small, and each time it fills up it is replaced by one 1.5 times larger, with every row read so far copied across. At the end it is copied once more to trim it to the exact number of rows. During each copy, the old and new arrays are both in memory, so its probably adding an extra 1.5x size in memory here as well.
I don't think the earlier fix (#10076) changed the memory use. The tokenizer doubles its text buffer each time the text outgrows it (1 GB, 2 GB, 4 GB, and so on), and #10076 corrected how that next size is calculated above 4 GB. This file's text is 2.4 GB, so the old calculation was already OK for it.
So there's some low-hanging fruit here. I have not looked at the behavior in reading just 2 columns, other than to say it doesn't seem to change memory usage, as already reported in this issue.
Activity
manodeep commentedon Jul 3, 2019
I ran the memory profiler within the jupyter notebook (new jupyter session, new browser session) to see what might be going on.
The system activity monitor had the memory usage roughly constant at 11.6 GB for the ~20 mins that I let the code run (the read did not complete, that's why the last two lines were not executed). The function memory profile accounts for less than 1 GB.
I am not sure how to include the memory profile for all the called functions, but it seems that the excessive memory is coming from some function within the
votableroutines.manodeep commentedon Jul 3, 2019
For completeness, here's the output from
line_profiler:Nothing surprising. All of the runtime is in the
parse_single_tablefunction.pllim commentedon Jul 9, 2019
Thanks for reporting this. Sounds like a bug, perhaps due to memory leak. 🤔
To profile the underlying calls, for the memory part, might need to call them directly, which is not very fun. For the performance part, might have to fall back to cProfile.
It all starts here:
astropy/astropy/io/votable/table.py
Lines 170 to 187 in 7e751f1
manodeep commentedon Jul 9, 2019
Thanks @pllim. Since
topcatread in the file just fine, I can confirm that this is indeed a bug withinastropyand not something peculiar about the file.pllim commentedon Aug 13, 2019
Finally got around to downloading this file. I just fired up
volintand immediately I see one of the CPU at 100% capacity (probably expected, though the CPU switches from one to the other once in a while) and memory use quickly ramped up to about over 20 GB and one point (whaaaat?) and then ramp down a bit and is staying much or less around 16-17 GB. 😱 Given how long you reported that it takes to parse the file (20 mins), I am gonna have to kill this job. Something is obviously not right...When I kill the job, here is the traceback it spitted out before it died:
This appears to be a BINARY2 format.
Note to self: What is this undocumented
_debug_python_based_parseroption intable.py? 🤔pllim commentedon Mar 13, 2020
manodeep commentedon Mar 13, 2020
Probably wouldn't be the case in the immigrant library ;-)
pllim commentedon Mar 13, 2020
manodeep commentedon Mar 13, 2020
@pllim Here you go async_subset.vot, 22MB
pllim commentedon Mar 13, 2020
Thanks! However, something isn't quite right. The file isn't binary anymore. And while the parsing is instantaneous this time without using much memory, the table looks invalid.
Also, it looks like
columnsis ignored?pllim commentedon Mar 13, 2020
Going back to the 1GB file, I ran this, walked away, came back an hour later, and amazingly it finished. Just posting this here for future reference. So for sure it did not get stuck in a loop somewhere, just eats up lots of memory and takes up to an hour to parse. 😱
pllim commentedon Mar 13, 2020
9 remaining items
jdavies-st commentedon Sep 30, 2026
After having spent time spelunking in the
io.votableC internals due to a different issue, I revisited this issue, using the original file (2.5 GB uncompressed, Gaia DR2) and current main branch.File is 3,000,000 rows x 96 columns, BINARY2. Big! But not crazy big. Should fit into laptop memory, but doesn't.
Today, on astropy main branch, speed is OK today; memory is not.
Parsing takes ~40 us per row and scales linearly with number of rows, so a little over 2 minutes for this file. Peak memory is about 16 GB, more than 6 times the file size, and passing
columns=does not reduce. The hour-long runs reported above were likely memory swapping/paging on laptops? My laptop here has a bit more memory than standard, but it also started swapping the full size file, so I made smaller sized versions of the same file for testing - 1%, 5%, 10%, etc. Same columns, fewer rows in the binary data section.The cause of the huge memory usage is mostly in
iterparse.c, as @pllim found.endElementbuilds the end tag event's text from a shared buffer but never empties it. Every enclosing end tag that follows then gets its own copy of the last element's text. For a BINARY2 table, , and each carry another full copy of the 2.4 GB stream.A toy example is below, showing this using the event iterator and logging the events between tags. If we look at the end tags only:
The pure-Python parser does roughly the same, so moving from the default fast parser to the python one doesn't help.
So fixing both of these would help reduce memory.
There's probably some smaller memory redundancies to add to this:
_get_binary_data_streamdecodes the stream withbase64.b64decode(text.encode("ascii")). This step makes a copy of all 2.4 GB in order to turn the text into bytes. There's a one-liner to do this without making a copy.nrowsattribute onTABLE). Typical of VOT query results. So the result array starts small, and each time it fills up it is replaced by one 1.5 times larger, with every row read so far copied across. At the end it is copied once more to trim it to the exact number of rows. During each copy, the old and new arrays are both in memory, so its probably adding an extra 1.5x size in memory here as well.I don't think the earlier fix (#10076) changed the memory use. The tokenizer doubles its text buffer each time the text outgrows it (1 GB, 2 GB, 4 GB, and so on), and #10076 corrected how that next size is calculated above 4 GB. This file's text is 2.4 GB, so the old calculation was already OK for it.
So there's some low-hanging fruit here. I have not looked at the behavior in reading just 2 columns, other than to say it doesn't seem to change memory usage, as already reported in this issue.
Stop XML end events from repeating the text of nested elements
Stop XML end events from repeating the text of nested elements
Stop XML end events from repeating the text of nested elements
Stop XML end events from repeating the text of nested elements
Reduce memory needed to read VOTable BINARY and BINARY2 streams (#20509)
Grow VOTable result arrays in place instead of copying them
Grow VOTable result arrays in place instead of copying them
Grow VOTable result arrays in place instead of copying them
Grow VOTable result arrays in place instead of copying them (#20743)