Error running
GregSilverman opened this issue · 1 comments
GregSilverman commented
Environment: Docker Dockerfile
Referenced scripts are here: scripts
Steps to reproduce:
- Create docker image:
docker build -t build --no-cache -t ahc-nlpie-docker.artifactory.umn.edu/biomedicus3 . - Deploy container:
docker run -it -v <local source for data_in>:/data ahc-nlpie-docker.artifactory.umn.edu/biomedicus3 /home/biomedicus3/scripts/deploy-biomedicus.sh - Bash into container:
docker exec -it <container-name> bash - Run pipeline
biomedicus run --include-label-text /data/data_in /data/data_out
Expected behavior:
Process remote directory data_in listed here:
root@501501a52289:/data# ls
Annotated_XMI clamp_out data_in out qumls_system_ct_score_bm-false.csv
'Plain text files' clamp_out.zip data_out qumls_out.csv txt
UMLS clamp_out_ metamap_out qumls_system_ct.csv uima.log
biomedicus_out ctakes_out metamap_out.zip qumls_system_ct_length.csv
biomedicus_out.zip ctakes_out.zip nlptab_manifest.txt qumls_system_ct_new.csv
root@501501a52289:/data#
root@2dc720921782:/data# ls -la data_in/
total 192
drwxr-xr-x 21 root root 672 Apr 21 2020 .
drwxr-xr-x 27 root root 864 Jan 27 18:26 ..
-rwxr-xr-x 1 root root 13784 Feb 28 2020 M1.txt
-rwxr-xr-x 1 root root 7548 Feb 28 2020 M10.txt
-rwxr-xr-x 1 root root 11104 Feb 28 2020 M2.txt
-rwxr-xr-x 1 root root 8967 Feb 28 2020 M3.txt
-rwxr-xr-x 1 root root 8375 Feb 28 2020 M4.txt
-rwxr-xr-x 1 root root 7158 Feb 28 2020 M5.txt
-rwxr-xr-x 1 root root 9949 Feb 28 2020 M6.txt
-rwxr-xr-x 1 root root 6386 Feb 28 2020 M7.txt
-rwxr-xr-x 1 root root 9640 Feb 28 2020 M8.txt
-rwxr-xr-x 1 root root 8895 Feb 28 2020 M9.txt
-rwxr-xr-x 1 root root 7057 Feb 28 2020 N1.txt
-rwxr-xr-x 1 root root 8233 Feb 28 2020 N2.txt
-rwxr-xr-x 1 root root 6477 Feb 28 2020 N3.txt
-rwxr-xr-x 1 root root 6415 Feb 28 2020 N4.txt
-rwxr-xr-x 1 root root 6727 Feb 28 2020 N5.txt
-rwxr-xr-x 1 root root 7339 Feb 28 2020 N6.txt
-rwxr-xr-x 1 root root 6747 Feb 28 2020 N7.txt
-rwxr-xr-x 1 root root 6467 Feb 28 2020 N8.txt
-rwxr-xr-x 1 root root 8863 Feb 28 2020 N9.txt
Verification service is accessible in running container:
(b9) D20181472:biomedicus3_src gms$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
2dc720921782 ahc-nlpie-docker.artifactory.umn.edu/biomedicus3 "/home/biomedicus3/s…" 6 minutes ago Up 6 minutes magical_driscoll
(b9) D20181472:biomedicus3_src gms$ docker exec -it 2dc720921782 bash
root@2dc720921782:/data#
root@2dc720921782:/data# netstat -na | grep "50100"
tcp 0 0 127.0.0.1:50100 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:50100 127.0.0.1:37806 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37772 ESTABLISHED
tcp 0 0 127.0.0.1:37800 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37760 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37762 ESTABLISHED
tcp 0 0 127.0.0.1:37798 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37804 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37796 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37788 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37810 ESTABLISHED
tcp 0 0 127.0.0.1:37814 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:37762 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37766 ESTABLISHED
tcp 0 0 127.0.0.1:37794 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:37734 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37816 ESTABLISHED
tcp 0 0 127.0.0.1:37772 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:37786 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:37766 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37792 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37732 ESTABLISHED
tcp 0 0 127.0.0.1:37764 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37808 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37736 ESTABLISHED
tcp 0 0 127.0.0.1:37822 127.0.0.1:50100 ESTABLISHED
tcp 0 0 127.0.0.1:50100 127.0.0.1:37768 ESTABLISHED
.... results truncated ...
Error thrown (NB: ran three times)
root@2dc720921782:/data# biomedicus run --include-label-text /data/data_in /data/data_out
0%| | 0/19 [00:00<?, ?event/s]Traceback (most recent call last):
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 982, in provide
doc = e.create_document(self.document_name, txt)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 154, in create_document
self.documents[document_name] = document
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 745, in __setitem__
if not self.client.add_document(self.event_id, k, v.text):
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 655, in add_document
response = self.stub.AddDocument(request)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 946, in __call__
return _end_unary_response_blocking(state, call, False, None)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 849, in _end_unary_response_blocking
raise _InactiveRpcError(state)
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
status = StatusCode.NOT_FOUND
details = "Did not find event_id: 'M10.txt'"
debug_error_string = "{"created":"@1643307348.091913200","description":"Error received from peer ipv4:127.0.0.1:50100","file":"src/core/lib/surface/call.cc","file_line":1067,"grpc_message":"Did not find event_id: 'M10.txt'","grpc_status":5}"
>
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/conda/bin/biomedicus", line 8, in <module>
sys.exit(main())
File "/opt/conda/lib/python3.9/site-packages/biomedicus/cli.py", line 117, in main
f(conf)
File "/opt/conda/lib/python3.9/site-packages/biomedicus/pipeline/default_pipeline.py", line 110, in run_default_pipeline
default_pipeline.pipeline.run_multithread(source)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 483, in run_multithread
runner.run()
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 913, in run
self.source.provide(consume)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 983, in provide
consume(doc)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 182, in __exit__
self.close()
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 129, in close
self.release_lease()
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 198, in release_lease
self.client.close_event(self.event_id)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 615, in close_event
response = self.stub.CloseEvent(request)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 946, in __call__
return _end_unary_response_blocking(state, call, False, None)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 849, in _end_unary_response_blocking
raise _InactiveRpcError(state)
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
status = StatusCode.NOT_FOUND
details = "Did not find event_id: 'M10.txt'"
debug_error_string = "{"created":"@1643307348.094577600","description":"Error received from peer ipv4:127.0.0.1:50100","file":"src/core/lib/surface/call.cc","file_line":1067,"grpc_message":"Did not find event_id: 'M10.txt'","grpc_status":5}"
>
0%|
root@501501a52289:/data# biomedicus run --include-label-text /data/data_in /data/data_out
0%| | 0/19 [00:00<?, ?event/s]E0127 15:56:58.040130600 790 chttp2_transport.cc:1113] Received a GOAWAY with error code ENHANCE_YOUR_CALM and debug data equal to "too_many_pings"
E0127 15:56:58.042006200 790 chttp2_transport.cc:1113] Received a GOAWAY with error code ENHANCE_YOUR_CALM and debug data equal to "too_many_pings"
E0127 15:56:58.042650600 790 client_channel.cc:1493] chand=0x55dd6dc25458: Illegal keepalive throttling value 9223372036854775807
Traceback (most recent call last):
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 982, in provide
doc = e.create_document(self.document_name, txt)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 154, in create_document
self.documents[document_name] = document
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 745, in __setitem__
if not self.client.add_document(self.event_id, k, v.text):
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 655, in add_document
response = self.stub.AddDocument(request)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 946, in __call__
return _end_unary_response_blocking(state, call, False, None)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 849, in _end_unary_response_blocking
raise _InactiveRpcError(state)
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
status = StatusCode.NOT_FOUND
details = "Did not find event_id: 'M4.txt'"
debug_error_string = "{"created":"@1643299018.053074800","description":"Error received from peer ipv4:127.0.0.1:50100","file":"src/core/lib/surface/call.cc","file_line":1067,"grpc_message":"Did not find event_id: 'M4.txt'","grpc_status":5}"
>
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/conda/bin/biomedicus", line 8, in <module>
sys.exit(main())
File "/opt/conda/lib/python3.9/site-packages/biomedicus/cli.py", line 117, in main
f(conf)
File "/opt/conda/lib/python3.9/site-packages/biomedicus/pipeline/default_pipeline.py", line 110, in run_default_pipeline
default_pipeline.pipeline.run_multithread(source)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 483, in run_multithread
runner.run()
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 913, in run
self.source.provide(consume)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 983, in provide
consume(doc)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 182, in __exit__
self.close()
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 129, in close
self.release_lease()
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 198, in release_lease
self.client.close_event(self.event_id)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 615, in close_event
response = self.stub.CloseEvent(request)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 946, in __call__
return _end_unary_response_blocking(state, call, False, None)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 849, in _end_unary_response_blocking
raise _InactiveRpcError(state)
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
status = StatusCode.NOT_FOUND
details = "Did not find event_id: 'M4.txt'"
debug_error_string = "{"created":"@1643299018.057313400","description":"Error received from peer ipv4:127.0.0.1:50100","file":"src/core/lib/surface/call.cc","file_line":1067,"grpc_message":"Did not find event_id: 'M4.txt'","grpc_status":5}"
>
0%|
root@2dc720921782:/data# biomedicus run --include-label-text /data/data_in /data/data_out
0%| | 0/19 [00:00<?, ?event/s]Traceback (most recent call last):
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 607, in open_event
response = self.stub.OpenEvent(request)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 946, in __call__
return _end_unary_response_blocking(state, call, False, None)
File "/opt/conda/lib/python3.9/site-packages/grpc/_channel.py", line 849, in _end_unary_response_blocking
raise _InactiveRpcError(state)
grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:
status = StatusCode.ALREADY_EXISTS
details = "Event already exists: "M1.txt""
debug_error_string = "{"created":"@1643308073.795291200","description":"Error received from peer ipv4:127.0.0.1:50100","file":"src/core/lib/surface/call.cc","file_line":1067,"grpc_message":"Event already exists: "M1.txt"","grpc_status":6}"
>
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/opt/conda/bin/biomedicus", line 8, in <module>
sys.exit(main())
File "/opt/conda/lib/python3.9/site-packages/biomedicus/cli.py", line 117, in main
f(conf)
File "/opt/conda/lib/python3.9/site-packages/biomedicus/pipeline/default_pipeline.py", line 110, in run_default_pipeline
default_pipeline.pipeline.run_multithread(source)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 483, in run_multithread
runner.run()
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 913, in run
self.source.provide(consume)
File "/opt/conda/lib/python3.9/site-packages/mtap/processing/_pipeline.py", line 980, in provide
with Event(event_id=relative, client=self.client,
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 72, in __init__
self._client.open_event(self._event_id, only_create_new=only_create_new)
File "/opt/conda/lib/python3.9/site-packages/mtap/data/_events.py", line 611, in open_event
raise ValueError("Event already exists") from e
ValueError: Event already exists
0%|
:
benknoll-umn commented
I think the root error caused by failure to create the event is getting inadvertently suppressed here:
mtap/python/mtap/data/_events.py
Line 604 in 67d506a
I may fix this suppression and replicate to get it to throw the original error.
It's possible that the GOAWAY throttling might be the root cause despite not appearing in the first run.