WeBWorK Problems

First student login with 2.19 sometimes fails to create an account?

Re: First student login with 2.19 sometimes fails to create an account?

by Danny Glin -
Number of replies: 10
Other than the extra w at the end of "nonce" that looks like it should work.

From what you've posted so far there still isn't an instance showing that a student successfully logged in via LTI. In the course login log look for entries that include "credential_source=LTIAdvanced". If you can find an entry with a user_id that belongs to a student then we can try to determine what's different about that student.
In reply to Danny Glin

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -
Does the log below suggest that LTI did work?

[Fri Jan 24 01:48:06.289953 2025] WeBWorK::Authen::write_log_entry: Writing to login log: 'LOGIN OK user_id=cwvolkert login_type=normal credential_source=LTIAdvanced host=130.215.217.96 port=47424 UA=Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36'.
[Fri Jan 24 03:23:35.399664 2025] WeBWorK::Authen::write_log_entry: Writing to login log: 'LOGIN OK user_id=crcermak login_type=normal credential_source=LTIAdvanced host=130.215.15.240 port=57914 UA=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36'.

If yes, I still am very confused on LTI configs.

cat authen_LTI.conf|grep -v "^#"|grep "\S"
$debug_lti_parameters = 0;
$debug_lti_grade_passback = 0;
$authen{user_module} = [
# { '*' => 'WeBWorK::Authen::LTIAdvantage' }, # first try LTI 1.3
{ '*' => 'WeBWorK::Authen::LTIAdvanced' }, # next try LTI 1.1
{ '*' => 'WeBWorK::Authen::Basic_TheLastOption' } # fallback authorization method
];
$authen{admin_module} = [
#'WeBWorK::Authen::LTIAdvantage',
#'WeBWorK::Authen::LTIAdvanced',
'WeBWorK::Authen::Basic_TheLastOption'
];
include('conf/authen_LTI_1_1.conf');
$LTIVersion = 'v1p1';
$LTIAccountCreationCutoff = 'ta';
$LMSManageUserData = 1;
$external_auth = 0;
$LTIGradeMode = '';
$LTIGradeMode = 'homework';
$LTIGradeOnSubmit = 1;
$LTICheckPrior = 0;

and

cat authen_LTI_1_1.conf|grep -v "^#"|grep "\S"
$LTI{v1p1}{LMS_name} = 'Canvas';
$LTI{v1p1}{LMS_url} = 'https://canvas.wpi.edu/';
$LTI{v1p1}{preferred_source_of_username} = 'lis_person_contact_email_primary';
$LTI{v1p1}{fallback_source_of_username} = '';
$LTI{v1p1}{strip_domain_from_email} = 1;
$LTI{v1p1}{lowercase_username} = 0;
$LTI{v1p1}{preferred_source_of_student_id} = 'custom_canvas_user_login_id';

secret is set and

$LTI{v1p1}{NonceLifeTime} = 60; # in seconds
$LTI{v1p1}{OverrideSiteURL} = '';
$LTI{v1p1}{OverrideSiteProtocolDomain} = '';

anything here seem wrong ?

student crcermak has success in LTI but also has
  "timestamp" => 1737707018,
  "user_id" => "crcermak"
}
[Fri Jan 24 03:23:54.81358 2025] WeBWorK::Authen::verify: BEGIN VERIFY
[Fri Jan 24 03:23:54.81565 2025] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced has been called for data verification
[Fri Jan 24 03:23:54.81692 2025] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced returning that it has insufficent data

does this suggest tuning NonceLifeTime would help ?
In reply to John Eismeier

Re: First student login with 2.19 sometimes fails to create an account?

by Glenn Rice -
Anytime that you see WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced returning that it has insufficent data in the debug log that means that one of the one of the oauth parameters (oauth_consumer_key, oauth_signature, oauth_nonce, or oauth_timestamp) was missing.  If any of those parameters are missing, it most likely is not a configuration issue at all that is causing the issue.  Are you sure that the instructor that created these links in Canvas actually used an "External Tool" setup for the links?  If the instructor created an "External URL" link as a Canvas module, then it will not work for LTI authentication.  Some instructor using a basic link instead of an external tool seems more likely to be the root of these issues than anything else.

Note that there is no reason to add debugging statements to the code to see this if you have debug in webwork2.mojolicious.conf turned on.  All parameters received in the request are shown in the debug log already.

If you have debug_lti_parameters turned on and are not getting the message "Nonce Expired.  Your NonceLifeTime may be too short", then tuning NonceLifeTime is probably not going to help.
In reply to Glenn Rice

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -

I have not verified all class work but for calc 1 I have attached the canvas side.  Does this seem wrong?


The student I mentioned in today's post has both LTI success and failure within a close time period.  I was not at this students screen when LTI was turned on but this does suggest to me increasing NonceLifeTime to maybe 120 vs current 60

While canvas is cloud based, with webwork is on campus in our datacenter.

Attachment Screenshot 2025-01-24 at 7.06.55 AM.png
In reply to John Eismeier

Re: First student login with 2.19 sometimes fails to create an account?

by Glenn Rice -
That looks right for the Canvas external tool setup. You can try changing the NonceLifeTime and see if it helps. I doubt that it will, but it is worth a shot.
In reply to Glenn Rice

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -
Thank you Glenn. Still seems like LTI is not fully functional. Why does grade pass back work well in both 2.18 and 2.19. From what I have learned in this thread, I am not sure LTI auth has ever fully worked correctly for WPI.

Our brief history included 2.13 not able to use grade passback. I deployed the 2.15 VM from the MAA site which worked well. With 2.15, our webwork performance improved and grade pass back worked.

Seems like I need to still focus on the oauth parameters (oauth_consumer_key, oauth_signature, oauth_nonce, or oauth_timestamp) that are missing ?
In reply to John Eismeier

Re: First student login with 2.19 sometimes fails to create an account?

by Glenn Rice -
It sounds like something is intercepting the request from Canvas to WeBWorK and not forwarding it properly. So by the time it reaches WeBWorK it is missing parameters. Is there a proxy of some sort involved here?
In reply to Glenn Rice

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -
The only proxy that I am aware of is the reverse proxy to webwork2 service on the webwork server.

Does the webwork server with apache need any special configs outside of the like Header always set X-Permitted-Cross-Domain-Policies ?
In reply to John Eismeier

Re: First student login with 2.19 sometimes fails to create an account?

by Glenn Rice -

If you are using the conf/webwork2.apache2.4.conf file, then everything that is needed should be set.  If you aren't using that file, then you should check it for things that are needed.

In reply to Glenn Rice

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -
I am using the conf/webwork2.apach2.4.conf

Thanks again Glenn.
In reply to Glenn Rice

Re: First student login with 2.19 sometimes fails to create an account?

by John Eismeier -
One additional observation on LTI failing then working includes first mouse pic of the iframe to webwork failing, go back to canvas assignments and second mouse pic of the iframe to webwork LTI succeeds ?


[Mon Jan 27 09:34:35.85924 2025] WeBWorK::Authen::verify: BEGIN VERIFY
[Mon Jan 27 09:34:35.86161 2025] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced has been called for data verification
[Mon Jan 27 09:34:35.86287 2025] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced returning that it has sufficient data
[Mon Jan 27 09:34:35.86421 2025] WeBWorK::Authen::do_verify: db ok
[Mon Jan 27 09:34:35.86508 2025] WeBWorK::Authen::LTIAdvanced::get_credentials: LTIAdvanced::get_credentials has been called
[Mon Jan 27 09:34:35.86703 2025] WeBWorK::Authen::LTIAdvanced::get_credentials: LTIAdvanced::get_credentials is returning a 1
[Mon Jan 27 09:34:35.86796 2025] WeBWorK::Authen::do_verify: credentials ok
[Mon Jan 27 09:34:35.86890 2025] WeBWorK::Authen::LTIAdvanced::check_user: LTIAdvanced::check_user has been called for user_id = |jpeismeier|
[Mon Jan 27 09:34:35.93577 2025] WeBWorK::Authen::LTIAdvanced::check_user: LTIAdvanced::check_user is about to return a 1.
[Mon Jan 27 09:34:35.93755 2025] WeBWorK::Authen::do_verify: check user ok
[Mon Jan 27 09:34:35.93921 2025] WeBWorK::Authen::LTIAdvanced::verify_normal_user: LTIAdvanced::verify_normal_user called for user |jpeismeier|
[Mon Jan 27 09:34:35.94019 2025] WeBWorK::Authen::LTIAdvanced::authenticate: LTIAdvanced::authenticate called for user |jpeismeier|
[Mon Jan 27 09:34:35.94116 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ref(c) = |WeBWorK::ContentGenerator::ProblemSet|
[Mon Jan 27 09:34:35.94203 2025] WeBWorK::Authen::LTIAdvanced::authenticate: Nonce = |M94SruraGDrxjvBUbjveo9pzMmv02fdOQYS26kDkrI|
[Mon Jan 27 09:34:35.118210 2025] WeBWorK::Authen::LTIAdvanced::authenticate: c->param(oauth_signature) = |iHanfFGxqvR3kktCQy9GHpaWG7U=|
[Mon Jan 27 09:34:35.118491 2025] WeBWorK::Authen::LTIAdvanced::authenticate: context_id->|d8a1f9b296d230304b3adbc70e3f2467ef86b6c9|
[Mon Jan 27 09:34:35.118652 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_assignment_title->|WW5_Differentiation|
[Mon Jan 27 09:34:35.118815 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcome_submission_prioritize_non_tool_grade_accepted->|true|
[Mon Jan 27 09:34:35.119033 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_module_id->|169152|
[Mon Jan 27 09:34:35.119200 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_signature_method->|HMAC-SHA1|
[Mon Jan 27 09:34:35.119362 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_user_id->|21063|
[Mon Jan 27 09:34:35.119510 2025] WeBWorK::Authen::LTIAdvanced::authenticate: tool_consumer_info_product_family_code->|canvas|
[Mon Jan 27 09:34:35.119652 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_person_name_given->|John|
[Mon Jan 27 09:34:35.119800 2025] WeBWorK::Authen::LTIAdvanced::authenticate: launch_presentation_locale->|en|
[Mon Jan 27 09:34:35.119939 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lti_message_type->|basic-lti-launch-request|
[Mon Jan 27 09:34:35.120088 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_course_offering_sourcedid->|MA1021-C25-CL01|
[Mon Jan 27 09:34:35.120226 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_module_item_id->|1235334|
[Mon Jan 27 09:34:35.120376 2025] WeBWorK::Authen::LTIAdvanced::authenticate: roles->|Instructor|
[Mon Jan 27 09:34:35.120516 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_assignment_id->|391097|
[Mon Jan 27 09:34:35.120650 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcome_submission_submitted_at_accepted->|true|
[Mon Jan 27 09:34:35.120783 2025] WeBWorK::Authen::LTIAdvanced::authenticate: context_label->|MA1021 in 2025C|
[Mon Jan 27 09:34:35.120917 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_course_id->|69872|
[Mon Jan 27 09:34:35.121062 2025] WeBWorK::Authen::LTIAdvanced::authenticate: resource_link_title->|WW5_Differentiation|
[Mon Jan 27 09:34:35.121195 2025] WeBWorK::Authen::LTIAdvanced::authenticate: launch_presentation_return_url->|https://canvas.wpi.edu/courses/69872/assignments|
[Mon Jan 27 09:34:35.121327 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_enrollment_state->|active|
[Mon Jan 27 09:34:35.121493 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_workflow_state->|available|
[Mon Jan 27 09:34:35.121625 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcome_data_values_accepted->|url,text|
[Mon Jan 27 09:34:35.121759 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_assignment_points_possible->|100|
[Mon Jan 27 09:34:35.121887 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_version->|1.0|
[Mon Jan 27 09:34:35.122020 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_timestamp->|1737988456|
[Mon Jan 27 09:34:35.122180 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_person_sourcedid->|799179330|
[Mon Jan 27 09:34:35.122315 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_callback->|about:blank|
[Mon Jan 27 09:34:35.122464 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_nonce->|M94SruraGDrxjvBUbjveo9pzMmv02fdOQYS26kDkrI|
[Mon Jan 27 09:34:35.122598 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_api_domain->|canvas.wpi.edu|
[Mon Jan 27 09:34:35.122732 2025] WeBWorK::Authen::LTIAdvanced::authenticate: tool_consumer_instance_contact_email->|notifications@instructure.com|
[Mon Jan 27 09:34:35.122869 2025] WeBWorK::Authen::LTIAdvanced::authenticate: custom_canvas_user_login_id->|jpeismeier|
[Mon Jan 27 09:34:35.123026 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_ims_lis_basic_outcome_url->|https://canvas.wpi.edu/api/lti/v1/tools/5566/ext_grade_passback|
[Mon Jan 27 09:34:35.123188 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_person_name_family->|Eismeier|
[Mon Jan 27 09:34:35.123333 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_person_contact_email_primary->|jpeismeier@wpi.edu|
[Mon Jan 27 09:34:35.123511 2025] WeBWorK::Authen::LTIAdvanced::authenticate: launch_presentation_document_target->|iframe|
[Mon Jan 27 09:34:35.123656 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_consumer_key->|Webwork|
[Mon Jan 27 09:34:35.123781 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lti_version->|LTI-1p0|
[Mon Jan 27 09:34:35.123905 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_outcome_service_url->|https://canvas.wpi.edu/api/lti/v1/tools/5566/grade_passback|
[Mon Jan 27 09:34:35.124069 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_roles->|urn:lti:instrole:ims/lis/Instructor,urn:lti:instrole:ims/lis/Student,urn:lti:role:ims/lis/Instructor,urn:lti:sysrole:ims/lis/User|
[Mon Jan 27 09:34:35.124223 2025] WeBWorK::Authen::LTIAdvanced::authenticate: tool_consumer_instance_guid->|kwYfg31wBxrVjenz1JaMnqbMH9lZTAoQXBPYsd2e:canvas-lms|
[Mon Jan 27 09:34:35.124399 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcome_submission_needs_additional_review_accepted->|true|
[Mon Jan 27 09:34:35.124540 2025] WeBWorK::Authen::LTIAdvanced::authenticate: user_id->|914417c9e49c5c2fcbff68eef21ff604fb1e2e22|
[Mon Jan 27 09:34:35.124670 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcomes_tool_placement_url->|https://canvas.wpi.edu/api/lti/v1/turnitin/outcomes_placement/5566|
[Mon Jan 27 09:34:35.124810 2025] WeBWorK::Authen::LTIAdvanced::authenticate: tool_consumer_instance_name->|Worcester Polytechnic Institute|
[Mon Jan 27 09:34:35.124933 2025] WeBWorK::Authen::LTIAdvanced::authenticate: user_image->|https://canvas.wpi.edu/images/thumbnails/3897825/hwmK4YWWVgcTZFjuwxVVCZ7CrllfIalAKjmx7bgK|
[Mon Jan 27 09:34:35.125067 2025] WeBWorK::Authen::LTIAdvanced::authenticate: tool_consumer_info_version->|cloud|
[Mon Jan 27 09:34:35.125201 2025] WeBWorK::Authen::LTIAdvanced::authenticate: resource_link_id->|f7759242528ab78d08d91f7bf563c7fcc4de92d1|
[Mon Jan 27 09:34:35.125326 2025] WeBWorK::Authen::LTIAdvanced::authenticate: lis_person_name_full->|John Eismeier|
[Mon Jan 27 09:34:35.125475 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_lti_assignment_id->|5fee1e76-1285-4711-a006-ca4bf1e53b43|
[Mon Jan 27 09:34:35.125596 2025] WeBWorK::Authen::LTIAdvanced::authenticate: oauth_signature->|iHanfFGxqvR3kktCQy9GHpaWG7U=|
[Mon Jan 27 09:34:35.125723 2025] WeBWorK::Authen::LTIAdvanced::authenticate: context_title->|Calculus I|
[Mon Jan 27 09:34:35.125846 2025] WeBWorK::Authen::LTIAdvanced::authenticate: ext_outcome_result_total_score_accepted->|true|
[Mon Jan 27 09:34:35.129569 2025] WeBWorK::Authen::LTIAdvanced::authenticate: OAuth verification SUCCEEDED !!
[Mon Jan 27 09:34:35.133488 2025] WeBWorK::Authen::LTIAdvanced::verify_normal_user: auth_result=|1|
[Mon Jan 27 09:34:35.133803 2025] WeBWorK::Authen::LTIAdvanced::verify_normal_user: session_key=|CMBaE4V5mdtXm8qBDSCaWZlTM28wKlxP|.
[Mon Jan 27 09:34:35.134122 2025] WeBWorK::Authen::write_log_entry: Writing to login log: 'LOGIN OK user_id=jpeismeier login_type=normal credential_source=LTIAdvanced host=10.217.64.207 port=36984 UA=Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:134.0) Gecko/20100101 Firefox/134.0'.
[Mon Jan 27 09:34:35.134806 2025] WeBWorK::Authen::fetchCookie: fetchCookie: Session cookie does not contain valid information. Returning nothing.
[Mon Jan 27 09:34:35.134925 2025] WeBWorK::Authen::maybe_send_cookie: used_cookie='' unused_valid_cookie='' user_requests_cookie='0' session_management_via_cookies ='1'
[Mon Jan 27 09:34:35.135144 2025] WeBWorK::Authen::set_params: params user='jpeismeier' key='CMBaE4V5mdtXm8qBDSCaWZlTM28wKlxP'
[Mon Jan 27 09:34:35.135276 2025] WeBWorK::Authen::verify: END VERIFY
[Mon Jan 27 09:34:35.135385 2025] WeBWorK::Authen::verify: result 1
[Mon Jan 27 09:34:35.373942 2025] WeBWorK::Authen::store_session: Saving database session. The database session contains
{
"key" => "CMBaE4V5mdtXm8qBDSCaWZlTM28wKlxP",
"session" => {},
"timestamp" => 1737988475,
"user_id" => "jpeismeier"
}


Any additional thoughts on why this could occur ?