Experimental code commit

Introduces wisper, resque jobs to process long-runing tasks

Gemfile

@@ -58,6 +58,9 @@ gem "sentry-ruby"
 gem "possessive"
 # Strip whitespace from active record attributes
 gem "auto_strip_attributes"
+# Background job processing
+gem 'resque', '~> 2.4'
+gem 'wisper', '~> 2.0'
 
 group :development, :test do
   # Check gems for known vulnerabilities
@@ -76,7 +79,6 @@ group :development do
   # Display performance information such as SQL time and flame graphs for each request in your browser.
   # Can be configured to work on production as well see: https://github.com/MiniProfiler/rack-mini-profiler/blob/master/README.md
   gem "erb_lint", require: false
-  gem "rack-mini-profiler", "~> 2.0"
   gem "rubocop-govuk", "4.3.0", require: false
   gem "rubocop-performance", require: false
   gem "rubocop-rails", require: false
@@ -92,6 +94,15 @@ group :test do
   gem "simplecov", require: false
   gem "timecop", "~> 0.9.4"
   gem "webmock", require: false
+  gem 'wisper-rspec', require: false  
+end
+
+group :development, :test do
+  gem "rack-mini-profiler"
+  gem "flamegraph"  
+  gem "stackprof"
+  gem "bullet"
+  gem "memory_profiler"  
 end
 
 # Windows does not include zoneinfo files, so bundle the tzinfo-data gem

Gemfile.lock

@@ -111,6 +111,9 @@ GEM
     bootsnap (1.13.0)
       msgpack (~> 1.2)
     builder (3.2.4)
+    bullet (7.0.3)
+      activesupport (>= 3.0.0)
+      uniform_notifier (~> 1.11)
     bundler-audit (0.9.1)
       bundler (>= 1.2.0, < 3)
       thor (~> 1.0)
@@ -167,6 +170,7 @@ GEM
     faker (2.23.0)
       i18n (>= 1.8.11, < 2)
     ffi (1.15.5)
+    flamegraph (0.9.5)
     globalid (1.0.0)
       activesupport (>= 5.0)
     govuk-components (3.2.1)
@@ -206,10 +210,15 @@ GEM
       mini_mime (>= 0.1.1)
     marcel (1.0.2)
     matrix (0.4.2)
+    memory_profiler (1.0.0)
     method_source (1.0.0)
     mini_mime (1.1.2)
     minitest (5.16.3)
+    mono_logger (1.1.1)
     msgpack (1.5.6)
+    multi_json (1.15.0)
+    mustermann (3.0.0)
+      ruby2_keywords (~> 0.0.1)
     net-imap (0.2.3)
       digest
       net-protocol
@@ -273,6 +282,8 @@ GEM
       rack (>= 1.0, < 3)
     rack-mini-profiler (2.3.4)
       rack (>= 1.2.0)
+    rack-protection (3.0.1)
+      rack
     rack-test (2.0.2)
       rack (>= 1.3)
     rails (7.0.3.1)
@@ -312,12 +323,19 @@ GEM
       redis-client (>= 0.7.4)
     redis-client (0.8.0)
       connection_pool
+    redis-namespace (1.9.0)
+      redis (>= 4)
     regexp_parser (2.5.0)
     request_store (1.5.1)
       rack (>= 1.4)
     responders (3.0.1)
       actionpack (>= 5.0)
       railties (>= 5.0)
+    resque (2.4.0)
+      mono_logger (~> 1.0)
+      multi_json (~> 1.0)
+      redis-namespace (~> 1.6)
+      sinatra (>= 0.9.2)
     rexml (3.2.5)
     roo (2.9.0)
       nokogiri (~> 1)
@@ -387,17 +405,25 @@ GEM
       simplecov_json_formatter (~> 0.1)
     simplecov-html (0.12.3)
     simplecov_json_formatter (0.1.4)
+    sinatra (3.0.1)
+      mustermann (~> 3.0)
+      rack (~> 2.2, >= 2.2.4)
+      rack-protection (= 3.0.1)
+      tilt (~> 2.0)
     smart_properties (1.17.0)
+    stackprof (0.2.21)
     stimulus-rails (1.1.0)
       railties (>= 6.0.0)
     strscan (3.0.4)
     thor (1.2.1)
+    tilt (2.0.11)
     timecop (0.9.5)
     timeout (0.3.0)
     tzinfo (2.0.5)
       concurrent-ruby (~> 1.0)
     uk_postcode (2.1.8)
     unicode-display_width (2.2.0)
+    uniform_notifier (1.16.0)
     view_component (2.69.0)
       activesupport (>= 5.0.0, < 8.0)
       concurrent-ruby (~> 1.0)
@@ -417,6 +443,8 @@ GEM
     websocket-driver (0.7.5)
       websocket-extensions (>= 0.1.0)
     websocket-extensions (0.1.5)
+    wisper (2.0.1)
+    wisper-rspec (1.1.0)
     xpath (3.2.0)
       nokogiri (~> 1.8)
     zeitwerk (2.6.0)
@@ -432,6 +460,7 @@ DEPENDENCIES
   auto_strip_attributes
   aws-sdk-s3
   bootsnap (>= 1.4.4)
+  bullet
   bundler-audit
   byebug
   capybara
@@ -442,12 +471,14 @@ DEPENDENCIES
   erb_lint
   factory_bot_rails
   faker
+  flamegraph
   govuk-components
   govuk_design_system_formbuilder
   govuk_markdown
   jsbundling-rails
   json-schema
   listen (~> 3.3)
+  memory_profiler
   notifications-ruby-client
   overcommit (>= 0.37.0)
   paper_trail
@@ -459,9 +490,10 @@ DEPENDENCIES
   pry-byebug
   puma (~> 5.0)
   rack-attack
-  rack-mini-profiler (~> 2.0)
+  rack-mini-profiler
   rails (~> 7.0.2)
   redis
+  resque (~> 2.4)
   roo
   rspec-rails
   rubocop-govuk (= 4.3.0)
@@ -471,6 +503,7 @@ DEPENDENCIES
   sentry-rails
   sentry-ruby
   simplecov
+  stackprof
   stimulus-rails
   timecop (~> 0.9.4)
   tzinfo-data
@@ -478,6 +511,8 @@ DEPENDENCIES
   view_component
   web-console (>= 4.1.0)
   webmock
+  wisper (~> 2.0)
+  wisper-rspec
 
 RUBY VERSION
    ruby 3.1.2p20

Procfile.dev

@@ -1,2 +1,3 @@
+QUEUE=* rake resque:work
 web: bin/rails server -p 3000
 js: yarn build --watch

Rakefile

@@ -2,5 +2,8 @@
 # for example lib/tasks/capistrano.rake, and they will automatically be available to Rake.
 
 require_relative "config/application"
+require 'resque/tasks'
+
+task 'resque:setup' => :environment
 
 Rails.application.load_tasks

app/controllers/lettings_test_controller.rb

@@ -0,0 +1,41 @@
+require 'nokogiri'
+require 'securerandom'
+require 'fileutils'
+
+class LettingsTestController < ApplicationController
+  def index
+    folder = '/Users/mohseeadmin/development-meta/CORE/CLDC-1222'
+    stash_folder = Time.now.to_i.to_s
+    generate_fixtures(folder, stash_folder, 50)
+
+    
+      LettingsLog.connection.truncate(LettingsLog.table_name)
+    
+
+    
+     
+    Imports::LettingsLogsImportService.new(Storage::S3Service).local_load("#{folder}/#{stash_folder}")
+
+  end
+
+  def node(xml_document, namespace, field)
+    xml_document.at_xpath("//#{namespace}:#{field}")
+  end  
+
+  def generate_fixtures(folder, stash_folder, num_files)
+    #folder = '/Users/mohseeadmin/development-meta/CORE/CLDC-1222/'
+    canonical_logfiles = %w[canonical_logfile1.xml canonical_logfile2.xml canonical_logfile3.xml]
+    
+    
+    FileUtils.mkdir_p("#{folder}/#{stash_folder}")
+    
+    (1..num_files).each do |i|
+      xml_document = Nokogiri::XML(File.read("#{folder.chomp('/')}/#{canonical_logfiles.sample}"))
+      document_id = node(xml_document, 'meta', 'document-id')
+      new_guid = SecureRandom.uuid.to_s
+      document_id.content = new_guid
+    
+      File.open("#{folder.chomp('/')}/#{stash_folder}/#{new_guid}.xml", 'w') { |f| f.puts xml_document }
+    end
+  end  
+end

app/events/base.rb

@@ -0,0 +1,4 @@
+module Events
+  class Base
+  end
+end

app/events/import.rb

@@ -0,0 +1,6 @@
+
+  module Import
+    STARTED = :events_import_started
+    ITEM_PROCESSED = :events_import_item_processed
+    FINISHED = :events_import_finished
+  end

app/helpers/lettings_test_helper.rb

@@ -0,0 +1,2 @@
+module LettingsTestHelper
+end

app/jobs/cleanup_job.rb

@@ -0,0 +1,7 @@
+class CleanupJob < ApplicationJob
+  queue_as :default
+
+  def perform(*args)
+    # Do something later
+  end
+end

app/jobs/lettings_log_import_job.rb

@@ -0,0 +1,16 @@
+
+class LettingsLogImportJob < ApplicationJob
+  include Wisper::Publisher
+
+  self.queue_name_prefix = '_lettings_logs'
+  queue_as :default
+
+  def perform(run_id, xml_document)
+    puts "PERFORMING RUN: #{run_id} WITH XML DOC: #{xml_document}"
+    #Wisper.subscribe(LettingsLogImportListener.new, prefix: :on)
+
+    processor = Imports::LettingsLogsImportProcessor.new(xml_document)
+
+    broadcast(::Import::ITEM_PROCESSED, run_id, processor)
+  end    
+end

app/listeners/lettings_log_import_listener.rb

@@ -0,0 +1,48 @@
+class LettingsLogImportListener
+  # include Wisper::Publisher
+
+  def on_events_import_started(run_id)
+    puts "LettingsLogs::ImportListener STARTING RUN -> #{run_id}"
+  end
+
+  def on_events_import_finished(run_id)
+    puts "LettingsLogs::ImportListener FINISHED RUN -> #{run_id}"
+  end  
+
+  def on_events_import_item_processed(run_id, processor)
+    puts "LettingsLogs::ImportListener ITEM PROCESSED -> #{run_id} old_id: #{processor.old_id}, discrepency?: #{processor.discrepancy?}"
+  
+    redis = Redis.new
+    obj = redis.get(run_id)
+    logs_import = Marshal.load(obj)
+    puts "GOT FROM REDIS: total: #{logs_import.total}"
+
+    logs_import.num_saved += 1
+
+    if processor.discrepancy?
+      logs_import.discrepancies << processor.old_id
+    end
+
+    redis.set(run_id, Marshal.dump(logs_import))
+    
+    if last_item?(logs_import)
+      collate_results_and_update_db(logs_import)
+      send_email_with_results(logs_import)
+      # broadcast(::Import::FINISHED, run_id)
+    end
+  end  
+
+  def last_item?(logs_import)
+    logs_import.total == (logs_import.num_saved + logs_import.num_skipped)
+  end
+
+  def collate_results_and_update_db(logs_import)
+    logs_import.finished_at = Time.zone.now
+    logs_import.duration_seconds = (logs_import.finished_at - logs_import.started_at).seconds.to_i
+    logs_import.save!
+  end
+
+  def send_email_with_results(logs_import)
+    # TODO
+  end
+end

app/models/lettings_log.rb

@@ -8,6 +8,7 @@ class LettingsLogValidator < ActiveModel::Validator
   include Validations::TenancyValidations
   include Validations::DateValidations
   include Validations::LocalAuthorityValidations
+
   def validate(record)
     validation_methods = public_methods.select { |method| method.starts_with?("validate_") }
     validation_methods.each { |meth| public_send(meth, record) }
@@ -24,8 +25,10 @@ class LettingsLog < ApplicationRecord
   before_validation :recalculate_start_year!, if: :startdate_changed?
   before_validation :reset_scheme_location!, if: :scheme_changed?, unless: :location_changed?
   before_validation :process_postcode_changes!, if: :postcode_full_changed?
-  before_validation :process_previous_postcode_changes!, if: :ppostcode_full_changed?
+  
-  before_validation :reset_invalidated_dependent_fields!
+  #SLOW: before_validation :process_previous_postcode_changes!, if: :ppostcode_full_changed?
+  #SLOW: before_validation :reset_invalidated_dependent_fields!
+  
   before_validation :reset_location_fields!, unless: :postcode_known?
   before_validation :reset_previous_location_fields!, unless: :previous_postcode_known?
   before_validation :set_derived_fields!
@@ -727,7 +730,7 @@ private
   end
 
   def upcase_and_remove_whitespace(string)
-    string.present? ? string.upcase.gsub(/\s+/, "") : string
+    string&.upcase.gsub(/\s+/, "")
   end
 
   def fully_wheelchair_accessible?

app/models/logs_import.rb

@@ -0,0 +1,2 @@
+class LogsImport < ApplicationRecord
+end

app/views/lettings_test/index.html.erb

@@ -0,0 +1 @@
+<h1>Lettings Test</h1>

config/environments/development.rb

@@ -1,6 +1,14 @@
 require "active_support/core_ext/integer/time"
 
 Rails.application.configure do
+  config.after_initialize do
+    Bullet.enable        = true
+    Bullet.alert         = true
+    Bullet.bullet_logger = true
+    Bullet.console       = true
+    Bullet.rails_logger  = true
+  end
+
   # Settings specified here will take precedence over those in config/application.rb.
 
   # In the development environment your application's code is reloaded any time
@@ -83,4 +91,8 @@ Rails.application.configure do
 
   # see https://discuss.rubyonrails.org/t/cve-2022-32224-possible-rce-escalation-bug-with-serialized-columns-in-active-record/81017
   config.active_record.yaml_column_permitted_classes = [Time]
+
+  config.active_job.queue_adapter = :resque  
+
+  Rack::MiniProfiler.config.storage = Rack::MiniProfiler::MemoryStore
 end

config/environments/staging.rb

@@ -127,4 +127,6 @@ Rails.application.configure do
 
   # see https://discuss.rubyonrails.org/t/cve-2022-32224-possible-rce-escalation-bug-with-serialized-columns-in-active-record/81017
   config.active_record.yaml_column_permitted_classes = [Time]
+
+  Rack::MiniProfiler.config.storage = Rack::MiniProfiler::MemoryStore
 end

config/environments/test.rb

@@ -6,6 +6,12 @@ require "active_support/core_ext/integer/time"
 # and recreated between test runs. Don't rely on the data there!
 
 Rails.application.configure do
+  config.after_initialize do
+    Bullet.enable        = true
+    Bullet.bullet_logger = true
+    Bullet.raise         = true # raise an error if n+1 query occurs
+  end
+
   # Settings specified here will take precedence over those in config/application.rb.
 
   # Turn false under Spring and add config.action_view.cache_template_loading = true
@@ -64,4 +70,6 @@ Rails.application.configure do
 
   # see https://discuss.rubyonrails.org/t/cve-2022-32224-possible-rce-escalation-bug-with-serialized-columns-in-active-record/81017
   config.active_record.yaml_column_permitted_classes = [Time]
+
+  Rack::MiniProfiler.config.storage = Rack::MiniProfiler::MemoryStore
 end

config/initializers/rack_profiler.rb

@@ -0,0 +1,3 @@
+if Rails.env == 'development' || Rails.env == 'test'
+  # Rack::MiniProfilerRails.initialize!(Rails.application)
+end

config/initializers/wisper.rb

@@ -0,0 +1,7 @@
+# Wisper global subscribers
+# https://github.com/krisleech/wisper
+
+#require_relative '../../app/listeners/lettings_logs/import_listener'
+#require_relative '../../app/services/imports/lettings_logs_import_service'
+
+# Wisper.subscribe(LettingsLogsImportListener.new, scope: [Imports::LettingsLogsImportService])

config/routes.rb

@@ -101,4 +101,6 @@ Rails.application.routes.draw do
     match "/422", to: "errors#unprocessable_entity"
     match "/500", to: "errors#internal_server_error"
   end
+
+  resources :lettings_test
 end

db/migrate/20220928002015_logs_imports.rb

@@ -0,0 +1,18 @@
+class LogsImports < ActiveRecord::Migration[7.0]
+  def change
+    create_table :logs_imports do |t|
+      t.string :run_id, null: false
+      t.datetime :started_at
+      t.datetime :finished_at
+      t.integer :duration_seconds, default: 0
+      t.integer :total, default: 0 # Total logs to import in batch
+      t.integer :num_saved, default: 0
+      t.integer :num_skipped, default: 0
+
+      t.jsonb :discrepancies # List of files with errors, etc
+      t.jsonb :filenames # List of filenames processed
+
+      t.timestamps
+    end    
+  end
+end

db/schema.rb

@@ -10,7 +10,7 @@
 #
 # It's strongly recommended that you check this file into your version control system.
 
-ActiveRecord::Schema[7.0].define(version: 2022_09_02_082245) do
+ActiveRecord::Schema[7.0].define(version: 2022_09_28_002015) do
   # These are extensions that must be enabled in order to support this database
   enable_extension "plpgsql"
 
@@ -259,6 +259,11 @@ ActiveRecord::Schema[7.0].define(version: 2022_09_02_082245) do
     t.index ["scheme_id"], name: "index_locations_on_scheme_id"
   end
 
+  create_table "log_imports", force: :cascade do |t|
+    t.datetime "created_at", null: false
+    t.datetime "updated_at", null: false
+  end
+
   create_table "logs_exports", force: :cascade do |t|
     t.datetime "created_at", default: -> { "CURRENT_TIMESTAMP" }
     t.datetime "started_at", null: false
@@ -267,6 +272,20 @@ ActiveRecord::Schema[7.0].define(version: 2022_09_02_082245) do
     t.boolean "empty_export", default: false, null: false
   end
 
+  create_table "logs_imports", force: :cascade do |t|
+    t.string "run_id", null: false
+    t.datetime "started_at"
+    t.datetime "finished_at"
+    t.integer "duration_seconds", default: 0
+    t.integer "total", default: 0
+    t.integer "num_saved", default: 0
+    t.integer "num_skipped", default: 0
+    t.jsonb "discrepancies"
+    t.jsonb "filenames"
+    t.datetime "created_at", null: false
+    t.datetime "updated_at", null: false
+  end
+
   create_table "organisation_relationships", force: :cascade do |t|
     t.integer "child_organisation_id"
     t.integer "parent_organisation_id"

spec/services/imports/lettings_logs_import_service_spec.rb

@@ -68,8 +68,15 @@ RSpec.describe Imports::LettingsLogsImportService do
       expect(logger).not_to receive(:error)
       expect(logger).not_to receive(:warn)
       expect(logger).not_to receive(:info)
-      expect { lettings_log_service.create_logs(remote_folder) }
+      #expect { lettings_log_service.create_logs(remote_folder) }
-        .to change(LettingsLog, :count).by(4)
+      #  .to change(LettingsLog, :count).by(4)
+      total_logs = LettingsLog.all.size
+      Rack::MiniProfiler.config.storage = Rack::MiniProfiler::MemoryStore
+      Rack::MiniProfiler.step('Create Case Logs') do
+        puts "Creating case logs, profiling!"
+        lettings_log_service.create_logs(remote_folder)
+      end 
+      expect(LettingsLog.all.size).to eq(total_logs + 4)     
     end
 
     it "only updates existing lettings logs" do