Giter Club home page Giter Club logo

Comments (7)

msabramo avatar msabramo commented on August 16, 2024

Here's what output looks like during one such failure:

❯ tox -e py27 -- -s --pdb honcho.test.integration.test_ports:TestPorts.test_proctype_increment
GLOB sdist-make: /Users/marca/dev/git-repos/honcho/setup.py
py27 inst-nodeps: /Users/marca/dev/git-repos/honcho/.tox/dist/honcho-0.5.0.zip
py27 runtests: PYTHONHASHSEED='1856189262'
py27 runtests: commands[0] | pip install -q -e .[export]
py27 runtests: commands[1] | nosetests -s --pdb honcho.test.integration.test_ports:TestPorts.test_proctype_increment
> /Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/case.py(1002)assertRegexpMatches()
-> raise self.failureException(msg)
(Pdb) u
> /Users/marca/dev/git-repos/honcho/honcho/test/integration/test_ports.py(19)test_proctype_increment()
-> self.assertRegexpMatches(out, r'web\.1    \| (....)?PORT=5000')
(Pdb) print out
15:18:13 system   | es.1 started (pid=92392)
15:18:13 system   | redis.1 started (pid=92393)
15:18:13 system   | web.1 started (pid=92394)
15:18:13 system   | worker.1 started (pid=92395)
15:18:13 es.1     | PORT=5300
15:18:13 system   | es.1 stopped (rc=0)
15:18:13 system   | sending SIGTERM to redis.1 (pid 92393)
15:18:13 system   | sending SIGTERM to web.1 (pid 92394)
15:18:13 system   | sending SIGTERM to worker.1 (pid 92395)
15:18:13 system   | web.1 stopped (rc=-15)
15:18:13 system   | redis.1 stopped (rc=-15)
15:18:13 system   | worker.1 stopped (rc=-15)

from honcho.

msabramo avatar msabramo commented on August 16, 2024

I suspect a race condition where it takes some time for processes to start up and have the output match the expected state. Sometimes it happens before the assertion and sometimes it doesn't.

from honcho.

msabramo avatar msabramo commented on August 16, 2024

Success looks like this:

❯ tox -e py27 -- -s honcho.test.integration.test_ports:TestPorts.test_get_port_from_env
GLOB sdist-make: /Users/marca/dev/git-repos/honcho/setup.py
py27 inst-nodeps: /Users/marca/dev/git-repos/honcho/.tox/dist/honcho-0.5.0.zip
py27 runtests: PYTHONHASHSEED='2418797409'
py27 runtests: commands[0] | pip install -q -e .[export]
py27 runtests: commands[1] | nosetests -s honcho.test.integration.test_ports:TestPorts.test_get_port_from_env
> /Users/marca/dev/git-repos/honcho/honcho/test/integration/test_ports.py(51)test_get_port_from_env()
-> self.assertRegexpMatches(out, r'web\.1    \| (....)?PORT=3000')
(Pdb) print out
15:32:47 system   | es.1 started (pid=95009)
15:32:47 system   | web.1 started (pid=95010)
15:32:47 system   | redis.1 started (pid=95011)
15:32:47 system   | worker.1 started (pid=95012)
15:32:47 es.1     | PORT=3300
15:32:47 web.1    | PORT=3000
15:32:47 system   | es.1 stopped (rc=0)
15:32:47 system   | sending SIGTERM to web.1 (pid 95010)
15:32:47 system   | sending SIGTERM to redis.1 (pid 95011)
15:32:47 system   | sending SIGTERM to worker.1 (pid 95012)
15:32:47 system   | web.1 stopped (rc=-15)
15:32:47 system   | redis.1 stopped (rc=-15)
15:32:47 system   | worker.1 stopped (rc=-15)

(Pdb) c
.
----------------------------------------------------------------------
Ran 1 test in 8.299s

OK
___________________________________________________________________________________ summary ____________________________________________________________________________________
  py27: commands succeeded
  congratulations :)

Failure looks like this:

❯ tox -e py27 -- -s honcho.test.integration.test_ports:TestPorts.test_get_port_from_env
GLOB sdist-make: /Users/marca/dev/git-repos/honcho/setup.py
py27 inst-nodeps: /Users/marca/dev/git-repos/honcho/.tox/dist/honcho-0.5.0.zip
py27 runtests: PYTHONHASHSEED='2812475943'
py27 runtests: commands[0] | pip install -q -e .[export]
py27 runtests: commands[1] | nosetests -s honcho.test.integration.test_ports:TestPorts.test_get_port_from_env
> /Users/marca/dev/git-repos/honcho/honcho/test/integration/test_ports.py(51)test_get_port_from_env()
-> self.assertRegexpMatches(out, r'web\.1    \| (....)?PORT=3000')
(Pdb) print out
15:35:39 system   | es.1 started (pid=96232)
15:35:39 system   | web.1 started (pid=96233)
15:35:39 system   | redis.1 started (pid=96234)
15:35:39 system   | worker.1 started (pid=96235)
15:35:39 es.1     | PORT=3300
15:35:39 system   | es.1 stopped (rc=0)
15:35:39 system   | sending SIGTERM to web.1 (pid 96233)
15:35:39 system   | sending SIGTERM to redis.1 (pid 96234)
15:35:39 system   | sending SIGTERM to worker.1 (pid 96235)
15:35:39 system   | redis.1 stopped (rc=-15)
15:35:39 system   | web.1 stopped (rc=-15)
15:35:39 system   | worker.1 stopped (rc=-15)

(Pdb) c
F
======================================================================
FAIL: test_get_port_from_env (honcho.test.integration.test_ports.TestPorts)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/marca/dev/git-repos/honcho/honcho/test/integration/test_ports.py", line 51, in test_get_port_from_env
    self.assertRegexpMatches(out, r'web\.1    \| (....)?PORT=3000')
AssertionError: Regexp didn't match: 'web\\.1    \\| (....)?PORT=3000' not found in '15:35:39 system   | es.1 started (pid=96232)\n15:35:39 system   | web.1 started (pid=96233)\n15:35:39 system   | redis.1 started (pid=96234)\n15:35:39 system   | worker.1 started (pid=96235)\n\x1b[35m15:35:39 es.1     | \x1b[0mPORT=3300\n15:35:39 system   | es.1 stopped (rc=0)\n15:35:39 system   | sending SIGTERM to web.1 (pid 96233)\n15:35:39 system   | sending SIGTERM to redis.1 (pid 96234)\n15:35:39 system   | sending SIGTERM to worker.1 (pid 96235)\n15:35:39 system   | redis.1 stopped (rc=-15)\n15:35:39 system   | web.1 stopped (rc=-15)\n15:35:39 system   | worker.1 stopped (rc=-15)\n'

----------------------------------------------------------------------
Ran 1 test in 3.745s

FAILED (failures=1)
ERROR: InvocationError: '/Users/marca/dev/git-repos/honcho/.tox/py27/bin/nosetests -s honcho.test.integration.test_ports:TestPorts.test_get_port_from_env'
___________________________________________________________________________________ summary ____________________________________________________________________________________
ERROR:   py27: commands failed

from honcho.

msabramo avatar msabramo commented on August 16, 2024

Hmmm, there's some non-determinism going on here.

Most of the time I see (SIGTERM message appears after PORT=5000 message):

❯ honcho start -f Procfile.ports | grep 'web\.1.*'
15:43:51 system   | web.1 started (pid=390)
15:43:51 web.1    | PORT=5000
15:43:51 system   | sending SIGTERM to web.1 (pid 390)
15:43:51 system   | web.1 stopped (rc=-15)

but occasionally I get (SIGTERM message appears before PORT=5000 message):

❯ honcho start -f Procfile.ports | grep 'web\.1.*'
15:49:36 system   | web.1 started (pid=3787)
15:49:36 system   | sending SIGTERM to web.1 (pid 3787)
15:49:36 web.1    | PORT=5000
15:49:36 system   | web.1 stopped (rc=-15)

or (PORT=5000 never appears in output`):

❯ honcho start -f Procfile.ports | grep 'web\.1.*'
15:44:09 system   | web.1 started (pid=849)
15:44:09 system   | sending SIGTERM to web.1 (pid 849)
15:44:09 system   | web.1 stopped (rc=-15)

from honcho.

msabramo avatar msabramo commented on August 16, 2024

I thought that bumping up the sleep interval in Procfile.ports might help:

web: echo PORT=$PORT && sleep 10
worker: echo PORT=$PORT && sleep 10
redis: echo PORT=$PORT && sleep 10
es: echo PORT=$PORT

but it doesn't:

❯ honcho start -f Procfile.ports | grep 'web\.1.*'
15:45:55 system   | web.1 started (pid=2217)
15:45:55 system   | sending SIGTERM to web.1 (pid 2217)
15:45:55 system   | web.1 stopped (rc=-15)

from honcho.

msabramo avatar msabramo commented on August 16, 2024

I have a theory -- that it's happening because the last process in Procfile.ports (the es process) has no sleep.

According to https://github.com/nickstenning/honcho/blob/master/honcho/manager.py#L83:

If one process terminates, all the others will be terminated by Honcho, and #loop() will return.

Thus, if es has no sleep and exits right away, everything else will be terminated too, pretty quickly, and possibly sometimes terminated before the echo gets written out.

I'll test with:

# Procfile.ports
web: echo PORT=$PORT && sleep 1
worker: echo PORT=$PORT && sleep 1
redis: echo PORT=$PORT && sleep 1
es: echo PORT=$PORT && sleep 1

Note the sleep 1 that I added to the es job. Hopefully, this makes things happier...

from honcho.

msabramo avatar msabramo commented on August 16, 2024

With #102, I haven't seen a test failure yet. Crossing fingers... 😄

from honcho.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.