def test_log_performance(self):
with self.construct_application() as app:
example_id = uuid4()
log = start_new_timebucketedlog(example_id, bucket_size="year")
log_reader = get_timebucketedlog_reader(log, app.log_event_store)
# Write a load of messages.
start_write = time.time()
number_of_messages = 111
events = []
for i in range(number_of_messages):
event = log.log_message("Logger message number {}".format(i))
events.append(event)
time_to_write = time.time() - start_write
print(
"Time to log {} messages: {:.2f}s ({:.0f} messages/s, {:.6f}s each)"
"".format(
number_of_messages,
time_to_write,
number_of_messages / time_to_write,
time_to_write / number_of_messages,
))
# Read pages of messages in descending order.
# - get a limited number until a time, then use the earliest in that list
# as the position
position = events[-1].timestamp
page_size = 10
# Page back through the log in reverse chronological order.
previous_position = None
count_pages = 0
total_time_to_read = 0
total_num_reads = 0
while True:
start_read = time.time()
page_of_events, next_position = self.get_message_logged_events_and_next_position(
log_reader, position, page_size)
time_to_read = time.time() - start_read
total_time_to_read += time_to_read
total_num_reads += 1
count_pages += 1
if next_position is None:
break
else:
previous_position, position = position, next_position
# Check we got to the end of the line.
self.assertEqual(count_pages, 11)
self.assertIsNone(next_position)
self.assertTrue(previous_position)
# Page forward through the log in chronological order.
count_pages = 0
position = None
while True:
start_read = time.time()
page_of_events, next_position = self.get_message_logged_events_and_next_position(
log_reader, position, page_size, is_ascending=True)
time_to_read = time.time() - start_read
total_time_to_read += time_to_read
total_num_reads += 1
count_pages += 1
if next_position is None:
break
else:
position = next_position
self.assertEqual(count_pages, 11)
self.assertIsNone(next_position)
self.assertTrue(previous_position)
reads_per_second = total_num_reads / total_time_to_read
messages_per_second = reads_per_second * number_of_messages
print(
"Time to read {} pages of logged messages: {:.6f}s ({:.0f} pages/s, "
"{:.0f} messages/s))"
"".format(
total_num_reads,
total_time_to_read,
reads_per_second,
messages_per_second,
))
def test_buckets_of_all_sizes(self):
# Start new second sized log.
log_id2 = uuid4()
log = start_new_timebucketedlog(name=log_id2, bucket_size='second')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new minute sized log.
log_id3 = uuid4()
log = start_new_timebucketedlog(name=log_id3, bucket_size='minute')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new hour sized log.
log_id4 = uuid4()
log = start_new_timebucketedlog(name=log_id4, bucket_size='hour')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new day sized log.
log_id5 = uuid4()
log = start_new_timebucketedlog(name=log_id5, bucket_size='day')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new month sized log.
log_id6 = uuid4()
log = start_new_timebucketedlog(name=log_id6, bucket_size='month')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new year sized log.
log_id7 = uuid4()
log = start_new_timebucketedlog(name=log_id7, bucket_size='year')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new default sized log.
log_id8 = uuid4()
log = start_new_timebucketedlog(name=log_id8)
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new invalid sized log.
with self.assertRaises(ValueError):
log_id9 = uuid4()
log = start_new_timebucketedlog(name=log_id9,
bucket_size='invalid')
# Check the helper methods are protected against invalid bucket sizes.
with self.assertRaises(ValueError):
log_id10 = uuid4()
make_timebucket_id(log_id10,
decimaltimestamp(),
bucket_size='invalid')
with self.assertRaises(ValueError):
bucket_starts(decimaltimestamp(), bucket_size='invalid')
with self.assertRaises(ValueError):
bucket_duration(bucket_size='invalid')
def test_buckets_size_second(self):
# Start new log.
log = start_new_timebucketedlog(name=uuid4(), bucket_size='second')
# Write messages across the time interval
start = datetime.datetime.now()
number_of_messages = 300
events = []
for i in range(number_of_messages):
message_logged = log.append_message(str(i))
events.append(message_logged)
sleep(0.01)
self.assertGreater(datetime.datetime.now() - start,
datetime.timedelta(seconds=1))
# Get the messages in descending order.
reader = TimebucketedlogReader(log, self.log_event_store)
messages = list(reader.get_messages(is_ascending=False, page_size=10))
self.assertEqual(len(messages), number_of_messages)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
list(reversed([str(i) for i in range(number_of_messages)])))
# Get the messages in ascending order.
messages = list(reader.get_messages(is_ascending=True, page_size=10))
self.assertEqual(len(messages), number_of_messages)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(number_of_messages)])
# Get a limited number of messages in descending order.
limit = 150
messages = list(
reader.get_messages(is_ascending=False, page_size=10, limit=limit))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
list(reversed([str(i)
for i in range(number_of_messages)]))[:limit])
# Get a limited number of messages in ascending order.
limit = 150
messages = list(
reader.get_messages(is_ascending=True, page_size=10, limit=limit))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(limit)])
# Get a limited number of messages in descending order from the midpoint down.
limit = 110
midpoint = events[150].timestamp
messages = list(
reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
lt=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
list(reversed([str(i) for i in range(150 - limit, 150)])))
# Get a limited number of messages in ascending order from the midpoint up.
limit = 110
midpoint = events[149].timestamp
messages = list(
reader.get_messages(is_ascending=True,
page_size=10,
limit=limit,
gt=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150, 150 + limit)])
# Get a limited number of messages in descending order above the midpoint down.
limit = 200
midpoint = events[150].timestamp
messages = list(
reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
gte=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), 150)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages,
list(reversed([str(i) for i in range(150, 300)])))
# Get a limited number of messages in ascending order below the midpoint up.
limit = 200
midpoint = events[149].timestamp
messages = list(
reader.get_messages(is_ascending=True,
page_size=10,
limit=limit,
lte=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), 150)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150)])
#
# Use the last position to start part way through.
limit = 20
last_position = reader.position
messages = reader.get_messages(is_ascending=True,
page_size=10,
limit=limit,
gt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150, 150 + limit)])
# Do it again.
last_position = reader.position
messages = reader.get_messages(is_ascending=True,
page_size=10,
limit=limit,
gt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages,
[str(i) for i in range(150 + limit, 150 + limit * 2)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
[str(i) for i in range(148 + limit * 2, 148 + limit, -1)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
[str(i) for i in range(128 + limit * 2, 128 + limit, -1)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
[str(i) for i in range(108 + limit * 2, 108 + limit, -1)])
# Repeat.
messages = reader.get_messages(is_ascending=False,
page_size=10,
limit=limit,
lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(
messages,
[str(i) for i in range(108 + limit * 2, 108 + limit, -1)])
def test_log_performance(self):
with self.construct_application() as app:
example_id = uuid4()
log = start_new_timebucketedlog(example_id, bucket_size='year')
log_reader = get_timebucketedlog_reader(log, app.log_event_store)
# Write a load of messages.
start_write = time.time()
number_of_messages = 111
events = []
for i in range(number_of_messages):
event = log.append_message('Logger message number {}'.format(i))
events.append(event)
time_to_write = (time.time() - start_write)
print("Time to log {} messages: {:.2f}s ({:.0f} messages/s, {:.6f}s each)"
"".format(number_of_messages, time_to_write, number_of_messages / time_to_write,
time_to_write / number_of_messages))
# Read pages of messages in descending order.
# - get a limited number until a time, then use the earliest in that list as the position
position = events[-1].timestamp
page_size = 10
# Page back through the log in reverse chronological order.
previous_position = None
count_pages = 0
total_time_to_read = 0
total_num_reads = 0
while True:
start_read = time.time()
page_of_events, next_position = self.get_message_logged_events_and_next_position(log_reader, position,
page_size)
time_to_read = (time.time() - start_read)
total_time_to_read += time_to_read
total_num_reads += 1
count_pages += 1
if next_position is None:
break
else:
previous_position, position = position, next_position
# Check we got to the end of the line.
self.assertEqual(count_pages, 11)
self.assertIsNone(next_position)
self.assertTrue(previous_position)
# Page forward through the log in chronological order.
count_pages = 0
position = None
while True:
start_read = time.time()
page_of_events, next_position = self.get_message_logged_events_and_next_position(log_reader, position,
page_size,
is_ascending=True)
time_to_read = (time.time() - start_read)
total_time_to_read += time_to_read
total_num_reads += 1
count_pages += 1
if next_position is None:
break
else:
position = next_position
self.assertEqual(count_pages, 11)
self.assertIsNone(next_position)
self.assertTrue(previous_position)
reads_per_second = total_num_reads / total_time_to_read
messages_per_second = reads_per_second * number_of_messages
print("Time to read {} pages of logged messages: {:.6f}s ({:.0f} pages/s, {:.0f} messages/s))"
"".format(total_num_reads, total_time_to_read, reads_per_second, messages_per_second))
def test_buckets_of_all_sizes(self):
# Start new second sized log.
log_id2 = uuid4()
log = start_new_timebucketedlog(name=log_id2, bucket_size='second')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new minute sized log.
log_id3 = uuid4()
log = start_new_timebucketedlog(name=log_id3, bucket_size='minute')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new hour sized log.
log_id4 = uuid4()
log = start_new_timebucketedlog(name=log_id4, bucket_size='hour')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new day sized log.
log_id5 = uuid4()
log = start_new_timebucketedlog(name=log_id5, bucket_size='day')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new month sized log.
log_id6 = uuid4()
log = start_new_timebucketedlog(name=log_id6, bucket_size='month')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new year sized log.
log_id7 = uuid4()
log = start_new_timebucketedlog(name=log_id7, bucket_size='year')
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new default sized log.
log_id8 = uuid4()
log = start_new_timebucketedlog(name=log_id8)
log.append_message('message')
# Get the messages.
reader = TimebucketedlogReader(log, self.log_event_store)
self.assertTrue(len(list(reader.get_messages())))
# Start new invalid sized log.
with self.assertRaises(ValueError):
log_id9 = uuid4()
log = start_new_timebucketedlog(name=log_id9, bucket_size='invalid')
# Check the helper methods are protected against invalid bucket sizes.
with self.assertRaises(ValueError):
log_id10 = uuid4()
make_timebucket_id(log_id10, time.time(), bucket_size='invalid')
with self.assertRaises(ValueError):
bucket_starts(time.time(), bucket_size='invalid')
with self.assertRaises(ValueError):
bucket_duration(bucket_size='invalid')
def test_buckets_size_second(self):
# Start new log.
log = start_new_timebucketedlog(name=uuid4(), bucket_size='second')
# Write messages across the time interval
start = datetime.datetime.now()
number_of_messages = 300
events = []
for i in range(number_of_messages):
message_logged = log.append_message(str(i))
events.append(message_logged)
sleep(0.01)
self.assertGreater(datetime.datetime.now() - start, datetime.timedelta(seconds=1))
# Get the messages in descending order.
reader = TimebucketedlogReader(log, self.log_event_store)
messages = list(reader.get_messages(is_ascending=False, page_size=10))
self.assertEqual(len(messages), number_of_messages)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, list(reversed([str(i) for i in range(number_of_messages)])))
# Get the messages in ascending order.
messages = list(reader.get_messages(is_ascending=True, page_size=10))
self.assertEqual(len(messages), number_of_messages)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(number_of_messages)])
# Get a limited number of messages in descending order.
limit = 150
messages = list(reader.get_messages(is_ascending=False, page_size=10, limit=limit))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, list(reversed([str(i) for i in range(number_of_messages)]))[:limit])
# Get a limited number of messages in ascending order.
limit = 150
messages = list(reader.get_messages(is_ascending=True, page_size=10, limit=limit))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(limit)])
# Get a limited number of messages in descending order from the midpoint down.
limit = 110
midpoint = events[150].timestamp
messages = list(reader.get_messages(is_ascending=False, page_size=10, limit=limit, lt=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, list(reversed([str(i) for i in range(150 - limit, 150)])))
# Get a limited number of messages in ascending order from the midpoint up.
limit = 110
midpoint = events[149].timestamp
messages = list(reader.get_messages(is_ascending=True, page_size=10, limit=limit, gt=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150, 150 + limit)])
# Get a limited number of messages in descending order above the midpoint down.
limit = 200
midpoint = events[150].timestamp
messages = list(reader.get_messages(is_ascending=False, page_size=10, limit=limit, gte=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), 150)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, list(reversed([str(i) for i in range(150, 300)])))
# Get a limited number of messages in ascending order below the midpoint up.
limit = 200
midpoint = events[149].timestamp
messages = list(reader.get_messages(is_ascending=True, page_size=10, limit=limit, lte=midpoint))
self.assertLess(limit, number_of_messages)
self.assertEqual(len(messages), 150)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150)])
#
# Use the last position to start part way through.
limit = 20
last_position = reader.position
messages = reader.get_messages(is_ascending=True, page_size=10, limit=limit, gt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150, 150 + limit)])
# Do it again.
last_position = reader.position
messages = reader.get_messages(is_ascending=True, page_size=10, limit=limit, gt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the same as the created order.
self.assertEqual(messages, [str(i) for i in range(150 + limit, 150 + limit * 2)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False, page_size=10, limit=limit, lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, [str(i) for i in range(148 + limit * 2, 148 + limit, -1)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False, page_size=10, limit=limit, lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, [str(i) for i in range(128 + limit * 2, 128 + limit, -1)])
# Go back.
last_position = reader.position
messages = reader.get_messages(is_ascending=False, page_size=10, limit=limit, lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, [str(i) for i in range(108 + limit * 2, 108 + limit, -1)])
# Repeat.
messages = reader.get_messages(is_ascending=False, page_size=10, limit=limit, lt=last_position)
messages = list(messages)
self.assertEqual(len(messages), limit)
# Expect the order of the messages is the reverse of the created order.
self.assertEqual(messages, [str(i) for i in range(108 + limit * 2, 108 + limit, -1)])