Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
jonboiser opened this issue Apr 5, 2021 · 4 comments
Open
Labels
P2 - normal Priority: Nice to have TAG: dev experience Build performance, linting, debugging...

Comments

@jonboiser
Copy link
Contributor

jonboiser commented Apr 5, 2021

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

@jonboiser jonboiser added the TAG: dev experience Build performance, linting, debugging... label Apr 5, 2021
@radinamatic
Copy link
Member

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

@nucleogenesis nucleogenesis added the P2 - normal Priority: Nice to have label Apr 13, 2021
@rtibbles
Copy link
Member

rtibbles commented Jul 8, 2021

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
Copy link
Contributor

indirectlylit commented Sep 25, 2021

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

indirectlylit added a commit to indirectlylit/kolibri that referenced this issue Sep 28, 2021
@indirectlylit
Copy link
Contributor

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

@indirectlylit indirectlylit removed the TAG: regression Something that previously worked label Sep 29, 2021
indirectlylit added a commit to indirectlylit/kolibri that referenced this issue Oct 6, 2021
indirectlylit added a commit to indirectlylit/kolibri that referenced this issue Oct 6, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
P2 - normal Priority: Nice to have TAG: dev experience Build performance, linting, debugging...
Projects
None yet
Development

No branches or pull requests

5 participants