Leaking file descriptors when using zenroom_exec

[smulube]

Hi @puria,

I had a question from Pablo (@elaragon) at Eurecat who noticed an issue when reading and decrypting data from the DECODE IoT pilot datastore. The error he was seeing when running was [Errno 24] Too many open files which happened when requesting data for a number of hours from the datastore. The logic of this read operation involves first requesting a page of results and for each event in that page of results we decrypt using zenroom via the zenroom_exec method, and then repeat for the next page of events until all have been consumed.

He located the issue to the line where zenroom is invoked (https://github.com/thingful/decode-data-collector-example/blob/zenroom-update/collector.py#L51-L52), which I think I was able to verify.

I looked in the zenroom wrapper source, and I see we are now doing something clever using multiprocessing, so my suspicion is that something in that Process or Manager usage is not being cleaned up properly so we end up leaking file descriptors until the process crashes.

Steps to reproduce.

We were using an old version of the zenroom wrapper, so I wanted to make sure that the problem still occurred with the latest published build, so I updated my little test script which you can find in the zenroom_update branch of the following repo: https://github.com/thingful/decode-data-collector-example/blob/zenroom-update/collector.py

If you check out this branch, install the dependencies into a Python 3.x virtualenv and then run python collector.py.

What you should see is that the script starts printing out data events as it pulls them from the datastore and decrypts using Zenroom. I've added the basic prometheus client to this little script as it has a built in data collector looking at file descriptors, so if you then open the following url: http://localhost:8000/metrics you should see the number of open file descriptors racing upwards (process_open_fds) until it reaches the process_max_fds value.

Because I added the prometheus client which runs an HTTP server, the script will just stall at this point with no new events being displayed, however if you comment out the start_http_server(8000) line (https://github.com/thingful/decode-data-collector-example/blob/zenroom-update/collector.py#L14), then you should see the script just crash when it runs out of file descriptors.

I understand that we can ask Pablo to change the limits on the server, but I wondered if you had any ideas on a fix.

many thanks

Sam

[puria]

I noticed this a while ago, when on the testing added a LOAD_TEST and had the same too many open files on gnu/linux.
I tried to address it by changing the way we use multiprocessing, and use multiprocessing.pools but was not able to fix it in an happy way...
need to play with that next week, any hint appreciated !

[puria]

I rememeber that at some point it was fixed, but then I was unable to print the stacktrace logs of zenroom, that was a huge drawback... need to check it again now, that a lot of fixes was introduces in zenroom itself.

[smulube]

I've done a little more investigating, and I think it might an issue with the capturing library you are using to capture output from the subprocess.

I used this simple script for testing:

#!/usr/bin/env python

import time

from zenroom import zenroom
from prometheus_client import start_http_server

start_http_server(8000)

while True:
    script = "print('Hello world')"
    output, errors = zenroom.zenroom_exec(script)

    print(output, errors)

again I'm only using the prometheus client library here for counting file descriptors (http://localhost:8000/metrics while the script is running).

I pulled down the latest published zenroom-py branch, and was messing around with it, and I found that if I changed the contents of the _zen_call function in zenroom.py to be just this:

def _zen_call(func, arguments):
    m = Manager()
    result = m.Queue()
    p = Process(target=_execute, args=(func, result, arguments))
    p.start()
    p.join()

    return result.get()

then the number of dangling file descriptors stayed rock steady at just 9 for as long as I let the script loop, but as soon as I added back in the CaptureOutput() context wrapper (which I presume is to capture both stdout and stderr from the child process) then the file descriptors started ballooning up again.

I had a look in the source of that library and it seems a complicated thing. There seems to be a bunch of machinery which spawns other child processes, and I'm afraid I couldn't follow the logic of what it's doing or see where it might be leaking descriptors but maybe you will have better luck.

I'm wondering if there is a simpler approach to capturing this output without introducing such a heavy dependency. I was looking at this stack overflow (https://stackoverflow.com/questions/19420211/access-standard-output-of-a-sub-process-in-python) which seemed vaguely related but would need to think a bit more about how this could be implemented.

[jaromil]

Hey Sam! thanks for your extensive investigation on this issue, as you can see also on zenroom's repo I'm actively cleaning up the stdout/err code and taking some decisions. As things stand, different wrappers can benefit from different approaches and the python one to me looks like it should only call the _tobuf variants (zenroom_exec_tobuf) and ignore the stdin/out ones so that the buffers are provided by the caller. Would that be a simplification?

[smulube]

yeah, i think that would probably clean up things from the python side. it gets back to that original slight tension between zenroom as a library vs zenroom as a command line tool that we discussed way back when thinking about the Go and indeed Python wrappers. If making this change would obviate the need to do tricky things with stdout/stderr then I think that would be a good thing