nonce timing issue

[Alex-Jordan]

@drgrice1 and I were recently in a hotel with poor wifi and noticed a timing issue with nonces when we connected to a WW course through each of our school's LMSes. Since then, I've had this reported from some other instructors. Here is a screenshot from one course where the error is reported:

There is an 8 second difference here. IIRC, @drgrice1 and I each saw a 7 second difference.

@taniwallach is this something that makes sense to you?

[taniwallach]

I certainly know when and how such a message is issues, as I added the code to do that.

One of the known causes of LTI problems is that the WeBWorK server and the LMS had significant differences in their clocks, and several forum threads have discussed problems in such cases. Time differences cause problems both with authentication and with grade pass-back.

In terms of authentication, by default (the setting from conf/authen_LTI.conf.dist) WeBWorK uses a $NonceLifeTime=60 so an incoming LTI authentication request requires that the oauth_timestamp (which becomes the timestamp of the created WeBWorK::Authen::LTIAdvanced::Nonce) not be earlier than the value of time() - $ce->{NonceLifeTime} when the nonce is checked during the call to authenticate.

The code was added to report when the difference is more than 5 second, which was intended to help determine when there are potential problems brewing. The threshold for triggering the message is set in LTIAdvanced.pl by
use constant TIME_DIFF_THRESHOLD => 5;

If the only problem is the warning being issues too frequently, we probably should increase the threshold.

https://webwork.maa.org/moodle/mod/forum/discuss.php?d=4955

[Alex-Jordan]

If the only problem is the warning being issues too frequently, we probably should increase the threshold.

I think there is a more significant issue. (Or perhaps the following is unrelated.)

An instructor is using homework grade passback, and we have it set to pass grades back on submit. We also have the mass update interval at just one hour. But grades are not returning to Canvas in a timely manner. Sometimes he notices it update in Canvas right away, but more often the Canvas score for the problem set does not update for a long time. I turned on debugging messages, and this part stands out:

    The response is:
    _headers HTTP::Headers=HASH(0x5635c7fe3010) _msg Unauthorized _content {"errors":[{"message":"Duplicate nonce detected"}]} _protocol HTTP/1.1 _rc 401 _request HTTP::Request=HASH(0x5635c7cd61f8) at /opt/webwork/webwork2/lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm line 474.

Could "Duplicate nonce detected" have to do with this timing issue?

[taniwallach]

Yes. See: https://webwork.maa.org/moodle/mod/forum/discuss.php?d=4906#p14795 and https://webwork.maa.org/moodle/mod/forum/discuss.php?d=4770#p14262 where Larry Riddle explained that Canvas reports such a duplicate nonce error when the WeBWorK time in the LTI grade-passback message is more than one minute ahead (or 5 minutes behind) the time in Canvas.

The other possibility is a real detection of a duplicate nonce, as from my investigation Canvas does store the nonces it receives for a period of time to implement the intended avoidance of nonce-reuse. The changes in how nonces are built by WW in #1177 uses 2 parts, one which depends on the sourcedid so should vary from student to student, and one which is time dependent. This was intended to prevent an identical nonce from being reused for a good amount of time.

[Alex-Jordan]

This is happening with at least one (possibly two) schools that are using Runestone WeBWorK hosting. Both are using Canvas. In each case, the reported clock difference is only 8 seconds, so it seems that it is not the +1min/-5min issue. But also it happens most of the time, not just occasionally, so it doesn't sound like it's the other issue either. (If it were that issue, this is a 2.16 server, so it has your work from #1177.)

Would a duplicate nonce issue also affect mass updates? I would assume yes, but something in one of those forum posts suggested otherwise. The mass update interval is set to just one hour, and that is not helping. Meaning, the Canvas grades are still not updating even a day later with activity in the course.

I'm reaching a point where I will advise them to get more technical assistance from their Canvas management to diagnose the issue more and get to the root cause for "duplicate nonce detected" errors in this case.

[taniwallach]

It does seem necessary to get some help from the Canvas side. From the Canvas code on GitHub (assuming I'm looking at the correct code):

• https://github.com/instructure/canvas-lms/blob/224ba5f068c3d84865e2728cd38427c5c68d5e03/app/controllers/lti_api_controller.rb#L178
• https://github.com/instructure/canvas-lms/blob/224ba5f068c3d84865e2728cd38427c5c68d5e03/lib/lti/security.rb#L119
  all we can tell is that the message occurs both when the timestamp is not in an allowed range and when the nonce is detected as a duplicate in the cache.

The duplicate nonce issue will certainly effect grade-passback also for mass updates, as when the LMS detects a duplicate nonce, it is not supposed to accept the LTI message.

Sarunas Burdulis had some grade-passback issues, and reported testing with both the old code, and the "new" nonce code in https://webwork.maa.org/moodle/mod/forum/discuss.php?d=4906 at which time both the old method and the new were working for grade passback on submit.

[taniwallach]

I think #1464 will fix the bug.
It needs testing where grade-passback is in significant production use when $lti_check_prior=0.

[taniwallach]

The grade passback bug was fixed by #1464 .

We have dropped the code to warn about clock differences unless debug_lti_parameters is enabled.