Error during new setup: No module named 'ecommerce.settings.tutor'

David · June 17, 2020, 11:11pm

Hi

I’m trying to setup a new install with ecommerce functionality from the start. I can get the core LMS & CMS running, but the quickstart command is consistently failing. The relevant part of the output is below.

This is on a completely fresh server install, so i’m assuming I’m missing something. I’ve completed the following steps:

Brand new Ubuntu Server 20.04 install, fully updated
Install docker, as per: https://docs.docker.com/engine/install/ubuntu
Install docker compose, as: https://docs.docker.com/compose/install
Added the user to the docker group, so not running as root. I’ve tested this, and docker runs fine without sudo / root.
Installed tutor binary v10.0.2 (previously tried v10.0.0 and v10.0.1 as they were released)
Enabled the discovery and ecommerce plugins
Run tutor local quickstart

The LMS and CMS are running, and if I create a user everything seems fine. I can’t get to anything eccomerce though, and the ecommerce url returns a server error. If I disable the plugins and run quickstart everything works as expected, but re-enabling the plugins leads to the same errors.

Plugin ecommerce: running init for service ecommerce...
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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm ecommerce-job sh -e -c ./manage.py migrate --noinput
./manage.py oscar_populate_countries --initial-only

./manage.py create_or_update_site \
  --site-id=1 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com:8130 \
  --site-name=dev \
  --partner-code=dev \
  --partner-name="Open edX - development" \
  --lms-url-root="http://test-jutapox-my.lightunwrapped.com:8000" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso-dev" \
  --sso-client-secret="b4CMzEnV" \
  --backend-service-client-id="ecommerce-dev" \
  --backend-service-client-secret="p9K0fkl9" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=http://discovery.test-jutapox-my.lightunwrapped.com:8381/api/v1/

# Production site
./manage.py create_or_update_site \
  --site-id=2 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com \
  --site-name=prod \
  --partner-code=openedx \
  --partner-name="Open edX" \
  --lms-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --lms-public-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso" \
  --sso-client-secret="b4CMzEnV" \
  --backend-service-client-id="ecommerce" \
  --backend-service-client-secret="p9K0fkl9" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=https://discovery.test-jutapox-my.lightunwrapped.com/api/v1/
Starting tutor_local_mysql_1 ... done
Traceback (most recent call last):
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 323, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 361, in execute
    self.check()
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 390, in check
    include_deployment_checks=include_deployment_checks,
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/commands/migrate.py", line 64, in _run_checks
    issues = run_checks(tags=[Tags.database])
  File "/openedx/venv/lib/python3.6/site-packages/django/core/checks/registry.py", line 72, in run_checks
    new_errors = check(app_configs=app_configs)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/checks/database.py", line 9, in check_database_backends
    for conn in connections.all():
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 216, in all
    return [self[alias] for alias in self]
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 213, in __iter__
    return iter(self.databases)
  File "/openedx/venv/lib/python3.6/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 147, in databases
    self._databases = settings.DATABASES
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 79, in __getattr__
    self._setup(name)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 66, in _setup
    self._wrapped = Settings(settings_module)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 157, in __init__
    mod = importlib.import_module(self.SETTINGS_MODULE)
  File "/usr/lib/python3.6/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
ModuleNotFoundError: No module named 'ecommerce.settings.tutor'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./manage.py", line 12, in <module>
    execute_from_command_line(sys.argv)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 381, in execute_from_command_line
    utility.execute()
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 375, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 336, in run_from_argv
    connections.close_all()
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 219, in close_all
    for alias in self:
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 213, in __iter__
    return iter(self.databases)
  File "/openedx/venv/lib/python3.6/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 147, in databases
    self._databases = settings.DATABASES
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 79, in __getattr__
    self._setup(name)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 66, in _setup
    self._wrapped = Settings(settings_module)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 157, in __init__
    mod = importlib.import_module(self.SETTINGS_MODULE)
  File "/usr/lib/python3.6/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
ModuleNotFoundError: No module named 'ecommerce.settings.tutor'
Error: Command failed with status 1: 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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm ecommerce-job sh -e -c ./manage.py migrate --noinput
./manage.py oscar_populate_countries --initial-only

./manage.py create_or_update_site \
  --site-id=1 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com:8130 \
  --site-name=dev \
  --partner-code=dev \
  --partner-name="Open edX - development" \
  --lms-url-root="http://test-jutapox-my.lightunwrapped.com:8000" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso-dev" \
  --sso-client-secret="b4CMzEnV" \
  --backend-service-client-id="ecommerce-dev" \
  --backend-service-client-secret="p9K0fkl9" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=http://discovery.test-jutapox-my.lightunwrapped.com:8381/api/v1/

# Production site
./manage.py create_or_update_site \
  --site-id=2 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com \
  --site-name=prod \
  --partner-code=openedx \
  --partner-name="Open edX" \
  --lms-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --lms-public-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso" \
  --sso-client-secret="b4CMzEnV" \
  --backend-service-client-id="ecommerce" \
  --backend-service-client-secret="p9K0fkl9" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=https://discovery.test-jutapox-my.lightunwrapped.com/api/v1/

regis · June 18, 2020, 8:02am

Hi @David! Thanks for the report. this is a bug. I just released a fix which will be released as v10.0.1 in a few minutes.

David · June 18, 2020, 10:32am

Thanks @regis

It’s a relief I wasn’t doing something wrong.

This may be a dumb question, but if I’ve installed tutor using the binary is it possible to update the plugin, or is the tutor 10.0.2 binary updated with the latest patches?

regis · June 18, 2020, 10:48am

This is not a dumb question The v10.0.2 tutor binary ships with ecommerce plugin v10.0.0. You will need to wait until Tutor v10.0.3 is released if you want to keep using the binary. This is likely to happen soon, as edX has just released a security patch for Juniper.

David · June 18, 2020, 3:11pm

Hi @regis

So I switched to installing from source. I’m running tutor v10.0.2 and ecommerce v10.0.1, again on a fresh server install.

On running quickstart I’m getting a similar error message at the same point:

Plugin ecommerce: running init for service ecommerce...
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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm ecommerce-job sh -e -c ./manage.py migrate --noinput
./manage.py oscar_populate_countries --initial-only

./manage.py create_or_update_site \
  --site-id=1 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com:8130 \
  --site-name=dev \
  --partner-code=dev \
  --partner-name="Open edX - development" \
  --lms-url-root="http://test-jutapox-my.lightunwrapped.com:8000" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso-dev" \
  --sso-client-secret="RWrxJk66" \
  --backend-service-client-id="ecommerce-dev" \
  --backend-service-client-secret="HviYN72R" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=http://discovery.test-jutapox-my.lightunwrapped.com:8381/api/v1/

# Production site
./manage.py create_or_update_site \
  --site-id=2 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com \
  --site-name=prod \
  --partner-code=openedx \
  --partner-name="Open edX" \
  --lms-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --lms-public-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso" \
  --sso-client-secret="RWrxJk66" \
  --backend-service-client-id="ecommerce" \
  --backend-service-client-secret="HviYN72R" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=https://discovery.test-jutapox-my.lightunwrapped.com/api/v1/
Starting tutor_local_mysql_1 ... done
Traceback (most recent call last):
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 323, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 361, in execute
    self.check()
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 390, in check
    include_deployment_checks=include_deployment_checks,
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/commands/migrate.py", line 64, in _run_checks
    issues = run_checks(tags=[Tags.database])
  File "/openedx/venv/lib/python3.6/site-packages/django/core/checks/registry.py", line 72, in run_checks
    new_errors = check(app_configs=app_configs)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/checks/database.py", line 9, in check_database_backends
    for conn in connections.all():
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 216, in all
    return [self[alias] for alias in self]
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 213, in __iter__
    return iter(self.databases)
  File "/openedx/venv/lib/python3.6/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 147, in databases
    self._databases = settings.DATABASES
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 79, in __getattr__
    self._setup(name)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 66, in _setup
    self._wrapped = Settings(settings_module)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 157, in __init__
    mod = importlib.import_module(self.SETTINGS_MODULE)
  File "/usr/lib/python3.6/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 941, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
ModuleNotFoundError: No module named 'ecommerce.settings.tutor'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "./manage.py", line 12, in <module>
    execute_from_command_line(sys.argv)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 381, in execute_from_command_line
    utility.execute()
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 375, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/openedx/venv/lib/python3.6/site-packages/django/core/management/base.py", line 336, in run_from_argv
    connections.close_all()
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 219, in close_all
    for alias in self:
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 213, in __iter__
    return iter(self.databases)
  File "/openedx/venv/lib/python3.6/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/openedx/venv/lib/python3.6/site-packages/django/db/utils.py", line 147, in databases
    self._databases = settings.DATABASES
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 79, in __getattr__
    self._setup(name)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 66, in _setup
    self._wrapped = Settings(settings_module)
  File "/openedx/venv/lib/python3.6/site-packages/django/conf/__init__.py", line 157, in __init__
    mod = importlib.import_module(self.SETTINGS_MODULE)
  File "/usr/lib/python3.6/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 941, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
ModuleNotFoundError: No module named 'ecommerce.settings.tutor'
Error: Command failed with status 1: 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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm ecommerce-job sh -e -c ./manage.py migrate --noinput
./manage.py oscar_populate_countries --initial-only

./manage.py create_or_update_site \
  --site-id=1 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com:8130 \
  --site-name=dev \
  --partner-code=dev \
  --partner-name="Open edX - development" \
  --lms-url-root="http://test-jutapox-my.lightunwrapped.com:8000" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso-dev" \
  --sso-client-secret="RWrxJk66" \
  --backend-service-client-id="ecommerce-dev" \
  --backend-service-client-secret="HviYN72R" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=http://discovery.test-jutapox-my.lightunwrapped.com:8381/api/v1/

# Production site
./manage.py create_or_update_site \
  --site-id=2 \
  --site-domain=ecommerce.test-jutapox-my.lightunwrapped.com \
  --site-name=prod \
  --partner-code=openedx \
  --partner-name="Open edX" \
  --lms-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --lms-public-url-root="https://test-jutapox-my.lightunwrapped.com" \
  --client-side-payment-processor=cybersource \
  --payment-processors=cybersource,paypal \
  --sso-client-id="ecommerce-sso" \
  --sso-client-secret="RWrxJk66" \
  --backend-service-client-id="ecommerce" \
  --backend-service-client-secret="HviYN72R" \
  --from-email support@lightunwrapped.com \
  --discovery_api_url=https://discovery.test-jutapox-my.lightunwrapped.com/api/v1/

regis · June 18, 2020, 3:15pm

@David I’m fairly sure you are still running the binary version of tutor and the older ecommerce plugin. What is the output of:

which tutor
tutor plugins list

?

You might have to remove the binary version with sudo rm /usr/local/bin/tutor.

David · June 18, 2020, 3:33pm

Hi @regis

I reinstalled the server from scratch, so can’t still be using the binary.

‘which tutor’ outputs:

/home/ubuntu/.local/bin/tutor

‘tutor --version’ outputs:

tutor, version 10.0.2

‘tutor plugins’ list:

ecommerce==10.0.1
discovery==10.0.0

There are no other plugins installed yet, although I was also looking at XBlock Flow Control

regis · June 18, 2020, 6:30pm

@David,
My bad, I forgot to make another change in the ecommerce plugin. Please upgrade it to v10.0.2 when it is released (in a few minutes).

David · June 19, 2020, 12:00am

hi @regis

Thanks, that’s fixed it as it seems to progress.

Unfortunately (and maybe this should be a separate thread) I’m now getting the following error. This one seems to be about the discovery plugin, but I can’t tell if it’s related. This is still as part of setup, so there’s no data in the system, if that makes a difference?

Plugin discovery: running init for service discovery...
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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm discovery-job sh -e -c make migrate

# Development partners
./manage.py create_or_update_partner  \
  --site-id 1 \
  --site-domain discovery.test-jutapox-my.lightunwrapped.com:8381 \
  --code dev --name "Open edX - development" \
  --lms-url="http://lms:8000" \
  --courses-api-url "http://test-jutapox-my.lightunwrapped.com:8000/api/courses/v1/"

# Production partner
./manage.py create_or_update_partner  \
  --site-id 2 \
  --site-domain discovery.test-jutapox-my.lightunwrapped.com \
  --code openedx --name "Open edX" \
  --lms-url="http://lms:8000" \
  --courses-api-url "http://test-jutapox-my.lightunwrapped.com/api/courses/v1/"

./manage.py refresh_course_metadata --partner_code=openedx
./manage.py update_index --disable-change-limit
Starting tutor_local_elasticsearch_1 ... done
Starting tutor_local_memcached_1     ... done
Starting tutor_local_rabbitmq_1      ... done
Starting tutor_local_rabbitmq_1      ...
Starting tutor_local_mongodb_1       ... done
Starting tutor_local_smtp_1          ... done
Starting tutor_local_forum_1         ... done
Starting tutor_local_lms_1           ... done
python manage.py migrate --noinput
Operations to perform:
  Apply all migrations: admin, auth, catalogs, contenttypes, core, course_metadata, django_comments, guardian, ietf_language_tags, journal, publisher, publisher_comments, sessions, sites, social_django, taggit, waffle
Running migrations:
  No migrations to apply.
  Your models have changes that are not yet reflected in a migration, and so won't be applied.
  Run 'manage.py makemigrations' to make new migrations, and then re-run 'manage.py migrate' to apply them.
python manage.py install_es_indexes
2020-06-18 22:56:47,496 INFO 12 [course_discovery.apps.core.management.commands.install_es_indexes] /openedx/discovery/course_discovery/apps/core/management/commands/install_es_indexes.py:19 - Attempting to establish initial connection to Elasticsearch host [http://elasticsearch:9200]...
2020-06-18 22:56:47,498 INFO 12 [course_discovery.apps.core.management.commands.install_es_indexes] /openedx/discovery/course_discovery/apps/core/management/commands/install_es_indexes.py:21 - ...success!
2020-06-18 22:56:47,498 INFO 12 [course_discovery.apps.core.utils] /openedx/discovery/course_discovery/apps/core/utils.py:18 - Making sure alias [catalog] exists...
2020-06-18 22:56:47,502 INFO 12 [course_discovery.apps.core.utils] /openedx/discovery/course_discovery/apps/core/utils.py:22 - ...alias exists.
2020-06-18 22:56:49,648 INFO 17 [course_discovery.apps.core.management.commands.create_or_update_partner] /openedx/discovery/course_discovery/apps/core/management/commands/create_or_update_partner.py:127 - Partner updated with code dev
2020-06-18 22:56:51,731 INFO 22 [course_discovery.apps.core.management.commands.create_or_update_partner] /openedx/discovery/course_discovery/apps/core/management/commands/create_or_update_partner.py:127 - Partner updated with code openedx
2020-06-18 22:56:53,883 INFO 27 [course_discovery.apps.course_metadata.management.commands.refresh_course_metadata] /openedx/discovery/course_discovery/apps/course_metadata/management/commands/refresh_course_metadata.py:116 - Command is not using threads to write data.
2020-06-18 22:56:53,886 INFO 27 [course_discovery.apps.course_metadata.management.commands.refresh_course_metadata] /openedx/discovery/course_discovery/apps/course_metadata/management/commands/refresh_course_metadata.py:153 - Executing Loader [http://test-jutapox-my.lightunwrapped.com/api/courses/v1/]
2020-06-18 22:56:54,897 ERROR 27 [course_discovery.apps.course_metadata.management.commands.refresh_course_metadata] /openedx/discovery/course_discovery/apps/course_metadata/management/commands/refresh_course_metadata.py:28 - CoursesApiDataLoader failed!
Traceback (most recent call last):
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 426, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 421, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 258, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/lib/python3.5/socket.py", line 575, in readinto
    return self._sock.recv_into(b)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/openedx/venv/lib/python3.5/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 725, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/util/retry.py", line 403, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/packages/six.py", line 735, in reraise
    raise value
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 677, in urlopen
    chunked=chunked,
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 428, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/openedx/venv/lib/python3.5/site-packages/urllib3/connectionpool.py", line 336, in _raise_timeout
    self, url, "Read timed out. (read timeout=%s)" % timeout_value
urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='lms', port=8000): Read timed out. (read timeout=1)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/openedx/discovery/course_discovery/apps/course_metadata/management/commands/refresh_course_metadata.py", line 25, in execute_loader
    loader_class(*loader_args).ingest()
  File "/openedx/discovery/course_discovery/apps/course_metadata/data_loaders/__init__.py", line 31, in __init__
    self.username = self.get_username_from_client(self.api_client)
  File "/openedx/discovery/course_discovery/apps/course_metadata/data_loaders/__init__.py", line 41, in get_username_from_client
    token = client.get_jwt_access_token()
  File "/openedx/venv/lib/python3.5/site-packages/edx_rest_api_client/client.py", line 270, in get_jwt_access_token
    self._ensure_authentication()
  File "/openedx/venv/lib/python3.5/site-packages/edx_rest_api_client/client.py", line 254, in _ensure_authentication
    timeout=self._timeout,
  File "/openedx/venv/lib/python3.5/site-packages/edx_rest_api_client/client.py", line 170, in get_and_cache_oauth_access_token
    timeout=timeout,
  File "/openedx/venv/lib/python3.5/site-packages/edx_rest_api_client/client.py", line 112, in get_oauth_access_token
    timeout=timeout
  File "/openedx/venv/lib/python3.5/site-packages/requests/api.py", line 119, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/openedx/venv/lib/python3.5/site-packages/requests/api.py", line 61, in request
    return session.request(method=method, url=url, **kwargs)
  File "/openedx/venv/lib/python3.5/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/openedx/venv/lib/python3.5/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/openedx/venv/lib/python3.5/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPConnectionPool(host='lms', port=8000): Read timed out. (read timeout=1)
CommandError: One or more of the data loaders above failed.
Error: Command failed with status 1: 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 --project-name tutor_local -f /home/ubuntu/.local/share/tutor/env/local/docker-compose.jobs.yml run --rm discovery-job sh -e -c make migrate

# Development partners
./manage.py create_or_update_partner  \
  --site-id 1 \
  --site-domain discovery.test-jutapox-my.lightunwrapped.com:8381 \
  --code dev --name "Open edX - development" \
  --lms-url="http://lms:8000" \
  --courses-api-url "http://test-jutapox-my.lightunwrapped.com:8000/api/courses/v1/"

# Production partner
./manage.py create_or_update_partner  \
  --site-id 2 \
  --site-domain discovery.test-jutapox-my.lightunwrapped.com \
  --code openedx --name "Open edX" \
  --lms-url="http://lms:8000" \
  --courses-api-url "http://test-jutapox-my.lightunwrapped.com/api/courses/v1/"

./manage.py refresh_course_metadata --partner_code=openedx
./manage.py update_index --disable-change-limit

regis · June 19, 2020, 9:17am

@David,
I do not experience the same error as you, but I understand where this is coming from. Basically, when the server is under heavy load, the LMS takes more than one second to answer the request that is coming from the discovery app. That one second limit is quite low, so I asked about it here: https://github.com/edx/edx-rest-api-client/pull/62#issuecomment-646526313

Basically, you need to try again until it works :-/ try to reduce the server load as much as possible by stopping all other services. For instance, try:

tutor local stop
tutor local init --limit=discovery

Of course, this is not an acceptable solution. I’ll work on a fix and open a pull request upstream.

~~Can you please open a new issue on the tutor-discovery repo? Please add a detailed description and a link to this conversation.~~ I also asked the question to the author of the read timeout: https://github.com/edx/edx-rest-api-client/pull/62#issuecomment-646526313

EDIT: it is no longer necessary to open an issue. There is a temporary fix in tutor-discovery v10.0.1 which will be released in a few minutes.

David · June 19, 2020, 1:03pm

Hi @regis

That seems to have fixed it, everything is up and running. It’s another fresh server install, running tutor v10.0.3, ecommerce v10.0.2 and discovery v10.0.1.

Thanks again
David