Adjust security group logging tests for possible ping delay
Less capable hardware (or CI misconfiguration, etc) may cause ping delay beyond tested time frame, which breaks the assertions since rate/burst limits are applied per second. The most delicate test is for entries over 1 second period, small time frame on purpose to target testing burst limit, therefor needed more solutions. Counter measures for robustness: 1) Adjusting the expected allowed range of log entries according to longer ping time beyond expected time frame (1s and 60s tests). 2) Retrying ping up to 5 times until duration is closer to 1s (10% expected offset allowed). 3) Last resort when both of the above failed, allowing on specific hardware up to 33% offset, only on delicate 1s test. 4) Adjusts for precision (floor/ceil and more). Signed-off-by: Maor Blaustein <mblue@redhat.com> Resolves: OSPRH-36602 Change-Id: I68cc8afc523655e9fd0cfad78b87dcecdef4f24e
This commit is contained in:
1 parent
736262947c
commit
6c50e090d6
1 file changed
+72
-20
@@ -13,8 +13,10 @@
|
||||
# License for the specific language governing permissions and limitations
|
||||
# under the License.
|
||||
|
||||
import math
|
||||
from pprint import pformat
|
||||
import random
|
||||
import re
|
||||
import socket
|
||||
import time
|
||||
|
||||
@@ -621,41 +623,91 @@ class BaseSecGroupLoggingTest(
|
||||
fetch_limit_cmd.format('burst')))
|
||||
rate_limit = int(self.master_cont_cmd_executor(
|
||||
fetch_limit_cmd.format('rate')))
|
||||
# 14) send excessive ICMP requests to VM for 1 second
|
||||
self.start_track_log(vm_a['hv_ssh_client'])
|
||||
self.validate_command(
|
||||
'sudo ping {} -i 0.002 -c 500 | tail -n4'.format(vm_a['fip']),
|
||||
pattern=r' 0% packet loss',
|
||||
local_shell=True)
|
||||
self.retrieve_tracked_log(vm_a['hv_ssh_client'])
|
||||
# 14) send excessive ICMP requests to VM for 1 second (testing burst)
|
||||
# NOTE(mblue): congestion on specific setups may delay few seconds
|
||||
# instead of 1s, optional few attempts done to get closer times to 1s
|
||||
expected_offset = 0.1
|
||||
expected_ping_duration = 1
|
||||
attempts_1s = 5
|
||||
for attempt in range(1, attempts_1s + 1):
|
||||
self.start_track_log(vm_a['hv_ssh_client'])
|
||||
ping_report = self.validate_command(
|
||||
'sudo ping {} -i 0.002 -c 500 | tail -n4'.format(vm_a['fip']),
|
||||
pattern=r' 0% packet loss',
|
||||
local_shell=True)
|
||||
# due to lots of requests and responses wait time,
|
||||
# difference beyond 1 second is possible, should be accounted for
|
||||
try:
|
||||
ping_ms = int(
|
||||
re.search(
|
||||
r'packet loss, time (\d+)ms', ping_report).group(1))
|
||||
except (TypeError, AttributeError):
|
||||
LOG.exception(
|
||||
'ms value failed to extract from ping output:\n'
|
||||
'```\n%s\n```',
|
||||
ping_report)
|
||||
ping_extra = max(0, ping_ms / 1000 - expected_ping_duration)
|
||||
self.retrieve_tracked_log(vm_a['hv_ssh_client'])
|
||||
# try reaching only 10% more time according to error offset tested
|
||||
if ping_extra < expected_offset:
|
||||
break
|
||||
if attempt == attempts_1s:
|
||||
LOG.warning(
|
||||
'Logging over 1s delayed %d times for many seconds '
|
||||
'(latest ping extra time is %.3f)',
|
||||
attempts_1s,
|
||||
ping_extra)
|
||||
# 15) verify log entries amount equals to:
|
||||
# rate limit + burst limit (up to 10% offset allowed)
|
||||
# rate limit + burst limit (up to 10% expected offset allowed)
|
||||
limits_fail_msg = "rate or burst log limits not enforced correctly"
|
||||
quick_test_target = burst_limit + rate_limit
|
||||
quick_test_target = \
|
||||
rate_limit * (expected_ping_duration + ping_extra) + burst_limit
|
||||
quick_test_logs_amount = self._hypervisors_counts[
|
||||
vm_a['hv_ssh_client'].host]['test_logs_amount']
|
||||
offset = 0.1
|
||||
# in very congested setups, last resort is allowing higher error
|
||||
# offset up to a sensible limit of 33% and only in case it is needed
|
||||
# (additionally to prior multiple attempts for short ping delay,
|
||||
# and adjusting limits to extra ping time in hindsight)
|
||||
final_offset = min(
|
||||
1 / 3,
|
||||
expected_offset if ping_extra < expected_offset else ping_extra)
|
||||
LOG.debug('final offset is %.3f', final_offset)
|
||||
self.assertIn(quick_test_logs_amount,
|
||||
range(round((1 - offset) * quick_test_target),
|
||||
round((1 + offset) * quick_test_target)),
|
||||
range(math.floor((1 - final_offset) * quick_test_target),
|
||||
math.ceil((1 + final_offset) * quick_test_target)),
|
||||
limits_fail_msg)
|
||||
# 16) send excessive ICMP requests to VM for 60 seconds
|
||||
# 16) send excessive ICMP requests to VM for 60 seconds (testing rate)
|
||||
expected_ping_duration = 60
|
||||
self.start_track_log(vm_a['hv_ssh_client'])
|
||||
self.validate_command(
|
||||
ping_report = self.validate_command(
|
||||
'sudo ping {} -i 0.005 -c 12000 | tail -n4'.format(vm_a['fip']),
|
||||
pattern=r' 0% packet loss',
|
||||
timeout=70,
|
||||
timeout=90,
|
||||
local_shell=True)
|
||||
# NOTE(mblue): due to lots of requests and their responses wait time,
|
||||
# difference beyond 60 seconds is possible, should be accounted for.
|
||||
try:
|
||||
ping_ms = int(
|
||||
re.search(
|
||||
r'packet loss, time (\d+)ms', ping_report).group(1))
|
||||
except (TypeError, AttributeError):
|
||||
LOG.exception(
|
||||
'ms value failed to extract from ping output:\n'
|
||||
'```\n%s\n```',
|
||||
ping_report)
|
||||
ping_extra = max(0, ping_ms / 1000 - expected_ping_duration)
|
||||
self.retrieve_tracked_log(vm_a['hv_ssh_client'])
|
||||
# 17) verify log entries amount equals to:
|
||||
# rate limit * 60 + burst limit (up to 5% offset allowed)
|
||||
long_test_target = rate_limit * 60 + burst_limit
|
||||
# rate limit * (60 + optional extra ping time) + burst limit
|
||||
# (up to 5% final offset allowed).
|
||||
long_test_target = \
|
||||
rate_limit * (expected_ping_duration + ping_extra) + burst_limit
|
||||
long_test_logs_amount = self._hypervisors_counts[
|
||||
vm_a['hv_ssh_client'].host]['test_logs_amount']
|
||||
offset = 0.05
|
||||
final_offset = 0.05
|
||||
self.assertIn(long_test_logs_amount,
|
||||
range(round((1 - offset) * long_test_target),
|
||||
round((1 + offset) * long_test_target)),
|
||||
range(math.floor((1 - final_offset) * long_test_target),
|
||||
math.ceil((1 + final_offset) * long_test_target)),
|
||||
limits_fail_msg)
|
||||
|
||||
self._verify_duplicate_entries(vm_a)
|
||||
|
||||
Reference in new issue
Block a user