Hosting LTI provider on different domain about ltijs

[michaelerobertsjr]

Thanks @Cvmcosta

Earlier today I figured out that there was some caching in the db so we have been dropping the db between tests to ensure we were getting a fresh session/cookie set.

I'm beginning to think it's an issue with the version of Moodle or permissions that are different in production.

If you have some time I think a hangout would be helpful. Can you email me at mike at sdcs.io and we can plan a time to jump on a screen share.

[hank-frank]

Thank you for the super fast response. I’ll give it a shot right now.

…

On Apr 13, 2020, at 5:57 PM, Carlos Vinícius Monteiro Costa ***@***.***> wrote: Hello! I think you should be sending the request to your Ltijs instance inteasd of moodle. You should send the request to a /grade endpoint in your Ltijs and then have something like: lti.app.post('/grade', async (req, res) => { try { const grade = { scoreGiven: 80, activityProgress: 'Completed', gradingProgress: 'FullyGraded' } // Sends a grade to a platform's grade line lti.Grade.ScorePublish(res.locals.token, grade) return res.send('Grade Succesfully Created') } catch (err) { return res.status(500).send(err.message) } }) Then the Grade.ScorePublish call will handle sending the grade to your Moodle. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#31 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ALTG55PFKC74DMFCFPHVZQTRMOYIDANCNFSM4MHK2G7A>.

[Cvmcosta]

Hello! I think you should be sending the request to your Ltijs instance instead of moodle.
You should send the request to a /grade endpoint in your Ltijs and then have something like:

lti.app.post('/grade', async (req, res) => {
  try {
    const grade = {
      scoreGiven: 80,
      activityProgress: 'Completed',
      gradingProgress: 'FullyGraded'
    }

    // Sends a grade to a platform's grade line
    lti.Grade.ScorePublish(res.locals.token, grade)
    return res.send('Grade Succesfully Created')
  } catch (err) {
    return res.status(500).send(err.message)
  }
})

Then the Grade.ScorePublish call will handle sending the grade to your Moodle.

[hank-frank]

Hey, I got that sorted out and am now hitting the /grade route. I have a console log within that route of 'res.locals' coming out populated with all of my live user info from the Moodle instance but no grades are making it into the grade book.

It seems to me that the lti.Grade.ScorePublish method isn't working.

I'm hoping that you might have a fix or troubleshooting idea for it. I notice that res.locals.token is a whole object, I'm wondering if it's the correct object that moodle needs?

[Cvmcosta]

Yes, the method receives the entire object. Can you run your code in debug mode and tell me what the logs display when you call the grade route?

You can do that by launching your code like this: DEBUG=provider:* npm start . Then watch the logs and tell me what happens when you try to send the grades.

[hank-frank]

Thank you for the help, It's this: I changed a few lines to not post personal details:

Deployed!
  provider:main Receiving request at path: /login +11s
  provider:main Receiving a login request from: https://webAddress +1ms
  provider:main Redirecting to platform authentication endpoint +3ms
  provider:main Receiving request at path: / +374ms
  provider:main Path does not match reserved endpoints +0ms
  provider:main Cookies received:  +0ms
  provider:main [Object: null prototype] {
  provider:main   'plataHR0cHM6Ly93d3csdfssssssss9jb2RlLnNjaG93D%3D/in/58_14': '15',
  provider:main   'plataHR0cHM6Ly93d3csdfssssssss9jb2RlLnNjaG93D%3D/in/58_15': '15' } +0ms
  provider:main Received idtoken for validation +5ms
  provider:auth Attempting to validate state +0ms
  provider:auth Request state: vioKqXapk5XXRcijseMedQ%3D%3D +0ms
  provider:auth Response state: vioKqXapk5XXRcijseMedQ%3D%3D +0ms
  provider:auth Attempting to validate iss claim +0ms
  provider:auth Request Iss claim: https://webAddress +0ms
  provider:auth Response Iss claim: https://webAddress +0ms
  provider:auth Attempting to retrieve registered platform +0ms
  provider:auth Retrieving key from jwk_set +3ms
  provider:auth Attempting to verify JWT with the given key +243ms
  provider:auth Token signature verified +3ms
  provider:auth Initiating OIDC aditional validation steps +0ms
  provider:auth Validating if aud (Audience) claim matches the value of the tool's clientId given by the platform +0ms
  provider:auth Aud claim: 5etTpg41f7wnBAS +0ms
  provider:auth Checking alg claim. Alg: RS256 +0ms
  provider:auth Checking iat claim to prevent old tokens from being passed. +0ms
  provider:auth Iat claim: 1586880949 +0ms
  provider:auth Current_time: 1586880950.232 +0ms
  provider:auth Time passed: 1.2320001125335693 +0ms
  provider:auth Validating nonce +0ms
  provider:auth Nonce: 2+bYJe9Kpaj7HzIBXkvbRg== +0ms
  provider:auth Tool's clientId: 5etasaswnBAS +1ms
  provider:auth Storing nonce +5ms
  provider:auth Successfully validated token! +0ms
  provider:main Generating LTIK and redirecting to main endpoint +276ms
  provider:main Receiving request at path: / +174ms
  provider:main Path does not match reserved endpoints +0ms
  provider:main Cookies received:  +1ms
  provider:main [Object: null prototype] {
  provider:main   'plataHR0cHM6Ly93d3cssssssssssssjb2RlLnNjaG93D%3D/main/58_14': '15',
  provider:main   'plataHR0cHM6Ly93d3cssssssssssssjb2RlLnNjaG93D%3D/main/58_15': '15',
  provider:main   'plataHR0cHM6Ly93d3cssssssssssssjb2RlLnNjaG93D%3D/58_15': '15' } +0ms
  provider:main LTIK found +0ms
  provider:main LTIK successfully verified +0ms
  provider:main Attempting to retrieve matching session cookie +0ms
  provider:auth Session cookie found +186ms
  provider:main Passing request to next handler +5ms
  provider:main Setting up path cookie for this resource with path: /main +2ms
  provider:main Receiving request at path: /main +169ms
  provider:main Path does not match reserved endpoints +0ms
  provider:main Cookies received:  +0ms
  provider:main [Object: null prototype] {
  provider:main   'plataHR0cHM6Ly93d3cssssssssssssjb2RlLnNjaG93D%3D/main/58_14': '15',
  provider:main   'plataHR0cHM6Ly93d3cssssssssssssjb2RlLnNjaG93D%3D/main/58_15': '15' } +0ms
  provider:main LTIK found +0ms
  provider:main LTIK successfully verified +1ms
  provider:main Attempting to retrieve matching session cookie +0ms
  provider:auth Session cookie found +177ms
  provider:main Passing request to next handler +3ms
  provider:main Receiving request at path: /grade +6s
  provider:main Path does not match reserved endpoints +0ms
  provider:main Cookies received:  +0ms
  provider:main [Object: null prototype] {
  provider:main   'plataHR0cHM6Ly93d3sssssssssssjb2RlLnNjaG93D%3D/main/58_14': '15',
  provider:main   'plataHR0cHM6Ly93d3sssssssssssjb2RlLnNjaG93D%3D/main/58_15': '15' } +0ms
  provider:main LTIK found +0ms
  provider:main LTIK successfully verified +0ms
  provider:main Attempting to retrieve matching session cookie +0ms
  provider:auth Session cookie found +6s
  provider:main Passing request to next handler +4ms
in route:  hank
  provider:gradeService Target platform: https://webAddress +0ms
  provider:gradeService Attempting to retrieve platform access_token for [https://webAddress] +3ms
  provider:platform Access_token for https://webAddress not found +0ms
  provider:platform Attempting to generate new access_token for https://webAddress +0ms
  provider:auth Awaiting return from the platform +6s
  provider:gradeService Unsupported protocol "hhttps:" +17ms

[Cvmcosta]

Okay, so some of your registered routes is wrong and has a hhttps protocol: provider:gradeService Unsupported protocol "hhttps:" +17ms. That should be causing the error.

When you identify the url causing the error, assuming its a platform url, you can change the Url by calling one of the methods from the platform object.

[hank-frank]

I'm having trouble finding any route in either the code or in the External Tool Configuration in Moodle that has an "hhttps". Is there a location that you would expect to find one of those registered routes?

and Again, thank you very much for helping me out with this. I sincerely appreciate it.

[Cvmcosta]

Looking at the logs i assume it's your platform's access token endpoint, it's not a route, but the endpoint used when registering the platform. And it's no problem :), glad to help.

[michaelerobertsjr]

@Cvmcosta I'm also working on troubleshooting this issue. It appears it we have narrowed it to a url in the gradeService, does it require setting up a custom Oauth provider/service in Moodle for the LTI to use?

[Cvmcosta]

@michaelerobertsjr Current versions of Moodle that support LTI 1.3 don't require any additional work. If your issue is the same as @hank-frank's you just have to check the registered endpoints of your Moodle:

let plat = await lti.registerPlatform({ 
    url: 'https://platform.url',
    name: 'Platform Name',
    clientId: 'TOOLCLIENTID',
    authenticationEndpoint: 'https://platform.url/auth',
    accesstokenEndpoint: 'https://platform.url/token', // Probably this one, can you tell me which url u're using?
    authConfig: { method: 'JWK_SET', key: 'https://platform.url/keyset' }
})

Can you tell me the exact acesstokenEndpoint you are using?

[hank-frank]

So I got the hhttps error solved, it turns out that it never updates the DB entry for those lti.registerPlatform values if you change them.

I'm having another issue that I've tracked down a bit more.

provider:gradeService Target platform: https://webAddressl +0ms
provider:gradeService Attempting to retrieve platform access_token for [https://webAddressl] +6ms
provider:gradeService inside try block 281 +0ms
provider:gradeService [AsyncFunction: platformAccessToken] +0ms
provider:platform inside platformaccesstoken function if!token +0ms
provider:platform Access_token for https://webAddressl not found +0ms
provider:platform Attempting to generate new access_token for https://webAddressl +0ms
provider:auth Awaiting return from the platform +5s
erroe:  { HTTPError: Response code 400 (Bad Request)
  at EventEmitter.emitter.on (/Users/Desktop/code/temp/lti-provider/node_modules/got/dist/source/as-promise.js:118:31)
  at process._tickCallback (internal/process/next_tick.js:68:7) name: 'HTTPError' }
provider:platform catch err:  { HTTPError: Response code 400 (Bad Request)
  at EventEmitter.emitter.on (/Users/Desktop/code/temp/lti-provider/node_modules/got/dist/source/as-promise.js:118:31)
  at process._tickCallback (internal/process/next_tick.js:68:7) name: 'HTTPError' } +185ms
provider:gradeService Access_token retrieved for [https://webAddressl] +189ms
provider:gradeService TypeError: Cannot read property 'token_type' of undefined
provider:gradeService     at Grade.ScorePublish (/Users/Desktop/code/temp/lti-provider/node_modules/ltijs/dist/Provider/Services/Grade.js:305:35)
provider:gradeService     at process._tickCallback (internal/process/next_tick.js:68:7) +6ms
provider:gradeService Cannot read property 'token_type' of undefined +0ms

I've followed these to the try/catch in Grades.js starting on line 279 and the call of

const tokenRes = await platform.platformAccessToken();

which is in Platform.js on line 321, specifically this call of Auth.getAccessToken() which I wrapped in a try/catch and got the "TypeError: Cannot read property 'token_type" of undefined" error above.

try{ //I added this try/catch block to get error message from this Auth.getAccessToken method
        const res = await Auth.getAccessToken(this, (0, _classPrivateFieldGet2.default)(this, _ENCRYPTIONKEY2), (0, _classPrivateFieldGet2.default)(this, _Database));
      return res;
      } catch (err ){
        provPlatformDebug('catch err: ', err); //
      }

I've opened Auth.js and found getAccessToken on line 241 but haven't been able to successfully troubleshoot within that method.

[Cvmcosta]

I see, moodle is not returning you an access token (and for some reason the exception is not being caught in the ScorePublish method, even though it's inside a try/catch block), the request for an access token is returning a 400. Now there are some things that can help us troubleshoot this:

• What is your Moodle's version?
• Is your provider correctly configured within Moodle? (Public key generated by the LTI provider is set and Grades are enabled)
• What is being returned in Moodle's error logs?
• Can i see the urls you are using in your registration? (platform url, access token endpoint etc)

[hank-frank]

Moode verison 3.7+
I just updated the Public Key and am now getting this error output:

provider:auth Awaiting return from the platform +2s
  provider:auth Successfully generated new access_token +345ms
  provider:gradeService Access_token retrieved for [https://URL] +360ms
  provider:gradeService tokenRes:  { access_token: 'sssssssssssssss6b19b588204',
  token_type: 'Bearer',
  expires_in: 3600,
  scope:
   'https://purl.imsglobal.org/spec/lti-ags/scope/lineitem https://purl.imsglobal.org/spec/lti-ags/scope/score https://purl.imsglobal.org/spec/lti-ags/scope/result.readonly' } +0ms
erroe:  { HTTPError: Response code 401 (Unauthorized)
    at EventEmitter.emitter.on (/Users/Desktop/code/temp/lti-provider/node_modules/got/dist/source/as-promise.js:118:31)
    at process._tickCallback (internal/process/next_tick.js:68:7) name: 'HTTPError' }
  provider:gradeService HTTPError: Response code 401 (Unauthorized)
  provider:gradeService     at EventEmitter.emitter.on (/Users/Desktop/code/temp/lti-provider/node_modules/got/dist/source/as-promise.js:118:31)
  provider:gradeService     at process._tickCallback (internal/process/next_tick.js:68:7) +153ms
  provider:gradeService Response code 401 (Unauthorized) +0ms

[Cvmcosta]

Okay, now the access token is being generated. Is the user you're trying to set the grades to registered in the course? (That's one possible reason) And is the Grade service authorized in your provider configuration at Moodle?

[hank-frank]

The user is registered in the course, I've tried it with both my admin-level account and a second student level account, both of which are registered in the course.

I'm going in to double check that the grade service is authorized now.

[Cvmcosta]

If everything seems okay you should try checking Moodle's error logs, maybe it'll give us some hint.

[hank-frank]

Am I correct in thinking that I will need to turn on debugging messages under the Site Administration => Development to see those logs?

[Cvmcosta]

Usually error logs are sent to /var/log/apache2/error.log, so i dont think it is necessary, but it doesnt hurt to try.

[michaelerobertsjr]

Here are the relevant lines in the access logs:

x.x.x.x - - [14/Apr/2020:23:25:59 +0000] "POST /mod/lti/token.php HTTP/1.1" 200 178
x.x.x.x - - [14/Apr/2020:23:26:00 +0000] "GET /mod/lti/services.php/58/lineitems?type_id=5 HTTP/1.1" 401 162
x.x.x.x - - [14/Apr/2020:23:26:04 +0000] "GET / HTTP/1.1" 303 429

[Cvmcosta]

What about the error log? We need to find out why it's returning an unauthorized status.

[michaelerobertsjr]

The closest errors in the time frame from the log:

[Tue Apr 14 19:29:58.264443 2020] [authz_core:error] [pid 30239:tid 140272188929792] [client 107.x.x.x:45746] AH01630: client denied by server configuration: /opt/bitnami/apps/phpmyadmin/htdocs/scripts
[Tue Apr 14 23:35:57.004494 2020] [authz_core:error] [pid 30239:tid 140272004290304] [client 172.x.x.x:49242] AH01630: client denied by server configuration: /opt/bitnami/apps/phpmyadmin/htdocs/

[Cvmcosta]

Okay, according to your access logs, the request sent to /mod/lti/services.php/58/lineitems?type_id=5 is returning 401. Looking through Moodle's files i can see that the error is coming from the method check_tool being called from the file /mod/lti/service/gradebookservices/classes/local/resources/lineitems.php. This method is used to "Check that the request has been properly signed and is permitted.".

So it is either some permission issue, or the token being issued is not signing the request correctly. Do you have access to this Moodle's code? And i suggest you delete the generated access token from the database (if it has not expired yet on it's own) and try generating a new one.

Sadly Moodle does not provide us with any logs to find out what is going on, so debugging is always problematic and we need to add our own error_log calls to try to figure things out. But i'll help as much as i can. If you want i can even hop on hangouts on my free time and you can share you screen so we can try to reach a solution.