lpereira / lwan

Experimental, scalable, high performance HTTP server
https://lwan.ws
GNU General Public License v2.0
5.94k stars 548 forks source link

Python testsuite FAIL: test_big_request (__main__.TestPost) #172

Open 0x003e opened 8 years ago

0x003e commented 8 years ago

Hi @lpereira ,

I have 3 errors when I execute the testssuite.


Traces:

~$ cd lwan/
~/lwan$ git log -1
commit 171f5fe464f675bfb0924de43508dc07e3927f2c
Author: Leandro Pereira <leandro@hardinfo.org>
Date:   Sun Sep 25 09:51:48 2016 -0300

    Use DEFAULT_BUFFER_SIZE to calculate maximum number of packets/request

    Use this instead of hardcoding 16.  The result is 5 now, which is smaller,
    but should be plenty.  The compiler is smart enough to fold the constants
    here, so there's no associated runtime cost.
~/lwan$ mkdir build
~/lwan$ cd build/
~/lwan/build$ cmake .. -DCMAKE_BUILD_TYPE=Release
-- The C compiler identification is GNU 5.4.0
-- Check for working C compiler: /usr/bin/cc
-- Check for working C compiler: /usr/bin/cc -- works
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Detecting C compile features
-- Detecting C compile features - done
-- Running CMake for lwan (Scalable, high performance, experimental web server)
-- Found ZLIB: /usr/lib/x86_64-linux-gnu/libz.so (found version "1.2.8") 
-- Looking for pthread.h
-- Looking for pthread.h - found
-- Looking for pthread_create
-- Looking for pthread_create - not found
-- Looking for pthread_create in pthreads
-- Looking for pthread_create in pthreads - not found
-- Looking for pthread_create in pthread
-- Looking for pthread_create in pthread - found
-- Found Threads: TRUE  
-- Performing Test HAVE_BUILTIN_CPU_INIT
-- Performing Test HAVE_BUILTIN_CPU_INIT - Success
-- Performing Test HAVE_BUILTIN_CLZLL
-- Performing Test HAVE_BUILTIN_CLZLL - Success
-- Performing Test HAVE_BUILTIN_MUL_OVERFLOW
-- Performing Test HAVE_BUILTIN_MUL_OVERFLOW - Success
-- Performing Test HAVE_STATIC_ASSERT
-- Performing Test HAVE_STATIC_ASSERT - Success
-- Looking for pthread_barrier_init
-- Looking for pthread_barrier_init - found
-- Looking for clock_gettime
-- Looking for clock_gettime - found
-- tcmalloc found: /usr/local/lib/libtcmalloc_minimal.so
-- Performing Test HAS_MTUNE_NATIVE
-- Performing Test HAS_MTUNE_NATIVE - Success
-- Performing Test HAS_RDYNAMIC
-- Performing Test HAS_RDYNAMIC - Success
-- Performing Test HAS_STD_GNU99
-- Performing Test HAS_STD_GNU99 - Success
-- Performing Test HAS_IMMEDIATE_BINDING
-- Performing Test HAS_IMMEDIATE_BINDING - Success
-- Performing Test HAS_READ_ONLY_GOT
-- Performing Test HAS_READ_ONLY_GOT - Success
-- Performing Test HAS_MALIGN_DATA_CACHELINE
-- Performing Test HAS_MALIGN_DATA_CACHELINE - Success
-- Performing Test HAS_ASYNC_UNWIND_TABLES
-- Performing Test HAS_ASYNC_UNWIND_TABLES - Success
-- Performing Test HAS_LTO
-- Performing Test HAS_LTO - Success
-- Performing Test HAS_FAT_LTO_OBJECTS
-- Performing Test HAS_FAT_LTO_OBJECTS - Success
-- Performing Test HAVE_BUILTIN_IA32_CRC32
-- Performing Test HAVE_BUILTIN_IA32_CRC32 - Success
-- Building with Valgrind support
-- Looking for rawmemchr
-- Looking for rawmemchr - found
-- Looking for mempcpy
-- Looking for mempcpy - found
-- Looking for memrchr
-- Looking for memrchr - found
-- Looking for pipe2
-- Looking for pipe2 - found
-- Looking for accept4
-- Looking for accept4 - found
-- Found PkgConfig: /usr/bin/pkg-config (found version "0.29.1") 
-- Checking for modules 'luajit>=2.0;luajit<=2.0.999'
--   Found luajit, version 2.0.4
--   Found luajit, version 2.0.4
-- Building with Lua support using luajit-5.1
-- Checking for module 'sqlite3>=3.6.20'
--   
-- Freegeoip sample application not being built: SQLite not found
-- Checking for module 'sqlite3>=3.6.20'
--   
-- Not building benchmark suite: database libraries not found.
-- Found PythonInterp: /usr/bin/python3 (found suitable version "3.5.2", minimum required is "3") 
-- Configuring done
-- Generating done
-- Build files have been written to: /home/l/lwan/build
$ make testsuite
[ 18%] Built target mimegen
[ 20%] Built target generate_mime_types_table
[ 93%] Built target lwan-static
[ 97%] Built target testrunner
[100%] Running Python tests: /home/l/lwan/tools/testsuite.py.
Using ./build/testrunner/testrunner for lwan
........................E.............EE......
======================================================================
ERROR: test_post_request (__main__.TestHelloWorld)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 377, in _make_request
    httplib_response = conn.getresponse(buffering=True)
TypeError: getresponse() got an unexpected keyword argument 'buffering'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 376, in send
    timeout=timeout
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 610, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/lib/python3/dist-packages/urllib3/util/retry.py", line 247, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3/dist-packages/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
requests.packages.urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/l/lwan/tools/testsuite.py", line 464, in test_post_request
    r = requests.post('http://127.0.0.1:8080/hello?dump_vars=1', data=data)
  File "/usr/lib/python3/dist-packages/requests/api.py", line 107, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/api.py", line 53, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 426, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

======================================================================
ERROR: test_big_request (__main__.TestPost)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 377, in _make_request
    httplib_response = conn.getresponse(buffering=True)
TypeError: getresponse() got an unexpected keyword argument 'buffering'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 376, in send
    timeout=timeout
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 610, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/lib/python3/dist-packages/urllib3/util/retry.py", line 247, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3/dist-packages/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
requests.packages.urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/l/lwan/tools/testsuite.py", line 81, in test_big_request
    headers={'Content-Type': 'x-test/trololo'})
  File "/usr/lib/python3/dist-packages/requests/api.py", line 107, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/api.py", line 53, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 426, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

======================================================================
ERROR: test_will_it_blend (__main__.TestPost)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 377, in _make_request
    httplib_response = conn.getresponse(buffering=True)
TypeError: getresponse() got an unexpected keyword argument 'buffering'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 376, in send
    timeout=timeout
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 610, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/lib/python3/dist-packages/urllib3/util/retry.py", line 247, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3/dist-packages/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 560, in urlopen
    body=body, headers=headers)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 379, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.5/http/client.py", line 1197, in getresponse
    response.begin()
  File "/usr/lib/python3.5/http/client.py", line 297, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.5/http/client.py", line 266, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
requests.packages.urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/l/lwan/tools/testsuite.py", line 72, in test_will_it_blend
    r = requests.post('http://127.0.0.1:8080/post/blend', json={'will-it-blend': True})
  File "/usr/lib/python3/dist-packages/requests/api.py", line 107, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/api.py", line 53, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 426, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',))

----------------------------------------------------------------------
Ran 46 tests in 78.307s

FAILED (errors=3)
CMakeFiles/testsuite.dir/build.make:57: recipe for target 'CMakeFiles/testsuite' failed
make[3]: *** [CMakeFiles/testsuite] Error 1
CMakeFiles/Makefile2:67: recipe for target 'CMakeFiles/testsuite.dir/all' failed
make[2]: *** [CMakeFiles/testsuite.dir/all] Error 2
CMakeFiles/Makefile2:74: recipe for target 'CMakeFiles/testsuite.dir/rule' failed
make[1]: *** [CMakeFiles/testsuite.dir/rule] Error 2
Makefile:162: recipe for target 'testsuite' failed
make: *** [testsuite] Error 2

After that modification

patch All error with requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response',)) are resolved

test_post_request (main.TestHelloWorld) OK test_will_it_blend (main.TestPost) OK

however test_big_request (__main__.TestPost) KO

~/lwan/build$ make testsuite
[ 18%] Built target mimegen
[ 20%] Built target generate_mime_types_table
[ 93%] Built target lwan-static
[ 97%] Built target testrunner
[100%] Running Python tests: ~/lwan/tools/testsuite.py.
Using ./build/testrunner/testrunner for lwan
......................................F.......
======================================================================
FAIL: test_big_request (__main__.TestPost)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "~/lwan/tools/testsuite.py", line 83, in test_big_request
    self.assertHttpResponseValid(r, 200, 'application/json')
  File "~/lwan/tools/testsuite.py", line 56, in assertHttpResponseValid
    self.assertEqual(request.status_code, status_code)
AssertionError: 413 != 200

----------------------------------------------------------------------
Ran 46 tests in 31.954s

FAILED (failures=1)

The previous python test suite fail at size = 100 000: at

I replay this request with curl in debug mode:
data="tro";
for i in {1..100000}; do data=$data"lo"; done
echo $data > post-data.big
curl -X POST -H "Content-Type: x-test/trololo" -d @post-data.big http://127.0.0.1:8080/post/blend 

Break POINT:

bp

lpereira commented 8 years ago

That's a really detailed bug report, thanks!

I did execute the test suite before pushing the commits, and it was not failing back then; it's failing now, so I guess that made the tests quite flaky. I'll take a closer look whenever I have time. The tree at 9e0a2042 (and their parents) seems fine, so it's likely the problem arrived in 55a11d0.

0x003e commented 8 years ago

@lpereira didn't understand why this testsuite not fail: https://buildbot.lwan.ws/builders/unit-tests/builds/574/steps/shell_11/logs/stdio (same HEAD commit)