API error after watching a video.

[cpauya]

Summary

After watching a video, an API error happens on the browser

Branch or installer method

• Installer: OSX on Bamboo - http://dungeon.learningequality.org/browse/KL-MT16-74/artifact
• Version: 0.16.x
• KA-Lite Branch: 0.16.x
• OS X - Yosemite v10.10.5 on VirtualBox and;
• OS X - El Capitan v10.10.3 on VirtualBox
• Used Safari Browser
• Applies to guest or admin users on KA-Lite

Traceback or relevant snippet from server.log

Here's the traceback at server.log:

...
[INFO] [2016-03-04 13:58:04,297] cherrypy.access.4349095504: 127.0.0.1 - - [04/Mar/2016:13:58:04] "GET /content/y2-uaPiyoxc.mp4 HTTP/1.1" 206 1115061 "http://127.0.0.1:8008/learn/khan/math/early-math/cc-early-math-counting-topic/cc-early-math-counting/counting-with-small-numbers/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_3) AppleWebKit/601.4.4 (KHTML, like Gecko) Version/9.0.3 Safari/601.4.4"
[INFO] [2016-03-04 13:58:06,711] django.request: HTTP Request /api/cherrypy/getpid - Response: 200
[ERROR] [2016-03-04 13:59:02,137] django.request.tastypie: Internal Server Error: /api/videolog/
Traceback (most recent call last):
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 195, in wrapper
    response = callback(request, *args, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 426, in dispatch_list
    return self.dispatch('list', request, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 458, in dispatch
    response = method(request, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 1320, in post_list
    updated_bundle = self.obj_create(bundle, **self.remove_api_resource_names(kwargs))
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 2084, in obj_create
    return self.save(bundle)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/tastypie/resources.py", line 2230, in save
    bundle.obj.save()
  File "/Applications/KA-Lite/support/pyrun-2.7/lib/python2.7/site-packages/ka_lite_static-0.16.0-py2.7.egg/kalite/main/models.py", line 83, in save
    super(VideoLog, self).save(*args, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/securesync/engine/models.py", line 478, in save
    super(DeferredCountSyncedModel, self).save(*args, increment_counters=increment_counters, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/securesync/engine/models.py", line 456, in save
    super(DeferredSignSyncedModel, self).save(*args, sign=sign, **kwargs)
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/securesync/engine/models.py", line 381, in save
    self.set_id()
  File "/Applications/KA-Lite/support/pyrun-2.7/share/kalite/python-packages/securesync/engine/models.py", line 481, in set_id
    self.id = self.id or self.get_uuid()
  File "/Applications/KA-Lite/support/pyrun-2.7/lib/python2.7/site-packages/ka_lite_static-0.16.0-py2.7.egg/kalite/main/models.py", line 86, in get_uuid
    assert self.user is not None and self.user.id is not None, "User ID required for get_uuid"
AssertionError: User ID required for get_uuid
[INFO] [2016-03-04 13:59:02,138] django.request: HTTP Request /api/videolog/ - Response: 500
[INFO] [2016-03-04 13:59:05,890] django.request: HTTP Request /api/cherrypy/getpid - Response: 200
[INFO] [2016-03-04 14:00:05,700] django.request: HTTP Request /api/cherrypy/getpid - Response: 200

How to reproduce

1. Download the OS X installer from Bamboo - http://dungeon.learningequality.org/browse/KL-MT16-74/artifact
2. Install it on an OS X Virtual Machine
3. Start KA Lite
4. Login as admin and download a video.
5. Navigate to that video on the topic tree.
6. Watch that video until it finishes.
7. Notice the error message "Sorry, this request could not be processed. Please try again later."
8. The Javascript Console also has "Error 500 - (Internal Server Error) - http://127.0.0.1:8008/api/videolog/

Screenshots

[rtibbles]

This is not a Javascript error, it is an API error.

Are you logged in as an admin?

[radinamatic]

Not able to replicate this, neither as admin nor learner. Same video, same build, OSX El Capitan.

[radinamatic]

Managed to replicate on OSX Mavericks, logged in as Admin (but without console error 500), and not on Learner user:

[cpauya]

Oops, yes @rtibbles API Error not Javascript error. :smile_cat:

Yes @rtibbles - I'm logged-in as admin. @radinamatic I used Yosemite VM.

Will update the title and description of the issue.

[cpauya]

I've updated the description with the traceback I found at the server.log. @radinamatic I was able to reproduce this on El Capitan VM using Safari v9.0.3.

[radinamatic]

Yep, confirming on OSX Yosemite in Safari and FF (as a non logged-in user).

Error does not seem to appear when logged in as Learner.

[radinamatic]

Happened at the end of several videos over here, so it is something that we should look at eventually.

[radinamatic]

Still getting this at the end of video - 0.16 repo running on OSX, client VM Ubuntu 15.10, Chromium browser, non-logged-in user:

[INFO] [2016-03-15 00:58:57,520] django.request: HTTP Request /content/y2-uaPiyoxc.mp4 - Response: 200
[15/Mar/2016 00:58:57] "GET /static/srt/en/subtitles/y2-uaPiyoxc.vtt HTTP/1.1" 404 1703
[15/Mar/2016 00:58:58] "GET /content/y2-uaPiyoxc.mp4 HTTP/1.1" 200 2526364
[ERROR] [2016-03-15 01:00:15,191] django.request: Internal Server Error: /api/videolog/
Traceback (most recent call last):
  File "/Users/didim/LE/ka-lite/python-packages/django/core/handlers/base.py", line 115, in get_response
    response = callback(request, *callback_args, **callback_kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/django/views/decorators/csrf.py", line 77, in wrapped_view
    return view_func(*args, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 195, in wrapper
    response = callback(request, *args, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 426, in dispatch_list
    return self.dispatch('list', request, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 458, in dispatch
    response = method(request, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 1320, in post_list
    updated_bundle = self.obj_create(bundle, **self.remove_api_resource_names(kwargs))
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 2084, in obj_create
    return self.save(bundle)
  File "/Users/didim/LE/ka-lite/python-packages/tastypie/resources.py", line 2230, in save
    bundle.obj.save()
  File "/Users/didim/LE/ka-lite/kalite/main/models.py", line 83, in save
    super(VideoLog, self).save(*args, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/securesync/engine/models.py", line 478, in save
    super(DeferredCountSyncedModel, self).save(*args, increment_counters=increment_counters, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/securesync/engine/models.py", line 456, in save
    super(DeferredSignSyncedModel, self).save(*args, sign=sign, **kwargs)
  File "/Users/didim/LE/ka-lite/python-packages/securesync/engine/models.py", line 381, in save
    self.set_id()
  File "/Users/didim/LE/ka-lite/python-packages/securesync/engine/models.py", line 481, in set_id
    self.id = self.id or self.get_uuid()
  File "/Users/didim/LE/ka-lite/kalite/main/models.py", line 86, in get_uuid
    assert self.user is not None and self.user.id is not None, "User ID required for get_uuid"
AssertionError: User ID required for get_uuid
[INFO] [2016-03-15 01:00:15,350] django.request: HTTP Request /api/videolog/ - Response: 500
[15/Mar/2016 01:00:15] "POST /api/videolog/ HTTP/1.1" 500 8556

[benjaoming]

Copy-pasting from above:

[INFO] [2016-03-15 01:00:15,350] django.request: HTTP Request /api/videolog/ - Response: 500
[15/Mar/2016 01:00:15] "POST /api/videolog/ HTTP/1.1" 500 8556

In current develop branch, this is working for a logged-in student. I recall @jamalex fixed this.

[17/Dec/2016 01:55:20] "POST /api/videolog/ HTTP/1.1" 201 0
[INFO] [2016-12-17 01:55:20,104] django.request: HTTP Request /api/videolog/4b61117e9dac5da79ea02532873a009e/ - Response: 200
[17/Dec/2016 01:55:20] "GET /api/videolog/4b61117e9dac5da79ea02532873a009e/?_=1481936110573 HTTP/1.1" 200 289
[INFO] [2016-12-17 01:55:50,190] django.request: HTTP Request /api/videolog/4b61117e9dac5da79ea02532873a009e/ - Response: 204
[17/Dec/2016 01:55:50] "PUT /api/videolog/4b61117e9dac5da79ea02532873a009e/ HTTP/1.1" 204 0