diff --git a/lib/waterdrop/instrumentation/logger_listener.rb b/lib/waterdrop/instrumentation/logger_listener.rb index d470c4b3..3006302b 100644 --- a/lib/waterdrop/instrumentation/logger_listener.rb +++ b/lib/waterdrop/instrumentation/logger_listener.rb @@ -118,6 +118,13 @@ def on_buffer_purged(event) end # @param event [Dry::Events::Event] event that happened with the details + def on_producer_closing(event) + info(event, 'Closing producer') + end + + # @param event [Dry::Events::Event] event that happened with the details + # @note While this says "Closing producer", it produces a nice message with time taken: + # "Closing producer took 12 ms" indicating it happened in the past. def on_producer_closed(event) info(event, 'Closing producer') end @@ -180,7 +187,11 @@ def debug(event, log_message) # @param event [Dry::Events::Event] event that happened with the details # @param log_message [String] message we want to publish def info(event, log_message) - @logger.info("[#{event[:producer_id]}] #{log_message} took #{event[:time]} ms") + if event.payload.key?(:time) + @logger.info("[#{event[:producer_id]}] #{log_message} took #{event[:time]} ms") + else + @logger.info("[#{event[:producer_id]}] #{log_message}") + end end # @param event [Dry::Events::Event] event that happened with the details diff --git a/spec/lib/waterdrop/instrumentation/logger_listener_spec.rb b/spec/lib/waterdrop/instrumentation/logger_listener_spec.rb index c8a01e66..aa3fc959 100644 --- a/spec/lib/waterdrop/instrumentation/logger_listener_spec.rb +++ b/spec/lib/waterdrop/instrumentation/logger_listener_spec.rb @@ -201,6 +201,14 @@ it { expect(logged_data[1]).to eq(nil) } end + describe '#on_producer_closing' do + before { listener.on_producer_closing(event) } + + it { expect(logged_data[0]).to include(producer.id) } + it { expect(logged_data[0]).to include('INFO') } + it { expect(logged_data[0]).to include('Closing producer') } + end + describe '#on_producer_closed' do before { listener.on_producer_closed(event) }