Hi everyone,
Students login to our WeBWorK Server is done via Blackboard LTI connection. Starting this year, some students are unable to login to the system. I don't know if there is any connection but the Central University who runs Blackboard upgraded the system last December and after that we started to have these issues Webwork Logins.
What happens is that some students try to login to their homework via a link posted by their instructors and they don't get to access the homework set. No message of error appear to the students neither. They are just taken directly to the main page of our WW Server, which is set only for faculty logins. Some of these students evently get to login and have access via the LTI logins.
Checking the debug file in our WW server, it shows that authentication fails when trying to WW is trying to fetch cookies during the LTI connections but no cookie is found.
I'm pasting below a particular instance of the occurance shown in our debug file.
I'm trying to understand if the issue is with Blackboard, our server or even if it is something with the Students's browsers. I appreciate if anyone can shred some light on why this happens.
Thank you.
-----------------------------------------
Begin WeBWorK::dispatch() <===
[Sun Feb 06 17:28:49.489945 2022] WeBWorK::dispatch: Hi, I'm the new dispatcher!
[Sun Feb 06 17:28:49.489995 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.490035 2022] WeBWorK::dispatch: Okay, I got some basic information:
[Sun Feb 06 17:28:49.490074 2022] WeBWorK::dispatch: The apache location is /webwork2
[Sun Feb 06 17:28:49.490110 2022] WeBWorK::dispatch: The request method is GET
[Sun Feb 06 17:28:49.490149 2022] WeBWorK::dispatch: The URI is /webwork2/MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.490189 2022] WeBWorK::dispatch: The path-info is /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.490228 2022] WeBWorK::dispatch: The argument string is
[Sun Feb 06 17:28:49.490265 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.490300 2022] WeBWorK::dispatch: The first thing we need to do is munge the path a little:
[Sun Feb 06 17:28:49.490343 2022] WeBWorK::dispatch: We can't trust the path-info, so we make our own path.
[Sun Feb 06 17:28:49.490381 2022] WeBWorK::dispatch: path-info claims: /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.490417 2022] WeBWorK::dispatch: but it's really: /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.490451 2022] WeBWorK::dispatch: (if it's empty, we set it to "/".)
[Sun Feb 06 17:28:49.490489 2022] WeBWorK::dispatch: ...and here it is without repeated slashes: /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.490528 2022] WeBWorK::dispatch: ...and here it is with a trailing slash: /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.490563 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.490598 2022] WeBWorK::dispatch: Now we need to look at the path a little to figure out where we are
[Sun Feb 06 17:28:49.490656 2022] WeBWorK::dispatch: -------------------- call to WeBWorK::URLPath::newFromPath
[Sun Feb 06 17:28:49.490717 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node root with path /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.490765 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^/):
[Sun Feb 06 17:28:49.490821 2022] WeBWorK::URLPath::debug: success!
[Sun Feb 06 17:28:49.490862 2022] WeBWorK::URLPath::debug: visitPathTypeNode: but path remains: MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.490899 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child course_admin:
[Sun Feb 06 17:28:49.490934 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node course_admin with path MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.490989 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^(admin)/):
[Sun Feb 06 17:28:49.491035 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.491070 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child html2xml:
[Sun Feb 06 17:28:49.491102 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node html2xml with path MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491137 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^html2xml/):
[Sun Feb 06 17:28:49.491173 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.491207 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child pgtotex:
[Sun Feb 06 17:28:49.491238 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node pgtotex with path MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491272 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^pgtotex.+):
[Sun Feb 06 17:28:49.491308 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.491341 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child instructorXMLHandler:
[Sun Feb 06 17:28:49.491372 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node instructorXMLHandler with path MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491407 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^instructorXMLHandler/):
[Sun Feb 06 17:28:49.491449 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.491482 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child set_list:
[Sun Feb 06 17:28:49.491522 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node set_list with path MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491558 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^([^/]+)/):
[Sun Feb 06 17:28:49.491604 2022] WeBWorK::URLPath::debug: success!
[Sun Feb 06 17:28:49.491662 2022] WeBWorK::URLPath::debug: visitPathTypeNode: setting argument courseID => MA10ALP_S22_HAdner_PNT1.
[Sun Feb 06 17:28:49.491699 2022] WeBWorK::URLPath::debug: visitPathTypeNode: but path remains: QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491733 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child equation_display:
[Sun Feb 06 17:28:49.491768 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node equation_display with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491804 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^equation/):
[Sun Feb 06 17:28:49.491862 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.491898 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child feedback:
[Sun Feb 06 17:28:49.491931 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node feedback with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.491969 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^feedback/):
[Sun Feb 06 17:28:49.492007 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492051 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child gateway_quiz:
[Sun Feb 06 17:28:49.492081 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node gateway_quiz with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492116 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^quiz_mode/([^/]+)/):
[Sun Feb 06 17:28:49.492154 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492188 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child proctored_gateway_quiz:
[Sun Feb 06 17:28:49.492218 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node proctored_gateway_quiz with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492261 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^proctored_quiz_mode/([^/]+)/):
[Sun Feb 06 17:28:49.492300 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492334 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child answer_log:
[Sun Feb 06 17:28:49.492364 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node answer_log with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492399 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^show_answers/):
[Sun Feb 06 17:28:49.492434 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492467 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child grades:
[Sun Feb 06 17:28:49.492497 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node grades with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492531 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^grades/):
[Sun Feb 06 17:28:49.492566 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492615 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child hardcopy:
[Sun Feb 06 17:28:49.492649 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node hardcopy with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492685 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^hardcopy/):
[Sun Feb 06 17:28:49.492722 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492757 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child achievements:
[Sun Feb 06 17:28:49.492790 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node achievements with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492825 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^achievements/):
[Sun Feb 06 17:28:49.492862 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.492897 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child logout:
[Sun Feb 06 17:28:49.492930 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node logout with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.492966 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^logout/):
[Sun Feb 06 17:28:49.493003 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.493038 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child options:
[Sun Feb 06 17:28:49.493071 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node options with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.493107 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^options/):
[Sun Feb 06 17:28:49.493144 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.493179 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child instructor_tools:
[Sun Feb 06 17:28:49.493212 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node instructor_tools with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.493248 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^instructor/):
[Sun Feb 06 17:28:49.493285 2022] WeBWorK::URLPath::debug: failed.
[Sun Feb 06 17:28:49.493320 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying child problem_list:
[Sun Feb 06 17:28:49.493353 2022] WeBWorK::URLPath::debug: visitPathTypeNode: visiting node problem_list with path QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.493390 2022] WeBWorK::URLPath::debug: visitPathTypeNode: trying to match (?^:^([^/]+)/):
[Sun Feb 06 17:28:49.493432 2022] WeBWorK::URLPath::debug: success!
[Sun Feb 06 17:28:49.493478 2022] WeBWorK::URLPath::debug: visitPathTypeNode: setting argument setID => QCC-MA010-14-Review-Final_Exam_Sample_Problems.
[Sun Feb 06 17:28:49.493515 2022] WeBWorK::URLPath::debug: visitPathTypeNode: no path left, type is problem_list
[Sun Feb 06 17:28:49.493582 2022] WeBWorK::dispatch: -------------------- call to WeBWorK::URLPath::newFromPath
[Sun Feb 06 17:28:49.493630 2022] WeBWorK::dispatch: The display module for this path is: WeBWorK::ContentGenerator::ProblemSet
[Sun Feb 06 17:28:49.493664 2022] WeBWorK::dispatch: ...and here are the arguments we'll pass to it:
[Sun Feb 06 17:28:49.493699 2022] WeBWorK::dispatch: courseID => MA10ALP_S22_HAdner_PNT1
[Sun Feb 06 17:28:49.493731 2022] WeBWorK::dispatch: setID => QCC-MA010-14-Review-Final_Exam_Sample_Problems
[Sun Feb 06 17:28:49.493814 2022] WeBWorK::dispatch: Reconstructing the original path gets us: /MA10ALP_S22_HAdner_PNT1/QCC-MA010-14-Review-Final_Exam_Sample_Problems/
[Sun Feb 06 17:28:49.493847 2022] WeBWorK::dispatch: And we can generate the path to our parent, too: /MA10ALP_S22_HAdner_PNT1/
[Sun Feb 06 17:28:49.493877 2022] WeBWorK::dispatch: (We could also figure out who our children are, but we'd need to supply additional arguments.)
[Sun Feb 06 17:28:49.493908 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.493938 2022] WeBWorK::dispatch: The URLPath looks good, we'll add it to the request.
[Sun Feb 06 17:28:49.493973 2022] WeBWorK::dispatch: Now we want to look at the parameters we got.
[Sun Feb 06 17:28:49.494003 2022] WeBWorK::dispatch: The raw params:
[Sun Feb 06 17:28:49.494055 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.494098 2022] WeBWorK::dispatch: We need to get a course environment (with or without a courseID!)
[Sun Feb 06 17:28:49.500976 2022] WeBWorK::dispatch: Here's the course environment: WeBWorK::CourseEnvironment=HASH(0x559a5b308550)
[Sun Feb 06 17:28:49.501654 2022] WeBWorK::dispatch: Using user_authen_module WeBWorK::Authen::LTIAdvanced: WeBWorK::Authen::LTIAdvanced=HASH(0x559a5d6314b8)
[Sun Feb 06 17:28:49.501750 2022] WeBWorK::dispatch: We got a courseID from the URLPath, now we can do some stuff:
[Sun Feb 06 17:28:49.501798 2022] WeBWorK::dispatch: ...we can create a database object...
[Sun Feb 06 17:28:49.508753 2022] WeBWorK::dispatch: (here's the DB handle: WeBWorK::DB=HASH(0x559a5d6315f0))
[Sun Feb 06 17:28:49.508861 2022] WeBWorK::Authen::verify: BEGIN VERIFY
[Sun Feb 06 17:28:49.508914 2022] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced has been called for data verification
[Sun Feb 06 17:28:49.508961 2022] WeBWorK::Authen::LTIAdvanced::request_has_data_for_this_verification_module: LTIAdvanced returning that it has insufficent data
[Sun Feb 06 17:28:49.509088 2022] WeBWorK::Authen::verify: BEGIN VERIFY
[Sun Feb 06 17:28:49.509146 2022] WeBWorK::Authen::do_verify: db ok
[Sun Feb 06 17:28:49.509189 2022] WeBWorK::Authen::get_credentials: self is WeBWorK::Authen::Basic_TheLastOption=HASH(0x559a5d6313e0)
[Sun Feb 06 17:28:49.509445 2022] WeBWorK::Authen::fetchCookie: found no cookie for this course. returning nothing.
[Sun Feb 06 17:28:49.509714 2022] WeBWorK::Authen::verify: END VERIFY
[Sun Feb 06 17:28:49.509777 2022] WeBWorK::Authen::verify: result 0
[Sun Feb 06 17:28:49.509827 2022] WeBWorK::dispatch: Bad news: authentication failed!
[Sun Feb 06 17:28:49.509866 2022] WeBWorK::dispatch: set displayModule to WeBWorK::ContentGenerator::Login
[Sun Feb 06 17:28:49.509904 2022] WeBWorK::dispatch: --------------------------------------------------------------------------------
[Sun Feb 06 17:28:49.509938 2022] WeBWorK::dispatch: Finally, we'll load the display module...
[Sun Feb 06 17:28:49.510052 2022] WeBWorK::dispatch: ...instantiate it...
[Sun Feb 06 17:28:49.510119 2022] WeBWorK::dispatch: ...and call it:
[Sun Feb 06 17:28:49.510156 2022] WeBWorK::dispatch: -------------------- call to WeBWorK::ContentGenerator::Login::go
[Sun Feb 06 17:28:49.514291 2022] WeBWorK::dispatch: -------------------- call to WeBWorK::ContentGenerator::Login::go
[Sun Feb 06 17:28:49.514506 2022] WeBWorK::dispatch: returning result: 0
[Sun Feb 06 17:28:56.547576 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: found data required for submitting grades to LMS
[Sun Feb 06 17:28:56.547893 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: obtained requestGen Net::OAuth::ConsumerRequest
[Sun Feb 06 17:28:56.548089 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: add required message params
[Sun Feb 06 17:28:56.548205 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: created grade request Net::OAuth::ConsumerRequest=HASH(0x559a5c3d4c50)
[Sun Feb 06 17:28:56.548806 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: signed grade request
[Sun Feb 06 17:28:56.549113 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: posting grade request: HTTP::Request=HASH(0x559a5cea85d8)
[Sun Feb 06 17:28:56.609521 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: Unable to update LMS grade bbgc61591048gi15127557 . LMS responded with message: failure
[Sun Feb 06 17:28:56.617992 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: found data required for submitting grades to LMS
[Sun Feb 06 17:28:56.618210 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: obtained requestGen Net::OAuth::ConsumerRequest
[Sun Feb 06 17:28:56.618346 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: add required message params
[Sun Feb 06 17:28:56.618448 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: created grade request Net::OAuth::ConsumerRequest=HASH(0x559a5c3d45c0)
[Sun Feb 06 17:28:56.618884 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: signed grade request
[Sun Feb 06 17:28:56.619195 2022] WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade: posting grade request: HTTP::Request=HASH(0x559a5ceac1e8)