Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-70282

Improve OAuth 2 exception information

    XMLWordPrintable

    Details

    • Testing Instructions:
      Hide

      Prerequisites

      1. An OAuth 2 issuer that supports authentication and refresh tokens. You can use Google for this purpose. See the docs on setting that up here:
        https://docs.moodle.org/310/en/OAuth_2_services
        https://docs.moodle.org/310/en/OAuth_2_Google_service
      2. Link a system account to the above Google issuer. To do this, from the OAuth2 services table click to link a system account and select the Google account of your choosing.
      3. Moodle configured as follows:
        1. The OAuth2 authentication plugin enabled.
        2. The 'pathtophp' setting has been set to '/usr/bin/php' or wherever your php binary lives (this allows us to run tasks from the web later on).
        3. The above OAuth 2 issuer correctly configured as an OAuth 2 service.
          1. Show on login page: Yes
        4. set debug: DEVELOPER, debugdisplay: Yes.

      Test 1: Successful authentication

      1. Log into Moodle using the OAuth 2 issuer's button (Login with Google) on the login page.
      2. Verify login is successful and no errors are seen

      Test 2: Successfully renew token endpoint

      1. Manually reset the system account token's expiry time:

        SELECT id FROM mdl_oauth2_access_token;   <==== record this id
        UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>;   <====== Use the id from above here 

      2. From Server > Scheduled tasks, run the scheduled task:
        \core\oauth2\refresh_system_tokens_task by clicking 'run now'.
      3. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task.
      4. Verify You see "Success" for the task's run in the "Result" column.
      5. Click "View" (🔍) to see the task's run output.
      6. Verify there are no errors, e.g.:

      Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
      ... used 7 dbqueries
      ... used 0.035740852355957 seconds
      Scheduled task complete: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)

      Test 3: Authentication fails due to token_endpoint HTTP error

      1. Go to the OAuth 2 Services page (Server > OAuth2 services)
      2. In the 'Edit' column, click "Configure endpoints' for the service
      3. Edit the OAuth 2 issuer's token_endpoint adding a '1' to the URL so that it's incorrect. Save.
      4. Log out.
      5. Try to log in again using the OAuth 2 issuer's button (Login with Google) on the login page.
      6. Verify you see an error mentioning HTTP 404, like the one below:

      Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 404
       More information about this error
       
      Debug info: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
       <html><head>
       <title>404 Not Found</title>
       </head><body>
       <h1>Not Found</h1>
       <p>The requested URL was not found on this server.</p>
       </body></html>
       
      Error code: oauth2upgradetoken
      

      Test 4: Token refresh fails due to token_endpoint HTTP error

      1. The token_endpoint should still be incorrect from test 3 (no changes required).
      2. Manually reset the system account token's expiry time:

        UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>;   <====== Use the id from before 

      3. From Server > Scheduled tasks, run the scheduled task:
        \core\oauth2\refresh_system_tokens_task by clicking 'run now'.
      4. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task.
      5. Verify You see "Fail" for the task's run in the "Result" column.
      6. Click "View" (🔍) to see the task's run output.
      7. Verify you see HTTP errors similar to the example below:

      Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
      Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 404 (<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
      <html><head>
      <title>404 Not Found</title>
      </head><body>
      <h1>Not Found</h1>
      <p>The requested URL was not found on this server.</p>
      </body></html>
      )
      Scheduled task failed: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task),Could not refresh OAuth 2 token for one or more issuers. View task output for details.
      

      Test 5: Authentication fails due to token_endpoint Curl error

      1. Login as admin
      2. Go to the OAuth 2 Services page (Server > OAuth2 services)
      3. In the 'Edit' column, click "Configure endpoints' for the service
      4. Edit the OAuth 2 issuer's token_endpoint changing this to a URL which does not connect, e.g. https://10.0.0.1/test (you may need to use a different address).
      5. Log out.
      6. Try to log in again using the OAuth 2 issuer's button (Login with Google) on the login page.
      7. Verify you see an error which may be similar to the one below. Note: It may also be something like "No route to host" - and that's acceptable too. We just want to confirm that we see a detailed error here.

      Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 0
       More information about this error
       
      Debug info: Connection timed out after 30001 milliseconds
       Error code: oauth2upgradetoken
      

      Test 6: Token refresh fails due to token_endpoint Curl error

      1. The token_endpoint should still be incorrect from test 5 (no change required)
      2. Manually reset the system account token's expiry time:

      UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>;    <===== Use the id from before 

      1. From Server > Scheduled tasks, run the scheduled task:
        \core\oauth2\refresh_system_tokens_task by clicking 'run now'.
      2. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task.
      3. Verify You see "Fail" for the task's run in the "Result" column.
      4. Click "View" (🔍) to see the task's run output.
      5. Verify you see errors similar to the following. Note: It may also be something like "No route to host" - and that's acceptable too. We just want to confirm that we see a detailed error here.

      Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
      Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 0 (Connection timed out after 30001 milliseconds)
      Scheduled task failed: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task),Could not refresh OAuth 2 token for one or more issuers. View task output for details.
      

      Show
      Prerequisites An OAuth 2 issuer that supports authentication and refresh tokens. You can use Google for this purpose. See the docs on setting that up here: https://docs.moodle.org/310/en/OAuth_2_services https://docs.moodle.org/310/en/OAuth_2_Google_service Link a system account to the above Google issuer. To do this, from the OAuth2 services table click to link a system account and select the Google account of your choosing. Moodle configured as follows: The OAuth2 authentication plugin enabled. The 'pathtophp' setting has been set to '/usr/bin/php' or wherever your php binary lives (this allows us to run tasks from the web later on). The above OAuth 2 issuer correctly configured as an OAuth 2 service. Show on login page: Yes set debug: DEVELOPER, debugdisplay: Yes. Test 1: Successful authentication Log into Moodle using the OAuth 2 issuer's button (Login with Google) on the login page. Verify login is successful and no errors are seen Test 2: Successfully renew token endpoint Manually reset the system account token's expiry time: SELECT id FROM mdl_oauth2_access_token; <==== record this id UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>; <====== Use the id from above here From Server > Scheduled tasks, run the scheduled task: \core\oauth2\refresh_system_tokens_task by clicking 'run now'. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task. Verify You see "Success" for the task's run in the "Result" column. Click "View" (🔍) to see the task's run output. Verify there are no errors, e.g.: Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task) ... used 7 dbqueries ... used 0.035740852355957 seconds Scheduled task complete: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task) Test 3: Authentication fails due to token_endpoint HTTP error Go to the OAuth 2 Services page (Server > OAuth2 services) In the 'Edit' column, click "Configure endpoints' for the service Edit the OAuth 2 issuer's token_endpoint adding a '1' to the URL so that it's incorrect. Save. Log out. Try to log in again using the OAuth 2 issuer's button (Login with Google) on the login page. Verify you see an error mentioning HTTP 404, like the one below: Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 404 More information about this error   Debug info: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN"> <html><head> <title>404 Not Found</title> </head><body> <h1>Not Found</h1> <p>The requested URL was not found on this server.</p> </body></html>   Error code: oauth2upgradetoken Test 4: Token refresh fails due to token_endpoint HTTP error The token_endpoint should still be incorrect from test 3 (no changes required). Manually reset the system account token's expiry time: UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>; <====== Use the id from before From Server > Scheduled tasks, run the scheduled task: \core\oauth2\refresh_system_tokens_task by clicking 'run now'. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task. Verify You see "Fail" for the task's run in the "Result" column. Click "View" (🔍) to see the task's run output. Verify you see HTTP errors similar to the example below: Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task) Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 404 (<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN"> <html><head> <title>404 Not Found</title> </head><body> <h1>Not Found</h1> <p>The requested URL was not found on this server.</p> </body></html> ) ⋮ Scheduled task failed: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task),Could not refresh OAuth 2 token for one or more issuers. View task output for details. Test 5: Authentication fails due to token_endpoint Curl error Login as admin Go to the OAuth 2 Services page (Server > OAuth2 services) In the 'Edit' column, click "Configure endpoints' for the service Edit the OAuth 2 issuer's token_endpoint changing this to a URL which does not connect, e.g. https://10.0.0.1/test (you may need to use a different address). Log out. Try to log in again using the OAuth 2 issuer's button (Login with Google) on the login page. Verify you see an error which may be similar to the one below. Note: It may also be something like "No route to host" - and that's acceptable too. We just want to confirm that we see a detailed error here. Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 0 More information about this error   Debug info: Connection timed out after 30001 milliseconds Error code: oauth2upgradetoken Test 6: Token refresh fails due to token_endpoint Curl error The token_endpoint should still be incorrect from test 5 (no change required) Manually reset the system account token's expiry time: UPDATE mdl_oauth2_access_token SET expires = 0 WHERE id = <ID>; <===== Use the id from before From Server > Scheduled tasks, run the scheduled task: \core\oauth2\refresh_system_tokens_task by clicking 'run now'. View the task's logs by visiting admin/tasklogs.php?filter=core\oauth2\refresh_system_tokens_task. Verify You see "Fail" for the task's run in the "Result" column. Click "View" (🔍) to see the task's run output. Verify you see errors similar to the following. Note: It may also be something like "No route to host" - and that's acceptable too. We just want to confirm that we see a detailed error here. Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task) Could not upgrade OAuth 2 token. HTTP status for remote endpoint: 0 (Connection timed out after 30001 milliseconds) ⋮ Scheduled task failed: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task),Could not refresh OAuth 2 token for one or more issuers. View task output for details.
    • Affected Branches:
      MOODLE_310_STABLE, MOODLE_39_STABLE
    • Fixed Branches:
      MOODLE_311_STABLE
    • Pull from Repository:
    • Pull 3.11 Branch:
      MDL-70282-oauth2_improve_error-311
    • Pull Master Branch:
      MDL-70282-oauth2_improve_error

      Description

      When OAuth 2 authentication fails due to some failure between Moodle and the issuer you get "error/Could not upgrade oauth token" which provides no information to help troubleshoot the cause. Unless you have access to the OAuth 2 issuer's logs you would have to trace into the Moodle source code to see what's being returned by the issuer – both the HTTP status code and the response body from the HTTP request in which the OAuth 2 issuer may have included helpful information to help resolve the problem. At present this response is ignored by Moodle and thus is unavailable to the admin.

      Also: The message "Could not upgrade oauth token" is a hardcoded string, ideally this should be a language string.

      Forum posts where people have faced the opaque "Could not upgrade oauth token" error:

        Attachments

        1. Screenshot_1.jpg
          Screenshot_1.jpg
          88 kB
        2. Screenshot_2.jpg
          Screenshot_2.jpg
          141 kB
        3. Screenshot_3.jpg
          Screenshot_3.jpg
          89 kB

          Issue Links

            Activity

              People

              Assignee:
              leonstr Leon Stringer
              Reporter:
              leonstr Leon Stringer
              Peer reviewer:
              David Mudrák (@mudrd8mz) David Mudrák (@mudrd8mz)
              Integrator:
              Sara Arjona (@sarjona) Sara Arjona (@sarjona)
              Tester:
              Janelle Barcega Janelle Barcega
              Participants:
              Component watchers:
              Adrian Greeve, Jake Dallimore, Mathew May, Mihail Geshoski, Peter Dias, Sujith Haridasan, Adrian Greeve, Jake Dallimore, Mathew May, Mihail Geshoski, Peter Dias, Sujith Haridasan
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:
                Fix Release Date:
                17/May/21

                  Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 4 hours, 51 minutes
                  4h 51m