Memory leak in pooled server

[animalmutch]

When using PooledJSONRPCServer, there appears to be a memory leak. To see the effect, you can run:

from jsonrpclib.SimpleJSONRPCServer import PooledJSONRPCServer
import objgraph
import gc

def poll():
    gc.collect()
    objgraph.show_growth()
    return "Hello world!"

server = PooledJSONRPCServer(('', 8080))
server.register_function(poll, 'poll')
server.serve_forever()

And poll repeatedly with:

from jsonrpclib import ServerProxy
import time

server = ServerProxy('http://host:port')

while True:
    response = server.poll()
    print(response)
    time.sleep(1)

Every iteration these extra objects are created and never cleared by the garbage collector:

dict +3 builtin_function_or_method +2 weakref +1 Event +1 Condition +1 deque +1 Thread +1

Over time, with a lot of requests, this is causing applications based on the library to crash.

This issue does not affect the SimpleJSONRPCServer.

It's an excellent library otherwise. I hope you are able to find a fix, as we've been using it for some time. Please let me know if more information is needed.

Thanks.

[tcalmant]

Thanks for the report, I'll look into it ASAP. Which version of Python do you use ? (in order to have a similar debug environment)

[tcalmant]

OK, problem found, solution under way

[tcalmant]

A patched version of jsonrpclib-pelix has been released as v0.3.2 on PyPI.

[animalmutch]

Wow. Amazingly quick response. Thanks. Would have taken me a good while to come up with a patch. I'll give it a try Monday and let you know how I get on. In case it's needed, I'm using Python 3.6, but looking at the fix you've put in, I'm confident it'll be fine now. Thanks again for the excellent tool you've provided :)

[animalmutch]

Hi. Just thought I'd let you know how I got on with the bug fix. Have run it through the above test, and all looks good. When running natively on Python in Windows, it looks good too. However, it appears that there is still an issue with Docker. Applications using jsonrpclib hold a steady amount of memory usage until http requests start coming in, upon which memory usage just keeps growing. It's a strange problem. Probably not to do with your library, but more likely to do with the Python Docker image I'm using. I'm working on tracking down the problem, but if you have any more ideas what it might be, then I'm very much open to suggestions. Thanks again for the fix.

[tcalmant]

Hi, thanks for the feedback 👍

Indeed, this is a strange behaviour... Does objgraph prints out some hints on the issue ? I don't have a Docker-able machine right now, but I can do some tests next week on the library itself. Also, do you call other libraries when in the methods called on server side ?

Maybe this can be related to #20, which I wasn't able to reproduce at the time.

[animalmutch]

Hi. Found the issue. It seems that debug logs were being created in our application every time the server received a request. These logs were being stashed using Python's rotating file handler. However, the rotating file handler keeps the logs in memory until the file is written once a day. With the amount of requests coming in, this was causing the application to crash. It seems it only happens on Linux because the rotating file handler writes the logs to stdout and keeps them there until the log file rotates, which doesn't happen in Windows. The strange thing is, that with the exact same logging setup, this doesn't happen using the SimpleJSONRPCServer. I wonder if there's something in the logging in jsonrpclib that's conflicting somehow. Anyway hope that helps you with any future issues. For now, though, we just need to rotate our log files a bit more often! Thanks again.

[tcalmant]

That's strange... The logging library is thread-safe, and jsonrpclib only calls the logging.getLogger() method.

[animalmutch]

Hi thought I'd share an update, just in case it helps you with future issues. It turns out that the logging issue was just a red-herring. I completely removed local logging in our application and the memory leak persisted. It turns out that the problem was caused by the mysql-connector-python library we were using. Apparently it doesn't play well with the threaded server, even though no connections or cursors were shared between threads (as per the docs). I switched to pymysql and everything is ok now. Thanks again for you help.

[tcalmant]

Hi, Thanks for the feedback, I really appreciate it. That's a good thing to know about the MySQL connector.