From ba79439f019421af4db00cfe2a6b4df59477b0f4 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 11 Dec 2020 12:33:24 +0530 Subject: [PATCH 01/20] Add efficacy metrics for block-level sync --- .../api/v3/facilities_controller.rb | 17 ++++++----- .../api/v3/protocols_controller.rb | 8 ++++-- .../concerns/api/v3/sync_to_user.rb | 28 +++++++++++++------ 3 files changed, 34 insertions(+), 19 deletions(-) diff --git a/app/controllers/api/v3/facilities_controller.rb b/app/controllers/api/v3/facilities_controller.rb index feb13fdb5c..5cb1470c28 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? @@ -44,10 +46,11 @@ def force_resync? end def records_to_sync - Facility - .updated_on_server_since(other_facilities_processed_since, limit) - .includes(:facility_group) - .where.not(facility_group: nil) + Statsd.instance.time("records_to_sync.Facility") do + other_facility_records + .includes(:facility_group) + .where.not(facility_group: nil) + end end private diff --git a/app/controllers/api/v3/protocols_controller.rb b/app/controllers/api/v3/protocols_controller.rb index b5cd65765b..cec246f8bb 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? diff --git a/app/controllers/concerns/api/v3/sync_to_user.rb b/app/controllers/concerns/api/v3/sync_to_user.rb index 13c19917ed..e7990d3100 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 - region_records - .where.not(patient: prioritized_patients) - .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) + Statsd.instance.time("other_facility_records.#{model.name}") do + 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 @@ -69,7 +78,8 @@ def current_facility_processed_since def force_resync? Rails.logger.info "Resync token modified in resource #{controller_name}" if resync_token_modified? - Rails.logger.info "Sync region modified in resource #{controller_name}" if sync_region_modified? + Rails.logger.info "Sync Regions modified in resource #{controller_name}" if sync_region_modified? + resync_token_modified? || sync_region_modified? end From 336c17a9d6807b4e37d41e6f7d046a3bee620a2b Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 15:23:38 +0530 Subject: [PATCH 02/20] Consolidate logging at the controller --- .../api/v3/facilities_controller.rb | 1 - .../api/v3/protocols_controller.rb | 1 - app/controllers/api/v3/sync_controller.rb | 23 ++++++++++++++++++- app/controllers/api_controller.rb | 5 +--- .../concerns/api/v3/sync_to_user.rb | 2 -- 5 files changed, 23 insertions(+), 9 deletions(-) diff --git a/app/controllers/api/v3/facilities_controller.rb b/app/controllers/api/v3/facilities_controller.rb index 5cb1470c28..6d0387829a 100644 --- a/app/controllers/api/v3/facilities_controller.rb +++ b/app/controllers/api/v3/facilities_controller.rb @@ -41,7 +41,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 diff --git a/app/controllers/api/v3/protocols_controller.rb b/app/controllers/api/v3/protocols_controller.rb index cec246f8bb..327c1bed76 100644 --- a/app/controllers/api/v3/protocols_controller.rb +++ b/app/controllers/api/v3/protocols_controller.rb @@ -39,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..f3c938142d 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -11,7 +11,11 @@ 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 + + log_block_level_sync_metrics(response_key) + AuditLog.create_logs_async(current_user, records, "fetch", Time.current) unless disable_audit_logs? + render( json: { response_key => records_to_sync.map { |record| transform_to_response(record) }, @@ -35,6 +39,23 @@ def disable_audit_logs? false end + def log_block_level_sync_metrics(response_key) + if resync_token_modified? + Rails.logger.info(msg: "[force_resync] Resync token modified", resource: response_key) + end + if sync_region_modified? + Rails.logger.info msg: "[force_resync] Sync region 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: "current_sync_region set to block", + block_id: current_block.id, + user_id: current_user.id + 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 c798f5b045..ccdd737a47 100644 --- a/app/controllers/concerns/api/v3/sync_to_user.rb +++ b/app/controllers/concerns/api/v3/sync_to_user.rb @@ -77,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 From 8c0280f2f4a7f99c4b6660d38df9c9c40ed87615 Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 16:35:37 +0530 Subject: [PATCH 03/20] Check if current_user exists in log method --- app/controllers/api/v3/sync_controller.rb | 22 ++++++++++++---------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index f3c938142d..993a933187 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -43,16 +43,18 @@ def log_block_level_sync_metrics(response_key) if resync_token_modified? Rails.logger.info(msg: "[force_resync] Resync token modified", resource: response_key) end - if sync_region_modified? - Rails.logger.info msg: "[force_resync] Sync region 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: "current_sync_region set to block", - block_id: current_block.id, - user_id: current_user.id + if current_user + if sync_region_modified? + Rails.logger.info msg: "[force_resync] Sync region 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: "current_sync_region set to block", + block_id: current_block.id, + user_id: current_user.id + end end end From d03061e862c28a12184fae0bd26c9b5c1e42835a Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 17:14:52 +0530 Subject: [PATCH 04/20] Add script to check for duplicate patients across facilities --- .../scripts/report_duplicate_passports.rb | 43 ++++++++++++++ .../report_duplicate_passports_spec.rb | 56 +++++++++++++++++++ 2 files changed, 99 insertions(+) create mode 100644 lib/tasks/scripts/report_duplicate_passports.rb create mode 100644 spec/tasks/scripts/report_duplicate_passports_spec.rb diff --git a/lib/tasks/scripts/report_duplicate_passports.rb b/lib/tasks/scripts/report_duplicate_passports.rb new file mode 100644 index 0000000000..e8a1677f7e --- /dev/null +++ b/lib/tasks/scripts/report_duplicate_passports.rb @@ -0,0 +1,43 @@ +class ReportDuplicatePassports + IDENTIFIER_TYPES = %w[simple_bp_passport] + + class << self + def report + Rails.logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities", + count: duplicate_passports_count + end + + def duplicate_passports + PatientBusinessIdentifier + .where(identifier_type: IDENTIFIER_TYPES) + .where(identifier: passports_at_multiple_facilities) + .where(identifier: passports_with_multiple_patients) + end + + def duplicate_passports_count + passports_at_multiple_facilities + .where(identifier: passports_with_multiple_patients) + .where(identifier_type: IDENTIFIER_TYPES) + .pluck(:identifier) + .count + end + + def passports_at_multiple_facilities + PatientBusinessIdentifier + .group(:identifier) + .having("COUNT(DISTINCT #{passport_assigning_facility}) > 1") + .select(:identifier) + end + + def passport_assigning_facility + "COALESCE((metadata->'assigning_facility_id'), (metadata->'assigningFacilityUuid'))::text" + end + + def passports_with_multiple_patients + PatientBusinessIdentifier + .group(:identifier) + .having("COUNT(DISTINCT patient_id) > 1") + .select(:identifier) + end + end +end diff --git a/spec/tasks/scripts/report_duplicate_passports_spec.rb b/spec/tasks/scripts/report_duplicate_passports_spec.rb new file mode 100644 index 0000000000..2f456870ce --- /dev/null +++ b/spec/tasks/scripts/report_duplicate_passports_spec.rb @@ -0,0 +1,56 @@ +require "rails_helper" +require "tasks/scripts/report_duplicate_passports" + +RSpec.describe ReportDuplicatePassports do + 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.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: []) + patients.map do |patient| + create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) + end + + expect(described_class.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.duplicate_passports).to be_empty + end + + it "only reports 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.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}), + create(:patient_business_identifier, identifier: identifier, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid})] + + expect(described_class.duplicate_passports).to match_array identifiers + expect(described_class.duplicate_passports_count).to eq described_class.duplicate_passports.group(:identifier).count.keys.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.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + + expect(described_class.duplicate_passports).to be_empty + end + end + end +end From aeff6a13969ee02c5779c889ac868b3c5858c777 Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 18:01:37 +0530 Subject: [PATCH 05/20] Fix spec --- spec/controllers/api/v3/facilities_controller_spec.rb | 1 + 1 file changed, 1 insertion(+) diff --git a/spec/controllers/api/v3/facilities_controller_spec.rb b/spec/controllers/api/v3/facilities_controller_spec.rb index b56194b00a..31ed2ee64e 100644 --- a/spec/controllers/api/v3/facilities_controller_spec.rb +++ b/spec/controllers/api/v3/facilities_controller_spec.rb @@ -113,6 +113,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) From 62fa93b00cfa58ab6defd7f3dc27873edc25778a Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 18:26:17 +0530 Subject: [PATCH 06/20] Add script to scheduler.rb --- app/controllers/api/v3/sync_controller.rb | 2 +- .../scripts => app/services}/report_duplicate_passports.rb | 4 ++-- config/schedule.rb | 4 ++++ .../scripts => services}/report_duplicate_passports_spec.rb | 2 +- 4 files changed, 8 insertions(+), 4 deletions(-) rename {lib/tasks/scripts => app/services}/report_duplicate_passports.rb (96%) rename spec/{tasks/scripts => services}/report_duplicate_passports_spec.rb (96%) diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index 993a933187..c7fb423cbb 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -41,7 +41,7 @@ def disable_audit_logs? def log_block_level_sync_metrics(response_key) if resync_token_modified? - Rails.logger.info(msg: "[force_resync] Resync token modified", resource: response_key) + Rails.logger.info msg: "[force_resync] Resync token modified", resource: response_key end if current_user if sync_region_modified? diff --git a/lib/tasks/scripts/report_duplicate_passports.rb b/app/services/report_duplicate_passports.rb similarity index 96% rename from lib/tasks/scripts/report_duplicate_passports.rb rename to app/services/report_duplicate_passports.rb index e8a1677f7e..568cc727e7 100644 --- a/lib/tasks/scripts/report_duplicate_passports.rb +++ b/app/services/report_duplicate_passports.rb @@ -1,7 +1,7 @@ class ReportDuplicatePassports - IDENTIFIER_TYPES = %w[simple_bp_passport] - class << self + IDENTIFIER_TYPES = %w[simple_bp_passport] + def report Rails.logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities", count: duplicate_passports_count 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/spec/tasks/scripts/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb similarity index 96% rename from spec/tasks/scripts/report_duplicate_passports_spec.rb rename to spec/services/report_duplicate_passports_spec.rb index 2f456870ce..bcb7786304 100644 --- a/spec/tasks/scripts/report_duplicate_passports_spec.rb +++ b/spec/services/report_duplicate_passports_spec.rb @@ -32,7 +32,7 @@ expect(described_class.duplicate_passports).to be_empty end - it "only reports different patients assigned to a passport at different facilities" do + 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.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}), From a5ef23f25a0e79f725eac407ec39fd5a7a688e3e Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 18:28:49 +0530 Subject: [PATCH 07/20] Better logging in enable block level sync --- lib/tasks/block_level_sync.rake | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/lib/tasks/block_level_sync.rake b/lib/tasks/block_level_sync.rake index 7b2fc8253e..f9cb3c3583 100644 --- a/lib/tasks/block_level_sync.rake +++ b/lib/tasks/block_level_sync.rake @@ -39,9 +39,11 @@ def set_block_level_sync(user, enable) else Flipper.disable(:block_level_sync, user) end - Rails.logger.info "Block level sync #{enable ? "enabled" : "disabled"} for #{user.id}" + Rails.logger.info msg: "Block level sync #{enable ? "enabled" : "disabled"} for #{user.id}", + user_id: user.id else - Rails.logger.info "User #{user.id} does not have a phone number authentication" + Rails.logger.info msg: "User #{user.id} does not have a phone number authentication", + user_id: user.id end end end From 66fa44e3bd84e3d8082a1a5ffc16913ce55c6558 Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 18:40:30 +0530 Subject: [PATCH 08/20] Fix spec --- spec/services/report_duplicate_passports_spec.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/spec/services/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb index bcb7786304..2108904495 100644 --- a/spec/services/report_duplicate_passports_spec.rb +++ b/spec/services/report_duplicate_passports_spec.rb @@ -1,5 +1,4 @@ require "rails_helper" -require "tasks/scripts/report_duplicate_passports" RSpec.describe ReportDuplicatePassports do describe ".duplicate_passports" do From 8e82202c679bd9d4bb003c10a345e527eab664a1 Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 19:41:30 +0530 Subject: [PATCH 09/20] Namespaced logging, log to statsd --- app/controllers/api/v3/sync_controller.rb | 4 +--- app/services/report_duplicate_passports.rb | 4 ++-- lib/statsd.rb | 2 +- lib/tasks/block_level_sync.rake | 4 ++-- 4 files changed, 6 insertions(+), 8 deletions(-) diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index c7fb423cbb..292529ad08 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -51,9 +51,7 @@ def log_block_level_sync_metrics(response_key) resource: response_key end if block_level_sync? - Rails.logger.info msg: "current_sync_region set to block", - block_id: current_block.id, - user_id: current_user.id + Rails.logger.info msg: "current_sync_region set to block", block_id: current_block.id end end end diff --git a/app/services/report_duplicate_passports.rb b/app/services/report_duplicate_passports.rb index 568cc727e7..79e8828625 100644 --- a/app/services/report_duplicate_passports.rb +++ b/app/services/report_duplicate_passports.rb @@ -3,8 +3,8 @@ class << self IDENTIFIER_TYPES = %w[simple_bp_passport] def report - Rails.logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities", - count: duplicate_passports_count + Rails.logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities" + Statsd.instance.gauge("passports_with_duplicate_patients_across_facilities", duplicate_passports_count) end def duplicate_passports 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/block_level_sync.rake b/lib/tasks/block_level_sync.rake index f9cb3c3583..170a56994b 100644 --- a/lib/tasks/block_level_sync.rake +++ b/lib/tasks/block_level_sync.rake @@ -40,10 +40,10 @@ def set_block_level_sync(user, enable) Flipper.disable(:block_level_sync, user) end Rails.logger.info msg: "Block level sync #{enable ? "enabled" : "disabled"} for #{user.id}", - user_id: user.id + block_level_sync_enabled_user_id: user.id else Rails.logger.info msg: "User #{user.id} does not have a phone number authentication", - user_id: user.id + block_level_sync_enabled_user_id: user.id end end end From cfb41c3b01fdaa7d4a038c9f5487090938778443 Mon Sep 17 00:00:00 2001 From: prabhanshuguptagit Date: Tue, 22 Dec 2020 20:06:33 +0530 Subject: [PATCH 10/20] Fix typo --- lib/tasks/block_level_sync.rake | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/tasks/block_level_sync.rake b/lib/tasks/block_level_sync.rake index 170a56994b..6b689d7615 100644 --- a/lib/tasks/block_level_sync.rake +++ b/lib/tasks/block_level_sync.rake @@ -43,7 +43,7 @@ def set_block_level_sync(user, enable) block_level_sync_enabled_user_id: user.id else Rails.logger.info msg: "User #{user.id} does not have a phone number authentication", - block_level_sync_enabled_user_id: user.id + block_level_sync_disabled_user_id: user.id end end end From a567abbe5976e7fcaceb1e32b7e643da843f5580 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 13:06:43 +0530 Subject: [PATCH 11/20] Add tagged logging to ReportDuplicatePassport --- app/controllers/api/v3/sync_controller.rb | 26 +++--- app/services/report_duplicate_passports.rb | 79 +++++++++++-------- .../api/v3/facilities_controller_spec.rb | 1 - .../report_duplicate_passports_spec.rb | 13 +-- 4 files changed, 68 insertions(+), 51 deletions(-) diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index 6595e72751..84af9c7bfd 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -40,18 +40,22 @@ def disable_audit_logs? end def log_block_level_sync_metrics(response_key) - if resync_token_modified? - Rails.logger.info msg: "[force_resync] Resync token modified", resource: response_key - end - if current_user - if sync_region_modified? - Rails.logger.info msg: "[force_resync] Sync region modified", - region_type: current_sync_region.class.name, - region_id: current_sync_region.id, - resource: response_key + Rails.logger.tagged("Block Sync") do + if resync_token_modified? + Rails.logger.info msg: "Resync token modified", resource: response_key end - if block_level_sync? - Rails.logger.info msg: "current_sync_region set to block", block_id: current_block.id + + 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 diff --git a/app/services/report_duplicate_passports.rb b/app/services/report_duplicate_passports.rb index 79e8828625..6350c813e6 100644 --- a/app/services/report_duplicate_passports.rb +++ b/app/services/report_duplicate_passports.rb @@ -1,43 +1,56 @@ class ReportDuplicatePassports - class << self - IDENTIFIER_TYPES = %w[simple_bp_passport] + include Memery - def report - Rails.logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities" - Statsd.instance.gauge("passports_with_duplicate_patients_across_facilities", duplicate_passports_count) - end + IDENTIFIER_TYPES = %w[simple_bp_passport] + delegate :logger, to: Rails - def duplicate_passports - PatientBusinessIdentifier - .where(identifier_type: IDENTIFIER_TYPES) - .where(identifier: passports_at_multiple_facilities) - .where(identifier: passports_with_multiple_patients) - end + def self.report + new.report + end - def duplicate_passports_count - passports_at_multiple_facilities - .where(identifier: passports_with_multiple_patients) - .where(identifier_type: IDENTIFIER_TYPES) - .pluck(:identifier) - .count + def report + logger.tagged("ReportDuplicatePassports") do + logger.info msg: "#{duplicate_passports_count} passports have duplicate patients across facilities" end - def passports_at_multiple_facilities - PatientBusinessIdentifier - .group(:identifier) - .having("COUNT(DISTINCT #{passport_assigning_facility}) > 1") - .select(:identifier) - end + Statsd.instance.gauge("ReportDuplicatePassports.size", duplicate_passports_count) + end - def passport_assigning_facility - "COALESCE((metadata->'assigning_facility_id'), (metadata->'assigningFacilityUuid'))::text" - 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 - def passports_with_multiple_patients - PatientBusinessIdentifier - .group(:identifier) - .having("COUNT(DISTINCT patient_id) > 1") - .select(:identifier) - 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/spec/controllers/api/v3/facilities_controller_spec.rb b/spec/controllers/api/v3/facilities_controller_spec.rb index 9c64facfe4..5180046d8e 100644 --- a/spec/controllers/api/v3/facilities_controller_spec.rb +++ b/spec/controllers/api/v3/facilities_controller_spec.rb @@ -110,7 +110,6 @@ 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_AUTHORIZATION"] = "Bearer #{request_user.access_token}" - request.env["HTTP_AUTHORIZATION"] = "Bearer #{request_user.access_token}" enable_flag(:block_level_sync, request_user) get :sync_to_user diff --git a/spec/services/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb index 2108904495..34a4599727 100644 --- a/spec/services/report_duplicate_passports_spec.rb +++ b/spec/services/report_duplicate_passports_spec.rb @@ -10,7 +10,7 @@ patient = create(:patient, business_identifiers: []) create_list(:patient_business_identifier, 2, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) - expect(described_class.duplicate_passports).to be_empty + 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 @@ -20,7 +20,7 @@ create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) end - expect(described_class.duplicate_passports).to be_empty + 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 @@ -28,7 +28,7 @@ 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.duplicate_passports).to be_empty + expect(described_class.new.duplicate_passports).to be_empty end it "only has different patients assigned to a passport at different facilities" do @@ -37,8 +37,9 @@ [create(:patient_business_identifier, identifier: identifier, patient: patients.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}), create(:patient_business_identifier, identifier: identifier, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid})] - expect(described_class.duplicate_passports).to match_array identifiers - expect(described_class.duplicate_passports_count).to eq described_class.duplicate_passports.group(:identifier).count.keys.count + expect(described_class.new.duplicate_passports).to match_array identifiers + 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 @@ -48,7 +49,7 @@ create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}) create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid}) - expect(described_class.duplicate_passports).to be_empty + expect(described_class.new.duplicate_passports).to be_empty end end end From b5a6b1b1aedce938cbf9de06828f71eeb54b77fa Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 13:20:31 +0530 Subject: [PATCH 12/20] Remove old other_facility_records --- app/controllers/concerns/api/v3/sync_to_user.rb | 13 ------------- 1 file changed, 13 deletions(-) diff --git a/app/controllers/concerns/api/v3/sync_to_user.rb b/app/controllers/concerns/api/v3/sync_to_user.rb index e0b6bed87a..e13bdef9d4 100644 --- a/app/controllers/concerns/api/v3/sync_to_user.rb +++ b/app/controllers/concerns/api/v3/sync_to_user.rb @@ -15,19 +15,6 @@ def current_facility_records end end - def other_facility_records - Statsd.instance.time("other_facility_records.#{model.name}") do - other_facilities_limit = limit - current_facility_records.size - other_patient_records = - current_sync_region.syncable_patients.pluck(:id) - current_facility.prioritized_patients.pluck(:id) - - model_sync_scope - .where(patient: other_patient_records) - .updated_on_server_since(other_facilities_processed_since, other_facilities_limit) - end - - end - def other_facility_records Statsd.instance.time("other_facility_records.#{model.name}") do other_facilities_limit = limit - current_facility_records.count From e67a5c9de6a0db95262c40381f80716d4ecf9761 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 13:34:00 +0530 Subject: [PATCH 13/20] Standard --- app/controllers/api/v3/sync_controller.rb | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/app/controllers/api/v3/sync_controller.rb b/app/controllers/api/v3/sync_controller.rb index 9e26aa0bfe..d5f7ad05dd 100644 --- a/app/controllers/api/v3/sync_controller.rb +++ b/app/controllers/api/v3/sync_controller.rb @@ -18,7 +18,7 @@ def __sync_to_user__(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 @@ -48,9 +48,9 @@ def log_block_level_sync_metrics(response_key) 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 + region_type: current_sync_region.class.name, + region_id: current_sync_region.id, + resource: response_key end if block_level_sync? From bb928d3b1c36e86b5b208401e4e8cb7503840ba9 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 13:44:32 +0530 Subject: [PATCH 14/20] Add specs for duplicate_passport_count --- .../report_duplicate_passports_spec.rb | 68 ++++++++++++++++--- 1 file changed, 58 insertions(+), 10 deletions(-) diff --git a/spec/services/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb index 34a4599727..fd0de27440 100644 --- a/spec/services/report_duplicate_passports_spec.rb +++ b/spec/services/report_duplicate_passports_spec.rb @@ -1,6 +1,56 @@ 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 } @@ -16,9 +66,8 @@ 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: []) - patients.map do |patient| - create(:patient_business_identifier, identifier: identifier, patient: patient, metadata: {assigningFacilityUuid: facility_id}) - end + 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 @@ -33,21 +82,20 @@ 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.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}), - create(:patient_business_identifier, identifier: identifier, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid})] + 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 - 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.first, metadata: {assigningFacilityUuid: SecureRandom.uuid}) - create(:patient_business_identifier, identifier: SecureRandom.uuid, patient: patients.second, metadata: {assigningFacilityUuid: SecureRandom.uuid}) + 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 From 9a442646c92a549fc534288a64f658b47bc240ea Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 13:49:16 +0530 Subject: [PATCH 15/20] Standard --- spec/services/report_duplicate_passports_spec.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spec/services/report_duplicate_passports_spec.rb b/spec/services/report_duplicate_passports_spec.rb index fd0de27440..4615d8b84e 100644 --- a/spec/services/report_duplicate_passports_spec.rb +++ b/spec/services/report_duplicate_passports_spec.rb @@ -1,7 +1,7 @@ require "rails_helper" RSpec.describe ReportDuplicatePassports do - describe '.duplicate_passports_count' do + describe ".duplicate_passports_count" do context "for passports with the same identifiers" do let!(:identifier) { SecureRandom.uuid } From d79dfbbb52b32ce06d5a7b21f8e3bc80e91916ee Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 14:56:01 +0530 Subject: [PATCH 16/20] Pull out `model` --- app/controllers/api/v3/patients_controller.rb | 21 +++++++++++-------- .../concerns/api/v3/sync_to_user.rb | 5 ++++- 2 files changed, 16 insertions(+), 10 deletions(-) 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/concerns/api/v3/sync_to_user.rb b/app/controllers/concerns/api/v3/sync_to_user.rb index e13bdef9d4..0d3819b899 100644 --- a/app/controllers/concerns/api/v3/sync_to_user.rb +++ b/app/controllers/concerns/api/v3/sync_to_user.rb @@ -3,7 +3,6 @@ module Api::V3::SyncToUser included do def region_records - model = controller_name.classify.constantize model.syncable_to_region(current_sync_region) end @@ -27,6 +26,10 @@ def other_facility_records private + def model + controller_name.classify.constantize + end + def records_to_sync Statsd.instance.time("records_to_sync.#{model.name}") do current_facility_records + other_facility_records From 4126890aaaa88d382a32bf9f512dc2cae8ca8000 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 15:44:28 +0530 Subject: [PATCH 17/20] Fix spec name --- spec/controllers/api/v3/facilities_controller_spec.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/spec/controllers/api/v3/facilities_controller_spec.rb b/spec/controllers/api/v3/facilities_controller_spec.rb index 5180046d8e..732811c5f6 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 From e237095f924a53fd1200d6ef4272e2bfe1a732b9 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 17:30:56 +0530 Subject: [PATCH 18/20] Make build green --- spec/controllers/api/v3/facilities_controller_spec.rb | 1 + 1 file changed, 1 insertion(+) diff --git a/spec/controllers/api/v3/facilities_controller_spec.rb b/spec/controllers/api/v3/facilities_controller_spec.rb index 732811c5f6..5bed3c6e25 100644 --- a/spec/controllers/api/v3/facilities_controller_spec.rb +++ b/spec/controllers/api/v3/facilities_controller_spec.rb @@ -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) From f94d1e61cf8f9642d62f38dd44422c99f2ac4d20 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Fri, 25 Dec 2020 17:32:31 +0530 Subject: [PATCH 19/20] Removing tag from log --- lib/tasks/block_level_sync.rake | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/lib/tasks/block_level_sync.rake b/lib/tasks/block_level_sync.rake index 6b689d7615..8c3ab6d4fc 100644 --- a/lib/tasks/block_level_sync.rake +++ b/lib/tasks/block_level_sync.rake @@ -42,8 +42,7 @@ def set_block_level_sync(user, enable) Rails.logger.info msg: "Block level sync #{enable ? "enabled" : "disabled"} for #{user.id}", block_level_sync_enabled_user_id: user.id else - Rails.logger.info msg: "User #{user.id} does not have a phone number authentication", - block_level_sync_disabled_user_id: user.id + Rails.logger.info msg: "User #{user.id} does not have a phone number authentication" end end end From 0b2be88a9116f0c561a50d82cba0c7e4a70fa5d2 Mon Sep 17 00:00:00 2001 From: Akshay Gupta Date: Mon, 28 Dec 2020 20:18:18 +0530 Subject: [PATCH 20/20] [unrelated] Filter out admins for block-sync percentage rollout --- lib/tasks/scripts/block_level_sync.rb | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) 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