Story #13147

[arv-put] Add request ID to requests for tracability

Added by Tom Morris over 1 year ago. Updated about 1 year ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Category:
-
Target version:
Start date:
03/06/2018
Due date:
% Done:

100%

Estimated time:
(Total: 0.00 h)
Story points:
1.0
Release relationship:
Auto

Description

Enhancing the Python SDK as needed to support the feature


Subtasks

Task #13156: Review 13147-arvput-request-idResolvedPeter Amstutz


Related issues

Related to Arvados - Feature #12167: [SDKs] [API] [keepstore] [keepproxy] Facilitate request tracing for all servicesResolved08/24/2017

Associated revisions

Revision 98c6c699
Added by Lucas Di Pentima over 1 year ago

Merge branch '13147-arvput-request-id'
Closes #13147

Arvados-DCO-1.1-Signed-off-by: Lucas Di Pentima <>

History

#1 Updated by Tom Morris over 1 year ago

  • Related to Feature #12167: [SDKs] [API] [keepstore] [keepproxy] Facilitate request tracing for all services added

#2 Updated by Lucas Di Pentima over 1 year ago

  • Status changed from New to In Progress

#3 Updated by Lucas Di Pentima over 1 year ago

Updates at 96f657210 - branch 13147-arvput-request-id
Test run: https://ci.curoverse.com/job/developer-run-tests/632/

Created a custom log formatter that appends the request-id on error messages. This formatter is used to replace the arvados formatter when running arv-put.

#4 Updated by Peter Amstutz over 1 year ago

Wouldn't the X-Request-Id check always pass, because it always prints out the request id at the beginning? Maybe the test run should include "--silent"?

    def test_api_error_handling(self):
        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(['--silent', '/dev/null'])
            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')

On further inspection, I guess that's not strictly true, because the regex is testing for "(X-Request-Id: req-testing123)" with the parenthesis as part of the match, which only shows up as part of an error message.

Another thought, if this adds the same request_id to every log message at ERROR or DEBUG level, that seems redundant. Maybe just add it once the first time?

Separately, I wonder if always logging X-Request-Id at INFO level at the beginning is desirable, even when the transfer was a success, but maybe that's a separate question (I don't want to get into it if it is going to be contraversial.)

#5 Updated by Lucas Di Pentima over 1 year ago

Updates at 19ee2e029
Test run: https://ci.curoverse.com/job/developer-run-tests/635/ (waiting for workers atm)

Don't show X-Request-Id message on command startup.
Only show the request id once when logging error or debug messages.
Related tests added.

#6 Updated by Peter Amstutz over 1 year ago

Lucas Di Pentima wrote:

Updates at 19ee2e029
Test run: https://ci.curoverse.com/job/developer-run-tests/635/ (waiting for workers atm)

Don't show X-Request-Id message on command startup.
Only show the request id once when logging error or debug messages.
Related tests added.

LGTM, please merge.

#7 Updated by Lucas Di Pentima over 1 year ago

  • Status changed from In Progress to Resolved

#8 Updated by Tom Morris about 1 year ago

  • Release set to 17

Also available in: Atom PDF