sanic: Random Failures during tox run on Mac

Describe the bug When running Unit Test in local machine (mac), few test cases randomly fail and re-cover during re-run.

Error Output

# Test session starts (platform: darwin, Python 3.5.6, pytest 3.3.2, pytest-sugar 0.9.1)
    def test_default_server_error_request_timeout():
        client = DelayableSanicTestClient(request_timeout_default_app, None, 3)
        request, response = client.get('/1')
>       assert response.status == 408
E       assert 200 == 408
E        +  where 200 = <test_request_timeout.DelayableTCPConnector.RequestContextManager object at 0x10723ccf8>.status
tests/test_request_timeout.py:194: AssertionError
# Test session starts (platform: darwin, Python 3.7.0, pytest 3.3.2, pytest-sugar 0.9.1)
    def test_default_server_error_request_timeout():
        client = DelayableSanicTestClient(request_timeout_default_app, None, 3)
        request, response = client.get('/1')
>       assert response.status == 408
E       assert 200 == 408
E        +  where 200 = <test_request_timeout.DelayableTCPConnector.RequestContextManager object at 0x112d87470>.status
tests/test_request_timeout.py:194: AssertionError
# py37-no-ext develop-inst-nodeps: <path>
# py37-no-ext installed: aiofiles==0.4.0,aiohttp==3.2.1,async-generator==1.10,async-timeout==3.0.1,attrs==18.2.0,beautifulsoup4==4.6.3,chardet==2.3.0,coverage==4.5.1,gunicorn==19.9.0,httptools==0.0.11,idna==2.7,multidict==4.4.2,pluggy==0.6.0,py==1.7.0,pytest==3.3.2,pytest-cov==2.6.0,pytest-sanic==0.1.13,pytest-sugar==0.9.1,-e git+git@github.com:harshanarayana/sanic.git@e3a27c2cc485d57aa1ff87d9f69098e4ab12727e#egg=sanic,six==1.11.0,termcolor==1.1.0,websockets==6.0,yarl==1.2.6
# py37-no-ext run-test-pre: PYTHONHASHSEED='27345397'
# py37-no-ext runtests: commands[0] | pytest tests --cov sanic --cov-report=
# Test session starts (platform: darwin, Python 3.7.0, pytest 3.3.2, pytest-sugar 0.9.1)E       AssertionError: assert {'Connection'...p-Alive': '2'} == {'Connection':...p-Alive': '2'}
E         Omitting 3 identical items, use -vv to show
E         Differing items:
E         {'Content-Length': '12'} != {'Content-Length': '11'}

Code snippet NA

Expected behavior Existing Unit Tests to pass in all Virtual env during tox execution.

Environment (please complete the following information):

  • OS: macOS Mojave
  • Version 10.14 (18A391)

Additional context NA

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Comments: 43 (43 by maintainers)

Commits related to this issue

Most upvoted comments

I finally found the problem 😓

$ TOXENV={py35,py36,py37}-no-ext tox -v
[ truncated ]
ERROR:   py35-no-ext: commands failed
ERROR:   py36-no-ext: commands failed
ERROR:   py37-no-ext: commands failed

$ ./.tox/py35-no-ext/bin/python    
Python 3.5.6 (default, Oct 13 2018, 16:17:36) 
[GCC 8.2.1 20180831] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import ujson
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ImportError: No module named 'ujson'
>>> import uvloop
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ImportError: No module named 'uvloop'
>>> exit()

Even the full test is now reporting “correctly” (prior to PR #1403):

$ tox -v
[ truncated ]
  py35: commands succeeded
  py36: commands succeeded
  py37: commands succeeded
ERROR:   py35-no-ext: commands failed
ERROR:   py36-no-ext: commands failed
ERROR:   py37-no-ext: commands failed
ERROR:   flake8: commands failed
  check: commands succeeded

How? Dead simple. The problem is here. When installing pytest-sanic as a test dependency, it will try to install what? Sanic. For some reason, under Python 3.5, the SANIC_NO_UVLOOP and SANIC_NO_UJSON environment variables aren’t broadcast when tox installs pytest-sanic … So it ends up requiring Sanic, which requires and installs uvloop and ujson 😒

This is way too random. Maybe because pytest-sanic has Python 3.5 inside its setup classifiers? I don’t really know 😕

I tried to set passenv inside tox.ini, set with SANIC_NO_UJSON and SANIC_NO_UVLOOP, with no luck as well:

$ tox -v
[ truncated ]
  py35: commands succeeded
  py36: commands succeeded
  py37: commands succeeded
  py35-no-ext: commands succeeded
ERROR:   py36-no-ext: commands failed
ERROR:   py37-no-ext: commands failed
ERROR:   flake8: commands failed
  check: commands succeeded

Anyway, here’s pip freeze under the tox environment with pytest-sanic in tox.ini (as it is today):

$ ./.tox/py35-no-ext/bin/pip freeze                                                 
aiofiles==0.4.0
aiohttp==3.2.1
async-generator==1.10
async-timeout==3.0.1
attrs==18.2.0
beautifulsoup4==4.6.3
chardet==2.3.0
coverage==4.5.1
gunicorn==19.9.0
httptools==0.0.11
idna==2.7
idna-ssl==1.1.0
multidict==4.4.2
pluggy==0.6.0
py==1.7.0
pytest==3.3.2
pytest-cov==2.6.0
pytest-sanic==0.1.13
pytest-sugar==0.9.1
-e git+git@github.com:vltr/sanic.git@1498baab0fd0e4799b228b32d73675848f0ac680#egg=sanic
six==1.11.0
termcolor==1.1.0
ujson==1.35
uvloop==0.11.3
websockets==5.0.1
yarl==1.2.6

And here’s pip freeze under the tox environment without pytest-sanic (that’s not even used in testing afaik):

$ ./.tox/py35-no-ext/bin/pip freeze                                                 
aiofiles==0.4.0
aiohttp==3.2.1
async-timeout==3.0.1
attrs==18.2.0
beautifulsoup4==4.6.3
chardet==2.3.0
coverage==4.5.1
gunicorn==19.9.0
httptools==0.0.11
idna==2.7
idna-ssl==1.1.0
multidict==4.4.2
pluggy==0.6.0
py==1.7.0
pytest==3.3.2
pytest-cov==2.6.0
pytest-sugar==0.9.1
-e git+git@github.com:vltr/sanic.git@1498baab0fd0e4799b228b32d73675848f0ac680#egg=sanic
six==1.11.0
termcolor==1.1.0
websockets==5.0.1
yarl==1.2.6

That was a needle in a hay.

@yunstanford should we just remove pytest-sanic as a test dependency from Tox? IMHO it creates a circular dependency as well …

@vltr when in doubt… blame it on the gremlins.

@vltr

 py35: commands succeeded
  py36: commands succeeded
  py37: commands succeeded
  py35-no-ext: commands succeeded
  py36-no-ext: commands succeeded
  py37-no-ext: commands succeeded
  lint: commands succeeded
  check: commands succeeded
  congratulations :)

Looks so good 😀

I confirm the reports from @harshanarayana regarding py37-no-ext.

The problem is: under ujson, an object dumps doesn’t create a space between colons :, while the Python json module does it (and after commas , too):

>>> import json
>>> import ujson
>>> json.dumps({"hello": "world", "foo": "bar"})
'{"hello": "world", "foo": "bar"}'
>>> ujson.dumps({"hello": "world", "foo": "bar"})
'{"hello":"world","foo":"bar"}'

To fix that, you just need to tell the json module to not add these spaces after colons:

>>> json.dumps({"hello": "world", "foo": "bar"}, separators=(',', ':'))
'{"hello":"world","foo":"bar"}'

I think a minor PR should fix that in responses.py using functools.partial 😉, basically:

    from json import dumps as _json_dumps
    json_dumps = partial(_json_dumps, separators=(',', ':'))

@vltr I can confirm that these random intermittent errors are seen no more. We can close this issue (The original issue I reported are all sorted). Thanks, everyone for the help 😃

@yunstanford , thanks for “fixing” pytest-sanic regarding this issue. I’ll bring up the matter for bringing some Sanic related projects (that are really a plus to have, like yours) into the huge-success umbrella 😉

@yunstanford great, we can sleep on that and think about proposals for the future 😉

@yunstanford I know pytest-sanic is not a direct dependency of Sanic, but it’s part of the development process (as being a test dependency). If Sanic test_client is error prone, then we should make it work or change pytest-sanic so it’ll act as an utility tool (without explicitly requiring Sanic). Otherwise, we will not be able to guarantee our testing environments, and that’s a big problem.

Since we are talking about this, why not bring pytest-sanic under the huge-success “umbrella”?

@vltr If we remove sanic as a dependency from pytest-sanic under it’s install_requires, pytest-sanic will not bother about sanic during the installation. That should address the circular dependency issue you were talking about before.

So, now that we are only going to use the sanic we have in our cloned repo for everything, if the right env variables for SANIC_NO_UJSON and SANIC_NO_UVLOOP gets passed into tox that should fix our main problem.

@harshanarayana don’t worry, I already addressed the issue with the core-devs to find the best solution - IMO pytest-sanic should not be a dependency in Sanic in any way, but let’s see what we can come out with.

@vltr Please do let me know if there is anything I can do to help your investigation into this criminal matter. 😉

@harshanarayana somehow, if I execute only the -no-ext tests, uvloop and ujson end up being installed into the Python 3.5 environment (through tox). No matter what (and how) I call [tox], ujson and uvloop will be in that environment. I’m digging a little bit deeper now into what happens with tox and the environment variables set to not install these dependencies being ignored in Python 3.5.

$ TOXENV={py35,py36,py37}-no-ext tox -v

[ truncated ]

  py35-no-ext: commands succeeded
ERROR:   py36-no-ext: commands failed
ERROR:   py37-no-ext: commands failed

$ ./.tox/py37-no-ext/bin/python        
Python 3.7.1 (default, Oct 22 2018, 10:41:28) 
[GCC 8.2.1 20180831] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import uvloop
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ModuleNotFoundError: No module named 'uvloop'
>>> import ujson
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ModuleNotFoundError: No module named 'ujson'
>>> exit()

$ ./.tox/py36-no-ext/bin/python
Python 3.6.7 (default, Nov  8 2018, 10:37:02) 
[GCC 8.2.1 20180831] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import ujson
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ModuleNotFoundError: No module named 'ujson'
>>> import uvloop
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ModuleNotFoundError: No module named 'uvloop'
>>> exit()

$ ./.tox/py35-no-ext/bin/python        
Python 3.5.6 (default, Oct 13 2018, 16:17:36) 
[GCC 8.2.1 20180831] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import uvloop
>>> import ujson
>>> exit()

$ ls -la .tox                          
total 28K
drwxr-xr-x  7 richard richard 4.0K Nov  8 13:48 ./
drwxr-xr-x 11 richard richard 4.0K Nov  8 13:49 ../
drwxr-xr-x  2 richard richard 4.0K Nov  8 13:47 log/
drwxr-xr-x  7 richard richard 4.0K Nov  8 13:47 py35-no-ext/
drwxr-xr-x  7 richard richard 4.0K Nov  8 13:48 py36-no-ext/
drwxr-xr-x  7 richard richard 4.0K Nov  8 13:48 py37-no-ext/
drwxr-xr-x  2 richard richard 4.0K Nov  8 13:47 .tmp/

@vltr Creating a PR with modified Test cases in a while. Saved me the effort of debugging the issue. 😃

This happens on my system too, exactly the same error - and I use Arch Linux, so it’s not an OS problem 😒