Capture better errors for failed grade passback

This adds oauth info to captured error exceptions

Fixes PLAT-1256

Test Plan:
The error report should include all of the OAuth1 header information
If the Authorization Header is not OAuth1 it should not include it
The error report should also include the signature canvas generates
The error report should include where the authorization failed. i.e.
signature, nonce, expiration

The best way to test this is run the test :D
The best way to manually test this:
- Setup an LTI Tool (I used the example tool with all the checkboxes
  checked)
- Use post man stand alone
- create a new request to "/api/lti/v1/tools/<tool_id>/grade_passback"
- Use post man's Authorization tab to setup OAuth1
- Use the tools key and secret
- tweak settings for different failure tests
- select add params to header
- click update request
- send the request

You will need to manually change the auth header to get to some
failures. Let me know if you need help

Change-Id: If09882017eaae0ddff96d39b7f33c2da9c1a7fc8
Reviewed-on: https://gerrit.instructure.com/65944
Tested-by: Jenkins
Reviewed-by: Nathan Mills <nathanm@instructure.com>
QA-Review: August Thornton <august@instructure.com>
Product-Review: Brad Horrocks <bhorrocks@instructure.com>

app/controllers/application_controller.rb

@@ -1085,6 +1085,7 @@ class ApplicationController < ActionController::Base
       # exceptions we want skipped
       unless exception.respond_to?(:skip_error_report?) && exception.skip_error_report?
         opts = {type: type}
+        opts[:canvas_error_info] = exception.canvas_error_info if exception.respond_to?(:canvas_error_info)
         info = Canvas::Errors::Info.new(request, @domain_root_account, @current_user, opts)
         error_info = info.to_h
         error_info[:tags][:response_code] = response_code
@@ -1177,6 +1178,9 @@ class ApplicationController < ActionController::Base
       data = { errors: [{message: 'Invalid access token.'}] }
     when ActionController::ParameterMissing
       data = { errors: [{message: "#{exception.param} is missing"}] }
+    when BasicLTI::BasicOutcomes::Unauthorized,
+        BasicLTI::BasicOutcomes::InvalidRequest
+      data = { errors: [{message: exception.message}] }
     else
       if status_code.is_a?(Symbol)
         status_code_string = status_code.to_s

app/controllers/lti_api_controller.rb

@@ -30,16 +30,13 @@ class LtiApiController < ApplicationController
     verify_oauth
 
     if request.content_type != "application/xml"
-      return render :text => '', :status => 415
+      raise BasicLTI::BasicOutcomes::InvalidRequest, "Content-Type must be 'application/xml'"
     end
 
     xml = Nokogiri::XML.parse(request.body)
 
     lti_response = BasicLTI::BasicOutcomes.process_request(@tool, xml)
     render :text => lti_response.to_xml, :content_type => 'application/xml'
-
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    render :text => e.to_s, :status => 401
   end
 
   # this similar API implements the older work-in-process BLTI 0.0.4 outcome
@@ -50,9 +47,6 @@ class LtiApiController < ApplicationController
 
     lti_response = BasicLTI::BasicOutcomes.process_legacy_request(@tool, params)
     render :text => lti_response.to_xml, :content_type => 'application/xml'
-
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    render :text => e.to_s, :status => 401
   end
 
   # examples: https://github.com/adlnet/xAPI-Spec/blob/master/xAPI.md#AppendixA
@@ -92,8 +86,6 @@ class LtiApiController < ApplicationController
     Lti::XapiService.log_page_view(token, params)
 
     return render :text => '', :status => 200
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    return render :text => e, :status => 401
   end
 
   #
@@ -130,8 +122,6 @@ class LtiApiController < ApplicationController
     Lti::CaliperService.log_page_view(token, params)
 
     return render :text => '', :status => 200
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    return render :text => e, :status => 401
   end
 
   def logout_service
@@ -139,8 +129,6 @@ class LtiApiController < ApplicationController
     verify_oauth(token.tool)
     Lti::LogoutService.register_logout_callback(token, params[:callback])
     return render :text => '', :status => 200
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    return render :text => e, :status => 401
   end
 
   def turnitin_outcomes_placement
@@ -151,8 +139,6 @@ class LtiApiController < ApplicationController
     turnitin_processor = Turnitin::OutcomeResponseProcessor.new(@tool, assignment, user, JSON.parse(request.body.read))
     turnitin_processor.process
     render json: {}, status: 200
-  rescue BasicLTI::BasicOutcomes::Unauthorized => e
-    return render :text => e, status:401
   end
 
 
@@ -166,21 +152,28 @@ class LtiApiController < ApplicationController
     begin
       @signature = OAuth::Signature.build(request, :consumer_secret => @tool.shared_secret)
       @signature.verify() or raise OAuth::Unauthorized
-    rescue OAuth::Signature::UnknownSignatureMethod,
-           OAuth::Unauthorized
-      raise BasicLTI::BasicOutcomes::Unauthorized, "Invalid authorization header"
+
+    rescue OAuth::Signature::UnknownSignatureMethod, OAuth::Unauthorized => e
+      Canvas::Errors::Reporter.raise_canvas_error(BasicLTI::BasicOutcomes::Unauthorized, "Invalid authorization header", oauth_error_info.merge({error_class: e.class.name}))
     end
 
     timestamp = Time.zone.at(@signature.request.timestamp.to_i)
     # 90 minutes is suggested by the LTI spec
     allowed_delta = Setting.get('oauth.allowed_timestamp_delta', 90.minutes.to_s).to_i
     if timestamp < allowed_delta.ago || timestamp > allowed_delta.from_now
-      raise BasicLTI::BasicOutcomes::Unauthorized, "Timestamp too old or too far in the future, request has expired"
+      Canvas::Errors::Reporter.raise_canvas_error(BasicLTI::BasicOutcomes::Unauthorized, "Timestamp too old or too far in the future, request has expired", oauth_error_info)
     end
 
     nonce = @signature.request.nonce
     unless Canvas::Redis.lock("nonce:#{@tool.asset_string}:#{nonce}", allowed_delta)
-      raise BasicLTI::BasicOutcomes::Unauthorized, "Duplicate nonce detected"
+      Canvas::Errors::Reporter.raise_canvas_error(BasicLTI::BasicOutcomes::Unauthorized, "Duplicate nonce detected", oauth_error_info)
     end
   end
+
+  def oauth_error_info
+    return {} unless @signature
+    {
+      generated_signature: @signature.signature
+    }
+  end
 end

lib/basic_lti/basic_outcomes.rb

@@ -20,10 +20,20 @@ require 'nokogiri'
 
 module BasicLTI
   module BasicOutcomes
-    class Unauthorized < Exception;
+    class Unauthorized < StandardError
+      def response_status
+        401
+      end
     end
 
-    class InvalidSourceId < Exception;
+
+    class InvalidRequest < StandardError
+      def response_status
+        415
+      end
+    end
+
+    class InvalidSourceId < StandardError
     end
 
     SOURCE_ID_REGEX = %r{^(\d+)-(\d+)-(\d+)-(\d+)-(\w+)$}

lib/canvas/errors/info.rb

@@ -16,6 +16,7 @@ module Canvas
         @user = user
         @rci = opts.fetch(:request_context_id, RequestContextGenerator.request_id)
         @type = opts.fetch(:type, nil)
+        @canvas_error_info = opts.fetch(:canvas_error_info, {})
       end
 
       # The ideal hash format to pass to Canvas::Errors.capture().
@@ -32,9 +33,10 @@ module Canvas
             request_context_id: @rci,
             request_method: @req.request_method_symbol,
             format: @req.format,
-            user_agent: @req.headers['User-Agent'],
             user_id: @user.try(:global_id),
           }.merge(self.class.useful_http_env_stuff_from_request(@req))
+                   .merge(self.class.useful_http_headers(@req))
+                   .merge(@canvas_error_info)
         }
       end
 
@@ -61,6 +63,19 @@ module Canvas
         Marshal.load(Marshal.dump(req_stuff))
       end
 
+      def self.useful_http_headers(req)
+        headers = {
+          user_agent: req.headers['User-Agent']
+        }
+
+        # if we have an oauth1 header lets get the appropriate info from it
+        if req.authorization && req.authorization.match(/^OAuth/)
+          headers.merge!(OAuth::Helper.parse_header(req.authorization))
+        end
+
+        headers
+      end
+
       def self.filtered_request_params(req, query_string)
         f = LoggingFilter
         {

lib/canvas/errors/reporter.rb

@@ -0,0 +1,30 @@
+require_relative '../errors'
+
+module Canvas
+  class Errors
+    class Reporter
+      def self.raise_canvas_error(existing_exception_class, message, opts={})
+        # This little bit of code lets you add meta data to your existing exceptions, without having to
+        # modify the exception, create a new exception (and updating rescues)!
+        #
+        # this was the best we could come up with to accomplish the following
+        # - Add metadata to the exception by adding a `canvas_error_info` method
+        # - Couldn't modify existing_exception_class directly
+        # - New exceptions needs to be rescue-able by rescues for the existing_exception_class
+        #
+        # Now anytime you want to add metadata to an exception you do:
+        # ```
+        # raise Canvas::Errors::Reporter.raise_canvas_error(BasicLTI::BasicOutcomes::Unauthorized, "Duplicate nonce detected", oauth_error_info)
+        # ```
+        err = existing_exception_class.new(message)
+        err.instance_variable_set(:@canvas_error_info, opts)
+        class << err
+          attr_reader :canvas_error_info
+        end
+
+        # this makes the stack trace originate from the call before this one
+        raise err, message, caller
+      end
+    end
+  end
+end

spec/apis/lti/grade_passback_spec.rb

@@ -32,6 +32,34 @@ describe LtiApiController, type: :request do
     tag.save!
   end
 
+  def check_error_response(message, check_generated_sig=true)
+    expect(response.body.strip).to_not be_empty, "Should not have an empty response body"
+
+    json = JSON.parse response.body
+    expect(json["errors"][0]["message"]).to eq message
+    expect(json["error_report_id"]).to be > 0
+
+    data = error_data(json)
+
+    expect(data.key?('oauth_signature')).to be true
+    expect(data.key?('oauth_signature_method')).to be true
+    expect(data.key?('oauth_nonce')).to be true
+    expect(data.key?('oauth_timestamp')).to be true
+    expect(data.key?('generated_signature')).to be true if check_generated_sig
+
+    expect(data['oauth_signature']).to_not be_empty
+    expect(data['oauth_signature_method']).to_not be_empty
+    expect(data['oauth_nonce']).to_not be_empty
+    expect(data['oauth_timestamp']).to_not be_empty
+    expect(data['generated_signature']).to_not be_empty if check_generated_sig
+  end
+
+  def error_data(json=nil)
+    json ||= JSON.parse response.body
+    error_report = ErrorReport.find json["error_report_id"]
+    error_report.data
+  end
+
   def make_call(opts = {})
     opts['path'] ||= "/api/lti/v1/tools/#{@tool.id}/grade_passback"
     opts['key'] ||= @tool.consumer_key
@@ -39,10 +67,17 @@ describe LtiApiController, type: :request do
     opts['content-type'] ||= 'application/xml'
     consumer = OAuth::Consumer.new(opts['key'], opts['secret'], :site => "https://www.example.com", :signature_method => "HMAC-SHA1")
     req = consumer.create_signed_request(:post, opts['path'], nil, :scheme => 'header', :timestamp => opts['timestamp'], :nonce => opts['nonce'])
+
+    auth = req['Authorization']
+    if opts['override_signature_method']
+      auth.gsub! "HMAC-SHA1", opts['override_signature_method']
+    end
+
     req.body = opts['body'] if opts['body']
     post "https://www.example.com#{req.path}",
       req.body,
-      { "CONTENT_TYPE" => opts['content-type'], "HTTP_AUTHORIZATION" => req['Authorization'] }
+      { "CONTENT_TYPE" => opts['content-type'], "HTTP_AUTHORIZATION" => auth }
+
   end
 
   def source_id
@@ -63,9 +98,48 @@ describe LtiApiController, type: :request do
     assert_status(415)
   end
 
-  it "should require the correct shared secret" do
-    make_call('secret' => 'bad secret is bad')
-    assert_status(401)
+  context "OAuth Requests" do
+    it "should fail on invalid signature method" do
+      make_call('override_signature_method' => 'BawkBawk256')
+      check_error_response("Invalid authorization header", false)
+      data = error_data
+
+      expect(data['error_class']).to eq "OAuth::Signature::UnknownSignatureMethod"
+      assert_status(401)
+    end
+
+    it "should require the correct shared secret" do
+      make_call('secret' => 'bad secret is bad')
+      check_error_response("Invalid authorization header")
+
+      data = error_data
+      expect(data['error_class']).to eq "OAuth::Unauthorized"
+
+      assert_status(401)
+    end
+
+    if Canvas.redis_enabled?
+      it "should not allow the same nonce to be used more than once" do
+        make_call('nonce' => 'not_so_random', 'content-type' => 'none')
+        assert_status(415)
+        make_call('nonce' => 'not_so_random', 'content-type' => 'none')
+        assert_status(401)
+        check_error_response("Duplicate nonce detected")
+      end
+    end
+
+    it "should block timestamps more than 90 minutes old" do
+      # the 90 minutes value is suggested by the LTI spec
+      make_call('timestamp' => 2.hours.ago.utc.to_i, 'content-type' => 'none')
+      assert_status(401)
+      expect(response.body).to match(/expired/i)
+      check_error_response("Timestamp too old or too far in the future, request has expired")
+    end
+
+    context "Error reports" do
+      context "Oauth 1" do
+      end
+    end
   end
 
   def replace_result(opts={})
@@ -521,23 +595,6 @@ to because the assignment has no points possible.
     check_failure('failure', 'Invalid sourcedid')
   end
 
-  if Canvas.redis_enabled?
-    it "should not allow the same nonce to be used more than once" do
-      make_call('nonce' => 'not_so_random', 'content-type' => 'none')
-      assert_status(415)
-      make_call('nonce' => 'not_so_random', 'content-type' => 'none')
-      assert_status(401)
-      expect(response.body).to match(/nonce/i)
-    end
-  end
-
-  it "should block timestamps more than 90 minutes old" do
-    # the 90 minutes value is suggested by the LTI spec
-    make_call('timestamp' => 2.hours.ago.utc.to_i, 'content-type' => 'none')
-    assert_status(401)
-    expect(response.body).to match(/expired/i)
-  end
-
   it "fails if course is deleted" do
     opts = {'body' => replace_result(score: '0.6')}
     @course.destroy

spec/controllers/application_controller_spec.rb

@@ -505,6 +505,7 @@ describe ApplicationController do
         req = mock()
         req.stubs(:url).returns('url')
         req.stubs(:headers).returns({})
+        req.stubs(:authorization).returns(nil)
         req.stubs(:request_method_symbol).returns(:get)
         req.stubs(:format).returns('format')
 

spec/lib/basic_lti/basic_outcomes_spec.rb

@@ -86,6 +86,27 @@ describe BasicLTI::BasicOutcomes do
     }
   end
 
+  context "Exceptions" do
+    it "BasicLTI::BasicOutcomes::Unauthorized should have 401 status" do
+
+      begin
+        raise BasicLTI::BasicOutcomes::Unauthorized, "Invalid signature"
+      rescue BasicLTI::BasicOutcomes::Unauthorized => e
+        expect(e.response_status).to be 401
+      end
+    end
+
+    it "BasicLTI::BasicOutcomes::InvalidRequest should have 415 status" do
+
+      begin
+        raise BasicLTI::BasicOutcomes::InvalidRequest, "Invalid request"
+      rescue BasicLTI::BasicOutcomes::InvalidRequest => e
+        expect(e.response_status).to be 415
+      end
+    end
+  end
+
+
   describe "#handle_replaceResult" do
     it "accepts a grade" do
       xml.css('resultData').remove

spec/lib/canvas/errors/info_spec.rb

@@ -5,10 +5,11 @@ module Canvas
       let(:request) do
         stub(env: {}, remote_ip: "", query_parameters: {},
              request_parameters: {}, path_parameters: {}, url: '',
-             request_method_symbol: '', format: 'HTML', headers: {})
+             request_method_symbol: '', format: 'HTML', headers: {}, authorization: nil)
       end
 
       let(:request_context_id){ 'abcdefg1234567'}
+      let(:auth_header){ "OAuth oauth_body_hash=\"2jmj7l5rSw0yVb%2FvlWAYkK%2FYBwk%3D\", oauth_consumer_key=\"test_key\", oauth_nonce=\"QFOhAwKHz0UATQSdycHdNkMZYpkhkzU1lYpwvIF3Q8\", oauth_signature=\"QUfER7WBKsq0nzIjJ8Y7iTcDaq0%3D\", oauth_signature_method=\"HMAC-SHA1\", oauth_timestamp=\"1445980405\", oauth_version=\"1.0\"" }
       let(:account){ stub(global_id: 1122334455) }
       let(:user) { stub(global_id: 5544332211)}
       let(:opts) { { request_context_id: request_context_id, type: 'core_meltdown' }}
@@ -53,6 +54,11 @@ module Canvas
           request.stubs(:headers).returns({'User-Agent'=>'the-agent'})
           expect(output[:extra][:user_agent]).to eq('the-agent')
         end
+
+        it 'passes oauth header info' do
+          request.stubs(:authorization).returns(auth_header)
+          check_oauth(output[:extra])
+        end
       end
 
       describe ".useful_http_env_stuff_from_request" do
@@ -72,6 +78,34 @@ module Canvas
         end
       end
 
+
+      describe ".useful_http_headers" do
+        it "returns some oauth header info" do
+          req = stub(authorization: auth_header, headers: {})
+          oauth_info = described_class.useful_http_headers(req)
+          check_oauth(oauth_info)
+        end
+
+        it "returns user agent" do
+          req = stub(headers: {'User-Agent'=>'the-agent'}, authorization: nil)
+          output = described_class.useful_http_headers(req)
+
+          expect(output[:user_agent]).to eq('the-agent')
+        end
+      end
+
+      def check_oauth(oauth_info)
+        expected_info = {
+          "oauth_body_hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=",
+          "oauth_consumer_key"=>"test_key",
+          "oauth_nonce"=>"QFOhAwKHz0UATQSdycHdNkMZYpkhkzU1lYpwvIF3Q8",
+          "oauth_signature"=>"QUfER7WBKsq0nzIjJ8Y7iTcDaq0=",
+          "oauth_signature_method"=>"HMAC-SHA1",
+          "oauth_timestamp"=>"1445980405",
+          "oauth_version"=>"1.0"
+        }
+        assert_hash_contains(oauth_info, expected_info)
+      end
     end
   end
 end

spec/lib/canvas/errors/reporter_spec.rb

@@ -0,0 +1,72 @@
+require 'spec_helper'
+
+class MyTestError < StandardError
+  def response_status
+    401
+  end
+end
+
+describe Canvas::Errors::Reporter do
+
+  it "Should be able to catch a composed exception" do
+    new_class = error_instance
+    exception_handled = false
+    begin
+      raise new_class
+    rescue MyTestError
+      exception_handled = true
+    end
+    expect(exception_handled).to be true
+  end
+
+  it "Should have extra info" do
+    new_class = error_instance
+    expect(new_class.respond_to?(:canvas_error_info)).to be true
+    expect(new_class.canvas_error_info[:princess_mode]).to be false
+    expect(new_class.canvas_error_info[:unicorn_spotted]).to be true
+    expect(new_class.canvas_error_info[:garbage]).to eq "%%jksdh38912398732987lkhjsadfkjhdfslk"
+  end
+
+  it "Should have correct backtrace" do
+    new_class = error_instance
+    expect(new_class.backtrace[0]).to match /typical_usage/
+  end
+
+  it "Shouldn't mess with existing classes" do
+    new_class = error_instance
+    old_class = MyTestError.new("i am a message")
+
+    expect(new_class).to_not be_nil
+    expect(old_class.respond_to?(:canvas_error_info)).to be false
+  end
+
+  it "Should inherrit from existing class" do
+    new_class = error_instance
+
+    expect(new_class.response_status).to be 401
+  end
+
+  it "Typical usecase" do
+    expect{typical_usage}.to raise_error(MyTestError)
+  end
+
+  def extra_error_info
+    {
+      princess_mode: false,
+      unicorn_spotted: true,
+      garbage: "%%jksdh38912398732987lkhjsadfkjhdfslk"
+    }
+  end
+
+  def error_instance
+    begin
+      typical_usage
+    rescue MyTestError => err
+      return err
+    end
+  end
+
+  def typical_usage
+    Canvas::Errors::Reporter.raise_canvas_error(MyTestError, "I am an error message", extra_error_info)
+  end
+end

spec/spec_helper.rb

@@ -540,6 +540,12 @@ RSpec.configure do |config|
     expect(parsed_test_query).to eq parsed_expected_query
   end
 
+  def assert_hash_contains(test_hash, expected_hash)
+    expected_hash.each do |key, expected_value|
+      expect(test_hash[key]).to eq expected_value
+    end
+  end
+
   def fixture_file_upload(path, mime_type=nil, binary=false)
     Rack::Test::UploadedFile.new(File.join(ActionController::TestCase.fixture_path, path), mime_type, binary)
   end