|
3 | 3 | require "spec_helper" |
4 | 4 |
|
5 | 5 | RSpec.describe Sentry::Rails::LogSubscribers::ActionControllerSubscriber, type: :request do |
6 | | - before do |
7 | | - make_basic_app do |config, app| |
8 | | - config.enable_logs = true |
9 | | - config.rails.structured_logging.enabled = true |
10 | | - config.rails.structured_logging.subscribers = { action_controller: Sentry::Rails::LogSubscribers::ActionControllerSubscriber } |
11 | | - end |
12 | | - end |
13 | | - |
14 | | - describe "integration with ActiveSupport::Notifications" do |
15 | | - it "logs controller action events when requests are processed" do |
16 | | - get "/world" |
17 | | - |
18 | | - Sentry.get_current_client.flush |
19 | | - |
20 | | - expect(sentry_logs).not_to be_empty |
21 | | - |
22 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
23 | | - expect(log_event).not_to be_nil |
24 | | - expect(log_event[:level]).to eq("info") |
25 | | - expect(log_event[:attributes][:controller][:value]).to eq("HelloController") |
26 | | - expect(log_event[:attributes][:action][:value]).to eq("world") |
27 | | - expect(log_event[:attributes][:status][:value]).to eq(200) |
28 | | - |
29 | | - duration = log_event[:attributes][:duration_ms][:value] |
30 | | - expect(duration).to be_a(Float) |
31 | | - expect(duration).to be_in(0.01..30.0) |
32 | | - |
33 | | - expect(log_event[:attributes][:method][:value]).to eq("GET") |
34 | | - expect(log_event[:attributes][:path][:value]).to eq("/world") |
35 | | - expect(log_event[:attributes][:format][:value]).to eq(:html) |
36 | | - end |
37 | | - |
38 | | - it "logs bad requests appropriately" do |
39 | | - get "/not_found" |
40 | | - |
41 | | - Sentry.get_current_client.flush |
42 | | - |
43 | | - expect(sentry_logs).not_to be_empty |
| 6 | + context "when logging is enabled" do |
| 7 | + before do |
| 8 | + make_basic_app do |config, app| |
| 9 | + config.enable_logs = true |
44 | 10 |
|
45 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#not_found" } |
46 | | - expect(log_event).not_to be_nil |
47 | | - expect(log_event[:level].to_sym).to be(:warn) |
48 | | - expect(log_event[:attributes][:status][:value]).to eq(400) |
| 11 | + config.rails.structured_logging.enabled = true |
| 12 | + config.rails.structured_logging.subscribers = { action_controller: Sentry::Rails::LogSubscribers::ActionControllerSubscriber } |
| 13 | + end |
49 | 14 | end |
50 | 15 |
|
51 | | - it "logs error status codes with error level" do |
52 | | - get "/exception" |
| 16 | + describe "integration with ActiveSupport::Notifications" do |
| 17 | + it "logs controller action events when requests are processed" do |
| 18 | + get "/world" |
53 | 19 |
|
54 | | - Sentry.get_current_client.flush |
55 | | - |
56 | | - expect(sentry_logs).not_to be_empty |
57 | | - |
58 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#exception" } |
59 | | - expect(log_event).not_to be_nil |
60 | | - expect(log_event[:level]).to eq("error") |
61 | | - expect(log_event[:attributes][:status][:value]).to eq(500) |
62 | | - end |
63 | | - |
64 | | - it "includes view runtime when available" do |
65 | | - get "/view" |
| 20 | + Sentry.get_current_client.flush |
66 | 21 |
|
67 | | - Sentry.get_current_client.flush |
| 22 | + expect(sentry_logs).not_to be_empty |
68 | 23 |
|
69 | | - expect(sentry_logs).not_to be_empty |
| 24 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 25 | + expect(log_event).not_to be_nil |
| 26 | + expect(log_event[:level]).to eq("info") |
| 27 | + expect(log_event[:attributes][:controller][:value]).to eq("HelloController") |
| 28 | + expect(log_event[:attributes][:action][:value]).to eq("world") |
| 29 | + expect(log_event[:attributes][:status][:value]).to eq(200) |
| 30 | + |
| 31 | + duration = log_event[:attributes][:duration_ms][:value] |
| 32 | + expect(duration).to be_a(Float) |
| 33 | + expect(duration).to be_in(0.01..30.0) |
| 34 | + |
| 35 | + expect(log_event[:attributes][:method][:value]).to eq("GET") |
| 36 | + expect(log_event[:attributes][:path][:value]).to eq("/world") |
| 37 | + expect(log_event[:attributes][:format][:value]).to eq(:html) |
| 38 | + end |
70 | 39 |
|
71 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#view" } |
72 | | - expect(log_event).not_to be_nil |
73 | | - expect(log_event[:attributes][:view_runtime_ms]).to be_present |
74 | | - expect(log_event[:attributes][:view_runtime_ms][:value]).to be >= 0 |
75 | | - end |
| 40 | + it "logs bad requests appropriately" do |
| 41 | + get "/not_found" |
76 | 42 |
|
77 | | - it "includes database runtime when available" do |
78 | | - Post.create! |
79 | | - get "/posts" |
| 43 | + Sentry.get_current_client.flush |
80 | 44 |
|
81 | | - Sentry.get_current_client.flush |
| 45 | + expect(sentry_logs).not_to be_empty |
82 | 46 |
|
83 | | - expect(sentry_logs).not_to be_empty |
| 47 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#not_found" } |
| 48 | + expect(log_event).not_to be_nil |
| 49 | + expect(log_event[:level].to_sym).to be(:warn) |
| 50 | + expect(log_event[:attributes][:status][:value]).to eq(400) |
| 51 | + end |
84 | 52 |
|
85 | | - log_event = sentry_logs.find { |log| log[:body] == "PostsController#index" } |
86 | | - expect(log_event).not_to be_nil |
| 53 | + it "logs error status codes with error level" do |
| 54 | + get "/exception" |
87 | 55 |
|
88 | | - if Rails.version.to_f >= 6.0 |
89 | | - expect(log_event[:attributes][:db_runtime_ms]).to be_present |
90 | | - expect(log_event[:attributes][:db_runtime_ms][:value]).to be >= 0 |
91 | | - else |
92 | | - if log_event[:attributes][:db_runtime_ms] |
93 | | - expect(log_event[:attributes][:db_runtime_ms][:value]).to be >= 0 |
94 | | - end |
95 | | - end |
96 | | - end |
| 56 | + Sentry.get_current_client.flush |
97 | 57 |
|
98 | | - context "when send_default_pii is enabled" do |
99 | | - before do |
100 | | - Sentry.configuration.send_default_pii = true |
101 | | - end |
| 58 | + expect(sentry_logs).not_to be_empty |
102 | 59 |
|
103 | | - after do |
104 | | - Sentry.configuration.send_default_pii = false |
| 60 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#exception" } |
| 61 | + expect(log_event).not_to be_nil |
| 62 | + expect(log_event[:level]).to eq("error") |
| 63 | + expect(log_event[:attributes][:status][:value]).to eq(500) |
105 | 64 | end |
106 | 65 |
|
107 | | - it "includes filtered request parameters" do |
108 | | - get "/world", params: { safe_param: "value", password: "secret" } |
| 66 | + it "includes view runtime when available" do |
| 67 | + get "/view" |
109 | 68 |
|
110 | 69 | Sentry.get_current_client.flush |
111 | 70 |
|
112 | 71 | expect(sentry_logs).not_to be_empty |
113 | 72 |
|
114 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 73 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#view" } |
115 | 74 | expect(log_event).not_to be_nil |
116 | | - expect(log_event[:attributes][:params]).to be_present |
117 | | - expect(log_event[:attributes][:params][:value]).to include("safe_param" => "value") |
118 | | - expect(log_event[:attributes][:params][:value]).to include("password" => "[FILTERED]") |
| 75 | + expect(log_event[:attributes][:view_runtime_ms]).to be_present |
| 76 | + expect(log_event[:attributes][:view_runtime_ms][:value]).to be >= 0 |
119 | 77 | end |
120 | 78 |
|
121 | | - it "filters sensitive parameter names" do |
122 | | - get "/world", params: { |
123 | | - normal_param: "value", |
124 | | - password: "secret", |
125 | | - api_key: "key123", |
126 | | - credit_card: "1234567890", |
127 | | - authorization: "Bearer token" |
128 | | - } |
| 79 | + it "includes database runtime when available" do |
| 80 | + Post.create! |
| 81 | + get "/posts" |
129 | 82 |
|
130 | 83 | Sentry.get_current_client.flush |
131 | 84 |
|
132 | 85 | expect(sentry_logs).not_to be_empty |
133 | 86 |
|
134 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 87 | + log_event = sentry_logs.find { |log| log[:body] == "PostsController#index" } |
135 | 88 | expect(log_event).not_to be_nil |
136 | 89 |
|
137 | | - params = log_event[:attributes][:params][:value] |
138 | | - expect(params).to include("normal_param" => "value") |
139 | | - expect(params).to include("password" => "[FILTERED]") |
140 | | - expect(params).to include("api_key" => "[FILTERED]") |
141 | | - expect(params).to include("credit_card" => "[FILTERED]") |
142 | | - expect(params).to include("authorization" => "[FILTERED]") |
| 90 | + if Rails.version.to_f >= 6.0 |
| 91 | + expect(log_event[:attributes][:db_runtime_ms]).to be_present |
| 92 | + expect(log_event[:attributes][:db_runtime_ms][:value]).to be >= 0 |
| 93 | + else |
| 94 | + if log_event[:attributes][:db_runtime_ms] |
| 95 | + expect(log_event[:attributes][:db_runtime_ms][:value]).to be >= 0 |
| 96 | + end |
| 97 | + end |
143 | 98 | end |
144 | 99 |
|
145 | | - it "respects Rails filter_parameters configuration" do |
146 | | - original_filter_params = Rails.application.config.filter_parameters.dup |
147 | | - Rails.application.config.filter_parameters += [:custom_secret] |
| 100 | + context "when send_default_pii is enabled" do |
| 101 | + before do |
| 102 | + Sentry.configuration.send_default_pii = true |
| 103 | + end |
148 | 104 |
|
149 | | - get "/world", params: { |
150 | | - normal_param: "value", |
151 | | - custom_secret: "should_be_filtered", |
152 | | - another_param: "visible" |
153 | | - } |
| 105 | + after do |
| 106 | + Sentry.configuration.send_default_pii = false |
| 107 | + end |
154 | 108 |
|
155 | | - Sentry.get_current_client.flush |
| 109 | + it "includes filtered request parameters" do |
| 110 | + get "/world", params: { safe_param: "value", password: "secret" } |
156 | 111 |
|
157 | | - expect(sentry_logs).not_to be_empty |
| 112 | + Sentry.get_current_client.flush |
158 | 113 |
|
159 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
160 | | - expect(log_event).not_to be_nil |
| 114 | + expect(sentry_logs).not_to be_empty |
161 | 115 |
|
162 | | - params = log_event[:attributes][:params][:value] |
163 | | - expect(params).to include("normal_param" => "value") |
164 | | - expect(params).to include("another_param" => "visible") |
165 | | - expect(params).to include("custom_secret" => "[FILTERED]") |
| 116 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 117 | + expect(log_event).not_to be_nil |
| 118 | + expect(log_event[:attributes][:params]).to be_present |
| 119 | + expect(log_event[:attributes][:params][:value]).to include("safe_param" => "value") |
| 120 | + expect(log_event[:attributes][:params][:value]).to include("password" => "[FILTERED]") |
| 121 | + end |
166 | 122 |
|
167 | | - Rails.application.config.filter_parameters = original_filter_params |
168 | | - end |
| 123 | + it "filters sensitive parameter names" do |
| 124 | + get "/world", params: { |
| 125 | + normal_param: "value", |
| 126 | + password: "secret", |
| 127 | + api_key: "key123", |
| 128 | + credit_card: "1234567890", |
| 129 | + authorization: "Bearer token" |
| 130 | + } |
169 | 131 |
|
170 | | - it "handles nested parameters correctly" do |
171 | | - get "/world", params: { |
172 | | - user: { |
173 | | - name: "John", |
174 | | - password: "secret123", |
175 | | - profile: { |
176 | | - api_key: "key456", |
177 | | - public_info: "visible" |
178 | | - } |
179 | | - }, |
180 | | - normal_param: "value" |
181 | | - } |
| 132 | + Sentry.get_current_client.flush |
182 | 133 |
|
183 | | - Sentry.get_current_client.flush |
| 134 | + expect(sentry_logs).not_to be_empty |
184 | 135 |
|
185 | | - expect(sentry_logs).not_to be_empty |
| 136 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 137 | + expect(log_event).not_to be_nil |
186 | 138 |
|
187 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
188 | | - expect(log_event).not_to be_nil |
| 139 | + params = log_event[:attributes][:params][:value] |
| 140 | + expect(params).to include("normal_param" => "value") |
| 141 | + expect(params).to include("password" => "[FILTERED]") |
| 142 | + expect(params).to include("api_key" => "[FILTERED]") |
| 143 | + expect(params).to include("credit_card" => "[FILTERED]") |
| 144 | + expect(params).to include("authorization" => "[FILTERED]") |
| 145 | + end |
189 | 146 |
|
190 | | - params = log_event[:attributes][:params][:value] |
191 | | - expect(params).to include("normal_param" => "value") |
192 | | - expect(params["user"]).to include("name" => "John") |
193 | | - expect(params["user"]).to include("password" => "[FILTERED]") |
194 | | - expect(params["user"]["profile"]).to include("api_key" => "[FILTERED]") |
195 | | - expect(params["user"]["profile"]).to include("public_info" => "visible") |
| 147 | + it "handles nested parameters correctly" do |
| 148 | + get "/world", params: { |
| 149 | + user: { |
| 150 | + name: "John", |
| 151 | + password: "secret123", |
| 152 | + profile: { |
| 153 | + api_key: "key456", |
| 154 | + public_info: "visible" |
| 155 | + } |
| 156 | + }, |
| 157 | + normal_param: "value" |
| 158 | + } |
| 159 | + |
| 160 | + Sentry.get_current_client.flush |
| 161 | + |
| 162 | + expect(sentry_logs).not_to be_empty |
| 163 | + |
| 164 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 165 | + expect(log_event).not_to be_nil |
| 166 | + |
| 167 | + params = log_event[:attributes][:params][:value] |
| 168 | + expect(params).to include("normal_param" => "value") |
| 169 | + expect(params["user"]).to include("name" => "John") |
| 170 | + expect(params["user"]).to include("password" => "[FILTERED]") |
| 171 | + expect(params["user"]["profile"]).to include("api_key" => "[FILTERED]") |
| 172 | + expect(params["user"]["profile"]).to include("public_info" => "visible") |
| 173 | + end |
196 | 174 | end |
197 | | - end |
198 | | - |
199 | | - context "when send_default_pii is disabled" do |
200 | | - it "does not include request parameters" do |
201 | | - sentry_transport.events.clear |
202 | | - sentry_transport.envelopes.clear |
203 | 175 |
|
204 | | - get "/world", params: { param: "value" } |
| 176 | + context "when send_default_pii is disabled" do |
| 177 | + it "does not include request parameters" do |
| 178 | + get "/world", params: { param: "value" } |
205 | 179 |
|
206 | | - Sentry.get_current_client.flush |
| 180 | + Sentry.get_current_client.flush |
207 | 181 |
|
208 | | - expect(sentry_logs).not_to be_empty |
| 182 | + expect(sentry_logs).not_to be_empty |
209 | 183 |
|
210 | | - log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
211 | | - expect(log_event).not_to be_nil |
212 | | - expect(log_event[:attributes]).not_to have_key(:params) |
| 184 | + log_event = sentry_logs.find { |log| log[:body] == "HelloController#world" } |
| 185 | + expect(log_event).not_to be_nil |
| 186 | + expect(log_event[:attributes]).not_to have_key(:params) |
| 187 | + end |
213 | 188 | end |
214 | 189 | end |
215 | 190 | end |
216 | 191 |
|
217 | | - describe "when logging is disabled" do |
| 192 | + context "when logging is disabled" do |
218 | 193 | before do |
219 | 194 | make_basic_app do |config| |
220 | 195 | config.enable_logs = false |
| 196 | + |
221 | 197 | config.rails.structured_logging.enabled = true |
222 | 198 | config.rails.structured_logging.subscribers = { action_controller: Sentry::Rails::LogSubscribers::ActionControllerSubscriber } |
223 | 199 | end |
|
0 commit comments