[ARVADOS] updated: 1.1.3-137-g19ee2e0
Git user
git at public.curoverse.com
Thu Mar 8 10:37:38 EST 2018
Summary of changes:
sdk/python/arvados/commands/put.py | 5 +--
sdk/python/tests/test_arv_put.py | 66 +++++++++++++++++++++++++++++++-------
2 files changed, 57 insertions(+), 14 deletions(-)
via 19ee2e029443d4d6de3df4a4e8bcb6ae9700475a (commit)
from 96f657210ce401a84eafc4a575f56694f2b39a0b (commit)
Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.
commit 19ee2e029443d4d6de3df4a4e8bcb6ae9700475a
Author: Lucas Di Pentima <ldipentima at veritasgenetics.com>
Date: Thu Mar 8 12:34:16 2018 -0300
13147: X-Request-Id logging updates when running arv-put.
Remove the initial request-id logging when starting the run.
Update the custom formatter so that it shows the request-id only once.
Add related tests.
Arvados-DCO-1.1-Signed-off-by: Lucas Di Pentima <ldipentima at veritasgenetics.com>
diff --git a/sdk/python/arvados/commands/put.py b/sdk/python/arvados/commands/put.py
index 0f8dc5f..3f4766d 100644
--- a/sdk/python/arvados/commands/put.py
+++ b/sdk/python/arvados/commands/put.py
@@ -313,6 +313,7 @@ class FileUploadList(list):
class ArvPutLogFormatter(logging.Formatter):
std_fmtr = logging.Formatter(arvados.log_format, arvados.log_date_format)
err_fmtr = None
+ request_id_informed = False
def __init__(self, request_id):
self.err_fmtr = logging.Formatter(
@@ -320,7 +321,8 @@ class ArvPutLogFormatter(logging.Formatter):
arvados.log_date_format)
def format(self, record):
- if record.levelno in (logging.DEBUG, logging.ERROR):
+ if (not self.request_id_informed) and (record.levelno in (logging.DEBUG, logging.ERROR)):
+ self.request_id_informed = True
return self.err_fmtr.format(record)
return self.std_fmtr.format(record)
@@ -1002,7 +1004,6 @@ def main(arguments=None, stdout=sys.stdout, stderr=sys.stderr):
status = 0
request_id = arvados.util.new_request_id()
- logger.info('X-Request-Id: '+request_id)
formatter = ArvPutLogFormatter(request_id)
logging.getLogger('arvados').handlers[0].setFormatter(formatter)
diff --git a/sdk/python/tests/test_arv_put.py b/sdk/python/tests/test_arv_put.py
index a376aeb..e11c309 100644
--- a/sdk/python/tests/test_arv_put.py
+++ b/sdk/python/tests/test_arv_put.py
@@ -575,6 +575,47 @@ class ArvadosPutReportTest(ArvadosBaseTestCase):
arv_put.human_progress(count, None)))
+class ArvPutLogFormatterTest(ArvadosBaseTestCase):
+ matcher = r'\(X-Request-Id: req-[a-z0-9]{20}\)'
+
+ def setUp(self):
+ super(ArvPutLogFormatterTest, self).setUp()
+ self.stderr = tutil.StringIO()
+ self.loggingHandler = logging.StreamHandler(self.stderr)
+ self.loggingHandler.setFormatter(
+ arv_put.ArvPutLogFormatter(arvados.util.new_request_id()))
+ self.logger = logging.getLogger()
+ self.logger.addHandler(self.loggingHandler)
+ self.logger.setLevel(logging.DEBUG)
+
+ def tearDown(self):
+ self.logger.removeHandler(self.loggingHandler)
+ self.stderr.close()
+ self.stderr = None
+ super(ArvPutLogFormatterTest, self).tearDown()
+
+ def test_request_id_logged_only_once_on_error(self):
+ self.logger.error('Ooops, something bad happened.')
+ self.logger.error('Another bad thing just happened.')
+ log_lines = self.stderr.getvalue().split('\n')[:-1]
+ self.assertEqual(2, len(log_lines))
+ self.assertRegex(log_lines[0], self.matcher)
+ self.assertNotRegex(log_lines[1], self.matcher)
+
+ def test_request_id_logged_only_once_on_debug(self):
+ self.logger.debug('This is just a debug message.')
+ self.logger.debug('Another message, move along.')
+ log_lines = self.stderr.getvalue().split('\n')[:-1]
+ self.assertEqual(2, len(log_lines))
+ self.assertRegex(log_lines[0], self.matcher)
+ self.assertNotRegex(log_lines[1], self.matcher)
+
+ def test_request_id_not_logged_on_info(self):
+ self.logger.info('This should be a useful message')
+ log_lines = self.stderr.getvalue().split('\n')[:-1]
+ self.assertEqual(1, len(log_lines))
+ self.assertNotRegex(log_lines[0], self.matcher)
+
class ArvadosPutTest(run_test_server.TestCaseWithServers,
ArvadosBaseTestCase,
tutil.VersionChecker):
@@ -604,7 +645,8 @@ class ArvadosPutTest(run_test_server.TestCaseWithServers,
self.main_stdout = tutil.StringIO()
self.main_stderr = tutil.StringIO()
self.loggingHandler = logging.StreamHandler(self.main_stderr)
- self.loggingHandler.setFormatter(arv_put.ArvPutLogFormatter('req-testing123'))
+ self.loggingHandler.setFormatter(
+ arv_put.ArvPutLogFormatter(arvados.util.new_request_id()))
logging.getLogger().addHandler(self.loggingHandler)
def tearDown(self):
@@ -705,18 +747,18 @@ class ArvadosPutTest(run_test_server.TestCaseWithServers,
self.assertLess(0, exc_test.exception.args[0])
self.assertLess(0, coll_save_mock.call_count)
self.assertEqual("", self.main_stdout.getvalue())
- # Mock request id is added on log formatter at setUp
- self.assertRegex(
- self.main_stderr.getvalue(), r'\(X-Request-Id: req-testing123\)\n')
-
- def test_request_id_logging(self):
- matcher = r'INFO: X-Request-Id: req-[a-z0-9]{20}\n'
-
- self.call_main_on_test_file()
- self.assertRegex(self.main_stderr.getvalue(), matcher)
- self.call_main_on_test_file(['--silent'])
- self.assertNotRegex(self.main_stderr.getvalue(), matcher)
+ def test_request_id_logging_on_error(self):
+ matcher = r'\(X-Request-Id: req-[a-z0-9]{20}\)\n'
+ coll_save_mock = mock.Mock(name='arv.collection.Collection().save_new()')
+ coll_save_mock.side_effect = arvados.errors.ApiError(
+ fake_httplib2_response(403), b'{}')
+ with mock.patch('arvados.collection.Collection.save_new',
+ new=coll_save_mock):
+ with self.assertRaises(SystemExit) as exc_test:
+ self.call_main_with_args(['/dev/null'])
+ self.assertRegex(
+ self.main_stderr.getvalue(), matcher)
class ArvPutIntegrationTest(run_test_server.TestCaseWithServers,
-----------------------------------------------------------------------
hooks/post-receive
--
More information about the arvados-commits
mailing list