12167: Test arv-get and arv-put X-Request-Id logging.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tclegg@veritasgenetics.com>

diff --git a/sdk/python/tests/test_arv_get.py b/sdk/python/tests/test_arv_get.py
index 5aa223a2eaf7fc1c444ff296641dbd5d344a228f..733cd6478c155131f9f29f4b3e7adedf6fa0508e 100644 (file)
--- a/sdk/python/tests/test_arv_get.py
+++ b/sdk/python/tests/test_arv_get.py
@@ -5,6 +5,7 @@
 from __future__ import absolute_import
 from future.utils import listitems
 import io
+import logging
 import mock
 import os
 import re
@@ -30,7 +31,14 @@ class ArvadosGetTestCase(run_test_server.TestCaseWithServers,
         self.tempdir = tempfile.mkdtemp()
         self.col_loc, self.col_pdh, self.col_manifest = self.write_test_collection()
 
+        self.stdout = tutil.BytesIO()
+        self.stderr = tutil.StringIO()
+        self.loggingHandler = logging.StreamHandler(self.stderr)
+        self.loggingHandler.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
+        logging.getLogger().addHandler(self.loggingHandler)
+
     def tearDown(self):
+        logging.getLogger().removeHandler(self.loggingHandler)
         super(ArvadosGetTestCase, self).tearDown()
         shutil.rmtree(self.tempdir)
 
@@ -52,8 +60,10 @@ class ArvadosGetTestCase(run_test_server.TestCaseWithServers,
                 c.manifest_text(strip=strip_manifest))
 
     def run_get(self, args):
-        self.stdout = tutil.BytesIO()
-        self.stderr = tutil.StringIO()
+        self.stdout.seek(0, 0)
+        self.stdout.truncate(0)
+        self.stderr.seek(0, 0)
+        self.stderr.truncate(0)
         return arv_get.main(args, self.stdout, self.stderr)
 
     def test_version_argument(self):
@@ -184,3 +194,15 @@ class ArvadosGetTestCase(run_test_server.TestCaseWithServers,
         self.assertEqual(0, r)
         self.assertEqual(b'', stdout.getvalue())
         self.assertFalse(stderr.write.called)
+
+    request_id_regex = r'INFO: X-Request-Id: req-[a-z0-9]{20}\n'
+
+    def test_request_id_logging_on(self):
+        r = self.run_get(["-v", "{}/".format(self.col_loc), self.tempdir])
+        self.assertEqual(0, r)
+        self.assertRegex(self.stderr.getvalue(), self.request_id_regex)
+
+    def test_request_id_logging_off(self):
+        r = self.run_get(["{}/".format(self.col_loc), self.tempdir])
+        self.assertEqual(0, r)
+        self.assertNotRegex(self.stderr.getvalue(), self.request_id_regex)

diff --git a/sdk/python/tests/test_arv_put.py b/sdk/python/tests/test_arv_put.py
index 346167846cd5ed185453ae85553a1676718e53d6..0c01619b4bd26798d8c74ba8bc4e584b626956de 100644 (file)
--- a/sdk/python/tests/test_arv_put.py
+++ b/sdk/python/tests/test_arv_put.py
@@ -12,6 +12,7 @@ import apiclient
 import datetime
 import hashlib
 import json
+import logging
 import mock
 import os
 import pwd
@@ -581,8 +582,10 @@ class ArvadosPutTest(run_test_server.TestCaseWithServers,
     Z_UUID = 'zzzzz-zzzzz-zzzzzzzzzzzzzzz'
 
     def call_main_with_args(self, args):
-        self.main_stdout = tutil.StringIO()
-        self.main_stderr = tutil.StringIO()
+        self.main_stdout.seek(0, 0)
+        self.main_stdout.truncate(0)
+        self.main_stderr.seek(0, 0)
+        self.main_stderr.truncate(0)
         return arv_put.main(args, self.main_stdout, self.main_stderr)
 
     def call_main_on_test_file(self, args=[]):
@@ -598,8 +601,14 @@ class ArvadosPutTest(run_test_server.TestCaseWithServers,
         super(ArvadosPutTest, self).setUp()
         run_test_server.authorize_with('active')
         arv_put.api_client = None
+        self.main_stdout = tutil.StringIO()
+        self.main_stderr = tutil.StringIO()
+        self.loggingHandler = logging.StreamHandler(self.main_stderr)
+        self.loggingHandler.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
+        logging.getLogger().addHandler(self.loggingHandler)
 
     def tearDown(self):
+        logging.getLogger().removeHandler(self.loggingHandler)
         for outbuf in ['main_stdout', 'main_stderr']:
             if hasattr(self, outbuf):
                 getattr(self, outbuf).close()
@@ -697,6 +706,15 @@ class ArvadosPutTest(run_test_server.TestCaseWithServers,
             self.assertLess(0, coll_save_mock.call_count)
             self.assertEqual("", self.main_stdout.getvalue())
 
+    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)
+
 
 class ArvPutIntegrationTest(run_test_server.TestCaseWithServers,
                             ArvadosBaseTestCase):

diff --git a/sdk/python/tests/test_events.py b/sdk/python/tests/test_events.py
index 7f6f71348e2bce794b674ccf2394aada1027343f..35614346d5c3e73465fc9aeb9f45932eb17d59cb 100644 (file)
--- a/sdk/python/tests/test_events.py
+++ b/sdk/python/tests/test_events.py
@@ -163,7 +163,7 @@ class WebsocketTest(run_test_server.TestCaseWithServers):
         """Convert minutes-east-of-UTC to RFC3339- and ISO-compatible time zone designator"""
         return '{:+03d}:{:02d}'.format(offset//60, offset%60)
 
-    # Test websocket reconnection on (un)execpted close
+    # Test websocket reconnection on (un)expected close
     def _test_websocket_reconnect(self, close_unexpected):
         run_test_server.authorize_with('active')
         events = queue.Queue(100)

diff --git a/sdk/python/tests/test_keep_client.py b/sdk/python/tests/test_keep_client.py
index d544b9261cf302d9b5ccf59da9f94bee23abc0f7..e0bb734b21fbf2671c51a4ce22dd5c954432a488 100644 (file)
--- a/sdk/python/tests/test_keep_client.py
+++ b/sdk/python/tests/test_keep_client.py
@@ -519,7 +519,7 @@ class KeepClientServiceTestCase(unittest.TestCase, tutil.ApiClientMock):
 
 
 @tutil.skip_sleep
-class KeepXRequestId(unittest.TestCase, tutil.ApiClientMock):
+class KeepXRequestIdTestCase(unittest.TestCase, tutil.ApiClientMock):
     def setUp(self):
         self.api_client = self.mock_keep_services(count=2)
         self.keep_client = arvados.KeepClient(api_client=self.api_client)