heads up: Memory leak in weewx

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

OOM killer is killing my weewx program from time to time. I am seen
this problem since I upgraded to 2.5, but I am sending my data to
quite a few online services (recent change), so maybe the problem
existed too in 2.4.

Currently my weewx process is growing around 2MB per hour so far. My
archive interval is 5 minutes. I will try to debug it myself, but
debugging memory leaks are tricky if the program is not using
different classes to store data :-).

Is anybody else seeing this?.

I am currently generating two independent reports and sending data to
five online services, including awekas (702, 2013-10-29).

Just to let you know. Suggestions welcomed.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/
jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUot0SJlgi5GaxT1NAQI3GgQAm8oV525+I4eMAsDkKFIlJbCkxPIWAZsy
qcfsITxnFPPPRzBG76dxc1qb9OCtgKupWXH9GEaHahRacjHoevq424prstaWqzRq
2MQBFdrGbgrCQy/9rm6drnz57uloUEJfrlnKqCo9sxTkJ+IYpoNPRqq3AO8e/SS7
JF/dxVIGPcg=
=g0qC
-----END PGP SIGNATURE-----

[mwall]

On Tuesday, November 19, 2013 9:23:05 AM UTC-5, Jesus Cea wrote:

OOM killer is killing my weewx program from time to time. I am seen
this problem since I upgraded to 2.5, but I am sending my data to
quite a few online services (recent change), so maybe the problem
existed too in 2.4.

Currently my weewx process is growing around 2MB per hour so far. My
archive interval is 5 minutes. I will try to debug it myself, but
debugging memory leaks are tricky if the program is not using
different classes to store data :-).

Is anybody else seeing this?.

jesus,

could you tell us what kind of station you are using?

i have noticed a leak as well, but i'm not yet sure where it is coming from.  it has been happening since at least 2.4 (that is when i started monitoring the computer resources).  this is on an arm-based plug computer with a ws28xx station, running weewx 2.5.0 with exfoliation skin 0.22, NWS and WU forecasting, extstats, and cmon.

you can see the leak in the attached image.  i have not yet had time to quantify it.

m

[Vince Skahan]

Yup - I see it too on 2.5.0 on a Seagate Dockstar (essentially a pogoplug) connected via USB/serial adaptor to a VP2.  I'm running Wunderground forecasting, cmon, and some small local skins.  Nothing too complicated.  Webserver is apache2 on Debian 7.x - fully up to date as of Sunday when I rebuilt the whole system.

Guess I should turn swap on before it goes boom.

[Thomas Keffer]

Well, a lot of new stuff was added with v2.5, so there are a lot of candidates!

I would suspect either the new search list extensions, or the forecast module. Is anyone running v2.5 without the forecast module and seeing the leak? That would narrow it down.

I tried very hard in the architecture of weewx to avoid cyclical memory references. As I understand it, Python will eventually discover them and delete them, but only if they do not have a __del__ method. None of the weewx objects do, but it's possible they inherit from something that does.

If someone wants an interesting, but potentially challenging project, try instrumenting weewx with one of the many Python memory debugging tools out there, such as objgraph, or Heapy.

-tk

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 19/11/13 19:06, mwall wrote:

> jesus,
>
> could you tell us what kind of station you are using?
>
> i have noticed a leak as well, but i'm not yet sure where it is
> coming from. it has been happening since at least 2.4 (that is
> when i started monitoring the computer resources). this is on an
> arm-based plug computer with a ws28xx station, running weewx 2.5.0
> with exfoliation skin 0.22, NWS and WU forecasting, extstats, and
> cmon.

This is a WH1080 station.

I have quite a few reports, and REST services enabled. I played
bisection with them and I am pretty sure that the issue is in report
generation. It is not in the FTP service neither in the REST client.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/
jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUpNdlZlgi5GaxT1NAQIW9wP9E8FtB24U2HwCps4Y8LFyzG/GGqrM4zOQ
QzZqBFlYkdXyb6QMXl90fnnpNZEzEjN6HAuWXjDu2i5jr9z5jzTHnb/XVDFPdTT2
+goMHxGCNZrTYmWA0Z/VKGacjKdIijvNWVZcJeWKzi6PNhtkRTuNM60Zn0yurAnO
m19MST2d7J8=
=NTJa
-----END PGP SIGNATURE-----

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 25/11/13 15:24, Jesus Cea wrote:

> I have quite a few reports, and REST services enabled. I played
> bisection with them and I am pretty sure that the issue is in
> report generation. It is not in the FTP service neither in the REST
> client.

Neither in the "phone home" feature (for the user map in weewx website).

I disabled everything. No leaks. I activate ONLY a simple report, with
no graphics and a single webpage. Nothing else, neither the FTP
upload. It leaks a bit. Then I enabled my main report, more heavy,
graphics, etc., and it leaks about 90 MB/day.

So, my bet is the report generation system.

I just add a "gc.collect()" in the main loop, to discard cyclic
references. Hope I did correctly. It still leaks.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/
jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUpNkoplgi5GaxT1NAQJRSgP+L7WmfpS/MmajaRrm0iEv4JsSj8P7awRR
b25iz/qm7452rR0tVsrm0BVxpIK1yb63OLKeEnhNbW8/cobg2RFbAU/tkWRAtqT7
GkC3oTAabtdsv/sBi0SZ2R6DgqDaTkYv89/YshsLD0aqHodlyA+PuYBHn5grSmcc
RPga1niF/Uc=
=zJzL
-----END PGP SIGNATURE-----

[Thomas Keffer]

Jesús,

Thanks for your careful, thoughtful sleuthing!

When you tried a "single web page," did it make use of CheetahGenerator, the new report generator? That is, did you use templates?

It's the only thing that changed significantly over the last couple of releases.

-tk

On Mon, Nov 25, 2013 at 6:54 AM, Jesus Cea <jc...@jcea.es> wrote:

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 25/11/13 15:24, Jesus Cea wrote:

> I have quite a few reports, and REST services enabled. I played
> bisection with them and I am pretty sure that the issue is in
> report generation. It is not in the FTP service neither in the REST
> client.

Neither in the "phone home" feature (for the user map in weewx website).

I disabled everything. No leaks. I activate ONLY a simple report, with
no graphics and a single webpage. Nothing else, neither the FTP
upload. It leaks a bit. Then I enabled my main report, more heavy,
graphics, etc., and it leaks about 90 MB/day.

So, my bet is the report generation system.

I just add a "gc.collect()" in the main loop, to discard cyclic
references. Hope I did correctly. It still leaks.

- --
Jesús Cea Avión                         _/_/      _/_/_/        _/_/_/

jc...@jcea.es - http://www.jcea.es/     _/_/    _/_/  _/_/    _/_/  _/_/
Twitter: @jcea                        _/_/    _/_/          _/_/_/_/_/
jabber / xmpp:jc...@jabber.org  _/_/  _/_/    _/_/          _/_/  _/_/
"Things are not so easy"      _/_/  _/_/    _/_/  _/_/    _/_/  _/_/
"My name is Dump, Core Dump"   _/_/_/        _/_/_/      _/_/  _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 25/11/13 16:20, Thomas Keffer wrote:
> When you tried a "single web page," did it make use of
> CheetahGenerator, the new report generator? That is, did you use
> templates?

Yes and yes.

I also suspected Cheetah, so I just commented out the Cheetah
invocation in weewx code:

"""
diff -r 7220c8a59334 bin/weewx/cheetahgenerator.py
- --- a/bin/weewx/cheetahgenerator.py Thu Nov 21 00:48:00 2013 +0100
+++ b/bin/weewx/cheetahgenerator.py Tue Nov 26 03:41:43 2013 +0100
@@ -245,10 +245,11 @@

searchList = self._getSearchList(encoding, timespan,
archivedb, statsdb)
- - text = Cheetah.Template.Template(file=template,
- - searchList=searchList,
- - filter=encoding,
- -
filtersLib=weewx.cheetahgenerator)
+# text = Cheetah.Template.Template(file=template,
+# searchList=searchList,
+# filter=encoding,
+#
filtersLib=weewx.cheetahgenerator)
+ text = "TEST!"

with open(_fullname, mode='w') as _file:
try:
"""

It still leaks. Same leak size.

I wrote a decorator to print memory used before and after a given
function. We can discard "weewx.cheetahgenerator.generate" from the
equation. We can discard "weewx.cheetahgenerator.run" too.

The right approach would be to decorate top-level functions and go
down from there, instead of going bottom-up. Just tried those
functions because I was suspicious of Cheetah.

If you want to play around with it:

File "memoryleak.py":

"""
from functools import wraps
import os
def logMem(f) :
pid = os.getpid()
@wraps(f)
def wrapper(*args, **kwargs) :
size = int(open("/proc/%d/statm" %pid).read().split()[0])
try :
return f(*args, **kwargs)
finally :
size2 = int(open("/proc/%d/statm" %pid).read().split()[0])
print >>open("/tmp/zz", "a"), \
f.__module__+"."+f.__name__,size, size2
return wrapper
"""

And you decorate functions with "@memoryleak.logMem".

Too bad we don't have class decorators in Python 2.7 :-)

Using this decorator to prune big sections of the code, I think the
issue should be findable easily.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/

jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUpQoFJlgi5GaxT1NAQL0GQQAnojLv7kUezpC5Q6JOOsCqoZ7rJbxlt20
Hgc/mELipPgm92zXHFouDve4ag+XOi6FL8c4LaF3UQ3zRits55abTmvYone88NY/
R3E6t5LuJ8mOz/Jelu4zhL9KDE48R3MiETXM8RlcPsOQUMQm4+Oj4cRifBbmC5Zp
Lj5KcNL5MXU=
=6pcs
-----END PGP SIGNATURE-----

[Thomas Keffer]

Thanks, Jesús! That looks like a useful tool. Unfortunately, I am away from my office (and Linux computer) for a couple of months, so I won't have a chance to try it. Perhaps someone else can?

-tk

- --
Jesús Cea Avión                         _/_/      _/_/_/        _/_/_/

jc...@jcea.es - http://www.jcea.es/     _/_/    _/_/  _/_/    _/_/  _/_/
Twitter: @jcea                        _/_/    _/_/          _/_/_/_/_/
jabber / xmpp:jc...@jabber.org  _/_/  _/_/    _/_/          _/_/  _/_/
"Things are not so easy"      _/_/  _/_/    _/_/  _/_/    _/_/  _/_/
"My name is Dump, Core Dump"   _/_/_/        _/_/_/      _/_/  _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

[John Harvey]

I’ve been looking at this since I am suffering from this as well and its been confusing me a lot.

Part of the problem is separating fragmentation from leaks.

Anyway I think I just found the cause for me which is the PIL image library draw.text method leaks.

I’ve commented that out and most of the rest of the code is the same (not completely so I will need to put things back together to be completely sure) and memory usage seems to be stable.

 

So this would depend on the system you have and whether it has replace image with PIL and also possibly what version of PIL is being used I guess.

I’ll dig into that a bit more tonight.

 

Jesus to test this comment out all the calls to draw.text in bin/weeplot/genplot.py and see if that helps for you as well.

 

 

John

[Thomas Keffer]

Hi, John

Thanks for your sleuthing. If you learn more, I'd like to know about it.

PIL has been at version 1.1.7 for as long as I remember. I would be surprised if there are versions of Python out there using an earlier version.

-tk

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 11/12/13 15:03, John Harvey wrote:
> What i realised after i sent the email the system i am seeing this
> on is using Pillow not PIL. I've downloaded the source for that to
> read through.

I am using Pillow too. Version 2.1.0.

I am still debugging this myself. It is being quite difficult and I am
getting interesting but very confusing results:

"""
2013-12-11 15:12:27: Top 10 allocations per file and line
#1: .../python2.7/site-packages/configobj.py:532: size=4984 KiB,
count=26180, average=194 B
#2: .../python2.7/site-packages/configobj.py:604: size=3665 KiB,
count=44282, average=84 B
#3: .../bin/weedb/sqlite.py:113: size=2642 KiB, count=57650, average=46 B
#4: .../python2.7/site-packages/configobj.py:605: size=1987 KiB,
count=2103, average=967 B
#5: .../python2.7/site-packages/configobj.py:1319: size=1881 KiB,
count=30395, average=63 B
#6: .../python2.7/site-packages/configobj.py:1611: size=1817 KiB,
count=12575, average=148 B
#7: .../python2.7/site-packages/configobj.py:641: size=1733 KiB,
count=1584, average=1120 B
#8: .../python2.7/site-packages/configobj.py:1629: size=1166 KiB,
count=38814, average=30 B
#9: .../python2.7/site-packages/configobj.py:1367: size=1154 KiB,
count=1260, average=938 B
#10: .../bin/weedb/sqlite.py:117: size=1038 KiB, count=31212, average=34 B
5451 more: size=18 MiB, count=258541, average=76 B
Total Python memory: size=40 MiB, count=504596, average=83 B
Total process memory: size=120 MiB (ignore tracemalloc: 15 KiB)

1 snapshots
"""

According to tracemalloc (ignore linenumbers, I am patching the
source), A lot of data generated in "configobj" is kept around by
"somebody". Still investigating.

When doing a "gc.collect()" and keeping the collected objects around
(gc.set_debug), I see tons and tons of "configobj" objects collected.
They are collected "eventually", but memory usage is high for no reason.

Example:

"""
>>> type(gc.garbage[1])
<type 'cell'>
>>> type(gc.garbage[2])
<type 'cell'>
>>> type(gc.garbage[3])
<type 'tuple'>
>>> type(gc.garbage[4])
<type 'function'>
>>> gc.garbage[4]
<function recursive_interpolate at 0x1cc9fb0>
>>> gc.garbage[1]
<cell at 0xb2724f10: function object at 0x1cc9fb0>
>>> gc.garbage[2]
<cell at 0xb2724d70: ConfigParserInterpolation object at 0xb27243f0>
>>> gc.garbage[3]
(<cell at 0xb2724f10: function object at 0x1cc9fb0>,
<cell at 0xb2724d70: ConfigParserInterpolation object at 0xb27243f0>)
"""

I have zillions of collections like that. This data to be kept around
for no reason is a typical cyclic reference pattern. Still trying to
find the culprit.

That is beside the leaking, still investigating.

I have a presentation tonight in Python Madrid user Group. I was
expecting to show a diagnostic and a patch there, but I haven't found
the bug yet. Too bad.

<http://www.python-madrid.es/post/reunion-python-madrid-diciembre-2013/>

John, do you confirm that commenting "draw.text" you don't see the
leak anymore?. In my initial tests I had an skin with NO GRAPHICS with
a small memory leak. That is, there was a leak there too, althought
far smaller. Maybe I was seeing the building of circular references
that would be eventually collected and I was not patient enough.
Please confirm that commenting "draw.text" you don't see the leak anymore.

PS: If not related, circular references with "configobj" data should
be addressed, because "peak memory" is now far higher that it could
be, and CPU usage for periodic full garbage collection is wasted too.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/

jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUqh5KZlgi5GaxT1NAQIijQQAnHAM5GrnQIbDuQv5v8+Ez6klWCH4Lhtz
ondgaaDFqPPu4H6Zj4/RxT/KwPGfjUgj/285OiB34R7IJAbntTyogr5rCxPX70CO
T9s6eMcW2mbQ0WGKU39uq/JGIDbwNd01kNcg9CHEHgReORoIDrHN9nnwMUBZfcij
lwiMrKTMgoQ=
=cRz1
-----END PGP SIGNATURE-----

[Thomas Keffer]

Thanks, Jesus. Interesting conclusions.

ConfigObj is used extensively in weewx. It holds the configuration information from weewx.conf and skin.conf. Many objects do reference it.

However, offhand, I do not see how it could be involved in a circular reference, at least within weewx. A ConfigObj object tends to get created by reading from a configuration file, then various parts of it get referenced. At no point does weewx pass in a reference to itself (via a callback, or something like that).

If ConfigObj is the culprit, it's more likely from fragmentation than from circular references.

-tk

- --
Jesús Cea Avión                         _/_/      _/_/_/        _/_/_/

jc...@jcea.es - http://www.jcea.es/     _/_/    _/_/  _/_/    _/_/  _/_/
Twitter: @jcea                        _/_/    _/_/          _/_/_/_/_/

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 11/12/13 15:49, Thomas Keffer wrote:
> However, offhand, I do not see how it could be involved in a
> circular reference, at least within weewx. A ConfigObj object tends
> to get created by reading from a configuration file, then various
> parts of it get referenced. At no point does weewx pass in a
> reference to itself (via a callback, or something like that).

The fact is that "tracemalloc" is telling me about hundred of
thousands of objects created INSIDE "configobj" kept alive by
"somebody". Trying to find the "somebody" :-).

Look at this:

"""
>>> sys.getrefcount(configobj.ConfigObj)
20
>>> gc.collect()
3957
>>> sys.getrefcount(configobj.ConfigObj)
5
"

That is, there were 20 "ConfigObj" instances and, after forcing a full
collection (that frees 3957 objects!), weewx only keeps 5 "ConfigObj"
instances. The only reasons I know for an object to be unreachable but
not collected is a) reference cycles and b) objects with "__del__()".
Since the objects are collected when doing "gc.collect()", I only can
think of option "a".

Still investigating, though.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/

jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUqh+EZlgi5GaxT1NAQJmuQP9Erpv96uTxTUwnRKqLpJzJ6HpFpuyKDau
Nz/G9R3G4pjXCVstb9N8DbaiPusP6y2cT++BrlZnpJfHIlqVB5rGzP9yTBrtyIZq
R1/2D28XHDSTaS5xcrM/I8PBKIk6CwUKFp7y1ZY+wZxFIdXffEbcZM8QQ8Ia57b6
pLGqCM8hl1U=
=AgDj
-----END PGP SIGNATURE-----

[Thomas Keffer]

I think you're on the right track. Looking through the source of ConfigObj, I do not see a __del__ method.

All weewx services, including report services, hold a reference a ConfigObj object holding either the parsed contents of weewx.conf or skin.conf, so I am not surprised that there are many instances. However, they should all be parsed once, on program startup. After that, all references should be simple lookups --- I would not expect them to generate many new objects and consume memory.

-tk

- --
Jesús Cea Avión                         _/_/      _/_/_/        _/_/_/

jc...@jcea.es - http://www.jcea.es/     _/_/    _/_/  _/_/    _/_/  _/_/
Twitter: @jcea                        _/_/    _/_/          _/_/_/_/_/
jabber / xmpp:jc...@jabber.org  _/_/  _/_/    _/_/          _/_/  _/_/
"Things are not so easy"      _/_/  _/_/    _/_/  _/_/    _/_/  _/_/
"My name is Dump, Core Dump"   _/_/_/        _/_/_/      _/_/  _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

[John Harvey]

I have been doing my head in looking at this as well.Things seem to move around a lot as you change code and some of it i think is down to memory fragmentation.

I have a few extra deletes happening and i'm also running a gc.collect() in the DispatchEvent loop and i think some of these help with getting the garbage collection to work properly.

So yes with those changes and draw.text removed at least when i left it this morning it didnt seem to be leaking but i will need to check when i get home since i only left it running for about 20 minutes.

 

I was also concerned about configobj but i dont think that is a problem if we trigger garbage collection (which we shouldnt need to do).

 

So you could also try adding gc.collect() to the end of the DisaptchEvent loop as well.

 

I suspect there is more than 1 thing going on but i wonder if these calls to collect help with freeing things earlier and then memory fragmentation.

 

I will keep looking.

 

John

 

 

From: Jesus Cea <jc...@jcea.es>
To: weewx-de...@googlegroups.com
Sent: Wednesday, 11 December 2013, 15:00
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

Jesús Cea Avión                        _/_/      _/_/_/        _/_/_/

[John Harvey]

What i realised after i sent the email the system i am seeing this on is using Pillow not PIL.

I've downloaded the source for that to read through.

 

John

 

jabber / mailto:xmpp%3Aj...@jabber.org  _/_/  _/_/    _/_/          _/_/  _/_/

"Things are not so easy"      _/_/  _/_/    _/_/  _/_/    _/_/  _/_/
"My name is Dump, Core Dump"   _/_/_/        _/_/_/      _/_/  _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

[Thomas Keffer]

As I understand it, garbage collection in Python runs automatically once a threshold of allocated vs unallocated objects is reached. Running gc.collect() does not affect whether it runs, only when it runs.

But, I could be wrong on this.

-tk

[John Harvey]

I think I’ve just found the leak in pillow.

I’ve only been running for a short time but there is a leak in its drawtext function that leaks a FreeType Glyph on every call to drawtext for each character.

This is in the latest version I downloaded the source for.

 

I’ll report it to Pillow & PIL mailing lists. But if you want to try it then in pillow’s source in the file _imageingft.c in font_getsize(…)

 

After the calls

FT_Get_Glyph(…)

FT_Glyph_Get(…)

 

Add

FT_Done_Glyph(glyph);

 

 

And yes I agree with your comments about gc.collect(). The only possible thing I think it could change is memory fragmentation. But now I’ve got rid of my big leak I can put everything back together and see what happens.

 

John

[John Harvey]

And 1 more thing this bug is just in pillow which explains why I don’t see it in the system using PIL and why it started happening for me recently (ish) when Arch Linux replaced PIL with PILLOW.

 

So I’ll just report it to Pillow.

 

John

[Thomas Keffer]

Question: does this Freetype glyph have a __del__ function, preventing it from being garbage collected? I mean, what is causing the leak?

-tk

[John Harvey]

No its c code implementation around the freetype library so not related to pythons garbage collecting.

It has been reported against pillow and acknowledged and they appear to be trying to do a point release (2.2.2) in the next few days which might include this fix if we are lucky, if not it looks like there might be a 2.3.0 within a month.

 

Unfortunately this isn’t the whole thing. It is my big leak but the memory usage has been creeping up slowly overnight.

After 9 ½ hours it was using 10695Kb

After about 13 hours it is now using 10733Kb

 

So this isn’t the complete answer but much better.

I am running most of the code again.

 

I’ve just removed  the reportgenerator and put the imagegeneration back to the complete code again so I’ll leave that running for the day and see how that looks.

 

John

[John Harvey]

I have continued investigating and I was convinced there was still a leak in the Pillow libraries. I ended up writing a test app that sat in a loop and created images & drew text and have just found it.

Pillow is leaking the font names every time we call getfont which we do for every graph each time it is drawn.

So  have a fix for it and the problem also occurs in the original PIL code and my test app has created over 200,000 images with no leaks.

 

We could avoid it (and probably speed things up very slightly) if we cached the font handles since we will be recreating almost identical ones for each graph.

If you think this would be worth doing I can consider looking at it after Christmas.

Anyway I will submit an issue to PIL & Pillow later in the week as well.

I’ve just restarted weewx with the fix and will see what it looks like (just running imagegenerator at the moment).

Then I will start putting all the code back together again and see what it looks like.

[Thomas Keffer]

That's great news, John!

I'm not a big fan of caching, but if it solves this problem, it's worth it.

Let me know what you come up with and we can put it in the code base.

-tk

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 24/12/13 22:21, Thomas Keffer wrote:
> That's great news, John!
>
> I'm not a big fan of caching, but if it solves this problem, it's
> worth it.
>
> Let me know what you come up with and we can put it in the code
> base.

Good catch, John.

Please, do not work around this problem unless pillow guys are not
responsive. Let them fix it. Just warm the user about what pillow
version they should install when the fix is available. LOUD.

I am seeing configobj creating tons and tons of cycles. They are
eventually cleaned up, but transient memory usage is huge, because
weewx needs several archive cycles (growing memory everytime) before
the python cycle collector is able to clean up tens of thousand of
garbage objects.

I consider this to be an ugly bug of configobj that needs to be fixed.
But last release was in 2010. Is it alive yet?.

In the meantime, I would do this:

1. "gc.disable()" before the mainloop: because python tries to do the
collection during the archive processing. This is not effective,
because those objects are alive yet, so you suck CPU without getting
anything in exchange.

2. In the mainloop, do "gc.collect()" in every cycle: So you drop
garbage object cycles between loop runs.

So you will still have a "sawchain" memory use, but at least the
shawchain peaks are smaller. In my case, with simple templates, I save
like 50 megabytes of memory just doing that (in my case, I need three
or four archive events before the cycle collector can do the cleanup).

If configobj is still maintained, we should bug the owner. If not...
how difficult would be to replace it?.

Maybe weewx could be patched to use configobj in a less "insane" way,
I didn't investigate further. The main culprit is
"recursive_interpolate". I have tons of garbage cycles with them.

For me, I have two tendencies. In the short term, a sawchain memory
usage. "configobj" is the culprit here. The long term is a slow memory
leak. Maybe John fix (for PILLOW) could be enough to solve it. I see a
growing number of Python objects in the process, not a "hidden" memory
leak in a extension. I don't know the details of John findings, so I
can't tell.

John, please, let me know about your bug report to pillow guys when
you write it.

Good work and Merry Christmas :)

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/

jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCUAwUBUrpO25lgi5GaxT1NAQLQngP3dnjBiI2Q4wnuBgVzpsxIkyHCkivf6J8o
s67J+4qj1SDXPkIH4SbH4rxrsiv26eQWVp5hRP6ZkNOZyTPmEvAoickzQWaYvCaE
/ySa7Owt1wzMd8IRNufkZdflforou0v7+5rTvT839ZnffS3nbqdOizHXBsxzMhnv
G2rAPaiRBg==
=bJXu
-----END PGP SIGNATURE-----

[Thomas Keffer]

Hi, Jesus

Good comments.

Unfortunately, as the vast majority of weewx users are using PIL, which  is no longer under development, we will have to patch weewx anyway.

Waaaay back in weewx v1.10 I put in a call to gc.collect(), pretty much as you describe: after an archive record has finished being processed. I took it back out after the 2.0 rewrite because it didn't seem to be making any difference. Certainly not the 50 MB you are reporting. How did you measure this?

If the problem is truly recursive interpolation, that would not be hard to change. Interpolation is used in only one place: in the specification of the sqlite databases in section [Databases]. Finding an alternative would not be hard. But, how did you determine that this is the problem? 

In summary, I want to make sure any changes we make are data driven, and not chasing anecdotal impressions.

-tk

- --
Jesús Cea Avión                         _/_/      _/_/_/        _/_/_/

jc...@jcea.es - http://www.jcea.es/     _/_/    _/_/  _/_/    _/_/  _/_/
Twitter: @jcea                        _/_/    _/_/          _/_/_/_/_/
jabber / xmpp:jc...@jabber.org  _/_/  _/_/    _/_/          _/_/  _/_/
"Things are not so easy"      _/_/  _/_/    _/_/  _/_/    _/_/  _/_/
"My name is Dump, Core Dump"   _/_/_/        _/_/_/      _/_/  _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

[John Harvey]

So just an update on where we are

My system is using a Davis Vantage VUE with the archive interval at 1 minute and of course since most of this is related to archive processing the archive rate will affect the rate at which we leak.

 

Issue 1)  There is 1 issue in PILLOW which leaks huge amounts of memory (Mb’s per hour) leaking 1 glyph per character rendered to an image.

https://github.com/python-imaging/Pillow/issues/446 has been submitted and should therefore be in the 3.0 release which looks to be coming soon.

 

Issue 2) There is a leak of filenames passed to getfont in PILLOW and PIL. I have submitted a pull request to PILLOW for this

https://github.com/python-imaging/Pillow/pull/459 and also reported against PIL https://bitbucket.org/effbot/pil-2009-raclette/issue/39/getfont-can-leak-the-memory-used-for . I hope this will get into the next PILLOW release as well . I don’t expect anything to happen for PIL though. This leak is approximately 40Kb per hour. I will try to generate a workaround for this in weewx and I think I know what I will do now and I don’t think it will be hard.

 

Remaing issues. I still have a leak of about 4Kb per hour which I am seeing using the simulator and only running StdArchive & StdPrint services.

So that rules out things like USB libraries talking to the weather station. I am running the simulator as fast as I can with a 1 minute archive interval (any less than that and I hit a divide by Zero somewhere)

This morning I stopped the Archive service writing to the database and I had a small memory increase after 1.4 hours but it has stayed the same since then (9.5 hours). So I guess this leak is probably somewhere in the database writing code.

I’m going to leave it running overnight and see what it looks like tomorrow morning.  Then I’ll try and enable statsdb writing only and see what happens and move on from there.

 

This is with sqlite and it could be different with mysql depending on where the error is.

 

John

 

 

 

From: weewx-de...@googlegroups.com [mailto:weewx-de...@googlegroups.com] On Behalf Of Thomas Keffer
Sent: 25 December 2013 13:14
To: weewx-de...@googlegroups.com
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

 

Hi, Jesus

[Thomas Keffer]

Outstanding sleuthing, John! 

This has been an annoying issue with me for months, and I'm glad to see you're finally wrestling it to the ground!

-tk

[John Harvey]

PILLOW has now merged the fix https://github.com/python-imaging/Pillow/pull/459 into its latest code so when PILLOW 3.0 releases things should be much better.

 

It looks like our last leak is in sqlite writing to the database so I wrote a test application to try it and it shows the same results.

Using a copy of the archive database it repeatedly adds rows increasing the timestamp each time  which showed the same memory increase of about 30Kb per ~640 insertions. This carried on until we had inserterd 12231 times and at that point the memory stopped growing.  In my test app I hit this point after 23 minutes and left it running for 9 hours and it still hadn’t changed.

I tried using apws instead of pysqlite and that seems to be faster but has similar growth. So I suspect this is some sort of caching going on in sqlite and isn’t worth chasing.

If my calculations are correct with 1 insertion happening at each archive interval (per database) and that happening at most every minute  then it would take 8 to 9 days before our memory stabilises and I haven’t been leaving any of these tests running that long.

 

So I am not intending to chase this memory leak any more and I think once I get the code written to work around the font leak then things are probably ok. So I’m going to start concentrating on that now.

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 31/12/13 12:56, John Harvey wrote:
> So I am not intending to chase this memory leak any more and I
> think once I get the code written to work around the font leak then

> things are probably ok. So I?m going to start concentrating on that
> now.

Pillow 2.3.0 is just released. Lets try it.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/

jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUsVZWplgi5GaxT1NAQKVlwP+JV0VUIVEiXRQwtvyabTv0ZKYD3hOptQt
nMosA8N04te4FeXXrbc9d4dgO32lOEZKiYV1snlkQXPeP/W/1rPYr9B6Lpd9bIZ7
ffUeeTO0dzT2hY+7qp+ONyy14CrZ1VdfQce6SZNvw2GeZh31nd/A+p/iLkTsqLAJ
cf7iUhYSUPc=
=ey8e
-----END PGP SIGNATURE-----

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

After upgrading to Pillow 2.3.0 and Weewx 2.5.1, I don't see leaks
anymore, after four days.

John, great hunting.

Thanks.

- --
Jesï¿œs Cea Aviï¿œn _/_/ _/_/_/ _/_/_/
jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQCVAwUBUshaL5lgi5GaxT1NAQLY7QP/atB6BOFn64fKJLKx6l4KcD9e58kcDXXw
uhiN3Mb3qXO0YR4MAkRcfSkmNfQ6H1fCjiJzUtUbSq6a9XxznclDakP5XNfYajfv
EZoJ8WQm5XrEpino2lZXYKm2KLJ27VY171v3ehg2kPSqHmOQag+sfnDP0IUbCQoE
gTW3qbWBTLY=
=8ry6
-----END PGP SIGNATURE-----

[John Harvey]

That’s great thanks for the feedback and also the memoryleak utility which I
used in a modified form to find these.
And also form prompting me to look at it since it was when I saw your
original email I realised why my system was playing up and not responding
properly,

John

-----Original Message-----
From: weewx-de...@googlegroups.com
[mailto:weewx-de...@googlegroups.com] On Behalf Of Jesus Cea
Sent: 04 January 2014 19:00
To: weewx-de...@googlegroups.com
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

After upgrading to Pillow 2.3.0 and Weewx 2.5.1, I don't see leaks anymore,
after four days.

John, great hunting.

Thanks.

- --

Jesús Cea Avión _/_/ _/_/_/ _/_/_/

[Thomas Keffer]

John and Jesus

Have you had a chance to try the patch? I've been running v2.6.0a5, which includes the patch, and I can't see it making any difference. Over 5 days

VIRT: from 66.2 Mb to 70.1 Mb

RES: from 19.8 Mb to 23.1 Mb

Have you two had any better luck?

-tk

[mwall]

On Thursday, January 30, 2014 7:17:10 PM UTC-5, Thomas Keffer wrote:

John and Jesus

Have you had a chance to try the patch? I've been running v2.6.0a5, which includes the patch, and I can't see it making any difference.

tom,

it seems to have worked for me.  this is weewx 2.5.1 plus the patch on an ionics plug computer (arm cpu) running debian 6.

m
 

[John Harvey]

The problem is my low memory system that was really suffering has the fixed version of PILLOW on it as well so the patch doesn’t help there. But there is also an underlying growth in cached memory use within the sqlite libraries which will go on for several days before hitting a peak. And how long that lasts for will depend on your archive interval. I think it is about 5 days with a 1 minute archive interval so with a 5 minute interval  that could be a few weeks. So this could well be that.

Do you have a comparison for running without the patch?

 

John

[Thomas Keffer]

Matthew, I can't read the vertical scale on your plot. Do you have the numbers? Also, is this the virtual image size, or the resident image? 

Finally, which do we care about? 

-tk

[mwall]

On Friday, January 31, 2014 10:49:45 AM UTC-5, Thomas Keffer wrote:

Matthew, I can't read the vertical scale on your plot. Do you have the numbers? Also, is this the virtual image size, or the resident image? 

i guess we should sort out the y-axis scaling issues :)

the plots show memory use based on numbers in /proc/meminfo

the dark green line is total memory of 513548 kB

the sawtooth (light green) is MemTotal - MemFree.  it ranges from 237 MB to 326 MB.  before the patch was applied it got up to almost 400 MB.

weewx was restarted on 14 january.  the patch was applied and weewx restarted again around 21 january.

the sawtooth pattern is caused by a ramdisk filling up with log files then being flushed by logrotate.

the memory leak was causing the upward climb of the sawtooth.

weewx, apache, and some power monitoring (btmon, rtmon) are the only things running.  before applying the patch, i verified that the upward climb happened only when weewx was running.  (there is another small upward climb caused by the thermostat monitor, but that is due to some rrdtool caching and it is much smaller than the climb caused by weewx)

in october/november, the sawtooth climbed all the way up to the total memory, but a power outage took the system down before i could see what happened when the system ran out of memory (there is no swap).

m

[Thomas Keffer]

Any way to tell how much of that memory is used by weewx? I'm sure hoping it isn't 200+ Mb!

And, because you have no swap space, this is the equivalent of RES memory?

-tk

[mwall]

On Friday, January 31, 2014 12:28:05 PM UTC-5, Thomas Keffer wrote:

Any way to tell how much of that memory is used by weewx? I'm sure hoping it isn't 200+ Mb!

i'm not tracking weewx specifically, so no.  however, current usage as reported by ps is VSZ=77360 RSS=37264

on a different system (dual core x86, with virtual memory) the usage looked like this:

DATE, VSZ, RSS
11:30:21 04-12-2013, 377536, 101628
12:06:03 04-12-2013, 377536, 102492
18:19:59 04-12-2013, 377536, 104632
19:22:18 04-12-2013, 227940, 66656
08:03:25 05-12-2013, 310204, 86276
11:04:01 05-12-2013, 310204, 86724
21:38:53 05-12-2013, 383936, 100440
17:03:38 06-12-2013, 384068, 106636
13:38:10 08-12-2013, 384068, 126568
13:02:46 09-12-2013, 384224, 136392
08:06:26 11-12-2013, 384224, 150952
08:20:19 12-12-2013, 311012, 92848
13:19:36 13-12-2013, 319208, 100936
15:18:23 13-12-2013, 319340, 101036

each time the memory dropped it was because weewx was restarted.  patch has not yet been applied to that system.

 

And, because you have no swap space, this is the equivalent of RES memory?

i don't know about that.

i supposed i could extend cmon to track memory usage of individual apps...  then we could call weewx "nagios junior" :)

m

[Thomas Keffer]

The memory patch in v2.6 doesn't seem to be working for me. Here's a chart of memory usage over the last few days. Steadily climbing. Now, maybe it's all in the sqlite library and it will level off, but I doubt it. 

-tk

[Thomas Keffer]

I did some of my own tests by running the report engine repeatedly, measuring the memory usage. It seems to stabilize after 30-50 loops through, the equivalent of a few hours use.

I then added garbage collection every 10th pass through and the total memory use stayed rock steady at about 37 Mb RSS. 

So, if there's a leak, it's got to be in something besides the reporting system.

I've added explicit garbage collection to the main engine loop. Now every 10th time through, it collects. I've restarted my station  ---- we'll see what happens.

-tk

[Vince Skahan]

Tom can you post how you made your graph happen ?  I can hook it into my 2.6.0a6 setup and let it run for a bit if you want.

[mwall]

On Tuesday, February 4, 2014 3:31:12 PM UTC-5, Vince Skahan wrote:

Tom can you post how you made your graph happen ?  I can hook it into my 2.6.0a6 setup and let it run for a bit if you want.

gary,

tom probably has someting in like two lines of python.  but here is a service called pmon (ProcessMonitor) you can use to monitor vsz and rss.  put it in bin/user then add this to weewx.conf:

[ProcessMonitor]
    database = pmon_sqlite
    max_age = None
    process = weewxd

[Databases]
    [[pmon_sqlite]]
        root = %(WEEWX_ROOT)s
        database = /var/lib/weewx/pmon.sdb
        driver = weedb.sqlite

then put this in skin.conf:

[ImageGenerator]
    [[day_images]]
        [[[dayproc]]]
            archive_database = pmon_sqlite
            [[[[mem_vsz]]]]
            [[[[mem_rss]]]]

[mwall]

sorry!  vince, not gary!

[Thomas Keffer]

Matthew's cmon extension is much more elegant. But, I wanted something temporary where I would not have to mess with the database. This weewx service will put memory data in soilMoist1, soilMoist2, and soilMoist3. 

Put in user/mem.py Then add user.mem.Memory to the end of process_services in weewx.conf. 

import os

import resource

import weewx

from weewx.wxengine import StdService

class Memory(StdService):

    

    def __init__(self, engine, config_dict):

        # Pass the initialization information on to my superclass:

        super(Memory, self).__init__(engine, config_dict)

        self.page_size = resource.getpagesize()

        self.bind(weewx.NEW_ARCHIVE_RECORD, self.newArchiveRecord)

    def newArchiveRecord(self, event):

        

        pid = os.getpid()

        procfile = "/proc/%s/statm" % pid

        try:

            mem_tuple = open(procfile).read().split()

        except (IOError, ):

            return

         

        # Unpack the tuple:

        (size, resident, share, text, lib, data, dt) = mem_tuple

        mb = 1024 * 1024

        event.record['soilMoist1'] = float(size)     * self.page_size / mb 

        event.record['soilMoist2'] = float(resident) * self.page_size / mb

        event.record['soilMoist3'] = float(share)    * self.page_size / mb

        

Modify skin.conf accordingly in order to plot:

    [[day_images]]

         ...

[[[dayMem]]]

  y_label = "Mb"

  [[[[soilMoist1]]]]

    label = VmSize

  [[[[soilMoist2]]]]

    label = VmRSS

  [[[[soilMoist3]]]]

    label = Shared

Then include dayMem.png, etc. in index.html.tmpl, etc.

-tk

[Thomas Keffer]

I added a call to garbage collection about once an hour. It seems to stabilize memory use after a couple days. I think John had it right.

The code base now has a call to do GC once every 3 hours.

-tk

On Tue, Feb 4, 2014 at 7:00 AM, Thomas Keffer <tke...@gmail.com> wrote:

[John Harvey]

That’s good to know.

It always seems strange that calling the garbage collection should be necessary but it does seem to change the behaviour enough which is strange.

 

John

 

From: weewx-de...@googlegroups.com [mailto:weewx-de...@googlegroups.com] On Behalf Of Thomas Keffer

Sent: 07 February 2014 20:17
To: John Harvey

Cc: Jesus Cea; weewx-de...@googlegroups.com
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

 

I added a call to garbage collection about once an hour. It seems to stabilize memory use after a couple days. I think John had it right.

[Thomas Keffer]

It does seems strange, but it seems to be working. After 2+ days, the memory usage is rock steady at about 68MB VSS, and 24MB RSS:

http://www.threefools.org/weewx/weekMem.png

I'm sure that if the call to garbage collect were not in there, memory usage would eventually stabilize, but it might take weeks, and it would probably be at a higher level.

Thanks John & Jesus! This has always nagged me!

-tk

[Thomas Keffer]

But, if you wait longer, memory usage clearly creeps up with time. Here's what it looks like after 16 days of up time (machine reboot on 8 February).

I don't know why there was the sudden jump in WmSize on 13 February. 

These are not big numbers (well under 1MB/day) and a machine could run like this for a year or more. But there is still either a memory leak in a library somewhere or, possibly, fragmentation. 

-tk

[John Harvey]

I would be interested to see what it is like in a couple of weeks. If you are using sqlite its memory usage and buffering is strange and takes a long time to stabilise so I still wouldn’t be surprised to see it settle down in another week or so.

 

If you can leave it running it would be interesting to see. I’ll add the monitoring like this to my 2 systems as well and see what they look like over the next couple of weeks.

[Thomas Keffer]

OK, I can do that.

-tk

[Thomas Keffer]

Well, I have now let weewx v2.6.2 run for a month. The memory usage looks like this:

If I squint my eyes I can sort of maybe not-sure see a slight decrease in the rate of growth, but it's not very convincing.

There's still a leak in there somewhere. I'm suspecting sqlite, but can't be sure. It would be interesting to see a similar chart, but for MySQL.

In any case, the rate of growth is very slow (well under 1 MB/day). Most systems can support that for months, or even longer.

-tk

[William Phelps]

I've been working on another project using python, and discovered a bug where python sometimes does not free objects when a function or class ends. It has to do with reusing the object name, when the object is a list. In my case since the list was fairly large, it would only run for about 10 hours or so before crashing. 

Apparently python's use count gets messed up by the re-use of the object name. I'm still pinning it down, but wanted to mention it here in case you recognize the symptoms. Python's "tri-valent" (my description) scope is a bit tricky and it looks like in this case they got something wrong...

William

[Thomas Keffer]

Not ringing a bell. Do you mean something like

a=[1,2,3]

a=[4,5,6]

or

a=[1,2,3]

a=len(a)

I'd be very surprised if either of these caused an issue, but I'd sure like to hear more!

-tk

[Jesus Cea]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 10/03/14 21:55, William Phelps wrote:
> Apparently python's use count gets messed up by the re-use of the
> object name. I'm still pinning it down, but wanted to mention it
> here in case you recognize the symptoms. Python's "tri-valent" (my
> description) scope is a bit tricky and it looks like in this case
> they got something wrong...

I am a python core developer. Please, try to triage this and let me
know the result.

- --
Jesús Cea Avión _/_/ _/_/_/ _/_/_/
jc...@jcea.es - http://www.jcea.es/ _/_/ _/_/ _/_/ _/_/ _/_/
Twitter: @jcea _/_/ _/_/ _/_/_/_/_/
jabber / xmpp:jc...@jabber.org _/_/ _/_/ _/_/ _/_/ _/_/
"Things are not so easy" _/_/ _/_/ _/_/ _/_/ _/_/ _/_/
"My name is Dump, Core Dump" _/_/_/ _/_/_/ _/_/ _/_/
"El amor es poner tu felicidad en la felicidad de otro" - Leibniz
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1

Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQEcBAEBCAAGBQJTIfiPAAoJEGjgN61Khv5DCHYH/3VORhe3PDsZNXk+vpKLtzHk
jqkw7teTvBqeFEoFAgIpbzs1pPytoGzycLGK9ow3sts3thMMVadSjq+oDRKkY3Bm
uRVwcCk/hUyTD8znc9kq42FPGwcMp0D5WMcbeFPHlj7v4sW/EX6oWxw9P+dmlTqi
hhHhZlSG92Aaud0CI3bBcKF/zI74JdC32TkWMDGpSEjPnEBT1pVf3qbzUNwBwX1a
lNtD42pCHhLlmylYJ5l5yg1GSgb9DssBo3NO1SGBpL2zya5hUiwyG24C99qa3a4C
yl6OH5L8iKfR7XCNupBNbpXmHXAfo1ODuyBwFh9kYysie9msToXdF1lW2o+MqfE=
=I2lj
-----END PGP SIGNATURE-----

[mwall]

here is another data point.  the attached plot shows weewx 2.5.1 running from 13 feb through 7 mar, followed by weewx 2.6.2 starting 7 mar.  vertical axis is KiB.

system: ubuntu 12.04.4 LTS
python: 2.7.3
station: vantage pro2
extensions: owfss, forecast, cmon, pmon
reports: standard-us, standard-metric, amphibian, exfoliation, darkness, simple, custom

[Thomas Keffer]

A clear and big improvement!

But, to my eye, memory usage is still rising, albeit very slowly, with 2.6.2.

-tk

[nileg...@guitar-o-rama.com]

I'm definitely seeing memory leakage.  Here is my current cmon memory graph:

This is on a recently installed Raspbian on Raspberry Pi running Weewx 2.6.2 with cmon.  The only activity on the system is Weewx and no changes were made to the system during this chart...the activity is solely Weewx processing, no login sessions.

With the limited available RAM on the RPi this level of memory leakage will exhaust available RAM rather quickly.

Nile

[nileg...@guitar-o-rama.com]

Just noticed...that legend should be in KBytes.  I just corrected that in my skin.conf.  -- Nile

[Thomas Keffer]

200 MB sounds extremely high. I'm usually around 30 MB RSS, 80 MB VSS. 

http://www.threefools.org/weewx/weekMem.png

Are you running any other services besides cmon?

-tk

[nileg...@guitar-o-rama.com]

Other services are very lightweight ones:  bcron, nullmailer, runit, socklog.  Looking at stats via top python process %MEM >10%,  Res = 44m, VIRT = 77212, SHR = 3928.  Everything else looks normal.

Another data point...when I rebooted the RPi about 36 hours ago it was only using about 140 MB and it has steadily grown since then.

Nile

[John Harvey]

I “think” that chart is of system memory not the memory consumption of weewx. If so then that is something very different and not something I would look at based on just that graph.

 

From: weewx-de...@googlegroups.com [mailto:weewx-de...@googlegroups.com] On Behalf Of Thomas Keffer
Sent: 24 March 2014 19:54
To: nileg...@guitar-o-rama.com
Cc: weewx-de...@googlegroups.com; mwall
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

 

200 MB sounds extremely high. I'm usually around 30 MB RSS, 80 MB VSS. 

 

http://www.threefools.org/weewx/weekMem.png

 

Are you running any other services besides cmon?

 

-tk

On Mon, Mar 24, 2014 at 11:39 AM, <nileg...@guitar-o-rama.com> wrote:

Just noticed...that legend should be in KBytes.  I just corrected that in my skin.conf.  -- Nile

On Monday, March 24, 2014 11:31:04 AM UTC-7, nileg...@guitar-o-rama.com wrote:

I'm definitely seeing memory leakage.  Here is my current cmon memory graph:

 

[John Harvey]

Assuming that is for weewxd then that is quite high.

You could post the output of ps –F –C weewxd  as well.

 

When Tom was asking about services I believe he was talking about weewx services not system ones.

So my system which just does the archiving, & stdreport including weewx-wd & a couple of small extra ones has Res = 27M and the above ps command shows SZ= 11869 (pages).

 

For your system you must have cmon as an addition weewx service do you also use any of the forecasting services or Uploads to other sites (Wunderground etc.) or anything non-standard.

 

Also what are you using for a database? Mysql or sqlite?

 

John

 

From: weewx-de...@googlegroups.com [mailto:weewx-de...@googlegroups.com] On Behalf Of nileg...@guitar-o-rama.com
Sent: 24 March 2014 20:24
To: weewx-de...@googlegroups.com
Cc: nileg...@guitar-o-rama.com; mwall
Subject: Re: [weewx-development] Re: heads up: Memory leak in weewx

 

Other services are very lightweight ones:  bcron, nullmailer, runit, socklog.  Looking at stats via top python process %MEM >10%,  Res = 44m, VIRT = 77212, SHR = 3928.  Everything else looks normal.

 

Another data point...when I rebooted the RPi about 36 hours ago it was only using about 140 MB and it has steadily grown since then.

Nile

On Monday, March 24, 2014 12:54:21 PM UTC-7, Thomas Keffer wrote:

200 MB sounds extremely high. I'm usually around 30 MB RSS, 80 MB VSS. 

 

http://www.threefools.org/weewx/weekMem.png

 

Are you running any other services besides cmon?

 

-tk

On Mon, Mar 24, 2014 at 11:39 AM, <nileg...@guitar-o-rama.com> wrote:

Just noticed...that legend should be in KBytes.  I just corrected that in my skin.conf.  -- Nile

On Monday, March 24, 2014 11:31:04 AM UTC-7, nileg...@guitar-o-rama.com wrote:

I'm definitely seeing memory leakage.  Here is my current cmon memory graph:

 

This is on a recently installed Raspbian on Raspberry Pi running Weewx 2.6.2 with cmon.  The only activity on the system is Weewx and no changes were made to the system during this chart...the activity is solely Weewx processing, no login sessions.

[nileg...@guitar-o-rama.com]

Output of ps -F <PID of python process running weewxd>:

UID        PID  PPID  C    SZ   RSS PSR STIME TTY      STAT   TIME CMD

root      2427     1  8 19447 45980   0 Mar23 ?        Sl   193:59 python /usr/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /etc/weewx/weewx.conf

As stated in an earlier post the only weewx external service I'm running is cmon 0.2, the latest version.  I'm also doing archiving, standard reporting, ftp publishing, Wunderground posting with RapidFire protocol, all specified in weewx.conf.  No exfoliation or similar external services and no additional forecasting module.  My daily graphs are a bit larger than the default (340x204 vs 300x180) and my weekly, monthly, and yearly graphs are 600x180 for better legibility. All databases are using the default sqlite install. That's it.

[nileg...@guitar-o-rama.com]

I noticed that last ps didn't catch VSZ:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root      2427  8.7 10.3  78152 46352 ?        Sl   Mar23 197:21 python /usr/bin/weewxd --daemon --pidfile=/var/run/weewx.pid /etc/weewx/weewx.conf

Nile

[mwall]

john harvey is right - the cmon plot shows memory used and memory total for the *system*, not for weewx.

if you want to monitor the memory use of just weewx (or any other process), use the pmon extension:

http://lancet.mit.edu/mwall/projects/weather/releases/weewx-pmon-0.1.tgz

it is crude, but it works.  attached plot is what i see for weewx running on an old dual-core x86 machine.  weewx 2.5.0 up to 7 march, then 2.6.2 through 23 march.  then switch from Vantage driver to OWFS driver on 23 march while we wait for davis instruments to replace the humidity sensors on the vantage (both inside and outside failed).

m

[John Harvey]

That’s ok the previous 1 had SZ which I believe is almost the same as VSZ except in pages instead of Kbytes so VSZ I think is just 4 times bigger than SZ.

They don’t look particularly bad at this time. You are running extra services so that possibly accounts for the extra memory usage.

Could you post the same output tomorrow at some point so we can see what happens over the next 20 hours or so?

 

Thanks

[nileg...@guitar-o-rama.com]

Will do.  I'm currently running a script that does executes 'ps -o %mem,rss,vsz -C python' every 5 minutes and appends the result and a timestamp to a text file.

The increases since earlier today are noticeable.  VSZ has grown from 76672 to 78408 just now, and RSS has grown to 46632 from 45888.

Nile

[nileg...@guitar-o-rama.com]

Ok, here are the first and last runs of the ps output:

Mon Mar 24 16:16:11 PDT 2014

%MEM   RSS    VSZ

10.4 46784  78408

Tue Mar 25 11:05:09 PDT 2014

%MEM   RSS    VSZ

11.6 52108  83832

I'd say it's growing.  Nile

[John Harvey]

Agreed and that is nearly 7Mbytes per day which is quite high.

As far as I can see the main difference (apart from probably a different OS/etc. which will almost definitely have different versions of python/libraries from me) is that you are pushing to weatherundergound & using rapidfire.

Could you try disabling those and see if it makes any difference?

Running for a couple of hours should be fairly obvious with that sort of rate.

Also what sort of weather station are you using and what is the update interval for the loop data and the archive interval?

[nileg...@guitar-o-rama.com]

I'll post a note when I get a chance to disable those two features.

I'm using a Davis Vantage Pro2.  Update intervals for loop and archive are the defaults...5 minutes for archive, not sure about the loop default, perhaps 2.5 seconds?

Nile

[nileg...@guitar-o-rama.com]

Ok, I commented out the parts that performed the Weather Underground updates and rapidfire updates as well as the FTP uploads.  I stopped and restarted weewx (sudo /etc/init.d/weewx stop then sudo /etc/init.d/weewx start) and here are the starting and ending memory stats for the period starting 14:34:53 PDT and ending 16:44:17 PDT:

Wed Mar 26 14:34:52 PDT 2014

%MEM   RSS    VSZ

 5.9 26452  49636

Wed Mar 26 16:44:17 PDT 2014

%MEM   RSS    VSZ

 6.5 29228  53348

It looks like it is leaking memory.

On Tuesday, March 25, 2014 11:32:54 AM UTC-7, John Harvey wrote:

[Thomas Keffer]

Two hours is a pretty short time to be drawing any conclusions. For one thing, v2.6.2 only garbage collects every 3 hours.

Can you keep it running for at least a day?

What parts are still running? Just the normal StdReport stuff?

-tk

[nileg...@guitar-o-rama.com]

John asked for a couple of hours of data, but sure, I can certainly run it overnight or possibly longer.  Thanks for mentioning the fact about the garbage collection period being every three hours.  I'll be looking for that in the graphs.    Yes, I had only the StdReport stuff running.  I can comment it out again and restart weewx.  I'll try to restart weewx and logging at 8pm PDT, then re-enable it about the same time tomorrow and post the results.

--Nile

[John Harvey]

And sorry we would probably need more data points than just the 2 as well so if we could get those figures for each hour interval that would help.

Ie it might have grown to 53M soon after the 1^st reading and then sat there for an hour and a half.

Those last numbers are about where mine has sat for the last 3 weeks. (in fact RSS has just gone down a bit)

http://jpharvey1.no-ip.biz/weather/weewx/monthMem.png

So it  could be stable now.

 

Thanks

JOhn

[Thomas Keffer]

John, do you use pyephem?

-tk

[John Harvey]

I have it installed but I wont reference any of the items from my skin so it probably isn’t being used. If you suspect that I can easily modify the skin to add something in somewhere.

[Thomas Keffer]

If you installed it and you're using the out-of-the-box weewx skins, then you're using pyephem. Weewx automatically detects its presence and generates accordingly.

If you're using custom skins, then different story.

-tk

[John Harvey]

Very custom skins. Re-using quite a few bits from the standard skins but nothing that uses pyephem.

But let me modify a page to reference something and see if it makes a difference. I can do that on my test system.

 

John

[nileg...@guitar-o-rama.com]

Thomas, the attached text file has 24 hours of the output of 'ps -o %mem,rss,vsz -C python' run every 5 minutes.  This is with only the StdReport stuff running...no Weather Underground reporting, no rapidfire updates, and no FTP uploads to a web server.  To my eyes the memory usage in this state looks quite stable and reasonable.

So which feature would you like me re-enable first? WU report w/o rapidfire or FTP?  I can then start the memory logging for another 24 hr period.

-- Nile

[John Harvey]

That looks good to me so at least with the same services you are seeing the same as me.

It doesn’t really matter I don’t think which order you add things back in. My guess is its WU or Rapidfire but only the experiments will prove it so I guess if you could run 24hrs for each of only add ftp, then disable ftp & add WU then disable WU and add Rapidfire that should show which of those are leaking.

 

I also put back in  pyephem last night on mine and after an initial growth it became stable so I don’t think that is the issue but I’ll leave it enabled for a few more days to be certain

 

http://jpharvey1.no-ip.biz/weather/weewx/dayMem.png

[Thomas Keffer]

With well over a month of runtime on v2.6.1, memory use is climbing at a pretty steady 0.5 MB/day:

-tk

[Gardner, Nile]

I've been noticing the same thing.  I haven't mentioned it because I've been too busy with work lately and was waiting for some downtime.  Is there some instrumentation that can be run on the code to help identify the source of memory leakage? 

[John Harvey]

I’ll try to add weatherunderground and rapidfire to mine and see if I see it as well with those enabled and then assuming I can I’ll try to work out what that leak is.

But it wont be quick too many other things to do and I’ve just been adding some code to allow beter control of ftp  times since I wanted to be able to transfer different files at different rates so I’ve been adding code which allows report jobs to be run at times specified like cron.

Will create a patch for it and post it soon to see if you think it is worth merging in to the main code.

 

John

[Thomas Keffer]

I finally got around to upgrading my own station from v2.6.1 to v2.6.3. Much to my astonishment, it seems to have fixed the memory leak! Here's what memory usage looks like for the last week:

I'm not too concerned with the size of virtual memory, just the size of resident memory. Rock steady for a week.

Looking through the list of fixes in 2.6.3, the only one that stands out is how CWOP retries are handled. It's possible there's some leak in the underlying socket code and 2.6.3 (inadvertently) gets around it.

Anyway, I'm happy.

-tk

[John Harvey]

Strange given mine is now increasing very slightly having moved to 2.6.3.

It’s a very slow increase but definitely there now and wasn’t before.

Its gone from about 53Mb to 56Mb over the last 2 weeks.

If I can find some time I’ll try to take a look but It wont be this week.

 

John

[Thomas Keffer]

Argh. 

I'm beginning to wonder if we aren't chasing different versions of the underlying libraries that add and then, later, fix internal memory leaks?

-tk

[Thomas Keffer]

I did a kernel upgrade about a week ago, rebooted, and now memory is climbing again:

(Disregard the graphs earlier in this thread: they are actually links to an image URL, so they change with time.)

-tk

On Mon, Jun 2, 2014 at 1:51 PM, John Harvey <john.p...@btinternet.com> wrote:

[John Harvey]

What a pain. Being so dependent on the environment its running on is going to make finding this harder.

What are you running on? I’ve just updated to a new release of Ubuntu and what I had was stable so I’ll keep an eye on it next week.