Measuring time spent by student

Hi all,

We need to measure the time that students spend in courses. Currently we are doing something by checking the tracking logs.
I wonder if someone implemented something in this direction. Maybe using google analytics?

1 Like

I was just about to post a question about mysql queries along these lines, so I’ll use your thread first and split into my own thread if you object.

I also want to track student time that they spend in classes, and with all the analytics currently broken + switching over to tutor yielding non-free analytics, I guess I have to make raw mysql queries myself.

So I use “Mark as complete” checkboxes for students to manually track their own progress. I’d like to extract from the database the times when students checked those boxes. I’d then graph that like this:

Then to extract a total time spent (approximation), I’d remove any time difference which is greater than a set amount that the longest section should ever take (e.g. 3 hours.) So from A->B is time 1, B->C is time 2, and then if C->D is like 2 days, I’d just exclude that, and continue on with the D->E time 3 etc. (Obviously this loses data where students didn’t end by checking a box, but oh well, so does auto-time tracking.)

So I know enough SQL to be able to puzzle out how to extract this data IF I can find my way into the db in the first place. So my question is:

  1. How can I get into the mysql db on a tutor-based system?
  2. Can anyone confirm that clicking those “Mark as complete” boxes does actually insert a timestamped event into the database somewhere?
1 Like

Well, at least for question 1, the answer is:
docker exec -it tutor_local_mysql_1 mysql -u root --password=FOO
where the mysql password is printed out by a “tutor local quickstart”

I think “Mark as completed” is an Xblock and thus the value should be stored somewhere in mongodb.
I am not 100%, but I really really doubt it that any xblock type of storage would be stored in mysql.

1 Like

It is indeed an xblock. I guess I’ll have to go learn a bit of mongodb then. Thanks for the tip.

Alright, I’ve learned how to get access to mongodb on tutor

tutor local exec mongodb bash
mongo

So I then went and toggled a completion block that was already marked done first off and then back on, and here’s the result that I see in the logs.

lms_1            | 2022-06-19 16:36:23,497 INFO 115 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg"}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {}, \"POST\": {\"{\\\"done\\\":false}\": [\"\"]}}", "time": "2022-06-19T16:36:23.496677+00:00", "event_type": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "event_source": "server", "page": null}
lms-worker_1     | 2022-06-19 16:26:26,402 INFO 107 [celery.app.trace] [user None] [ip None] trace.py:125 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[e890b6a9-7fd8-4803-951a-895940df33f1] succeeded in 1.676757762208581s: None
lms-worker_1     | 2022-06-19 16:36:23,926 INFO 1 [celery.worker.strategy] [user None] [ip None] strategy.py:157 - Received task: lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[07829744-0e12-4f1b-9344-45b62488a64f]  ETA:[2022-06-19 16:36:25.905313+00:00] 
lms-worker_1     | 2022-06-19 16:36:25,138 INFO 1 [celery.worker.strategy] [user None] [ip None] strategy.py:157 - Received task: lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[c99fad5c-4548-47e2-a326-f84fb9e97a1c]  ETA:[2022-06-19 16:36:27.091576+00:00] 
lms-worker_1     | 2022-06-19 16:36:26,254 WARNING 107 [edx_toggles.toggles.internal.waffle.flag] [user None] [ip None] flag.py:79 - Grades: Flag 'grades.enforce_freeze_grade_after_course_end' accessed without a request
lms-worker_1     | /openedx/venv/lib/python3.8/site-packages/celery/platforms.py:800: RuntimeWarning: You're running the worker with superuser privileges: this is
lms-worker_1     | absolutely not recommended!
lms-worker_1     | 
lms-worker_1     | Please specify a different user using the --uid option.
lms-worker_1     | 
lms-worker_1     | User information: uid=0 euid=0 gid=0 egid=0
lms-worker_1     | 
lms-worker_1     |   warnings.warn(RuntimeWarning(ROOT_DISCOURAGED.format(
lms-worker_1     | 2022-06-19 16:36:27,278 WARNING 108 [edx_toggles.toggles.internal.waffle.flag] [user None] [ip None] flag.py:79 - Grades: Flag 'grades.enforce_freeze_grade_after_course_end' accessed without a request
lms-worker_1     | 2022-06-19 16:36:28,740 WARNING 107 [edx_toggles.toggles.internal.waffle.flag] [user None] [ip None] flag.py:79 - Flag 'certificates_revamp.use_allowlist' accessed without a request
lms-worker_1     | 2022-06-19 16:36:28,745 INFO 107 [lms.djangoapps.grades.course_grade_factory] [user None] [ip None] course_grade_factory.py:218 - Grades: Update, Course: course_key: course-v1:MyOrg+MyClass+Run1, version: 6293af44c5818b812eb1bb5d, edited_on: 2022-05-29 17:37:08.419000+00:00, grading_policy: EuAnck2qOGYAN+FjlLkuji6w1Ak=, User: 77, Course Grade: percent: 0.32, letter_grade: None, passed: False, persisted: False
lms-worker_1     | 2022-06-19 16:36:28,752 INFO 107 [celery.app.trace] [user None] [ip None] trace.py:125 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[07829744-0e12-4f1b-9344-45b62488a64f] succeeded in 2.5147724989801645s: None
lms_1            | 2022-06-19 16:36:23,525 INFO 7 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.done.toggled", "context": {"user_id": 77, "path": "/event", "course_id": "course-v1:MyOrg+MyClass+Run1", "org_id": "MyOrg"}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": "{\"done\": false}", "time": "2022-06-19T16:36:23.525016+00:00", "event_type": "edx.done.toggled", "event_source": "browser", "page": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234"}
lms_1            | [pid: 7|app: 0|req: 32/170] 172.18.0.12 () {60 vars in 2442 bytes} [Sun Jun 19 16:36:23 2022] POST /event => generated 7 bytes in 92 msecs (HTTP/1.0 200) 7 headers in 363 bytes (1 switches on core 0)
lms_1            | 2022-06-19 16:36:23,904 INFO 115 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.grades.problem.submitted", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg", "module": {"display_name": "Completion", "usage_key": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8"}}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": {"user_id": "77", "course_id": "course-v1:MyOrg+MyClass+Run1", "problem_id": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8", "event_transaction_id": "f865e0a8-649a-42bf-b401-1ec2a0158d02", "event_transaction_type": "edx.grades.problem.submitted", "weighted_earned": 0, "weighted_possible": 1}, "time": "2022-06-19T16:36:23.903747+00:00", "event_type": "edx.grades.problem.submitted", "event_source": "server", "page": null}
lms_1            | 2022-06-19 16:36:23,929 INFO 115 [celery_utils.logged_task] [user 77] [ip 1.2.3.4] logged_task.py:25 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[07829744-0e12-4f1b-9344-45b62488a64f] submitted with arguments None, {'user_id': 5, 'anonymous_user_id': None, 'course_id': 'course-v1:MyOrg+MyClass+Run1', 'usage_id': 'block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8', 'only_if_higher': None, 'expected_modified_time': 1655656583, 'score_deleted': None, 'event_transaction_id': 'f865e0a8-649a-42bf-b401-1ec2a0158d02', 'event_transaction_type': 'edx.grades.problem.submitted', 'score_db_table': 'csm', 'force_update_subsections': False}
lms_1            | 2022-06-19 16:36:23,933 INFO 115 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.done.toggled", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg", "module": {"display_name": "Completion", "usage_key": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8"}, "asides": {}}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": {"done": false}, "time": "2022-06-19T16:36:23.932822+00:00", "event_type": "edx.done.toggled", "event_source": "server", "page": "x_module"}
lms-worker_1     | 2022-06-19 16:36:29,745 WARNING 108 [edx_toggles.toggles.internal.waffle.flag] [user None] [ip None] flag.py:79 - Flag 'certificates_revamp.use_allowlist' accessed without a request
lms-worker_1     | 2022-06-19 16:36:29,750 INFO 108 [lms.djangoapps.grades.course_grade_factory] [user None] [ip None] course_grade_factory.py:218 - Grades: Update, Course: course_key: course-v1:MyOrg+MyClass+Run1, version: 6293af44c5818b812eb1bb5d, edited_on: 2022-05-29 17:37:08.419000+00:00, grading_policy: EuAnck2qOGYAN+FjlLkuji6w1Ak=, User: 77, Course Grade: percent: 0.32, letter_grade: None, passed: False, persisted: False
lms-worker_1     | 2022-06-19 16:36:29,752 INFO 108 [celery.app.trace] [user None] [ip None] trace.py:125 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[c99fad5c-4548-47e2-a326-f84fb9e97a1c] succeeded in 2.51161296851933s: None
lms_1            | [pid: 115|app: 0|req: 28/171] 172.18.0.12 () {60 vars in 2839 bytes} [Sun Jun 19 16:36:23 2022] POST /courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button => generated 16 bytes in 509 msecs (HTTP/1.0 200) 6 headers in 327 bytes (1 switches on core 0)



lms_1            | 2022-06-19 16:36:24,998 INFO 7 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg"}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": "{\"GET\": {}, \"POST\": {\"{\\\"done\\\":true}\": [\"\"]}}", "time": "2022-06-19T16:36:24.998361+00:00", "event_type": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "event_source": "server", "page": null}
lms_1            | 2022-06-19 16:36:25,018 INFO 115 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.done.toggled", "context": {"user_id": 77, "path": "/event", "course_id": "course-v1:MyOrg+MyClass+Run1", "org_id": "MyOrg"}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": "{\"done\": true}", "time": "2022-06-19T16:36:25.018217+00:00", "event_type": "edx.done.toggled", "event_source": "browser", "page": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234"}
lms_1            | [pid: 115|app: 0|req: 29/172] 172.18.0.12 () {60 vars in 2442 bytes} [Sun Jun 19 16:36:24 2022] POST /event => generated 7 bytes in 42 msecs (HTTP/1.0 200) 7 headers in 363 bytes (1 switches on core 0)
lms_1            | 2022-06-19 16:36:25,087 INFO 7 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.grades.problem.submitted", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg", "module": {"display_name": "Completion", "usage_key": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8"}}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": {"user_id": "77", "course_id": "course-v1:MyOrg+MyClass+Run1", "problem_id": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8", "event_transaction_id": "f2df8662-4892-42a5-b5bd-d1ddc77e1bd6", "event_transaction_type": "edx.grades.problem.submitted", "weighted_earned": 1, "weighted_possible": 1}, "time": "2022-06-19T16:36:25.086556+00:00", "event_type": "edx.grades.problem.submitted", "event_source": "server", "page": null}
lms_1            | 2022-06-19 16:36:25,139 INFO 7 [celery_utils.logged_task] [user 77] [ip 1.2.3.4] logged_task.py:25 - Task lms.djangoapps.grades.tasks.recalculate_subsection_grade_v3[c99fad5c-4548-47e2-a326-f84fb9e97a1c] submitted with arguments None, {'user_id': 5, 'anonymous_user_id': None, 'course_id': 'course-v1:MyOrg+MyClass+Run1', 'usage_id': 'block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8', 'only_if_higher': None, 'expected_modified_time': 1655656585, 'score_deleted': None, 'event_transaction_id': 'f2df8662-4892-42a5-b5bd-d1ddc77e1bd6', 'event_transaction_type': 'edx.grades.problem.submitted', 'score_db_table': 'csm', 'force_update_subsections': False}
lms_1            | 2022-06-19 16:36:25,141 INFO 7 [tracking] [user 77] [ip 1.2.3.4] logger.py:41 - {"name": "edx.done.toggled", "context": {"course_id": "course-v1:MyOrg+MyClass+Run1", "course_user_tags": {"view-welcome-message": "9ef6989220644cdd374e1c8b7daadb38"}, "user_id": 77, "path": "/courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button", "org_id": "MyOrg", "module": {"display_name": "Completion", "usage_key": "block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8"}, "asides": {}}, "username": "MyUsername", "session": "9201d5987022c0022ec8012cfdb7a5f3", "ip": "1.2.3.4", "agent": "Mozilla/5.0 (Windows; rv:101.0) Gecko/20100101 Firefox/101.0", "host": "example.com", "referer": "https://example.com/courses/course-v1:MyOrg+MyClass+Run1/courseware/8080c07c742c4a98b719350bd1df6444/4567c45563dd465dbaab468d1a051234/?activate_block_id=block-v1%3AMyOrg%2BMyClass%2BRun1%2Btype%40sequential%2Bblock%404567c45563dd465dbaab468d1a051234", "accept_language": "en-US,en;q=0.5", "event": {"done": true}, "time": "2022-06-19T16:36:25.141579+00:00", "event_type": "edx.done.toggled", "event_source": "server", "page": "x_module"}
lms_1            | [pid: 7|app: 0|req: 33/173] 172.18.0.12 () {60 vars in 2839 bytes} [Sun Jun 19 16:36:24 2022] POST /courses/course-v1:MyOrg+MyClass+Run1/xblock/block-v1:MyOrg+MyClass+Run1+type@done+block@acdc20da12d9474e818e70243b169bb8/handler/toggle_button => generated 15 bytes in 183 msecs (HTTP/1.0 200) 6 headers in 327 bytes (1 switches on core 0)

So there’s some pretty clear elements in there like

\"POST\": {\"{\\\"done\\\":false}\":
...
"event": {"done": false}

followed by

\"POST\": {\"{\\\"done\\\":true}\":
...
"event": {"done": true}

However, it’s not clear to me from the logs how I’d go find the backing store data in mongodb.

When I look around in mongodb…

> show dbs
admin                0.000GB
config               0.000GB
cs_comments_service  0.001GB
local                0.000GB
openedx              1.014GB
> use openedx
switched to db openedx
> show collections
fs.chunks
fs.files
modulestore.active_versions
modulestore.definitions
modulestore.structures

everything seems to be just core course data, not the student data

Any ideas?

Any other xblock maintainers know where to find xblock persistent data in mongodb?