def test_recorder(self):
queue = Queue()
class TestTraceWriter(TraceWriter):
def write(self, traces: List[RequestTrace]):
for t in traces:
queue.put(t)
recorder = RedisTraceRecorder(self.redis.rds, exp_id='exp1', writer=TestTraceWriter(), flush_every=2)
recorder.start()
reporter = RedisTraceReporter(self.redis.rds)
fixture = [
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, response='hello there'),
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, server='s1'),
]
expected = [
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, response='hello there', exp_id='exp1'),
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, server='s1', exp_id='exp1')
]
reporter.report_multiple(fixture)
trace = queue.get(timeout=2)
self.assertEqual(expected[0], trace)
trace = queue.get(timeout=2)
self.assertEqual(expected[1], trace)
recorder.stop(timeout=2)
def test_delete(self):
exp_id = 'id1'
exp = Experiment(exp_id, 'name1', 'creator1', 1, 20, 7, 'FINISH')
telemetry: List[Telemetry] = [
Telemetry(1, 'metric1', 'node1', 1, exp_id),
Telemetry(2, 'metric2', 'node2', 2, exp_id)
]
traces: List[RequestTrace] = [
RequestTrace('req1', 'client1', 'service1', 2, 2, 3),
RequestTrace('req2', 'client2', 'service2', 6, 5, 4)
]
db = self.db_resource.db
db.save_experiment(exp)
db.save_telemetry(telemetry)
db.save_traces(traces)
db.touch_traces(exp)
self.simulate_delete('/api/experiments/id1')
self.assertEqual(len(db.find_all()), 0)
traces_fetched = db.db.fetchall('SELECT * FROM traces')
telemetry_fetched = db.db.fetchall('SELECT * FROM telemetry')
self.assertEqual(len(traces_fetched), 0)
self.assertEqual(len(telemetry_fetched), 0)
pass
def perform_request(self, request):
client_id = self.client_id
traces = self.traces
router = self.router
if request is RequestGenerator.DONE:
self.eventbus.publish(WorkloadDoneEvent(self.client_id))
return
logger.debug('client %s processing request %s', client_id, request)
request.client_id = client_id
request.request_id = self._create_request_id(request)
try:
request.sent = -1 # will be updated by router
response: requests.Response = router.request(request)
host = response.url.split("//")[-1].split("/")[0].split('?')[0]
t = RequestTrace(request_id=request.request_id,
client=client_id,
service=request.service,
created=request.created,
sent=request.sent,
done=time.time(),
status=response.status_code,
server=host,
response=response.text.strip(),
headers=json.dumps(dict(response.headers)))
except Exception as e:
if logger.isEnabledFor(logging.DEBUG):
logger.exception('error while handling request %s', request)
else:
logger.error('error while handling request %s: %s', request, e)
t = RequestTrace(request_id=request.request_id,
client=client_id,
service=request.service,
created=request.created,
sent=request.sent,
done=time.time(),
status=-1)
if t.status < 0 or t.status >= 300:
self.failed_counter += 1
try:
traces.put_nowait(t)
except Full:
pass
def _record(self, t: RequestTrace):
t = t._replace(exp_id=self.exp_id)
self.buffer.append(t)
self.i = (self.i + 1) % self.flush_every
if self.i == 0:
self._flush()
def parse(line: str) -> RequestTrace:
# FIXME: this is turning into a bad line-based protocol ...
data = line.split(',', maxsplit=9)
for i in range(len(data)):
if data[i] == 'None':
data[i] = None
response = data[9]
if response:
response = response.replace('\\n', '\n')
return RequestTrace(
request_id=data[0],
client=data[1],
service=data[2],
created=float(data[3]),
sent=float(data[4]),
done=float(data[5]),
status=int(data[6]),
server=data[7],
exp_id=data[8],
response=response,
)
def test_parse(self):
parse = TracesSubscriber.parse
expected = RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, response="foo=bar\nfield1=value1,a,b,c")
actual = parse(r"r1,c1,s1,1.1000000,1.2000000,1.3000000,200,None,None,foo=bar\nfield1=value1,a,b,c")
self.assertEqual(expected, actual)
def test_report_response_with_noisy_string(self):
reporter = RedisTraceReporter(self.redis.rds)
subscriber = RedisSubscriber(self.redis.rds,
RedisTraceReporter.channel)
subscriber.start()
response = "foo=bar\nfield1=value1,a,b,c"
reporter.report_multiple([
RequestTrace('r1',
'c1',
's1',
1.1,
1.2,
1.3,
200,
response=response),
])
data = subscriber.queue.get(1)
self.assertEqual(
r"r1,c1,s1,1.1000000,1.2000000,1.3000000,200,None,None,foo=bar\nfield1=value1,a,b,c",
data)
subscriber.shutdown()
def get_traces(self, exp_id=None) -> List[RequestTrace]:
fields = self.db.sql_field_list(RequestTrace._fields)
if exp_id is None:
sql = f'SELECT {fields} from `traces`'
entries = self.db.fetchall(sql)
else:
sql = f'SELECT {fields} from `traces` WHERE EXP_ID = {self.db.placeholder}'
entries = self.db.fetchall(sql, (exp_id, ))
return list(map(lambda x: RequestTrace(*(tuple(x))), entries))
def trigger_flush(self):
for i in range(self.flush_interval):
self.queue.put(
RequestTrace(f'req{i}',
'client',
'service',
1,
1,
1,
status=200,
response='data'))
def test_report_multiple(self):
reporter = RedisTraceReporter(self.redis.rds)
subscriber = RedisSubscriber(self.redis.rds,
RedisTraceReporter.channel)
subscriber.start()
fixture = [
RequestTrace('r1',
'c1',
's1',
1.1,
1.2,
1.3,
200,
response='hello there'),
RequestTrace('r2', 'c1', 's1', 2.1, 2.2, 2.3, 200,
server='server'),
]
reporter.report_multiple(fixture)
try:
data = subscriber.queue.get(timeout=1)
self.assertTrue('r1' in data)
self.assertTrue('r2' not in data)
self.assertTrue('server' not in data)
self.assertTrue('hello there' in data)
data = subscriber.queue.get(timeout=1)
self.assertTrue('r1' not in data)
self.assertTrue('r2' in data)
self.assertTrue('server' in data)
self.assertTrue('hello there' not in data)
self.assertTrue(subscriber.queue.empty())
finally:
subscriber.shutdown()
def test_recorder(self):
queue = Queue()
class TestTraceRecorder(TraceRecorder):
def _record(self, t):
queue.put(t)
recorder = TestTraceRecorder(self.redis.rds)
recorder.start()
reporter = RedisTraceReporter(self.redis.rds)
fixture = [
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, response='hello there'),
RequestTrace('r1', 'c1', 's1', 1.1, 1.2, 1.3, 200, server='s1', exp_id='exp1')
]
reporter.report_multiple(fixture)
trace = queue.get(timeout=2)
self.assertEqual(fixture[0], trace)
trace = queue.get(timeout=2)
self.assertEqual(fixture[1], trace)
recorder.stop(timeout=2)
import shutil
import threading
import unittest
from time import sleep
from unittest.mock import patch
from timeout_decorator import timeout_decorator
from galileodb.model import RequestTrace
from galileodb.reporter.traces import RedisTraceReporter
from galileodb.trace import TraceLogger, POISON, START, PAUSE, FLUSH, TraceWriter, FileTraceWriter, \
RedisTopicTraceWriter, DatabaseTraceWriter
from tests.testutils import RedisResource, SqliteResource, assert_poll, RedisSubscriber
traces = [
RequestTrace('req1', 'client', 'service', 1.1, 1.2, 1.3),
RequestTrace('req2', 'client', 'service', 2.2, 2.3, 2.4, 200, 'server1',
'exp1', 'hello'),
RequestTrace('req3',
'client',
'service',
3.2,
3.3,
3.4,
status=200,
server='server1',
response='foo=bar\nx=1,"2",3')
]
class TestTraceLogger(unittest.TestCase):
def test_save_and_touch_and_get_traces(self):
traces = [
RequestTrace('req1',
'c1',
's1',
1.1,
1.2,
1.3,
server='h1',
status=200),
RequestTrace('req2',
'c2',
's2',
2.1,
2.2,
2.3,
server='h2',
status=200),
RequestTrace('req3',
'c3',
's1',
3.1,
3.2,
3.3,
server='h1',
status=200,
response='time=123'),
RequestTrace('req4',
'c1',
's1',
4.1,
4.2,
4.3,
server='h1',
status=200),
]
self.db.save_experiment(
Experiment('exp1', start=1, end=3.5, status='FINISHED'))
self.db.save_traces(traces)
self.db.touch_traces(
self.db.get_experiment('exp1')) # should touch the first 3
actual = self.db.get_traces('exp1')
expected = [
RequestTrace('req1',
'c1',
's1',
1.1,
1.2,
1.3,
server='h1',
status=200,
exp_id='exp1'),
RequestTrace('req2',
'c2',
's2',
2.1,
2.2,
2.3,
server='h2',
status=200,
exp_id='exp1'),
RequestTrace('req3',
'c3',
's1',
3.1,
3.2,
3.3,
server='h1',
status=200,
response='time=123',
exp_id='exp1')
]
self.assertEqual(expected, actual)