[ARVADOS] created: 1.1.0-39-g0e12d04
Git user
git at public.curoverse.com
Tue Oct 31 16:38:57 EDT 2017
at 0e12d049716003b08c4fc881343ebf14c3522b99 (commit)
commit 0e12d049716003b08c4fc881343ebf14c3522b99
Author: Tom Clegg <tclegg at veritasgenetics.com>
Date: Mon Oct 30 23:07:52 2017 -0400
12167: Improve request-id tracking in Workbench.
Include current request ID in API requests via X-Request-Id header
instead of a form parameter. (Also move Arvados API token from form
to Authorization request header.)
Always log request ID as its own field, instead of adding it to params
(where it might get truncated before being logged).
Use new request ID format: "req-" + 20-random-alphanum-chars.
Use an around_filter to set/clear the current request ID in one place,
instead of setting it in controller code and clearing it in logging
code.
Return request ID to browser via X-Request-Id header.
Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tclegg at veritasgenetics.com>
diff --git a/apps/workbench/Gemfile.lock b/apps/workbench/Gemfile.lock
index 34db9cd..8ffc1d3 100644
--- a/apps/workbench/Gemfile.lock
+++ b/apps/workbench/Gemfile.lock
@@ -58,7 +58,7 @@ GEM
railties (>= 3.1)
bootstrap-x-editable-rails (1.5.1.1)
railties (>= 3.0)
- builder (3.2.2)
+ builder (3.2.3)
byebug (3.5.1)
columnize (~> 0.8)
debugger-linecache (~> 1.2)
@@ -87,6 +87,7 @@ GEM
coffee-script-source (1.8.0)
columnize (0.9.0)
commonjs (0.2.7)
+ concurrent-ruby (1.0.5)
daemon_controller (1.2.0)
debugger-linecache (1.2.0)
deep_merge (1.0.1)
@@ -124,11 +125,12 @@ GEM
headless (1.0.2)
highline (1.6.21)
httpclient (2.8.2.4)
- i18n (0.7.0)
+ i18n (0.9.0)
+ concurrent-ruby (~> 1.0)
jquery-rails (3.1.2)
railties (>= 3.0, < 5.0)
thor (>= 0.14, < 2.0)
- json (1.8.3)
+ json (1.8.6)
jwt (1.5.4)
launchy (2.4.3)
addressable (~> 2.3)
@@ -142,10 +144,11 @@ GEM
logging (2.1.0)
little-plugger (~> 1.1)
multi_json (~> 1.10)
- lograge (0.3.6)
- actionpack (>= 3)
- activesupport (>= 3)
- railties (>= 3)
+ lograge (0.7.1)
+ actionpack (>= 4, < 5.2)
+ activesupport (>= 4, < 5.2)
+ railties (>= 4, < 5.2)
+ request_store (~> 1.0)
logstash-event (1.2.02)
mail (2.6.3)
mime-types (>= 1.16, < 3)
@@ -153,7 +156,7 @@ GEM
metaclass (0.0.4)
mime-types (2.99)
mini_portile (0.6.2)
- minitest (5.8.4)
+ minitest (5.10.3)
mocha (1.1.0)
metaclass (~> 0.0.1)
morrisjs-rails (0.5.1)
@@ -207,11 +210,12 @@ GEM
activesupport (= 4.1.12)
rake (>= 0.8.7)
thor (>= 0.18.1, < 2.0)
- rake (10.4.2)
+ rake (12.2.1)
rake-compiler (0.9.5)
rake
raphael-rails (2.1.2)
ref (1.0.5)
+ request_store (1.3.2)
retriable (1.4.1)
ruby-debug-passenger (0.2.0)
ruby-prof (0.15.2)
@@ -254,10 +258,10 @@ GEM
therubyracer (0.12.1)
libv8 (~> 3.16.14.0)
ref
- thor (0.19.1)
- thread_safe (0.3.5)
+ thor (0.20.0)
+ thread_safe (0.3.6)
tilt (1.4.1)
- tzinfo (1.2.2)
+ tzinfo (1.2.4)
thread_safe (~> 0.1)
uglifier (2.7.2)
execjs (>= 0.3.0)
@@ -323,4 +327,4 @@ DEPENDENCIES
wiselinks
BUNDLED WITH
- 1.15.1
+ 1.16.0
diff --git a/apps/workbench/app/controllers/application_controller.rb b/apps/workbench/app/controllers/application_controller.rb
index 5acf9a7..8d9e857 100644
--- a/apps/workbench/app/controllers/application_controller.rb
+++ b/apps/workbench/app/controllers/application_controller.rb
@@ -11,8 +11,8 @@ class ApplicationController < ActionController::Base
ERROR_ACTIONS = [:render_error, :render_not_found]
- prepend_before_filter :set_current_request_id, except: ERROR_ACTIONS
around_filter :thread_clear
+ around_filter :set_current_request_id
around_filter :set_thread_api_token
# Methods that don't require login should
# skip_around_filter :require_thread_api_token
@@ -573,6 +573,19 @@ class ApplicationController < ActionController::Base
Rails.cache.delete_matched(/^request_#{Thread.current.object_id}_/)
end
+ def set_current_request_id
+ response.headers['X-Request-Id'] =
+ Thread.current[:request_id] =
+ "req-" + Random::DEFAULT.rand(2**128).to_s(36)[0..19]
+ yield
+ Thread.current[:request_id] = nil
+ end
+
+ def append_info_to_payload(payload)
+ super
+ payload[:request_id] = response.headers['X-Request-Id']
+ end
+
# Set up the thread with the given API token and associated user object.
def load_api_token(new_token)
Thread.current[:arvados_api_token] = new_token
@@ -1307,10 +1320,4 @@ class ApplicationController < ActionController::Base
def wiselinks_layout
'body'
end
-
- def set_current_request_id
- # Request ID format: '<timestamp>-<9_digits_random_number>'
- current_request_id = "#{Time.new.to_i}-#{sprintf('%09d', rand(0..10**9-1))}"
- Thread.current[:current_request_id] = current_request_id
- end
end
diff --git a/apps/workbench/app/models/arvados_api_client.rb b/apps/workbench/app/models/arvados_api_client.rb
index 8638b0a..ac2fe3a 100644
--- a/apps/workbench/app/models/arvados_api_client.rb
+++ b/apps/workbench/app/models/arvados_api_client.rb
@@ -114,14 +114,10 @@ class ArvadosApiClient
url.sub! '/arvados/v1/../../', '/'
query = {
- 'api_token' => (tokens[:arvados_api_token] ||
- Thread.current[:arvados_api_token] ||
- ''),
'reader_tokens' => ((tokens[:reader_tokens] ||
Thread.current[:reader_tokens] ||
[]) +
[Rails.configuration.anonymous_user_token]).to_json,
- 'current_request_id' => (Thread.current[:current_request_id] || ''),
}
if !data.nil?
data.each do |k,v|
@@ -143,12 +139,19 @@ class ArvadosApiClient
query["_profile"] = "true"
end
- header = {"Accept" => "application/json"}
+ headers = {
+ "Accept" => "application/json",
+ "Authorization" => "OAuth2 " +
+ (tokens[:arvados_api_token] ||
+ Thread.current[:arvados_api_token] ||
+ ''),
+ "X-Request-Id" => Thread.current[:request_id] || '',
+ }
profile_checkpoint { "Prepare request #{query["_method"] or "POST"} #{url} #{query[:uuid]} #{query.inspect[0,256]}" }
msg = @client_mtx.synchronize do
begin
- @api_client.post(url, query, header: header)
+ @api_client.post(url, query, headers)
rescue => exception
raise NoApiResponseException.new(url, exception)
end
diff --git a/apps/workbench/config/initializers/lograge.rb b/apps/workbench/config/initializers/lograge.rb
index 321bd03..6e7f165 100644
--- a/apps/workbench/config/initializers/lograge.rb
+++ b/apps/workbench/config/initializers/lograge.rb
@@ -6,15 +6,20 @@ ArvadosWorkbench::Application.configure do
config.lograge.enabled = true
config.lograge.formatter = Lograge::Formatters::Logstash.new
config.lograge.custom_options = lambda do |event|
+ payload = {
+ request_id: event.payload[:request_id],
+ }
+ # Also log params (minus the pseudo-params added by Rails). But if
+ # params is huge, don't log the whole thing, just hope we get the
+ # most useful bits in truncate(json(params)).
exceptions = %w(controller action format id)
- params = {current_request_id: Thread.current[:current_request_id]}.
- merge(event.payload[:params].except(*exceptions))
+ params = event.payload[:params].except(*exceptions)
params_s = Oj.dump(params)
- Thread.current[:current_request_id] = nil # Clear for next request
if params_s.length > 1000
- { params_truncated: params_s[0..1000] + "[...]" }
+ payload[:params_truncated] = params_s[0..1000] + "[...]"
else
- { params: params }
+ payload[:params] = params
end
+ payload
end
end
diff --git a/apps/workbench/test/controllers/application_controller_test.rb b/apps/workbench/test/controllers/application_controller_test.rb
index d38e88f..0bcf7a1 100644
--- a/apps/workbench/test/controllers/application_controller_test.rb
+++ b/apps/workbench/test/controllers/application_controller_test.rb
@@ -338,11 +338,11 @@ class ApplicationControllerTest < ActionController::TestCase
assert_response 404
end
- test "requesting to the API server includes client_session_id param" do
- got_query = nil
+ test "requesting to the API server includes X-Request-Id header" do
+ got_header = nil
stub_api_calls
- stub_api_client.stubs(:post).with do |url, query, opts={}|
- got_query = query
+ stub_api_client.stubs(:post).with do |url, query, header={}|
+ got_header = header
true
end.returns fake_api_response('{}', 200, {})
@@ -352,14 +352,21 @@ class ApplicationControllerTest < ActionController::TestCase
test_uuid = "zzzzz-j7d0g-zzzzzzzzzzzzzzz"
get(:show, {id: test_uuid})
- assert_includes got_query, 'current_request_id'
- assert_match /\d{10}-\d{9}/, got_query['current_request_id']
+ assert_not_nil got_header
+ assert_includes got_header, 'X-Request-Id'
+ assert_match /^req-[0-9a-zA-Z]{20}$/, got_header["X-Request-Id"]
end
- test "current_request_id is nil after a request" do
+ test "current request_id is nil after a request" do
@controller = NodesController.new
get(:index, {}, session_for(:active))
- assert_nil Thread.current[:current_request_id]
+ assert_nil Thread.current[:request_id]
+ end
+
+ test "X-Request-Id header" do
+ @controller = NodesController.new
+ get(:index, {}, session_for(:active))
+ assert_match /^req-[0-9a-zA-Z]{20}$/, response.headers['X-Request-Id']
end
[".navbar .login-menu a",
-----------------------------------------------------------------------
hooks/post-receive
--
More information about the arvados-commits
mailing list