diff --git a/.rubocop.yml b/.rubocop.yml index 0a89227168..9cfd53fc2f 100644 --- a/.rubocop.yml +++ b/.rubocop.yml @@ -1249,6 +1249,7 @@ Style/MethodCallWithArgsParentheses: - add_dependency - add_development_dependency - catch + - debug - expect - fail - gem diff --git a/lib/new_relic/agent.rb b/lib/new_relic/agent.rb index 694b2a55c9..7618924f7d 100644 --- a/lib/new_relic/agent.rb +++ b/lib/new_relic/agent.rb @@ -620,16 +620,19 @@ def tl_is_execution_traced? def add_custom_attributes(params) # THREAD_LOCAL_ACCESS record_api_supportability_metric(:add_custom_attributes) - if params.is_a?(Hash) - Transaction.tl_current&.add_custom_attributes(params) - - segment = ::NewRelic::Agent::Tracer.current_segment - if segment - add_new_segment_attributes(params, segment) - end - else + unless params.is_a?(Hash) ::NewRelic::Agent.logger.warn("Bad argument passed to #add_custom_attributes. Expected Hash but got #{params.class}") + return end + + if NewRelic::Agent.agent&.serverless? + ::NewRelic::Agent.logger.warn('Custom attributes are not supported in serverless mode') + return + end + + Transaction.tl_current&.add_custom_attributes(params) + segment = ::NewRelic::Agent::Tracer.current_segment + add_new_segment_attributes(params, segment) if segment end def add_new_segment_attributes(params, segment) diff --git a/lib/new_relic/agent/new_relic_service.rb b/lib/new_relic/agent/new_relic_service.rb index b2aab16fa1..467188d455 100644 --- a/lib/new_relic/agent/new_relic_service.rb +++ b/lib/new_relic/agent/new_relic_service.rb @@ -143,6 +143,9 @@ def build_metric_data_array(stats_hash) end def metric_data(stats_hash) + # let the serverless handler handle serialization + return NewRelic::Agent.agent.serverless_handler.metric_data(stats_hash) if NewRelic::Agent.agent.serverless? + timeslice_start = stats_hash.started_at timeslice_end = stats_hash.harvested_at || Process.clock_gettime(Process::CLOCK_REALTIME) metric_data_array = build_metric_data_array(stats_hash) @@ -154,6 +157,9 @@ def metric_data(stats_hash) end def error_data(unsent_errors) + # let the serverless handler handle serialization + return NewRelic::Agent.agent.serverless_handler.error_data(unsent_errors) if NewRelic::Agent.agent.serverless? + invoke_remote(:error_data, [@agent_id, unsent_errors], :item_count => unsent_errors.size) end diff --git a/lib/new_relic/agent/serverless_handler.rb b/lib/new_relic/agent/serverless_handler.rb index d927988c2c..90315a81d8 100644 --- a/lib/new_relic/agent/serverless_handler.rb +++ b/lib/new_relic/agent/serverless_handler.rb @@ -8,34 +8,37 @@ module NewRelic module Agent class ServerlessHandler - COLD_START_ATTRIBUTE = 'aws.lambda.coldStart' - COLD_START_DESTINATIONS = NewRelic::Agent::AttributeFilter::DST_TRANSACTION_TRACER | + ATTRIBUTE_ARN = 'aws.lambda.arn' + ATTRIBUTE_COLD_START = 'aws.lambda.coldStart' + ATTRIBUTE_REQUEST_ID = 'aws.requestId' + AGENT_ATTRIBUTE_DESTINATIONS = NewRelic::Agent::AttributeFilter::DST_TRANSACTION_TRACER | NewRelic::Agent::AttributeFilter::DST_TRANSACTION_EVENTS EXECUTION_ENVIRONMENT = "AWS_Lambda_ruby#{RUBY_VERSION.rpartition('.').first}".freeze LAMBDA_MARKER = 'NR_LAMBDA_MONITORING' LAMBDA_ENVIRONMENT_VARIABLE = 'AWS_LAMBDA_FUNCTION_NAME' - METADATA_VERSION = 2 # internal to New Relic's cross-agent specs - METHOD_BLOCKLIST = %i[connect preconnect shutdown profile_data get_agent_commands agent_command_results].freeze + METHOD_BLOCKLIST = %i[agent_command_results connect get_agent_commands preconnect profile_data + shutdown].freeze NAMED_PIPE = '/tmp/newrelic-telemetry' SUPPORTABILITY_METRIC = 'Supportability/AWSLambda/HandlerInvocation' FUNCTION_NAME = 'lambda_function' - VERSION = 2 # internal to New Relic's cross-agent specs + PAYLOAD_VERSION = ENV.fetch('NEW_RELIC_SERVERLESS_PAYLOAD_VERSION', 2) def self.env_var_set? ENV.key?(LAMBDA_ENVIRONMENT_VARIABLE) end def initialize + @context = nil @payloads = {} end def invoke_lambda_function_with_new_relic(event:, context:, method_name:, namespace: nil) NewRelic::Agent.increment_metric(SUPPORTABILITY_METRIC) - parse_context(context) + @context = context NewRelic::Agent::Tracer.in_transaction(category: :other, name: function_name) do - notice_cold_start + add_agent_attributes NewRelic::LanguageSupport.constantize(namespace).send(method_name, event: event, context: context) end @@ -51,6 +54,36 @@ def store_payload(method, payload) @payloads[method] = payload end + def metric_data(stats_hash) + payload = [nil, + stats_hash.started_at, + (stats_hash.harvested_at || Process.clock_gettime(Process::CLOCK_REALTIME)), + []] + stats_hash.each do |metric_spec, stats| + next if stats.is_reset? + + hash = {name: metric_spec.name} + hash[:scope] = metric_spec.scope unless metric_spec.scope.empty? + + payload.last.push([hash, [ + stats.call_count, + stats.total_call_time, + stats.total_exclusive_time, + stats.min_call_time, + stats.max_call_time, + stats.sum_of_squares + ]]) + end + + return if payload.last.empty? + + store_payload(:metric_data, payload) + end + + def error_data(errors) + store_payload(:error_data, [nil, errors.map(&:to_collector_array)]) + end + private def harvest! @@ -60,23 +93,11 @@ def harvest! end def metadata - {arn: @function_arn, + {arn: @context.invoked_function_arn, protocol_version: NewRelic::Agent::NewRelicService::PROTOCOL_VERSION, - function_version: @function_version, + function_version: @context.function_version, execution_environment: EXECUTION_ENVIRONMENT, - agent_version: NewRelic::VERSION::STRING, - metadata_version: METADATA_VERSION, - agent_language: LANGUAGE}.reject { |_k, v| v.nil? } - end - - def parse_context(context) - @function_arn = nil - @function_version = nil - return unless context - return unless context.respond_to?(:function_arn) && context.respond_to?(:function_version) - - @function_arn = context.function_arn - @function_version = context.function_version + agent_version: NewRelic::VERSION::STRING} end def function_name @@ -84,15 +105,31 @@ def function_name end def write_output - json = NewRelic::Agent.agent.service.marshaller.dump(@payloads) - gzipped = NewRelic::Agent::NewRelicService::Encoders::Compressed::Gzip.encode(json) - base64_encoded = NewRelic::Base64.encode64(gzipped) - array = [VERSION, LAMBDA_MARKER, metadata, base64_encoded] - string = ::JSON.dump(array) + string = PAYLOAD_VERSION == 1 ? payload_v1 : payload_v2 return puts string unless use_named_pipe? - File.open(NAMED_PIPE, 'w') { |f| f.puts string } + File.write(NAMED_PIPE, string) + + NewRelic::Agent.logger.debug "Wrote serverless payload to #{NAMED_PIPE}\n" \ + "BEGIN PAYLOAD>>>\n#{string}\n<< metadata, 'data' => @payloads} + json = NewRelic::Agent.agent.service.marshaller.dump(payload_hash) + gzipped = NewRelic::Agent::NewRelicService::Encoders::Compressed::Gzip.encode(json) + base64_encoded = NewRelic::Base64.strict_encode64(gzipped) + array = [PAYLOAD_VERSION, LAMBDA_MARKER, base64_encoded] + ::JSON.dump(array) + end + + def payload_v2 + json = NewRelic::Agent.agent.service.marshaller.dump(@payloads) + gzipped = NewRelic::Agent::NewRelicService::Encoders::Compressed::Gzip.encode(json) + base64_encoded = NewRelic::Base64.strict_encode64(gzipped) + array = [PAYLOAD_VERSION, LAMBDA_MARKER, metadata, base64_encoded] + ::JSON.dump(array) end def use_named_pipe? @@ -101,12 +138,16 @@ def use_named_pipe? @use_named_pipe = File.exist?(NAMED_PIPE) && File.writable?(NAMED_PIPE) end - def notice_cold_start - return unless cold? && NewRelic::Agent::Tracer.current_transaction + def add_agent_attributes + return unless NewRelic::Agent::Tracer.current_transaction + + add_agent_attribute(ATTRIBUTE_COLD_START, true) if cold? + add_agent_attribute(ATTRIBUTE_ARN, @context.invoked_function_arn) + add_agent_attribute(ATTRIBUTE_REQUEST_ID, @context.aws_request_id) + end - NewRelic::Agent::Tracer.current_transaction.add_agent_attribute(COLD_START_ATTRIBUTE, - true, - COLD_START_DESTINATIONS) + def add_agent_attribute(attribute, value) + NewRelic::Agent::Tracer.current_transaction.add_agent_attribute(attribute, value, AGENT_ATTRIBUTE_DESTINATIONS) end def cold? @@ -117,6 +158,7 @@ def cold? end def reset! + @context = nil @payloads.replace({}) end end diff --git a/test/new_relic/agent/serverless_handler_test.rb b/test/new_relic/agent/serverless_handler_test.rb index c7b93b20cb..9860911a6e 100644 --- a/test/new_relic/agent/serverless_handler_test.rb +++ b/test/new_relic/agent/serverless_handler_test.rb @@ -69,10 +69,15 @@ def test_rescued_errors_are_noticed end end + errors = output.last['error_data'].last + + assert_equal 1, errors.size + assert_equal 'lambda_function', errors.first[1] + assert_equal 'Kaboom!', errors.first[2] assert_equal 'Kaboom!', output.last['error_event_data'].last.first.first['error.message'] end - def test_log_events_and_reported + def test_log_events_are_reported output = with_output do handler.invoke_lambda_function_with_new_relic(method_name: :customer_lambda_function, event: {simulate_logging: true}, @@ -82,19 +87,6 @@ def test_log_events_and_reported assert_match 'languidly', output.last['log_event_data'].first['logs'].first['message'] end - def test_errors_and_logs_at_the_same_time_man - output = with_output do - assert_raises RuntimeError do - handler.invoke_lambda_function_with_new_relic(method_name: :customer_lambda_function, - event: {simulate_exception: true, simulate_logging: true}, - context: testing_context) - end - end - - assert_equal 1, output.last['error_data'].last.size - assert_equal 1, output.last['log_event_data'].first['logs'].size - end - def test_customer_function_lives_within_a_namespace context = testing_context output = with_output do @@ -111,6 +103,65 @@ def test_customer_function_lives_within_a_namespace assert_match(/lambda_function/, output.to_s) end + def test_agent_attributes_are_present + context = testing_context + output = with_output do + result = handler.invoke_lambda_function_with_new_relic(method_name: :customer_lambda_function, + event: {}, + context: context) + + assert_equal 'Running just as fast as we can', result[:body] + end + context.verify + agent_attributes_hash = output.last['analytic_event_data'].last.last.last + + assert agent_attributes_hash.key?('aws.lambda.arn') + assert agent_attributes_hash.key?('aws.requestId') + end + + def test_metric_data_adheres_to_the_agent_specs + output = with_output do + handler.invoke_lambda_function_with_new_relic(method_name: :customer_lambda_function, + event: {}, + context: testing_context) + end + metric_data = output.last['metric_data'] + + assert_kind_of Array, metric_data + assert_equal 4, metric_data.size + refute metric_data.first # agent run id + assert_kind_of Float, metric_data[1] # start time + assert_kind_of Float, metric_data[2] # stop time + assert_kind_of Array, metric_data.last # array of metrics arrays + refute metric_data.last.any? { |metric| metric.first.key?('scope') && metric.first['scope'].empty? }, + "Did not expect to find any metrics with a nil 'scope' value!" + + single_metric = metric_data.last.first + + assert_kind_of Array, single_metric + assert_equal 2, single_metric.size + assert_kind_of Hash, single_metric.first + assert_kind_of Array, single_metric.last + assert_equal 6, single_metric.last.size + end + + def test_support_for_payload_format_v1 + NewRelic::Agent::ServerlessHandler.stub_const(:PAYLOAD_VERSION, 1) do + output = with_output do + result = handler.invoke_lambda_function_with_new_relic(method_name: :customer_lambda_function, + event: {por_que_no: :los_dos}, + context: testing_context) + + assert_equal 'Running just as fast as we can', result[:body] + end + + assert_equal 1, output.first, "Expected to find a payload version of '1', got #{output.first}" + assert output.last.key?('metadata'), "Expected a v1 payload format with a 'metadata' key!" + assert_equal 4, output.last['data']['metric_data'].size + assert_match(/lambda_function/, output.to_s) + end + end + # unit style def test_named_pipe_check_true @@ -190,6 +241,7 @@ def test_output_hits_the_named_pipe_when_available temp = Tempfile.new('lambda_named_pipe') NewRelic::Agent::ServerlessHandler.stub_const(:NAMED_PIPE, temp.path) do + handler.instance_variable_set(:@context, testing_context) handler.send(:write_output) end @@ -201,41 +253,6 @@ def test_output_hits_the_named_pipe_when_available temp.unlink end - def test_handle_a_nil_context - h = fresh_handler - h.send(:parse_context, nil) - - assert_nil h.instance_variable_get(:@function_arn) - assert_nil h.instance_variable_get(:@function_method) - end - - def test_handle_a_context_that_does_not_respond_to_arn_and_method_calls - h = fresh_handler - h.send(:parse_context, :bogus_context) - - assert_nil h.instance_variable_get(:@function_arn) - assert_nil h.instance_variable_get(:@function_method) - end - - def test_notice_cold_start_only_does_work_when_cold - h = fresh_handler - def h.cold?; false; end - - NewRelic::Agent::Tracer.stub :current_transaction, -> { raise 'kaboom' } do - # because cold is false, the raise won't be reached - h.send(:notice_cold_start) - end - end - - def test_notice_cold_start_only_does_work_with_a_current_transaction_present - h = fresh_handler - def h.cold?; true; end - - NewRelic::Agent::Tracer.stub :current_transaction, nil do - h.send(:notice_cold_start) - end - end - def test_store_payload method = :br_2049 payload = 'little red bear' @@ -251,6 +268,27 @@ def test_store_payload_short_circuits_for_non_serverless_appropriate_methods assert_empty handler.instance_variable_get(:@payloads) end + def test_agent_attributes_arent_set_without_a_transaction + refute fresh_handler.send(:add_agent_attributes) + end + + def test_custom_attributes_arent_supported_when_serverless + skip_unless_minitest5_or_above + + attrs = {cool_id: 'James', server: 'less', current_time: Time.now.to_s} + tl_current_mock = Minitest::Mock.new + tl_current_mock.expect :add_custom_attributes, -> { attribute_set_attempted = true }, [attrs] + + attribute_set_attempted = false + in_transaction do + Transaction.stub :tl_current, tl_current_mock do + ::NewRelic::Agent.add_custom_attributes(attrs) + end + end + + refute attribute_set_attempted + end + private def handler @@ -258,15 +296,20 @@ def handler end def fresh_handler - NewRelic::Agent::ServerlessHandler.new + h = NewRelic::Agent::ServerlessHandler.new + h.instance_variable_set(:@context, testing_context) + h end def testing_context - function_arn = 'Resident Alien' + invoked_function_arn = 'Resident Alien' function_version = '1138' + aws_request_id = 'microkelvin' context = Minitest::Mock.new - context.expect :function_arn, function_arn + context.expect :invoked_function_arn, invoked_function_arn + context.expect :invoked_function_arn, invoked_function_arn context.expect :function_version, function_version + context.expect :aws_request_id, aws_request_id end def with_output(&block)