RuntimeError: reentrant call logging errors during shutdown of devserver on mac

[indirectlylit]

Observed behavior

On shutdown, observing many errors like:

--- Logging error ---
Traceback (most recent call last):
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1029, in emit
    self.flush()
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1009, in flush
    self.stream.flush()
RuntimeError: reentrant call inside <_io.BufferedWriter name='/Users/d/kolibri/B/logs/debug.txt'>
Call stack:
  File "/Users/d/Projects/le/kolibri-2/.venv/bin/kolibri", line 33, in <module>
    sys.exit(load_entry_point('kolibri', 'console_scripts', 'kolibri')())
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/cli.py", line 194, in invoke
    return super(KolibriDjangoCommand, self).invoke(ctx)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/cli.py", line 256, in start
    background=background,
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 653, in start
    bus.block()
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/process.py", line 145, in block
    self.wait('EXITED', interval=interval, channel='main', sleep=sleep)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 352, in wait
    _wait()
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 325, in _wait
    r, w, x = select.select([read_fd], [], [], interval)
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 410, in _handle_signal
    return super(SignalHandler, self)._handle_signal(signum, frame)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/plugins/signalhandler.py", line 130, in _handle_signal
    self.bus.log('Caught signal %s.' % signame)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 362, in log
    self.publish('log', msg, level)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 273, in publish
    result = listener(*args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 390, in log
    logger.log(level, msg)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1444, in log
    self._log(level, msg, args, **kwargs)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1514, in _log
    self.handle(record)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1524, in handle
    self.callHandlers(record)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1586, in callHandlers
    hdlr.handle(record)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 894, in handle
    self.emit(record)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1127, in emit
    StreamHandler.emit(self, record)
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1029, in emit
    self.flush()
  File "/Users/d/.pyenv/versions/3.7.11/lib/python3.7/logging/__init__.py", line 1009, in flush
    self.stream.flush()
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 410, in _handle_signal
    return super(SignalHandler, self)._handle_signal(signum, frame)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/plugins/signalhandler.py", line 131, in _handle_signal
    self.bus.publish(signame)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 273, in publish
    result = listener(*args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 422, in handle_SIGINT
    self.bus.transition("EXITED")
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 186, in transition
    output.append(self._transition(next_state))
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 215, in _transition
    return self.publish(newstate, *args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/.venv/lib/python3.7/site-packages/magicbus/base.py", line 273, in publish
    result = listener(*args, **kwargs)
  File "/Users/d/Projects/le/kolibri-2/kolibri/utils/server.py", line 273, in STOP
    worker.shutdown(wait=True)
  File "/Users/d/Projects/le/kolibri-2/kolibri/core/tasks/worker.py", line 81, in shutdown
    logger.info("Asking job schedulers to shut down.")
Message: 'Asking job schedulers to shut down.'
Arguments: ()
INFO     Asking job schedulers to shut down.

See attached logs for full context:

logs.txt

Note that after this, in fact Kolibri did not appear to be fully shut down. Trying to run production serveryarn run build and then kolibri start:

~/Projects/le/kolibri-2 release-v0.15.x
.venv ❯ kolibri start                
INFO: No C extensions are available for this platform
INFO     Option HTTP_PORT in section [Deployment] being overridden by environment variable KOLIBRI_HTTP_PORT
INFO     Option RUN_MODE in section [Deployment] being overridden by environment variable KOLIBRI_RUN_MODE
INFO     Running Kolibri with the following settings: kolibri.deployment.default.settings.base
INFO     Importing 'tasks' module from django apps
ERROR    There is another Kolibri server running. Please use `kolibri stop` and try again.

~/Projects/le/kolibri-2 release-v0.15.x
.venv ❯ kolibri stop 
INFO: No C extensions are available for this platform
INFO     Option HTTP_PORT in section [Deployment] being overridden by environment variable KOLIBRI_HTTP_PORT
INFO     Option RUN_MODE in section [Deployment] being overridden by environment variable KOLIBRI_RUN_MODE
INFO: Already stopped: Stopped

~/Projects/le/kolibri-2 release-v0.15.x
.venv ❯ kolibri start
INFO: No C extensions are available for this platform
INFO     Option HTTP_PORT in section [Deployment] being overridden by environment variable KOLIBRI_HTTP_PORT
INFO     Option RUN_MODE in section [Deployment] being overridden by environment variable KOLIBRI_RUN_MODE
INFO     Running Kolibri with the following settings: kolibri.deployment.default.settings.base
INFO     Importing 'tasks' module from django apps
ERROR    There is another Kolibri server running. Please use `kolibri stop` and try again.

~/Projects/le/kolibri-2 release-v0.15.x
.venv ❯ 

Expected behavior

clean shutdown with no errors

User-facing consequences

unknown

Steps to reproduce

On mac:

• clone a new copy of kolibri code with an empty KOLIBRI_HOME
• start devserver
• shutdown with ctrl+c

Context

latest 0.15