Skip to content

Commit bdbfa6e

Browse files
authored
#132413: Implement SafeJsonFormatter for SemanticLogger (#27330)
* #132413: Implement SafeJsonFormatter for SemanticLogger * create tests for formatter behavior * Update CODEOWNERS * fix spec/formatters directory * add methods to SafeJsonFormatter class * prepend SafeFormatter instantiation to prod and dev config * move formatter from app/ to lib/ * Update CODEOWNERS * lib/formatters -> lib/semantic_logger * remove unused app/formatters/ folder * fix typo in lib/semantic_logger/ entry * remove unused spec/formatters folder * fix typo in require_relative in application.rb * add tests, expand rescue, sanitize keys
1 parent 974b616 commit bdbfa6e

File tree

6 files changed

+197
-3
lines changed

6 files changed

+197
-3
lines changed

.github/CODEOWNERS

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1127,6 +1127,7 @@ lib/search @department-of-veterans-affairs/backend-review-group
11271127
lib/search/pii_redactor.rb @department-of-veterans-affairs/backend-review-group
11281128
lib/search_click_tracking @department-of-veterans-affairs/backend-review-group
11291129
lib/search_gsa @department-of-veterans-affairs/backend-review-group
1130+
lib/semantic_logger/safe_json_formatter.rb @department-of-veterans-affairs/backend-review-group
11301131
lib/sentry @department-of-veterans-affairs/backend-review-group
11311132
lib/sftp_writer @department-of-veterans-affairs/backend-review-group
11321133
lib/shrine @department-of-veterans-affairs/backend-review-group
@@ -1735,6 +1736,7 @@ spec/lib/search @department-of-veterans-affairs/backend-review-group
17351736
spec/lib/search/pii_redactor_spec.rb @department-of-veterans-affairs/backend-review-group
17361737
spec/lib/search_click_tracking @department-of-veterans-affairs/backend-review-group
17371738
spec/lib/search_gsa @department-of-veterans-affairs/backend-review-group
1739+
spec/lib/semantic_logger/safe_json_formatter_spec.rb @department-of-veterans-affairs/backend-review-group
17381740
spec/lib/sentry @department-of-veterans-affairs/backend-review-group
17391741
spec/lib/sftp_writer @department-of-veterans-affairs/backend-review-group
17401742
spec/lib/sftp_writer/factory_spec.rb @department-of-veterans-affairs/backend-review-group

config/application.rb

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@
1818
# Require the gems listed in Gemfile, including any gems
1919
# you've limited to :test, :development, or :production.
2020
Bundler.require(*Rails.groups)
21-
21+
require_relative '../lib/semantic_logger/safe_json_formatter'
2222
require_relative '../lib/olive_branch_patch'
2323

2424
module VetsAPI

config/environments/development.rb

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -90,6 +90,6 @@
9090
config.semantic_logger.add_appender(
9191
io: $stdout,
9292
level: :info, # For debug, see log/development.log
93-
formatter: config.rails_semantic_logger.format
93+
formatter: SafeJsonFormatter.new
9494
)
9595
end

config/environments/production.rb

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -75,7 +75,7 @@
7575
config.rails_semantic_logger.add_file_appender = false
7676
config.semantic_logger.add_appender(io: $stdout,
7777
level: config.log_level,
78-
formatter: config.rails_semantic_logger.format)
78+
formatter: SafeJsonFormatter.new)
7979

8080
config.semantic_logger.application = if Sidekiq.server?
8181
'vets-api-worker'
Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,62 @@
1+
# frozen_string_literal: true
2+
3+
class SafeJsonFormatter < SemanticLogger::Formatters::Json
4+
# Raw formatter path can call `log.file_name_and_line`, which expects an
5+
# Exception-like object with a backtrace. Skip source extraction when callers
6+
# pass non-exceptions such as a String to `exception:`.
7+
def file_name_and_line
8+
return if log.exception && !log.exception.respond_to?(:backtrace)
9+
10+
super
11+
end
12+
13+
def exception
14+
return unless log.exception
15+
16+
if log.exception.respond_to?(:backtrace)
17+
super
18+
else
19+
hash[:exception] = {
20+
name: log.exception.class.name,
21+
message: sanitize_string(log.exception.to_s)
22+
}
23+
end
24+
end
25+
26+
def call(log, logger)
27+
super
28+
rescue JSON::GeneratorError
29+
fallback = hash || {}
30+
sanitize_values(fallback).tap do |safe|
31+
# String keys: sanitize_values normalizes hash keys to UTF-8 strings for JSON.
32+
safe['level'] ||= log.level.to_s
33+
safe['message'] ||= '[SafeJsonFormatter: original message unrecoverable]'
34+
safe['safe_json_formatter_fallback'] = true
35+
end.to_json
36+
end
37+
38+
private
39+
40+
def sanitize_string(value)
41+
value.to_s.encode('UTF-8', invalid: :replace, undef: :replace, replace: '?')
42+
end
43+
44+
def sanitize_values(value)
45+
case value
46+
when String
47+
sanitize_string(value)
48+
when Hash
49+
value.each_with_object({}) do |(key, nested), acc|
50+
acc[sanitize_hash_key(key)] = sanitize_values(nested)
51+
end
52+
when Array
53+
value.map { |nested| sanitize_values(nested) }
54+
else
55+
value
56+
end
57+
end
58+
59+
def sanitize_hash_key(key)
60+
sanitize_string(key.to_s)
61+
end
62+
end
Lines changed: 130 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,130 @@
1+
# frozen_string_literal: true
2+
3+
require 'rails_helper'
4+
5+
RSpec.describe SafeJsonFormatter do
6+
subject(:formatter) { described_class.new }
7+
8+
let(:logger_context) do
9+
double(
10+
host: 'test-host',
11+
application: 'vets-api',
12+
environment: 'test'
13+
)
14+
end
15+
16+
def build_log(message:, exception: nil, payload: nil)
17+
log = SemanticLogger::Log.new('SafeJsonFormatterSpec', :error, 0)
18+
log.instance_variable_set(:@message, message)
19+
log.instance_variable_set(:@exception, exception)
20+
log.instance_variable_set(:@payload, payload)
21+
log
22+
end
23+
24+
describe 'FM1 string-as-exception handling' do
25+
it 'does not raise when exception is a String' do
26+
log = build_log(message: 'upload failed', exception: 'string exception')
27+
28+
expect { formatter.call(log, logger_context) }.not_to raise_error
29+
end
30+
31+
it 'handles string exception and invalid UTF-8 in payload together' do
32+
invalid_bytes = +"\xA1x"
33+
invalid_bytes.force_encoding(Encoding::ASCII_8BIT)
34+
35+
log = build_log(
36+
message: 'both failure modes',
37+
exception: 'string-as-exception',
38+
payload: { body: invalid_bytes }
39+
)
40+
41+
parsed = JSON.parse(formatter.call(log, logger_context))
42+
43+
expect(parsed.dig('exception', 'name')).to eq('String')
44+
expect(parsed.dig('exception', 'message')).to eq('string-as-exception')
45+
expect(parsed['safe_json_formatter_fallback']).to be true
46+
expect(parsed['payload']['body']).to eq('?x')
47+
end
48+
end
49+
50+
describe 'FM2 encoding sanitization' do
51+
it 'does not raise JSON::GeneratorError for invalid UTF-8 payload content' do
52+
invalid_bytes = +"\xA1bad-data"
53+
invalid_bytes.force_encoding(Encoding::ASCII_8BIT)
54+
55+
log = build_log(
56+
message: 'binary payload',
57+
payload: {
58+
body: invalid_bytes,
59+
nested: ['ok', { detail: invalid_bytes }]
60+
}
61+
)
62+
63+
expect { formatter.call(log, logger_context) }.not_to raise_error
64+
end
65+
66+
it 'marks logs that used the JSON fallback path' do
67+
invalid_bytes = +"\xA1bad-data"
68+
invalid_bytes.force_encoding(Encoding::ASCII_8BIT)
69+
70+
log = build_log(
71+
message: 'binary payload',
72+
payload: { body: invalid_bytes }
73+
)
74+
75+
parsed = JSON.parse(formatter.call(log, logger_context))
76+
77+
expect(parsed['safe_json_formatter_fallback']).to be true
78+
expect(parsed['payload']['body']).to eq('?bad-data')
79+
expect(parsed['level']).to be_present
80+
expect(parsed['message']).to eq('binary payload')
81+
end
82+
83+
it 'sanitizes invalid UTF-8 in hash keys so the fallback JSON encodes' do
84+
bad_key = +"\xA1meta"
85+
bad_key.force_encoding(Encoding::ASCII_8BIT)
86+
87+
log = build_log(
88+
message: 'bad key',
89+
payload: { bad_key => 'ok' }
90+
)
91+
92+
parsed = JSON.parse(formatter.call(log, logger_context))
93+
94+
expect(parsed['safe_json_formatter_fallback']).to be true
95+
expect(parsed['payload'].keys).to eq(['?meta'])
96+
expect(parsed['payload']['?meta']).to eq('ok')
97+
end
98+
end
99+
100+
describe 'standard exception serialization' do
101+
it 'continues to serialize a real exception' do
102+
error = RuntimeError.new('Exception!')
103+
error.set_backtrace(%w[a.rb:1 b.rb:2])
104+
log = build_log(message: 'failed', exception: error)
105+
106+
result = formatter.call(log, logger_context)
107+
parsed = JSON.parse(result)
108+
109+
expect(parsed.dig('exception', 'name')).to eq('RuntimeError')
110+
expect(parsed.dig('exception', 'message')).to eq('Exception!')
111+
expect(parsed).not_to have_key('safe_json_formatter_fallback')
112+
end
113+
end
114+
115+
describe 'JSON fallback metadata' do
116+
it 'fills placeholder message when the original is absent after failure' do
117+
invalid_bytes = +"\xFF"
118+
invalid_bytes.force_encoding(Encoding::ASCII_8BIT)
119+
120+
log = SemanticLogger::Log.new('SafeJsonFormatterSpec', :error, 0)
121+
log.instance_variable_set(:@message, nil)
122+
log.instance_variable_set(:@payload, { body: invalid_bytes })
123+
124+
parsed = JSON.parse(formatter.call(log, logger_context))
125+
126+
expect(parsed['safe_json_formatter_fallback']).to be true
127+
expect(parsed['message']).to eq('[SafeJsonFormatter: original message unrecoverable]')
128+
end
129+
end
130+
end

0 commit comments

Comments
 (0)