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.

Sign up for GitHub

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

Jump to bottom

Deproxy errors on TCP segmentation tests #512

Closed
krizhanovsky opened this issue Sep 7, 2023 · 4 comments
Closed

Deproxy errors on TCP segmentation tests #512

krizhanovsky opened this issue Sep 7, 2023 · 4 comments
Assignees
@RomanBelozerov @EvgeniiMekhanik
Labels
bug Something isn't working
Milestone
0.9 (LA) for tests

Comments

@krizhanovsky
Copy link
Contributor

Tempesta master as of 4d16c3ee8294817b1bc15994804d17a7d47a4c22 and tempesa-test master as of d56358e . Tests config:

[General]
ip = 127.0.0.1
ipv6 = ::1
verbose = 1
workdir = /tmp/host
duration = 10
concurrent_connections = 10
log_file = tests_log.log
stress_threads = 2
stress_large_content_length = 65536
stress_requests_count = 100
stress_mtu = 1500
long_body_size = 500

[Client]
ip = 127.0.0.1
ipv6 = ::1
hostname = localhost
ab = ab
wrk = /root/wrk/wrk
h2load = h2load
tls-perf = /root/tls-perf/tls-perf
workdir = /tmp/client
unavaliable_timeout = 300

[Tempesta]
ip = 127.0.0.1
ipv6 = ::1
hostname = localhost
user = root
port = 22
srcdir = /root/tempesta
workdir = /tmp/tempesta
config = tempesta.conf
unavaliable_timeout = 300

[Server]
ip = 127.0.0.1
ipv6 = ::1
hostname = localhost
user = root
port = 22
nginx = nginx
workdir = /tmp/nginx
resources = /var/www/html/
aliases_interface = ens3
aliases_base_ip = 192.168.100.4
max_workers = 16
keepalive_timeout = 60
keepalive_requests = 100
unavaliable_timeout = 300

TCP segmentation tests fail with deproxy errors:

# ./run_tests.py -T 1 -n tls.test_tls_integrity
Root privileges are required: need access to module loading on localhost.

----------------------------------------------------------------------
Running functional tests...
----------------------------------------------------------------------

test_various_req_resp_sizes (tls.test_tls_integrity.Proxy) ... ok
test_various_req_resp_sizes (tls.test_tls_integrity.ManyClientsH2) ... Exception in thread Thread-2 (run_deproxy_server):
Traceback (most recent call last):
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_client.py", line 587, in handle_write
    sent = self.socket.send(chunk)
  File "/usr/lib/python3.10/ssl.py", line 1206, in send
    return self._sslobj.write(data)
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2426)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/root/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.10/asyncore.py", line 195, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.10/asyncore.py", line 124, in readwrite
    obj.handle_error()
  File "/root/tempesta-test/helpers/deproxy.py", line 865, in handle_error
    error.bug("\tDeproxy: Client: %s" % v)
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_client.py", line 587, in handle_write
    sent = self.socket.send(chunk)
  File "/usr/lib/python3.10/ssl.py", line 1206, in send
    return self._sslobj.write(data)
helpers.error.Error: 	Deproxy: Client: EOF occurred in violation of protocol (_ssl.c:2426) (SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2426))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/root/tempesta-test/framework/deproxy_manager.py", line 34, in run_deproxy_server
    error.bug(f"\n\tDeproxy: Manager:")
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/root/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.10/asyncore.py", line 195, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.10/asyncore.py", line 124, in readwrite
    obj.handle_error()
  File "/root/tempesta-test/helpers/deproxy.py", line 865, in handle_error
    error.bug("\tDeproxy: Client: %s" % v)
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_client.py", line 587, in handle_write
    sent = self.socket.send(chunk)
  File "/usr/lib/python3.10/ssl.py", line 1206, in send
    return self._sslobj.write(data)
helpers.error.Error: 
	Deproxy: Manager: (Error: 	Deproxy: Client: EOF occurred in violation of protocol (_ssl.c:2426) (SSLEOFError: EOF occurred in violation of protocol (_ssl.c:2426)))
FAIL
test_various_req_resp_sizes (tls.test_tls_integrity.ManyClients) ... Exception in thread Thread-3 (run_deproxy_server):
Traceback (most recent call last):
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
BlockingIOError: [Errno 11] Resource temporarily unavailable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/root/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.10/asyncore.py", line 195, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.10/asyncore.py", line 124, in readwrite
    obj.handle_error()
  File "/root/tempesta-test/framework/deproxy_server.py", line 43, in handle_error
    error.bug("\tDeproxy: SrvConnection: %s" % v)
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
helpers.error.Error: 	Deproxy: SrvConnection: [Errno 11] Resource temporarily unavailable (BlockingIOError: [Errno 11] Resource temporarily unavailable)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/root/tempesta-test/framework/deproxy_manager.py", line 34, in run_deproxy_server
    error.bug(f"\n\tDeproxy: Manager:")
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/root/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.10/asyncore.py", line 195, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.10/asyncore.py", line 124, in readwrite
    obj.handle_error()
  File "/root/tempesta-test/framework/deproxy_server.py", line 43, in handle_error
    error.bug("\tDeproxy: SrvConnection: %s" % v)
  File "/root/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.10/asyncore.py", line 117, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.10/asyncore.py", line 446, in handle_write_event
    self.handle_write()
  File "/root/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
helpers.error.Error: 
	Deproxy: Manager: (Error: 	Deproxy: SrvConnection: [Errno 11] Resource temporarily unavailable (BlockingIOError: [Errno 11] Resource temporarily unavailable))
FAIL
test7 (tls.test_tls_integrity.CloseConnection) ... ok
test6 (tls.test_tls_integrity.CloseConnection) ... ok
test5 (tls.test_tls_integrity.CloseConnection) ... ok
test4 (tls.test_tls_integrity.CloseConnection) ... ok
test3 (tls.test_tls_integrity.CloseConnection) ... ok
test2 (tls.test_tls_integrity.CloseConnection) ... ok
test1 (tls.test_tls_integrity.CloseConnection) ... ok

======================================================================
FAIL: test_various_req_resp_sizes (tls.test_tls_integrity.ManyClientsH2)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/tempesta-test/tls/test_tls_integrity.py", line 251, in test_various_req_resp_sizes
    self.common_check(65536, 65536)
  File "/root/tempesta-test/tls/test_tls_integrity.py", line 320, in common_check
    self.assertTrue(
AssertionError: False is not true : Cannot process request (len=65536) or response (len=65536)

======================================================================
FAIL: test_various_req_resp_sizes (tls.test_tls_integrity.ManyClients)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/tempesta-test/tls/test_tls_integrity.py", line 251, in test_various_req_resp_sizes
    self.common_check(65536, 65536)
  File "/root/tempesta-test/tls/test_tls_integrity.py", line 320, in common_check
    self.assertTrue(
AssertionError: False is not true : Cannot process request (len=65536) or response (len=65536)

----------------------------------------------------------------------
Ran 10 tests in 42.098s

FAILED (failures=2)

Full log with verbose = 6 (unpack it with tar --xz -xf tests_log.log.tar.xz.txt)
tests_log.log.tar.xz.txt
@krizhanovsky krizhanovsky added the bug Something isn't working label Sep 7, 2023
@krizhanovsky krizhanovsky added this to the Beta milestone Sep 7, 2023
@krizhanovsky
Copy link
Contributor Author 

# pip list
Package                Version
---------------------- ----------------
appdirs                1.4.4
attrs                  21.2.0
Automat                20.2.0
awscli                 1.25.18
Babel                  2.8.0
backcall               0.2.0
bcrypt                 3.2.0
beautifulsoup4         4.10.0
beniget                0.4.1
blinker                1.4
boto                   2.49.0
botocore               1.27.18
Brotli                 1.0.9
certifi                2020.6.20
chardet                4.0.0
click                  8.0.3
cloud-init             23.2.2
colorama               0.4.4
command-not-found      0.3
configobj              5.0.6
constantly             15.1.0
cryptography           3.4.8
cycler                 0.11.0
dbus-python            1.2.18
decorator              4.4.2
distro                 1.7.0
distro-info            1.1+ubuntu0.1
docutils               0.16
fonttools              4.29.1
fs                     2.4.12
future                 0.18.2
gast                   0.5.2
gyp                    0.1
h2                     4.1.0
hpack                  4.0.0
html5lib               1.1
httplib2               0.20.2
hyperframe             6.0.1
hyperlink              21.0.0
idna                   3.3
importlib-metadata     4.6.4
incremental            21.3.0
ipython                7.31.1
jedi                   0.18.0
jeepney                0.7.1
Jinja2                 3.0.3
jmespath               1.0.1
jsonpatch              1.32
jsonpointer            2.0
jsonschema             3.2.0
keyring                23.5.0
kiwisolver             1.3.2
launchpadlib           1.10.16
lazr.restfulclient     0.14.4
lazr.uri               1.0.6
lxml                   4.8.0
lz4                    3.1.3+dfsg
MarkupSafe             2.0.1
matplotlib             3.5.1
matplotlib-inline      0.1.3
more-itertools         8.10.0
mpmath                 0.0.0
netifaces              0.11.0
numpy                  1.21.5
oauthlib               3.2.0
olefile                0.46
packaging              21.3
paramiko               2.9.3
parso                  0.8.1
pexpect                4.8.0
pickleshare            0.7.5
Pillow                 9.0.1
pip                    22.0.2
ply                    3.11
prompt-toolkit         3.0.28
ptyprocess             0.7.0
pyasn1                 0.4.8
pyasn1-modules         0.2.1
pycryptodome           3.15.0
pycryptodomex          3.15.0
Pygments               2.11.2
PyGObject              3.42.1
PyHamcrest             2.0.2
PyJWT                  2.3.0
pymacaroons            0.13.0
PyNaCl                 1.5.0
pyOpenSSL              21.0.0
pyparsing              2.4.7
pyrsistent             0.18.1
pyserial               3.5
python-apt             2.4.0+ubuntu2
python-dateutil        2.8.1
python-debian          0.1.43+ubuntu1.1
python-magic           0.4.24
pythran                0.10.0
pytz                   2022.1
PyYAML                 5.4.1
requests               2.25.1
roman                  3.3
rsa                    4.7.2
s3transfer             0.6.0
scapy                  2.4.4
scipy                  1.8.0
SCons                  4.0.1
SecretStorage          3.3.1
service-identity       18.1.0
setuptools             59.6.0
six                    1.16.0
sos                    4.5.6
soupsieve              2.3.1
ssh-import-id          5.11
subprocess32           3.5.4
sympy                  1.9
systemd-python         234
tinyec                 0.4.0
traitlets              5.1.1
Twisted                22.1.0
ubuntu-advantage-tools 8001
ufoLib2                0.13.1
ufw                    0.36.1
unattended-upgrades    0.1
unicodedata2           14.0.0
urllib3                1.26.5
wadllib                1.3.6
wcwidth                0.2.5
webencodings           0.5.1
websockets             10.3
wheel                  0.37.1
wrk                    0.3.2
zipp                   1.0.0
zope.interface         5.4.0

@krizhanovsky
Copy link
Contributor Author

krizhanovsky commented Sep 7, 2023 •
edited
Loading

Call trace from CI

test_various_req_resp_sizes (tls.test_tls_integrity.ManyClients) ... Exception in thread Thread-11:
Traceback (most recent call last):
  File "/usr/lib/python3.8/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.8/asyncore.py", line 439, in handle_write_event
    self.handle_write()
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
BlockingIOError: [Errno 11] Resource temporarily unavailable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.8/asyncore.py", line 188, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.8/asyncore.py", line 117, in readwrite
    obj.handle_error()
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_server.py", line 43, in handle_error
    error.bug("\tDeproxy: SrvConnection: %s" % v)
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.8/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.8/asyncore.py", line 439, in handle_write_event
    self.handle_write()
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
helpers.error.Error: 	Deproxy: SrvConnection: [Errno 11] Resource temporarily unavailable (BlockingIOError: [Errno 11] Resource temporarily unavailable)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_manager.py", line 34, in run_deproxy_server
    error.bug(f"\n\tDeproxy: Manager:")
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_manager.py", line 27, in run_deproxy_server
    poll_fun()
  File "/usr/lib/python3.8/asyncore.py", line 188, in poll2
    readwrite(obj, flags)
  File "/usr/lib/python3.8/asyncore.py", line 117, in readwrite
    obj.handle_error()
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_server.py", line 43, in handle_error
    error.bug("\tDeproxy: SrvConnection: %s" % v)
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/helpers/error.py", line 44, in bug
    raise Error(msg).with_traceback(exc_info[2])
  File "/usr/lib/python3.8/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
  File "/usr/lib/python3.8/asyncore.py", line 439, in handle_write_event
    self.handle_write()
  File "/home/jenkins/workspace/_PR_tempesta_PR-1972/tempesta-test/framework/deproxy_server.py", line 100, in handle_write
    sent = self.socket.send(resp[:segment_size])
helpers.error.Error: 
	Deproxy: Manager: (Error: 	Deproxy: SrvConnection: [Errno 11] Resource temporarily unavailable (BlockingIOError: [Errno 11] Resource temporarily unavailable))
FAIL

@krizhanovsky
Copy link
Contributor Author

My initial test case was run inside a VM with 4GB RAM and I saw OOM in dmesg. When I reran it in a VM with 8GB RAM, the test is successful:

./run_tests.py -T 1 -n tls.test_tls_integrity
Root privileges are required: need access to module loading on localhost.

----------------------------------------------------------------------
Running functional tests...
----------------------------------------------------------------------

test_various_req_resp_sizes (tls.test_tls_integrity.Proxy) ... ok
test_various_req_resp_sizes (tls.test_tls_integrity.ManyClientsH2) ... ok
test_various_req_resp_sizes (tls.test_tls_integrity.ManyClients) ... ok
test7 (tls.test_tls_integrity.CloseConnection) ... ok
test6 (tls.test_tls_integrity.CloseConnection) ... ok
test5 (tls.test_tls_integrity.CloseConnection) ... ok
test4 (tls.test_tls_integrity.CloseConnection) ... ok
test3 (tls.test_tls_integrity.CloseConnection) ... ok
test2 (tls.test_tls_integrity.CloseConnection) ... ok
test1 (tls.test_tls_integrity.CloseConnection) ... ok

----------------------------------------------------------------------
Ran 10 tests in 44.240s

OK

@krizhanovsky krizhanovsky mentioned this issue Feb 29, 2024
Open
6 tasks
@EvgeniiMekhanik
Copy link
Contributor

EvgeniiMekhanik commented Mar 5, 2024 •
edited by RomanBelozerov
Loading

This tests fails because of out of memory. I think these tests should be fixed after 498 in tempesta will be implemented.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@RomanBelozerov RomanBelozerov

@EvgeniiMekhanik EvgeniiMekhanik

Labels
bug Something isn't working
Projects
None yet
Milestone
0.9 (LA) for tests
Development

No branches or pull requests
3 participants
@krizhanovsky @RomanBelozerov @EvgeniiMekhanik