On CI TCP segmentation.
======================================================================
FAIL: sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined
----------------------------------------------------------------------
Traceback (most recent call last):
File "/home/jenkins/workspace/Daily_tests_master/tempesta-test/sessions/test_js_challenge.py", line 511, in test_first_post_request_pipelined
client.send_request(
File "/home/jenkins/workspace/Daily_tests_master/tempesta-test/framework/deproxy_client.py", line 256, in send_request
assert expected_status_code in self.last_response.status, (
AssertionError: HTTP response status codes mismatch. Expected - 200. Received - 403
https://tempesta-tech.com:8080/job/Daily_tests_master/217/pipeline-overview/
test log
Start test 'tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined'
----------------------------------------------------------------------------------------------------
05:10:30.070 | INFO | env | remote | 233 | LocalNode(localhost) | 'echo "Start test: tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined" > /dev/kmsg'
05:10:30.073 | INFO | test | tester | 385 | | setUp 'tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined'
05:10:30.073 | INFO | env | remote | 480 | RemoteNode(192.168.122.191) | 'echo -n check'
05:10:30.083 | INFO | env | remote | 233 | LocalNode(localhost) | 'date +%s.%N'
05:10:30.088 | INFO | test | tester | 342 | | Creating Tempesta service...
05:10:30.092 | INFO | test | tester | 265 | | Creating backend service with ID='server-1' and TYPE='deproxy'.
05:10:30.092 | INFO | test | tester | 237 | | Creating client service with ID='client-1' and TYPE='deproxy'.
05:10:30.093 | INFO | test | tester | 414 | | setUp completed 'tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined'
05:10:30.094 | INFO | service | stateful | 069 | StaticDeproxyServer(127.0.0.3:8000) | Starting...
05:10:30.094 | INFO | tcp | deproxy_base | 066 | StaticDeproxyServer(127.0.0.3:8000) | Trying to bind ('127.0.0.3', 8000) for StaticDeproxyServer
05:10:30.094 | INFO | service | stateful | 076 | StaticDeproxyServer(127.0.0.3:8000) | Start completed
05:10:30.094 | INFO | env | remote | 233 | LocalNode(localhost) | 'date +%s.%N'
05:10:30.098 | INFO | service | stateful | 069 | Tempesta(localhost) | Starting...
05:10:30.098 | INFO | service | tempesta | 472 | Tempesta(localhost) | Tempesta config content:
server 127.0.0.3:8000;
listen 80;
listen 443 proto=h2;
tls_certificate /tmp/tempesta/tempesta.crt;
tls_certificate_key /tmp/tempesta/tempesta.key;
tls_match_any_server_name;
frang_limits {
http_method_override_allowed true;
http_strict_host_checking false;
}
block_action attack reply;
block_action error reply;
cache 2;
cache_methods GET HEAD POST;
cache_fulfill * *;
sticky {
cookie enforce name=cname max_misses=2;
js_challenge resp_code=503 delay_min=1000 delay_range=1500
/tmp/tempesta/js1.html;
}
05:10:30.098 | INFO | env | remote | 233 | LocalNode(localhost) | '/root/tempesta/scripts/tempesta.sh --start'
05:10:31.030 | INFO | service | stateful | 076 | Tempesta(localhost) | Start completed
05:10:31.030 | INFO | test | dmesg | 164 | | Finding pattern '\[tempesta\ fw\]\ Tempesta\ FW\ is\ ready' in dmesg.
05:10:31.030 | INFO | env | remote | 233 | LocalNode(localhost) | 'journalctl -k -o cat --since=@1770786630.097859'
05:10:31.052 | INFO | service | stateful | 069 | DeproxyManager() | Starting...
05:10:31.053 | INFO | service | stateful | 076 | DeproxyManager() | Start completed
05:10:31.060 | INFO | service | stateful | 069 | DeproxyClient(127.0.0.2:80) | Starting...
05:10:31.061 | INFO | tcp | deproxy_base | 066 | DeproxyClient(127.0.0.2:80) | Trying to bind ('127.0.0.2', 0) for DeproxyClient
05:10:31.061 | INFO | tcp | deproxy_client | 247 | DeproxyClient(127.0.0.2:80) | Trying to connect to 127.0.0.1:80.
05:10:31.062 | INFO | service | stateful | 076 | DeproxyClient(127.0.0.2:80) | Start completed
05:10:31.062 | INFO | dap | deproxy_auto_parser | 132 | DeproxyAutoParser() | Prepare expected request
05:10:31.062 | INFO | dap | deproxy_auto_parser | 247 | DeproxyAutoParser() | Remove hop-by-hop headers from expected response/request
05:10:31.062 | INFO | dap | deproxy_auto_parser | 132 | DeproxyAutoParser() | Prepare expected request
05:10:31.063 | INFO | dap | deproxy_auto_parser | 247 | DeproxyAutoParser() | Remove hop-by-hop headers from expected response/request
05:10:31.071 | INFO | http | deproxy_client | 343 | DeproxyClient(127.0.0.2:80) | A response was receive. The response status=403. The current number of responses - 1.
05:10:31.072 | INFO | dap | deproxy_auto_parser | 127 | DeproxyAutoParser() | Received response is not checked because the expected response was not generated.
05:10:31.076 | INFO | http | deproxy_client | 178 | DeproxyClient(127.0.0.2:80) | A request was send. The current number of a request - 1
05:10:31.113 | INFO | http | deproxy_client | 343 | DeproxyClient(127.0.0.2:80) | A response was receive. The response status=503. The current number of responses - 2.
05:10:31.113 | INFO | dap | deproxy_auto_parser | 127 | DeproxyAutoParser() | Received response is not checked because the expected response was not generated.
05:10:33.316 | INFO | dap | deproxy_auto_parser | 132 | DeproxyAutoParser() | Prepare expected request
05:10:33.316 | INFO | dap | deproxy_auto_parser | 247 | DeproxyAutoParser() | Remove hop-by-hop headers from expected response/request
05:10:33.326 | INFO | http | deproxy_client | 178 | DeproxyClient(127.0.0.2:80) | A request was send. The current number of a request - 2
05:10:33.361 | INFO | http | deproxy_client | 343 | DeproxyClient(127.0.0.2:80) | A response was receive. The response status=403. The current number of responses - 3.
05:10:33.361 | INFO | dap | deproxy_auto_parser | 127 | DeproxyAutoParser() | Received response is not checked because the expected response was not generated.
05:10:33.367 | INFO | test | tester | 417 | | Cleanup: stopping all services...
05:10:33.367 | INFO | service | stateful | 093 | DeproxyClient(127.0.0.2:80) | Stopping...
05:10:33.367 | INFO | service | stateful | 081 | DeproxyClient(127.0.0.2:80) | Stop procedures list: ['__stop']
05:10:33.367 | INFO | service | stateful | 098 | DeproxyClient(127.0.0.2:80) | Stop completed
05:10:33.367 | INFO | service | stateful | 093 | Tempesta(localhost) | Stopping...
05:10:33.367 | INFO | service | stateful | 081 | Tempesta(localhost) | Stop procedures list: ['stop_tempesta', 'remove_config_files', 'drop_access_log_table']
05:10:33.367 | INFO | env | remote | 233 | LocalNode(localhost) | '/root/tempesta/scripts/tempesta.sh --stop'
05:10:33.950 | INFO | service | stateful | 098 | Tempesta(localhost) | Stop completed
05:10:33.950 | INFO | service | stateful | 093 | StaticDeproxyServer(127.0.0.3:8000) | Stopping...
05:10:33.950 | INFO | service | stateful | 081 | StaticDeproxyServer(127.0.0.3:8000) | Stop procedures list: ['__stop']
05:10:33.951 | INFO | service | stateful | 098 | StaticDeproxyServer(127.0.0.3:8000) | Stop completed
05:10:33.951 | INFO | service | stateful | 093 | DeproxyManager() | Stopping...
05:10:33.951 | INFO | service | stateful | 081 | DeproxyManager() | Stop procedures list: ['__stop']
05:10:33.952 | INFO | service | stateful | 098 | DeproxyManager() | Stop completed
05:10:33.952 | INFO | test | tester | 428 | | Cleanup: all services are stopped.
05:10:33.952 | INFO | test | tester | 434 | | Cleanup: finish all deproxy sockets...
05:10:33.952 | INFO | test | tester | 440 | | Cleanup: all deproxy sockets are closed.
05:10:33.952 | INFO | test | tester | 443 | | Cleanup: Removing interfaces
05:10:33.952 | INFO | env | remote | 233 | LocalNode(localhost) | 'LANG=C ip route get to 127.0.0.1 | grep -o 'dev [a-zA-Z0-9_-]*''
05:10:33.957 | INFO | env | remote | 233 | LocalNode(localhost) | 'ip -6 addr show dev lo'
05:10:33.961 | INFO | env | remote | 233 | LocalNode(localhost) | 'LANG=C ip addr show lo |grep -o 'mtu [0-9]*''
05:10:33.965 | INFO | env | remote | 233 | LocalNode(localhost) | 'sysctl --values net.ipv4.route.mtu_expires'
05:10:33.968 | INFO | env | remote | 233 | LocalNode(localhost) | 'sysctl --values net.ipv4.ip_no_pmtu_disc'
05:10:33.972 | INFO | env | remote | 233 | LocalNode(localhost) | 'ethtool --show-features lo | grep tcp-segmentation-offload'
05:10:33.976 | INFO | env | remote | 233 | LocalNode(localhost) | 'ethtool --show-features lo | grep generic-receive-offload'
05:10:33.979 | INFO | env | remote | 233 | LocalNode(localhost) | 'ethtool --show-features lo | grep generic-segmentation-offload'
05:10:33.984 | INFO | test | tester | 450 | | Cleanup: stopping tcpdump
05:10:33.984 | INFO | test | tester | 454 | | Cleanup: checking dmesg
05:10:33.984 | INFO | env | remote | 233 | LocalNode(localhost) | 'journalctl -k -o cat --since=@1770786630.088006'
05:10:34.006 | INFO | test | tester | 457 | |
----------------------dmesg---------------------
[tempesta sc] OS configuration or hardware is not suitable/ (Total 1 errors)
[tempesta sc] 1. The minimal amount of RAM required by Tempesta is 8192 MB, but you have 7433 MB
[tempesta sc] Kernel config params are missing or have different values. Please, check configuration of `/boot/config-6.12.12.tfw-4ef6f26`/ (Total 2 errors)
[tempesta sc] 1. `CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC_VALUE={'1'}` is not defined.
[tempesta sc] 2. `CONFIG_BOOTPARAM_HARDLOCKUP_PANIC_VALUE={'1'}` is not defined.
[tempesta sc] Sysctl config params are missing or have different values. Please, check configuration of `/etc/sysctl.conf`/ (Total 1 errors)
[tempesta sc] 1. `kernel.softlockup_panic={'1'}` is not defined.
[tempesta sc] Verification passed with errors!
[tempesta sc] Skipped Netconsole configuration and Support Server connection
[tdb] Start Tempesta DB
[tempesta fw] Initializing Tempesta FW kernel module...
[tempesta fw] Warning: Vhost default doesn't have certificate with matching SAN/CN.
Maybe that's fine, but it's worth checking the
config - if there is no relations between the
names, then host name confusion attack is possible.
[tempesta fw] http_sess: JavaScript challenge requires enforced sticky cookie mode
[tempesta fw] Configuration processing is completed.
[tdb] Opened table /opt/tempesta/db/filter0.tdb: size=16777216 rec_size=32 base=00000000a91b2f77
[tdb] Opened table /opt/tempesta/db/cache0.tdb: size=268435456 rec_size=0 base=00000000c70453d7
[tdb] Opened table /opt/tempesta/db/sessions0.tdb: size=16777216 rec_size=312 base=000000005fee9d2f
[tdb] Opened table /opt/tempesta/db/client0.tdb: size=16777216 rec_size=608 base=000000002ac7c808
[tempesta fw] Open listen socket on: 0.0.0.0:443
[tempesta fw] Open listen socket on: 0.0.0.0
[tempesta fw] Tempesta FW is ready
[tempesta fw] Warning: http_sess: jsch redirect received too early for 127.0.0.2 (4305528252 is not after 4305528253)
[tdb] Close table 'client0.tdb'
[tdb] Close table 'sessions0.tdb'
[tdb] Close table 'cache0.tdb'
[tdb] Close table 'filter0.tdb'
[tempesta fw] modules are stopped
[tempesta fw] exiting...
[tdb] Shutdown Tempesta DB
-------------------end dmesg--------------------
05:10:34.007 | INFO | test | tester | 481 | | Cleanup: Check exceptions in the deproxy auto parser.
05:10:34.007 | INFO | test | tester | 476 | | Cleanup: Cleanup the deproxy auto parser.
05:10:34.009 | INFO | env | remote | 233 | LocalNode(localhost) | 'echo "End test: tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined" > /dev/kmsg'
05:10:34.012 | INFO | test | shell | 188 | |
----------------------------------------------------------------------------------------------------
End test 'tests.sessions.test_js_challenge.JSChallengeHttp.test_first_post_request_pipelined'
tempesta-test - 8f17ce7
tempesta - 7bc2ff4660a0430c69972d03be187e925f84a5d6
On CI TCP segmentation.
https://tempesta-tech.com:8080/job/Daily_tests_master/217/pipeline-overview/
test log
tempesta-test - 8f17ce7
tempesta - 7bc2ff4660a0430c69972d03be187e925f84a5d6