error/Could not upgrade oauth token

error/Could not upgrade oauth token

by Andrew Lyman-Buttler -
Number of replies: 6

Hi all,

I've been reading forums pretty exhaustively about this issue so I'll try to be as specific as possible about what I've already tried. Thanks in advance, I really appreciate the help.

When any user tries to log in with Google, they get the error message "error/Could not upgrade oauth token". The most infuriating thing is that it's intermittent; sometimes the login succeeds! I can't identify any pattern that predicts when it will work or not. It seems random. Here's the stack trace:

Debug info: 
Error code: Could not upgrade oauth token
$a contents:
Stack trace:
  • line 567 of /lib/oauthlib.php: moodle_exception thrown
  • line 475 of /lib/oauthlib.php: call to oauth2_client->upgrade_token()
  • line 44 of /auth/oauth2/login.php: call to oauth2_client->is_logged_in()

My site was previously using the googleoauth2 third-party authentication plugin, and I was still using it when the errors began. I didn't change anything on the site configuration, when suddenly, apropos of nothing, on the evening of 4/13/18 (Friday the 13th!) I started getting emails from my server with the subject "OAuth refresh token expired for Google on your site". These have been coming once every hour. I assume this is because the scheduled task that refreshes the token has been failing.

Here's what I've tried so far to fix the problem, approximately in order:

1) I connected the system account. This apparently succeeded and I see a green check with the email address. I've tried this with my admin account as well as a different Google account that's not connected to any user accounts on the site.

2) I uninstalled the googleoauth2 plugin and deleted all of its files from my server. Then, I went through the mdl_user table and manually changed everyone's username to be the same as their Google account email address. I changed auth to oauth2 for everyone. I made sure the password field is empty. The database table is configured correctly as far as I can tell.

3) I deleted the Moodle directory from my server and replaced it with a fresh install of 3.4.2, although I did re-copy my config.php file.

4) I erased all browsing history, cookies, etc.

5) I deleted the Google Oauth integration from the Admin --> Server --> Oauth2 settings and re-created it.

6) I logged into the Google API Console and deleted the credentials and the "project", re-created it from scratch, and re-entered the key and client secret on my moodle site as a new Google service.

7) I put the site in maintenance mode, enabled debugging, went into Server --> Scheduled Tasks, and manually ran the "Refresh Oauth tokens for service accounts" task. I got this back:



Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
... started 09:41:37. Current memory use 29.9MB.

Warning: Error while sending QUERY packet. PID=141047 in /home/edison19/public_html/moodle/lib/dml/mysqli_native_moodle_database.php on line 1215
... used 5 dbqueries ... used 30.054812908173 seconds Scheduled task failed: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task),Error reading from database Debug info: MySQL server has gone away SELECT u.* FROM mdlxsre_user u WHERE u.deleted = 0 AND u.id IN (5,3) [array ( )] Backtrace: * line 1216 of /lib/dml/mysqli_native_moodle_database.php: call to moodle_database->query_end() * line 110 of /lib/datalib.php: call to mysqli_native_moodle_database->get_records_sql() * line 56 of /lib/classes/oauth2/refresh_system_tokens_task.php: call to get_admins() * line 98 of /lib/classes/oauth2/refresh_system_tokens_task.php: call to core\oauth2\refresh_system_tokens_task->notify_admins() * line 104 of /lib/cronlib.php: call to core\oauth2\refresh_system_tokens_task->execute() * line 292 of /lib/cronlib.php: call to cron_run_inner_scheduled_task() * line 91 of /admin/tool/task/schedule_task.php: call to cron_run_single_task()

Error reading from database

More information about this error

Debug info: MySQL server has gone away
SELECT * FROM mdlxsre_task_scheduled WHERE classname = ?
[array (
0 => '\\core\\oauth2\\refresh_system_tokens_task',
)]
Error code: dmlreadexception
Stack trace:
  • line 486 of /lib/dml/moodle_database.php: dml_read_exception thrown
  • line 1216 of /lib/dml/mysqli_native_moodle_database.php: call to moodle_database->query_end()
  • line 1571 of /lib/dml/moodle_database.php: call to mysqli_native_moodle_database->get_records_sql()
  • line 1543 of /lib/dml/moodle_database.php: call to moodle_database->get_record_sql()
  • line 1522 of /lib/dml/moodle_database.php: call to moodle_database->get_record_select()
  • line 665 of /lib/classes/task/manager.php: call to moodle_database->get_record()
  • line 132 of /lib/cronlib.php: call to core\task\manager::scheduled_task_failed()
  • line 292 of /lib/cronlib.php: call to cron_run_inner_scheduled_task()
  • line 91 of /admin/tool/task/schedule_task.php: call to cron_run_single_task()
However, a little later, I ran it again and got this:

Execute scheduled task: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
... started 10:13:31. Current memory use 29.9MB.
... used 4 dbqueries
... used 15.198276042938 seconds
Scheduled task complete: Refresh OAuth tokens for service accounts (core\oauth2\refresh_system_tokens_task)
This makes sense given the intermittent nature of the problem. I'm completely baffled, and my students are freaking out.

Thanks,
Andrew


Average of ratings: -
In reply to Andrew Lyman-Buttler

Re: error/Could not upgrade oauth token

by Ken Task -
Picture of Particularly helpful Moodlers

Went through this just the other day and while my paths/methods were slightly different than yours, did end up, finally, getting the built-in/core GoogleOauth to work.

The link that went to "more information about this error".

https://docs.moodle.org/34/en/error/moodle/dmlreadexception

First line says:

"This message was displayed because Moodle experienced a problem trying to read data from your Moodle database."

and is evidenced by the next line in debugging:

Debug info: MySQL server has gone away

typically, that means the max_allowed_packet setting for your MySQL DB is too low ... default is 1MB.

https://dev.mysql.com/doc/refman/5.5/en/packet-too-large.html

Set that variable to ohhhh .... say 32M in the my.cnf file ... config file for MySQL

[mysqld] (somewhere below this line ... and before the next [] section

max_allowed_packet=32m
Why 32M?  Well, you did see in the task that it used 29.9M of memory when executing ... 32M is slightly higher than that.  Now how would anyone know to do that in advance?   Beats me!   But that same error - gone away - might show also when backing up a large course ... not large in files but in processing ... like a bunch of quizzes and a bunch of users, etc.

Restart your MySQL DB server and let's see if that error goes away and things start to settle down for you.

Most of the time, uninstalling a plugin isn't all that difficult ... this one, however, presented some extra work due to the fact it was an authentication plugin and most of the users in the system were authentication via the old authentication.  Un-installing didn't go into the mdl_user table and change anything .... and shouldn't be expected to ... cause there is no way for the system to know what/how users accounts should be changed.

Through the years, I've learned this about 'plugins/addons' ... after successful install, config, and usage, poke around the tables of your DB to see what tables were added ...  how is the plugin referenced in mdl_config_plugins etc.  IF, then, there is a hickup, I might re-call where to look for some clues.
 

'spirit of sharing', Ken

In reply to Ken Task

Re: error/Could not upgrade oauth token

by Andrew Lyman-Buttler -

Thanks Ken! Yes, I have had database errors when backing up large courses before. I'll get that setting changed (I have shared hosting & can't do it myself) and report back.

In reply to Ken Task

Re: error/Could not upgrade oauth token

by Andrew Lyman-Buttler -

Here's what I got back from the support team at Inmotion Hosting:

The QUERY packet error you've sent us is typically indicative that at the time you are/were using the maximum number of database connections at a time for your user. Unfortunately this is not able to be increased on a shared server, but the issue should only be intermittent. That issue being intermittent along with your issue being intermittent tells me this *may* be where the source of our problem is coming from.

If you didn't make any changes between when the site was working and when it wasn't, this may also indicate this is the ultimate source of our issue.

In order to resolve that, you would need to upgrade to a VPS or higher as if you're on a VPS then you'd have full access to the server and we could increase the max user connections for you at that point. Unfortunately if we made that change on the shared server it would affect all users on the server, so we are not able to do this on shared.

I can't afford a VPS plan--I'm just one teacher paying out of pocket for hosting--but do you think their response makes sense? Is there anything I can do about excessive database connections?
In reply to Andrew Lyman-Buttler

Re: error/Could not upgrade oauth token

by Ken Task -
Picture of Particularly helpful Moodlers

IMHO, honest answer.   Solution proposed is probably the only way your site can avoid the error.

What can you do about it?   You'd have to get cooperation of all your users ... and never put them into a situation where they would have to login about the same time.   Dunno how you'd do that ... assignment deadlines set - but life gets in the way and students are then pressed to get 'er done before the deadline ... burst of access/activity and thus the error.

How do you do that with a quiz/test?   You might already be doing things to reduce the hits on DB ... like fewer questions per page.   In order to find other areas of your course where you might be able to reduce the hits on the DB, you'd have to really know Moodle.    Uhhh ... who really wants to do that?    Not I!

Can't buy a Volks and expect the performance of a Mercedes Benz sports model!

Bottom line ... don't think anyone has been able to get blood out of a turnip or fit a square peg in a round hole .... sooooo.

'spirit of sharing', Ken


In reply to Ken Task

Re: error/Could not upgrade oauth token

by Andrew Lyman-Buttler -

Thanks for your perspective. I haven't had any database issues except for running large course backups, and now this. Funny how it started out of the blue, seemingly unprovoked. I got the DB error when trying to Oauth login at night when no students were on. On the other hand, I've had 30 kids in a room taking a quiz at the same time with no DB problems.

I've decided to just give up on Oauth and switch everyone over to username/password authentication. I'll revisit the issue this summer when classes are done and I can be a bit more aggressive about messing with the server since there will not be a live site.

In reply to Andrew Lyman-Buttler

Re: error/Could not upgrade oauth token

by Ken Task -
Picture of Particularly helpful Moodlers

If you re-read how they responded ... and since I used to run core services for some 38 ISD's in a wide area private network ... I can tell you beyond a doubt, that 'no students were on' doesn't mean they (or others) weren't poking at the server in ways that Moodle wouldn't see.  30 students in one class taking a quiz ... sounds like a blended site and the students have devices/laptops/tech they can use to access while not physically present in your class.  Does site allow messages between users on your system?   Students not present in your class could be logged on and using messages to 'chat' with one another ... while that's supposed to use less bandwith/processes than true chat and thought to be private, interesting to see spikes in usage or server during messages ... and insights teachers/admin user can aquire by paying attention to the 'conversation'.

Bout the only way one could see traffic headed at your site is ssh access and watching apache access log and apache error log in realtime ... as stuff happens ... and that level of access one doesn't have with shared server most of the time.

The issues with Oauth login might have been just a coincidence in reality.

Depending upon what you teach, having Oauth2 with Google opens some possibilities using Google Docs/Sheets, etc. and in some cases students will be able to do things that have not yet made it to Moodle code ... core nor plugin.

'spirit of sharing', Ken