def setUp(self):
self._fake_clock = FakeClock()
self._test_state = {
'count': 0,
'times': [],
}
self._test_state_lock = threading.Lock()
self._outcome_generator_lock = threading.Lock()
def setUp(self):
super(BlockingRateLimiterTest, self).setUp()
self._fake_clock = FakeClock()
self._test_state = {
'count': 0,
'times': [],
}
self._test_state_lock = threading.Lock()
self._outcome_generator_lock = threading.Lock()
def __init__(self):
self.__processor = FakeProcessor()
self.__pod_cache = _K8sCache(self.__processor, "Pod")
self.wait_timeout = 5
self.k8s = FakeK8s(wait_timeout=self.wait_timeout)
self.__clock = FakeClock()
def run_test():
manager_poll_interval = 30
fake_clock = FakeClock()
monitors_manager, config = ScalyrTestUtils.create_test_monitors_manager(
config_monitors=[{
'module':
"scalyr_agent.builtin_monitors.kubernetes_monitor",
}],
extra_toplevel_config={
'user_agent_refresh_interval': manager_poll_interval
},
null_logger=True,
fake_clock=fake_clock,
)
copying_manager = CopyingManager(config, monitors_manager.monitors)
def run_test():
manager_poll_interval = 30
fake_clock = FakeClock()
monitors_manager, config = ScalyrTestUtils.create_test_monitors_manager(
config_monitors=[{
"module":
"scalyr_agent.builtin_monitors.kubernetes_monitor"
}],
extra_toplevel_config={
"user_agent_refresh_interval": manager_poll_interval
},
null_logger=True,
fake_clock=fake_clock,
)
copying_manager = CopyingManager(config, monitors_manager.monitors)
self.assertEquals(
copying_manager._CopyingManager__expanded_server_attributes.
get("_k8s_ver"),
"star",
)
class BlockingRateLimiterTest(ScalyrTestCase):
def setUp(self):
super(BlockingRateLimiterTest, self).setUp()
self._fake_clock = FakeClock()
self._test_state = {
'count': 0,
'times': [],
}
self._test_state_lock = threading.Lock()
self._outcome_generator_lock = threading.Lock()
def test_init_exceptions(self):
BRL = BlockingRateLimiter
# strategy must be restricted to proper values
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=100,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=5,
strategy='bad strategy',
))
# max_concurrency must be 1 or more
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=100,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=5,
max_concurrency=0,
))
# consecutive_success_threshold must be a positive int
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=100,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=-5.0,
))
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=100,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=99.99,
))
# user-supplied init must be between user-supplied min/max
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=0.7,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=5,
))
self.assertRaises(
ValueError, lambda: BRL(
num_agents=1,
initial_cluster_rate=7777,
max_cluster_rate=1000,
min_cluster_rate=1,
consecutive_success_threshold=5,
))
def test_lazy_adjust_min_max_init_rates(self):
"""Tests the one-time lazy adjustments"""
# Make sure proper adjustments are made if out of bounds
BRL = BlockingRateLimiter
rl = BRL(
num_agents=1,
initial_cluster_rate=BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE + 1000,
max_cluster_rate=BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE + 2000000,
min_cluster_rate=float(BRL.HARD_LIMIT_MIN_CLUSTER_RATE) / 10,
consecutive_success_threshold=5,
)
rl._lazy_adjust_min_max_rates()
self.assertEqual(rl._initial_cluster_rate,
BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE)
self.assertEqual(rl._max_cluster_rate,
BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE + 2000000)
self.assertEqual(rl._min_cluster_rate, BRL.HARD_LIMIT_MIN_CLUSTER_RATE)
# Make sure adjustments are NOT made if within bounds
rl = BRL(
num_agents=1,
initial_cluster_rate=BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE - 1,
max_cluster_rate=BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE - 1,
min_cluster_rate=float(BRL.HARD_LIMIT_MIN_CLUSTER_RATE) + 1,
consecutive_success_threshold=5,
)
rl._lazy_adjust_min_max_rates()
self.assertEqual(rl._initial_cluster_rate,
BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE - 1)
self.assertEqual(rl._max_cluster_rate,
BRL.HARD_LIMIT_INITIAL_CLUSTER_RATE + -1)
self.assertEqual(rl._min_cluster_rate,
BRL.HARD_LIMIT_MIN_CLUSTER_RATE + 1)
# Init rate cannot be lower than min rate
rl = BlockingRateLimiter(
num_agents=1,
initial_cluster_rate=0.1,
max_cluster_rate=1000,
min_cluster_rate=0,
consecutive_success_threshold=5,
)
rl._lazy_adjust_min_max_rates()
self.assertEqual(rl._initial_cluster_rate, 1)
def __create_consumer_threads(self, num_threads, rate_limiter,
experiment_end_time,
reported_outcome_generator):
"""
Create a list of client thread that will consume from the rate limiter.
@param num_threads: Number of client threads
@param rate_limiter: The rate limiter to test
@param experiment_end_time: consumer threads terminate their loops when the fake clock has exceeded this.
@param reported_outcome_generator: Generator to get reported outcome boolean value
@type rate_limiter: BlockingRateLimiter
@type threads: iterable of Thread objects
@type experiment_end_time: int (utc seconds)
@type reported_outcome_generator: generator
@returns: list of consumer threads
@rtype: list(Thread)
"""
def consume_token_blocking():
"""consumer threads will keep acquiring tokens until experiment end time"""
while self._fake_clock.time() < experiment_end_time:
# A simple loop that acquires token, updates a counter, then releases token with an outcome
# provided by reported_outcome_generator()
t1 = self._fake_clock.time()
token = rate_limiter.acquire_token()
# update test state
self._test_state_lock.acquire()
try:
self._test_state['count'] += 1
self._test_state['times'].append(int(t1))
finally:
self._test_state_lock.release()
self._outcome_generator_lock.acquire()
try:
outcome = reported_outcome_generator.next()
rate_limiter.release_token(token, outcome)
finally:
self._outcome_generator_lock.release()
return [
threading.Thread(target=consume_token_blocking)
for _ in range(num_threads)
]
def __create_fake_clock_advancer_thread(self, rate_limiter,
consumer_threads):
"""
Run a separate thread that advances time in order to allow rate_limiter to release tokens
@param rate_limiter: The rate limiter to test
@param consumer_threads: Other threads that are consumers of the Rate Limiter. The advancer thread will run
for as long as the consumer threads continue to run.
@type rate_limiter: BlockingRateLimiter
@type consumer_threads: iterable of Thread objects
@returns: Thread object
@rtype: Thread
"""
class FakeClockAdvancerThread(StoppableThread):
def __init__(self2):
StoppableThread.__init__(self2,
name='FakeClockAdvancerThread',
is_daemon=True)
def run_and_propagate(self2):
at_least_one_client_thread_incomplete = True
while at_least_one_client_thread_incomplete:
# All client threads are likely blocking on the token queue at this point
# The experiment will never start until at least one token is granted (and waiting threads notified)
# To jump start this, simply advance fake clock to the ripe_time.
delta = rate_limiter._ripe_time - self._fake_clock.time()
self._fake_clock.advance_time(increment_by=delta)
# Wake up after 1 second just in case and trigger another advance
[t.join(1) for t in consumer_threads]
at_least_one_client_thread_incomplete = False
for t in consumer_threads:
if t.isAlive():
at_least_one_client_thread_incomplete = True
break
return FakeClockAdvancerThread()
def test_rate_adjustment_logic(self):
"""Make sure rate adjustments work according to spec
The cases we test are:
1. All successes. Actual rate is very high. New target rate is always increase_factor * current target rate.
2. All successes. Actual rate is very low. New target rate is always increase_factor * actual rate,
(but no lower than current rate).
3. All failures. Actual rate is very low. New target rate is always backoff_factor * current target rate.
4. All failures. Actual rate is very high. New target rate is always backoff_factor * actual rate.
(but no higher than current rate).
"""
required_successes = 5
max_cluster_rate = 10000
min_cluster_rate = 1
initial_cluster_rate = 100
increase_factor = 2.0
backoff_factor = 0.5
def _create_rate_limiter():
return BlockingRateLimiter(
num_agents=1,
initial_cluster_rate=initial_cluster_rate,
max_cluster_rate=max_cluster_rate,
min_cluster_rate=min_cluster_rate,
consecutive_success_threshold=required_successes,
strategy=BlockingRateLimiter.STRATEGY_MULTIPLY,
increase_factor=increase_factor,
backoff_factor=backoff_factor,
max_concurrency=1,
fake_clock=self._fake_clock)
def _mock_get_next_ripe_time_actual_rate_leads(rate_limiter):
# Make the rate limiter grant tokens faster than the target rate
def _func(*args, **kwargs):
delta = 1.0 / rate_limiter._current_cluster_rate
return rl._ripe_time + 0.9 * delta
return _func
def _mock_get_next_ripe_time_actual_rate_lags(rate_limiter):
# Make the rate limiter grant tokens slower than the target rate
def _func(*args, **kwargs):
delta = 1.0 / rate_limiter._current_cluster_rate
return rl._ripe_time + 1.1 * delta
return _func
rl = _create_rate_limiter()
@patch.object(rl, '_get_next_ripe_time')
def _case1_test_successes_actual_rate_leads_target_rate(
mock_get_next_ripe_time):
"""Examine rate-increasing behavior in the context of very high actual rates"""
mock_get_next_ripe_time.side_effect = _mock_get_next_ripe_time_actual_rate_leads(
rl)
advancer = self.__create_fake_clock_advancer_thread(
rl, [threading.currentThread()])
advancer.start()
while True:
token = rl.acquire_token()
for x in range(required_successes - 1):
rl.release_token(token, True)
rl.acquire_token()
# Actual rate always leads target rate
old_target_rate = rl._current_cluster_rate
old_actual_rate = rl._get_actual_cluster_rate()
self.assertGreater(old_actual_rate, old_target_rate)
# Token grant causes new rate to be calculated
rl.release_token(token, True)
# assert that the new rate is calculated based on the (lower/more conservative) target rate
if increase_factor * old_target_rate < max_cluster_rate:
self.assertEqual(rl._current_cluster_rate,
increase_factor * old_target_rate)
else:
# assert that new rate never exceeds max rate
self.assertEqual(rl._current_cluster_rate,
max_cluster_rate)
break
advancer.stop(wait_on_join=False)
_case1_test_successes_actual_rate_leads_target_rate()
rl = _create_rate_limiter()
@patch.object(rl, '_get_next_ripe_time')
def _case2_test_successes_actual_rate_lags_target_rate(
mock_get_next_ripe_time):
"""Examine rate-increasing behavior in the context of very high actual rates"""
mock_get_next_ripe_time.side_effect = _mock_get_next_ripe_time_actual_rate_lags(
rl)
advancer = self.__create_fake_clock_advancer_thread(
rl, [threading.currentThread()])
advancer.start()
while True:
token = rl.acquire_token()
for x in range(required_successes - 1):
rl.release_token(token, True)
rl.acquire_token()
# Actual rate always lags target rate
old_target_rate = rl._current_cluster_rate
old_actual_rate = rl._get_actual_cluster_rate()
self.assertLess(old_actual_rate, old_target_rate)
# Token grant causes new rate to be calculated
rl.release_token(token, True)
# assert that the new rate is calculated based on the (lower/more conservative) actual rate
if increase_factor * old_actual_rate < max_cluster_rate:
if increase_factor * old_actual_rate < old_target_rate:
self.assertEqual(round(rl._current_cluster_rate, 2),
round(old_target_rate, 2))
else:
self.assertEqual(
round(rl._current_cluster_rate, 2),
round(increase_factor * old_actual_rate, 2))
else:
# assert that new rate never exceeds max rate
self.assertEqual(rl._current_cluster_rate,
max_cluster_rate)
break
advancer.stop(wait_on_join=False)
_case2_test_successes_actual_rate_lags_target_rate()
rl = _create_rate_limiter()
@patch.object(rl, '_get_next_ripe_time')
def _case3_test_failures_actual_rate_lags_target_rate(
mock_get_next_ripe_time):
"""Examine rate-decreasing behavior in the context of very high actual rates"""
mock_get_next_ripe_time.side_effect = _mock_get_next_ripe_time_actual_rate_lags(
rl)
advancer = self.__create_fake_clock_advancer_thread(
rl, [threading.currentThread()])
advancer.start()
counter = 0
while True:
token = rl.acquire_token()
# Actual rate always lags target rate
old_target_rate = rl._current_cluster_rate
old_actual_rate = rl._get_actual_cluster_rate()
if old_actual_rate is not None:
self.assertLess(old_actual_rate, old_target_rate)
# Token grant a 100 initial successes followed by all failures
counter += 1
if counter <= required_successes:
rl.release_token(token, True)
continue
else:
rl.release_token(token, False)
# assert that the new rate is calculated based on the (higher/more conservative) target rate
if backoff_factor * old_target_rate > min_cluster_rate:
self.assertEqual(
round(rl._current_cluster_rate, 2),
round(backoff_factor * old_target_rate, 2))
else:
# assert that new rate never goes lower than min rate
self.assertEqual(round(rl._current_cluster_rate, 2),
round(min_cluster_rate, 2))
break
advancer.stop(wait_on_join=False)
_case3_test_failures_actual_rate_lags_target_rate()
rl = _create_rate_limiter()
@patch.object(rl, '_get_next_ripe_time')
def _case4_test_failures_actual_rate_leads_target_rate(
mock_get_next_ripe_time):
"""Examine rate-decreasing behavior in the context of very high actual rates"""
mock_get_next_ripe_time.side_effect = _mock_get_next_ripe_time_actual_rate_leads(
rl)
advancer = self.__create_fake_clock_advancer_thread(
rl, [threading.currentThread()])
advancer.start()
counter = 0
while True:
token = rl.acquire_token()
# Actual rate is always None because
old_target_rate = rl._current_cluster_rate
old_actual_rate = rl._get_actual_cluster_rate()
if old_actual_rate is not None:
self.assertGreater(old_actual_rate, old_target_rate)
# Token grant a 100 initial successes followed by all failures
counter += 1
if counter <= required_successes:
rl.release_token(token, True)
continue
else:
rl.release_token(token, False)
# assert that the new rate is calculated based on the (higher/more conservative) actual rate
if backoff_factor * old_target_rate > min_cluster_rate:
self.assertEqual(
round(rl._current_cluster_rate, 2),
round(backoff_factor * old_target_rate, 2))
else:
# assert that new rate never goes lower than min rate
self.assertEqual(rl._current_cluster_rate,
min_cluster_rate)
break
advancer.stop(wait_on_join=False)
_case4_test_failures_actual_rate_leads_target_rate()
def test_fixed_rate_single_concurrency(self):
"""Longer experiment"""
# 1 rps x 1000 simulated seconds => 1000 increments
self._test_fixed_rate(desired_agent_rate=1.0,
experiment_duration=10000,
concurrency=1,
expected_requests=10000,
allowed_variance=(0.95, 1.05))
def test_fixed_rate_multiple_concurrency(self):
"""Multiple clients should not affect overall rate"""
# 1 rps x 100 simulated seconds => 100 increments
# Higher concurrency has more variance
self._test_fixed_rate(desired_agent_rate=1.0,
experiment_duration=10000,
concurrency=3,
expected_requests=10000,
allowed_variance=(0.8, 1.2))
def _test_fixed_rate(self, desired_agent_rate, experiment_duration,
concurrency, expected_requests, allowed_variance):
"""A utility pass-through that fixes the initial, upper and lower rates"""
num_agents = 1000
cluster_rate = num_agents * desired_agent_rate
self._test_rate_limiter(num_agents=num_agents,
initial_cluster_rate=cluster_rate,
max_cluster_rate=cluster_rate,
min_cluster_rate=cluster_rate,
consecutive_success_threshold=5,
experiment_duration=experiment_duration,
max_concurrency=concurrency,
expected_requests=expected_requests,
allowed_variance=allowed_variance)
def test_variable_rate_single_concurrency_all_successes(self):
"""Rate should quickly max out at max_cluster_rate"""
# Test variables
initial_agent_rate = 1
experiment_duration = 1000
concurrency = 1
max_rate_multiplier = 10
# Expected behavior (saturates at upper rate given all successes)
expected_requests = max_rate_multiplier * experiment_duration
allowed_variance = (0.8, 1.2)
# Derived values
num_agents = 10
initial_cluster_rate = num_agents * initial_agent_rate
max_cluster_rate = max_rate_multiplier * initial_cluster_rate
self._test_rate_limiter(
num_agents=10,
initial_cluster_rate=initial_cluster_rate,
max_cluster_rate=max_cluster_rate,
min_cluster_rate=0,
experiment_duration=experiment_duration,
max_concurrency=concurrency,
consecutive_success_threshold=5,
increase_strategy=BlockingRateLimiter.STRATEGY_RESET_THEN_MULTIPLY,
expected_requests=expected_requests,
allowed_variance=allowed_variance,
)
def test_variable_rate_single_concurrency_all_failures(self):
"""Rate should quickly decrease to min_cluster_rate"""
# temporarily disable hard lower limit as it is irrelevant to this test and we want to let it go down to really
# low numbers to gather enough data.
orig_hard_limit = BlockingRateLimiter.HARD_LIMIT_MIN_CLUSTER_RATE
BlockingRateLimiter.HARD_LIMIT_MIN_CLUSTER_RATE = -float('inf')
# Test variables
initial_agent_rate = 1
experiment_duration = 1000000
concurrency = 1
min_rate_multiplier = 0.01 # min rate should be at least an order of magnitude lower than initial rate.
# Expected behavior
expected_requests = min_rate_multiplier * experiment_duration
allowed_variance = (0.8, 1.2)
# Derived values
num_agents = 10
initial_cluster_rate = num_agents * initial_agent_rate
max_cluster_rate = initial_cluster_rate
min_cluster_rate = min_rate_multiplier * initial_cluster_rate
self._test_rate_limiter(
num_agents=num_agents,
initial_cluster_rate=initial_cluster_rate,
max_cluster_rate=max_cluster_rate,
min_cluster_rate=min_cluster_rate,
experiment_duration=experiment_duration,
max_concurrency=concurrency,
consecutive_success_threshold=5,
increase_strategy=BlockingRateLimiter.STRATEGY_RESET_THEN_MULTIPLY,
expected_requests=expected_requests,
allowed_variance=allowed_variance,
reported_outcome_generator=always_false(),
)
# Restore the min hard limit
BlockingRateLimiter.HARD_LIMIT_MIN_CLUSTER_RATE = orig_hard_limit
def test_variable_rate_single_concurrency_push_pull(self):
"""Rate should fluctuate closely around initial rate because of equal successes/failures"""
# Test variables
initial_agent_rate = 1
experiment_duration = 10000
concurrency = 1
min_rate_multiplier = 0.1
max_rate_multiplier = 10
consecutive_success_threshold = 5
backoff_factor = 0.5
increase_factor = 2.0
# Expected behavior
# 1 * 1 rps * 100s
expected_requests = 1 * experiment_duration
allowed_variance = (
0.8, 1.2
) # variance increases as difference between backoffs increase
# Derived values
num_agents = 100
initial_cluster_rate = num_agents * initial_agent_rate
self._test_rate_limiter(
num_agents=num_agents,
initial_cluster_rate=initial_cluster_rate,
max_cluster_rate=max_rate_multiplier * initial_cluster_rate,
min_cluster_rate=min_rate_multiplier * initial_cluster_rate,
experiment_duration=experiment_duration,
max_concurrency=concurrency,
consecutive_success_threshold=consecutive_success_threshold,
increase_strategy=BlockingRateLimiter.STRATEGY_RESET_THEN_MULTIPLY,
expected_requests=expected_requests,
allowed_variance=allowed_variance,
reported_outcome_generator=rate_maintainer(
consecutive_success_threshold, backoff_factor,
increase_factor),
backoff_factor=backoff_factor,
increase_factor=increase_factor,
)
def _test_rate_limiter(
self,
num_agents,
consecutive_success_threshold,
initial_cluster_rate,
max_cluster_rate,
min_cluster_rate,
experiment_duration,
max_concurrency,
expected_requests,
allowed_variance,
reported_outcome_generator=always_true(),
increase_strategy=BlockingRateLimiter.STRATEGY_MULTIPLY,
backoff_factor=0.5,
increase_factor=2.0,
):
"""Main test logic that runs max_concurrency client threads for a defined experiment duration.
The experiment is driven off a fake_clock (so it can complete in seconds, not minutes or hours).
Each time a successful acquire() completes, a counter is incremented. At experiment end, this counter
should be close enough to a calculated expected value, based on the specified rate.
Concurrency should not affect the overall rate of allowed acquisitions.
The reported outcome by acquiring clients is determined by invoking the callable `reported_outcome_callable`.
@param num_agents: Num agents in cluster (to derive agent rate from cluster rate)
@param consecutive_success_threshold:
@param initial_cluster_rate: Initial cluster rate
@param max_cluster_rate: Upper bound on cluster rate
@param min_cluster_rate: Lower bound on cluster rate
@param increase_strategy: Strategy for increasing rate
@param experiment_duration: Experiment duration in seconds
@param max_concurrency: Number of tokens to create
@param expected_requests: Expected number of requests at the end of experiment
@param allowed_variance: Allowed variance between expected and actual number of requests. (e.g. 0.1 = 10%)
@param reported_outcome_generator: Generator to get reported outcome boolean value
@param fake_clock_increment: Fake clock increment by (seconds)
"""
rate_limiter = BlockingRateLimiter(
num_agents=num_agents,
initial_cluster_rate=initial_cluster_rate,
max_cluster_rate=max_cluster_rate,
min_cluster_rate=min_cluster_rate,
consecutive_success_threshold=consecutive_success_threshold,
strategy=increase_strategy,
increase_factor=increase_factor,
backoff_factor=backoff_factor,
max_concurrency=max_concurrency,
fake_clock=self._fake_clock,
)
# Create and start a list of consumer threads
experiment_end_time = self._fake_clock.time() + experiment_duration
threads = self.__create_consumer_threads(max_concurrency, rate_limiter,
experiment_end_time,
reported_outcome_generator)
[t.setDaemon(True) for t in threads]
[t.start() for t in threads]
# Create and join and advancer thread (which in turn lasts until all client threads die
advancer = self.__create_fake_clock_advancer_thread(
rate_limiter, threads)
advancer.start()
advancer.join()
requests = self._test_state['count']
# Assert that count is close enough to the expected count
observed_ratio = float(requests) / expected_requests
self.assertGreater(observed_ratio, allowed_variance[0])
self.assertLess(observed_ratio, allowed_variance[1])
def test_user_agent_fragment(self, mocked_docker):
def fake_init(self):
"""Simulate syslog mode (null container checker). Init the version variable and it's lock"""
self._DockerMonitor__container_checker = None
self._DockerMonitor__version_lock = threading.RLock()
self._DockerMonitor__version = None
with mock.patch.object(DockerMonitor, "_initialize", fake_init):
manager_poll_interval = 30
fake_clock = FakeClock()
manager, _ = ScalyrTestUtils.create_test_monitors_manager(
config_monitors=[{
"module": "scalyr_agent.builtin_monitors.docker_monitor",
"log_mode": "syslog",
}],
extra_toplevel_config={
"user_agent_refresh_interval": manager_poll_interval
},
null_logger=True,
fake_clock=fake_clock,
)
fragment_polls = FakeClockCounter(fake_clock, num_waiters=2)
counter = {"callback_invocations": 0}
detected_fragment_changes = []
# Mock the callback (that would normally be invoked on ScalyrClientSession
def augment_user_agent(fragments):
counter["callback_invocations"] += 1
detected_fragment_changes.append(fragments[0])
# Decorate the get_user_agent_fragment() function as follows:
# Each invocation increments the FakeClockCounter
# Simulate the following race condition:
# 1. The first 10 polls by MonitorsManager is such that DockerMonitor has not yet started. Therefore,
# the docker version is None
# 2. After the 20th poll, docker version is set
# 3. After the 30th poll, docker mode changes to docker_api|raw
# 4. After the 40th poll, docker mode changes to docker_api|api
#
# Note: (3) and (4) do not happen in real life. We force these config changes to test permutations
# of user agent fragments for different config scenarios
#
# Total number of times the user_agent_callback is called should be twice:
# - once for when docker version is None (fragment is 'docker=true')
# - once for when docker version changes to a real number
fake_docker_version = "18.09.2"
docker_mon = manager.monitors[0]
original_get_user_agent_fragment = docker_mon.get_user_agent_fragment
original_monitor_config_get = docker_mon._config.get
def fake_get_user_agent_fragment():
result = original_get_user_agent_fragment()
fragment_polls.increment()
return result
def fake_fetch_and_set_version():
# Simulate slow-to-start DockerMonitor where version is set only after 10th poll by MonitorsManager
# Thus, polls 0-9 return in version=None which ultimately translates to 'docker=true' fragment
docker_mon._DockerMonitor__version_lock.acquire()
try:
if fragment_polls.count() < 10:
docker_mon._DockerMonitor__version = None
else:
docker_mon._DockerMonitor__version = fake_docker_version
finally:
docker_mon._DockerMonitor__version_lock.release()
def fake_monitor_config_get(key):
# Fake the return values from MonitorConfig.get in order to exercise different permutations of
# user_agent fragment.
if key == "log_mode":
if fragment_polls.count() < 20:
return "syslog"
else:
return "docker_api"
elif key == "docker_raw_logs":
if fragment_polls.count() < 30:
return True
else:
return False
else:
return original_monitor_config_get(key)
@patch.object(docker_mon, "get_user_agent_fragment")
@patch.object(docker_mon, "_fetch_and_set_version")
@patch.object(docker_mon._config, "get")
def start_test(m3, m2, m1):
m1.side_effect = fake_get_user_agent_fragment
m2.side_effect = fake_fetch_and_set_version
m3.side_effect = fake_monitor_config_get
manager.set_user_agent_augment_callback(augment_user_agent)
manager.start_manager()
fragment_polls.sleep_until_count_or_maxwait(
40, manager_poll_interval, maxwait=1)
m1.assert_called()
m2.assert_called()
m3.assert_called()
self.assertEquals(fragment_polls.count(), 40)
self.assertEquals(counter["callback_invocations"], 4)
self.assertEquals(
detected_fragment_changes,
[
"docker=true",
"docker=18.09.2|syslog",
"docker=18.09.2|docker_api|raw",
"docker=18.09.2|docker_api|api",
],
)
manager.stop_manager(wait_on_join=False)
fake_clock.advance_time(increment_by=manager_poll_interval)
start_test()
def test_write_to_disk_extra_detect_escaped_strings(self, verify):
fake_journal = {
"_AUDIT_LOGINUID":
1000,
"_CAP_EFFECTIVE":
"0",
"_SELINUX_CONTEXT":
"unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023",
"_GID":
1000,
"CODE_LINE":
1,
"_HOSTNAME":
"...",
"_SYSTEMD_SESSION":
52,
"_SYSTEMD_OWNER_UID":
1000,
"MESSAGE":
'"testing 1,2,3 "test""',
# '__MONOTONIC_TIMESTAMP':
# journal.Monotonic(timestamp=datetime.timedelta(2, 76200, 811585), bootid=UUID('958b7e26-df4c-453a-a0f9-a8406cb508f2')),
"SYSLOG_IDENTIFIER":
"python3",
"_UID":
1000,
"_EXE":
"/usr/bin/python3",
"_PID":
7733,
"_COMM":
"...",
"CODE_FUNC":
"<module>",
"CODE_FILE":
"<doctest journal.rst[4]>",
"_SOURCE_REALTIME_TIMESTAMP":
datetime.datetime(2015, 9, 5, 13, 17, 4, 944355),
# '__CURSOR': 's=...',
"_BOOT_ID":
UUID("958b7e26-df4c-453a-a0f9-a8406cb508f2"),
"_CMDLINE":
"/usr/bin/python3 ...",
"_MACHINE_ID":
UUID("263bb31e-3e13-4062-9bdb-f1f4518999d2"),
"_SYSTEMD_SLICE":
"user-1000.slice",
"_AUDIT_SESSION":
52,
"__REALTIME_TIMESTAMP":
datetime.datetime(2015, 9, 5, 13, 17, 4, 945110),
"_SYSTEMD_UNIT":
"session-52.scope",
"_SYSTEMD_CGROUP":
"/user.slice/user-1000.slice/session-52.scope",
"_TRANSPORT":
'"journal"',
}
def fake_pending_entries(self):
self._journal = [fake_journal]
return True
with mock.patch.object(JournaldMonitor, "_has_pending_entries",
fake_pending_entries):
journal_directory = tempfile.mkdtemp(suffix="journal")
fake_clock = FakeClock()
manager_poll_interval = 30
manager, _ = ScalyrTestUtils.create_test_monitors_manager(
config_monitors=[{
"module": "scalyr_agent.builtin_monitors.journald_monitor",
"journal_path": journal_directory,
"journal_fields": {
"_TRANSPORT": "transport"
},
}],
extra_toplevel_config={
"user_agent_refresh_interval":
manager_poll_interval,
"agent_log_path":
journal_directory,
"journald_logs": [{
"journald_unit": ".*",
"parser": "journaldParser",
"detect_escaped_strings": True,
}],
},
null_logger=True,
fake_clock=fake_clock,
)
monitor = manager.monitors[0]
monitor.log_manager.set_log_watcher(LogWatcher())
monitor.gather_sample()
self.assertLogFileContainsLineRegex(
"....\\-..\\-.. ..\\:..\\:..\\....." + re.escape(
' [journald_monitor()] details "testing 1,2,3 "test"" transport="journal"'
),
file_path=os.path.join(journal_directory,
"journald_monitor.log"),
)
manager.stop_manager(wait_on_join=False)
def setUp(self):
super(Test_K8sCache, self).setUp()
self.k8s = FakeK8s()
self.clock = FakeClock()
self.processor = FakeProcessor()
self.cache = _K8sCache(self.processor, "foo")
class Test_K8sCache(ScalyrTestCase):
""" Tests the _K8sCache
"""
NAMESPACE_1 = "namespace_1"
POD_1 = "pod_1"
class DummyObject(object):
def __init__(self, access_time):
self.access_time = access_time
def setUp(self):
super(Test_K8sCache, self).setUp()
self.k8s = FakeK8s()
self.clock = FakeClock()
self.processor = FakeProcessor()
self.cache = _K8sCache(self.processor, "foo")
def tearDown(self):
self.k8s.stop()
def test_purge_expired(self):
processor = Mock()
cache = _K8sCache(processor, "foo")
current_time = time.time()
obj1 = self.DummyObject(current_time - 10)
obj2 = self.DummyObject(current_time + 15)
obj3 = self.DummyObject(current_time - 20)
objects = {"default": {"obj1": obj1, "obj2": obj2, "obj3": obj3}}
# we should probably look at using actual values returned from k8s here
# and loading them via 'cache.update'
cache._objects = objects
cache.purge_unused(current_time)
objects = cache._objects.get("default", {})
self.assertEquals(1, len(objects))
self.assertTrue("obj2" in objects)
self.assertTrue(objects["obj2"] is obj2)
def test_lookup_not_in_cache(self):
self.k8s.set_response(self.NAMESPACE_1, self.POD_1, success=True)
self.assertFalse(
self.cache.is_cached(self.NAMESPACE_1,
self.POD_1,
allow_expired=True))
obj = self.cache.lookup(self.k8s, self.clock.time(), self.NAMESPACE_1,
self.POD_1)
self.assertTrue(
self.cache.is_cached(self.NAMESPACE_1,
self.POD_1,
allow_expired=True))
self.assertEqual(obj.name, self.POD_1)
self.assertEqual(obj.namespace, self.NAMESPACE_1)
def test_lookup_already_in_cache(self):
query_options = ApiQueryOptions()
self.k8s.set_response(self.NAMESPACE_1, self.POD_1, success=True)
obj = self.cache.lookup(
self.k8s,
self.clock.time(),
self.NAMESPACE_1,
self.POD_1,
query_options=query_options,
)
self.assertTrue(
self.cache.is_cached(self.NAMESPACE_1,
self.POD_1,
allow_expired=True))
self.k8s.set_response(self.NAMESPACE_1,
self.POD_1,
permanent_error=True)
obj = self.cache.lookup(
self.k8s,
self.clock.time(),
self.NAMESPACE_1,
self.POD_1,
query_options=query_options,
)
self.assertTrue(
self.cache.is_cached(self.NAMESPACE_1,
self.POD_1,
allow_expired=True))
self.assertEqual(obj.name, self.POD_1)
self.assertEqual(obj.namespace, self.NAMESPACE_1)
def test_raise_exception_on_query_error(self):
query_options = ApiQueryOptions()
self.k8s.set_response(self.NAMESPACE_1,
self.POD_1,
permanent_error=True)
self.assertRaises(
K8sApiPermanentError,
lambda: self.cache.lookup(
self.k8s,
self.clock.time(),
self.NAMESPACE_1,
self.POD_1,
query_options=query_options,
),
)
def test_return_none_on_query_error_without_options(self):
self.k8s.set_response(self.NAMESPACE_1,
self.POD_1,
permanent_error=True)
obj = self.cache.lookup(
self.k8s,
self.clock.time(),
self.NAMESPACE_1,
self.POD_1,
ignore_k8s_api_exception=True,
)
self.assertIsNone(obj)
def setUp(self):
self.k8s = FakeK8s()
self.clock = FakeClock()
self.processor = FakeProcessor()
self.cache = _K8sCache( self.processor, 'foo' )
def test_user_agent_fragment(self, mock_docker):
def fake_init(self):
# Initialize variables that would have been
self._KubernetesMonitor__container_checker = None
self._KubernetesMonitor__namespaces_to_ignore = []
self._KubernetesMonitor__include_controller_info = None
self._KubernetesMonitor__report_container_metrics = None
self._KubernetesMonitor__metric_fetcher = None
self._KubernetesMonitor__metrics_controlled_warmer = None
with mock.patch.object(KubernetesMonitor, "_initialize", fake_init):
manager_poll_interval = 30
fake_clock = FakeClock()
manager, _ = ScalyrTestUtils.create_test_monitors_manager(
config_monitors=[{
"module":
"scalyr_agent.builtin_monitors.kubernetes_monitor"
}],
extra_toplevel_config={
"user_agent_refresh_interval": manager_poll_interval,
},
null_logger=True,
fake_clock=fake_clock,
)
fragment_polls = FakeClockCounter(fake_clock, num_waiters=2)
counter = {"callback_invocations": 0}
detected_fragment_changes = []
# Mock the callback (that would normally be invoked on ScalyrClientSession
def augment_user_agent(fragments):
counter["callback_invocations"] += 1
detected_fragment_changes.append(fragments[0])
# Decorate the get_user_agent_fragment() function as follows:
# Each invocation increments the FakeClockCounter
# Simulate the following race condition:
# 1. The first 10 polls by MonitorsManager is such that KubernetesMonitor has not yet started. Therefore,
# the version is None
# 2. After the 20th poll, version is set
# 3. After the 30th poll, version changes (does not normally happen, but we ensure this repeated check)
#
# Total number of times the user_agent_callback is called should be twice:
# - once for when docker version is None (fragment is 'k8s=true')
# - once for when docker version changes to a real number
version1 = "1.13.4"
version2 = "1.14.1"
k8s_mon = manager.monitors[0]
original_get_user_agent_fragment = k8s_mon.get_user_agent_fragment
def fake_get_user_agent_fragment():
result = original_get_user_agent_fragment()
fragment_polls.increment()
return result
def fake_get_api_server_version():
if fragment_polls.count() < 10:
return None
elif fragment_polls.count() < 20:
return version1
else:
return version2
container_runtime = "cri"
@patch.object(k8s_mon, "get_user_agent_fragment")
@patch.object(k8s_mon, "_KubernetesMonitor__get_k8s_cache"
) # return Mock obj instead of a KubernetesCache)
def start_test(m2, m1):
m1.side_effect = fake_get_user_agent_fragment
m2.return_value.get_api_server_version.side_effect = (
fake_get_api_server_version)
m2.return_value.get_container_runtime.side_effect = (
lambda: container_runtime)
manager.set_user_agent_augment_callback(augment_user_agent)
manager.start_manager()
fragment_polls.sleep_until_count_or_maxwait(
40, manager_poll_interval, maxwait=1)
m1.assert_called()
m2.assert_called()
self.assertEqual(fragment_polls.count(), 40)
self.assertEqual(counter["callback_invocations"], 3)
self.assertEquals(
detected_fragment_changes,
[
"k8s=true;k8s-runtime=%s" % container_runtime,
"k8s=%s;k8s-runtime=%s" %
(version1, container_runtime),
"k8s=%s;k8s-runtime=%s" %
(version2, container_runtime),
],
)
manager.stop_manager(wait_on_join=False)
fake_clock.advance_time(increment_by=manager_poll_interval)
start_test() # pylint: disable=no-value-for-parameter
