Catch Redis server errors #1119

mrunge · 2021-02-17T10:09:10Z

There seems to happen a bad interaction with Redis over
HAProxy, and Redis connections are reported as closed,
which is only temporary.

There seems to happen a bad interaction with Redis over HAProxy, and Redis connections are reported as closed, which is only temporary.

gnocchi/cli/metricd.py

mrunge · 2021-02-17T19:56:00Z

Thank you for the review. The follow-up patch should address the review comments.

Pull request has been modified.

jd

Sorry it's been a long time since I did Gnocchi stuff so my brain was a bit slow the first review

jd · 2021-02-18T13:09:16Z

gnocchi/cli/metricd.py

@@ -85,6 +86,8 @@ def run(self):
            with utils.StopWatch() as timer:
                try:
                    self._run_job()
+                except ConnectionError:


Ok I see another problem here, is that you are violating separation of concern.
The metricd tool does not need to know about Redis, and anything else can be used. That means the exception must be managed in the redis driver itself, not here.

underlying incoming/redis does not handle any exceptions, but it probably should. There has been a change in redis-py around 3.0, which hinted/suggested to catch and handle exceptions in applications and not in redis-py. I can not find the issue/pr in redis-py at the moment.

Where would you want the exception handled then?

In such files https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/incoming/redis.py and its method.
I'm not sure which part of Redis raises ConnectionError, if it's all of the, you might need to decorate with a tenacity decorator to retry a few times the operations, and bail out if it fails too much.

jd · 2021-02-18T13:09:22Z

gnocchi/cli/metricd.py

@@ -192,6 +195,8 @@ def _fill_sacks_to_process(self):
                    self.wakeup()
        except exceptions.NotImplementedError:
            LOG.info("Incoming driver does not support notification")
+        except ConnectionError:


same as above

jd · 2021-02-18T13:10:07Z

gnocchi/cli/metricd.py

@@ -219,6 +224,7 @@ def _get_sacks_to_process(self):
        finally:
            return self._tasks or self.fallback_tasks

+    @utils.retry_on_exception.wraps


That's unrelated to redis, it should probably not be there; it'll retry on ANY exception.

jd · 2021-02-18T13:10:18Z

setup.cfg

@@ -34,6 +34,7 @@ install_requires =
    futures; python_version < '3'
    jsonpatch
    cotyledon>=1.5.0
+    redis >= 3.2.0 # MIT


Redis is not mandatory to run gnocchi, do not make that change.

I agree. Moving the change to the incoming redis driver should not make it a requirement here. I've moved it back to the redis section.

as suggested in the review. Closes gnocchixyz#1120

Pull request has been modified.

in tests. s3 Was spuriously failing, we turned off testing for ceph some time ago. Time to turn it on again.

jd · 2021-02-19T10:05:03Z

.travis.yml

@@ -18,10 +18,10 @@ env:

  - TARGET: py36-mysql-file
  - TARGET: py36-mysql-swift
-  - TARGET: py36-mysql-s3
+  - TARGET: py36-mysql-ceph


This looks unrelated to this PR :(

yes indeed it is.
Ideally, I would like to have all backends enabled. There seems to be a timing(?) issue with CI, and lately, the s3 tests were failing with a chance of > 50%

jd · 2021-02-19T10:06:30Z

gnocchi/incoming/redis.py

+    @tenacity.retry(
+        wait=utils.wait_exponential,
+        # Never retry except when explicitly asked by raising TryAgain
+        retry=tenacity.retry_never)


I'd go with:

Suggested change

@tenacity.retry(

wait=utils.wait_exponential,

# Never retry except when explicitly asked by raising TryAgain

retry=tenacity.retry_never)

@tenacity.retry(

wait=utils.wait_exponential,

retry=tenacity.retry_if_exception_type(ConnectionError))

That should be simpler.
You probably want to stop at some point too though, I'd add a condition for it to stop retrying after a few tries.

That looks better. Thank you for the suggestion.

I've never seen this repeated more than twice for now.

Pull request has been modified.

jd

you still miss a stop condition right?

jd · 2021-02-19T11:17:00Z

gnocchi/incoming/redis.py

+        try:
+            for key in self._client.scan_iter(match=match, count=1000):
+                metrics += 1
+                pipe.llen(key)
+                if details:
+                    m_list.append(key.split(redis.SEP)[1].decode("utf8"))
+                # group 100 commands/call
+                if metrics % 100 == 0:
+                    results = pipe.execute()
+                    update_report(results, m_list)
+                    m_list = []
+                    pipe = self._client.pipeline()
+            else:
                results = pipe.execute()
                update_report(results, m_list)
-                m_list = []
-                pipe = self._client.pipeline()
-        else:
-            results = pipe.execute()
-            update_report(results, m_list)
+        except ConnectionError:
+            LOG.debug("Redis Server closed connection. Retrying.")


you don't need this anymore (the try/except)

jd · 2021-02-19T11:17:06Z

gnocchi/incoming/redis.py

+        try:
+            for message in p.listen():
+                if message['type'] == 'pmessage' and message['pattern'] == pattern:
+                    # FIXME(jd) This is awful, we need a better way to extract this
+                    # Format is defined by _get_sack_name: incoming128-17
+                    yield self._make_sack(int(message['channel'].split(b"-")[-1]))
+        except ConnectionError:
+            LOG.debug("Redis Server closed connection. Retrying.")


Pull request has been modified.

jd · 2021-02-19T11:59:08Z

gnocchi/incoming/redis.py

@@ -176,6 +183,10 @@ def process_measures_for_sack(self, sack):
            pipe.ltrim(key, item_len + 1, -1)
        pipe.execute()

+    @tenacity.retry(
+        wait=utils.wait_exponential,
+        # Never retry except when explicitly asked by raising TryAgain


wrong comment

gnocchi/incoming/redis.py

Pull request has been modified.

jd · 2021-02-19T14:46:55Z

@mrunge LGTM
Are you able to test it on your setup to see if it fixes your issue?

mrunge · 2021-02-19T17:22:58Z

Thank you for your reviews!

Yes, I've tested this a couple of times already over each iteration. That's why I had debug logs etc and wasn't that much concerned about stop condition.

This latest proposal does not fix the issue, try/except is required, apparently.

jd · 2021-02-19T23:03:47Z

This latest proposal does not fix the issue, try/except is required, apparently.

That does not make sense. What's the traceback?

mrunge · 2021-02-22T08:05:00Z

Sorry for not getting back earlier. While I got stack traces on Friday, The deployment is now running flawlessly for over a hour, no stack traces. Before, these kind of traces errors happened every 2 to 5 minutes. We should consider this PR to fix the issues.

mrunge · 2021-02-22T08:12:31Z

Just after my last comment, I saw this trace in the logs

2021-02-22 08:09:20,432 [32] ERROR    gnocchi.cli.metricd: Unexpected error during reporting job
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/gnocchi/cli/metricd.py", line 87, in run
    self._run_job()
  File "/usr/lib/python3.6/site-packages/gnocchi/cli/metricd.py", line 127, in _run_job
    report = self.incoming.measures_report(details=False)
  File "/usr/lib/python3.6/site-packages/gnocchi/incoming/__init__.py", line 211, in measures_report
    metrics, measures, full_details = self._build_report(details)
TypeError: 'NoneType' object is not iterable

mrunge · 2021-02-22T11:00:06Z

It turned out I had a try/except left over in my test deployment where I also tried this out. It's running for quite a while now in the form of being proposed here. Sorry to cause confusion here.

Thank you for your effort here. With this PR merged being merged, I see the issue being fixed then.

jd · 2021-02-22T11:03:30Z

Your traceback makes little sense as the _build_report function never returns None, and if the retry fails it should raise a RetryError. 🤔
You sure you got this right?

mrunge · 2021-02-22T11:08:58Z

I had wrapped

gnocchi/gnocchi/incoming/redis.py

Lines 186 to 190 in eb87188

    
           for message in p.listen(): 
        
               if message['type'] == 'pmessage' and message['pattern'] == pattern: 
        
                   # FIXME(jd) This is awful, we need a better way to extract this 
        
                   # Format is defined by _get_sack_name: incoming128-17 
        
                   yield self._make_sack(int(message['channel'].split(b"-")[-1]))

with a try/except, which then could lead to returning none.

 try:
        for message in p.listen():
            if message['type'] == 'pmessage' and message['pattern'] == pattern:
                # FIXME(jd) This is awful, we need a better way to extract this
                # Format is defined by _get_sack_name: incoming128-17
                yield self._make_sack(int(message['channel'].split(b"-")[-1]))
  except ....:
      LOG.debug....

mrunge · 2021-02-22T11:17:20Z

I understand it that way, that my additional changes/left overs were causing the exception reported in #1119 (comment).

jd · 2021-02-22T11:48:00Z

Oh ok, I got confused, I thought this PR was doing that. Ok so it should be fine!

mrunge · 2021-02-22T17:22:12Z

thank you @jd

Catch Redis server errors

3ddee4f

There seems to happen a bad interaction with Redis over HAProxy, and Redis connections are reported as closed, which is only temporary.

mrunge force-pushed the redis_reconnect branch from a9200ba to 3ddee4f Compare February 17, 2021 10:17

Move redis to install dependencies

5353276

mrunge closed this Feb 17, 2021

mrunge reopened this Feb 17, 2021

jd previously requested changes Feb 17, 2021

View reviewed changes

gnocchi/cli/metricd.py Outdated Show resolved Hide resolved

gnocchi/cli/metricd.py Outdated Show resolved Hide resolved

gnocchi/cli/metricd.py Outdated Show resolved Hide resolved

decorate function and skip other exception

841287a

mrunge requested a review from jd February 17, 2021 19:56

Remove left over variables in excepts

c27ba76

jd previously requested changes Feb 18, 2021

View reviewed changes

mrunge mentioned this pull request Feb 19, 2021

Redis closes the connection #1120

Closed

Move all exception handling to incoming/redis

79e2363

as suggested in the review. Closes gnocchixyz#1120

mrunge added 3 commits February 19, 2021 09:45

Remove empty line added in previous commit

e507e41

Remove s3 and try to enable ceph again

7677b1c

in tests. s3 Was spuriously failing, we turned off testing for ceph some time ago. Time to turn it on again.

Catch exception in another place

8fc147f

jd previously requested changes Feb 19, 2021

View reviewed changes

Turn back testing to s3 and address review feedback

df18070

mrunge force-pushed the redis_reconnect branch from c1c9276 to df18070 Compare February 19, 2021 11:14

jd previously requested changes Feb 19, 2021

View reviewed changes

Drop debug output

d6fb9e8

jd previously requested changes Feb 19, 2021

View reviewed changes

Add stop condition and fix comment

c2e6fd0

mrunge closed this Feb 22, 2021

mrunge reopened this Feb 22, 2021

jd approved these changes Feb 22, 2021

View reviewed changes

Merge branch 'master' into redis_reconnect

08a1974

mergify bot merged commit df55ac6 into gnocchixyz:master Feb 22, 2021

mrunge deleted the redis_reconnect branch February 23, 2021 11:06

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Catch Redis server errors #1119

Catch Redis server errors #1119

mrunge commented Feb 17, 2021

mrunge commented Feb 17, 2021

jd left a comment

jd Feb 18, 2021

mrunge Feb 18, 2021

jd Feb 18, 2021

jd Feb 18, 2021

jd Feb 18, 2021

jd Feb 18, 2021

mrunge Feb 19, 2021

jd Feb 19, 2021

mrunge Feb 19, 2021

jd Feb 19, 2021

mrunge Feb 19, 2021

jd left a comment

jd Feb 19, 2021

jd Feb 19, 2021

jd Feb 19, 2021

jd commented Feb 19, 2021

mrunge commented Feb 19, 2021

jd commented Feb 19, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

jd commented Feb 22, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

jd commented Feb 22, 2021

mrunge commented Feb 22, 2021

Catch Redis server errors #1119

Catch Redis server errors #1119

Conversation

mrunge commented Feb 17, 2021

mrunge commented Feb 17, 2021

jd left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jd left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jd commented Feb 19, 2021

mrunge commented Feb 19, 2021

jd commented Feb 19, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

jd commented Feb 22, 2021

mrunge commented Feb 22, 2021

mrunge commented Feb 22, 2021

jd commented Feb 22, 2021

mrunge commented Feb 22, 2021