Log subscribers to stdout

Gemfile

@@ -53,7 +53,7 @@ group :assets do
   gem "compass",               "1.0.3"
 end
 
-gem 'cartodb-common', git: 'https://github.com/cartodb/cartodb-common.git', tag: 'v0.4.5'
+gem 'cartodb-common', git: 'https://github.com/cartodb/cartodb-common.git', tag: 'v0.4.6'
 gem 'roo',                     '1.13.2'
 gem 'state_machines-activerecord', '~> 0.5.0'
 gem 'typhoeus',                '1.3.1'

Gemfile.lock

@@ -8,13 +8,14 @@ GIT
 
 GIT
   remote: https://github.com/cartodb/cartodb-common.git
-  revision: aebf468b520da4065ddb2ec6f9ddfdd0fc320de6
-  tag: v0.4.5
+  revision: 608c1f1ced5e8b56f0dda2b315d0f10ff69d778d
+  tag: v0.4.6
   specs:
     cartodb-common (0.4.5)
-      activesupport (>= 4, < 6)
       argon2 (~> 2)
       google-cloud-pubsub (~> 1.2)
+      rails (>= 4, < 6)
+      rollbar
 
 GIT
   remote: https://github.com/kuldeepaggarwal/fake_net_ldap.git

NEWS.md

@@ -25,6 +25,7 @@ Development
 * Data loss on table rename due to GhostTablesManager [#15935](https://github.com/CartoDB/cartodb/pull/15935)
 * Add DO datasets sync size in /me endpoint [#15932](https://github.com/CartoDB/cartodb/pull/15932)
 * Load GoogleMaps library for a map if the owner's query string is available [#15948](https://github.com/CartoDB/cartodb/pull/15948)
+* Log subscribers to STDOUT and fix JSON format [#15957](https://github.com/CartoDB/cartodb/pull/15957)
 
 4.43.0 (2020-11-06)
 -------------------

app/helpers/logger_helper.rb

@@ -18,12 +18,10 @@ module LoggerHelper
 
   def log_error(params = {})
     rails_log(:error, params)
-    send_exception_to_rollbar(params)
   end
 
   def log_fatal(params = {})
     rails_log(:fatal, params)
-    send_exception_to_rollbar(params)
   end
 
   private
@@ -32,32 +30,21 @@ module LoggerHelper
     parsed_params = {}.with_indifferent_access
 
     params.each do |key, value|
-      if value.is_a?(Exception)
-        parsed_params[:exception] = { class: value.class.name, message: value.message, backtrace_hint: value.backtrace&.take(5) }
-        parsed_params[:message] = value.message if params[:message].blank?
-      elsif value.is_a?(::User) || value.is_a?(::Carto::User)
-        parsed_params[key] = value.username
-      elsif value.is_a?(Carto::Organization)
-        parsed_params[key] = value.name
-      else
-        parsed_params[key] = value
-      end
+      parsed_params[key] = case value
+                           when ::User
+                             value.username
+                           when ::Carto::User
+                             value.username
+                           when ::Carto::Organization
+                             value.name
+                           else
+                             value
+                           end
     end
 
     Rails.logger.send(level, log_context.merge(parsed_params))
   end
 
-  def send_exception_to_rollbar(params)
-    exception = params[:exception]
-    message = params[:message]
-
-    if message && exception && exception.is_a?(Exception)
-      Rollbar.error(exception, message)
-    else
-      Rollbar.error(exception || message)
-    end
-  end
-
   # Can be overriden in more specific contexts to add additional information.
   # Example: current_user and request_id in a controller
   def log_context

lib/tasks/central_updates_subscriber.rake

@@ -1,31 +1,36 @@
 namespace :message_broker do
   desc 'Consume messages from subscription "central_cartodb_commands"'
   task cartodb_subscribers: [:environment] do |_task, _args|
-    include ::LoggerHelper
+    begin
+      logger = Carto::Common::Logger.new
 
-    message_broker = Carto::Common::MessageBroker.instance
-    subscription_name = Carto::Common::MessageBroker::Config.instance.central_commands_subscription
-    subscription = message_broker.get_subscription(subscription_name)
-    notifications_topic = message_broker.get_topic(:cartodb_central)
-    central_user_commands = Carto::Subscribers::CentralUserCommands.new(notifications_topic)
+      message_broker = Carto::Common::MessageBroker.new(logger: logger)
+      subscription_name = Carto::Common::MessageBroker::Config.instance.central_commands_subscription
+      subscription = message_broker.get_subscription(subscription_name)
+      notifications_topic = message_broker.get_topic(:cartodb_central)
+      central_user_commands = Carto::Subscribers::CentralUserCommands.new(notifications_topic)
 
-    subscription.register_callback(:update_user,
-                                   &central_user_commands.method(:update_user))
+      subscription.register_callback(:update_user,
+                                     &central_user_commands.method(:update_user))
 
-    subscription.register_callback(:create_user,
-                                   &central_user_commands.method(:create_user))
+      subscription.register_callback(:create_user,
+                                     &central_user_commands.method(:create_user))
 
-    subscription.register_callback(:delete_user,
-                                   &central_user_commands.method(:delete_user))
+      subscription.register_callback(:delete_user,
+                                     &central_user_commands.method(:delete_user))
 
-    at_exit do
-      log_debug(message: 'Stopping subscriber...')
-      subscription.stop!
-      log_debug(message: 'Done')
-    end
+      at_exit do
+        logger.info(message: 'Stopping subscriber...')
+        subscription.stop!
+        logger.info(message: 'Done')
+      end
 
-    subscription.start
-    log_debug(message: 'Consuming messages from subscription')
-    sleep
+      subscription.start
+      logger.info(message: 'Consuming messages from subscription')
+      sleep
+    rescue StandardError => e
+      logger.error(exception: e)
+      exit(1)
+    end
   end
 end

spec/helpers/logger_helper_spec.rb

@@ -1,10 +1,13 @@
 require 'spec_helper'
 require './app/helpers/logger_helper'
 
-describe LoggerHelper do
+class MockObject
+
+  include LoggerHelper
 
-  class MockObject; include LoggerHelper end
+end
 
+describe LoggerHelper do
   before { User.any_instance.stubs(:update_in_central).returns(true) }
 
   let(:mock_object) { MockObject.new }
@@ -24,24 +27,6 @@ describe LoggerHelper do
 
       mock_object.log_warning(message: 'Message')
     end
-
-    it 'reports plain error message to Rollbar' do
-      Rollbar.expects(:error).with('Custom error message')
-
-      mock_object.log_error(message: 'Custom error message')
-    end
-
-    it 'reports exceptions to Rollbar' do
-      Rollbar.expects(:error).with(exception)
-
-      mock_object.log_error(exception: exception)
-    end
-
-    it 'reports exceptions with custom message to Rollbar' do
-      Rollbar.expects(:error).with(exception, 'Message')
-
-      mock_object.log_error(message: 'Message', exception: exception)
-    end
   end
 
   describe 'serialization' do
@@ -79,15 +64,5 @@ describe LoggerHelper do
 
       mock_object.log_info(message: 'Message', organization: carto_organization)
     end
-
-    it 'serializes Exception objects' do
-      Rails.logger.expects(:error).with(
-        'message' => 'Message',
-        'exception' => { 'class' => 'StandardError', 'message' => 'Exception message', 'backtrace_hint' => nil }
-      )
-
-      mock_object.log_error(message: 'Message', exception: exception)
-    end
   end
-
 end

spec/models/common_data_spec.rb

@@ -29,17 +29,10 @@ describe CommonData do
 
   it 'should return empty datasets and notify error for invalid json' do
     stub_api_response(200, INVALID_JSON_RESPONSE)
-    JSON::ParserError.any_instance.stubs(:backtrace).returns(%w(line_1 line_2))
 
     Rails.logger.expects(:error).with(
-      'exception' => {
-        'class' => 'JSON::ParserError',
-        'message' => '784: unexpected token at \'{\'',
-        'backtrace_hint' => ['line_1', 'line_2']
-      },
-      'message' => '784: unexpected token at \'{\''
+      has_entries('exception' => is_a(JSON::ParserError))
     )
-
     Rails.logger.expects(:error).with('message' => 'common-data empty', 'url' => common_data_url)
 
     expect(@common_data.datasets).to be_empty