[omniORB] std::terminate in omniORBpy

Thu May 12 11:59:00 UTC 2022

Hi,

since upgrading from 4.2.4, I sometimes get aborts on python shutdown.
Must be a race condition somewhere as it does not happen reliably.

Thread 1 (Thread 0x7f6949e7b700 (LWP 2933428) (Exiting)):
#0  0x00007f69ca7bc37f in raise () from /usr/lib64/libc.so.6
#1  0x00007f69ca7a6db5 in abort () from /usr/lib64/libc.so.6
#2  0x00007f69c75207ba in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib64/libstdc++.so.6
--Type <RET> for more, q to quit, c to continue without paging--
#3  0x00007f69c751e53c in __cxxabiv1::__terminate(void (*)()) () from /usr/lib64/libstdc++.so.6
#4  0x00007f69c751e597 in std::terminate() () from /usr/lib64/libstdc++.so.6
#5  0x00007f69c751df0a in __gxx_personality_v0 () from /usr/lib64/libstdc++.so.6
#6  0x00007f69c7280bf8 in _Unwind_ForcedUnwind_Phase2 () from /usr/lib64/libgcc_s.so.1
#7  0x00007f69c7281240 in _Unwind_ForcedUnwind () from /usr/lib64/libgcc_s.so.1
#8  0x00007f69cb2e5556 in __pthread_unwind () from /usr/lib64/libpthread.so.0
#9  0x00007f69cb2dd40b in pthread_exit () from /usr/lib64/libpthread.so.0
#10 0x00007f69cb55c3fd in PyThread_exit_thread () from /usr/lib64/libpython3.6m.so.1.0
#11 0x00007f69cb5ed322 in PyEval_RestoreThread () from /usr/lib64/libpython3.6m.so.1.0
#12 0x00007f69c7e68ece in omnipyThreadCache::threadExit (cn=0x7f6938004de0) at pyThreadCache.cc:234
#13 0x00007f69c7e690eb in omnipyThreadData::~omnipyThreadData (this=0x7f6938005710, __in_chrg=<optimized out>) at 
pyThreadCache.cc:78
#14 omnipyThreadData::~omnipyThreadData (this=0x7f6938005710, __in_chrg=<optimized out>) at pyThreadCache.cc:79
#15 0x00007f69c781fc98 in omni_thread::~omni_thread (this=0x7f694c002710, __in_chrg=<optimized out>) at posix.cc:536
#16 0x00007f69c7af6c94 in omniAsyncWorker::~omniAsyncWorker (this=0x7f694c002710, __in_chrg=<optimized out>) at 
invoker.cc:109
#17 omniAsyncWorker::~omniAsyncWorker (this=0x7f694c002710, __in_chrg=<optimized out>) at invoker.cc:117
#18 0x00007f69c78205df in omni_thread::exit (return_value=return_value at entry=0x0) at posix.cc:774
#19 0x00007f69c7820724 in omni_thread_wrapper (ptr=0x7f694c002710) at posix.cc:460
#20 0x00007f69cb2dc17a in start_thread () from /usr/lib64/libpthread.so.0
#21 0x00007f69ca881dc3 in clone () from /usr/lib64/libc.so.6

there are several such threads and
the main thread is here:

Thread 5 (Thread 0x7f69cc13ab80 (LWP 2933363)):
#0  0x00007f69cb2e274a in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1  0x00007f69cb5ed0a4 in take_gil () from /usr/lib64/libpython3.6m.so.1.0
#2  0x00007f69cb5ed2dd in PyEval_RestoreThread () from /usr/lib64/libpython3.6m.so.1.0
#3  0x00007f69c7e3eb06 in omniPy::InterpreterUnlocker::~InterpreterUnlocker (this=<synthetic pointer>, 
__in_chrg=<optimized out>) at ./omnipy.h:404
#4  pyObjRef_dealloc (self=0x7f699f0d1ee8) at pyObjectRef.cc:604
#5  0x00007f69cb5deb2c in dict_dealloc () from /usr/lib64/libpython3.6m.so.1.0
#6  0x00007f69cb67b351 in subtype_dealloc () from /usr/lib64/libpython3.6m.so.1.0
#7  0x00007f69cb5deb87 in dict_dealloc () from /usr/lib64/libpython3.6m.so.1.0
#8  0x00007f69cb5dafcf in free_keys_object () from /usr/lib64/libpython3.6m.so.1.0
#9  0x00007f69cb6aa806 in type_clear () from /usr/lib64/libpython3.6m.so.1.0
#10 0x00007f69cb66c276 in collect () from /usr/lib64/libpython3.6m.so.1.0
#11 0x00007f69cb6e424b in _PyGC_CollectNoFail () from /usr/lib64/libpython3.6m.so.1.0
#12 0x00007f69cb6fe169 in PyImport_Cleanup () from /usr/lib64/libpython3.6m.so.1.0
#13 0x00007f69cb701772 in Py_FinalizeEx () from /usr/lib64/libpython3.6m.so.1.0
#14 0x00007f69cb702544 in Py_Main () from /usr/lib64/libpython3.6m.so.1.0
#15 0x000055e0d2a45b96 in main ()

When I set ORBtraceLevel=40 I see this:

omniORB: (9) 2022-05-12 13:44:38.662928: ORB shutdown is complete.
omniORB: (9) 2022-05-12 13:44:38.662932: Shut down AsyncInvoker...
omniORB: (9) 2022-05-12 13:44:38.662937: Shut down dedicated thread queue.
omniORB: (9) 2022-05-12 13:44:38.662942: AsyncInvoker shut down.
omniORB: (9) 2022-05-12 13:44:38.662955: Deleting Python state for thread id 140552133670656 (thread exit)
omniORB: (3) 2022-05-12 13:44:39.149144: Scan for idle connections (1652355879,149046000)
omniORB: (3) 2022-05-12 13:44:39.149201: Scavenger reduce idle count for strand 0x558342c168e0 to 23
omniORB: (3) 2022-05-12 13:44:39.149211: Scavenger reduce idle count for strand 0x558342d11100 to 23
omniORB: (3) 2022-05-12 13:44:39.149216: Scavenger reduce idle count for strand 0x5583424957f0 to 23
omniORB: (3) 2022-05-12 13:44:39.149221: Scavenger reduce idle count for strand 0x558342920020 to 23
omniORB: (3) 2022-05-12 13:44:39.149226: Scavenger reduce idle count for strand 0x558342ada5e0 to 23
omniORB: (3) 2022-05-12 13:44:39.149233: Scan for idle connections done (1652355879,149046000).
omniORB: (0) 2022-05-12 13:44:39.661452: Destroy ORB...
omniORB: (1) 2022-05-12 13:44:39.661536: Remove Python state for thread id 140552643036928 from cache (shutdown)
omniORB: (1) 2022-05-12 13:44:39.661570: Remove Python state for thread id 140552617858816 from cache (shutdown)
omniORB: (1) 2022-05-12 13:44:39.661582: Remove Python state for thread id 140552626251520 from cache (shutdown)
omniORB: (1) 2022-05-12 13:44:39.661585: Remove Python state for thread id 140553558406912 from cache (shutdown)
omniORB: (1) 2022-05-12 13:44:39.661590: Remove Python state for thread id 140552634644224 from cache (shutdown)
omniORB: (1) 2022-05-12 13:44:39.661711: Python thread state scavenger exit.
omniORB: (0) 2022-05-12 13:44:39.661818: Terminate strand scavenger.
omniORB: (0) 2022-05-12 13:44:39.661838: Close remaining strands.
omniORB: (0) 2022-05-12 13:44:39.661844: Shutdown close connection to giop:tcp:[::1]:15001
omniORB: (3) 2022-05-12 13:44:39.661885: Scan for idle connections (1652355884,149246000)
omniORB: (0) 2022-05-12 13:44:39.661910: Client connection giop:tcp:[::1]:15001 refcount (forced) = 0
omniORB: (0) 2022-05-12 13:44:39.661915: Client close connection to giop:tcp:[::1]:15001
omniORB: (0) 2022-05-12 13:44:39.661921: Shutdown close connection to giop:tcp:10.49.64.73:15001
omniORB: (0) 2022-05-12 13:44:39.661925: sendCloseConnection: to giop:tcp:10.49.64.73:15001 12 bytes
omniORB: (0) 2022-05-12 13:44:39.661928:
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (0) 2022-05-12 13:44:39.661971: Client connection giop:tcp:10.49.64.73:15001 refcount (forced) = 0
omniORB: (0) 2022-05-12 13:44:39.661976: Client close connection to giop:tcp:10.49.64.73:15001
omniORB: (0) 2022-05-12 13:44:39.661980: Shutdown close connection to giop:tcp:10.49.64.73:34493
omniORB: (0) 2022-05-12 13:44:39.661983: sendCloseConnection: to giop:tcp:10.49.64.73:34493 12 bytes
omniORB: (0) 2022-05-12 13:44:39.661985:
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (0) 2022-05-12 13:44:39.662016: Client connection giop:tcp:10.49.64.73:34493 refcount (forced) = 0
omniORB: (0) 2022-05-12 13:44:39.662020: Client close connection to giop:tcp:10.49.64.73:34493
omniORB: (0) 2022-05-12 13:44:39.662024: Shutdown close connection to giop:tcp:10.49.64.73:48261
omniORB: (0) 2022-05-12 13:44:39.662027: sendCloseConnection: to giop:tcp:10.49.64.73:48261 12 bytes
omniORB: (0) 2022-05-12 13:44:39.662029:
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (0) 2022-05-12 13:44:39.662059: Client connection giop:tcp:10.49.64.73:48261 refcount (forced) = 0
omniORB: (0) 2022-05-12 13:44:39.662067: Client close connection to giop:tcp:10.49.64.73:48261
omniORB: (0) 2022-05-12 13:44:39.662071: Shutdown close connection to giop:tcp:10.49.64.73:39675
omniORB: (0) 2022-05-12 13:44:39.662074: sendCloseConnection: to giop:tcp:10.49.64.73:39675 12 bytes
omniORB: (0) 2022-05-12 13:44:39.662077:
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (0) 2022-05-12 13:44:39.662109: Client connection giop:tcp:10.49.64.73:39675 refcount (forced) = 0
omniORB: (0) 2022-05-12 13:44:39.662114: Client close connection to giop:tcp:10.49.64.73:39675
omniORB: (0) 2022-05-12 13:44:39.662147: 0 remaining bidir ropes deleted.
omniORB: (0) 2022-05-12 13:44:39.662157: 5 remaining ropes deleted.
omniORB: (0) 2022-05-12 13:44:39.662172: Clear endPoint options.
omniORB: (3) 2022-05-12 13:44:39.662184: Scan for idle connections done (1652355884,149246000).
omniORB: (0) 2022-05-12 13:44:39.662215: Wait for 7 invoker threads to finish.
omniORB: (3) 2022-05-12 13:44:39.662235: AsyncInvoker: thread id 3 finished immediate general task.
omniORB: (3) 2022-05-12 13:44:39.662264: AsyncInvoker: thread id 3 released from general tasks. Total general threads = 1.
omniORB: (3) 2022-05-12 13:44:39.662274: AsyncInvoker: thread id 3 has exited. Total threads = 6.
omniORB: (2) 2022-05-12 13:44:39.662281: AsyncInvoker: thread id 2 released from general tasks. Total general threads = 0.
omniORB: (2) 2022-05-12 13:44:39.662298: AsyncInvoker: thread id 2 has exited. Total threads = 5.
omniORB: (7) 2022-05-12 13:44:39.662309: AsyncInvoker: thread id 7 released from server tasks. Total server threads = 4.
omniORB: (8) 2022-05-12 13:44:39.662324: AsyncInvoker: thread id 8 released from server tasks. Total server threads = 3.
omniORB: (7) 2022-05-12 13:44:39.662330: AsyncInvoker: thread id 7 has exited. Total threads = 4.
omniORB: (8) 2022-05-12 13:44:39.662336: AsyncInvoker: thread id 8 has exited. Total threads = 3.
omniORB: (7) 2022-05-12 13:44:39.662360: Deleting Python state for thread id 140552626251520 (thread exit)
omniORB: (8) 2022-05-12 13:44:39.662362: Deleting Python state for thread id 140552617858816 (thread exit)
omniORB: (5) 2022-05-12 13:44:39.662393: AsyncInvoker: thread id 5 released from server tasks. Total server threads = 1.
omniORB: (5) 2022-05-12 13:44:39.662432: AsyncInvoker: thread id 5 has exited. Total threads = 2.
omniORB: (5) 2022-05-12 13:44:39.662447: Deleting Python state for thread id 140552643036928 (thread exit)
omniORB: (4) 2022-05-12 13:44:39.662371: AsyncInvoker: thread id 4 released from server tasks. Total server threads = 2.
omniORB: (4) 2022-05-12 13:44:39.662505: AsyncInvoker: thread id 4 has exited. Total threads = 1.
omniORB: (4) 2022-05-12 13:44:39.662551: Deleting Python state for thread id 140553558406912 (thread exit)
omniORB: (6) 2022-05-12 13:44:39.662561: AsyncInvoker: thread id 6 released from server tasks. Total server threads = 0.
omniORB: (6) 2022-05-12 13:44:39.662586: AsyncInvoker: thread id 6 has exited. Total threads = 0.
omniORB: (6) 2022-05-12 13:44:39.662601: Deleting Python state for thread id 140552634644224 (thread exit)
omniORB: (0) 2022-05-12 13:44:39.662625: Invoker threads finished.
omniORB: (0) 2022-05-12 13:44:39.662640: AsyncInvoker: deleted.
omniORB: (0) 2022-05-12 13:44:39.662654: ORB destroyed.
omniORB: (0) 2022-05-12 13:44:39.662792: No more references to the ORB -- deleted.
omniORB: (0) 2022-05-12 13:44:39.743916: ObjRef(IDL:fundamental/Server:1.0) -- deleted.
terminate called without an active exception

It's not critical because it's on exit anyway, but annoying enough to ask for help here. Is it maybe because there 
somehow are object references after ORB destruction which may be throw exceptions (similar to 
https://stackoverflow.com/questions/59082973/terminate-called-without-an-active-exception-after-pthread-cancel although 
no cancel involved?)

I'll do some more tests to find out what exactly changed. The python code was changed as well so maybe it's just 
coincidence that this happened after the update...

Greetings,
   Michael