ConnectionTimeout with Elasticsearch

[anjalijain22]

Hello,

Hope you're doing well!

I'm running the seqr pipeline locally on a VCF file containing 350 samples. The pipeline creates the .mt file just fine but runs into a Connection Timeout (full error message below) on Stage 18 (creation of the ES index):

[Stage 18:=====================================================>(591 + 1) / 592]^MERROR: [pid 1100320] Worker Worker(salt=087941419, workers=1, host=8bcf3758d98c, username=root, pid=1100320) failed    SeqrMTToESTask(source_path=<lui
gi.parameter.Parameter object at 0x7f511284f2b0>, use_temp_loading_nodes=True, es_host=elasticsearch, es_port=9200, es_index=tof_ontario_extension, es_username=pipeline, es_password=None, es_index_min_num_shards=1,
 source_paths=/input_vcfs/GRCh38/Mital_Lab/TOF-Ontario/TOF_Ontario_Extension_cohort_GATK_fix.vcf.gz, dest_path=/input_vcfs/GRCh38/Mital_Lab/TOF-Ontario/TOF_Ontario_Extension_cohort_GATK_fix.mt, genome_version=38, v
ep_runner=VEP, reference_ht_path=/seqr-reference-data/GRCh38/combined_reference_data_grch38.ht, clinvar_ht_path=/seqr-reference-data/GRCh38/clinvar.GRCh38.ht, hgmd_ht_path=None, sample_type=WGS, dont_validate=False
, dataset_type=VARIANTS, remap_path=, subset_path=, vep_config_json_path=/vep_configs/vep-GRCh38-loftee.json, grch38_to_grch37_ref_chain=gs://hail-common/references/grch38_to_grch37.over.chain.gz)
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 449, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 444, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/local/lib/python3.7/http/client.py", line 1321, in getresponse
    response.begin()
  File "/usr/local/lib/python3.7/http/client.py", line 296, in begin
    version, status, reason = self._read_status()
  File "/usr/local/lib/python3.7/http/client.py", line 257, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/local/lib/python3.7/socket.py", line 589, in readinto
    return self._sock.recv_into(b)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/connection/http_urllib3.py", line 246, in perform_request
    method, url, body, retries=Retry(False), headers=request_headers, **kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 786, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/retry.py", line 525, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/local/lib/python3.7/site-packages/urllib3/packages/six.py", line 770, in reraise
    raise value
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 710, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 451, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 341, in _raise_timeout
    self, url, "Read timed out. (read timeout=%s)" % timeout_value
urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='elasticsearch', port=9200): Read timed out. (read timeout=10)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/luigi/worker.py", line 199, in run
    new_deps = self._run_get_new_deps()
  File "/usr/local/lib/python3.7/site-packages/luigi/worker.py", line 141, in _run_get_new_deps
    task_gen = self.task.run()
  File "/hail-elasticsearch-pipelines/luigi_pipeline/seqr_loading.py", line 252, in run
    self.cleanup(es_shards)
  File "/hail-elasticsearch-pipelines/luigi_pipeline/lib/hail_tasks.py", line 251, in cleanup
    self._es.wait_for_shard_transfer(self.es_index)
  File "/hail-elasticsearch-pipelines/hail_scripts/elasticsearch/elasticsearch_client_v7.py", line 139, in wait_for_shard_transfer
    shards = self.es.cat.shards(index=index_name)
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/client/utils.py", line 152, in _wrapped
    return func(*args, params=params, headers=headers, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/client/cat.py", line 304, in shards
    "GET", _make_path("_cat", "shards", index), params=params, headers=headers
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/transport.py", line 392, in perform_request
    raise e
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/transport.py", line 365, in perform_request
    timeout=timeout,
  File "/usr/local/lib/python3.7/site-packages/elasticsearch/connection/http_urllib3.py", line 257, in perform_request
    raise ConnectionTimeout("TIMEOUT", str(e), e)
elasticsearch.exceptions.ConnectionTimeout: ConnectionTimeout caused by - ReadTimeoutError(HTTPConnectionPool(host='elasticsearch', port=9200): Read timed out. (read timeout=10))
DEBUG: 1 running tasks, waiting for next task to finish
INFO: Informed scheduler that task   SeqrMTToESTask__seqr_reference__VARIANTS__input_vcfs_GRCh_636a959576   has status   FAILED
DEBUG: Asking scheduler for work...
DEBUG: Done
DEBUG: There are no more tasks to run at this time
DEBUG: There are 1 pending tasks possibly being run by other workers
DEBUG: There are 1 pending tasks unique to this worker
DEBUG: There are 1 pending tasks last scheduled by this worker
INFO: Worker Worker(salt=087941419, workers=1, host=8bcf3758d98c, username=root, pid=1100320) was stopped. Shutting down Keep-Alive thread
INFO: 
===== Luigi Execution Summary =====

Scheduled 3 tasks of which:
* 1 complete ones were encountered:
    - 1 VcfFile(filename=/input_vcfs/GRCh38/Mital_Lab/TOF-Ontario/TOF_Ontario_Extension_cohort_GATK_fix.vcf.gz)
* 1 ran successfully:
    - 1 SeqrVCFToMTTask(...)
* 1 failed:
    - 1 SeqrMTToESTask(...)

This progress looks :( because there were failed tasks

===== Luigi Execution Summary =====

I'm wondering if:

1. You have seen this message below and have ideas on how to debug it?
2. If there is a command I can use to just execute Stage 18 (creation of the ES Index) instead of running the entire pipeline again? Is this recommended?

Many thanks for your help in advance!

[bpblanken]

Hi @anjalijain22

I haven't seen this specific error before, but it looks like this is a socket timeout issue. My first approach for debugging would be to add a request_timeout=60 argument to this line or setting timeout=60 when the client is initialized.

There are additional suggestions on this Stack Overflow post.

Regarding your second question, if you have left the intermediate MatrixTables the pipeline will be able to use them and can proceed to the elasticsearch export.

[anjalijain22]

Hi @bpblanken, thanks for your prompt response!
I have made the change you suggested but I'm encountering another issue now - the previous pipeline run had created an incomplete ES index so I deleted it from the Data Management page. However, now when I try to rerun the pipeline it says there are no pending tasks to complete. Not sure how to tackle this - does this mean the ES index was not deleted properly? If so, how can I delete it? I don't see it in the Data Management page any more

===== Luigi Execution Summary =====

Scheduled 1 tasks of which:
* 1 complete ones were encountered:
    - 1 SeqrMTToESTask(...)

Did not run any tasks
This progress looks :) because there were no failed tasks or missing dependencies

===== Luigi Execution Summary =====

[bpblanken]

Hi @anjalijain22, I believe the SeqrMTToESTask outputs a completion marker on this line. You might be able to try deleting at that path.

If you're not able to find the file, try something like find . -type f | grep _EXPORTED_TO_ES.