Can't access course after Nutmeg upgrade, but also can't find useful error in logs

Site Operators Site Operations Help
1

A student pointed out that they can no longer get to one of our old beta testing courses. I confirmed with my student account that I also see an error of “There was an error loading this course.”. However, the strange thing about this error vs. what I normally see is that I can’t find any meaningful error messages in the logs.

The first thing I did was check that there were no emojis in any section, subsection, or unit titles - and there aren’t. (Though I’m going to try that emoji fix shortly to see if it somehow magically solves this, but I wanted to post my error message before I make that change, just incase it’s different afterwards. Edit: The issue remains after doing the emoji fix.)

If I grep for the timestamp where I attempted to accessed the class as a student, I get the following:

ubuntu@ip-172-31-72-11:~$ tutor local logs --tail=1000 | grep -e '21:33:'
lms_1                        | 2022-08-07 21:33:04,719 INFO 19 [tracking] [user 7] [ip 1.2.3.4] logger.py:41 - {"name": "/api/course_home/outline/course-v1:MyOrg+MyClass+MyRun", "context": {"user_id": 7, "path": "/api/course_home/outline/course-v1:MyOrg+MyClass+MyRun", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "TestStudent", "session": "5591daf2b90fd84d67385f8b8a095dAA", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:103.0) Gecko/20100101 Firefox/103.0", "host": "my.site.com", "referer": "https://apps.my.site.com/", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2022-08-07T21:33:04.718832+00:00", "event_type": "/api/course_home/outline/course-v1:MyOrg+MyClass+MyRun", "event_source": "server", "page": null}
lms_1                        | 2022-08-07 21:33:04,719 INFO 7 [tracking] [user 7] [ip 1.2.3.4] logger.py:41 - {"name": "/theming/asset/images/logo.png", "context": {"user_id": 7, "path": "/theming/asset/images/logo.png", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "TestStudent", "session": "5591daf2b90fd84d67385f8b8a095dAA", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:103.0) Gecko/20100101 Firefox/103.0", "host": "my.site.com", "referer": "https://apps.my.site.com/", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2022-08-07T21:33:04.718965+00:00", "event_type": "/theming/asset/images/logo.png", "event_source": "server", "page": null}
lms_1                        | [pid: 7|app: 0|req: 22736/69940] 172.19.0.3 () {50 vars in 2966 bytes} [Sun Aug  7 21:33:04 2022] GET /theming/asset/images/logo.png => generated 0 bytes in 54 msecs (HTTP/1.1 302) 7 headers in 380 bytes (1 switches on core 0)
lms_1                        | 2022-08-07 21:33:04,778 INFO 7 [tracking] [user 7] [ip 1.2.3.4] logger.py:41 - {"name": "/api/course_home/course_metadata/course-v1:MyOrg+MyClass+MyRun", "context": {"user_id": 7, "path": "/api/course_home/course_metadata/course-v1:MyOrg+MyClass+MyRun", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "TestStudent", "session": "5591daf2b90fd84d67385f8b8a095dAA", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:103.0) Gecko/20100101 Firefox/103.0", "host": "my.site.com", "referer": "https://apps.my.site.com/", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {\"browser_timezone\": [\"America/Los_Angeles\"]}, \"POST\": {}}", "time": "2022-08-07T21:33:04.778360+00:00", "event_type": "/api/course_home/course_metadata/course-v1:MyOrg+MyClass+MyRun", "event_source": "server", "page": null}
lms_1                        | [pid: 7|app: 0|req: 22737/69941] 172.19.0.3 () {54 vars in 3228 bytes} [Sun Aug  7 21:33:04 2022] GET /api/course_home/course_metadata/course-v1:MyOrg+MyClass+MyRun?browser_timezone=America%2FLos_Angeles => generated 23 bytes in 86 msecs (HTTP/1.1 404) 9 headers in 446 bytes (1 switches on core 0)
lms_1                        | 2022-08-07 21:33:04,994 INFO 7 [tracking] [user 7] [ip 1.2.3.4] logger.py:41 - {"name": "/theming/asset/images/favicon.ico", "context": {"user_id": 7, "path": "/theming/asset/images/favicon.ico", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "TestStudent", "session": "5591daf2b90fd84d67385f8b8a095dAA", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:103.0) Gecko/20100101 Firefox/103.0", "host": "my.site.com", "referer": "https://apps.my.site.com/", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2022-08-07T21:33:04.993753+00:00", "event_type": "/theming/asset/images/favicon.ico", "event_source": "server", "page": null}
lms_1                        | [pid: 7|app: 0|req: 22738/69942] 172.19.0.3 () {50 vars in 2972 bytes} [Sun Aug  7 21:33:04 2022] GET /theming/asset/images/favicon.ico => generated 0 bytes in 99 msecs (HTTP/1.1 302) 7 headers in 383 bytes (1 switches on core 0)
lms_1                        | 2022-08-07 21:33:05,349 INFO 19 [edx.certificate] [user 7] [ip 1.2.3.4] api.py:378 - Checking if student 7 has an invalidated certificate in course course-v1:MyOrg+MyClass+MyRun.
lms_1                        | 2022-08-07 21:33:05,358 INFO 19 [edx.certificate] [user 7] [ip 1.2.3.4] api.py:703 - Checking if student 7 is on the allowlist in course course-v1:MyOrg+MyClass+MyRun
lms_1                        | [pid: 19|app: 0|req: 22443/69943] 172.19.0.3 () {54 vars in 3135 bytes} [Sun Aug  7 21:33:04 2022] GET /api/course_home/outline/course-v1:MyOrg+MyClass+MyRun => generated 37426 bytes in 752 msecs (HTTP/1.1 200) 10 headers in 479 bytes (1 switches on core 0)
lms_1                        | [pid: 7|app: 0|req: 22739/69944] 172.19.0.3 () {50 vars in 896 bytes} [Sun Aug  7 21:33:44 2022] GET /asset-v1:MyOrg+MyClass+MyRun+type@asset+block@instructor.jpeg => generated 72255 bytes in 24 msecs (HTTP/1.1 200) 6 headers in 174 bytes (1 switches on core 0)
ubuntu@ip-172-31-72-11:~$ tutor local logs --tail=1000 | grep -e '21:34:'
lms_1                        | [pid: 19|app: 0|req: 22444/69945] 172.19.0.3 () {54 vars in 1139 bytes} [Sun Aug  7 21:34:54 2022] GET /asset-v1:MyOrg+MyClass+MyRun+type@asset+block@instructor.jpeg => generated 72255 bytes in 23 msecs (HTTP/1.1 200) 6 headers in 174 bytes (1 switches on core 0)

But even just not grepping specifically for those times and eyeballing the log or searching for “error” I can’t see anything around that time in the logs.

Does anyone have any ideas of what specifically to look for in the logs that could be correlated to a “There was an error loading this course.” error message displayed to students?

2

Hi,

Do you have hidden courses?

This error came out when I had them like this, due to mfe, so I changed them to about and it was resolved

3

Yes, it looks like the common thread is that courses set to “none” are no longer accessible to past students, whereas courses set to “about” are.

This seems like a bug, or at least change of behavior though. Did you make a thread discussing this on the forums previously, and if so can you point me at it?

4

I did make one, but I didn’t know how to document or explain it so they could verify it.

5

Thanks. I filed a github issue as Regis recommended on the Tutor forums.

1 Like
6

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.