intermittent error in ReasoningUtilities.py

[saramsey]

Quite often (but not consistently everytime), I get the following error when importing ARAXQuery in the demo branch:

    from ARAX_query import ARAXQuery
  File "/Users/sramsey/Work/Proj/ncats-translator/git-demo/code/ARAX/ARAXQuery/ARAX_query.py", line 35, in <module>
    from ParseQuestion import ParseQuestion
  File "/Users/sramsey/Work/Proj/ncats-translator/git-demo/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/ParseQuestion.py", line 3, in <module>
    import Question
  File "/Users/sramsey/Work/Proj/ncats-translator/git-demo/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/Question.py", line 14, in <module>
 from ReasoningUtilities import ReasoningUtilities as RU
  File "/Users/sramsey/Work/Proj/ncats-translator/git-demo/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/ReasoningUtilities.py", line 61, in <module>
    driver = GraphDatabase.driver(rtxConfig.neo4j_bolt, auth=basic_auth(rtxConfig.neo4j_username, rtxConfig.neo4j_password))
  File "/usr/local/lib/python3.7/site-packages/neo4j/__init__.py", line 108, in driver
    return Driver(uri, **config)
  File "/usr/local/lib/python3.7/site-packages/neo4j/__init__.py", line 147, in __new__
    return subclass(uri, **config)
  File "/usr/local/lib/python3.7/site-packages/neo4j/__init__.py", line 221, in __new__
    pool.release(pool.acquire())
  File "/usr/local/lib/python3.7/site-packages/neobolt/direct.py", line 698, in acquire
    return self.acquire_direct(self.address)
  File "/usr/local/lib/python3.7/site-packages/neobolt/direct.py", line 591, in acquire_direct
    connection = self.connector(address, error_handler=self.connection_error_handler)
  File "/usr/local/lib/python3.7/site-packages/neo4j/__init__.py", line 218, in connector
    return connect(address, **dict(config, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/neobolt/direct.py", line 949, in connect
    raise last_error
  File "/usr/local/lib/python3.7/site-packages/neobolt/direct.py", line 940, in connect
    s, der_encoded_server_certificate = _secure(s, address[0], security_plan.ssl_context, **config)
  File "/usr/local/lib/python3.7/site-packages/neobolt/direct.py", line 832, in _secure
    s = ssl_context.wrap_socket(s, server_hostname=host if HAS_SNI and host else None)
  File "/usr/local/Cellar/python/3.7.6_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 423, in wrap_socket
    session=session
  File "/usr/local/Cellar/python/3.7.6_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 870, in _create
    self.do_handshake()
  File "/usr/local/Cellar/python/3.7.6_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1139, in do_handshake
    self._sslobj.do_handshake()
ConnectionResetError: [Errno 54] Connection reset by peer

This is on a 2018 MBP running macOS 10.14.6 and running python 3.7.6. The output of pip freeze is shown below:

alv==1.3.2
appnope==0.1.0
argh==0.26.2
backcall==0.1.0
basicauth==0.4.1
biopython==1.73
bleach==3.1.0
CacheControl==0.12.6
cachier==1.2.5
certifi==2018.11.29
chardet==3.0.4
Click==7.0
colorama==0.4.1
cycler==0.10.0
Cython==0.29.5
decorator==4.3.2
defusedxml==0.5.0
dirlistproc==1.4.5
entrypoints==0.3
flake8==3.7.7
Flask==1.1.1
idna==2.8
ipdb==0.11
ipykernel==5.1.0
ipython==7.2.0
ipython-cypher==0.2.6
ipython-genutils==0.2.0
ipywidgets==7.4.2
isodate==0.6.0
itsdangerous==1.1.0
jedi==0.13.2
Jinja2==2.11.1
jsobject==0.10.2
jsonasobj==1.2.1
jsonschema==2.6.0
jupyter==1.0.0
jupyter-client==5.2.4
jupyter-console==6.0.0
jupyter-core==4.4.0
kiwisolver==1.0.1
logomaker==0.8
MarkupSafe==1.1.0
marshmallow==3.0.0b3
matplotlib==3.0.3
mccabe==0.6.1
mistune==0.8.4
msgpack==1.0.0
mypy==0.761
mypy-extensions==0.4.3
mysqlclient==1.4.2.post1
nbconvert==5.4.1
nbformat==4.4.0
neo4j==1.7.1
neo4jrestclient==2.1.1
neobolt==1.7.4
neotime==1.7.4
networkx==2.2
nltk==3.4.5
notebook==5.7.4
numpy==1.16.1
obonet==0.2.5
ontobio==1.7.1
Owlready2==0.14
pandas==0.24.1
pandocfilters==1.4.2
parso==0.3.3
pathtools==0.1.2
pexpect==4.6.0
pickleDB==0.9.2
pickleshare==0.7.5
portalocker==1.3.0
prefixcommons==0.1.7
prettytable==0.7.2
prometheus-client==0.5.0
prompt-toolkit==2.0.8
pronto==0.12.1
ptyprocess==0.6.0
pycodestyle==2.5.0
pyflakes==2.1.1
Pygments==2.3.1
PyMySQL==0.9.3
pyparsing==2.3.1
pysolr==3.8.1
python-dateutil==2.8.0
pytz==2018.9
PyYAML==4.2b4
pyzmq==17.1.2
qtconsole==4.4.3
rdflib==4.2.2
rdflib-jsonld==0.4.0
requests==2.21.0
requests-cache==0.4.13
requests-testadapter==0.3.0
scipy==1.2.1
Send2Trash==1.5.0
six==1.12.0
SNOMEDToOWL==0.3.1
SPARQLWrapper==1.8.2
SQLAlchemy==1.3.13
terminado==0.8.1
testpath==0.4.2
tornado==5.1.1
traitlets==4.3.2
typed-ast==1.4.1
typing-extensions==3.7.4.1
urllib3==1.24.1
virtualenv==16.7.2
watchdog==0.9.0
wcwidth==0.1.7
webencodings==0.5.1
Werkzeug==1.0.0
widgetsnbextension==3.4.2
yamldown==0.1.6

[edeutsch]

Looks like a problem of python not being able to open the neo4j connection properly (intermittently). I have no idea about how to debug that. Maybe an SSL thing. Sorry, I really don't know. I don't run on OS X.

[saramsey]

Yes, I am just documenting the issue here. Totally understand that this may be a user-setup issue.

[saramsey]

Wonder if there is some kind of "race condition" going on, in the Neo4j connection establishment.

[dkoslicki]

This might be cause by ReasoningUtilities being imported in ARAX_query.py that also tries to make a Neo4j connection (I've seen this same issue on two different flavors of Ubuntu). If @edeutsch isn't using ReasoningUtilities, I vote we remove it from ARAX_query.py

[edeutsch]

I don't recall if any code is using it. A lot of stuff imports it. I can try to pull it out and see if it all still works.

[edeutsch]

I have observed this same behavior many times now too. I recently observed it running KGNodeIndex which does an import of ReasoningUtilities. The only thing it imports is: import ReasoningUtilities as RU from RTXConfiguration import RTXConfiguration

I'm pretty sure RTXConfiguration won't touch neo4j.

so the conclusion is that just a single import of ReasoningUtilities can sporadically cause this error.

Seems to happen on multiple clients. I've seen it on arax.rtx.ai. And Steve on his Mac.

I am concerned there is an instability with the neo4j server itself that causes it sometimes to reject connections.

Traceback (most recent call last):
File "KGNodeIndex.py", line 14, in
import ReasoningUtilities as RU
File "G:\Repositories\GitHub\RTX\code\reasoningtool\kg-construction/../QuestionAnswering\ReasoningUtilities.py", line 61, in
driver = GraphDatabase.driver(rtxConfig.neo4j_bolt, auth=basic_auth(rtxConfig.neo4j_username, rtxConfig.neo4j_password))
File "C:\Program Files\Python37\lib\site-packages\neo4j__init.py", line 120, in driver
return Driver(uri, config)
File "C:\Program Files\Python37\lib\site-packages\neo4j__init.py", line 161, in new__
return subclass(uri, config)
File "C:\Program Files\Python37\lib\site-packages\neo4j__init.py", line 235, in new__
pool.release(pool.acquire())
File "C:\Program Files\Python37\lib\site-packages\neobolt\direct.py", line 715, in acquire
return self.acquire_direct(self.address)
File "C:\Program Files\Python37\lib\site-packages\neobolt\direct.py", line 608, in acquire_direct
connection = self.connector(address, error_handler=self.connection_error_handler)
File "C:\Program Files\Python37\lib\site-packages\neo4j\init__.py", line 232, in connector
return connect(address, dict(config, kwargs))
File "C:\Program Files\Python37\lib\site-packages\neobolt\direct.py", line 972, in connect
raise last_error
File "C:\Program Files\Python37\lib\site-packages\neobolt\direct.py", line 963, in connect
s, der_encoded_server_certificate = _secure(s, host, security_plan.ssl_context, **config)
File "C:\Program Files\Python37\lib\site-packages\neobolt\direct.py", line 854, in _secure
s = ssl_context.wrap_socket(s, server_hostname=host if HAS_SNI and host else None)
File "C:\Program Files\Python37\lib\ssl.py", line 423, in wrap_socket
session=session
File "C:\Program Files\Python37\lib\ssl.py", line 870, in _create
self.do_handshake()
File "C:\Program Files\Python37\lib\ssl.py", line 1139, in do_handshake
self._sslobj.do_handshake()
FileNotFoundError: [Errno 2] No such file or directory

Although weirdly, a FileNotFoundError. This was on Windows.

[edeutsch]

This just happened to me over on arax.rtx.ai (completely different OS than previous report). It seems to happen most frequently when a shell hasn't connected in a long while? something stale-ish? Immediately re-trying the script yielded success. RTXConfiguration is no longer part of the picture. So the only import is ReasoningUtilities. and that's where it dies.

Traceback (most recent call last): File "KGNodeIndex.py", line 14, in import ReasoningUtilities as RU File "/mnt/data/orangeboard/devED/RTX/code/reasoningtool/kg-construction/../QuestionAnswering/ReasoningUtilities.py", line 51, in import fisher_exact File "/mnt/data/orangeboard/devED/RTX/code/reasoningtool/kg-construction/../QuestionAnswering/fisher_exact.py", line 55, in driver = GraphDatabase.driver(rtxConfig.neo4j_bolt, auth=basic_auth(rtxConfig.neo4j_username, rtxConfig.neo4j_password)) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neo4j/init.py", line 116, in driver return Driver(uri, config) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neo4j/init.py", line 157, in new return subclass(uri, config) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neo4j/init.py", line 231, in new pool.release(pool.acquire()) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neobolt/direct.py", line 719, in acquire return self.acquire_direct(self.address) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neobolt/direct.py", line 612, in acquire_direct connection = self.connector(address, error_handler=self.connection_error_handler) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neo4j/init.py", line 228, in connector return connect(address, dict(config, kwargs)) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neobolt/direct.py", line 976, in connect raise last_error File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neobolt/direct.py", line 967, in connect s, der_encoded_server_certificate = _secure(s, host, security_plan.ssl_context, **config) File "/mnt/data/python/Python-3.7.3/lib/python3.7/site-packages/neobolt/direct.py", line 858, in _secure s = ssl_context.wrap_socket(s, server_hostname=host if HAS_SNI and host else None) File "/mnt/data/python/Python-3.7.3/lib/python3.7/ssl.py", line 412, in wrap_socket session=session File "/mnt/data/python/Python-3.7.3/lib/python3.7/ssl.py", line 853, in _create self.do_handshake() File "/mnt/data/python/Python-3.7.3/lib/python3.7/ssl.py", line 1117, in do_handshake self._sslobj.do_handshake() ConnectionResetError: [Errno 104] Connection reset by peer

[edeutsch]

On arax.rtx.ai I continue to get this about once per day. Seems to be most frequent when connecting to neo4j after a bit of a hiatus. i.e. the first time I run a script in a day it has a higher chance of this crash than during an active development/debugging session. but the latter is not 0.0 either.

Immediate retry succeeds 95% of the time. Is 100% success after two retries.

[saramsey]

FWIW, I can confirm that I am seeing this from time to time, even after having switched to a "stock" installation of ARAX from the demo branch (no funky sqlite stuff).

[edeutsch]

on your mac?

[edeutsch]

I am also seeing this problem more and more frequently on the running instances. It happened a lot this afternoon. I have an hourly health monitoring agent and here is a list of all the errors for the last week. Good thing it was stable before noon today, cuz it sure wasn't after noon.

[edeutsch]

On a whim, tried this on arax.rtx.ai:

pip3 install --upgrade neo4j-driver Successfully installed neo4j-driver-1.7.6

pip3 install --upgrade neobolt Successfully installed neobolt-1.7.16

and restarted /beta endpoint.

fingers crossed.

[amykglen]

Wanted to document that I also get this error on my macbook multiple times a day - agree it seems to be most frequent when connecting to neo4j after a hiatus, though that's not always the case. It always works fine if I immediately retry.

(rtx-env-7) amys-macbook:ARAXQuery aglen$ python ARAX_query.py 1212
Traceback (most recent call last):
  File "ARAX_query.py", line 36, in <module>
    from ParseQuestion import ParseQuestion
  File "/Users/aglen/translator/RTX/RTX/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/ParseQuestion.py", line 3, in <module>
    import Question
  File "/Users/aglen/translator/RTX/RTX/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/Question.py", line 14, in <module>
    from ReasoningUtilities import ReasoningUtilities as RU
  File "/Users/aglen/translator/RTX/RTX/code/ARAX/ARAXQuery/../../reasoningtool/QuestionAnswering/ReasoningUtilities.py", line 61, in <module>
    driver = GraphDatabase.driver(rtxConfig.neo4j_bolt, auth=basic_auth(rtxConfig.neo4j_username, rtxConfig.neo4j_password))
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neo4j/__init__.py", line 120, in driver
    return Driver(uri, **config)
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neo4j/__init__.py", line 161, in __new__
    return subclass(uri, **config)
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neo4j/__init__.py", line 235, in __new__
    pool.release(pool.acquire())
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neobolt/direct.py", line 715, in acquire
    return self.acquire_direct(self.address)
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neobolt/direct.py", line 608, in acquire_direct
    connection = self.connector(address, error_handler=self.connection_error_handler)
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neo4j/__init__.py", line 232, in connector
    return connect(address, **dict(config, **kwargs))
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neobolt/direct.py", line 972, in connect
    raise last_error
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neobolt/direct.py", line 963, in connect
    s, der_encoded_server_certificate = _secure(s, host, security_plan.ssl_context, **config)
  File "/Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages/neobolt/direct.py", line 854, in _secure
    s = ssl_context.wrap_socket(s, server_hostname=host if HAS_SNI and host else None)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 423, in wrap_socket
    session=session
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 870, in _create
    self.do_handshake()
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1139, in do_handshake
    self._sslobj.do_handshake()
OSError: [Errno 0] Error

Here's my environment's neo4j-driver info:

(rtx-env-7) amys-macbook:ARAXQuery aglen$ pip show neo4j-driver
Name: neo4j-driver
Version: 1.7.6
Summary: Neo4j Bolt driver for Python
Home-page: https://github.com/neo4j/neo4j-python-driver
Author: Neo Technology
Author-email: drivers@neo4j.com
License: Apache License, Version 2.0
Location: /Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages
Requires: neobolt, neotime
Required-by: 

And neobolt:

(rtx-env-7) amys-macbook:ARAXQuery aglen$ pip show neobolt
Name: neobolt
Version: 1.7.16
Summary: Neo4j Bolt connector for Python
Home-page: https://github.com/neo4j-drivers/neobolt
Author: Neo4j Sweden AB
Author-email: drivers@neo4j.com
License: Apache License, Version 2.0
Location: /Users/aglen/translator/RTX/rtx-env-7/lib/python3.7/site-packages
Requires: 
Required-by: neo4j-driver

[edeutsch]

It seems that everyone is seeing this on multiple client platforms. I'm thinking it's server. Is there a possibility that there is a newer version of the neo4j server available, perhaps with some bugfixes?

[dkoslicki]

@edeutsch looks like some sort of encryption issue as noted in these threads/issues observing the same thing: https://github.com/neo4j/neo4j/issues/12392 https://community.neo4j.com/t/connect-to-neo4j-hosted-on-a-remote-ec2-instance-via-python-running-on-my-current-ec2-instance/13774/2 https://community.neo4j.com/t/connecting-to-local-db-via-python-bolt-episode-ii/16969

So looks like the fix is driver = GraphDatabase.driver(... , encrypted=False) Or set up SSL properly with https://github.com/neo4j/neo4j/issues/12392#issuecomment-589730390

[edeutsch]

Seems like most of these complaints are about not being able to connect at all? Rather than just intermittent failures? But, we can certainly try it. I assume SSL is set up properly on neo4j, otherwise we wouldn't be able to connect at all?

So the two options seem to be: 1) See if we are running the very latest neo4j code and upgrade if not 2) turn off encrypted connections as suggested above

Which approach shall we try first?

[dkoslicki]

@edeutsch Option 1 seems best (if there's a way to roll back if it breaks things), then 2 if that doesn't work

[edeutsch]

I agree. Can we ask @finnagin or @saramsey to try option 1?

[finnagin]

Next steps to try from the meeting today:

1. diff the config files in arax.rtx.ai and kg2endpoint.rtx.ai to see if problems could be coming from there
2. try adding encrypted=False to line 61 in reasoningutilities
3. try standing up rtx2 container in arax.rtx.ai and try installing a newer version of neo4j (either 3.5.17 or 4.0)

[saramsey]

OK @finnagin please try:

1. the suggestion from @dkoslicki about using encrypted=False in the static method call `GraphDatabase.driver, on the client side in some test area; use the test loop code that @amykglen wrote
2. diff the /etc/neo4j/neo4.conf files from kg1endpoint.rxt.ai (which does not have the bug) and kg2endpoint2.rtx.ai (which does not have the bug) and the rtx1 container on arax.rtx.ai.
3. check the /var/log/neo4n/debug.log file for the KG1 neo4j. Compare to the Neo4j log file on kg2endpoint2 to see if we can identify a stack backtrace on the RTX1 Neo4j that corresponds to this "connection reset by peer" fault (the stack backtrace should presumably not be occurring in the debug.log file on kg2endpoint2.
4. Maybe look into setting up container RTX2 on ARAX so we can reproduce the problem, but using a totally separate Neo4j from our production KG1 neo4j.

[finnagin]

@amykglen is something like this what you are using to test the error?

from neo4j.v1 import GraphDatabase, basic_auth
from RTXConfiguration import RTXConfiguration
rtxConfig = RTXConfiguration()
for i in range(40):
    driver = GraphDatabase.driver(rtxConfig.neo4j_bolt, auth=basic_auth(rtxConfig.neo4j_username, rtxConfig.neo4j_password))

[amykglen]

yes, close, although I avoided using RTXConfiguration (to totally eliminate all RTX/ARAX code) and just (locally) directly plugged in the auth info:

from neo4j import GraphDatabase
for num in range(80):
    driver = GraphDatabase.driver(BOLT_URL, auth=(USER_NAME, PASSWORD))
    with driver.session() as session:
        results = session.run(cypher_query).data()
    driver.close()

[finnagin]

1. unfortunately adding encrypted=False does not seem to work.

2. Here are the results form the diff between arax and kg1endpoint. Things that jump out at me:

   • I see that The initial heap size and max heap size is not set on arax could try adding this in
   • A bunch of ssl options are set differently on arax but they are all commented out on both arax and kg1endpoint so I don't think they are being used in either of them

> #dbms.active_database=graph.db
12c13,14
< dbms.directories.data=/var/lib/neo4j/data
---
> #dbms.directories.data=/var/lib/neo4j/data
> dbms.directories.data=/mnt/data/RTX1
35,36c37,38
< dbms.memory.heap.initial_size=512m
< dbms.memory.heap.max_size=12G
---
> #dbms.memory.heap.initial_size=512m
> #dbms.memory.heap.max_size=512m
124c126
< #dbms.ssl.policy.default.base_directory=certificates/default
---
> #dbms.ssl.policy.default.base_directory=/etc/letsencrypt/live/ncats.saramsey.org
147c149
< #dbms.ssl.policy.default.private_key=
---
> #dbms.ssl.policy.default.private_key=privkey.pem
153c155
< #dbms.ssl.policy.default.public_certificate=
---
> #dbms.ssl.policy.default.public_certificate=fullchain.pem
216a219,225
> # Query logging options
> dbms.logs.query.enabled=true
> dbms.logs.query.rotation.keep_number=1000
> dbms.logs.query.rotation.size=1G
> dbms.logs.query.threshold=0
> dbms.logs.query.time_logging_enabled=true
> 
319c328
< dbms.security.procedures.unrestricted=apoc.*,algo.*
---
> dbms.security.procedures.unrestricted=apoc.*

3. looks like this is the backrace in the debug file:

at java.lang.Thread.run(Thread.java:748)
2020-05-19 20:18:22.695+0000 ERROR [io.netty.util.concurrent.DefaultPromise.rejectedExecution] Failed to submit a listener notification task. Event loop shut down? event executor terminated
java.util.concurrent.RejectedExecutionException: event executor terminated

from a quick google search I found this: https://github.com/netty/netty/issues/7289

And it is mentioned that this error has to do with memory management so this makes me think that changing that config option to allow for a larger max heap size might work.

I think the next step would be to try changing this config option and then restarting neo4j to see if this would work though I would like to wait for a low use time to try restarting. Maybe late at night?

[saramsey]

I think the next step would be to try changing this config option and then restarting neo4j to see if this would work though I would like to wait for a low use time to try restarting. Maybe late at night?

OK sure, but please save a copy of the previous config file so you can revert.

[finnagin]

Just updated neo4j.conf (after saving a backup) and restarted and this seems to have fixed it. I just tried a loop of 80 and then another loop of 300 and no errors on my end.

[saramsey]

Awesome! @finnagin can you please

1. record the specific config change that you made, in this issue?
2. check the new Neo4j config file into the project github directory https://github.com/RTXteam/RTX/tree/master/notes/ARAX
3. tag this issue in the commit log when you are doing item (2)?

[saramsey]

Solid teamwork on this issue, folks.

[finnagin]

Now that I've uploaded the conf file I'm going to go ahead and close this issue.