Resolution for 'ValueError: Unable to configure handler ‘local’'

Tutor
1

Hi all,

I’m currently in the process of updating my instance and fork of edx from koa to the latest maple release, and after building i’m coming across a
ValueError: Unable to configure handler ‘local’
and constant reboots of the worker containers due to this error

I’m noticing that this error is mentioned pretty explicitly in the tutor troubleshooting docs, but seems to refer to a fix in the “development_” section, which i’m having a little trouble interpreting.

https://docs.tutor.overhang.io/troubleshooting.html?highlight=development_#valueerror-unable-to-configure-handler-local

I’m not 100% sure I’m not just being thick headed or if this is just a broken reference in the docs, but could someone direct me to the section about resolving this error?

The only other topic i see mentioning what i’m experiencing is this one which suggests uninstalling and deleting the config directory entirely, which I’m fairly sure will solve my problem…

2

For sure there is an error in the docs, but we’ll consider this later. For now, let’s figure out what is going on, then we’ll amend the docs with the right instructions.

Which version of Tutor are you running? What command are you running? What is the full stacktrace? Are you overriding the edx-platform settings? If yes, are you creating custom settings on top of the tutor.devevelopment settings?

3

starting from a cloned VM of the previous working copy with:

  • ubuntu 18.04
  • tutor 11.2.6 (binary version)
  • Openedx using a custom fork of open-release/koa.3

upgraded to

  • tutor --version: 13.1.4 (pip version) latest at the time
  • still working on a fork for maple, so not integrating this until the system is up and running

the process (may have been out of order due to my interpretation of the docs which may have resulted in the issue, but not sure):

  • stopped running containers,
  • removed now outdated custom theme to avoid issues
  • updated tutor using pip
  • ran tutor config save
  • ran tutor local upgrade --from=koa
  • ran tutor images build all
    • successful build but started throwing the error
  • backtracked and attempted tutor local quickstart
    • successful build again, but same ‘local’ error

also worth noting it’s currently running in production mode albeit an offline local copy to replicate the actual live production system (not sure if that may play into the error or not)

there are custom modifications to cms & lms env.json and auth.json to enable some features. and the only settings i can recall making/find to the production.py and development.py were to map oauth and s3 bucket for ORA. if these are the settings you’re referring to. if not, or i’m missing anything let me know and i’ll dig a little more

here’s the stack trace from the cms / cms-worker containers: (i tried grabbing a full log but the post body limit was exceeded, if you need a specific container’s logs let me know and i’ll grab it

cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/__main__.py", line 16, in main
cms-worker_1                 |     _main()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 322, in main
cms-worker_1                 |     cmd.execute_from_commandline(argv)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 499, in execute_from_commandline
cms-worker_1                 |     super(CeleryCommand, self).execute_from_commandline(argv)))
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/base.py", line 305, in execute_from_commandline
cms-worker_1                 |     return self.handle_argv(self.prog_name, argv[1:])
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 491, in handle_argv
cms-worker_1                 |     return self.execute(command, argv)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 415, in execute
cms-worker_1                 |     return cls(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/worker.py", line 223, in run_from_argv
cms-worker_1                 |     return self(*args, **options)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/base.py", line 253, in __call__
cms-worker_1                 |     ret = self.run(*args, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/worker.py", line 253, in run
cms-worker_1                 |     worker = self.app.Worker(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/worker/worker.py", line 99, in __init__
cms-worker_1                 |     self.app.loader.init_worker()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/loaders/base.py", line 114, in init_worker
cms-worker_1                 |     self.import_default_modules()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/loaders/base.py", line 108, in import_default_modules
cms-worker_1                 |     raise response
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/utils/dispatch/signal.py", line 288, in send
cms-worker_1                 |     response = receiver(signal=self, sender=sender, **named)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 84, in on_import_modules
cms-worker_1                 |     self.worker_fixup.validate_models()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 122, in validate_models
cms-worker_1                 |     self.django_setup()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 118, in django_setup
cms-worker_1                 |     django.setup()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/django/__init__.py", line 19, in setup
cms-worker_1                 |     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/django/utils/log.py", line 75, in configure_logging
cms-worker_1                 |     logging_config_func(logging_settings)
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 808, in dictConfig
cms-worker_1                 |     dictConfigClass(config).configure()
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 570, in configure
cms-worker_1                 |     raise ValueError('Unable to configure handler '
cms-worker_1                 | ValueError: Unable to configure handler 'local'
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 563, in configure
cms-worker_1                 |     handler = self.configure_handler(handlers[name])
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 744, in configure_handler
cms-worker_1                 |     result = factory(**kwargs)
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/handlers.py", line 435, in __init__
cms-worker_1                 |     logging.FileHandler.__init__(self, filename, mode, encoding, delay)
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1147, in __init__
cms-worker_1                 |     StreamHandler.__init__(self, self._open())
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1176, in _open
cms-worker_1                 |     return open(self.baseFilename, self.mode, encoding=self.encoding)
cms-worker_1                 | PermissionError: [Errno 13] Permission denied: '/openedx/data/logs/all.log'
cms-worker_1                 | 
cms-worker_1                 | The above exception was the direct cause of the following exception:
cms-worker_1                 | 
cms-worker_1                 | Traceback (most recent call last):
cms-worker_1                 |   File "/openedx/venv/bin/celery", line 8, in <module>
cms-worker_1                 |     sys.exit(main())
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/__main__.py", line 16, in main
cms-worker_1                 |     _main()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 322, in main
cms-worker_1                 |     cmd.execute_from_commandline(argv)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 499, in execute_from_commandline
cms-worker_1                 |     super(CeleryCommand, self).execute_from_commandline(argv)))
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/base.py", line 305, in execute_from_commandline
cms-worker_1                 |     return self.handle_argv(self.prog_name, argv[1:])
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 491, in handle_argv
cms-worker_1                 |     return self.execute(command, argv)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/celery.py", line 415, in execute
cms-worker_1                 |     return cls(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/worker.py", line 223, in run_from_argv
cms-worker_1                 |     return self(*args, **options)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/base.py", line 253, in __call__
cms-worker_1                 |     ret = self.run(*args, **kwargs)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/bin/worker.py", line 253, in run
cms-worker_1                 |     worker = self.app.Worker(
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/worker/worker.py", line 99, in __init__
cms-worker_1                 |     self.app.loader.init_worker()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/loaders/base.py", line 114, in init_worker
cms-worker_1                 |     self.import_default_modules()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/loaders/base.py", line 108, in import_default_modules
cms-worker_1                 |     raise response
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/utils/dispatch/signal.py", line 288, in send
cms-worker_1                 |     response = receiver(signal=self, sender=sender, **named)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 84, in on_import_modules
cms-worker_1                 |     self.worker_fixup.validate_models()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 122, in validate_models
cms-worker_1                 |     self.django_setup()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/celery/fixups/django.py", line 118, in django_setup
cms-worker_1                 |     django.setup()
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/django/__init__.py", line 19, in setup
cms-worker_1                 |     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
cms-worker_1                 |   File "/openedx/venv/lib/python3.8/site-packages/django/utils/log.py", line 75, in configure_logging
cms-worker_1                 |     logging_config_func(logging_settings)
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 808, in dictConfig
cms-worker_1                 |     dictConfigClass(config).configure()
cms_1                        | Python main interpreter initialized at 0x557b12d08790
cms_1                        | python threads support enabled
cms_1                        | your server socket listen backlog is limited to 100 connections
cms_1                        | your mercy for graceful operations on workers is 60 seconds
cms_1                        | mapped 154032 bytes (150 KB) for 2 cores
cms_1                        | *** Operational MODE: preforking ***
cms_1                        | Traceback (most recent call last):
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 563, in configure
cms_1                        |     handler = self.configure_handler(handlers[name])
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 744, in configure_handler
cms_1                        |     result = factory(**kwargs)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/handlers.py", line 435, in __init__
cms_1                        |     logging.FileHandler.__init__(self, filename, mode, encoding, delay)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1147, in __init__
cms_1                        |     StreamHandler.__init__(self, self._open())
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1176, in _open
cms_1                        |     return open(self.baseFilename, self.mode, encoding=self.encoding)
cms_1                        | PermissionError: [Errno 13] Permission denied: '/openedx/data/logs/all.log'
cms_1                        | 
cms_1                        | The above exception was the direct cause of the following exception:
cms_1                        | 
cms_1                        | Traceback (most recent call last):
cms_1                        |   File "cms/wsgi.py", line 22, in <module>
cms_1                        |     startup.run()
cms_1                        |   File "/openedx/edx-platform/./cms/startup.py", line 20, in run
cms_1                        |     django.setup()
cms_1                        |   File "/openedx/venv/lib/python3.8/site-packages/django/__init__.py", line 19, in setup
cms_1                        |     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
cms_1                        |   File "/openedx/venv/lib/python3.8/site-packages/django/utils/log.py", line 75, in configure_logging
cms_1                        |     logging_config_func(logging_settings)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 808, in dictConfig
cms_1                        |     dictConfigClass(config).configure()
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 570, in configure
cms_1                        |     raise ValueError('Unable to configure handler '
cms_1                        | ValueError: Unable to configure handler 'local'
cms_1                        | unable to load app 0 (mountpoint='') (callable not found or import error)
cms_1                        | *** no app loaded. going in full dynamic mode ***
cms_1                        | spawned uWSGI worker 1 (pid: 7, cores: 1)
cms_1                        | spawned uWSGI worker 2 (pid: 10, cores: 1)
cms_1                        | [uwsgi-static] added mapping for /static => /openedx/staticfiles/
cms_1                        | [uwsgi-static] added mapping for /media => /openedx/media/
cms_1                        | *** Starting uWSGI 2.0.20 (64bit) on [Mon Feb 21 15:37:48 2022] ***
cms_1                        | compiled with version: 9.3.0 on 15 February 2022 14:47:31
cms_1                        | os: Linux-4.15.0-167-generic #175-Ubuntu SMP Wed Jan 5 01:56:07 UTC 2022
cms_1                        | nodename: 40af70fe3df2
cms_1                        | machine: x86_64
cms_1                        | clock source: unix
cms_1                        | detected number of CPU cores: 2
cms_1                        | current working directory: /openedx/edx-platform
cms_1                        | detected binary path: /openedx/venv/bin/uwsgi
cms_1                        | !!! no internal routing support, rebuild with pcre support !!!
cms_1                        | *** WARNING: you are running uWSGI without its master process manager ***
cms_1                        | your memory page size is 4096 bytes
cms_1                        | detected max file descriptor number: 1048576
cms_1                        | building mime-types dictionary from file /etc/mime.types...567 entry found
cms_1                        | lock engine: pthread robust mutexes
cms_1                        | thunder lock: enabled
cms_1                        | uWSGI http bound on 0.0.0.0:8000 fd 4
cms_1                        | spawned uWSGI http 1 (pid: 9)
cms_1                        | uwsgi socket 0 bound to TCP address 127.0.0.1:38569 (port auto-assigned) fd 3
cms_1                        | Python version: 3.8.12 (default, Feb  8 2022, 15:53:52)  [GCC 9.3.0]
cms_1                        | Python main interpreter initialized at 0x5582e39eb790
cms_1                        | python threads support enabled
cms_1                        | your server socket listen backlog is limited to 100 connections
cms_1                        | your mercy for graceful operations on workers is 60 seconds
cms_1                        | mapped 154032 bytes (150 KB) for 2 cores
cms_1                        | *** Operational MODE: preforking ***
cms_1                        | Traceback (most recent call last):
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 563, in configure
cms_1                        |     handler = self.configure_handler(handlers[name])
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 744, in configure_handler
cms_1                        |     result = factory(**kwargs)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/handlers.py", line 435, in __init__
cms_1                        |     logging.FileHandler.__init__(self, filename, mode, encoding, delay)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1147, in __init__
cms_1                        |     StreamHandler.__init__(self, self._open())
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/__init__.py", line 1176, in _open
cms_1                        |     return open(self.baseFilename, self.mode, encoding=self.encoding)
cms_1                        | PermissionError: [Errno 13] Permission denied: '/openedx/data/logs/all.log'
cms_1                        | 
cms_1                        | The above exception was the direct cause of the following exception:
cms_1                        | 
cms_1                        | Traceback (most recent call last):
cms_1                        |   File "cms/wsgi.py", line 22, in <module>
cms_1                        |     startup.run()
cms_1                        |   File "/openedx/edx-platform/./cms/startup.py", line 20, in run
cms_1                        |     django.setup()
cms_1                        |   File "/openedx/venv/lib/python3.8/site-packages/django/__init__.py", line 19, in setup
cms-worker_1                 |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 570, in configure
cms-worker_1                 |     raise ValueError('Unable to configure handler '
cms-worker_1                 | ValueError: Unable to configure handler 'local'
cms_1                        |     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
cms_1                        |   File "/openedx/venv/lib/python3.8/site-packages/django/utils/log.py", line 75, in configure_logging
cms_1                        |     logging_config_func(logging_settings)
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 808, in dictConfig
cms_1                        |     dictConfigClass(config).configure()
cms_1                        |   File "/opt/pyenv/versions/3.8.12/lib/python3.8/logging/config.py", line 570, in configure
cms_1                        |     raise ValueError('Unable to configure handler '
cms_1                        | ValueError: Unable to configure handler 'local'
cms_1                        | unable to load app 0 (mountpoint='') (callable not found or import error)
cms_1                        | *** no app loaded. going in full dynamic mode ***
cms_1                        | spawned uWSGI worker 1 (pid: 8, cores: 1)
cms_1                        | spawned uWSGI worker 2 (pid: 11, cores: 1)
4

as an update:
I attempted to rebuild again using quickstart after a brief hiatus and was getting the same error displayed above. seeing the permission issue on the log files:

...
PermissionError: [Errno 13] Permission denied: '/openedx/data/logs/all.log'
...

i did an experiment, (that i’m sure isn’t the intended fix for this) to set the permissions manually on the log files to full access

DISCLAIMER: I’m sure that this isn’t recommended

sudo chmod 777 $(tutor config printroot)/data/lms/logs/all.log
sudo chmod 777 $(tutor config printroot)/data/lms/logs/tracking.log
sudo chmod 777 $(tutor config printroot)/data/cms/logs/all.log
sudo chmod 777 $(tutor config printroot)/data/cms/logs/tracking.log

this didn’t appear to do anything at first, then after running quickstart one more time to ensure the changes were included, built successfully, and the site was able to load

so i can only assume it’s a permission issue of some kind, or i managed to short-circuit the logging in an unexpected way… not sure if this helps in tracking the issue or not, but i’m pretty sure it’s not a viable solution in the long term…

5

For what it’s worth, the files in $(tutor config printroot)/data/lms/logs/ and $(tutor config printroot)/data/lms/logs/ should have their permissions set by the “lms-permissions” and the “cms-permissions” container. If they haven’t, it’s possible to force the ownership with:

cd $(tutor config printroot)/data
sudo chown -r 1000:1000 lms/ cms/
1 Like
6

It’s possible these files had different permissions from before this update process started. My data directory was initially created back in ironwood, so if the process had changed, potentially that may have been the cause.

just to verify the default permissions are sufficient with the change in ownership, the default permissions should be
chmod 755 -R lms/ cms/ correct?
(if not could you provide the correct permissions?)

7

Yes, this should be correct.

8

So it looks like that did the trick, at least in my case.

Just to summarize if someone else comes across this, I can’t speak for newer/fresh builds getting this issue, but in the event someone is upgrading the edx-platform and tutor from an older instances and receives the following error in the logs when accessing the site: (i.e. successful build, server error when accessing frontend)

ValueError: unable to configure handler 'local'

along with preceding permission errors such as the following

...
PermissionError: [Errno 13] Permission denied: '/openedx/data/logs/all.log'
...

updating the ownership appears to have resolved the issue

cd $(tutor config printroot)/data
sudo chown -R 1000:1000 /lms /cms

Thanks for the help @regis

1 Like
9

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.