Memory leaks

[megies]

With long running multichannel plots I've experienced memory usage going up over time. I am not sure yet if it is a problem of the seedlink updating or the plotting, I've tried to debug this using objgraph but without success so far.. (the multiple threads make it a bit harder to debug..).

[sbonaime]

No problem with one station. I have one PC running for 1 month and the other since May 21 ! I am using on those boxes an old seedlink_plotter version. The memory leak may not come from the seedlink updating...

[megies]

Ok, I already suspected matplotlib. I've had issues like that with automated scripts that overwrite figure instances in loops. Right now I'm doing a Figure.clear() in the loop because closing the figure (what I usually do in long running scripts) obviously is no option.. but that might not be enough.

[sbonaime]

After fews days in Multichannel mode, I can see that memory usage is increasing. But not in Singlechannel.

[megies]

Hmm.. for me it is also increasing in singlechannel. I have a plot running with the following call:

./seedlink_plotter.py -s "G_FDF:00BHZ" --x_position 200
 --y_position 50 --x_size 800 --y_size 600 -b 24 --scale 20000
 --seedlink_server "rtserver.ipgp.fr:18000" --x_scale 60 --with_decoration

And here is how the memory evolved (after around 17days):

• x axis is in units of 5 minutes
• i'm monitoring memory of the process with grep "^Vm" /proc/$PROCID/status

[sbonaime]

I started to log this memory leak problem using Objgraph. Each time the plot_graph is used, I record date and objgraph.show_growth(limit=20) which shows the increase in peak object counts since last call. My test program is seedlink-plotter -s "G_SSB:00BHZ" --x_position 200 --y_position 50 --x_size 800 --y_size 600 -b 2 --scale 20000 --seedlink_server "rtserver.ipgp.fr:18000" --x_scale 60 --with_decoration --update_time 5

Here are the first results for around 20h. I just put the objgraph events with corresponding dates after few minutes:

2013-10-08T16:38:23.760201Z
#Start of seedlink_ploter

2013-10-08T18:00:05.436937Z
dict     6387        +2
2013-10-08T18:00:12.274996Z
tuple        4310        +4
function    13836        +2
list         2750        +2
weakref      2774        +2
instance      925        +2
Bbox          119        +2
2013-10-08T18:29:31.016238Z
list      2754        +4
tuple     4311        +1
2013-10-08T19:00:09.904105Z
tuple        4314        +3
weakref      2776        +2
function    13838        +2
instance      927        +2
Bbox          121        +2
2013-10-08T19:55:16.093002Z
LP_c_char               1        +1
tuple                4315        +1
LP_LP_MSRecord_s        1        +1
2013-10-08T20:00:07.575958Z
tuple        4318        +3
weakref      2778        +2
function    13840        +2
instance      929        +2
Bbox          123        +2
2013-10-08T21:00:09.894672Z
tuple        4322        +4
function    13842        +2
list         2756        +2
weakref      2780        +2
instance      931        +2
Bbox          125        +2
2013-10-08T22:00:13.763550Z
tuple        4326        +4
function    13844        +2
list         2758        +2
weakref      2782        +2
instance      933        +2
Bbox          127        +2
2013-10-08T23:00:08.063935Z
tuple        4330        +4
function    13846        +2
list         2760        +2
weakref      2784        +2
instance      935        +2
Bbox          129        +2
2013-10-09T00:00:11.027501Z
tuple        4334        +4
function    13848        +2
list         2762        +2
weakref      2786        +2
instance      937        +2
Bbox          131        +2
2013-10-09T00:33:22.057960Z
list      2766        +4
tuple     4335        +1
2013-10-09T05:57:05.323414Z
dict     6389        +2
2013-10-09T05:57:19.957977Z
dict     6391        +2
2013-10-09T05:57:34.592687Z
dict     6393        +2
2013-10-09T05:57:56.570650Z
dict     6395        +2
2013-10-09T05:58:11.223912Z
dict     6397        +2
2013-10-09T05:58:33.234135Z
dict     6399        +2
2013-10-09T05:58:47.887630Z
dict     6401        +2
2013-10-09T05:59:09.923517Z
dict     6403        +2
2013-10-09T05:59:24.612431Z
dict     6405        +2
2013-10-09T05:59:39.302503Z
dict     6407        +2
2013-10-09T06:00:01.402795Z
dict     6409        +2
2013-10-09T06:56:05.204634Z
dict     6411        +2
2013-10-09T06:56:27.272454Z
dict     6413        +2
2013-10-09T06:56:41.989269Z
dict     6415        +2
2013-10-09T06:56:56.696949Z
dict     6417        +2
2013-10-09T06:57:18.788659Z
UTCDateTime      789        +2
dict            6419        +2
Stats            390        +1
Trace            390        +1
2013-10-09T06:57:33.535237Z
UTCDateTime      791        +2
dict            6421        +2
Stats            391        +1
Trace            391        +1
2013-10-09T06:57:55.644768Z
UTCDateTime      793        +2
dict            6423        +2
Stats            392        +1
Trace            392        +1
2013-10-09T06:58:10.379122Z
UTCDateTime      795        +2
dict            6425        +2
Stats            393        +1
Trace            393        +1
2013-10-09T06:58:32.525598Z
UTCDateTime      797        +2
dict            6427        +2
Stats            394        +1
Trace            394        +1
2013-10-09T06:58:47.285405Z
UTCDateTime      799        +2
dict            6429        +2
Stats            395        +1
Trace            395        +1
2013-10-09T06:59:02.054648Z
UTCDateTime      801        +2
dict            6431        +2
Stats            396        +1
Trace            396        +1
2013-10-09T06:59:24.251110Z
UTCDateTime      803        +2
dict            6433        +2
Stats            397        +1
Trace            397        +1
2013-10-09T06:59:39.019753Z
UTCDateTime      805        +2
dict            6435        +2
Stats            398        +1
Trace            398        +1
2013-10-09T07:00:01.230510Z
UTCDateTime      807        +2
dict            6437        +2
Stats            399        +1
Trace            399        +1
2013-10-09T07:56:57.271901Z
UTCDateTime      809        +2
dict            6439        +2
Stats            400        +1
Trace            400        +1
2013-10-09T07:57:12.062459Z
UTCDateTime      811        +2
dict            6441        +2
Stats            401        +1
Trace            401        +1
2013-10-09T07:57:34.278661Z
UTCDateTime      813        +2
dict            6443        +2
Stats            402        +1
Trace            402        +1
2013-10-09T07:57:49.078459Z
UTCDateTime      815        +2
dict            6445        +2
Stats            403        +1
Trace            403        +1
2013-10-09T07:58:11.305539Z
UTCDateTime      817        +2
dict            6447        +2
Stats            404        +1
Trace            404        +1
2013-10-09T07:58:26.121530Z
UTCDateTime      819        +2
dict            6449        +2
Stats            405        +1
Trace            405        +1
2013-10-09T07:58:40.920127Z
UTCDateTime      821        +2
dict            6451        +2
Stats            406        +1
Trace            406        +1
2013-10-09T07:59:03.149784Z
UTCDateTime      823        +2
dict            6453        +2
Stats            407        +1
Trace            407        +1
2013-10-09T07:59:17.990992Z
UTCDateTime      825        +2
dict            6455        +2
Stats            408        +1
Trace            408        +1
2013-10-09T07:59:40.299385Z
UTCDateTime      827        +2
dict            6457        +2
Stats            409        +1
Trace            409        +1
2013-10-09T07:59:55.169205Z
UTCDateTime      829        +2
dict            6459        +2
Stats            410        +1
Trace            410        +1
2013-10-09T08:04:08.412626Z
SLState        2        +1
2013-10-09T08:59:25.410017Z
UTCDateTime      831        +2
dict            6461        +2
Stats            411        +1
Trace            411        +1
2013-10-09T08:59:40.263153Z
UTCDateTime      833        +2
dict            6463        +2
Stats            412        +1
Trace            412        +1
2013-10-09T08:59:55.115838Z
UTCDateTime      835        +2
dict            6465        +2
Stats            413        +1
Trace            413        +1
2013-10-09T11:29:32.922730Z
instance      941        +4
weakref      2788        +2
function    13850        +2
Affine2D       49        +2
tuple        4336        +1
2013-10-09T12:59:42.265549Z
dict     6467        +2
2013-10-09T13:00:04.579938Z
UTCDateTime      837        +2
dict            6469        +2
Stats            414        +1
Trace            414        +1
2013-10-09T13:58:37.020633Z
UTCDateTime      839        +2
dict            6471        +2
Stats            415        +1
Trace            415        +1
2013-10-09T13:58:59.376481Z
UTCDateTime      841        +2
dict            6473        +2
Stats            416        +1
Trace            416        +1
2013-10-09T13:59:14.300766Z
UTCDateTime      843        +2
dict            6475        +2
Stats            417        +1
Trace            417        +1
2013-10-09T13:59:29.196593Z
UTCDateTime      845        +2
dict            6477        +2
Stats            418        +1
Trace            418        +1
2013-10-09T13:59:44.088499Z
UTCDateTime      847        +2
dict            6479        +2
Stats            419        +1
Trace            419        +1
2013-10-09T13:59:58.998178Z
UTCDateTime      849        +2
dict            6481        +2
Stats            420        +1
Trace            420        +1
2013-10-09T14:00:06.449455Z
dict            6483        +2
MaskedArray       16        +2

What we can see is that they are clearly more and more Objects. It seems that each round hour, we get some new ones but not every hours !

[megies]

Once thing I wanted to check next is to replace fig.clear() with plt.close() and building the figure from scratch each time, to see if that is were we leak objects. I had problems before in loops making plots, where I was overwriting my figure variable each time but the memory did not get freed completely. Explicitely closing the figure solved the problem there..

[megies]

Maybe this is interesting: https://github.com/matplotlib/matplotlib/blob/master/unit/memleak_gui.py

[sbonaime]

from https://gist.github.com/astrofrog/824941

fig = plt.figure()
    ax = fig.add_subplot(1, 1, 1)
    ax.scatter(np.random.random(10), np.random.random(10))
    fig.savefig('test.png')

    plt.close()

seems to be a good solution without memory leak

[megies]

Well, it is not proven yet that the leak definitively is in matplotlib, right (although that would be my guess too)? If it is, plt.close() is no option for us, I think, we can not have figures getting closed and reopened again.. But the other comment is interesting.. about avoiding to use anything from pyplot/pylab interface. That would mean serious work though.. probably, setting up a little TK window from scratch.. but ObsPy imaging code itself is also using pyplot..

[megies]

I am pretty sure this is fixed by obspy/obspy@5ce975c3710ca62ee3acd1e1cf2a13b7051eb939, see obspy/obspy#918. Maybe there should be a warning regarding the leak when ObsPy version < 0.10.0 is used.

[megies]

Here's a comparison of memory usage after a day of multichannel plot with 7 channels at 200 Hz. I'll keep it running to see how it goes..

Update: