Use native ruby logging capabilities for OGM tasks

Closes #138

Author: thatbudakguy

lib/geo_combine/geo_blacklight_harvester.rb

@@ -1,5 +1,7 @@
 # frozen_string_literal: true
 
+require 'geo_combine/logger'
+
 module GeoCombine
   ##
   # A class to harvest and index results from GeoBlacklight sites
@@ -45,24 +47,25 @@ def document_transformer
 
     attr_reader :site, :site_key
 
-    def initialize(site_key)
+    def initialize(site_key, logger: GeoCombine::Logger.logger)
       @site_key = site_key
       @site = self.class.config[site_key]
+      @logger = logger
 
       raise ArgumentError, "Site key #{@site_key.inspect} is not configured for #{self.class.name}" unless @site
     end
 
     def index
-      puts "Fetching page 1 @ #{base_url}&page=1" if self.class.config[:debug]
+      @logger.debug "fetching page 1 @ #{base_url}&page=1"
       response = JSON.parse(Net::HTTP.get(URI("#{base_url}&page=1")))
       response_class = BlacklightResponseVersionFactory.call(response)
 
-      response_class.new(response: response, base_url: base_url).documents.each do |docs|
+      response_class.new(response:, base_url:, logger: @logger).documents.each do |docs|
         docs.map! do |document|
           self.class.document_transformer&.call(document)
         end.compact
 
-        puts "Adding #{docs.count} documents to solr" if self.class.config[:debug]
+        @logger.debug "adding #{docs.count} documents to solr"
         solr_connection.update params: { commitWithin: commit_within, overwrite: true },
                                data: docs.to_json,
                                headers: { 'Content-Type' => 'application/json' }
@@ -91,10 +94,11 @@ class LegacyBlacklightResponse
       attr_reader :base_url
       attr_accessor :response, :page
 
-      def initialize(response:, base_url:)
+      def initialize(response:, base_url:, logger: GeoCombine::Logger.logger)
         @base_url = base_url
         @response = response
         @page = 1
+        @logger = logger
       end
 
       def documents
@@ -106,12 +110,12 @@ def documents
           break if current_page == total_pages
 
           self.page += 1
-          puts "Fetching page #{page} @ #{url}" if GeoCombine::GeoBlacklightHarvester.config[:debug]
+          @logger.debug "fetching page #{page} @ #{url}"
 
           begin
             self.response = JSON.parse(Net::HTTP.get(URI(url)))
           rescue StandardError => e
-            puts "Request for #{url} failed with #{e}"
+            @logger.error "request for #{url} failed with #{e}"
             self.response = nil
           end
         end
@@ -138,10 +142,11 @@ class ModernBlacklightResponse
       attr_reader :base_url
       attr_accessor :response, :page
 
-      def initialize(response:, base_url:)
+      def initialize(response:, base_url:, logger: GeoCombine::Logger.logger)
         @base_url = base_url
         @response = response
         @page = 1
+        @logger = logger
       end
 
       def documents
@@ -157,11 +162,11 @@ def documents
 
           url = "#{url}&format=json"
           self.page += 1
-          puts "Fetching page #{page} @ #{url}" if GeoCombine::GeoBlacklightHarvester.config[:debug]
+          @logger.debug "fetching page #{page} @ #{url}"
           begin
             self.response = JSON.parse(Net::HTTP.get(URI(url)))
           rescue StandardError => e
-            puts "Request for #{url} failed with #{e}"
+            @logger.error "Request for #{url} failed with #{e}"
             self.response = nil
           end
         end
@@ -170,11 +175,11 @@ def documents
       private
 
       def documents_from_urls(urls)
-        puts "Fetching #{urls.count} documents for page #{page}" if GeoCombine::GeoBlacklightHarvester.config[:debug]
+        @logger.debug "fetching #{urls.count} documents for page #{page}"
         urls.map do |url|
           JSON.parse(Net::HTTP.get(URI("#{url}/raw")))
         rescue StandardError => e
-          puts "Fetching \"#{url}/raw\" failed with #{e}"
+          @logger.error "fetching \"#{url}/raw\" failed with #{e}"
 
           nil
         end.compact

lib/geo_combine/harvester.rb

@@ -4,6 +4,7 @@
 require 'find'
 require 'git'
 require 'net/http'
+require 'geo_combine/logger'
 
 module GeoCombine
   # Harvests Geoblacklight documents from OpenGeoMetadata for indexing
@@ -30,26 +31,37 @@ def self.ogm_api_uri
 
     def initialize(
       ogm_path: ENV.fetch('OGM_PATH', 'tmp/opengeometadata'),
-      schema_version: ENV.fetch('SCHEMA_VERSION', '1.0')
+      schema_version: ENV.fetch('SCHEMA_VERSION', '1.0'),
+      logger: GeoCombine::Logger.logger
     )
       @ogm_path = ogm_path
       @schema_version = schema_version
+      @logger = logger
     end
 
     # Enumerable of docs to index, for passing to an indexer
     def docs_to_index
       return to_enum(:docs_to_index) unless block_given?
 
+      @logger.info "loading documents from #{ogm_path}"
       Find.find(@ogm_path) do |path|
         # skip non-json and layers.json files
-        next unless File.basename(path).include?('.json') && File.basename(path) != 'layers.json'
+        if File.basename(path) == 'layers.json' || !File.basename(path).end_with?('.json')
+          @logger.debug "skipping #{path}; not a geoblacklight JSON document"
+          next
+        end
 
         doc = JSON.parse(File.read(path))
         [doc].flatten.each do |record|
           # skip indexing if this record has a different schema version than what we want
           record_schema = record['gbl_mdVersion_s'] || record['geoblacklight_version']
-          next unless record_schema == @schema_version
+          record_id = record['layer_slug_s'] || record['dc_identifier_s']
+          if record_schema != @schema_version
+            @logger.debug "skipping #{record_id}; schema version #{record_schema} doesn't match #{@schema_version}"
+            next
+          end
 
+          @logger.debug "found record #{record_id} at #{path}"
           yield record, path
         end
       end
@@ -62,40 +74,44 @@ def pull(repo)
       clone(repo) unless File.directory? repo_path
 
       Git.open(repo_path).pull
-      puts "Updated #{repo}"
-      1
+      @logger.info "updated #{repo}"
+      repo
     end
 
     # Update all repositories
-    # Return the count of repositories updated
+    # Return the names of repositories updated
     def pull_all
-      repositories.map(&method(:pull)).reduce(:+)
+      updated = repositories.map(&method(:pull)).compact
+      @logger.info "updated #{updated.size} repositories"
+      updated
     end
 
     # Clone a repository via git
     # If the repository already exists, skip it.
     def clone(repo)
       repo_path = File.join(@ogm_path, repo)
       repo_info = repository_info(repo)
+      repo_url = "https://github.com/OpenGeoMetadata/#{repo}.git"
 
       # Skip if exists; warn if archived or empty
       if File.directory? repo_path
-        puts "Skipping clone to #{repo_path}; directory exists"
-        return 0
+        @logger.warn "skipping clone to #{repo_path}; directory exists"
+        return nil
       end
-      puts "WARNING: repository '#{repo}' is archived" if repo_info['archived']
-      puts "WARNING: repository '#{repo}' is empty" if repo_info['size'].zero?
+      @logger.warn "repository is archived: #{repo_url}" if repo_info['archived']
+      @logger.warn "repository is empty: #{repo_url}" if repo_info['size'].zero?
 
-      repo_url = "https://github.com/OpenGeoMetadata/#{repo}.git"
       Git.clone(repo_url, nil, path: ogm_path, depth: 1)
-      puts "Cloned #{repo_url}"
-      1
+      @logger.info "cloned #{repo_url} to #{repo_path}"
+      repo
     end
 
     # Clone all repositories via git
-    # Return the count of repositories cloned.
+    # Return the names of repositories cloned.
     def clone_all
-      repositories.map(&method(:clone)).reduce(:+)
+      cloned = repositories.map(&method(:clone)).compact
+      @logger.info "cloned #{cloned.size} repositories"
+      cloned
     end
 
     private

lib/geo_combine/logger.rb

@@ -0,0 +1,16 @@
+# frozen_string_literal: true
+
+require 'logger'
+
+module GeoCombine
+  # Logger for gem
+  class Logger
+    def self.logger
+      @logger ||= ::Logger.new(
+        $stderr,
+        progname: 'GeoCombine',
+        level: ENV.fetch('LOG_LEVEL', 'info').to_sym
+      )
+    end
+  end
+end

lib/tasks/geo_combine.rake

@@ -12,24 +12,20 @@ namespace :geocombine do
   desc 'Clone OpenGeoMetadata repositories'
   task :clone, [:repo] do |_t, args|
     harvester = GeoCombine::Harvester.new
-    total = args[:repo] ? harvester.clone(args.repo) : harvester.clone_all
-    puts "Cloned #{total} repositories"
+    args[:repo] ? harvester.clone(args.repo) : harvester.clone_all
   end
 
   desc '"git pull" OpenGeoMetadata repositories'
   task :pull, [:repo] do |_t, args|
     harvester = GeoCombine::Harvester.new
-    total = args[:repo] ? harvester.pull(args.repo) : harvester.pull_all
-    puts "Updated #{total} repositories"
+    args[:repo] ? harvester.pull(args.repo) : harvester.pull_all
   end
 
   desc 'Index all JSON documents except Layers.json'
   task :index do
     harvester = GeoCombine::Harvester.new
     indexer = GeoCombine::Indexer.new
-    puts "Indexing #{harvester.ogm_path} into #{indexer.solr_url}"
-    total = indexer.index(harvester.docs_to_index)
-    puts "Indexed #{total} documents"
+    indexer.index(harvester.docs_to_index)
   end
 
   namespace :geoblacklight_harvester do

spec/lib/geo_combine/geo_blacklight_harvester_spec.rb

@@ -5,8 +5,9 @@
 require 'rsolr'
 
 RSpec.describe GeoCombine::GeoBlacklightHarvester do
-  subject(:harvester) { described_class.new(site_key) }
+  subject(:harvester) { described_class.new(site_key, logger:) }
 
+  let(:logger) { instance_double(Logger, warn: nil, info: nil, error: nil, debug: nil) }
   let(:site_key) { :INSTITUTION }
   let(:stub_json_response) { '{}' }
   let(:stub_solr_connection) { double('RSolr::Connection') }
@@ -40,7 +41,7 @@
 
     let(:docs) { [{ layer_slug_s: 'abc-123' }, { layer_slug_s: 'abc-321' }] }
     let(:stub_json_response) do
-      { response: { docs: docs, pages: { current_page: 1, total_pages: 1 } } }.to_json
+      { response: { docs:, pages: { current_page: 1, total_pages: 1 } } }.to_json
     end
 
     it 'adds documents returned to solr' do
@@ -142,7 +143,7 @@
         ).and_return(stub_second_response.to_json)
         base_url = 'https://example.com?f%5Bdct_provenance_s%5D%5B%5D=INSTITUTION&format=json&per_page=100'
         docs = described_class::LegacyBlacklightResponse.new(response: stub_first_response,
-                                                             base_url: base_url).documents
+                                                             base_url:).documents
 
         expect(docs.to_a).to eq([first_docs, second_docs])
       end
@@ -182,7 +183,7 @@
 
         base_url = 'https://example.com?f%5Bdct_provenance_s%5D%5B%5D=INSTITUTION&format=json&per_page=100'
         docs = described_class::ModernBlacklightResponse.new(response: first_results_response,
-                                                             base_url: base_url).documents
+                                                             base_url:).documents
 
         expect(docs.to_a).to eq([
                                   [{ 'layer_slug_s' => 'abc-123' }, { 'layer_slug_s' => 'abc-321' }],

spec/lib/geo_combine/harvester_spec.rb

@@ -5,8 +5,9 @@
 require 'spec_helper'
 
 RSpec.describe GeoCombine::Harvester do
-  subject(:harvester) { described_class.new(ogm_path: 'spec/fixtures/indexing') }
+  subject(:harvester) { described_class.new(ogm_path: 'spec/fixtures/indexing', logger:) }
 
+  let(:logger) { instance_double(Logger, warn: nil, info: nil, error: nil, debug: nil) }
   let(:repo_name) { 'my-institution' }
   let(:repo_path) { File.join(harvester.ogm_path, repo_name) }
   let(:repo_url) { "https://github.com/OpenGeoMetadata/#{repo_name}.git" }
@@ -47,7 +48,7 @@
     end
 
     it 'skips records with a different schema version' do
-      harvester = described_class.new(ogm_path: 'spec/fixtures/indexing/', schema_version: 'Aardvark')
+      harvester = described_class.new(ogm_path: 'spec/fixtures/indexing/', schema_version: 'Aardvark', logger:)
       expect { |b| harvester.docs_to_index(&b) }.to yield_successive_args(
         [JSON.parse(File.read('spec/fixtures/indexing/aardvark.json')), 'spec/fixtures/indexing/aardvark.json']
       )
@@ -74,8 +75,8 @@
       expect(stub_repo).to have_received(:pull).exactly(2).times
     end
 
-    it 'returns the count of repositories pulled' do
-      expect(harvester.pull_all).to eq(2)
+    it 'returns the names of repositories pulled' do
+      expect(harvester.pull_all).to eq(%w[my-institution another-institution])
     end
 
     it 'skips repositories in the denylist' do
@@ -106,20 +107,6 @@
       harvester.clone(repo_name)
       expect(Git).not_to have_received(:clone)
     end
-
-    it 'warns if a repository is empty' do
-      allow(Net::HTTP).to receive(:get).with('https://api.github.com/repos/opengeometadata/empty').and_return('{"size": 0}')
-      expect do
-        harvester.clone('empty')
-      end.to output(/repository 'empty' is empty/).to_stdout
-    end
-
-    it 'warns if a repository is archived' do
-      allow(Net::HTTP).to receive(:get).with('https://api.github.com/repos/opengeometadata/empty').and_return('{"archived": true}')
-      expect do
-        harvester.clone('outdated-institution')
-      end.to output(/repository 'outdated-institution' is archived/).to_stdout
-    end
   end
 
   describe '#clone_all' do
@@ -133,8 +120,8 @@
       expect(Git).not_to have_received(:clone).with('https://github.com/OpenGeoMetadata/aardvark.git')
     end
 
-    it 'returns the count of repositories cloned' do
-      expect(harvester.clone_all).to eq(2)
+    it 'returns the names of repositories cloned' do
+      expect(harvester.clone_all).to eq(%w[my-institution another-institution])
     end
   end