Change log formatting when logging to journald

config/environments/production.rb

@@ -38,18 +38,7 @@
   # Send deprecation notices to registered listeners.
   config.active_support.deprecation = :notify
 
-  # Use default logging formatter so that PID and timestamp are not suppressed.
-  config.log_formatter = ::Logger::Formatter.new
-
-  # Use a different logger for distributed setups.
-  # require 'syslog/logger'
-  # config.logger = ActiveSupport::TaggedLogging.new(Syslog::Logger.new 'app-name')
-
-  if ENV['RAILS_LOG_TO_STDOUT'].present?
-    logger           = ActiveSupport::Logger.new(STDOUT)
-    logger.formatter = config.log_formatter
-    config.logger    = ActiveSupport::TaggedLogging.new(logger)
-  end
+  config.logger = RMT::Logger.new(STDOUT)
 
   # Do not dump schema after migrations.
   config.active_record.dump_schema_after_migration = false

lib/rmt/downloader.rb

@@ -14,13 +14,13 @@ class NotModifiedException < RuntimeError; end
 
   attr_accessor :repository_url, :destination_dir, :concurrency, :logger, :auth_token, :cache_dir
 
-  def initialize(repository_url:, destination_dir:, auth_token: nil, logger: nil, cache_dir: nil, save_for_dedup: true)
+  def initialize(repository_url:, destination_dir:, logger:, auth_token: nil, cache_dir: nil, save_for_dedup: true)
     Typhoeus::Config.user_agent = "RMT/#{RMT::VERSION}"
     @repository_url = repository_url
     @destination_dir = destination_dir
     @concurrency = 4
     @auth_token = auth_token
-    @logger = logger || Logger.new('/dev/null')
+    @logger = logger
     @cache_dir = cache_dir
     @save_for_dedup = save_for_dedup
   end

lib/rmt/logger.rb

@@ -0,0 +1,12 @@
+class RMT::Logger < ActiveSupport::Logger
+  def initialize(dest)
+    super(dest)
+    self.formatter = if ENV['LOG_TO_JOURNALD'].present?
+                       proc do |severity, _time, _progname, msg|
+                         "#{severity}: #{msg}\n"
+                       end
+                     else
+                       ::Logger::Formatter.new
+                     end
+  end
+end

lib/rmt/mirror.rb

@@ -8,11 +8,11 @@ class RMT::Mirror
   class RMT::Mirror::Exception < RuntimeError
   end
 
-  def initialize(mirroring_base_dir:, repository_url:, local_path:, mirror_src: false, auth_token: nil, logger: nil, to_offline: false)
+  def initialize(mirroring_base_dir:, repository_url:, local_path:, logger:, mirror_src: false, auth_token: nil, to_offline: false)
     @repository_dir = File.join(mirroring_base_dir, local_path)
     @repository_url = repository_url
     @mirror_src = mirror_src
-    @logger = logger || Logger.new('/dev/null')
+    @logger = logger
     @primary_files = []
     @deltainfo_files = []
     @auth_token = auth_token
@@ -49,7 +49,7 @@ def self.from_url(uri, auth_token, repository_url: nil, base_dir: nil, to_offlin
       auth_token: auth_token,
       local_path: Repository.make_local_path(repository_url),
       mirror_src: Settings.mirroring.mirror_src,
-      logger: Logger.new(STDOUT),
+      logger: RMT::Logger.new(STDOUT),
       to_offline: to_offline
     )
   end

lib/rmt/scc.rb

@@ -1,4 +1,5 @@
 require 'rmt/config'
+require 'rmt/logger'
 require 'suse/connect/api'
 
 class RMT::SCC
@@ -7,7 +8,7 @@ class CredentialsError < RuntimeError; end
   class DataFilesError < RuntimeError; end
 
   def initialize(options = {})
-    @logger = Logger.new(STDOUT)
+    @logger = RMT::Logger.new(STDOUT)
     @logger.level = (options[:debug]) ? Logger::DEBUG : Logger::INFO
   end
 

package/rmt-migration.service

@@ -7,6 +7,7 @@ Before=rmt.service
 [Service]
 Type=oneshot
 User=_rmt
+Environment=LOG_TO_JOURNALD=1
 WorkingDirectory=/usr/share/rmt
 ExecStart=/usr/share/rmt/bin/rails db:create db:migrate RAILS_ENV=production
 

package/rmt-server-mirror.service

@@ -6,6 +6,7 @@ Requires=rmt.service
 [Service]
 Type=simple
 Restart=no
+Environment=LOG_TO_JOURNALD=1
 ExecStart=/usr/share/rmt/bin/rmt-cli mirror
 
 [Install]

package/rmt-server-sync.service

@@ -6,6 +6,7 @@ Requires=rmt.service
 [Service]
 Type=simple
 Restart=no
+Environment=LOG_TO_JOURNALD=1
 ExecStart=/usr/share/rmt/bin/rmt-cli sync
 
 [Install]

package/rmt.service

@@ -9,7 +9,7 @@ After=rmt-migration.service
 Type=simple
 User=_rmt
 PrivateTmp=yes
-Environment=RAILS_LOG_TO_STDOUT=1
+Environment=LOG_TO_JOURNALD=1
 WorkingDirectory=/usr/share/rmt
 ExecStart=/usr/share/rmt/bin/rails server -e production
 Restart=always

spec/lib/rmt/downloader_spec.rb

@@ -3,7 +3,7 @@
 
 RSpec.describe RMT::Downloader do
   let(:dir) { Dir.mktmpdir }
-  let(:downloader) { described_class.new(repository_url: 'http://example.com', destination_dir: dir) }
+  let(:downloader) { described_class.new(repository_url: 'http://example.com', destination_dir: dir, logger: RMT::Logger.new('/dev/null')) }
   let(:headers) { { 'User-Agent' => "RMT/#{RMT::VERSION}" } }
 
   after do
@@ -80,7 +80,14 @@
     end
 
     context 'with auth_token' do
-      let(:downloader) { described_class.new(repository_url: 'http://example.com', destination_dir: dir, auth_token: 'repo_auth_token') }
+      let(:downloader) do
+        described_class.new(
+          repository_url: 'http://example.com',
+          destination_dir: dir,
+          logger: RMT::Logger.new('/dev/null'),
+          auth_token: 'repo_auth_token'
+        )
+      end
       let(:content) { 'test' }
 
       before do
@@ -107,7 +114,14 @@
     describe '#download with If-Modified-Since' do
       let(:cache_dir) { Dir.mktmpdir }
       let(:repo_dir) { Dir.mktmpdir }
-      let(:downloader) { described_class.new(repository_url: 'http://example.com', destination_dir: repo_dir, cache_dir: cache_dir) }
+      let(:downloader) do
+        described_class.new(
+          repository_url: 'http://example.com',
+          destination_dir: repo_dir,
+          logger: RMT::Logger.new('/dev/null'),
+          cache_dir: cache_dir
+        )
+      end
       let(:time) { Time.utc(2018, 1, 1, 10, 10, 0) }
       let(:if_modified_headers) do
         {
@@ -170,7 +184,7 @@
 
     let(:dir2) { Dir.mktmpdir }
     let(:path) { 'file://' + File.expand_path(file_fixture('dummy_repo/')) + '/' }
-    let(:downloader) { described_class.new(repository_url: path, destination_dir: dir2) }
+    let(:downloader) { described_class.new(repository_url: path, destination_dir: dir2, logger: RMT::Logger.new('/dev/null')) }
 
     # WebMock doesn't work nicely with file://
     around do |example|

spec/lib/rmt/logger_spec.rb

@@ -0,0 +1,35 @@
+require 'rails_helper'
+
+RSpec.describe RMT::Logger do
+  describe 'logging format' do
+    subject(:logger) { described_class.new(log) }
+
+    let(:log) { StringIO.new }
+
+    context 'with env variable' do
+      before do
+        ENV['LOG_TO_JOURNALD'] = '1'
+      end
+
+      it do
+        logger.info('42')
+        log.rewind
+        expect(log.read).to eq("INFO: 42\n")
+      end
+    end
+
+    context 'without env variable' do
+      before do
+        ENV['LOG_TO_JOURNALD'] = nil
+      end
+
+      it do
+        Timecop.freeze(Time.local(2018, 4, 4, 11, 11, 0)) do # rubocop:disable Rails/TimeZone
+          logger.info('42')
+          log.rewind
+          expect(log.read).to eq("I, [2018-04-04T11:11:00.000000 ##{Process.pid}]  INFO -- : 42\n")
+        end
+      end
+    end
+  end
+end

spec/lib/rmt/mirror_spec.rb

@@ -15,6 +15,7 @@
         described_class.new(
           mirroring_base_dir: @tmp_dir,
           repository_url: 'http://localhost/dummy_repo/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_repo',
           mirror_src: false
         )
@@ -40,6 +41,7 @@
         described_class.new(
           mirroring_base_dir: @tmp_dir,
           repository_url: 'http://localhost/dummy_repo/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_repo',
           auth_token: 'repo_auth_token',
           mirror_src: false
@@ -66,6 +68,7 @@
         described_class.new(
           mirroring_base_dir: @tmp_dir,
           repository_url: 'http://localhost/dummy_product/product/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_product/product/',
           auth_token: 'repo_auth_token',
           mirror_src: false
@@ -105,6 +108,7 @@
         described_class.new(
           mirroring_base_dir: mirroring_dir,
           repository_url: 'http://localhost/dummy_product/product/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_product/product/',
           auth_token: 'repo_auth_token',
           mirror_src: false
@@ -138,6 +142,7 @@
           described_class.new(
             mirroring_base_dir: @tmp_dir,
             repository_url: 'http://localhost/dummy_repo/',
+            logger: RMT::Logger.new('/dev/null'),
             local_path: '/dummy_product/product/',
             mirror_src: false
           )
@@ -193,6 +198,7 @@
         described_class.new(
           mirroring_base_dir: @tmp_dir,
           repository_url: 'http://localhost/dummy_product/product/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_product/product/',
           auth_token: 'repo_auth_token',
           mirror_src: false
@@ -202,6 +208,7 @@
         described_class.new(
           mirroring_base_dir: @tmp_dir,
           repository_url: 'http://localhost/dummy_deduped_product/product/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_deduped_product/product/',
           auth_token: 'repo_auth_token',
           mirror_src: false
@@ -326,6 +333,7 @@
         described_class.new(
           mirroring_base_dir: mirroring_dir,
           repository_url: 'http://localhost/dummy_product/product/',
+          logger: RMT::Logger.new('/dev/null'),
           local_path: '/dummy_product/product/',
           auth_token: 'repo_auth_token',
           mirror_src: false