[ARVADOS] created: 1.1.3-136-g96f6572

[Git user]

        at  96f657210ce401a84eafc4a575f56694f2b39a0b (commit)


commit 96f657210ce401a84eafc4a575f56694f2b39a0b
Author: Lucas Di Pentima <ldipentima at veritasgenetics.com>
Date:   Tue Mar 6 17:29:14 2018 -0300

    13147: Append X-Request-Id on error & debug log messages.
    
    Set up a custom formatter that replaces the standard arvados one
    when running arv-put, so that it appends the Req-Id on errors.
    Replacing 'arvados' log formatter makes all loggers below it (arv_put and
    api in this case) use the same format.
    
    Arvados-DCO-1.1-Signed-off-by: Lucas Di Pentima <ldipentima at veritasgenetics.com>

diff --git a/sdk/python/arvados/__init__.py b/sdk/python/arvados/__init__.py
index 06a4f07..bb97f3c 100644
--- a/sdk/python/arvados/__init__.py
+++ b/sdk/python/arvados/__init__.py
@@ -41,10 +41,10 @@ import arvados.util as util
 
 # Set up Arvados logging based on the user's configuration.
 # All Arvados code should log under the arvados hierarchy.
+log_format = '%(asctime)s %(name)s[%(process)d] %(levelname)s: %(message)s'
+log_date_format = '%Y-%m-%d %H:%M:%S'
 log_handler = logging.StreamHandler()
-log_handler.setFormatter(logging.Formatter(
-        '%(asctime)s %(name)s[%(process)d] %(levelname)s: %(message)s',
-        '%Y-%m-%d %H:%M:%S'))
+log_handler.setFormatter(logging.Formatter(log_format, log_date_format))
 logger = logging.getLogger('arvados')
 logger.addHandler(log_handler)
 logger.setLevel(logging.DEBUG if config.get('ARVADOS_DEBUG')
diff --git a/sdk/python/arvados/commands/put.py b/sdk/python/arvados/commands/put.py
index 2032da0..0f8dc5f 100644
--- a/sdk/python/arvados/commands/put.py
+++ b/sdk/python/arvados/commands/put.py
@@ -309,6 +309,22 @@ class FileUploadList(list):
         super(FileUploadList, self).append(other)
 
 
+# Appends the X-Request-Id to the log message when log level is ERROR or DEBUG
+class ArvPutLogFormatter(logging.Formatter):
+    std_fmtr = logging.Formatter(arvados.log_format, arvados.log_date_format)
+    err_fmtr = None
+
+    def __init__(self, request_id):
+        self.err_fmtr = logging.Formatter(
+            arvados.log_format+' (X-Request-Id: {})'.format(request_id),
+            arvados.log_date_format)
+
+    def format(self, record):
+        if record.levelno in (logging.DEBUG, logging.ERROR):
+            return self.err_fmtr.format(record)
+        return self.std_fmtr.format(record)
+
+
 class ResumeCache(object):
     CACHE_DIR = '.cache/arvados/arv-put'
 
@@ -988,6 +1004,9 @@ def main(arguments=None, stdout=sys.stdout, stderr=sys.stderr):
     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)
+
     if api_client is None:
         api_client = arvados.api('v1', request_id=request_id)
 
diff --git a/sdk/python/tests/test_arv_put.py b/sdk/python/tests/test_arv_put.py
index 0c01619..a376aeb 100644
--- a/sdk/python/tests/test_arv_put.py
+++ b/sdk/python/tests/test_arv_put.py
@@ -604,7 +604,7 @@ 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(logging.Formatter('%(levelname)s: %(message)s'))
+        self.loggingHandler.setFormatter(arv_put.ArvPutLogFormatter('req-testing123'))
         logging.getLogger().addHandler(self.loggingHandler)
 
     def tearDown(self):
@@ -705,6 +705,9 @@ 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'

commit 8682bb87e37e3ef9831dc83167a6620594fc8b52
Author: Lucas Di Pentima <ldipentima at veritasgenetics.com>
Date:   Mon Mar 5 18:39:04 2018 -0300

    13147: Logger call fix.
    
    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 97ff8c6..2032da0 100644
--- a/sdk/python/arvados/commands/put.py
+++ b/sdk/python/arvados/commands/put.py
@@ -887,7 +887,7 @@ class ArvPutUploadJob(object):
         m = self._my_collection().stripped_manifest().encode()
         local_pdh = '{}+{}'.format(hashlib.md5(m).hexdigest(), len(m))
         if pdh != local_pdh:
-            logger.warning("\n".join([
+            self.logger.warning("\n".join([
                 "arv-put: API server provided PDH differs from local manifest.",
                 "         This should not happen; showing API server version."]))
         return pdh

-----------------------------------------------------------------------


hooks/post-receive
--