parsing fails when running in a thread

[mjmottram]

Hi,

I'm not sure whether this is a known issue, but if I run pyosmium parsing in a thread then the process hangs indefinitely. For example:

import sys
import threading

import osmium

function_complete = threading.Event()


def run_parsing(filename):
    print("Parsing %s ..." % filename)
    h = osmium.SimpleHandler()
    h.apply_file(filename)
    print("Parsed %s" % filename)
    function_complete.set()


if __name__ == "__main__":
    test_file = sys.argv[1]

    run_parsing(test_file)

    function_complete.clear()
    threading.Thread(target=run_parsing, args=(test_file,))
    function_complete.wait(timeout=10)

    if not function_complete.is_set():
        raise RuntimeError("parsing did not complete")

will parse when in the main thread, then raise as the threaded parsing never completes. Is this behaviour understood?

I'm running this on macOS in python 2.7.

Thanks!

[lonvia]

You need to actually start the thread:

t = threading.Thread(target=run_parsing, args=(test_file,))
t.start()

[mjmottram]

D'oh, my bad! I'm finding pyosmium hanging in certain situations but can't find the cause...

[mjmottram]

OK, I've re-encountered the issue (and it does seem to be caused by threading). Subclassing osmium.SimpleHandler per the docs, running apply_file hangs when run in a thread:

import sys
import threading

import osmium

function_complete = threading.Event()


class WayNodeHandler(osmium.SimpleHandler):
    def __init__(self):
        super(WayNodeHandler, self).__init__()
        self.node_count = 0
        self.way_count = 0

    def way(self, way):
        self.way_count += 1

    def node(self, node):
        self.node_count += 1


def run_parsing(filename):
    print("Parsing %s ..." % filename)
    h = WayNodeHandler()
    h.apply_file(filename)
    print("Parsed %s: %s %s" % (filename, h.way_count, h.node_count))
    function_complete.set()


if __name__ == "__main__":
    test_file = sys.argv[1]

    run_parsing(test_file)

    function_complete.clear()
    t = threading.Thread(target=run_parsing, args=(test_file,))
    t.start()
    function_complete.wait(timeout=10)

    if not function_complete.is_set():
        raise RuntimeError("parsing did not complete")

Even though it's running in a thread, it blocks the main thread (i.e. the RuntimeError is never raised).

[cazaco]

Using Python 3.7 on MacOS Mojave 10.14.2 and following the workaround explained here, works quite good.

[lonvia]

I can reproduce @mjmottram's problem. I suspect that something needs to be done about the GIL to make multi-threaded code work. The pybind11 documentation has a short entry on that.

[wiktorn]

I'm not sure if it's related to GIL. Per pybind11 docs, GIL is always held when calling to C++ code.

I've just tried with GDB:

(gdb) run test_thr.py andorra-latest.osm.pbf 
Starting program: /home/w/PycharmProjects/pyosmium/venv/bin/python test_thr.py andorra-latest.osm.pbf
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff4c22700 (LWP 3598)]
Parsing andorra-latest.osm.pbf ...
[New Thread 0x7fffeffff700 (LWP 3599)]
[New Thread 0x7fffef7fe700 (LWP 3600)]
[New Thread 0x7fffeeffd700 (LWP 3601)]
[New Thread 0x7fffee7fc700 (LWP 3602)]
[Thread 0x7fffeffff700 (LWP 3599) exited]

(gdb) info threads
  Id   Target Id         Frame 
* 1    Thread 0x7ffff7fd9740 (LWP 3594) "python" 0x00007ffff7bc3f85 in futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7fffffffd200, expected=0, futex_word=0xa8b1e8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
  2    Thread 0x7ffff4c22700 (LWP 3598) "python" 0x00007ffff7bc3f85 in futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7ffff4c20300, expected=0, futex_word=0xa8b1e8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
  4    Thread 0x7fffef7fe700 (LWP 3600) "_osmium_worker" 0x00007ffff7bc39f3 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x7ffff5fd0c0c) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
  5    Thread 0x7fffeeffd700 (LWP 3601) "_osmium_worker" 0x00007ffff7bc39f3 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x7ffff5fd0c0c) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
  6    Thread 0x7fffee7fc700 (LWP 3602) "_osmium_pbf_in" 0x00007ffff7bc3f85 in futex_abstimed_wait_cancelable (private=<optimized out>, abstime=0x7fffee7fbad0, expected=0, futex_word=0x7ffff4c20f80) at ../sysdeps/unix/sysv/linux/futex-internal.h:205

So, we've got:

• 2 python threads (main thread and newly created in the code)
• 3 osmium threads
  One of the osmium_worker threads finishes. I don't know, what other threads are waiting.

If we're parsing within one core thread in Python we would have:

• 1 python thread calling to osmium (so it holds GIL)
• 3 osmium threads parsing, that somehow are calling back to Python code (does it go through the 1 thread?)

Is it possible that somehow callbacks to python code go through different thread (that's waiting for GIL) and that's why it fails?

[joto]

I can't see a problem when I am trying to reproduce this here. Your script, @mjmottram, doesn't actually have two threads running. It starts run_parsing in the main thread and when it is finished, it starts it again in a subthread and waits for it to finish. So there is never more than one thread running here really.

The following script shows it running in parallel, you can see the interleaved prints:

import sys
import threading
import time

import osmium

function_complete = threading.Event()


class WayNodeHandler(osmium.SimpleHandler):
    def __init__(self):
        super(WayNodeHandler, self).__init__()
        self.node_count = 0
        self.way_count = 0

    def way(self, way):
        self.way_count += 1
        if way.id % 10000 == 0:
            print("way %d" % way.id)

    def node(self, node):
        self.node_count += 1
        if node.id % 10000 == 0:
            print("node %d" % node.id)


def run_parsing(filename):
    print("Parsing %s ..." % filename)
    h = WayNodeHandler()
    h.apply_file(filename)
    print("Parsed %s: %s %s" % (filename, h.way_count, h.node_count))
    function_complete.set()


if __name__ == "__main__":
    test_file = sys.argv[1]

    function_complete.clear()
    t = threading.Thread(target=run_parsing, args=(test_file,))
    t.start()

    run_parsing(test_file)

    function_complete.wait(timeout=10)

[mjmottram]

Single subthread or in parallel, I see this hanging either way (running with python2.7 - cannot migrate codebase to 3.7 yet). @joto even if the thread hung in your version, the call to run_parsing in the main thread would still result in function_complete to be set (unless the parsing in the thread blocks the call from the main thread). Either way, it still hangs for me with any call to run_parsing within a Thread.

[lonvia]

Turns out this is a bug in pybind11, see pybind/pybind11#1211. This is fixed in the latest master, so you should be able to work around the bug by using pybind11 master.

The ticket also states that releasing the GIL works around the issue. As mentioned before, this is something nice to have anyway. So I'll leave this ticket open for a bit as a remainder to properly manage the GIL.