Skip to content

Commit

Permalink
Fix usage of .tagged with several tags
Browse files Browse the repository at this point in the history 
When calling `.tagged` on our logger directly (without wrapping it
in `ActiveSupport::TaggedLogging`) we should support passing tags
as separate arguments, like newer versions of Rails do.
  • Loading branch information
@unflxw
unflxw committed Dec 17, 2024
1 parent 78247b7 commit ae7527e
Show file tree
Hide file tree
Showing 3 changed files with 145 additions and 127 deletions.
6 changes: 6 additions & 0 deletions .changesets/fix--appsignal--logger-tagged--with-several-tags.md
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
---
bump: patch
type: fix
---

Fix an issue when calling `Appsignal::Logger#tagged` directly with several tags. This does not affect users of `Appsignal::Logger` who also use `ActiveSupport::TaggedLogging` to wrap the logger.
10 changes: 9 additions & 1 deletion lib/appsignal/logger.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -151,7 +151,11 @@ def fatal(message = nil, attributes = {})
end

# Listen to ActiveSupport tagged logging tags set with `Rails.logger.tagged`.
def tagged(tags)
def tagged(*tags)
# Depending on the Rails version, the tags can be passed as an array or
# as separate arguments. Flatten the tags argument array to deal with them
# indistinctly.
tags = tags.flatten
@tags.append(*tags)
yield self
ensure
Expand All @@ -160,6 +164,10 @@ def tagged(tags)

# Listen to ActiveSupport tagged logging tags set with `Rails.config.log_tags`.
def push_tags(*tags)
# Depending on the Rails version, the tags can be passed as an array or
# as separate arguments. Flatten the tags argument array to deal with them
# indistinctly.
tags = tags.flatten
@tags.append(*tags)
end

Expand Down
256 changes: 130 additions & 126 deletions spec/lib/appsignal/logger_spec.rb
View file
Original file line number Diff line number Diff line change
@@ -1,3 +1,127 @@
shared_examples "tagged logging" do
it "logs messages with tags from logger.tagged" do
expect(Appsignal::Extension).to receive(:log)
.with(
"group",
3,
0,
a_string_starting_with("[My tag] [My other tag] Some message"),
Appsignal::Utils::Data.generate({})
)

logger.tagged("My tag", "My other tag") do
logger.info("Some message")
end
end

it "logs messages with nested tags from logger.tagged" do
expect(Appsignal::Extension).to receive(:log)
.with(
"group",
3,
0,
a_string_starting_with("[My tag] [My other tag] [Nested tag] [Nested other tag] Some message"),
Appsignal::Utils::Data.generate({})
)

logger.tagged("My tag", "My other tag") do
logger.tagged("Nested tag", "Nested other tag") do
logger.info("Some message")
end
end
end

it "logs messages with tags from Rails.application.config.log_tags" do
allow(Appsignal::Extension).to receive(:log)

# This is how Rails sets the `log_tags` values
logger.push_tags(["Request tag", "Second tag"])
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with(
"[Request tag] [Second tag] [First message] [My other tag] Some message"
),
Appsignal::Utils::Data.generate({})
)

# Logs all messsages within the time between `push_tags` and `pop_tags`
# with the same set tags
logger.tagged("Second message") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with("[Request tag] [Second tag] [Second message] Some message"),
Appsignal::Utils::Data.generate({})
)

# This is how Rails clears the `log_tags` values
# It will no longer includes those tags in new log messages
logger.pop_tags(2)
logger.tagged("Third message") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with("[Third message] Some message"),
Appsignal::Utils::Data.generate({})
)
end

it "logs messages with tags from Rails 8 application.config.log_tags" do
allow(Appsignal::Extension).to receive(:log)

# This is how Rails sets the `log_tags` values
logger.push_tags("Request tag", "Second tag")
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with(
"[Request tag] [Second tag] [First message] [My other tag] Some message"
),
Appsignal::Utils::Data.generate({})
)
end

it "clears all tags with clear_tags!" do
allow(Appsignal::Extension).to receive(:log)

# This is how Rails sets the `log_tags` values
logger.push_tags(["Request tag", "Second tag"])
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with(
"[Request tag] [Second tag] [First message] [My other tag] Some message"
),
Appsignal::Utils::Data.generate({})
)

logger.clear_tags!
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
a_string_starting_with("[First message] [My other tag] Some message"),
Appsignal::Utils::Data.generate({})
)
end
end

describe Appsignal::Logger do
let(:log_stream) { StringIO.new }
let(:logs) { log_contents(log_stream) }
Expand Down Expand Up @@ -233,136 +357,16 @@
end
end

if DependencyHelper.rails_present?
describe "tagged logging" do
it "logs messages with tags from logger.tagged" do
expect(Appsignal::Extension).to receive(:log)
.with(
"group",
3,
0,
"[My tag] [My other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)

appsignal_logger = Appsignal::Logger.new("group")
logger = ActiveSupport::TaggedLogging.new(appsignal_logger)
logger.tagged("My tag", "My other tag") do
logger.info("Some message")
end
end

it "logs messages with nested tags from logger.tagged" do
expect(Appsignal::Extension).to receive(:log)
.with(
"group",
3,
0,
"[My tag] [My other tag] [Nested tag] [Nested other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)

appsignal_logger = Appsignal::Logger.new("group")
logger = ActiveSupport::TaggedLogging.new(appsignal_logger)
logger.tagged("My tag", "My other tag") do
logger.tagged("Nested tag", "Nested other tag") do
logger.info("Some message")
end
end
end

it "logs messages with tags from Rails.application.config.log_tags" do
allow(Appsignal::Extension).to receive(:log)

appsignal_logger = Appsignal::Logger.new("group")
logger = ActiveSupport::TaggedLogging.new(appsignal_logger)

# This is how Rails sets the `log_tags` values
logger.push_tags(["Request tag", "Second tag"])
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[Request tag] [Second tag] [First message] [My other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)

# Logs all messsages within the time between `push_tags` and `pop_tags`
# with the same set tags
logger.tagged("Second message") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[Request tag] [Second tag] [Second message] Some message\n",
Appsignal::Utils::Data.generate({})
)

# This is how Rails clears the `log_tags` values
# It will no longer includes those tags in new log messages
logger.pop_tags(2)
logger.tagged("Third message") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[Third message] Some message\n",
Appsignal::Utils::Data.generate({})
)
end

it "logs messages with tags from Rails 8 application.config.log_tags" do
allow(Appsignal::Extension).to receive(:log)
it_behaves_like "tagged logging"

if DependencyHelper.rails_present?
describe "wrapped in ActiveSupport::TaggedLogging" do
let(:logger) do
appsignal_logger = Appsignal::Logger.new("group")
logger = ActiveSupport::TaggedLogging.new(appsignal_logger)

# This is how Rails sets the `log_tags` values
logger.push_tags("Request tag", "Second tag")
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[Request tag] [Second tag] [First message] [My other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)
ActiveSupport::TaggedLogging.new(appsignal_logger)
end

it "clears all tags with clear_tags!" do
allow(Appsignal::Extension).to receive(:log)

appsignal_logger = Appsignal::Logger.new("group")
logger = ActiveSupport::TaggedLogging.new(appsignal_logger)

# This is how Rails sets the `log_tags` values
logger.push_tags(["Request tag", "Second tag"])
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[Request tag] [Second tag] [First message] [My other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)

logger.clear_tags!
logger.tagged("First message", "My other tag") { logger.info("Some message") }
expect(Appsignal::Extension).to have_received(:log)
.with(
"group",
3,
0,
"[First message] [My other tag] Some message\n",
Appsignal::Utils::Data.generate({})
)
end
it_behaves_like "tagged logging"
end
end
end

0 comments on commit ae7527e

Please sign in to comment.