Skip to content

Commit 2feeac5

Browse files
authored
Add user agent to telemetry (#4654)
* Add user agent to telemetry * Add user agent to telemetry Update from code review * Add user agent to telemetry Fix Rubocop error
1 parent 9c23e4e commit 2feeac5

File tree

9 files changed

+257
-14
lines changed

9 files changed

+257
-14
lines changed

lib/cloud_controller/rack_app_builder.rb

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
require 'syslog/logger'
2-
require 'vcap_request_id'
2+
require 'vcap_request_context_setter'
33
require 'cors'
44
require 'request_metrics'
55
require 'request_logs'
@@ -24,7 +24,7 @@ def build(config, request_metrics, request_logs)
2424
Rack::Builder.new do
2525
use CloudFoundry::Middleware::RequestMetrics, request_metrics
2626
use CloudFoundry::Middleware::Cors, config.get(:allowed_cors_domains)
27-
use CloudFoundry::Middleware::VcapRequestId
27+
use CloudFoundry::Middleware::VcapRequestContextSetter
2828
use CloudFoundry::Middleware::BelowMinCliWarning if config.get(:warn_if_below_min_cli_version)
2929
use CloudFoundry::Middleware::NewRelicCustomAttributes if config.get(:newrelic_enabled)
3030
use CloudFoundry::Middleware::SecurityContextSetter, configurer

lib/cloud_controller/telemetry_logger.rb

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,9 @@ def emit(event_name, entries, raw_entries={})
3131
INTEGER_FIELDS.include?(k)
3232
end.transform_values(&:to_i))
3333

34+
user_agent = ::VCAP::Request.user_agent
35+
converted_entries['user-agent'] = user_agent if user_agent.present?
36+
3437
resp = {
3538
'telemetry-source' => 'cloud_controller_ng',
3639
'telemetry-time' => Time.now.to_datetime.rfc3339,

lib/vcap/request.rb

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,14 @@ def b3_span_id
5656
Thread.current[:b3_span_id]
5757
end
5858

59+
def user_agent=(user_agent)
60+
Thread.current[:user_agent] = user_agent
61+
end
62+
63+
def user_agent
64+
Thread.current[:user_agent]
65+
end
66+
5967
def db_query_metrics
6068
init_db_query_metrics
6169

middleware/vcap_request_id.rb renamed to middleware/vcap_request_context_setter.rb

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,19 +3,21 @@
33

44
module CloudFoundry
55
module Middleware
6-
class VcapRequestId
6+
class VcapRequestContextSetter
77
def initialize(app)
88
@app = app
99
end
1010

1111
def call(env)
1212
env['cf.request_id'] = external_request_id(env) || internal_request_id
1313
::VCAP::Request.current_id = env['cf.request_id']
14+
::VCAP::Request.user_agent = env['HTTP_USER_AGENT']
1415

1516
begin
1617
status, headers, body = @app.call(env)
1718
ensure
1819
::VCAP::Request.current_id = nil
20+
::VCAP::Request.user_agent = nil
1921
end
2022

2123
headers['X-VCAP-Request-ID'] = env['cf.request_id']

spec/diego/client_spec.rb

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ module Diego
1919
end
2020

2121
before do
22-
# from middleware/vcap_request_id.rb
22+
# from middleware/vcap_request_context_setter.rb
2323
::VCAP::Request.current_id = "#{request_id}::b62be6c2-0f2c-4199-94d3-41a69e00f67d"
2424
allow(Steno).to receive(:logger).with('cc.diego.client').and_return(logger)
2525
allow(logger).to receive(:info)
Lines changed: 113 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,113 @@
1+
require 'spec_helper'
2+
3+
module VCAP::CloudController
4+
RSpec.describe 'VCAP Request ID Middleware - User Agent' do
5+
let(:captured_values) { {} }
6+
7+
before do
8+
allow_any_instance_of(CloudFoundry::Middleware::VcapRequestContextSetter).to receive(:call).and_wrap_original do |original_method, *args|
9+
env = args[0]
10+
result = original_method.call(*args)
11+
captured_values[:user_agent_during_request] = env['HTTP_USER_AGENT']
12+
captured_values[:request_id_during_request] = env['cf.request_id']
13+
14+
result
15+
end
16+
end
17+
18+
describe 'user agent and request id handling' do
19+
let(:space) { VCAP::CloudController::Space.make }
20+
let(:user) { make_developer_for_space(space) }
21+
let(:request_id) { 'test-request-123' }
22+
let(:user_agent) { 'cf/8.7.0 (go1.21.4; amd64 linux)' }
23+
let(:user_headers) do
24+
headers_for(user, user_name: 'roto').merge('HTTP_USER_AGENT' => user_agent)
25+
end
26+
27+
context 'when User-Agent header is provided' do
28+
it 'sets VCAP::Request.user_agent during the request' do
29+
get '/v3/spaces', nil, user_headers
30+
expect(last_response.status).to eq(200)
31+
expect(captured_values[:user_agent_during_request]).to eq(user_agent)
32+
expect(captured_values[:request_id_during_request]).to be_present
33+
# After the request completes, user_agent should be nil
34+
expect(::VCAP::Request.user_agent).to be_nil
35+
end
36+
end
37+
38+
context 'when User-Agent header and HTTP_X_VCAP_REQUEST_ID are provided' do
39+
it 'sets VCAP::Request.user_agent and HTTP_X_VCAP_REQUEST_ID during the request' do
40+
get '/v3/spaces', nil, user_headers.merge('HTTP_X_VCAP_REQUEST_ID' => request_id)
41+
expect(last_response.status).to eq(200)
42+
expect(captured_values[:user_agent_during_request]).to eq(user_agent)
43+
expect(captured_values[:request_id_during_request]).to include(request_id)
44+
expect(last_response.headers['X-VCAP-Request-ID']).to include(request_id)
45+
# After the request completes, user_agent and current_id should be nil
46+
expect(::VCAP::Request.user_agent).to be_nil
47+
expect(::VCAP::Request.current_id).to be_nil
48+
end
49+
end
50+
end
51+
52+
context 'telemetry' do
53+
let(:space) { VCAP::CloudController::Space.make }
54+
let(:org) { space.organization }
55+
let(:user) { make_developer_for_space(space) }
56+
let(:user_agent) { 'cf/8.7.0 (go1.21.4; amd64 linux)' }
57+
let(:user_header) { headers_for(user, user_name: 'roto').merge('HTTP_USER_AGENT' => user_agent) }
58+
let(:logger_spy) { spy('logger') }
59+
let(:stack) { VCAP::CloudController::Stack.make }
60+
let(:buildpack) { VCAP::CloudController::Buildpack.make(stack: stack.name) }
61+
let(:create_request) do
62+
{
63+
name: 'my_app',
64+
lifecycle: {
65+
type: 'buildpack',
66+
data: {
67+
stack: buildpack.stack,
68+
buildpacks: [buildpack.name]
69+
}
70+
},
71+
relationships: {
72+
space: {
73+
data: {
74+
guid: space.guid
75+
}
76+
}
77+
}
78+
}
79+
end
80+
81+
before do
82+
org.add_user(user)
83+
space.add_developer(user)
84+
allow(VCAP::CloudController::TelemetryLogger).to receive(:logger).and_return(logger_spy)
85+
end
86+
87+
it 'includes user-agent in telemetry logs when making a request' do
88+
Timecop.freeze do
89+
post '/v3/apps', create_request.to_json, user_header
90+
91+
parsed_response = Oj.load(last_response.body)
92+
app_guid = parsed_response['guid']
93+
94+
expected_json = {
95+
'telemetry-source' => 'cloud_controller_ng',
96+
'telemetry-time' => Time.now.to_datetime.rfc3339,
97+
'create-app' => {
98+
'api-version' => 'v3',
99+
'app-id' => OpenSSL::Digest::SHA256.hexdigest(app_guid),
100+
'user-id' => OpenSSL::Digest::SHA256.hexdigest(user.guid),
101+
'user-agent' => user_agent
102+
}
103+
}
104+
expect(logger_spy).to have_received(:info) do |actual_json|
105+
actual = Oj.load(actual_json)
106+
expect(actual).to eq(expected_json)
107+
end
108+
expect(last_response.status).to eq(201), last_response.body
109+
end
110+
end
111+
end
112+
end
113+
end

spec/unit/lib/cloud_controller/telemetry_logger_spec.rb

Lines changed: 83 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -127,5 +127,88 @@ class DisabledTelemetryLogger < TelemetryLogger; end
127127
})
128128
end
129129
end
130+
131+
describe 'user-agent tracking' do
132+
context 'when user-agent is set' do
133+
before do
134+
::VCAP::Request.user_agent = 'cf/8.7.0 (go1.21.4; amd64 linux)'
135+
end
136+
137+
after do
138+
::VCAP::Request.user_agent = nil
139+
end
140+
141+
it 'includes user-agent in v3 telemetry events' do
142+
TelemetryLogger.v3_emit(
143+
'some-event',
144+
{ 'key' => 'value' }
145+
)
146+
147+
expect(Oj.load(file.read)).to match({
148+
'telemetry-source' => 'cloud_controller_ng',
149+
'telemetry-time' => rfc3339,
150+
'some-event' => {
151+
'key' => OpenSSL::Digest.hexdigest('SHA256', 'value'),
152+
'api-version' => 'v3',
153+
'user-agent' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
154+
}
155+
})
156+
end
157+
158+
it 'includes user-agent in v2 telemetry events' do
159+
TelemetryLogger.v2_emit(
160+
'some-event',
161+
{ 'key' => 'value' }
162+
)
163+
164+
expect(Oj.load(file.read)).to match({
165+
'telemetry-source' => 'cloud_controller_ng',
166+
'telemetry-time' => rfc3339,
167+
'some-event' => {
168+
'key' => OpenSSL::Digest.hexdigest('SHA256', 'value'),
169+
'api-version' => 'v2',
170+
'user-agent' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
171+
}
172+
})
173+
end
174+
175+
it 'includes user-agent in internal telemetry events' do
176+
TelemetryLogger.internal_emit(
177+
'some-event',
178+
{ 'key' => 'value' }
179+
)
180+
181+
expect(Oj.load(file.read)).to match({
182+
'telemetry-source' => 'cloud_controller_ng',
183+
'telemetry-time' => rfc3339,
184+
'some-event' => {
185+
'key' => OpenSSL::Digest.hexdigest('SHA256', 'value'),
186+
'api-version' => 'internal',
187+
'user-agent' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
188+
}
189+
})
190+
end
191+
192+
it 'includes user-agent with other raw entries' do
193+
TelemetryLogger.v3_emit(
194+
'some-event',
195+
{ 'anonymize_key' => 'anonymize_value' },
196+
{ 'safe_key' => 'safe-value', 'memory-in-mb' => '2048' }
197+
)
198+
199+
expect(Oj.load(file.read)).to match({
200+
'telemetry-source' => 'cloud_controller_ng',
201+
'telemetry-time' => rfc3339,
202+
'some-event' => {
203+
'anonymize_key' => OpenSSL::Digest.hexdigest('SHA256', 'anonymize_value'),
204+
'safe_key' => 'safe-value',
205+
'memory-in-mb' => 2048,
206+
'api-version' => 'v3',
207+
'user-agent' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
208+
}
209+
})
210+
end
211+
end
212+
end
130213
end
131214
end

spec/unit/lib/vcap/request_spec.rb

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -131,5 +131,25 @@ module VCAP
131131
expect(Steno.config.context.data.key?('user_guid')).to be false
132132
end
133133
end
134+
135+
describe '.user_agent' do
136+
after do
137+
Request.user_agent = nil
138+
end
139+
140+
let(:user_agent) { 'cf/99.0.0-dev-961e7e2+build1070100 (go1.25.2; arm64 darwin)' }
141+
142+
it 'sets the new user_agent' do
143+
Request.user_agent = user_agent
144+
145+
expect(Request.user_agent).to eq user_agent
146+
end
147+
148+
it 'uses the :user_agent thread local' do
149+
Request.user_agent = user_agent
150+
151+
expect(Thread.current[:user_agent]).to eq(user_agent)
152+
end
153+
end
134154
end
135155
end

spec/unit/middleware/vcap_request_id_spec.rb renamed to spec/unit/middleware/vcap_request_context_setter_spec.rb

Lines changed: 24 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1,19 +1,20 @@
11
require 'spec_helper'
2-
require 'vcap_request_id'
2+
require 'vcap_request_context_setter'
33

44
module CloudFoundry
55
module Middleware
6-
RSpec.describe VcapRequestId do
7-
let(:middleware) { VcapRequestId.new(app) }
8-
let(:app) { VcapRequestId::FakeApp.new }
6+
RSpec.describe VcapRequestContextSetter do
7+
let(:middleware) { VcapRequestContextSetter.new(app) }
8+
let(:app) { VcapRequestContextSetter::FakeApp.new }
99
let(:app_response) { [200, {}, 'a body'] }
1010
let(:uuid_regex) { '\w+-\w+-\w+-\w+-\w+' }
1111

12-
class VcapRequestId::FakeApp
13-
attr_accessor :last_request_id, :last_env_input
12+
class VcapRequestContextSetter::FakeApp
13+
attr_accessor :last_request_id, :last_env_input, :last_user_agent
1414

1515
def call(env)
1616
@last_request_id = ::VCAP::Request.current_id
17+
@last_user_agent = ::VCAP::Request.user_agent
1718
@last_env_input = env
1819
[200, {}, 'a body']
1920
end
@@ -22,13 +23,21 @@ def call(env)
2223
describe 'handling the request' do
2324
context 'setting the request_id in the logger' do
2425
it 'has assigned it before passing the request' do
25-
middleware.call('HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id')
26+
middleware.call(
27+
'HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id',
28+
'HTTP_USER_AGENT' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
29+
)
2630
expect(app.last_request_id).to match(/^specific-request-id::#{uuid_regex}$/)
31+
expect(app.last_user_agent).to eq('cf/8.7.0 (go1.21.4; amd64 linux)')
2732
end
2833

2934
it 'nils it out after the request has been processed' do
30-
middleware.call('HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id')
35+
middleware.call(
36+
'HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id',
37+
'HTTP_USER_AGENT' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
38+
)
3139
expect(::VCAP::Request.current_id).to be_nil
40+
expect(::VCAP::Request.user_agent).to be_nil
3241
end
3342
end
3443

@@ -41,15 +50,20 @@ def call(env)
4150
end
4251

4352
it 'sets the request id to nil' do
44-
expect { middleware.call('HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id') }.to raise_error(error)
53+
expect { middleware.call('HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id', 'HTTP_USER_AGENT' => 'cf/8.7.0 (go1.21.4; amd64 linux)') }.to raise_error(error)
4554
expect(::VCAP::Request.current_id).to be_nil
55+
expect(::VCAP::Request.user_agent).to be_nil
4656
end
4757
end
4858

4959
context 'and no error is raised when the request is passed' do
5060
it 'sets the request id to nil' do
51-
middleware.call('HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id')
61+
middleware.call(
62+
'HTTP_X_VCAP_REQUEST_ID' => 'specific-request-id',
63+
'HTTP_USER_AGENT' => 'cf/8.7.0 (go1.21.4; amd64 linux)'
64+
)
5265
expect(::VCAP::Request.current_id).to be_nil
66+
expect(::VCAP::Request.user_agent).to be_nil
5367
end
5468
end
5569
end

0 commit comments

Comments
 (0)