-
Notifications
You must be signed in to change notification settings - Fork 68
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
vcs.plot(iso) creates text object that are not removed after clear #1424
Comments
@doutriaux1 it seems you've nailed where the slow down is happening, which is The following code: bg = False
counter = 1
for var in ['sic','sst']:
...
for data in ['obs','bcs']:
...
x = vcs.init()
for count,y in enumerate(range(1870,2013)):
...
for m in range(12):
startTime = time.time()
...
title.string = '%i-%.2i' % (y,m+1)
x.plot(title,bg=bg)
x.plot(s1,t1,iso1,bg=bg)
x.plot(diff,t2,iso2,bg=bg)
x.plot(s2,t3,iso1,bg=bg)
...
x.png(fileName)
x.clear()
del(vcs.elements["isofill"][iso1.name])
del(vcs.elements["isofill"][iso2.name])
del(vcs.elements["textcombined"][title.name])
del(vcs.elements["template"][t1.name])
del(vcs.elements["template"][t2.name])
del(vcs.elements["template"][t3.name])
for nm in vcs.elements["texttable"].keys():
if not nm in basic_tt:
del(vcs.elements["texttable"][nm])
for nm in vcs.elements["textorientation"].keys():
if not nm in basic_to:
del(vcs.elements["textorientation"][nm])
for nm in vcs.elements["textcombined"].keys():
if not nm in basic_tc:
del(vcs.elements["textcombined"][nm])
endTime = time.time()
print counterStr,printStr,varName.ljust(6),BC,timeStr,memStr
counter = counter+1
gc.collect() ; # Attempt to force a memory flush
x.close() Gets this output:
For comparison, the timings and resource usage (which were erroneously listed in #1397 - doesn't have much to do with the
It would be great if |
@doutriaux1 as an aside, it also appears that the x = vcs.init()
x.ffmpeg('out.mp4',outFileList,rate=5,bitrate=2048)
x.close() The first time it's called it seems to jump the memory usage a little:
Whereas subsequent calls don't appear to do the same:
|
@doutriaux1 this will get you there - it's the script which reports the time and mem usage above: |
and removes them at clear time fix #1424
@doutriaux1 seems like there are some more things which aren't being purged, reopening.. Code that includes: del(vcs.elements["isofill"][iso1.name])
del(vcs.elements["isofill"][iso2.name])
del(vcs.elements["textcombined"][title.name])
del(vcs.elements["template"][t1.name])
del(vcs.elements["template"][t2.name])
del(vcs.elements["template"][t3.name])
for nm in vcs.elements["texttable"].keys():
if not nm in basic_tt:
del(vcs.elements["texttable"][nm])
for nm in vcs.elements["textorientation"].keys():
if not nm in basic_to:
del(vcs.elements["textorientation"][nm])
for nm in vcs.elements["textcombined"].keys():
if not nm in basic_tc:
del(vcs.elements["textcombined"][nm]) Yields the following timings/memory usage in a loop: UV-CDAT version: 2.2.0
UV-CDAT prefix: /usr/local/uvcdat/2.2.0
delFudge: True
count frameTime residentMemory
00001 processing: 1870-01 sic Time: 03.241 secs; Max mem: 0.241 GB
...
00500 processing: 1911-08 sic Time: 03.179 secs; Max mem: 0.274 GB
...
01000 processing: 1953-04 sic Time: 03.169 secs; Max mem: 0.295 GB And without: UV-CDAT version: 2.2.0-204-geef3c60
UV-CDAT prefix: /usr/local/uvcdat/2015-07-14-full
delFudge: False
count frameTime residentMemory
00001 processing: 1870-01 sic Time: 03.225 secs; Max mem: 0.237 GB
...
00010 processing: 1870-10 sic Time: 05.558 secs; Max mem: 0.238 GB
...
00020 processing: 1871-08 sic Time: 09.972 secs; Max mem: 0.240 GB
...
00030 processing: 1872-06 sic Time: 15.952 secs; Max mem: 0.241 GB
...
00040 processing: 1873-04 sic Time: 23.081 secs; Max mem: 0.243 GB
...
00050 processing: 1874-02 sic Time: 31.757 secs; Max mem: 0.246 GB
...
00060 processing: 1874-12 sic Time: 42.138 secs; Max mem: 0.246 GB
...
00070 processing: 1875-10 sic Time: 53.792 secs; Max mem: 0.250 GB
...
00080 processing: 1876-08 sic Time: 68.210 secs; Max mem: 0.256 GB
...
00090 processing: 1877-06 sic Time: 78.360 secs; Max mem: 0.263 GB
...
00100 processing: 1878-04 sic Time: 93.911 secs; Max mem: 0.266 GB
...
00110 processing: 1879-02 sic Time: 111.486 secs; Max mem: 0.267 GB And just for completeness, adding back in the UV-CDAT version: 2.2.0-204-geef3c60
UV-CDAT prefix: /usr/local/uvcdat/2015-07-14-full
delFudge: True
count frameTime residentMemory
00001 processing: 1870-01 sic Time: 03.795 secs; Max mem: 0.241 GB
...
00020 processing: 1871-08 sic Time: 03.140 secs; Max mem: 0.242 GB
...
00050 processing: 1874-02 sic Time: 03.164 secs; Max mem: 0.242 GB
...
00100 processing: 1878-04 sic Time: 03.131 secs; Max mem: 0.243 GB
...
00200 processing: 1886-08 sic Time: 03.139 secs; Max mem: 0.245 GB
...
00500 processing: 1911-08 sic Time: 03.179 secs; Max mem: 0.255 GB
...
01000 processing: 1953-04 sic Time: 03.244 secs; Max mem: 0.271 GB
...
01500 processing: 1994-12 sic Time: 03.384 secs; Max mem: 0.276 GB
...
06864 processing: 2012-12 tos bc Time: 07.218 secs; Max mem: 0.376 GB |
@doutriaux1 looks to me like even the |
@durack1 we know there's a tiny tiniy leak in cdtime (8bits I believe) . Lots of relative/component conversion could lead to big leak eventually. But that might not be it. |
@doutriaux1, nope |
@durack1 if you use cdms2 and have a time axis, you are using cdtime and trigger that leak. |
@doutriaux1 not sure this is enough to trigger it: https://github.com/PCMDI/amipbcs/blob/master/make_newVsOldDiffs.py#L171-177 There's no explicit time axis manipulation.. |
@dnadeau4 we should take a look at the tiniy cdtime/cdms leak |
@doutriaux1 did you want me to run my test on current master - are there changes in there that should solve this issue? |
@doutriaux1 to see where [duro@ocean 150219_AMIPForcingData]$ make_newVsOldDiffs.py
UV-CDAT version: 2.4.0rc1-8-gd23939e
UV-CDAT prefix: /usr/local/uvcdat/2.4.0rc1
delFudge: True
00001 processing: 1870-01 sic Time: 03.731 secs; Max mem: 0.239 GB
...
00020 processing: 1871-08 sic Time: 02.857 secs; Max mem: 0.241 GB
...
00050 processing: 1874-02 sic Time: 02.892 secs; Max mem: 0.245 GB
...
00100 processing: 1878-04 sic Time: 02.865 secs; Max mem: 0.246 GB
...
00200 processing: 1886-08 sic Time: 02.934 secs; Max mem: 0.248 GB
...
00500 processing: 1911-08 sic Time: 02.887 secs; Max mem: 0.257 GB
...
00750 processing: 1932-06 sic Time: 02.998 secs; Max mem: 0.267 GB
...
01000 processing: 1953-04 sic Time: 03.074 secs; Max mem: 0.274 GB
...
01500 processing: 1994-12 sic Time: 05.771 secs; Max mem: 0.289 GB
...
02000 processing: 1893-08 sic bc Time: 03.263 secs; Max mem: 0.291 GB
...
02500 processing: 1935-04 sic bc Time: 03.494 secs; Max mem: 0.306 GB
...
05000 processing: 2000-08 tos Time: 05.025 secs; Max mem: 0.345 GB
...
06000 processing: 1940-12 tos bc Time: 06.134 secs; Max mem: 0.356 GB
...
06864 processing: 2012-12 tos bc Time: 06.850 secs; Max mem: 0.373 GB So long story short, it's better than previously, but could do with another look before closing.. @chaosphere2112 here are the numbers I mentioned earlier.. |
@chaosphere2112 I was curious about your [duro@ocean 150219_AMIPForcingData]$ more make_newVsOldDiffs7.txt
UV-CDAT version: 2.4.0rc1-8-gd23939e
UV-CDAT prefix: /usr/local/uvcdat/2.4.0rc1
delFudge: True
00001 processing: 1870-01 sic Time: 03.313 secs; Max mem: 0.239 GB PyObj#: 0050634;
...
00005 processing: 1870-05 sic Time: 03.096 secs; Max mem: 0.240 GB PyObj#: 0050839;
...
00010 processing: 1870-10 sic Time: 02.913 secs; Max mem: 0.242 GB PyObj#: 0051099;
...
00020 processing: 1871-08 sic Time: 02.928 secs; Max mem: 0.244 GB PyObj#: 0051621;
...
00030 processing: 1872-06 sic Time: 02.920 secs; Max mem: 0.244 GB PyObj#: 0052143;
...
00040 processing: 1873-04 sic Time: 02.925 secs; Max mem: 0.244 GB PyObj#: 0052665;
...
00050 processing: 1874-02 sic Time: 02.944 secs; Max mem: 0.244 GB PyObj#: 0053187;
...
00500 processing: 1911-08 sic Time: 02.863 secs; Max mem: 0.253 GB PyObj#: 0076581;
...
01000 processing: 1953-04 sic Time: 03.011 secs; Max mem: 0.269 GB PyObj#: 0102585;
...
02000 processing: 1893-08 sic bc Time: 03.354 secs; Max mem: 0.287 GB PyObj#: 0154686;
...
03000 processing: 1976-12 sic bc Time: 03.819 secs; Max mem: 0.308 GB PyObj#: 0206692;
...
04000 processing: 1917-04 tos Time: 04.239 secs; Max mem: 0.328 GB PyObj#: 0258811;
...
05000 processing: 2000-08 tos Time: 05.023 secs; Max mem: 0.346 GB PyObj#: 0310817;
...
06000 processing: 1940-12 tos bc Time: 06.097 secs; Max mem: 0.362 GB PyObj#: 0362918;
...
06864 processing: 2012-12 tos bc Time: 07.090 secs; Max mem: 0.379 GB PyObj#: 0407830; So a further cleanup of these objects would be a very good idea indeed. Not sure where things stand in |
@durack1 Nope, not yet. I'll try and get a branch up this afternoon, I've been on other projects for the last month or so. |
@durack1 Also, if you want to eliminate your delFudge stuff, you can plot your labels using "donotstoredisplay=True" |
@chaosphere2112 great, I'm just running with that additional argument now in |
@chaosphere2112 I just ran the script with
|
@durack1 Yeah, that's a bit much. I'm working on some other stuff right now, but I should be able to sit down with you and your script this week and see if anything leaps out to me. |
@chaosphere2112 no probs - I'm in this week so let me know.. |
@doutriaux1 this issue along with a couple of others (#1770, #1931 and #1944) should probably be pinned to a |
@chaosphere2112 just to see changes between
|
@doutriaux1 @danlipsa @chaosphere2112 just pinging you folks here.. Wishful thinking for |
Not related to #1397 (bg=1 memory leak)
The text was updated successfully, but these errors were encountered: