From 3d8f90e9d875d39a51ad6bf7acd1e1c4ace7e8c6 Mon Sep 17 00:00:00 2001 From: Evan Battaglia Date: Mon, 30 Jan 2023 14:10:19 -0700 Subject: [PATCH] better errors / stats for Turnitin errors This will help us what the story is with the sudden uptick in these errors, and replace the "private method select for NilClass" errors with a less-generic error flag=none refs INTEROP-7919 Test plan: - add some debugging to the statsd code, e.g. add to initializers/inst_statsd.rb: class << InstStatsd::Statsd def increment(*args) puts "DEBUG STATSD increment: #{args.to_json}" end end - get the contents of a failed job from prod from an employee sandbox. puts the `job.handler`. From this you will need: - get the referenced tool and copy the key and secret - copy the outcomes_response_json - In a rails console you can then run Turnitin::OutcomeResponseProcessor.new( ContextExternalTool.new(key: KEY, secret: SECRET), Assignment.find(ANY_EXISTING_ASSIGNMENT), # Assignment.new might also work User.find(ANY_EXISTING_USER), OUTCOMES_RESPONSE_JSON_HASH ).update_originality_data( ANY_EXISTING_SUBMISSION, # Submission.new might also work "attachment_1234" ) - run the job and watch it increment the correct statsd counter and check /error_reports to check that the error is accurate. Both the stastsd counter and the error in error_reports identifies the message body as one of the known error messages Change-Id: Ic73cd590de7ae0c304d6c4cc12b707692e9685dc Reviewed-on: https://gerrit.instructure.com/c/canvas-lms/+/309945 Tested-by: Service Cloud Jenkins QA-Review: Evan Battaglia Build-Review: Jacob Burroughs Reviewed-by: Paul Gray Product-Review: Paul Gray --- Gemfile.rails61.lock.partial | 2 + Gemfile.rails70.lock.partial | 2 + .../outcomes_response_transformer.rb | 28 +++++++++- .../outcomes_response_transformer_spec.rb | 53 ++++++++++++++++++- gems/turnitin_api/turnitin_api.gemspec | 2 + 5 files changed, 85 insertions(+), 2 deletions(-) diff --git a/Gemfile.rails61.lock.partial b/Gemfile.rails61.lock.partial index eb6d2eb02ed..4639a1ececd 100644 --- a/Gemfile.rails61.lock.partial +++ b/Gemfile.rails61.lock.partial @@ -321,8 +321,10 @@ PATH railties stringify_ids (1.0.0) turnitin_api (0.1.0) + activesupport faraday (~> 0.17.3) faraday_middleware (~> 0.8) + inst_statsd simple_oauth (~> 0.3) twitter (1.0.0) html_text_helper diff --git a/Gemfile.rails70.lock.partial b/Gemfile.rails70.lock.partial index c5a21c86d64..6cc3893d29d 100644 --- a/Gemfile.rails70.lock.partial +++ b/Gemfile.rails70.lock.partial @@ -321,8 +321,10 @@ PATH railties stringify_ids (1.0.0) turnitin_api (0.1.0) + activesupport faraday (~> 0.17.3) faraday_middleware (~> 0.8) + inst_statsd simple_oauth (~> 0.3) twitter (1.0.0) html_text_helper diff --git a/gems/turnitin_api/lib/turnitin_api/outcomes_response_transformer.rb b/gems/turnitin_api/lib/turnitin_api/outcomes_response_transformer.rb index 495e840d66e..aed40d4a0d5 100644 --- a/gems/turnitin_api/lib/turnitin_api/outcomes_response_transformer.rb +++ b/gems/turnitin_api/lib/turnitin_api/outcomes_response_transformer.rb @@ -18,6 +18,8 @@ # with this program. If not, see . require "simple_oauth" +require "inst_statsd" +require "active_support/core_ext/string/filters" module TurnitinApi class OutcomesResponseTransformer @@ -27,6 +29,16 @@ module TurnitinApi attr_accessor :outcomes_response_json, :key, :lti_params + class InvalidResponse < StandardError; end + + KNOWN_ERROR_MESSAGES = { + api_login_failed: 'API Login failed: "oauth_signature" incorrect credentials and/or signature calculation', + api_product_inactive: "API product inactive or expired", + oauth_consumer_key: '"oauth_consumer_key" value is missing or not valid.', + not_enabled: "This integration is not currently enabled. Contact your account administrator.", + not_found: "The requested Object Result could not be found." + }.freeze + def initialize(key, secret, lti_params, outcomes_response_json) @key = key @secret = secret @@ -35,7 +47,21 @@ module TurnitinApi end def response - @response ||= make_call(outcomes_response_json["outcomes_tool_placement_url"]) + @response ||= make_call(outcomes_response_json["outcomes_tool_placement_url"]).tap do |resp| + if (200..299).cover?(resp.status) + resp + else + error_msg = KNOWN_ERROR_MESSAGES.find { |_name, text| resp.body&.include?(text) }&.first + error_msg ||= :unknown + + stats_tags = { status: resp.status, message: error_msg } + InstStatsd::Statsd.increment("lti.tii.outcomes_response_bad", tags: stats_tags) + + raise InvalidResponse, + "TII returned #{resp.status} code, content length=#{resp.body&.length}, " \ + "message #{error_msg}, body #{resp.body&.truncate(100).inspect}" + end + end end # download original diff --git a/gems/turnitin_api/spec/outcomes_response_transformer_spec.rb b/gems/turnitin_api/spec/outcomes_response_transformer_spec.rb index bd5418f89b3..a4155bc951d 100644 --- a/gems/turnitin_api/spec/outcomes_response_transformer_spec.rb +++ b/gems/turnitin_api/spec/outcomes_response_transformer_spec.rb @@ -42,14 +42,65 @@ describe TurnitinApi::OutcomesResponseTransformer do end describe "response" do + let(:stubbed_response) do + { + status: 200, + body: fixture("outcome_detailed_response.json"), + headers: { "Content-Type" => "application/json" } + } + end + before do stub_request(:post, "http://turnitin.com/api/lti/1p0/outcome_tool_data/4321") - .to_return(status: 200, body: fixture("outcome_detailed_response.json"), headers: { "Content-Type" => "application/json" }) + .to_return(stubbed_response) end it "returns expected json response" do expect(subject.response.body["outcome_originalfile"]["launch_url"]).to eq "https://turnitin.com/api/lti/1p0/dow...72874634?lang=" end + + context "when TII returns a non-2xx response" do + let(:stubbed_body) { "TII errored out oh no " * 10 } + let(:stubbed_response) { { status: 403, body: stubbed_body } } + let(:truncated_body) { stubbed_body.truncate(100).inspect } + + it "raises an InvalidResponse error with the status code and content length" do + expect { subject.response }.to raise_error( + described_class::InvalidResponse, + "TII returned 403 code, content length=#{stubbed_body.length}, message unknown, body #{truncated_body}" + ) + end + + it "increments a statsd counter which includes the status code" do + allow(InstStatsd::Statsd).to receive(:increment) + expect { subject.response }.to raise_error(described_class::InvalidResponse) + expect(InstStatsd::Statsd).to have_received(:increment).with( + "lti.tii.outcomes_response_bad", + tags: { status: 403, message: :unknown } + ) + end + + context "when the response body is one of the known recognized ones" do + let(:stubbed_body) { "bla bla API product inactive or expired bla bla" } + let(:stubbed_response) { { status: 401, body: stubbed_body } } + + it "identifies known responses in the InvalidResponse error" do + expect { subject.response }.to raise_error( + described_class::InvalidResponse, + "TII returned 401 code, content length=47, message api_product_inactive, body #{truncated_body}" + ) + end + + it "identifies known responses in the statsd counter" do + allow(InstStatsd::Statsd).to receive(:increment) + expect { subject.response }.to raise_error(described_class::InvalidResponse) + expect(InstStatsd::Statsd).to have_received(:increment).with( + "lti.tii.outcomes_response_bad", + tags: { status: 401, message: :api_product_inactive } + ) + end + end + end end describe "original_submission" do diff --git a/gems/turnitin_api/turnitin_api.gemspec b/gems/turnitin_api/turnitin_api.gemspec index 31aa24020f2..3b7636ed3c8 100644 --- a/gems/turnitin_api/turnitin_api.gemspec +++ b/gems/turnitin_api/turnitin_api.gemspec @@ -15,8 +15,10 @@ Gem::Specification.new do |spec| spec.executables = spec.files.grep(%r{^exe/}) { |f| File.basename(f) } spec.require_paths = ["lib"] + spec.add_dependency "activesupport" spec.add_dependency "faraday", "~> 0.17.3" spec.add_dependency "faraday_middleware", "~> 0.8" + spec.add_dependency "inst_statsd" spec.add_dependency "simple_oauth", "~> 0.3" spec.add_development_dependency "bundler", "~> 2.2"