From 2d8986bda4fd96f3aa177589a8a272e3d1f455d5 Mon Sep 17 00:00:00 2001
From: Julia Kreger <juliaashleykreger@gmail.com>
Date: Thu, 20 Jul 2023 11:01:00 -0700
Subject: [PATCH] Fix retry logic logging
logging has a method debug, and a static variable DEBUG, which are entirely
different. Tenacity requires the integer value which is passed in for logging
actions.
This is rooted in the examples published on tenacity logging, since the lower
level caller doesn't log in many cases, and our testing didn't catch this precise
case because we were only validating that logging was called, not that logging
worked. We also didn't see any of the errors related to CI resource
contention being lessened when the patch was running, and many of the chances
of lock conflicts being reduced in other fixes.
Duplicates the retry test *without* the logging mock, as not mocking the logging
would have yielded the break.
Change-Id: I4a65a044e90aff3cffae24f191e425bc75b5fb74
---
ironic/db/sqlalchemy/api.py | 2 +-
ironic/tests/unit/db/test_nodes.py | 20 ++++++++++++++++++++
2 files changed, 21 insertions(+), 1 deletion(-)
diff --git a/ironic/db/sqlalchemy/api.py b/ironic/db/sqlalchemy/api.py
index 5c976e8152..05b50d11dc 100644
--- a/ironic/db/sqlalchemy/api.py
+++ b/ironic/db/sqlalchemy/api.py
@@ -85,7 +85,7 @@ def wrap_sqlite_retry(f):
multiplier=0.25,
max=CONF.database.sqlite_max_wait_for_retry),
before_sleep=(
- tenacity.before_sleep_log(LOG, logging.debug)
+ tenacity.before_sleep_log(LOG, logging.DEBUG)
),
reraise=True):
with attempt:
diff --git a/ironic/tests/unit/db/test_nodes.py b/ironic/tests/unit/db/test_nodes.py
index ba93ec7122..3dee718eb1 100644
--- a/ironic/tests/unit/db/test_nodes.py
+++ b/ironic/tests/unit/db/test_nodes.py
@@ -879,6 +879,26 @@ class DbNodeTestCase(base.DbTestCase):
self.assertEqual(3, mock_update.call_count)
self.assertEqual(2, log_mock.log.call_count)
+ def test_update_node_retries_without_log_mock(self):
+ """Test retry logic to ensure it works."""
+ node = utils.create_test_node()
+ CONF.set_override('sqlite_retries', True, group='database')
+ # NOTE(TheJulia): Update is an ideal place to test retries
+ # as the underlying work is done by _do_update_node.
+ with mock.patch.object(db_conn, '_do_update_node',
+ autospec=True) as mock_update:
+ sa_err = sa_exc.OperationalError(
+ statement=None,
+ params=None,
+ orig=Exception('database is locked'))
+ mock_update.side_effect = [
+ sa_err,
+ sa_err,
+ node
+ ]
+ self.dbapi.update_node(node.id, {'extra': {'foo': 'bar'}})
+ self.assertEqual(3, mock_update.call_count)
+
def test_update_node_uuid(self):
node = utils.create_test_node()
self.assertRaises(exception.InvalidParameterValue,