Uncaught ConnectionTimeout causes the disabling of the rules

[nicolasnovelli]

Hello everyone!
I am having some troubles with disabled rules and uncaught exceptions.

In the past few days, I made some changes to the Elasticsearch cluster and it happened that it was not available at times. I noticed that some rules were often disabled, but restarting the service fixed the problem. Investigating the issue from the log file and the elastalert_error index, I found some uncaught exceptions similar to this one:

elastalert Uncaught exception running rule spike_in_requests: ConnectionTimeout caused by - ReadTimeout(HTTPSConnectionPool(host='example_host', port=9200): Read timed out. (read timeout=20))

In the logs file, I found two stack traces, one starting from the writeback function and the other from the clear_scroll call in the run_query function. This is the one from clear_scroll.

elastalert Traceback (most recent call last):
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 449, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 444, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.9/http/client.py", line 1347, in getresponse
    response.begin()
  File "/usr/lib/python3.9/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.9/http/client.py", line 268, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/lib/python3.9/socket.py", line 704, in readinto
    return self._sock.recv_into(b)
  File "/usr/lib/python3.9/ssl.py", line 1241, in recv_into
    return self.read(nbytes, buffer)
  File "/usr/lib/python3.9/ssl.py", line 1099, in read
    return self._sslobj.read(len, buffer)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/requests/adapters.py", line 440, in send
    resp = conn.urlopen(
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 785, in urlopen
    retries = retries.increment(
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/util/retry.py", line 550, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/packages/six.py", line 770, in reraise
    raise value
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 703, in urlopen
    httplib_response = self._make_request(
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 451, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 340, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='example_host', port=9200): Read timed out. (read timeout=20)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/connection/http_requests.py", line 161, in perform_request
    response = self.session.send(prepared_request, **send_kwargs)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/requests/sessions.py", line 645, in send
    r = adapter.send(request, **kwargs)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/requests/adapters.py", line 532, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='example_host, port=9200): Read timed out. (read timeout=20)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elastalert/elastalert.py", line 1234, in handle_rule_execution
    num_matches = self.run_rule(rule, endtime, rule.get('initial_starttime'))
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elastalert/elastalert.py", line 868, in run_rule
    if not self.run_query(rule, rule['starttime'], endtime):
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elastalert/elastalert.py", line 629, in run_query
    self.thread_data.current_es.clear_scroll(scroll_id=scroll_id)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/client/utils.py", line 152, in _wrapped
    return func(*args, params=params, headers=headers, **kwargs)
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/client/__init__.py", line 481, in clear_scroll
    return self.transport.perform_request(
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/transport.py", line 392, in perform_request
    raise e
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/transport.py", line 358, in perform_request
    status, headers_response, data = connection.perform_request(
  File "/opt/test/apps/elastalert/env/lib/python3.9/site-packages/elasticsearch/connection/http_requests.py", line 176, in perform_request
    raise ConnectionTimeout("TIMEOUT", str(e), e)
elasticsearch.exceptions.ConnectionTimeout: ConnectionTimeout caused by - ReadTimeout(HTTPSConnectionPool(host='example_host', port=9200): Read timed out. (read timeout=20))

I noticed that in almost all interactions with Elasticsearch (I searched for current_es in the code), the ElasticsearchException is caught, while the clear_scroll call only catches exceptions of type NotFoundError. Is there a reason why only NotFoundError is caught?

I think that the uncaught exception is raised by the clear_scroll call, but I'm not 100% sure. I was wondering if you have ever encountered similar problems.

Thanks!

[nsano-rururu]

#323

[nicolasnovelli]

Thank you for the link. However, it is still unclear to me whether it is correct that similar exceptions are not caught only in clear scroll calls, while in other interactions with Elasticsearch they are handled correctly. I'm ok with some timeout error, but I don't think it should disable the rule, therefore affecting also future executions.

Have a nice day!

[jertel]

It was likely an oversight and I suspect very few people have run into it, because it would mean the ES server needs to go offline at a very specific time during the rule processing. If you want to submit a PR, please review the contribution guidelines first. Alternatively, you can disable the behavior where it disables rules after encountering an error.