add logging around tool reinstallation

closes PLAT-4725

Test Plan:
- verify the ability to still add/remove a tool, preferrable
  the plagarism platform tool
- verify that removing and adding tool logs all relavant method
  calls

Change-Id: Ia7e7f41ba0503d58faf64de7fe0d19c3ac9eaf61
Reviewed-on: https://gerrit.instructure.com/205803
Reviewed-by: Weston Dransfield <wdransfield@instructure.com>
Tested-by: Jenkins
QA-Review: Weston Dransfield <wdransfield@instructure.com>
Product-Review: Clint Furse <cfurse@instructure.com>

app/controllers/lti/tool_proxy_controller.rb

@@ -96,6 +96,10 @@ module Lti
     end
 
     def update_workflow_state(workflow_state)
+      Rails.logger.info do
+        "in: ToolProxyController::update_workflow_state, tool_id: #{@tool_proxy.id}, "\
+        "old state: #{@tool_proxy.workflow_state}, new state: #{workflow_state}"
+      end
       @tool_proxy.update_attribute(:workflow_state, workflow_state)
 
       # destroy or create subscriptions

app/models/assignment_configuration_tool_lookup.rb

@@ -46,6 +46,10 @@ class AssignmentConfigurationToolLookup < ActiveRecord::Base
     end
 
     def recreate_missing_subscriptions(account, message_handler)
+      Rails.logger.info do
+        "in: AssignmentConfigurationToolLookup::recreate_missing_subscriptions,"\
+        "account_id: #{account.id}, handler_id: #{message_handler.id}"
+      end
       Assignment.active.where(
         context_id: Course.not_deleted.where(account: account).pluck(:id)
       ).find_in_batches do |assignments|
@@ -56,6 +60,10 @@ class AssignmentConfigurationToolLookup < ActiveRecord::Base
     private
 
     def recreate_subscriptions(message_handler, assignments)
+      Rails.logger.info do
+        "in: AssignmentConfigurationToolLookup::recreate_subscriptions, "\
+        "handler_id: #{message_handler.id}, assignments_size: #{assignments.count}"
+      end
       by_message_handler(message_handler, assignments).each do |lookup|
         lookup.destroy_subscription
         lookup.create_subscription
@@ -79,6 +87,7 @@ class AssignmentConfigurationToolLookup < ActiveRecord::Base
   end
 
   def destroy_subscription
+    Rails.logger.info { "in: AssignmentConfigurationToolLookup::destroy_subscription, tool_lookup_id: #{id}" }
     return unless lti_tool.instance_of? Lti::MessageHandler
     tool_proxy = lti_tool.resource_handler.tool_proxy
     Lti::AssignmentSubscriptionsHelper.new(tool_proxy).destroy_subscription(subscription_id)

app/models/lti/message_handler.rb

@@ -106,6 +106,7 @@ module Lti
     end
 
     def recreate_missing_subscriptions
+      Rails.logger.info { "in: MessageHandler::recreate_missing_subscriptions, handler_id: #{id}" }
       # Only attempt to recreate subscriptions for account level plagiarism tools
       return unless tool_proxy&.context.is_a?(Account) &&
         capabilities&.include?(Lti::ResourcePlacement::SIMILARITY_DETECTION_LTI2)

app/models/lti/tool_proxy_service.rb

@@ -24,10 +24,12 @@ module Lti
 
     class << self
       def delete_subscriptions(tool_proxy)
+        Rails.logger.info { "in: ToolProxyService::delete_subscriptions, tool_proxy_id: #{tool_proxy.id}" }
         self.new.delete_subscriptions_for(tool_proxy)
       end
 
       def recreate_missing_subscriptions(tool_proxy)
+        Rails.logger.info { "in: ToolProxyService::recreate_missing_subscriptions, tool_proxy_id: #{tool_proxy.id}" }
         tool_proxy&.message_handlers&.each(&:recreate_missing_subscriptions)
       end
     end
@@ -81,6 +83,7 @@ module Lti
     end
 
     def delete_subscriptions_for(tool_proxy)
+      Rails.logger.info { "in: ToolProxyService::delete_subscriptions_for, tool_id: #{tool_proxy.id}" }
       product_family = tool_proxy.product_family
       subscription_helper = AssignmentSubscriptionsHelper.new(tool_proxy)
       lookups = AssignmentConfigurationToolLookup.where(tool_product_code: product_family.product_code,

lib/lti/assignment_subscriptions_helper.rb

@@ -35,6 +35,7 @@ module Lti
     end
 
     def create_subscription
+      Rails.logger.info { "in: AssignmentSubscriptionsHelper::create_subscription, assignment_id: #{assignment.id}, tool_proxy_id: #{tool_proxy.id}" }
       if Services::LiveEventsSubscriptionService.available? && assignment.present?
         subscription = assignment_subscription(assignment.global_id)
         result = Services::LiveEventsSubscriptionService.create_tool_proxy_subscription(tool_proxy, subscription)
@@ -57,6 +58,7 @@ module Lti
     end
 
     def destroy_subscription(subscription_id)
+      Rails.logger.info { "in: AssignmentSubscriptionsHelper::destroy_subscription, subscription_id: #{subscription_id}" }
       if Services::LiveEventsSubscriptionService.available?
         Services::LiveEventsSubscriptionService.destroy_tool_proxy_subscription(tool_proxy, subscription_id)
       end

lib/services/live_events_subscription_service.rb

@@ -33,6 +33,10 @@ module Services
       end
 
       def create_tool_proxy_subscription(tool_proxy, subscription)
+        Rails.logger.info do
+          "in: LiveEventsSubscriptionService::create_tool_proxy_subscription, "\
+          "tool_proxy_id: #{tool_proxy.id}, subscription: #{subscription}"
+        end
         options = {
           headers: headers(tool_proxy_jwt_body(tool_proxy), { 'Content-Type' => 'application/json' }),
           body: subscription.to_json
@@ -49,6 +53,10 @@ module Services
       end
 
       def destroy_tool_proxy_subscription(tool_proxy, subscription_id)
+        Rails.logger.info do
+          "in: LiveEventsSubscriptionService::destroy_tool_proxy_subscription, "\
+          "tool_proxy_id: #{tool_proxy.id}, subscription_id: #{subscription_id}"
+        end
         options = { headers: headers(tool_proxy_jwt_body(tool_proxy)) }
         request(:delete, "/api/subscriptions/#{subscription_id}", options)
       end

spec/lib/services/live_events_subscription_service_spec.rb

@@ -87,6 +87,7 @@ module Services
 
       let(:tool_proxy) do
         tool_proxy = double()
+        allow(tool_proxy).to receive(:id).and_return('1')
         allow(tool_proxy).to receive(:guid).and_return('151b52cd-d670-49fb-bf65-6a327e3aaca0')
         allow(tool_proxy).to receive(:product_family).and_return(product_family)
         tool_proxy