search

learningequality / kolibri

Kolibri Learning Platform: the offline app for universal education
https://learningequality.org/kolibri/
MIT License
804 stars 668 forks source link

Devserver should exit more cleanly after being terminated with "Ctrl-C" #7955

Open jonboiser opened 3 years ago

jonboiser commented 3 years ago

Observed behavior

  1. I run devserver with yarn run devserver-hot
  2. In the terminal, I press ctrl-c to stop the server
  3. CherryPy raises an error (it doesn't do this when running kolibri start)
  4. Then, after the shell prompt is returned, you see the "graceful" cherrypy shutdown logs

Note: This might depend on when Ctrl-C is pressed. Looking into this. Sometimes Ctrl-C will cause cherrypy to raise an error, sometimes not. But the INFO logs consistently happen after the prompt is restored.

Errors and logs

Logs start at ^C (Ctrl-C)

^CINFO     ENGINE Caught signal SIGINT.
--- Logging error ---
Traceback (most recent call last):
  File "/Users/jon/.pyenv/versions/3.6.8/Python.framework/Versions/3.6/lib/python3.6/logging/__init__.py", line 997, in emit
    stream.write(self.terminator)
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/server.py", line 386, in handler
    original_handler(signum, frame)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/plugins.py", line 200, in _handle_signal
    self.bus.log('Caught signal %s.' % signame)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 601, in log
    self.publish('log', msg, level)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 248, in publish
    raise exc
cherrypy.process.wspbus.ChannelFailures: RuntimeError("reentrant call inside <_io.BufferedWriter name='<stderr>'>",)
Call stack:

  File "/Users/jon/.pyenv/versions/kolibri-dev/bin/kolibri", line 33, in <module>
    sys.exit(load_entry_point('kolibri', 'console_scripts', 'kolibri')())
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/cli.py", line 275, in invoke
    return super(KolibriDjangoCommand, self).invoke(ctx)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/cli.py", line 535, in start
    server.start(port=port, serve_http=serve_http)
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/server.py", line 157, in start
    run_server(port=port, serve_http=serve_http)
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/server.py", line 402, in run_server
    cherrypy.engine.block()
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 336, in block
    self.wait(states.EXITING, interval=interval, channel='main')
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 394, in wait
    _wait()
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 380, in _wait
    time.sleep(interval)
  File "/Users/jon/Github/kolibri-dev/kolibri/utils/server.py", line 386, in handler
    original_handler(signum, frame)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/plugins.py", line 200, in _handle_signal
    self.bus.log('Caught signal %s.' % signame)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 601, in log
    self.publish('log', msg, level)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/process/wspbus.py", line 230, in publish
    output.append(listener(*args, **kwargs))
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/__init__.py", line 352, in _buslog
    log.error(msg, 'ENGINE', severity=level)
  File "/Users/jon/.pyenv/versions/3.6.8/envs/kolibri-dev/lib/python3.6/site-packages/cherrypy/_cplogging.py", line 223, in error
    exc_info=exc_info,
Message: 'ENGINE Caught signal SIGINT.'
Arguments: ()
INFO     ENGINE Bus STOPPING

Then after the prompt

~/Github/kolibri-dev develop 46s
kolibri-dev ➜ rmINFO     ENGINE HTTP Server cheroot.wsgi.Server(('0.0.0.0', 8888)) shut down
 INFO     ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 8000)) shut down
INFO     ENGINE Stopped thread 'Autoreloader'.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Kolibri instance 'c1f175dcb0230ad4ba9716ad5de11a4e' has left the zeroconf network.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     ENGINE Bus STOPPED
INFO     ENGINE Bus EXITING
INFO     ENGINE Bus EXITED
INFO     ENGINE Waiting for child threads to terminate...
INFO     ENGINE Waiting for thread SCHEDULECHECKER-f489c0b1ad0946bb9f62ba362e82353f.

Expected behavior

Turning off the dev-server raises no errors, and is more similar to running the production server.

^CINFO     ENGINE Caught signal SIGINT.
INFO     ENGINE Bus STOPPING
INFO     ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 8080)) shut down
INFO     ENGINE HTTP Server cheroot.wsgi.Server(('0.0.0.0', 8888)) shut down
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Kolibri instance 'c1f175dcb0230ad4ba9716ad5de11a4e' has left the zeroconf network.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     Asking job schedulers to shut down.
INFO     ENGINE Bus STOPPED
INFO     ENGINE Bus EXITING
INFO     ENGINE Bus EXITED
INFO     ENGINE Waiting for child threads to terminate...

~/Github/kolibri-dev develop 11s
kolibri-dev ➜

And then a clean prompt appears underneath

Steps to reproduce

  1. start dev server
  2. turn it off with ctrl-c

Context

Python 3.6.8 MacOS Running in dev mode

radinamatic commented 3 years ago

I don't recall having seen errors, but I always have to type Ctrl+C twice, sometimes even 3 times, for the server to actually stop.

Python 3.6.9 Ubuntu 18.04.5

rtibbles commented 3 years ago

I've done some investigation of this, as I was confused, and it's not to do with the Python server itself, but because it's being run from yarn. When the same commands are run from command line, it works fine and waits until everything has shut down before exiting to the terminal, for some reason yarn manages to snatch the ctrl-c and interpret it, dropping out to the terminal, while the dev server is still handling it.

indirectlylit commented 3 years ago

Flagging as a regression because yarn run devserver previously shut down cleanly

indirectlylit commented 3 years ago

update: re-opening #8465 and removing regression label because they seem to be different issues