500 statuscode on subsection-completion API request

I have got a freshly installed tutor[version 12.1.2] in local. I am trying to make an api for subsection completion /completion/v1/subsection-completion/{username}/{course_key}/(P{subsection_id}[/]*) referencing to http://local.overhang.io/api-docs and it is responding 500 which is saying in log KeyError: '(Pblock-v1' and it is also responding the same in Open edX API

Can you describe more precisely what leads you to this error? A screenshot would be nice. Also, the full stacktrace from the LMS logs would be very useful (tutor local logs --tail=100 lms).

EDIT: I managed to reproduce the issue.

  1. Go to http://local.overhang.io/api-docs/
  2. In the /completion/v1/subsection-completion/{username}/{course_key}/(P{subsection_id}[/]*) endpoint, add as parameters:
course key: course-v1:edX+DemoX+Demo_Course
subsection id: 82d599b014b246c7a9b5dfc750dc08a9
username: regis

Here is the lms stacktrace:

lms_1            | Traceback (most recent call last):                                                                                                                                                              
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 234, in get_namespace_plugin                                                                                   
lms_1            |     return drivers[namespace].plugin                                                                                                                                                            
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/stevedore/extension.py", line 326, in __getitem__         
lms_1            |     return self._extensions_by_name[name]                                                                                                                                                       
lms_1            | KeyError: '(Pblock-v1'                                                                                                                                                                          
lms_1            | 
lms_1            | The above exception was the direct cause of the following exception:
lms_1            | 
lms_1            | Traceback (most recent call last):
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 186, in from_string
lms_1            |     key_class = cls.get_namespace_plugin(namespace)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 239, in get_namespace_plugin
lms_1            |     raise InvalidKeyError(cls, f'{namespace}:*') from error
lms_1            | opaque_keys.InvalidKeyError: <class 'opaque_keys.edx.keys.UsageKey'>: (Pblock-v1:*
lms_1            | 
lms_1            | During handling of the above exception, another exception occurred:
lms_1            | 
lms_1            | Traceback (most recent call last):
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/exception.py", line 34, in inner
lms_1            |     response = get_response(request)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 115, in _get_response
lms_1            |     response = self.process_exception_by_middleware(e, request)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 113, in _get_response
lms_1            |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
lms_1            |   File "/opt/pyenv/versions/3.8.6/lib/python3.8/contextlib.py", line 75, in inner
lms_1            |     return func(*args, **kwds)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
lms_1            |     return view_func(*args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/views/generic/base.py", line 71, in view
lms_1            |     return self.dispatch(request, *args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
lms_1            |     response = self.handle_exception(exc)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 469, in handle_exception
lms_1            |     self.raise_uncaught_exception(exc)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
lms_1            |     raise exc
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
lms_1            |     response = handler(request, *args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/completion/api/v1/views.py", line 245, in get
lms_1            |     UsageKey.from_string(subsection_id),
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 194, in from_string
lms_1            |     return cls.deprecated_fallback._from_deprecated_string(serialized)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/edx/locator.py", line 987, in _from_deprecated_string
lms_1            |     raise InvalidKeyError(BlockUsageLocator, serialized)
lms_1            | opaque_keys.InvalidKeyError: <class 'opaque_keys.edx.locator.BlockUsageLocator'>: (Pblock-v1:edX+DemoX+Demo_Course+type@html+block@82d599b014b246c7a9b5dfc750dc08a9[
lms_1            | 2021-09-30 08:29:06,340 ERROR 121 [django.request] [user 5] [ip 172.21.0.1] log.py:222 - Internal Server Error: /api/completion/v1/subsection-completion/regis/course-v1:edX+DemoX+Demo_Course/(
Pblock-v1:edX+DemoX+Demo_Course+type@html+block@82d599b014b246c7a9b5dfc750dc08a9[/]*)
lms_1            | Traceback (most recent call last):
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 234, in get_namespace_plugin
lms_1            |     return drivers[namespace].plugin
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/stevedore/extension.py", line 326, in __getitem__
lms_1            |     return self._extensions_by_name[name]
lms_1            | KeyError: '(Pblock-v1'
lms_1            | 
lms_1            | The above exception was the direct cause of the following exception:
lms_1            | 
lms_1            | Traceback (most recent call last):
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 186, in from_string
lms_1            |     key_class = cls.get_namespace_plugin(namespace)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 239, in get_namespace_plugin
lms_1            |     raise InvalidKeyError(cls, f'{namespace}:*') from error
lms_1            | opaque_keys.InvalidKeyError: <class 'opaque_keys.edx.keys.UsageKey'>: (Pblock-v1:*
lms_1            | 
lms_1            | During handling of the above exception, another exception occurred:
lms_1            | 
lms_1            | Traceback (most recent call last):
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/exception.py", line 34, in inner
lms_1            |     response = get_response(request)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 115, in _get_response
lms_1            |     response = self.process_exception_by_middleware(e, request)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 113, in _get_response
lms_1            |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
lms_1            |   File "/opt/pyenv/versions/3.8.6/lib/python3.8/contextlib.py", line 75, in inner
lms_1            |     return func(*args, **kwds)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
lms_1            |     return view_func(*args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/django/views/generic/base.py", line 71, in view
lms_1            |     return self.dispatch(request, *args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
lms_1            |     response = self.handle_exception(exc)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 469, in handle_exception
lms_1            |     self.raise_uncaught_exception(exc)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
lms_1            |     raise exc
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
lms_1            |     response = handler(request, *args, **kwargs)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/completion/api/v1/views.py", line 245, in get
lms_1            |     UsageKey.from_string(subsection_id),
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/__init__.py", line 194, in from_string
lms_1            |     return cls.deprecated_fallback._from_deprecated_string(serialized)
lms_1            |   File "/openedx/venv/lib/python3.8/site-packages/opaque_keys/edx/locator.py", line 987, in _from_deprecated_string
lms_1            |     raise InvalidKeyError(BlockUsageLocator, serialized)
lms_1            | opaque_keys.InvalidKeyError: <class 'opaque_keys.edx.locator.BlockUsageLocator'>: (Pblock-v1:edX+DemoX+Demo_Course+type@html+block@82d599b014b246c7a9b5dfc750dc08a9[

This issue can be more easily reproduced in development by simply opening the following url:

http://local.overhang.io:8000/api/completion/v1/subsection-completion/regis/course-v1%3AedX%2BDemoX%2BDemo_Course/(Pblock-v1%3AedX%2BDemoX%2BDemo_Course%2Btype%40html%2Bblock%4082d599b014b246c7a9b5dfc750dc08a9[/]*)

However, it works when trimming the (P and [/]*) at the start and end of the subsection ID argument in this url, thus resulting in:

http://local.overhang.io:8000/api/completion/v1/subsection-completion/regis/course-v1%3AedX%2BDemoX%2BDemo_Course/block-v1%3AedX%2BDemoX%2BDemo_Course%2Btype%40html%2Bblock%4082d599b014b246c7a9b5dfc750dc08a9

Opening this url results in a 200 response for me (success).

Thus, I believe that the error comes from the automatic API generation. In edx-platform/docs/swagger.yml, the url is listed as /completion/v1/subsection-completion/{username}/{course_key}/(P{subsection_id}[/]*), which is obviously wrong. It looks like drf-yasg is incorrectly reading the endpoint url.

Indeed, dr-yasg does not like regex urls that end with a closing parenthesis ‘)’ drf-yasg/generators.py at effc8f2c06e66813a0ab5bad5a4478c0a8e1969c · axnsan12/drf-yasg · GitHub
It’s too bad that this warning was silenced, it would have given us a clue earlier… Turns out, warnings are disabled globally by the generate_swagger command from yasg: drf-yasg/generate_swagger.py at effc8f2c06e66813a0ab5bad5a4478c0a8e1969c · axnsan12/drf-yasg · GitHub (can I just say that I hate it when people do that?)

Digging deeper… drf-yasg is making a call to rest framework’s rest_framework.schemas.generators.EndpointEnumerator.get_path_from_regex, which itself is calling from django.contrib.admindocs.views.simplify_regex. If we open a shell:

>> from django.contrib.admindocs.views import simplify_regex
>> simplify_regex(r'^api/completion/^v1/^subsection-completion/(?P<username>[^/]*)/(?P<course_key>[^/+]+(/|\\+)[^/+]+(/|\\+)[^/?]+)/(?P<subsection_id>[^/]*)')
'/api/completion/v1/subsection-completion/<username>/<course_key>/(P<subsection_id>[/]*)'

Thus, the bug seems to come from django itself… The code at fault is in replace_named_groups because:

>> from django.contrib.admindocs.utils import replace_named_groups
>> replace_named_groups(r'^api/completion/^v1/^subsection-completion/(?P<username>[^/]*)/(?P<course_key>[^/+]+(/|\\+)[^/+]+(/|\\+)[^/?]+)/(?P<subsection_id>[^/]*)'))
'^api/completion/^v1/^subsection-completion/<username>/<course_key>/(?P<subsection_id>[^/]*)'

Aaaaaand, it turns out that this error does not occur anymore in Django 3.2.7. Indeed, it was fixed here: Fixed #30731 -- Fixed handling trailing groups in simplify_regex(). by n2ygk · Pull Request #11728 · django/django · GitHub

Here are the corresponding upstream issues:

https://code.djangoproject.com/ticket/30731

The fix was included in Django 3.0. Thus, the best option to fix this is to wait for the Django 3.2 upgrade, coming up in Maple.

Pfiuu, now this was a deep dive…

Thanks for the info.
Now I am getting 401 statuscode. :sweat_smile: I passed the Bearer token which I copied from /admin/oauth2_provider/accesstoken.
{"detail":"Authentication credentials were not provided."}
Here is my CURL request :

curl --header "Authorization: Bearer 2DS0puwPgt3kGWFXXS3tuSE2Ss0QFr" 'http://local.overhang.io/api/completion/v1/subsection-completion/hein/course-v1%3AedX%2BDemoX%2BDemo_Course/block-v1%3AedX%2BDemoX%2BDemo_Course%2Btype%40sequential%2Bblock%40edx_introduction'

Could you provide your sample CURL?

Unfortunately I don’t have time to do that research right now…