Error logging on: Contact registrant: Domain registry contact error

Dockerfile.staging

@@ -38,6 +38,8 @@ RUN bundle config set --local without 'development test' && \
 
 # Copy application code
 COPY . .
+COPY config/application-example.yml config/application.yml
+COPY config/database-example.yml config/database.yml
 
 # Precompile assets
 RUN RAILS_ENV=production bundle exec rake assets:precompile

app/services/registry_connector.rb

@@ -7,17 +7,20 @@ class RegistryConnector
   attr_accessor :request
 
   def self.perform_request(request, url)
-    @response = Net::HTTP.start(url.host, url.port,
-                                use_ssl: url.scheme == 'https') do |http|
+    response = Net::HTTP.start(url.host, url.port, use_ssl: url.scheme == 'https') do |http|
       http.request(request)
     end
 
-    @body_as_string = @response.body
-    @code_as_string = @response.code.to_s
-
-    return JSON.parse(@body_as_string) if [HTTP_CREATED, HTTP_SUCCESS].include? @code_as_string
-
-    raise CommunicationError.new(request, @code_as_string)
+    handle_response(response, request)
+  rescue Timeout::Error, SocketError, Errno::ECONNREFUSED => e
+    log_error(e, request, url, 'network_error')
+    false
+  rescue CommunicationError => e
+    log_error(e, request, url, 'communication_error', e.response)
+    false
+  rescue StandardError => e
+    log_error(e, request, url, 'unexpected_error')
+    false
   end
 
   def self.request(url:, type:)
@@ -33,17 +36,13 @@ def self.do_save(data)
     request = request(url: url, type: :post)
     request.body = { contact_request: data }.to_json
     perform_request(request, url)
-  rescue CommunicationError
-    false
   end
 
   def self.do_update(id:, data:)
     url = URI.join(BASE_URL, id.to_s)
     request = request(url: url, type: :put)
     request.body = { contact_request: data }.to_json
     perform_request(request, url)
-  rescue CommunicationError
-    false
   end
 
   def self.request_by_type(type)
@@ -54,4 +53,54 @@ def self.request_by_type(type)
       Net::HTTP::Put
     end
   end
+
+  def self.logger
+    Rails.logger
+  end
+
+  private_class_method
+
+  def self.handle_response(response, request)
+    if [HTTP_CREATED, HTTP_SUCCESS].include?(response.code.to_s)
+      JSON.parse(response.body)
+    else
+      raise CommunicationError.new(request, response)
+    end
+  end
+
+  def self.log_error(exception, request, url, event, response = nil)
+    logger.error({
+      timestamp: Time.current.utc.iso8601(3),
+      level: 'error',
+      message: "Registry API #{event.gsub('_', ' ')}",
+      event: "registry.api.#{event}",
+      service: 'rest-whois',
+      environment: Rails.env,
+      host: Socket.gethostname,
+      pid: Process.pid,
+      error: {
+        type: exception.class.name,
+        message: exception.message,
+        stack: exception.backtrace&.first(5)&.join(' | ')
+      },
+      details: {
+        url: url.to_s,
+        request_method: request&.method,
+        request_uri: request&.uri,
+        response_body: response&.body
+      },
+      schema_version: '1.0.0',
+      log_version: '1.0.0'
+    }.to_json)
+  end
+end
+
+class CommunicationError < StandardError
+  attr_reader :request, :response
+
+  def initialize(request = nil, response = nil)
+    @request = request
+    @response = response
+    super("Communication failed with status #{response&.code}")
+  end
 end

test/services/registry_connector_test.rb

@@ -0,0 +1,127 @@
+require 'test_helper'
+
+class RegistryConnectorTest < ActiveSupport::TestCase
+  def setup
+    @url = URI('http://registry.test/api/v1/contact_requests/')
+    @request = Net::HTTP::Post.new(@url)
+    @request.body = { contact_request: { email: 'test@example.com' } }.to_json
+    @logger = create_logger_spy
+  end
+
+  {
+    Timeout::Error => 'network_error',
+    SocketError => 'network_error',
+    Errno::ECONNREFUSED => 'network_error'
+  }.each do |error_class, event_type|
+    test "logs #{event_type} on #{error_class}" do
+      perform_with_http_error(error_class.new('Simulated error')) do |result|
+        assert_not result
+      end
+
+      assert_logged_with_event(event_type)
+    end
+  end
+
+  test "logs communication_error with response body" do
+    response = Net::HTTPBadRequest.new('1.1', '400', 'Bad Request')
+    response.instance_variable_set(:@read, true)
+    response.body = 'Error message'
+
+    http_mock = Minitest::Mock.new
+    http_mock.expect(:request, response, [@request])
+
+    RegistryConnector.stub(:logger, @logger) do
+      Net::HTTP.stub(:start, ->(*_args, &block) { block.call(http_mock) }) do
+        result = RegistryConnector.perform_request(@request, @url)
+        assert_not result
+      end
+    end
+
+    assert_logged_with_event('communication_error')
+    log_data = parse_logged_data
+    assert_equal 'Error message', log_data['details']['response_body']
+  end
+
+  test "logs unexpected_error" do
+    perform_with_http_error(StandardError.new('Unexpected error')) do |result|
+      assert_not result
+    end
+
+    assert_logged_with_event('unexpected_error')
+  end
+
+  test "logged data contains required fields" do
+    perform_with_http_error(Timeout::Error.new('Connection timeout'))
+
+    log_data = parse_logged_data
+
+    assert log_data['timestamp']
+    assert_equal 'error', log_data['level']
+    assert_equal 'registry.api.network_error', log_data['event']
+    assert_equal 'rest-whois', log_data['service']
+    assert_equal Rails.env, log_data['environment']
+    assert log_data['host']
+    assert log_data['pid']
+    assert log_data['error']
+    assert_equal 'Timeout::Error', log_data['error']['type']
+    assert log_data['error']['message']
+    assert log_data['details']
+    assert_equal @url.to_s, log_data['details']['url']
+    assert_equal 'POST', log_data['details']['request_method']
+    assert log_data['schema_version']
+    assert log_data['log_version']
+  end
+
+  test "logged data contains truncated error stack trace" do
+    error = Timeout::Error.new('Connection timeout')
+    error.set_backtrace(['line1', 'line2', 'line3', 'line4', 'line5', 'line6'])
+
+    perform_with_http_error(error)
+
+    log_data = parse_logged_data
+    stack_trace = log_data['error']['stack']
+
+    assert stack_trace
+    assert_match(/line1/, stack_trace)
+    assert_match(/line5/, stack_trace)
+    refute_match(/line6/, stack_trace) 
+  end
+
+  private
+
+  def perform_with_http_error(error)
+    RegistryConnector.stub(:logger, @logger) do
+      Net::HTTP.stub(:start, ->(*_args, &block) { raise error }) do
+        result = RegistryConnector.perform_request(@request, @url)
+        yield result if block_given?
+        result
+      end
+    end
+  end
+
+  def create_logger_spy
+    logged_messages = []
+
+    logger_spy = Object.new
+    logger_spy.define_singleton_method(:error) do |message|
+      logged_messages << message
+    end
+    logger_spy.define_singleton_method(:logged_messages) do
+      logged_messages
+    end
+
+    logger_spy
+  end
+
+  def assert_logged_with_event(event_type)
+    assert @logger.logged_messages.any?, "Expected logger.error to be called"
+
+    log_data = parse_logged_data
+    assert_equal "registry.api.#{event_type}", log_data['event']
+    assert_match(/Registry API #{event_type.gsub('_', ' ')}/, log_data['message'])
+  end
+
+  def parse_logged_data
+    JSON.parse(@logger.logged_messages.last)
+  end
+end