Students' "Progress" page doesn't update when new Problems are added

ABC · March 1, 2023, 8:19pm

I noticed something strange today. I have a class that’s already running, but when I add new Problems to the class, the students’ Progress page doesn’t update.

E.g. if a section started out with 1 problem, and the student sees this:

(Note it says 0/1)

Then if I add 5 new Problems. The student still sees 0/1 (and I confirmed it’s not just a browser caching issue, as I completely cleared my Firefox history and restarted the application.)

However if the student goes in, and completes a couple Problems, then their Progress page updates:

(Note, it says 2/6)

This is a problem for me, because I want to tell the students: “Go look at your Progress page, and do all the new Problems I’ve created”. But they won’t see which sections have new problems!

So I then tried to force-update the state for everyone to force their Problem pages to refresh. However, when I pick a new Problem which I know no one has done yet, and try to adjust everyone’s scores (to force-refresh their Problem pages), I get this error:

The “rescore all learners’ submissions” button yields the same error.

So my question is: is there a way to force-refresh all students’ Progress pages, so I can tell them to go complete unfinished Problems?

Side note: I’m pretty sure this wasn’t an issue in Maple, and I know it’s not currently a problem in Lilac on a different server. Is this perhaps an issue with the new Progress page?

Also, apparently I already had set PersistentGradesEnabledFlag = true (at least according to Django admin/grades/persistentgradesenabledflag/1/change/). So I tried

tutor local run lms ./manage.py lms compute_grades --all_courses

But that didn’t solve it.

dave · March 3, 2023, 4:14am

The REST API that the new Progress page calls makes use of Block Transformers, which is a way that course content is sort of compiled into a more denormalized form that makes it easier to query across large portions of it at once (as happens during grading). That compilation/collection phase happens just after you click the publish button. If that step fails because of some system error when trying to collect your course content, it’s possible to get into a state where the data stored for that course becomes stale.

Can you try making some trivial change in Studio, publish, and see if you see errors in your workers (there might be references to “block structures”, “transformers”, or the “collect” phase).

ABC · March 3, 2023, 12:02pm

Thanks for the suggestion. I made a change of adding a single space to a single question in a section that was not updating the grade for the test student account. Then I published it. Then I refreshed the progress page. There was no update, as expected.

I had “tutor local logs -f --tail=1” running. When I examined the output for the time period of both publication, and refreshing the Progress page, I don’t see any references to “error”, “block structures”, “transformers”, or “collect”.

One thing which I noticed, which you can tell me whether you think is related or not, is that apparently I can’t export the class. I can export other classes fine. And I can generate grade reports fine. (So I know it’s not my previous problem with an overly large redis file.) But the export of the class is currently stuck in the “Exporting” state. I checked django admin/user_tasks/usertaskstatus/ and I don’t see a new state (only my successful other-class exports.) There is the one old export that I manually set to “Failure” after I got around the redis error (which I thought had fixed export, but maybe I’m misremembering).

Is it possible that whatever’s causing the export to hang is also causing the re-grading failure?

dave · March 3, 2023, 9:09pm

Both the course export and the collect phase for block transformers will do a traversal of all the nodes of the course content, so it’s quite possible that the same thing is breaking both. Is there anything that comes up in the error logs when you try to export?

ABC · March 3, 2023, 10:24pm

Shouldn’t the grade_course traverse all the nodes too? But that’s still working…

When I go to the Export page, I just get a bunch of this in my logs:

caddy_1                      | {"level":"info","ts":1677881934.9485931,"logger":"http.log.access.log1","msg":"handled request","request":{"remote_addr":"1.2.3.4:52406","proto":"HTTP/2.0","method":"GET","host":"studio.my.site.com","uri":"/export_status/course-v1:MyOrg+MyClass+V1","tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"studio.my.site.com"}},"user_id":"","duration":0.043942536,"size":23,"status":200}
cms_1                        | 2023-03-03 22:18:55,990 INFO 13 [tracking] [user 3] [ip 1.2.3.4] logger.py:41 - {"name": "/export_status/course-v1:MyOrg+MyClass+V1", "context": {"user_id": 3, "path": "/export_status/course-v1:MyOrg+MyClass+V1", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "MyAdmin", "session": "186d132c5d2a9fc1efafdf1190c61cd5", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36", "host": "studio.my.site.com", "referer": "https://studio.my.site.com/export/course-v1:MyOrg+MyClass+V1", "accept_language": "en-US,en;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2023-03-03T22:18:55.990476+00:00", "event_type": "/export_status/course-v1:MyOrg+MyClass+V1", "event_source": "server", "page": null}
cms_1                        | [pid: 13|app: 0|req: 3258/6937] 172.19.0.8 () {58 vars in 3905 bytes} [Fri Mar  3 22:18:55 2023] GET /export_status/course-v1:MyOrg+MyClass+V1 => generated 23 bytes in 35 msecs (HTTP/1.1 200) 7 headers in 490 bytes (1 switches on core 0)
caddy_1                      | {"level":"info","ts":1677881936.013765,"logger":"http.log.access.log1","msg":"handled request","request":{"remote_addr":"1.2.3.4:52406","proto":"HTTP/2.0","method":"GET","host":"studio.my.site.com","uri":"/export_status/course-v1:MyOrg+MyClass+V1","tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"studio.my.site.com"}},"user_id":"","duration":0.036602876,"size":23,"status":200}
cms_1                        | 2023-03-03 22:18:57,054 INFO 7 [tracking] [user 3] [ip 1.2.3.4] logger.py:41 - {"name": "/export_status/course-v1:MyOrg+MyClass+V1", "context": {"user_id": 3, "path": "/export_status/course-v1:MyOrg+MyClass+V1", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "MyAdmin", "session": "186d132c5d2a9fc1efafdf1190c61cd5", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36", "host": "studio.my.site.com", "referer": "https://studio.my.site.com/export/course-v1:MyOrg+MyClass+V1", "accept_language": "en-US,en;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2023-03-03T22:18:57.054330+00:00", "event_type": "/export_status/course-v1:MyOrg+MyClass+V1", "event_source": "server", "page": null}
cms_1                        | [pid: 7|app: 0|req: 3276/6938] 172.19.0.8 () {58 vars in 3905 bytes} [Fri Mar  3 22:18:57 2023] GET /export_status/course-v1:MyOrg+MyClass+V1 => generated 23 bytes in 34 msecs (HTTP/1.1 200) 7 headers in 490 bytes (1 switches on core 0)
caddy_1                      | {"level":"info","ts":1677881937.0759754,"logger":"http.log.access.log1","msg":"handled request","request":{"remote_addr":"1.2.3.4:52406","proto":"HTTP/2.0","method":"GET","host":"studio.my.site.com","uri":"/export_status/course-v1:MyOrg+MyClass+V1","tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"studio.my.site.com"}},"user_id":"","duration":0.035747216,"size":23,"status":200}
cms_1                        | 2023-03-03 22:18:58,120 INFO 13 [tracking] [user 3] [ip 1.2.3.4] logger.py:41 - {"name": "/export_status/course-v1:MyOrg+MyClass+V1", "context": {"user_id": 3, "path": "/export_status/course-v1:MyOrg+MyClass+V1", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "MyAdmin", "session": "186d132c5d2a9fc1efafdf1190c61cd5", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36", "host": "studio.my.site.com", "referer": "https://studio.my.site.com/export/course-v1:MyOrg+MyClass+V1", "accept_language": "en-US,en;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2023-03-03T22:18:58.119633+00:00", "event_type": "/export_status/course-v1:MyOrg+MyClass+V1", "event_source": "server", "page": null}
caddy_1                      | {"level":"info","ts":1677881938.142998,"logger":"http.log.access.log1","msg":"handled request","request":{"remote_addr":"1.2.3.4:52406","proto":"HTTP/2.0","method":"GET","host":"studio.my.site.com","uri":"/export_status/course-v1:MyOrg+MyClass+V1","tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"studio.my.site.com"}},"user_id":"","duration":0.037241062,"size":23,"status":200}
cms_1                        | [pid: 13|app: 0|req: 3259/6939] 172.19.0.8 () {58 vars in 3904 bytes} [Fri Mar  3 22:18:58 2023] GET /export_status/course-v1:MyOrg+MyClass+V1 => generated 23 bytes in 36 msecs (HTTP/1.1 200) 7 headers in 490 bytes (1 switches on core 0)
cms_1                        | 2023-03-03 22:18:59,181 INFO 7 [tracking] [user 3] [ip 1.2.3.4] logger.py:41 - {"name": "/export_status/course-v1:MyOrg+MyClass+V1", "context": {"user_id": 3, "path": "/export_status/course-v1:MyOrg+MyClass+V1", "course_id": "", "org_id": "", "enterprise_uuid": ""}, "username": "MyAdmin", "session": "186d132c5d2a9fc1efafdf1190c61cd5", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36", "host": "studio.my.site.com", "referer": "https://studio.my.site.com/export/course-v1:MyOrg+MyClass+V1", "accept_language": "en-US,en;q=0.9", "event": "{\"GET\": {}, \"POST\": {}}", "time": "2023-03-03T22:18:59.180838+00:00", "event_type": "/export_status/course-v1:MyOrg+MyClass+V1", "event_source": "server", "page": null}
caddy_1                      | {"level":"info","ts":1677881939.2006226,"logger":"http.log.access.log1","msg":"handled request","request":{"remote_addr":"1.2.3.4:52406","proto":"HTTP/2.0","method":"GET","host":"studio.my.site.com","uri":"/export_status/course-v1:MyOrg+MyClass+V1","tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"studio.my.site.com"}},"user_id":"","duration":0.033780371,"size":23,"status":200}
cms_1                        | [pid: 7|app: 0|req: 3277/6940] 172.19.0.8 () {58 vars in 3904 bytes} [Fri Mar  3 22:18:59 2023] GET /export_status/course-v1:MyOrg+MyClass+V1 => generated 23 bytes in 33 msecs (HTTP/1.1 200) 7 headers in 490 bytes (1 switches on core 0)

Which I assume is more about the website trying to auto-refresh the page for once it’s done. The problem is the hung export situation just shows the status gear spinning, it doesn’t show the Export button for me to try to cause new log events. (The export button flashes for a split-second before disappearing. Implying that it’s picking up on the stuck state, and then transitioning the UI.)

Is there some deeper way to find the stuck state and force-reset it? Could I do something manually (like from the terminal) to try and do the equivalent of what the export button does, and look at the logs more effectively?

(I just remembered about the command tutor local run -v /home/ubuntu/all_course:/tmp/bla cms ./manage.py cms export_all_courses /tmp/bla and I was able to run that successfully, so that’s a workaround for now (but it doesn’t help any of the non-sysadmin Instructors). So it does seem to me like it’s got to be some issue with some element being keyed off of by the Export page UI (and Progress page UI?), rather than a fundamental export issue.)

dave · March 4, 2023, 1:44am

Quick sanity check: are the instances that run your celery tasks running (cms-worker, lms-worker)?

ABC · March 4, 2023, 3:06am

How would I check that?

dave · March 4, 2023, 4:42am

What is the output of: tutor local status

If the state for your cms-worker and lms-worker are not “Up”, try:

tutor local start cms-worker
tutor local start lms-worker

If that outputs errors, please list them here. Though honestly, if it turns out that this is a tutor configuration issue, @regis or @kmccormick are going to be much more helpful to you than I am.

ABC · March 4, 2023, 11:30am

They are both up (and I did a quickstart as well, but that didn’t solve the issue):

tutor local status
docker-compose -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.yml -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.prod.yml -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.tmp.yml --project-name tutor_local ps
                 Name                                Command               State                                         Ports                                      
--------------------------------------------------------------------------------------------------------------------------------------------------------------------
tutor_local_caddy_1                       caddy run --config /etc/ca ...   Up       2019/tcp, 0.0.0.0:443->443/tcp,:::443->443/tcp, 0.0.0.0:80->80/tcp,:::80->80/tcp
tutor_local_cms-permissions_1             setowner 1000 /openedx/dat ...   Exit 0                                                                                   
tutor_local_cms-worker_1                  celery --app=cms.celery wo ...   Up       8000/tcp                                                                        
tutor_local_cms_1                         /bin/sh -c uwsgi     --sta ...   Up       8000/tcp                                                                        
tutor_local_elasticsearch-permissions_1   setowner 1000 /usr/share/e ...   Exit 0                                                                                   
tutor_local_elasticsearch_1               /tini -- /usr/local/bin/do ...   Up       9200/tcp, 9300/tcp                                                              
tutor_local_forum_1                       docker-entrypoint.sh /bin/ ...   Up       4567/tcp                                                                        
tutor_local_lms-permissions_1             setowner 1000 /openedx/dat ...   Exit 0                                                                                   
tutor_local_lms-worker_1                  celery --app=lms.celery wo ...   Up       8000/tcp                                                                        
tutor_local_lms_1                         /bin/sh -c uwsgi     --sta ...   Up       8000/tcp                                                                        
tutor_local_mfe_1                         caddy run --config /etc/ca ...   Up       2019/tcp, 443/tcp, 80/tcp                                                       
tutor_local_mongodb-permissions_1         setowner 999 /data/db            Exit 0                                                                                   
tutor_local_mongodb_1                     docker-entrypoint.sh mongo ...   Up       27017/tcp                                                                       
tutor_local_mysql-permissions_1           setowner 999 /var/lib/mysql      Exit 0                                                                                   
tutor_local_mysql_1                       docker-entrypoint.sh mysql ...   Up       3306/tcp, 33060/tcp                                                             
tutor_local_redis-permissions_1           setowner 1000 /openedx/red ...   Exit 0                                                                                   
tutor_local_redis_1                       docker-entrypoint.sh redis ...   Up       6379/tcp                                                                        
tutor_local_smtp_1                        /sbin/tini -- exim -bdf -q15m    Up       8025/tcp

dave · March 4, 2023, 7:28pm

Could you attach a copy of your worker logs when you:

Publish the course
Export the course

Thank you.

ABC · March 4, 2023, 10:44pm

I’d be happy to, and I appreciate the help you’re offering. But to be sure I’m collecting the right thing, by “worker logs”, is it sufficient to grep the tutor logs for worker like tutor local logs -f --tail=1 | grep worker ? If so, the logs are below. If not, LMK how to collect those.

Successfully publishing a change to a page within the course:

Attaching to tutor_local_cms-worker_1, tutor_local_lms-worker_1, tutor_local_cms_1, tutor_local_lms_1, tutor_local_forum_1, tutor_local_redis_1, tutor_local_mongodb_1, tutor_local_elasticsearch_1, tutor_local_mongodb-permissions_1, tutor_local_mysql-permissions_1, tutor_local_lms-permissions_1, tutor_local_cms-permissions_1, tutor_local_elasticsearch-permissions_1, tutor_local_mfe_1, tutor_local_redis-permissions_1, tutor_local_mysql_1, tutor_local_smtp_1, tutor_local_caddy_1
cms-worker_1                 | [2023-03-04 20:48:02,355: INFO/ForkPoolWorker-3] Task lms.djangoapps.discussion.tasks.update_discussions_map[bc57eefc-e23d-47eb-a4d0-d43158880d51] succeeded in 0.06337620003614575s: None
lms-worker_1                 | 2023-03-04 21:53:36,715 INFO 53 [celery.app.trace] [user None] [ip None] trace.py:131 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[52889644-65d8-42e0-b43a-057e7b220b5c] succeeded in 1.166973004990723s: None
cms-worker_1                 | [2023-03-04 22:32:15,459: INFO/MainProcess] Task cms.djangoapps.contentstore.tasks.update_special_exams_and_publish[590ec5b3-7274-4193-83ca-31621a346cd0] received
cms-worker_1                 | [2023-03-04 22:32:15,464: INFO/ForkPoolWorker-3] cms.djangoapps.contentstore.tasks.update_special_exams_and_publish[590ec5b3-7274-4193-83ca-31621a346cd0]: Attempting to register exams for course course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:15,464: INFO/ForkPoolWorker-3] cms.djangoapps.contentstore.tasks.update_special_exams_and_publish[590ec5b3-7274-4193-83ca-31621a346cd0]: Successfully registered exams for course course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:15,465: INFO/ForkPoolWorker-3] cms.djangoapps.contentstore.tasks.update_special_exams_and_publish[590ec5b3-7274-4193-83ca-31621a346cd0]: Publishing course course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:15,467: INFO/ForkPoolWorker-3] Task cms.djangoapps.contentstore.tasks.update_special_exams_and_publish[590ec5b3-7274-4193-83ca-31621a346cd0] succeeded in 0.004456143011339009s: None
cms-worker_1                 | [2023-03-04 22:32:15,474: INFO/MainProcess] Task cms.djangoapps.contentstore.tasks.update_outline_from_modulestore_task[42f65ddc-1c99-4bc2-8272-0f9420acd148] received
cms-worker_1                 | [2023-03-04 22:32:15,492: INFO/MainProcess] Task cms.djangoapps.contentstore.tasks.update_search_index[d2d05009-ec0c-4416-8f42-77a3e03edcd3] received
cms-worker_1                 | [2023-03-04 22:32:15,505: INFO/MainProcess] Task openedx.core.djangoapps.discussions.tasks.update_discussions_settings_from_course_task[8bb2a1ba-ff03-45cb-a5b9-d009f82d6e83] received
cms-worker_1                 | [2023-03-04 22:32:15,515: INFO/ForkPoolWorker-2] HEAD http://elasticsearch:9200/courseware_content [status:200 request:0.013s]
lms-worker_1                 | 2023-03-04 22:32:15,603 INFO 1 [celery.worker.strategy] [user None] [ip None] strategy.py:161 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[bc565e35-2d20-48b5-9baf-63c5dfeb3f0a] received
cms-worker_1                 | [2023-03-04 22:32:15,675: INFO/MainProcess] Task openedx.core.djangoapps.bookmarks.tasks.update_xblocks_cache[0b0275bf-0700-44f3-8884-74f64e7855aa] received
cms-worker_1                 | [2023-03-04 22:32:15,890: INFO/ForkPoolWorker-2] HEAD http://elasticsearch:9200/course_info [status:200 request:0.011s]
cms-worker_1                 | [2023-03-04 22:32:16,074: INFO/ForkPoolWorker-2] GET http://elasticsearch:9200/course_info/_mapping [status:200 request:0.004s]
cms-worker_1                 | [2023-03-04 22:32:16,099: INFO/ForkPoolWorker-2] POST http://elasticsearch:9200/_bulk [status:200 request:0.013s]
cms-worker_1                 | [2023-03-04 22:32:17,202: INFO/ForkPoolWorker-3] Replacing CourseOutline for course-v1:MyOrg+MyClass+V1 (version 6403a5600d4a136848d519a0, 33 sequences)
cms-worker_1                 | [2023-03-04 22:32:17,217: INFO/ForkPoolWorker-3] Found CourseContext for course-v1:MyOrg+MyClass+V1, updating...
cms-worker_1                 | [2023-03-04 22:32:17,993: INFO/ForkPoolWorker-3] Task cms.djangoapps.contentstore.tasks.update_outline_from_modulestore_task[42f65ddc-1c99-4bc2-8272-0f9420acd148] succeeded in 2.5163512229919434s: None
cms-worker_1                 | [2023-03-04 22:32:17,999: INFO/ForkPoolWorker-3] Updating discussion settings for course: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:18,065: INFO/ForkPoolWorker-3] Updating existing discussion topic links for course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:18,070: INFO/ForkPoolWorker-3] Creating new discussion topic links for course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:18,073: INFO/ForkPoolWorker-3] Responses of the Open edX Event <org.openedx.learning.discussions.configuration.changed.v1>: 
cms-worker_1                 | [(<function handle_course_discussion_config_update at 0x7f06ab6ff670>, None)]
cms-worker_1                 | [2023-03-04 22:32:18,076: INFO/ForkPoolWorker-3] Task openedx.core.djangoapps.discussions.tasks.update_discussions_settings_from_course_task[8bb2a1ba-ff03-45cb-a5b9-d009f82d6e83] succeeded in 0.07943719800096005s: None
cms-worker_1                 | [2023-03-04 22:32:18,083: INFO/MainProcess] Task openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[441f0607-8e61-45c9-9802-5d48d8b5492d] received
cms-worker_1                 | [2023-03-04 22:32:18,089: INFO/ForkPoolWorker-3] Starting XBlockCaches update for course_key: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:19,209: INFO/MainProcess] Task lms.djangoapps.discussion.tasks.update_discussions_map[8e812304-5fa1-4312-bc12-04ea7b1a6bb8] received
cms-worker_1                 | [2023-03-04 22:32:20,172: INFO/ForkPoolWorker-3] Ending XBlockCaches update for course_key: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:20,175: INFO/ForkPoolWorker-3] Task openedx.core.djangoapps.bookmarks.tasks.update_xblocks_cache[0b0275bf-0700-44f3-8884-74f64e7855aa] succeeded in 2.0889096279861405s: None
cms-worker_1                 | [2023-03-04 22:32:20,181: INFO/ForkPoolWorker-3] openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[441f0607-8e61-45c9-9802-5d48d8b5492d]: Caching course apps status for course with id: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-04 22:32:20,293: WARNING/ForkPoolWorker-3] Flag 'course_live.enable_course_live' accessed without a request, which is likely in the context of a celery task.
cms-worker_1                 | [2023-03-04 22:32:20,309: WARNING/ForkPoolWorker-3] Flag 'teams.enable_teams_app' accessed without a request, which is likely in the context of a celery task.
cms-worker_1                 | [2023-03-04 22:32:20,341: INFO/ForkPoolWorker-3] Task openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[441f0607-8e61-45c9-9802-5d48d8b5492d] succeeded in 0.16155889898072928s: None

Result when I navigate to the Export page:

Attaching to tutor_local_cms-worker_1, tutor_local_lms-worker_1, tutor_local_cms_1, tutor_local_lms_1, tutor_local_forum_1, tutor_local_redis_1, tutor_local_mongodb_1, tutor_local_elasticsearch_1, tutor_local_mongodb-permissions_1, tutor_local_mysql-permissions_1, tutor_local_lms-permissions_1, tutor_local_cms-permissions_1, tutor_local_elasticsearch-permissions_1, tutor_local_mfe_1, tutor_local_redis-permissions_1, tutor_local_mysql_1, tutor_local_smtp_1, tutor_local_caddy_1
cms-worker_1                 | [2023-03-04 22:32:46,965: INFO/ForkPoolWorker-3] Task lms.djangoapps.discussion.tasks.update_discussions_map[8e812304-5fa1-4312-bc12-04ea7b1a6bb8] succeeded in 0.41830553102772683s: None
lms-worker_1                 | 2023-03-04 22:32:15,603 INFO 1 [celery.worker.strategy] [user None] [ip None] strategy.py:161 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[bc565e35-2d20-48b5-9baf-63c5dfeb3f0a] received
lms-worker_1                 | 2023-03-04 22:32:56,814 INFO 53 [openedx.core.djangoapps.content.block_structure.store] [user None] [ip None] store.py:165 - BlockStructure: Added to cache; block-v1:MyOrg+MyClass+V1+type@course+block@course, size: 66694
lms-worker_1                 | 2023-03-04 22:32:56,819 INFO 53 [celery.app.trace] [user None] [ip None] trace.py:131 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[bc565e35-2d20-48b5-9baf-63c5dfeb3f0a] succeeded in 11.179432905977592s: None
cms-worker_1                 | [2023-03-04 22:33:06,424: INFO/ForkPoolWorker-2] GET http://elasticsearch:9200/courseware_content/_mapping [status:200 request:0.003s]
cms-worker_1                 | [2023-03-04 22:33:06,463: INFO/ForkPoolWorker-2] POST http://elasticsearch:9200/_bulk [status:200 request:0.013s]
cms-worker_1                 | [2023-03-04 22:33:06,575: INFO/ForkPoolWorker-2] POST http://elasticsearch:9200/courseware_content/_search [status:200 request:0.102s]
cms-worker_1                 | [2023-03-04 22:33:06,581: INFO/ForkPoolWorker-2] Task cms.djangoapps.contentstore.tasks.update_search_index[d2d05009-ec0c-4416-8f42-77a3e03edcd3] succeeded in 51.08238783100387s: None

Where I just see this Exporting UI forever:

Results when successfully exporting any class except this one:

Attaching to tutor_local_cms-worker_1, tutor_local_lms-worker_1, tutor_local_cms_1, tutor_local_lms_1, tutor_local_forum_1, tutor_local_redis_1, tutor_local_mongodb_1, tutor_local_elasticsearch_1, tutor_local_mongodb-permissions_1, tutor_local_mysql-permissions_1, tutor_local_lms-permissions_1, tutor_local_cms-permissions_1, tutor_local_elasticsearch-permissions_1, tutor_local_mfe_1, tutor_local_redis-permissions_1, tutor_local_mysql_1, tutor_local_smtp_1, tutor_local_caddy_1
cms-worker_1                 | [2023-03-04 22:33:06,581: INFO/ForkPoolWorker-2] Task cms.djangoapps.contentstore.tasks.update_search_index[d2d05009-ec0c-4416-8f42-77a3e03edcd3] succeeded in 51.08238783100387s: None
lms-worker_1                 | 2023-03-04 22:32:56,819 INFO 53 [celery.app.trace] [user None] [ip None] trace.py:131 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[bc565e35-2d20-48b5-9baf-63c5dfeb3f0a] succeeded in 11.179432905977592s: None
cms-worker_1                 | [2023-03-04 22:39:55,080: INFO/MainProcess] Task cms.djangoapps.contentstore.tasks.export_olx[e5a990d8-29e8-4de7-80b6-3d7c7805fe12] received
cms-worker_1                 | [2023-03-04 22:39:56,117: INFO/MainProcess] Task cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[65c34487-1d1f-4b3e-ac3a-47948c6204bc] received
cms-worker_1                 | [2023-03-04 22:39:56,120: INFO/ForkPoolWorker-3] Task cms.djangoapps.contentstore.tasks.export_olx[e5a990d8-29e8-4de7-80b6-3d7c7805fe12] succeeded in 1.0049937010044232s: None
cms-worker_1                 | [2023-03-04 22:39:57,347: INFO/ForkPoolWorker-2] cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[65c34487-1d1f-4b3e-ac3a-47948c6204bc]: Task complete email has been sent to User admin@my.site.com
cms-worker_1                 | [2023-03-04 22:39:57,349: INFO/ForkPoolWorker-2] Task cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[65c34487-1d1f-4b3e-ac3a-47948c6204bc] succeeded in 1.2291199080063961s: None

dave · March 7, 2023, 7:35pm

Thank you, those look like the correct logs, but I’m a little stumped as to how it’s breaking. Another question: What advanced modules (XBlock types) do you have enabled in advanced settings for this course?

ABC · March 7, 2023, 8:56pm

[
    "library_content",
    "done",
    "survey",
    "markdown"
]

But these are the same as are enabled in the class that exports fine. (I wasn’t sure if a working one for sure was actually using a survey, but I checked and it is.)

When I look at the two logs, the main difference between the working export and non-working export I see, is that the non-working export has this line:

store.py:165 - BlockStructure: Added to cache; block-v1:MyOrg+MyClass+V1+type@course+block@course, size: 66694

Which sort of jives with the idea of it being stuck thinking there’s an export happening already, which is why the UI keeps coming up like that.

The working one also has “cms.djangoapps.contentstore.tasks.export_olx” and references to INFO/MainProcess which the non-working doesn’t.

ABC · March 8, 2023, 6:01pm

So today, for unknown reasons, the Export UI went back to its normal well-behaved self, and it even let me export the class again… I have no idea what could have caused this, but I’ve been continuously adding to the class over the past few days. And I did deleted one Problem just now.

However, this does not appear to have correlated with a solution to the main issue from the subject line. When I view the Progress page as a student, it still shows the incorrect old count for the score on subsections where extra Problems have been added. Additionally, an export-then-import (and a student-side browser cache clear and browser restart) doesn’t appear to cause an update to the Progress page for the student account.

ABC · March 8, 2023, 8:29pm

I tried exporting a Library from the server (at what I assume is time 20:10 in the logs), and it was taking way longer than it seemed like it should have (it was just 19 multiple choice and checkbox Problems). Eventually (at time 20:13) it finished, but there was an error that came along with it:

“too_many_clauses’, ‘reason’: ‘maxClauseCount is set to 1024’}”
and
ERROR/ForkPoolWorker-17] Indexing error encountered, courseware index may be out of date course-v1:MyOrg+MyClass+V1

cms-worker_1                 | [2023-03-08 20:14:31,845: WARNING/ForkPoolWorker-17] POST http://elasticsearch:9200/courseware_content/_search [status:400 request:0.005s]
cms-worker_1                 | [2023-03-08 20:14:31,846: ERROR/ForkPoolWorker-17] error while searching index - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})
-------------------[cut]------------------------
cms-worker_1                 | [2023-03-08 20:14:31,846: ERROR/ForkPoolWorker-17] Indexing error encountered, courseware index may be out of date course-v1:MyOrg+MyClass+V1 - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})

Could this be part of the problem? If so, how do I either increase the maxClauseCount, or force update the elasticsearch(?) indexing?

@regis I can see there’s some elasticsearch configuration options in tutor (like ELASTICSEARCH_HEAP_SIZE). Is there a way to increase maxClauseCount? If not, should I file a ticket for this?

Full logs below:

lms-worker_1                 | 2023-03-08 20:10:07,741 INFO 1 [celery.worker.strategy] [user None] [ip None] strategy.py:161 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[d2e9ee66-34a0-43bf-af41-c53d484c728e] received
lms-worker_1                 | 2023-03-08 20:10:14,673 INFO 221 [openedx.core.djangoapps.content.block_structure.store] [user None] [ip None] store.py:165 - BlockStructure: Added to cache; block-v1:MyOrg+MyClass+V1+type@course+block@course, size: 86162
lms-worker_1                 | 2023-03-08 20:10:14,681 INFO 221 [celery.app.trace] [user None] [ip None] trace.py:131 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[05c2ecca-880e-4005-9bb4-618dd6aa1fe2] succeeded in 13.269585105008446s: None
lms-worker_1                 | 2023-03-08 20:10:51,363 INFO 221 [openedx.core.djangoapps.content.block_structure.store] [user None] [ip None] store.py:165 - BlockStructure: Added to cache; block-v1:MyOrg+MyClass+V1+type@course+block@course, size: 87187
lms-worker_1                 | 2023-03-08 20:10:51,371 INFO 221 [celery.app.trace] [user None] [ip None] trace.py:131 - Task openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[d2e9ee66-34a0-43bf-af41-c53d484c728e] succeeded in 13.347861725022085s: None
cms-worker_1                 | [2023-03-08 20:13:49,650: INFO/ForkPoolWorker-16] POST http://elasticsearch:9200/_bulk [status:200 request:0.069s]
cms-worker_1                 | [2023-03-08 20:13:50,643: WARNING/ForkPoolWorker-16] POST http://elasticsearch:9200/courseware_content/_search [status:400 request:0.959s]
cms-worker_1                 | [2023-03-08 20:13:50,643: ERROR/ForkPoolWorker-16] error while searching index - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/search/elastic.py", line 645, in search
cms-worker_1                 |     es_response = self._es.search(index=self.index_name, body=body, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/utils.py", line 168, in _wrapped
cms-worker_1                 |     return func(*args, params=params, headers=headers, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/__init__.py", line 1670, in search
cms-worker_1                 |     return self.transport.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 415, in perform_request
cms-worker_1                 |     raise e
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 381, in perform_request
cms-worker_1                 |     status, headers_response, data = connection.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/http_urllib3.py", line 277, in perform_request
cms-worker_1                 |     self._raise_error(response.status, raw_data)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/base.py", line 330, in _raise_error
cms-worker_1                 |     raise HTTP_EXCEPTIONS.get(status_code, TransportError)(
cms-worker_1                 | elasticsearch.exceptions.RequestError: RequestError(400, 'search_phase_execution_exception', 'failed to create query: maxClauseCount is set to 1024')
cms-worker_1                 | [2023-03-08 20:13:50,644: ERROR/ForkPoolWorker-16] Indexing error encountered, courseware index may be out of date course-v1:MyOrg+MyClass+V1 - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/openedx/edx-platform/cms/djangoapps/contentstore/courseware_index.py", line 260, in index
cms-worker_1                 |     cls.remove_deleted_items(searcher, structure_key, indexed_items)
cms-worker_1                 |   File "/openedx/edx-platform/cms/djangoapps/contentstore/courseware_index.py", line 109, in remove_deleted_items
cms-worker_1                 |     response = searcher.search(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/search/elastic.py", line 645, in search
cms-worker_1                 |     es_response = self._es.search(index=self.index_name, body=body, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/utils.py", line 168, in _wrapped
cms-worker_1                 |     return func(*args, params=params, headers=headers, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/__init__.py", line 1670, in search
cms-worker_1                 |     return self.transport.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 415, in perform_request
cms-worker_1                 |     raise e
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 381, in perform_request
cms-worker_1                 |     status, headers_response, data = connection.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/http_urllib3.py", line 277, in perform_request
cms-worker_1                 |     self._raise_error(response.status, raw_data)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/base.py", line 330, in _raise_error
cms-worker_1                 |     raise HTTP_EXCEPTIONS.get(status_code, TransportError)(
cms-worker_1                 | elasticsearch.exceptions.RequestError: RequestError(400, 'search_phase_execution_exception', 'failed to create query: maxClauseCount is set to 1024')
cms-worker_1                 | [2023-03-08 20:13:50,649: ERROR/ForkPoolWorker-16] cms.djangoapps.contentstore.tasks.update_search_index[7e93182d-80c7-4495-b614-90a2cf34b865]: Search indexing error for complete course course-v1:MyOrg+MyClass+V1 - Error(s) present during indexing - ['General indexing error occurred']
cms-worker_1                 | [2023-03-08 20:13:50,658: INFO/ForkPoolWorker-16] Task cms.djangoapps.contentstore.tasks.update_search_index[7e93182d-80c7-4495-b614-90a2cf34b865] succeeded in 132.37137719092425s: None
cms-worker_1                 | [2023-03-08 20:13:50,665: INFO/ForkPoolWorker-16] Updating discussion settings for course: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:50,740: INFO/ForkPoolWorker-16] Updating existing discussion topic links for course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:50,743: INFO/ForkPoolWorker-16] Creating new discussion topic links for course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:50,746: INFO/ForkPoolWorker-16] Responses of the Open edX Event <org.openedx.learning.discussions.configuration.changed.v1>: 
cms-worker_1                 | [(<function handle_course_discussion_config_update at 0x7f06ab6ff670>, None)]
cms-worker_1                 | [2023-03-08 20:13:50,748: INFO/ForkPoolWorker-16] Task openedx.core.djangoapps.discussions.tasks.update_discussions_settings_from_course_task[2e7caf0b-9967-4926-8d86-f5844b760916] succeeded in 0.08524999290239066s: None
cms-worker_1                 | [2023-03-08 20:13:50,753: INFO/MainProcess] Task openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[ab1dc55e-a32a-4a4e-a44d-307c3ea6a020] received
cms-worker_1                 | [2023-03-08 20:13:50,755: INFO/ForkPoolWorker-16] Starting XBlockCaches update for course_key: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:51,064: INFO/MainProcess] Task lms.djangoapps.discussion.tasks.update_discussions_map[72a7a5ae-c9ed-4169-81cf-d680d9af293a] received
cms-worker_1                 | [2023-03-08 20:13:51,069: INFO/MainProcess] Task cms.djangoapps.contentstore.tasks.export_olx[5032675a-6360-4e52-9e58-626d47e7ec6e] received
cms-worker_1                 | [2023-03-08 20:13:53,922: INFO/ForkPoolWorker-16] Ending XBlockCaches update for course_key: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:53,925: INFO/ForkPoolWorker-16] Task openedx.core.djangoapps.bookmarks.tasks.update_xblocks_cache[bcef2f2f-a178-4ff2-b55e-595d73c9bcbc] succeeded in 3.1712943569291383s: None
cms-worker_1                 | [2023-03-08 20:13:53,932: INFO/ForkPoolWorker-16] openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[ab1dc55e-a32a-4a4e-a44d-307c3ea6a020]: Caching course apps status for course with id: course-v1:MyOrg+MyClass+V1
cms-worker_1                 | [2023-03-08 20:13:54,046: WARNING/ForkPoolWorker-16] Flag 'course_live.enable_course_live' accessed without a request, which is likely in the context of a celery task.
cms-worker_1                 | [2023-03-08 20:13:54,058: WARNING/ForkPoolWorker-16] Flag 'teams.enable_teams_app' accessed without a request, which is likely in the context of a celery task.
cms-worker_1                 | [2023-03-08 20:13:54,094: INFO/ForkPoolWorker-16] Task openedx.core.djangoapps.course_apps.tasks.update_course_apps_status[ab1dc55e-a32a-4a4e-a44d-307c3ea6a020] succeeded in 0.16263084998354316s: None
cms-worker_1                 | [2023-03-08 20:13:54,343: INFO/ForkPoolWorker-16] Task lms.djangoapps.discussion.tasks.update_discussions_map[72a7a5ae-c9ed-4169-81cf-d680d9af293a] succeeded in 0.24337788205593824s: None
cms-worker_1                 | [2023-03-08 20:13:54,793: INFO/MainProcess] Task cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[c0e59cda-d5a4-4555-b4f2-380ff55e7647] received
cms-worker_1                 | [2023-03-08 20:13:54,798: INFO/ForkPoolWorker-16] Task cms.djangoapps.contentstore.tasks.export_olx[5032675a-6360-4e52-9e58-626d47e7ec6e] succeeded in 0.3992679190123454s: None
cms-worker_1                 | [2023-03-08 20:13:55,702: INFO/ForkPoolWorker-16] cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[c0e59cda-d5a4-4555-b4f2-380ff55e7647]: Task complete email has been sent to User admin@mysite.com
cms-worker_1                 | [2023-03-08 20:13:55,704: INFO/ForkPoolWorker-16] Task cms.djangoapps.cms_user_tasks.tasks.send_task_complete_email[c0e59cda-d5a4-4555-b4f2-380ff55e7647] succeeded in 0.9000500189140439s: None
cms-worker_1                 | [2023-03-08 20:14:31,585: INFO/ForkPoolWorker-17] GET http://elasticsearch:9200/courseware_content/_mapping [status:200 request:0.002s]
cms-worker_1                 | [2023-03-08 20:14:31,830: INFO/ForkPoolWorker-17] POST http://elasticsearch:9200/_bulk [status:200 request:0.016s]
cms-worker_1                 | [2023-03-08 20:14:31,845: WARNING/ForkPoolWorker-17] POST http://elasticsearch:9200/courseware_content/_search [status:400 request:0.005s]
cms-worker_1                 | [2023-03-08 20:14:31,846: ERROR/ForkPoolWorker-17] error while searching index - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/search/elastic.py", line 645, in search
cms-worker_1                 |     es_response = self._es.search(index=self.index_name, body=body, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/utils.py", line 168, in _wrapped
cms-worker_1                 |     return func(*args, params=params, headers=headers, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/__init__.py", line 1670, in search
cms-worker_1                 |     return self.transport.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 415, in perform_request
cms-worker_1                 |     raise e
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 381, in perform_request
cms-worker_1                 |     status, headers_response, data = connection.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/http_urllib3.py", line 277, in perform_request
cms-worker_1                 |     self._raise_error(response.status, raw_data)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/base.py", line 330, in _raise_error
cms-worker_1                 |     raise HTTP_EXCEPTIONS.get(status_code, TransportError)(
cms-worker_1                 | elasticsearch.exceptions.RequestError: RequestError(400, 'search_phase_execution_exception', 'failed to create query: maxClauseCount is set to 1024')
cms-worker_1                 | [2023-03-08 20:14:31,846: ERROR/ForkPoolWorker-17] Indexing error encountered, courseware index may be out of date course-v1:MyOrg+MyClass+V1 - RequestError(400, 'search_phase_execution_exception', {'error': {'root_cause': [{'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content'}], 'type': 'search_phase_execution_exception', 'reason': 'all shards failed', 'phase': 'query', 'grouped': True, 'failed_shards': [{'shard': 0, 'index': 'courseware_content', 'node': '0YuJynDBRSKSPHqmJ7yGGQ', 'reason': {'type': 'query_shard_exception', 'reason': 'failed to create query: maxClauseCount is set to 1024', 'index_uuid': 'xiegEFgxTa2Ll_0trcRvOQ', 'index': 'courseware_content', 'caused_by': {'type': 'too_many_clauses', 'reason': 'maxClauseCount is set to 1024'}}}]}, 'status': 400})
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/openedx/edx-platform/cms/djangoapps/contentstore/courseware_index.py", line 260, in index
cms-worker_1                 |     cls.remove_deleted_items(searcher, structure_key, indexed_items)
cms-worker_1                 |   File "/openedx/edx-platform/cms/djangoapps/contentstore/courseware_index.py", line 109, in remove_deleted_items
cms-worker_1                 |     response = searcher.search(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/search/elastic.py", line 645, in search
cms-worker_1                 |     es_response = self._es.search(index=self.index_name, body=body, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/utils.py", line 168, in _wrapped
cms-worker_1                 |     return func(*args, params=params, headers=headers, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/client/__init__.py", line 1670, in search
cms-worker_1                 |     return self.transport.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 415, in perform_request
cms-worker_1                 |     raise e
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/transport.py", line 381, in perform_request
cms-worker_1                 |     status, headers_response, data = connection.perform_request(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/http_urllib3.py", line 277, in perform_request
cms-worker_1                 |     self._raise_error(response.status, raw_data)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/elasticsearch/connection/base.py", line 330, in _raise_error
cms-worker_1                 |     raise HTTP_EXCEPTIONS.get(status_code, TransportError)(
cms-worker_1                 | elasticsearch.exceptions.RequestError: RequestError(400, 'search_phase_execution_exception', 'failed to create query: maxClauseCount is set to 1024')
cms-worker_1                 | [2023-03-08 20:14:31,848: ERROR/ForkPoolWorker-17] cms.djangoapps.contentstore.tasks.update_search_index[6dd253e6-8dc0-48c8-88c1-34311e14cbc0]: Search indexing error for complete course course-v1:MyOrg+MyClass+V1 - Error(s) present during indexing - ['General indexing error occurred']
cms-worker_1                 | [2023-03-08 20:14:31,850: INFO/ForkPoolWorker-17] Task cms.djangoapps.contentstore.tasks.update_search_index[6dd253e6-8dc0-48c8-88c1-34311e14cbc0] succeeded in 106.26902770798188s: None

ABC · March 16, 2023, 4:13pm

@regis I can see there’s some elasticsearch configuration options in tutor (like ELASTICSEARCH_HEAP_SIZE). Is there a way to increase maxClauseCount? If not, should I file a ticket for this?

regis · March 16, 2023, 5:56pm

I have no idea. How would you modify that setting in a regular Docker-based installation of Elasticsearch?

I’d rather not, as GitHub issues are not made for user support.

sambapete · March 16, 2023, 6:40pm

You can modify the maxClauseCount through docker-compose.override.yml

We ran into a similar problem at some point and added a section for elasticsearch in docker-compose.override.yml

version: "3.7"
services:

  elasticsearch:
    environment:
      - indices.query.bool.max_clause_count=4096

ABC · March 16, 2023, 7:56pm

Thanks @sambapete! And according to this it looks like that file needs to be put into $(tutor config printroot)/env/local/docker-compose.override.yml correct? I’m just checking if that’s still applicable this year and a half later.

Out of curiosity, do you know what it is about classes that makes them exceed that max clause count?

Edit: What I can see is that if I put the file in $(tutor config printroot)/env/local/docker-compose.override.yml, do “tutor local stop”, “tutor local start -d”, I don’t see any more maxClauseCount errors in the log when it’s started back up. So that seems like a Good Thing!

However, this appears to not be the root cause of the failure to update the Progress page, as I created a new Problem, published it, and then went and looked from a refreshed student Progress page (logged in as the fake student in a different browser), and the Problem didn’t show up still in the score. :-/

sambapete · March 16, 2023, 8:08pm

That’s correct. I am currently using it with nutmeg.3 and tutor v14.2.3

And no, I haven’t checked what caused the default values to be exceeded. It fixed one of the problems we had when reindexing discovery through elasticsearch.

I only suggested a solution to your maxClauseCount errors.

Topic		Replies	Views
Students’ “Progress” page doesn’t update when new Problems are added or update and delete the problem Development	0	413	June 20, 2023
Grades not updating in gradebook, progress page, or database Tutor Help tutor , nutmeg	2	868	October 25, 2022
Debugging persistent grade issues Site Operators palm	7	666	December 15, 2023
Grades not updating on progress page or database Tutor Help how-to , devstack , tutor , nutmeg	0	268	November 2, 2023
How to set new progress page for course? Site Operators	7	925	July 1, 2022

Students' "Progress" page doesn't update when new Problems are added

Related topics