diff --git a/app/controllers/api/v3/facilities_controller.rb b/app/controllers/api/v3/facilities_controller.rb index c32ae6e419..23f284ab8b 100644 --- a/app/controllers/api/v3/facilities_controller.rb +++ b/app/controllers/api/v3/facilities_controller.rb @@ -16,9 +16,11 @@ def current_facility_records end def other_facility_records - Facility - .with_discarded - .updated_on_server_since(other_facilities_processed_since, limit) + Statsd.instance.time("other_facility_records.Facility") do + Facility + .with_discarded + .updated_on_server_since(other_facilities_processed_since, limit) + end end def disable_audit_logs? @@ -39,15 +41,16 @@ def response_process_token end def force_resync? - Rails.logger.info "Resync token modified in resource #{controller_name}" if resync_token_modified? resync_token_modified? end def records_to_sync - other_facility_records - .with_block_region_id - .includes(:facility_group) - .where.not(facility_group: nil) + Statsd.instance.time("records_to_sync.Facility") do + other_facility_records + .with_block_region_id + .includes(:facility_group) + .where.not(facility_group: nil) + end end private diff --git a/app/controllers/api/v3/patients_controller.rb b/app/controllers/api/v3/patients_controller.rb index cba44a368a..323c31427f 100644 --- a/app/controllers/api/v3/patients_controller.rb +++ b/app/controllers/api/v3/patients_controller.rb @@ -14,22 +14,25 @@ def request_metadata end def region_records - super - .includes(:address, :phone_numbers, :business_identifiers) + super.includes(:address, :phone_numbers, :business_identifiers) end def current_facility_records - region_records - .where(registration_facility: current_facility) - .updated_on_server_since(current_facility_processed_since, limit) + Statsd.instance.time("current_facility_records.Patient") do + region_records + .where(registration_facility: current_facility) + .updated_on_server_since(current_facility_processed_since, limit) + end end def other_facility_records - other_facilities_limit = limit - current_facility_records.count + Statsd.instance.time("other_facility_records.Patient") do + other_facilities_limit = limit - current_facility_records.count - region_records - .where.not(registration_facility: current_facility) - .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) + region_records + .where.not(registration_facility: current_facility) + .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) + end end private diff --git a/app/controllers/api/v3/protocols_controller.rb b/app/controllers/api/v3/protocols_controller.rb index b5cd65765b..327c1bed76 100644 --- a/app/controllers/api/v3/protocols_controller.rb +++ b/app/controllers/api/v3/protocols_controller.rb @@ -16,9 +16,11 @@ def current_facility_records end def other_facility_records - Protocol - .with_discarded - .updated_on_server_since(other_facilities_processed_since, limit) + Statsd.instance.time("other_facility_records.Protocol") do + Protocol + .with_discarded + .updated_on_server_since(other_facilities_processed_since, limit) + end end def disable_audit_logs? @@ -37,7 +39,6 @@ def response_process_token end def force_resync? - Rails.logger.info "Resync token modified in resource #{controller_name}" if resync_token_modified? resync_token_modified? end end diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index 039cc2bf41..d5f7ad05dd 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -11,10 +11,14 @@ def __sync_from_user__(params) end def __sync_to_user__(response_key) - AuditLog.create_logs_async(current_user, records_to_sync, "fetch", Time.current) unless disable_audit_logs? + records = records_to_sync + + AuditLog.create_logs_async(current_user, records, "fetch", Time.current) unless disable_audit_logs? + log_block_level_sync_metrics(response_key) + render( json: { - response_key => records_to_sync.map { |record| transform_to_response(record) }, + response_key => records.map { |record| transform_to_response(record) }, "process_token" => encode_process_token(response_process_token) }, status: :ok @@ -35,6 +39,27 @@ def disable_audit_logs? false end + def log_block_level_sync_metrics(response_key) + Rails.logger.tagged("Block Sync") do + if resync_token_modified? + Rails.logger.info msg: "Resync token modified", resource: response_key + end + + if current_user + if sync_region_modified? + Rails.logger.info msg: "Sync region ID modified", + region_type: current_sync_region.class.name, + region_id: current_sync_region.id, + resource: response_key + end + + if block_level_sync? + Rails.logger.info msg: "The current_sync_region set to block", block_id: current_block.id + end + end + end + end + def params_with_errors(params, errors) error_ids = errors.map { |error| error[:id] } params diff --git a/app/controllers/api_controller.rb b/app/controllers/api_controller.rb index 455076605b..ac605730c0 100644 --- a/app/controllers/api_controller.rb +++ b/app/controllers/api_controller.rb @@ -38,10 +38,7 @@ def current_sync_region # allow other region types as well return current_facility_group if requested_sync_region_id.blank? return current_facility_group if requested_sync_region_id == current_facility_group.id - if block_level_sync? - Rails.logger.info "current_sync_region set to block #{current_block.id} for user #{current_user.id}" - return current_block - end + return current_block if block_level_sync? current_facility_group end diff --git a/app/controllers/concerns/api/v3/sync_to_user.rb b/app/controllers/concerns/api/v3/sync_to_user.rb index af720791dc..0d3819b899 100644 --- a/app/controllers/concerns/api/v3/sync_to_user.rb +++ b/app/controllers/concerns/api/v3/sync_to_user.rb @@ -3,28 +3,37 @@ module Api::V3::SyncToUser included do def region_records - model = controller_name.classify.constantize model.syncable_to_region(current_sync_region) end def current_facility_records - region_records - .where(patient: prioritized_patients) - .updated_on_server_since(current_facility_processed_since, limit) + Statsd.instance.time("current_facility_records.#{model.name}") do + region_records + .where(patient: prioritized_patients) + .updated_on_server_since(current_facility_processed_since, limit) + end end def other_facility_records - other_facilities_limit = limit - current_facility_records.count + Statsd.instance.time("other_facility_records.#{model.name}") do + other_facilities_limit = limit - current_facility_records.count - region_records - .where.not(patient: prioritized_patients) - .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) + region_records + .where.not(patient: prioritized_patients) + .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) + end end private + def model + controller_name.classify.constantize + end + def records_to_sync - current_facility_records + other_facility_records + Statsd.instance.time("records_to_sync.#{model.name}") do + current_facility_records + other_facility_records + end end def prioritized_patients @@ -68,8 +77,6 @@ def current_facility_processed_since end def force_resync? - Rails.logger.info "[force_resync] Resync token modified in resource #{controller_name}" if resync_token_modified? - Rails.logger.info "[force_resync] Sync region modified in resource #{controller_name}" if sync_region_modified? resync_token_modified? || sync_region_modified? end diff --git a/app/services/report_duplicate_passports.rb b/app/services/report_duplicate_passports.rb new file mode 100644 index 0000000000..6350c813e6 --- /dev/null +++ b/app/services/report_duplicate_passports.rb @@ -0,0 +1,56 @@ +class ReportDuplicatePassports + include Memery + + IDENTIFIER_TYPES = %w[simple_bp_passport] + delegate :logger, to: Rails + + def self.report + new.report + end + + def report + logger.tagged("ReportDuplicatePassports") do + logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities" + end + + Statsd.instance.gauge("ReportDuplicatePassports.size", duplicate_passports_count) + end + + memoize def duplicate_passports_count + passports_at_multiple_facilities + .where(identifier: passports_with_multiple_patients) + .where(identifier_type: IDENTIFIER_TYPES) + .pluck(:identifier) + .count + end + + # this is a utility function for fetching the actual duplicate passports + # you could call this and get counts from it but duplicate_passports_count is faster + # leaving this here as useful method for debugging + def duplicate_passports + PatientBusinessIdentifier + .where(identifier_type: IDENTIFIER_TYPES) + .where(identifier: passports_at_multiple_facilities) + .where(identifier: passports_with_multiple_patients) + end + + def passports_at_multiple_facilities + PatientBusinessIdentifier + .group(:identifier) + .having("COUNT(DISTINCT #{passport_assigning_facility}) > 1") + .select(:identifier) + end + + def passports_with_multiple_patients + PatientBusinessIdentifier + .group(:identifier) + .having("COUNT(DISTINCT patient_id) > 1") + .select(:identifier) + end + + private + + def passport_assigning_facility + "COALESCE((metadata->'assigning_facility_id'), (metadata->'assigningFacilityUuid'))::text" + end +end diff --git a/config/schedule.rb b/config/schedule.rb index 70b6d2ed38..9ebe5ab16a 100644 --- a/config/schedule.rb +++ b/config/schedule.rb @@ -40,6 +40,10 @@ def local(time) rake "db:seed_users_data" end +every :day, at: local("05:00 am"), roles: [:cron] do + runner "ReportDuplicatePassports.report" +end + every :monday, at: local("6:00 am"), roles: [:cron] do if Flipper.enabled?(:weekly_telemed_report) rake "reports:telemedicine" diff --git a/lib/statsd.rb b/lib/statsd.rb index 086fe5403c..0e289dec15 100644 --- a/lib/statsd.rb +++ b/lib/statsd.rb @@ -7,5 +7,5 @@ def initialize attr_reader :statsd - delegate :increment, :time, :timing, to: :statsd + delegate :increment, :time, :timing, :gauge, to: :statsd end diff --git a/lib/tasks/scripts/block_level_sync.rb b/lib/tasks/scripts/block_level_sync.rb index 5db6a6668b..73363590dd 100644 --- a/lib/tasks/scripts/block_level_sync.rb +++ b/lib/tasks/scripts/block_level_sync.rb @@ -73,8 +73,11 @@ def touch_facilities(user) .update_all(updated_at: Time.current) end + # this filters out admin users since there's no easy way to filter them out during percentage ramp-up def enabled_user_ids - User.find_each(batch_size: 100).each_with_object([]) do |user, ids| + User + .non_admins + .find_each(batch_size: 100).each_with_object([]) do |user, ids| ids.push(user.id) if user.feature_enabled?(:block_level_sync) end end diff --git a/spec/controllers/api/v3/facilities_controller_spec.rb b/spec/controllers/api/v3/facilities_controller_spec.rb index 5180046d8e..5bed3c6e25 100644 --- a/spec/controllers/api/v3/facilities_controller_spec.rb +++ b/spec/controllers/api/v3/facilities_controller_spec.rb @@ -97,7 +97,7 @@ def create_record_list(n, _options = {}) end context "when region level sync is enabled" do - it "sets the sync_region_id to the block id and user is not available" do + it "sets the sync_region_id to the facility group id when user is not available" do enable_flag(:block_level_sync, request_user) get :sync_to_user @@ -109,6 +109,7 @@ def create_record_list(n, _options = {}) it "sets the sync_region_id to the block id when user is available" do request.env["HTTP_X_USER_ID"] = request_user.id + request.env["HTTP_X_FACILITY_ID"] = request_user.facility.id request.env["HTTP_AUTHORIZATION"] = "Bearer #{request_user.access_token}" enable_flag(:block_level_sync, request_user) diff --git a/spec/services/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb new file mode 100644 index 0000000000..4615d8b84e --- /dev/null +++ b/spec/services/report_duplicate_passports_spec.rb @@ -0,0 +1,104 @@ +require "rails_helper" + +RSpec.describe ReportDuplicatePassports do + describe ".duplicate_passports_count" do + context "for passports with the same identifiers" do + let!(:identifier) { SecureRandom.uuid } + + it "does not have passports with same patient at the same facility" do + facility_id = SecureRandom.uuid + patient = create(:patient, business_identifiers: []) + create_list(:patient_business_identifier, 2, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) + + expect(described_class.new.duplicate_passports_count).to eq(0) + end + + it "does not have passports with duplicate patients (different by id) at the same facility" do + facility_id = SecureRandom.uuid + patients = create_list(:patient, 2, business_identifiers: []) + create(:patient_business_identifier, identifier: identifier, patient: patients[0], metadata: {assigningFacilityUuid: facility_id}) + create(:patient_business_identifier, identifier: identifier, patient: patients[1], metadata: {assigningFacilityUuid: facility_id}) + + expect(described_class.new.duplicate_passports_count).to eq(0) + end + + it "does not have passports with the same patient assigned to it at different facilities" do + patient = create(:patient, business_identifiers: []) + create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expect(described_class.new.duplicate_passports_count).to eq(0) + end + + it "only has different patients assigned to a passport at different facilities" do + patients = create_list(:patient, 2, business_identifiers: []) + create(:patient_business_identifier, identifier: identifier, patient: patients[0], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: identifier, patient: patients[1], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expected_count = described_class.new.duplicate_passports.group(:identifier).count.keys.count + expect(described_class.new.duplicate_passports_count).to eq(expected_count) + end + end + + context "for passports without the same identifiers" do + it "does not count them" do + patients = create_list(:patient, 2, business_identifiers: []) + create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients[0], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients[1], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expect(described_class.new.duplicate_passports_count).to eq(0) + end + end + end + + describe ".duplicate_passports" do + context "for passports with the same identifiers" do + let!(:identifier) { SecureRandom.uuid } + + it "does not have passports with same patient at the same facility" do + facility_id = SecureRandom.uuid + patient = create(:patient, business_identifiers: []) + create_list(:patient_business_identifier, 2, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) + + expect(described_class.new.duplicate_passports).to be_empty + end + + it "does not have passports with duplicate patients (different by id) at the same facility" do + facility_id = SecureRandom.uuid + patients = create_list(:patient, 2, business_identifiers: []) + create(:patient_business_identifier, identifier: identifier, patient: patients[0], metadata: {assigningFacilityUuid: facility_id}) + create(:patient_business_identifier, identifier: identifier, patient: patients[1], metadata: {assigningFacilityUuid: facility_id}) + + expect(described_class.new.duplicate_passports).to be_empty + end + + it "does not have passports with the same patient assigned to it at different facilities" do + patient = create(:patient, business_identifiers: []) + create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expect(described_class.new.duplicate_passports).to be_empty + end + + it "only has different patients assigned to a passport at different facilities" do + patients = create_list(:patient, 2, business_identifiers: []) + identifiers = [ + create(:patient_business_identifier, identifier: identifier, patient: patients[0], metadata: {assigningFacilityUuid: SecureRandom.uuid}), + create(:patient_business_identifier, identifier: identifier, patient: patients[1], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + ] + + expect(described_class.new.duplicate_passports).to match_array identifiers + end + end + + context "for passports without the same identifiers" do + it "does not count them" do + patients = create_list(:patient, 2, business_identifiers: []) + create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients[0], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients[1], metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expect(described_class.new.duplicate_passports).to be_empty + end + end + end +end