Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Paramiko / SSHTunnel hang #594

Open
markfinn opened this issue Dec 1, 2021 · 4 comments
Open

Paramiko / SSHTunnel hang #594

markfinn opened this issue Dec 1, 2021 · 4 comments
Labels

Comments

@markfinn
Copy link

markfinn commented Dec 1, 2021

I'm on version 7.3, dealing with an issue similar to #158 that seems to have a similar solution.

When using a pure python ssh tunnel with a cx_oracle pool still hangs for me. Using an external tunnel is fine.

Based on the fix in #158 (releasing the GIL) I checked out what threads where waiting inside the cx_Oracle*.so and think that the call to dpiStmt_close() inside cxoCursor_close() might also need the GIL released while waiting. Doing that seems to fix my hang. I don't really have any understanding of which dpi* functions make external calls, so I don't know if this also should have included the dpiStmt_release() call.

static PyObject *cxoCursor_close(cxoCursor *cursor, PyObject *args)
{
+    int status;
     if (cxoCursor_isOpen(cursor) < 0)
         return NULL;
     Py_CLEAR(cursor->bindVariables);
     Py_CLEAR(cursor->fetchVariables);
     if (cursor->handle) {
-        if (dpiStmt_close(cursor->handle, NULL, 0) < 0)
+        Py_BEGIN_ALLOW_THREADS
+        status = dpiStmt_close(cursor->handle, NULL, 0);
+        Py_END_ALLOW_THREADS
+        if (status < 0)
             return cxoError_raiseAndReturnNull();
         dpiStmt_release(cursor->handle);
         cursor->handle = NULL;
    }
    cursor->isOpen = 0;

    Py_RETURN_NONE;
}
@markfinn markfinn added the bug label Dec 1, 2021
@anthony-tuininga
Copy link
Member

Thanks, @markfinn. This documentation will tell you which ODPI-C calls may generate a round trip (and therefore should have the GIL released). I'll have this one fixed. I will also put the call to dpiStmt_release() inside the block where the GIL is released -- not because it is necessary but just because the GIL isn't needed anyway!

@markfinn
Copy link
Author

markfinn commented Dec 1, 2021

Thanks! I assume my chances of getting this fixed in a 7.3.x are roughly zero? Some day I'll have the time to get to python 3... Some day.

@anthony-tuininga
Copy link
Member

Hmm, the ODPI-C documentation I referenced suggests that dpiStmt_close() does NOT require a round-trip! That suggests there may be something more in play here. Do you have a sample that demonstrates the problem?

As for patching 7.3, yeah, that ship sailed a while ago! Well over 90% of the downloads are now for cx_Oracle 8. It looks like you have made your own patch anyway. Hopefully you can join the Python 3 party relatively soon anyway! ;-)

@markfinn
Copy link
Author

markfinn commented Dec 1, 2021

Now that you say that, I can see it isn't in a round trip, but it is instead waiting on a lock. My guess is that that lock is held by a different thread that IS in a round trip. I hate to say it, but everything that can ever even wait on a non-python-managed lock should probably release the GIL.

Boiling down the code to something to reproduce it as a race condition might be really hard but I can reproduce the deadlock in about 3 seconds every time. Are there debug any capabilities that will show what locks are held or waiting by the layers under cx_Oracle?

Here are the threads involved. I would guess one of the two in "read" (cxoConnection_init or cxoCursor_execute) is holding a lock that blocks dpiStmt_close(), and that the the read can't complete because SSHTunnel needs the GIL.

Thread 43 (Thread 0x7fffdfebb640 (LWP 1445928) "python"):
#0  futex_wait (private=0, expected=2, futex_word=0x555555f35520) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex@entry=0x555555f35520, private=0) at lowlevellock.c:50
#2  0x00007ffff39beec2 in lll_mutex_lock_optimized (mutex=0x555555f35520) at pthread_mutex_lock.c:49
#3  ___pthread_mutex_lock (mutex=0x555555f35520) at pthread_mutex_lock.c:89
#4  0x00007fffec64b08e in kpureq2 () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffec616c8d in OCIStmtPrepare2 () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007ffff2536a74 in dpiOci__stmtPrepare2 () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#7  0x00007ffff253eead in dpiStmt__prepare () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#8  0x00007ffff2525ab2 in dpiConn_prepareStmt () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#9  0x00007ffff25114db in cxoCursor_internalPrepare () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#10 0x00007ffff25144c6 in cxoCursor_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 42 (Thread 0x7fffe07fd640 (LWP 1445927) "python"):
#0  futex_wait (private=0, expected=2, futex_word=0x555555f35520) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex@entry=0x555555f35520, private=0) at lowlevellock.c:50
#2  0x00007ffff39beec2 in lll_mutex_lock_optimized (mutex=0x555555f35520) at pthread_mutex_lock.c:49
#3  ___pthread_mutex_lock (mutex=0x555555f35520) at pthread_mutex_lock.c:89
#4  0x00007fffec665b37 in kpugparm () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007ffff25345e8 in dpiOci__paramGet () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#6  0x00007ffff253dbb5 in dpiStmt__createQueryVars () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#7  0x00007ffff253e6b6 in dpiStmt__execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#8  0x00007ffff253f6ee in dpiStmt_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#9  0x00007ffff251452a in cxoCursor_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 41 (Thread 0x7fffe2c8e640 (LWP 1445926) "python"):
#0  futex_wait (private=0, expected=2, futex_word=0x555555f35520) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex@entry=0x555555f35520, private=0) at lowlevellock.c:50
#2  0x00007ffff39beec2 in lll_mutex_lock_optimized (mutex=0x555555f35520) at pthread_mutex_lock.c:49
#3  ___pthread_mutex_lock (mutex=0x555555f35520) at pthread_mutex_lock.c:89
#4  0x00007fffeef646d3 in kpuexec () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffeef5d9a9 in OCIStmtExecute () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007ffff2536610 in dpiOci__stmtExecute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#7  0x00007ffff253e590 in dpiStmt__execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#8  0x00007ffff253f6ee in dpiStmt_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#9  0x00007ffff251452a in cxoCursor_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 40 (Thread 0x7fffe3f12640 (LWP 1445925) "python"):
#0  __GI___libc_read (nbytes=8208, buf=0x555555f41586, fd=13) at ../sysdeps/unix/sysv/linux/read.c:26
#1  __GI___libc_read (fd=13, buf=0x555555f41586, nbytes=8208) at ../sysdeps/unix/sysv/linux/read.c:24
#2  0x00007fffeef7e160 in snttread () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#3  0x00007fffeef7d0f0 in nttfprd () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#4  0x00007fffeef78f50 in nsbasic_brc () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffeef6f9c4 in nioqrc () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007fffeef89b69 in ttcdrv () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#7  0x00007fffeef73b79 in nioqwa () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#8  0x00007fffeef5e200 in upirtrc () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#9  0x00007fffeef6a2f6 in kpurcsc () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#10 0x00007fffeef62439 in kpuexec () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#11 0x00007fffeef5d9a9 in OCIStmtExecute () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#12 0x00007ffff2536610 in dpiOci__stmtExecute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#13 0x00007ffff253e590 in dpiStmt__execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#14 0x00007ffff253f6ee in dpiStmt_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#15 0x00007ffff251452a in cxoCursor_execute () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 39 (Thread 0x7fffe35d0640 (LWP 1445924) "python"):
#0  futex_wait (private=0, expected=2, futex_word=0x555555f35520) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex@entry=0x555555f35520, private=0) at lowlevellock.c:50
#2  0x00007ffff39beec2 in lll_mutex_lock_optimized (mutex=0x555555f35520) at pthread_mutex_lock.c:49
#3  ___pthread_mutex_lock (mutex=0x555555f35520) at pthread_mutex_lock.c:89
#4  0x00007fffec64d327 in kpustmtrelease () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffec616e14 in OCIStmtRelease () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007ffff2536b74 in dpiOci__stmtRelease () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#7  0x00007ffff253ebd1 in dpiStmt__close () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#8  0x00007ffff253f3e6 in dpiStmt_close () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#9  0x00007ffff2512337 in cxoCursor_close () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 6 (Thread 0x7fffe9a65640 (LWP 1445849) "python"):
#0  futex_wait (private=0, expected=2, futex_word=0x555555ea5190) at ../sysdeps/nptl/futex-internal.h:146
#1  __GI___lll_lock_wait (futex=futex@entry=0x555555ea5190, private=0) at lowlevellock.c:50
#2  0x00007ffff39beec2 in lll_mutex_lock_optimized (mutex=0x555555ea5190) at pthread_mutex_lock.c:49
#3  ___pthread_mutex_lock (mutex=0x555555ea5190) at pthread_mutex_lock.c:89
#4  0x00007fffed4bfbd5 in kpuspreltopool () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffed4bd5b1 in kpuspsessionrelease () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007fffed2dfc92 in OCISessionRelease () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#7  0x00007ffff253525f in dpiOci__sessionRelease () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#8  0x00007ffff2521fa9 in dpiConn__close () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#9  0x00007ffff2523e61 in dpiConn_close () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#10 0x00007ffff251adb0 in cxoSessionPool_release () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so


Thread 5 (Thread 0x7fffea3a7640 (LWP 1445848) "python"):
#0  __GI___libc_read (nbytes=8208, buf=0x555556601876, fd=28) at ../sysdeps/unix/sysv/linux/read.c:26
#1  __GI___libc_read (fd=28, buf=0x555556601876, nbytes=8208) at ../sysdeps/unix/sysv/linux/read.c:24
#2  0x00007fffeef7e160 in snttread () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#3  0x00007fffec83887d in nttrd () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#4  0x00007fffec735485 in nsprecv () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#5  0x00007fffec7febfa in nscon () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#6  0x00007fffec6fb305 in nsdo () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#7  0x00007fffec7f7637 in nsbasic_rc () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#8  0x00007fffec6f7332 in nscall3 () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#9  0x00007fffec6f4a9b in nscall () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#10 0x00007fffec7893df in niotns () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#11 0x00007fffec794066 in osncon () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#12 0x00007fffec63ccfd in kpuadef () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#13 0x00007fffec623897 in upiini () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#14 0x00007fffec63b93c in kpuatch () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#15 0x00007fffed4c136a in kpuspextend () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#16 0x00007fffed4c36d3 in kpuspgetfreesession () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#17 0x00007fffed4c0433 in kpuspgetpooledsession () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#18 0x00007fffed4bc38d in kpuspsessionget () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#19 0x00007fffed2dfb4c in OCISessionGet () from /home/mark/data/fedex/splits3_project_stuff/localinstall/venv/oracle/instantclient_12_2/libclntsh.so
#20 0x00007ffff2534eb8 in dpiOci__sessionGet () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#21 0x00007ffff25232b3 in dpiConn__create () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#22 0x00007ffff25384d0 in dpiPool__acquireConnection () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#23 0x00007ffff2524342 in dpiConn_create () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so
#24 0x00007ffff250e997 in cxoConnection_init () from /home/mark/data/fedex/workspace/splits3/venv-20190401-pypy711/site-packages/cx_Oracle.pypy-41.so

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants