diff --git a/.changesets/add-heartbeat-check-ins.md b/.changesets/add-heartbeat-check-ins.md new file mode 100644 index 000000000..fcc5cccfe --- /dev/null +++ b/.changesets/add-heartbeat-check-ins.md @@ -0,0 +1,26 @@ +--- +bump: minor +type: add +--- + +Add support for heartbeat check-ins. + +Use the `Appsignal::CheckIn.heartbeat` method to send a single heartbeat check-in event from your application. This can be used, for example, in your application's main loop: + +```ruby +loop do + Appsignal::CheckIn.heartbeat("job_processor") + process_job +end +``` + +Heartbeats are deduplicated and sent asynchronously, without blocking the current thread. Regardless of how often the `.heartbeat` method is called, at most one heartbeat with the same identifier will be sent every ten seconds. + +Pass `continuous: true` as the second argument to send heartbeats continuously during the entire lifetime of the current process. This can be used, for example, after your application has finished its boot process: + +```ruby +def main + start_app + Appsignal::CheckIn.heartbeat("my_app", continuous: true) +end +``` diff --git a/lib/appsignal/check_in.rb b/lib/appsignal/check_in.rb index cd4c1d272..425642268 100644 --- a/lib/appsignal/check_in.rb +++ b/lib/appsignal/check_in.rb @@ -2,10 +2,21 @@ module Appsignal module CheckIn + HEARTBEAT_CONTINUOUS_INTERVAL_SECONDS = 30 class << self + # @api private + def continuous_heartbeats + @continuous_heartbeats ||= [] + end + + # @api private + def kill_continuous_heartbeats + continuous_heartbeats.each(&:kill) + end + # Track cron check-ins. # - # Track the execution of certain processes by sending a cron check-in. + # Track the execution of scheduled processes by sending a cron check-in. # # To track the duration of a piece of code, pass a block to {.cron} # to report both when the process starts, and when it finishes. @@ -40,6 +51,37 @@ def cron(identifier) output end + # Track heartbeat check-ins. + # + # Track the execution of long-lived processes by sending a heartbeat + # check-in. + # + # @example Send a heartbeat check-in + # Appsignal::CheckIn.heartbeat("main_loop") + # + # @param identifier [String] identifier of the heartbeat check-in to report. + # @param continuous [Boolean] whether the heartbeats should be sent continuously + # during the lifetime of the process. Defaults to `false`. + # @yield the block to monitor. + # @return [void] + # @since 4.1.0 + # @see https://docs.appsignal.com/check-ins/heartbeat + def heartbeat(identifier, continuous: false) + if continuous + continuous_heartbeats << Thread.new do + loop do + heartbeat(identifier) + sleep HEARTBEAT_CONTINUOUS_INTERVAL_SECONDS + end + end + + return + end + + event = Event.heartbeat(:identifier => identifier) + scheduler.schedule(event) + end + # @api private def transmitter @transmitter ||= Transmitter.new( @@ -60,5 +102,6 @@ def stop end end +require "appsignal/check_in/event" require "appsignal/check_in/scheduler" require "appsignal/check_in/cron" diff --git a/lib/appsignal/check_in/cron.rb b/lib/appsignal/check_in/cron.rb index 7d77540da..9befefd26 100644 --- a/lib/appsignal/check_in/cron.rb +++ b/lib/appsignal/check_in/cron.rb @@ -22,13 +22,11 @@ def finish private def event(kind) - { + Event.cron( :identifier => @identifier, :digest => @digest, - :kind => kind, - :timestamp => Time.now.utc.to_i, - :check_in_type => "cron" - } + :kind => kind + ) end end end diff --git a/lib/appsignal/check_in/event.rb b/lib/appsignal/check_in/event.rb new file mode 100644 index 000000000..8a3cce8df --- /dev/null +++ b/lib/appsignal/check_in/event.rb @@ -0,0 +1,72 @@ +# frozen_string_literal: true + +module Appsignal + module CheckIn + # @api private + class Event + class << self + def new(check_in_type:, identifier:, digest: nil, kind: nil) + { + :identifier => identifier, + :digest => digest, + :kind => kind, + :timestamp => Time.now.utc.to_i, + :check_in_type => check_in_type + }.compact + end + + def cron(identifier:, digest:, kind:) + new( + :check_in_type => "cron", + :identifier => identifier, + :digest => digest, + :kind => kind + ) + end + + def heartbeat(identifier:) + new( + :check_in_type => "heartbeat", + :identifier => identifier + ) + end + + def redundant?(event, other) + return false if + other[:check_in_type] != event[:check_in_type] || + other[:identifier] != event[:identifier] + + return false if event[:check_in_type] == "cron" && ( + other[:digest] != event[:digest] || + other[:kind] != event[:kind] + ) + + return false if + event[:check_in_type] != "cron" && + event[:check_in_type] != "heartbeat" + + true + end + + def describe(events) + if events.empty? + # This shouldn't happen. + "no check-in events" + elsif events.length > 1 + "#{events.length} check-in events" + else + event = events.first + if event[:check_in_type] == "cron" + "cron check-in `#{event[:identifier] || "unknown"}` " \ + "#{event[:kind] || "unknown"} event (digest #{event[:digest] || "unknown"})" + elsif event[:check_in_type] == "heartbeat" + "heartbeat check-in `#{event[:identifier] || "unknown"}` event" + else + "unknown check-in event" + end + end + end + end + end + end +end diff --git a/lib/appsignal/check_in/scheduler.rb b/lib/appsignal/check_in/scheduler.rb index 5b000b8c1..62e4e63dd 100644 --- a/lib/appsignal/check_in/scheduler.rb +++ b/lib/appsignal/check_in/scheduler.rb @@ -29,7 +29,7 @@ def initialize def schedule(event) unless Appsignal.active? Appsignal.internal_logger.debug( - "Cannot transmit #{describe([event])}: AppSignal is not active" + "Cannot transmit #{Event.describe([event])}: AppSignal is not active" ) return end @@ -37,7 +37,7 @@ def schedule(event) @mutex.synchronize do if @queue.closed? Appsignal.internal_logger.debug( - "Cannot transmit #{describe([event])}: AppSignal is stopped" + "Cannot transmit #{Event.describe([event])}: AppSignal is stopped" ) return end @@ -48,7 +48,7 @@ def schedule(event) start_waker(INITIAL_DEBOUNCE_SECONDS) if @waker.nil? Appsignal.internal_logger.debug( - "Scheduling #{describe([event])} to be transmitted" + "Scheduling #{Event.describe([event])} to be transmitted" ) # Make sure to start the thread after an event has been added. @@ -92,7 +92,7 @@ def run end def transmit(events) - description = describe(events) + description = Event.describe(events) begin response = CheckIn.transmitter.transmit(events, :format => :ndjson) @@ -110,42 +110,18 @@ def transmit(events) end end - def describe(events) - if events.empty? - # This shouldn't happen. - "no check-in events" - elsif events.length > 1 - "#{events.length} check-in events" - else - event = events.first - if event[:check_in_type] == "cron" - "cron check-in `#{event[:identifier] || "unknown"}` " \ - "#{event[:kind] || "unknown"} event (digest #{event[:digest] || "unknown"})" \ - else - "unknown check-in event" - end - end - end - # Must be called from within a `@mutex.synchronize` block. def add_event(event) # Remove redundant events, keeping the newly added one, which # should be the one with the most recent timestamp. - if event[:check_in_type] == "cron" - # Remove any existing cron check-in event with the same identifier, - # digest and kind as the one we're adding. - @events.reject! do |existing_event| - next unless existing_event[:identifier] == event[:identifier] && - existing_event[:digest] == event[:digest] && - existing_event[:kind] == event[:kind] && - existing_event[:check_in_type] == "cron" + @events.reject! do |existing_event| + next unless Event.redundant?(event, existing_event) - Appsignal.internal_logger.debug( - "Replacing previously scheduled #{describe([existing_event])}" - ) + Appsignal.internal_logger.debug( + "Replacing previously scheduled #{Event.describe([existing_event])}" + ) - true - end + true end @events << event diff --git a/spec/lib/appsignal/check_in/cron_spec.rb b/spec/lib/appsignal/check_in/cron_spec.rb index 9d2598abc..b432d0355 100644 --- a/spec/lib/appsignal/check_in/cron_spec.rb +++ b/spec/lib/appsignal/check_in/cron_spec.rb @@ -5,6 +5,7 @@ let(:config) { project_fixture_config } let(:cron_checkin) { described_class.new(:identifier => "cron-checkin-name") } let(:scheduler) { Appsignal::CheckIn.scheduler } + let(:stubs) { [] } before do start_agent( @@ -12,10 +13,13 @@ :internal_logger => test_logger(log_stream) ) end - after { stop_scheduler } - def stop_scheduler + after do scheduler.stop + + stubs.each do |stub| + expect(stub.count).to eq(1) + end end describe "when Appsignal is not active" do @@ -26,7 +30,7 @@ def stop_scheduler cron_checkin.start cron_checkin.finish - stop_scheduler + scheduler.stop expect(logs).to contains_log( :debug, @@ -48,12 +52,14 @@ def stop_scheduler expect(logs).to contains_log( :debug, - "Cannot transmit cron check-in `cron-checkin-name` start event" + /Cannot transmit cron check-in `cron-checkin-name` start event .+: AppSignal is stopped/ ) expect(logs).to contains_log( :debug, - "Cannot transmit cron check-in `cron-checkin-name` finish event" + /Cannot transmit cron check-in `cron-checkin-name` finish event .+: AppSignal is stopped/ ) + + scheduler.stop end end @@ -61,11 +67,10 @@ def stop_scheduler it "sends a cron check-in start" do cron_checkin.start - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-name", - "kind" => "start", - "check_in_type" => "cron" + "kind" => "start" ] ) @@ -85,11 +90,10 @@ def stop_scheduler it "logs an error if it fails" do cron_checkin.start - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-name", - "kind" => "start", - "check_in_type" => "cron" + "kind" => "start" ], :response => { :status => 499 } ) @@ -111,11 +115,10 @@ def stop_scheduler it "sends a cron check-in finish" do cron_checkin.finish - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-name", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) @@ -134,11 +137,10 @@ def stop_scheduler it "logs an error if it fails" do cron_checkin.finish - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-name", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ], :response => { :status => 499 } ) @@ -159,19 +161,14 @@ def stop_scheduler describe ".cron" do describe "when a block is given" do it "sends a cron check-in start and finish and return the block output" do - stub_check_in_request( - :events => [ + stubs << stub_cron_check_in_request( + :events => [{ "identifier" => "cron-checkin-with-block", - "kind" => "start", - "check_in_type" => "cron" - ] - ) - stub_check_in_request( - :events => [ + "kind" => "start" + }, { "identifier" => "cron-checkin-with-block", - "kind" => "finish", - "check_in_type" => "cron" - ] + "kind" => "finish" + }] ) output = Appsignal::CheckIn.cron("cron-checkin-with-block") { "output" } @@ -179,11 +176,10 @@ def stop_scheduler end it "does not send a cron check-in finish event when an error is raised" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-with-block", - "kind" => "start", - "check_in_type" => "cron" + "kind" => "start" ] ) @@ -195,11 +191,10 @@ def stop_scheduler describe "when no block is given" do it "only sends a cron check-in finish event" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "cron-checkin-without-block", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) diff --git a/spec/lib/appsignal/check_in/event_spec.rb b/spec/lib/appsignal/check_in/event_spec.rb new file mode 100644 index 000000000..12e1ef507 --- /dev/null +++ b/spec/lib/appsignal/check_in/event_spec.rb @@ -0,0 +1,169 @@ +describe Appsignal::CheckIn::Event do + describe "#describe" do + it "describes an empty list of check-ins" do + expect( + described_class.describe([]) + ).to eq("no check-in events") + end + + it "describes a cron check-in by identifier, kind, and digest" do + expect( + described_class.describe([ + described_class.cron( + :identifier => "cron-checkin-name", + :digest => "some-digest", + :kind => "some-kind" + ) + ]) + ).to eq("cron check-in `cron-checkin-name` some-kind event (digest some-digest)") + end + + it "describes a heartbeat check-in by identifier" do + expect( + described_class.describe([ + described_class.heartbeat(:identifier => "heartbeat-checkin-name") + ]) + ).to eq("heartbeat check-in `heartbeat-checkin-name` event") + end + + it "describes an unknown check-in event" do + expect( + described_class.describe([ + described_class.new( + :check_in_type => "unknown-type", + :identifier => "unknown-checkin-name" + ) + ]) + ).to eq("unknown check-in event") + end + + it "describes multiple check-ins by count" do + expect( + described_class.describe([ + described_class.heartbeat(:identifier => "heartbeat-checkin-name"), + described_class.cron( + :identifier => "cron-checkin-name", + :digest => "digest", + :kind => "start" + ) + ]) + ).to eq("2 check-in events") + end + end + + describe "#redundant?" do + it "returns false for different check-in types" do + event = described_class.heartbeat(:identifier => "checkin-name") + other = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + + it "returns false for different heartbeat identifiers" do + event = described_class.heartbeat(:identifier => "checkin-name") + other = described_class.heartbeat(:identifier => "other-checkin-name") + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + + it "returns true for the same heartbeat identifier" do + event = described_class.heartbeat(:identifier => "checkin-name") + other = described_class.heartbeat(:identifier => "checkin-name") + + expect( + described_class.redundant?(event, other) + ).to be(true) + end + + it "returns false for different cron identifiers" do + event = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + other = described_class.cron( + :identifier => "other-checkin-name", + :digest => "digest", + :kind => "start" + ) + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + + it "returns false for different cron digests" do + event = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + other = described_class.cron( + :identifier => "checkin-name", + :digest => "other-digest", + :kind => "start" + ) + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + + it "returns false for different cron kinds" do + event = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + other = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "finish" + ) + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + + it "returns true for the same cron identifier, digest, and kind" do + event = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + other = described_class.cron( + :identifier => "checkin-name", + :digest => "digest", + :kind => "start" + ) + + expect( + described_class.redundant?(event, other) + ).to be(true) + end + + it "returns false for unknown check-in event kinds" do + event = described_class.new( + :check_in_type => "unknown", + :identifier => "checkin-name" + ) + other = described_class.new( + :check_in_type => "unknown", + :identifier => "checkin-name" + ) + + expect( + described_class.redundant?(event, other) + ).to be(false) + end + end +end diff --git a/spec/lib/appsignal/check_in/heartbeat_spec.rb b/spec/lib/appsignal/check_in/heartbeat_spec.rb new file mode 100644 index 000000000..c7eec9330 --- /dev/null +++ b/spec/lib/appsignal/check_in/heartbeat_spec.rb @@ -0,0 +1,127 @@ +describe "Appsignal::CheckIn.heartbeat" do + include WaitForHelper + include TakeAtMostHelper + + let(:log_stream) { std_stream } + let(:logs) { log_contents(log_stream) } + let(:appsignal_options) { {} } + let(:config) { project_fixture_config } + let(:scheduler) { Appsignal::CheckIn.scheduler } + let(:stubs) { [] } + + before do + start_agent( + :options => appsignal_options, + :internal_logger => test_logger(log_stream) + ) + end + + after do + Appsignal::CheckIn.kill_continuous_heartbeats + scheduler.stop + + stubs.each do |stub| + expect(stub.count).to eq(1) + end + end + + def schedule_heartbeat(**kwargs) + Appsignal::CheckIn.heartbeat("heartbeat-checkin-name", **kwargs) + end + + describe "when Appsignal is not active" do + let(:appsignal_options) { { :active => false } } + + it "does not transmit any events" do + expect(Appsignal).to_not be_started + + schedule_heartbeat + scheduler.stop + + expect(logs).to contains_log( + :debug, + "Cannot transmit heartbeat check-in `heartbeat-checkin-name` event: AppSignal is not active" + ) + end + end + + describe "when AppSignal is stopped" do + it "does not transmit any events" do + Appsignal.stop + + schedule_heartbeat + + expect(logs).to contains_log( + :debug, + "Cannot transmit heartbeat check-in `heartbeat-checkin-name` event: AppSignal is stopped" + ) + + scheduler.stop + end + end + + it "sends a heartbeat" do + schedule_heartbeat + + stubs << stub_heartbeat_check_in_request( + :events => [ + "identifier" => "heartbeat-checkin-name" + ] + ) + + scheduler.stop + + expect(logs).to_not contains_log(:error) + expect(logs).to contains_log( + :debug, + "Scheduling heartbeat check-in `heartbeat-checkin-name` event" + ) + end + + it "logs an error if it fails" do + schedule_heartbeat + + stubs << stub_heartbeat_check_in_request( + :events => [ + "identifier" => "heartbeat-checkin-name" + ], + :response => { :status => 499 } + ) + + scheduler.stop + + expect(logs).to contains_log( + :debug, + "Scheduling heartbeat check-in `heartbeat-checkin-name` event" + ) + expect(logs).to contains_log( + :error, + "Failed to transmit heartbeat check-in `heartbeat-checkin-name` event: 499 status code" + ) + end + + describe "when the continuous option is set" do + it "keeps sending heartbeats continuously" do + stub_const("Appsignal::CheckIn::Scheduler::INITIAL_DEBOUNCE_SECONDS", 0.1) + stub_const("Appsignal::CheckIn::Scheduler::BETWEEN_TRANSMISSIONS_DEBOUNCE_SECONDS", 0.1) + stub_const("Appsignal::CheckIn::HEARTBEAT_CONTINUOUS_INTERVAL_SECONDS", 0.1) + + schedule_heartbeat(:continuous => true) + + stub = stub_check_in_requests( + # Additional requests could be made due to timing issues or when the + # scheduler is stopped in the `after` block -- stub additional requests + # to prevent the test from failing. + :requests => Array.new(5) do + [ + "identifier" => "heartbeat-checkin-name", + "check_in_type" => "heartbeat" + ] + end + ) + + wait_for("the event to be transmitted") { scheduler.transmitted == 2 } + expect(stub.count).to be >= 2 + end + end +end diff --git a/spec/lib/appsignal/check_in/scheduler_spec.rb b/spec/lib/appsignal/check_in/scheduler_spec.rb index 11cb58bba..096a401ed 100644 --- a/spec/lib/appsignal/check_in/scheduler_spec.rb +++ b/spec/lib/appsignal/check_in/scheduler_spec.rb @@ -6,6 +6,7 @@ let(:logs) { log_contents(log_stream) } let(:appsignal_options) { {} } let(:scheduler) { Appsignal::CheckIn.scheduler } + let(:stubs) { [] } before do start_agent(:options => appsignal_options, :internal_logger => test_logger(log_stream)) @@ -16,6 +17,10 @@ after do scheduler.stop + + stubs.each do |stub| + expect(stub.count).to eq(1) + end end describe "when no event is sent" do @@ -60,11 +65,10 @@ describe "when an event is sent" do it "starts a thread" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) Appsignal::CheckIn.cron("test") @@ -72,11 +76,10 @@ end it "schedules a debounce" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) Appsignal::CheckIn.cron("test") @@ -84,11 +87,10 @@ end it "schedules the event to be transmitted" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) @@ -114,11 +116,10 @@ stub_const("Appsignal::CheckIn::Scheduler::INITIAL_DEBOUNCE_SECONDS", 10) stub_const("Appsignal::CheckIn::Scheduler::BETWEEN_TRANSMISSIONS_DEBOUNCE_SECONDS", 10) - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) @@ -148,14 +149,16 @@ stub_const("Appsignal::CheckIn::Scheduler::INITIAL_DEBOUNCE_SECONDS", 10) stub_const("Appsignal::CheckIn::Scheduler::BETWEEN_TRANSMISSIONS_DEBOUNCE_SECONDS", 10) - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", "kind" => "finish", "check_in_type" => "cron" ] ) + Appsignal::CheckIn.cron("test") + take_at_most(0.1) do expect { scheduler.stop }.not_to raise_error end @@ -170,33 +173,35 @@ end it "closes the queue when stopped" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", "kind" => "finish", "check_in_type" => "cron" ] ) + Appsignal::CheckIn.cron("test") scheduler.stop expect(scheduler.queue.closed?).to be(true) end it "kills the thread when stopped" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", "kind" => "finish", "check_in_type" => "cron" ] ) + Appsignal::CheckIn.cron("test") scheduler.stop expect(scheduler.thread.alive?).to be(false) end it "unschedules the debounce when stopped" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", "kind" => "finish", @@ -214,15 +219,15 @@ describe "when many events are sent" do describe "within the short debounce interval" do it "transmits all events at once" do - ["first", "second", "third"].map do |identifier| - stub_check_in_request( - :events => [ + stubs << stub_cron_check_in_request( + :events => ["first", "second", "third"].map do |identifier| + { "identifier" => identifier, "kind" => "finish", "check_in_type" => "cron" - ] - ) - end + } + end + ) Appsignal::CheckIn.cron("first") Appsignal::CheckIn.cron("second") @@ -238,15 +243,15 @@ # stopped. stub_const("Appsignal::CheckIn::Scheduler::INITIAL_DEBOUNCE_SECONDS", 10) - ["first", "second", "third"].map do |identifier| - stub_check_in_request( - :events => [ + stubs << stub_cron_check_in_request( + :events => ["first", "second", "third"].map do |identifier| + { "identifier" => identifier, "kind" => "finish", "check_in_type" => "cron" - ] - ) - end + } + end + ) Appsignal::CheckIn.cron("first") Appsignal::CheckIn.cron("second") @@ -260,7 +265,7 @@ describe "further apart than the short debounce interval" do it "transmits the first event and enqueues future events" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "first", "kind" => "finish", @@ -272,7 +277,7 @@ wait_for("the first event to be transmitted") { scheduler.transmitted == 1 } - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ { "identifier" => "second", @@ -286,6 +291,7 @@ } ] ) + Appsignal::CheckIn.cron("second") Appsignal::CheckIn.cron("third") @@ -299,28 +305,26 @@ end it "transmits the other events after the debounce interval" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "first", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) + Appsignal::CheckIn.cron("first") wait_for("the first event to be transmitted") { scheduler.transmitted == 1 } - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ { "identifier" => "second", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" }, { "identifier" => "third", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" } ] ) @@ -348,28 +352,25 @@ # immediately when the scheduler is stopped. stub_const("Appsignal::CheckIn::Scheduler::BETWEEN_TRANSMISSIONS_DEBOUNCE_SECONDS", 10) - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "first", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) Appsignal::CheckIn.cron("first") wait_for("the event to be transmitted") { scheduler.transmitted == 1 } - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ { "identifier" => "second", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" }, { "identifier" => "third", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" } ] ) @@ -400,11 +401,10 @@ # `.cron` helper would use a different digest for each invocation. cron = Appsignal::CheckIn::Cron.new(:identifier => "test") - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "test", - "kind" => "start", - "check_in_type" => "cron" + "kind" => "start" ] ) @@ -466,19 +466,10 @@ describe "when transmitting returns a non-success response code" do it "logs the error and continues" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "first", - "kind" => "start", - "check_in_type" => "cron" - ], - :response => { :status => 404 } - ) - stub_check_in_request( - :events => [ - "identifier" => "first", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ], :response => { :status => 404 } ) @@ -487,18 +478,10 @@ wait_for("the first event to be transmitted") { scheduler.transmitted == 1 } - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "second", - "kind" => "start", - "check_in_type" => "cron" - ] - ) - stub_check_in_request( - :events => [ - "identifier" => "second", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) @@ -519,11 +502,10 @@ describe "when transmitting throws an error" do it "logs the error and continues" do - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "first", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ], :response => ExampleStandardError.new("Something went wrong") ) @@ -532,11 +514,10 @@ wait_for("the first event to be transmitted") { scheduler.transmitted == 1 } - stub_check_in_request( + stubs << stub_cron_check_in_request( :events => [ "identifier" => "second", - "kind" => "finish", - "check_in_type" => "cron" + "kind" => "finish" ] ) diff --git a/spec/support/helpers/api_request_helper.rb b/spec/support/helpers/api_request_helper.rb index d03c918a2..192a2495d 100644 --- a/spec/support/helpers/api_request_helper.rb +++ b/spec/support/helpers/api_request_helper.rb @@ -1,4 +1,16 @@ module ApiRequestHelper + class RequestCounter + attr_reader :count + + def initialize + @count = 0 + end + + def increase + @count += 1 + end + end + def stub_api_request(config, path, body = nil) options = { :query => { @@ -18,7 +30,33 @@ def stub_api_request(config, path, body = nil) stub_request(:post, "#{endpoint}/1/#{path}").with(options) end - def stub_check_in_request(events:, response: { :status => 200 }) + def stub_cron_check_in_request(events:, response: { :status => 200 }) + stub_check_in_requests( + :requests => [events], + :event_shape => { + "identifier" => nil, + "digest" => kind_of(String), + "kind" => nil, + "timestamp" => kind_of(Integer), + "check_in_type" => "cron" + }, + :response => response + ) + end + + def stub_heartbeat_check_in_request(events:, response: { :status => 200 }) + stub_check_in_requests( + :requests => [events], + :event_shape => { + "identifier" => nil, + "timestamp" => kind_of(Integer), + "check_in_type" => "heartbeat" + }, + :response => response + ) + end + + def stub_check_in_requests(requests:, event_shape: {}, response: { :status => 200 }) config = Appsignal.config options = { :query => { @@ -31,24 +69,25 @@ def stub_check_in_request(events:, response: { :status => 200 }) :headers => { "Content-Type" => "application/x-ndjson; charset=UTF-8" } } + counter = RequestCounter.new + request_stub = stub_request( :post, "#{config[:logging_endpoint]}/check_ins/json" ).with(options) do |request| + events = requests.shift + expect(events).to_not(be_nil, "More requests were made than expected") + counter.increase # Parse each line as JSON per the NDJSON format payloads = request.body.split("\n").map { |line| JSON.parse(line) } formatted_events = events.map do |event| - { - "identifier" => nil, - "digest" => kind_of(String), - "kind" => "start", - "timestamp" => kind_of(Integer), - "check_in_type" => "cron" - }.merge(event) + a_hash_including(**event_shape.merge(event)) end + expect(payloads).to include(*formatted_events) + expect(payloads.length).to eq(formatted_events.length) end if response.is_a?(Exception) @@ -56,5 +95,7 @@ def stub_check_in_request(events:, response: { :status => 200 }) else request_stub.to_return(response) end + + counter end end