Ecommerce Plugin 500 Error On Fresh Setup

sbrewer · November 5, 2019, 8:53pm

Hi All, running into an issue trying to purchase courses via Paypal on a new Tutor-OpenEDX system. Tried to provide as much details about the system setup and recreation steps as possible. In general, nothing special about the setup at all. Just trying to get paid courses with Ecommerce working via Paypal.

I don’t think this is the issue, but it is worth mentioning it wasn’t clear how I should setup Paypal for integration. So I just used the default app it creates for you when you make a business account, left it in sandbox, and got the rest client id and secret for the system.

The OpenEdx platform was setup from the source about a month ago. If the exact version is needed I can log back in and get the version from git that was installed.

Platform was setup with ‘tutor local quickstart’. I checked out the changes and confirm the LMS and CMS are working as expected.

I installed the ecommerce plugin follow the instructions from this site: https://pypi.org/project/tutor-ecommerce/

Logged into the Ecommerce dashboard and create a new professional course for a published course on the LMS.

Confirmed on LMS site that when I click on enroll in course it displays the price of $10 and shows the buttons to checkout.

I then updated the configuration to set the Paypal properties (ECOMMERCE_PAYMENT_PROCESSORS) as follows:

paypal:
  cancel_url: /checkout/cancel-checkout/
  client_id: IDFROMPAYPAL
  client_secret: SECRETFROMPAYPAL
  error_url: /checkout/error/
  mode: sandbox
  receipt_url: /checkout/receipt/

This file was set with tutor save config. I also updated ECOMMERCE_ENABLED_PAYMENT_PROCESSORS=['paypal'] and ECOMMERCE_ENABLED_CLIENT_SIDE_PAYMENT_PROCESSORS=[]

After making all these changes I ran ‘tutor local quickstart’ to reboot the system.

Navigating back to the LMS to enroll in the paid professional course, I click ‘checkout with paypal’. After a brief pause (2 seconds) an error is displayed on the same page and it doesn’t proceed to any kind of checkout.

Looking at logs, the LMS shows it got a 500 back. Here is a screenshot from logs from where the 500 was generated.

regis · November 7, 2019, 8:05am

Hi @sbrewer! The interesting piece of information is missing from your screenshot I’d like to see what appears after the Traceback (the last line of captured text). Please post here the complete output of the following command: tutor local logs --tail=100 ecommerce. This command should be run right after triggering the 500 error. Do not post a screenshot! Instead, please copy-paste the entire error. This makes it easier for other users to find the error.

sbrewer · November 7, 2019, 3:07pm

docker-compose -f /root/.local/share/tutor/env/local/docker-compose.yml --project-name tutor_local logs --tail 100 ecommerce
Attaching to tutor_local_ecommerce_1
ecommerce_1         | [2019-11-05 02:16:45 +0000] [6] [INFO] Starting gunicorn 19.7.1
ecommerce_1         | [2019-11-05 02:16:45 +0000] [6] [INFO] Listening at: http://0.0.0.0:8000 (6)
ecommerce_1         | [2019-11-05 02:16:45 +0000] [6] [INFO] Using worker: sync
ecommerce_1         | [2019-11-05 02:16:45 +0000] [10] [INFO] Booting worker with pid: 10
ecommerce_1         | [2019-11-05 02:16:45 +0000] [11] [INFO] Booting worker with pid: 11
ecommerce_1         | 2019-11-05 02:24:20,547 WARNING 11 [edx_rest_framework_extensions.auth.jwt.middleware] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/auth/jwt/middleware.py:62 - The view PaymentProcessorListView allows Jwt Authentication but needs to include the NotJwtRestrictedApplication permission class (adding it for you)
ecommerce_1         | 2019-11-05 02:24:20,553 DEBUG 11 [edx_rest_framework_extensions.permissions] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/permissions.py:57 - Permission JwtRestrictedApplication: returns False.
ecommerce_1         | 2019-11-05 02:24:36,195 WARNING 10 [edx_rest_framework_extensions.auth.jwt.middleware] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/auth/jwt/middleware.py:62 - The view BasketCreateView allows Jwt Authentication but needs to include the NotJwtRestrictedApplication permission class (adding it for you)
ecommerce_1         | 2019-11-05 02:24:36,200 DEBUG 10 [edx_rest_framework_extensions.permissions] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/permissions.py:57 - Permission JwtRestrictedApplication: returns False.
ecommerce_1         | 2019-11-05 02:24:36,245 DEBUG 10 [ecommerce.extensions.analytics.utils] /openedx/ecommerce/ecommerce/extensions/analytics/utils.py:144 - Event [Product Added] was NOT fired because no Segment key is set for site configuration [2]
ecommerce_1         | 2019-11-05 02:24:36,245 INFO 10 [ecommerce.extensions.api.v2.views.baskets] /openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py:192 - Added product with SKU [863DBEB] to basket [1]
ecommerce_1         | 2019-11-05 02:24:36,267 INFO 10 [ecommerce.extensions.analytics.utils] /openedx/ecommerce/ecommerce/extensions/analytics/utils.py:88 - basket_frozen: amount="10.00", basket_id="1", currency="USD", user_id="3"
ecommerce_1         | 2019-11-05 02:24:37,902 ERROR 10 [ecommerce.extensions.api.v2.views.baskets] /openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py:223 - Failed to initiate checkout for Basket [1]. The basket has been deleted.
ecommerce_1         | Traceback (most recent call last):
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py", line 220, in create
ecommerce_1         |     response_data = self._checkout(basket, payment_processor(request.site), request)
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py", line 268, in _checkout
ecommerce_1         |     parameters = payment_processor.get_transaction_parameters(basket, request=self.request)
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/payment/processors/paypal.py", line 129, in get_transaction_parameters
ecommerce_1         |     'cancel_url': self.cancel_url,
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/payment/processors/paypal.py", line 63, in cancel_url
ecommerce_1         |     return get_ecommerce_url(self.configuration['cancel_checkout_path'])
ecommerce_1         | KeyError: u'cancel_checkout_path'
ecommerce_1         | 2019-11-05 17:53:30,624 WARNING 11 [django.request] /openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py:152 - Not Found: /
ecommerce_1         | 2019-11-05 17:53:30,624 WARNING 11 [django.request] /openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py:152 - Not Found: /
ecommerce_1         | 2019-11-05 17:53:30,624 WARNING 11 [django.request] /openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py:152 - Not Found: /
ecommerce_1         | 2019-11-07 15:04:46,383 DEBUG 11 [edx_rest_framework_extensions.permissions] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/permissions.py:57 - Permission JwtRestrictedApplication: returns False.
ecommerce_1         | 2019-11-07 15:05:29,448 WARNING 11 [edx_rest_framework_extensions.auth.jwt.middleware] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/auth/jwt/middleware.py:62 - The view BasketCreateView allows Jwt Authentication but needs to include the NotJwtRestrictedApplication permission class (adding it for you)
ecommerce_1         | 2019-11-07 15:05:29,452 DEBUG 11 [edx_rest_framework_extensions.permissions] /openedx/venv/local/lib/python2.7/site-packages/edx_rest_framework_extensions/permissions.py:57 - Permission JwtRestrictedApplication: returns False.
ecommerce_1         | 2019-11-07 15:05:29,491 DEBUG 11 [ecommerce.extensions.analytics.utils] /openedx/ecommerce/ecommerce/extensions/analytics/utils.py:144 - Event [Product Added] was NOT fired because no Segment key is set for site configuration [2]
ecommerce_1         | 2019-11-07 15:05:29,491 INFO 11 [ecommerce.extensions.api.v2.views.baskets] /openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py:192 - Added product with SKU [863DBEB] to basket [2]
ecommerce_1         | 2019-11-07 15:05:29,514 INFO 11 [ecommerce.extensions.analytics.utils] /openedx/ecommerce/ecommerce/extensions/analytics/utils.py:88 - basket_frozen: amount="10.00", basket_id="2", currency="USD", user_id="3"
ecommerce_1         | 2019-11-07 15:05:29,536 ERROR 11 [ecommerce.extensions.api.v2.views.baskets] /openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py:223 - Failed to initiate checkout for Basket [2]. The basket has been deleted.
ecommerce_1         | Traceback (most recent call last):
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py", line 220, in create
ecommerce_1         |     response_data = self._checkout(basket, payment_processor(request.site), request)
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/api/v2/views/baskets.py", line 268, in _checkout
ecommerce_1         |     parameters = payment_processor.get_transaction_parameters(basket, request=self.request)
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/payment/processors/paypal.py", line 129, in get_transaction_parameters
ecommerce_1         |     'cancel_url': self.cancel_url,
ecommerce_1         |   File "/openedx/ecommerce/ecommerce/extensions/payment/processors/paypal.py", line 63, in cancel_url
ecommerce_1         |     return get_ecommerce_url(self.configuration['cancel_checkout_path'])
ecommerce_1         | KeyError: u'cancel_checkout_path'

regis · November 8, 2019, 9:18am

@sbrewer Thanks! This is the interesting bit:

File "/openedx/ecommerce/ecommerce/extensions/payment/processors/paypal.py", line 63, in cancel_url
ecommerce_1         |     return get_ecommerce_url(self.configuration['cancel_checkout_path'])
ecommerce_1         | KeyError: u'cancel_checkout_path'

I’m no expert of the paypal payment processor, but what I understand from reading the ecommerce source code is that the cancel_url configuration entry should be renamed to cancel_checkout_path in your configuration.

For the record, I originally picked that cancel_url from the configuration repo. For the life of me I have no idea why edX whould document the cancel_url configuration setting. I’ll change the plugin docs.

sbrewer · November 9, 2019, 2:43am

This simple change fixed it. Confirmed it works E2E now.

Thank You!

regis · November 12, 2019, 10:50am

For the record, I created upstream PRs:

bryancr89 · April 7, 2020, 10:07pm

I did the same setup but once I click enroll, I get a 500 error and this the console output, I followed the plugin steps and ran tutor local quickstart

lms_1               | 2020-04-07 21:33:14,922 INFO 12 [tracking] logger.py:50 - {"username": "bryancr89", "event_type": "/verify_student/start-flow/course-v1:edX+DemoX+Demo_Course/", "ip": "172.18.0.1", "agent": "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.163 Safari/537.36", "host": "localhost", "referer": "http://localhost/courses/course-v1:edX+DemoX+Demo_Course/about", "accept_language": "en,es;q=0.9", "event": "{\"POST\": {}, \"GET\": {\"purchase_workflow\": [\"single\"]}}", "event_source": "server", "context": {"user_id": 13, "org_id": "", "course_id": "", "path": "/verify_student/start-flow/course-v1:edX+DemoX+Demo_Course/"}, "time": "2020-04-07T21:33:14.922484+00:00", "page": null}
lms_1               | 2020-04-07 21:33:14,964 INFO 12 [lms.djangoapps.verify_student.views] views.py:294 - Entering payment flow for user '13', course 'course-v1:edX+DemoX+Demo_Course', with current step 'None'
lms_1               | 2020-04-07 21:33:15,514 ERROR 12 [root] signals.py:21 - Uncaught exception from None
lms_1               | Traceback (most recent call last):
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/exception.py", line 41, in inner
lms_1               |     response = get_response(request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 249, in _legacy_get_response
lms_1               |     response = self._get_response(request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 187, in _get_response
lms_1               |     response = self.process_exception_by_middleware(e, request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 185, in _get_response
lms_1               |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 185, in inner
lms_1               |     return func(*args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/views/generic/base.py", line 68, in view
lms_1               |     return self.dispatch(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/views/generic/base.py", line 88, in dispatch
lms_1               |     return handler(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 67, in _wrapper
lms_1               |     return bound_func(*args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/contrib/auth/decorators.py", line 23, in _wrapped_view
lms_1               |     return view_func(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 63, in bound_func
lms_1               |     return func.__get__(self, type(self))(*args2, **kwargs2)
lms_1               |   File "/openedx/edx-platform/lms/djangoapps/verify_student/views.py", line 407, in get
lms_1               |     processors = ecommerce_api_client(request.user).payment.processors.get()
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/slumber/__init__.py", line 155, in get
lms_1               |     resp = self._request("GET", params=kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/slumber/__init__.py", line 97, in _request
lms_1               |     resp = self._store["session"].request(method, url, data=data, params=params, files=files, headers=headers)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/sessions.py", line 533, in request
lms_1               |     resp = self.send(prep, **send_kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/sessions.py", line 646, in send
lms_1               |     r = adapter.send(request, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/adapters.py", line 516, in send
lms_1               |     raise ConnectionError(e, request=request)
lms_1               | ConnectionError: HTTPConnectionPool(host='ecommerce.localhost', port=80): Max retries exceeded with url: /api/v2/payment/processors/ (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f74c69a7a50>: Failed to establish a new connection: [Errno -2] Name or service not known',))
lms_1               | 2020-04-07 21:33:15,515 ERROR 12 [django.request] exception.py:135 - Internal Server Error: /verify_student/start-flow/course-v1:edX+DemoX+Demo_Course/
lms_1               | Traceback (most recent call last):
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/exception.py", line 41, in inner
lms_1               |     response = get_response(request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 249, in _legacy_get_response
lms_1               |     response = self._get_response(request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 187, in _get_response
lms_1               |     response = self.process_exception_by_middleware(e, request)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 185, in _get_response
lms_1               |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 185, in inner
lms_1               |     return func(*args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/views/generic/base.py", line 68, in view
lms_1               |     return self.dispatch(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/views/generic/base.py", line 88, in dispatch
lms_1               |     return handler(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 67, in _wrapper
lms_1               |     return bound_func(*args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/contrib/auth/decorators.py", line 23, in _wrapped_view
lms_1               |     return view_func(request, *args, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/django/utils/decorators.py", line 63, in bound_func
lms_1               |     return func.__get__(self, type(self))(*args2, **kwargs2)
lms_1               |   File "/openedx/edx-platform/lms/djangoapps/verify_student/views.py", line 407, in get
lms_1               |     processors = ecommerce_api_client(request.user).payment.processors.get()
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/slumber/__init__.py", line 155, in get
lms_1               |     resp = self._request("GET", params=kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/slumber/__init__.py", line 97, in _request
lms_1               |     resp = self._store["session"].request(method, url, data=data, params=params, files=files, headers=headers)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/sessions.py", line 533, in request
lms_1               |     resp = self.send(prep, **send_kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/sessions.py", line 646, in send
lms_1               |     r = adapter.send(request, **kwargs)
lms_1               |   File "/openedx/venv/local/lib/python2.7/site-packages/requests/adapters.py", line 516, in send
lms_1               |     raise ConnectionError(e, request=request)
lms_1               | ConnectionError: HTTPConnectionPool(host='ecommerce.localhost', port=80): Max retries exceeded with url: /api/v2/payment/processors/ (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f74c69a7a50>: Failed to establish a new connection: [Errno -2] Name or service not known',))

Any ideas of what’s wrong?