def setUp(self):
super(StatsFrameworkLogTest, self).setUp()
stats_framework_logs_mock.configure(self)
self.h = stats_framework.StatisticsFramework('test_framework',
Snapshot,
generate_snapshot)
class GenerateHandler(webapp2.RequestHandler):
def get(self2):
stats_logs.add_entry('Hello')
self2.response.write('Yay')
class JsonHandler(webapp2.RequestHandler):
def get(self2):
self2.response.headers['Content-Type'] = (
'application/json; charset=utf-8')
duration = int(self2.request.get('duration', 120))
now = self2.request.get('now')
resolution = self2.request.get('resolution')
data = stats_framework.get_stats(self.h, resolution, now,
duration, True)
self2.response.write(
stats_framework.utils.encode_to_json(data))
routes = [
('/generate', GenerateHandler),
('/json', JsonHandler),
]
real_app = webapp2.WSGIApplication(routes, debug=True)
self.app = webtest.TestApp(real_app,
extra_environ={'REMOTE_ADDR': 'fake-ip'})
self.now = datetime.datetime(2010, 1, 2, 3, 4, 5, 6)
self.mock_now(self.now, 0)
def test_empty(self):
handler = stats_framework.StatisticsFramework('test_framework',
Snapshot, self.fail)
self.assertEqual(0, stats_framework.StatsRoot.query().count())
self.assertEqual(0, handler.stats_day_cls.query().count())
self.assertEqual(0, handler.stats_hour_cls.query().count())
self.assertEqual(0, handler.stats_minute_cls.query().count())
def test_framework_empty(self):
handler = stats_framework.StatisticsFramework('test_framework',
Snapshot, self.fail)
now = get_now()
self.mock_now(now, 0)
handler._set_last_processed_time(strip_seconds(now))
i = handler.process_next_chunk(0)
self.assertEqual(0, i)
self.assertEqual(1, stats_framework.StatsRoot.query().count())
self.assertEqual(0, handler.stats_day_cls.query().count())
self.assertEqual(0, handler.stats_hour_cls.query().count())
self.assertEqual(0, handler.stats_minute_cls.query().count())
root = handler.root_key.get()
self.assertEqual(strip_seconds(now), root.timestamp)
def test_keys(self):
handler = stats_framework.StatisticsFramework('test_framework',
Snapshot, self.fail)
date = datetime.datetime(2010, 1, 2)
self.assertEqual(
ndb.Key('StatsRoot', 'test_framework', 'StatsDay', '2010-01-02'),
handler.day_key(date.date()))
self.assertEqual(
ndb.Key('StatsRoot', 'test_framework', 'StatsDay', '2010-01-02',
'StatsHour', '00'), handler.hour_key(date))
self.assertEqual(
ndb.Key('StatsRoot', 'test_framework', 'StatsDay', '2010-01-02',
'StatsHour', '00', 'StatsMinute', '00'),
handler.minute_key(date))
def test_framework_last_few(self):
called = []
def gen_data(start, end):
"""Returns fake statistics."""
self.assertEqual(start + 60, end)
called.append(start)
return Snapshot(requests=1,
b=1,
inner=InnerSnapshot(c='%d,' % len(called)))
handler = stats_framework.StatisticsFramework('test_framework',
Snapshot, gen_data)
now = get_now()
self.mock_now(now, 0)
handler._set_last_processed_time(
strip_seconds(now) - datetime.timedelta(seconds=3 * 60))
i = handler.process_next_chunk(1)
self.assertEqual(2, i)
self.assertEqual(1, stats_framework.StatsRoot.query().count())
self.assertEqual(1, handler.stats_day_cls.query().count())
self.assertEqual(1, handler.stats_hour_cls.query().count())
self.assertEqual(2, handler.stats_minute_cls.query().count())
root = handler.root_key.get()
self.assertEqual(
strip_seconds(now) - datetime.timedelta(seconds=60),
root.timestamp)
# Trying to process more won't do anything.
i = handler.process_next_chunk(1)
self.assertEqual(0, i)
root = handler.root_key.get()
self.assertEqual(
strip_seconds(now) - datetime.timedelta(seconds=60),
root.timestamp)
expected = [
{
'key': '2010-01-02',
'requests': 0,
'b': 0.0,
'd': [],
'inner': {
'c': u''
},
},
]
self.assertEqual(
expected, stats_framework.get_stats(handler, 'days', now, 100,
True))
expected = [
{
'key': '2010-01-02T03',
'requests': 2,
'b': 2.0,
'd': [],
'inner': {
'c': u'1,2,'
},
},
]
self.assertEqual(
expected,
stats_framework.get_stats(handler, 'hours', now, 100, True))
expected = [
{
'key': '2010-01-02T03:03',
'requests': 1,
'b': 1.0,
'd': [],
'inner': {
'c': u'2,'
},
},
{
'key': '2010-01-02T03:02',
'requests': 1,
'b': 1.0,
'd': [],
'inner': {
'c': u'1,'
},
},
]
self.assertEqual(
expected,
stats_framework.get_stats(handler, 'minutes', now, 100, True))
def test_framework_fresh(self):
# Ensures the processing will run for 120 minutes starting
# StatisticsFramework.MAX_BACKTRACK days ago.
called = []
def gen_data(start, end):
"""Returns fake statistics."""
self.assertEqual(start + 60, end)
called.append(start)
return Snapshot(requests=1,
b=1,
inner=InnerSnapshot(c='%d,' % len(called)))
handler = stats_framework.StatisticsFramework('test_framework',
Snapshot, gen_data)
now = get_now()
self.mock_now(now, 0)
start_date = now - datetime.timedelta(days=handler._max_backtrack_days)
limit = handler._max_minutes_per_process
i = handler.process_next_chunk(5)
self.assertEqual(limit, i)
# Fresh new stats gathering always starts at midnight.
midnight = datetime.datetime(*start_date.date().timetuple()[:3])
expected_calls = [
calendar.timegm(
(midnight + datetime.timedelta(minutes=i)).timetuple())
for i in range(limit)
]
self.assertEqual(expected_calls, called)
# Verify root.
root = stats_framework.StatsRoot.query().fetch()
self.assertEqual(1, len(root))
# When timestamp is not set, it starts at the begining of the day,
# MAX_BACKTRACK days ago, then process MAX_MINUTES_PER_PROCESS.
timestamp = midnight + datetime.timedelta(seconds=(limit - 1) * 60)
expected = {
'created': now,
'timestamp': timestamp,
}
self.assertEqual(expected, root[0].to_dict())
# Verify days.
expected = [{
'key': str(midnight.date()),
'requests': limit,
'b': float(limit),
'd': [],
'inner': {
'c': u''.join('%d,' % i for i in range(1, limit + 1)),
},
}]
days = handler.stats_day_cls.query().fetch()
self.assertEqual(expected, [d.to_dict() for d in days])
# These are left out from .to_dict().
self.assertEqual(now, days[0].created)
self.assertEqual(now, days[0].modified)
self.assertEqual(3, days[0].hours_bitmap)
# Verify hours.
expected = [{
'key':
(midnight +
datetime.timedelta(seconds=i * 60 * 60)).strftime('%Y-%m-%dT%H'),
'requests':
60,
'b':
60.,
'd': [],
'inner': {
'c':
u''.join('%d,' % i
for i in range(60 * i + 1, 60 * (i + 1) + 1)),
},
} for i in range(limit / 60)]
hours = handler.stats_hour_cls.query().fetch()
self.assertEqual(expected, [d.to_dict() for d in hours])
for h in hours:
# These are left out from .to_dict().
self.assertEqual(now, h.created)
self.assertEqual((1 << 60) - 1, h.minutes_bitmap)
# Verify minutes.
expected = [{
'key':
(midnight +
datetime.timedelta(seconds=i * 60)).strftime('%Y-%m-%dT%H:%M'),
'requests':
1,
'b':
1.,
'd': [],
'inner': {
'c': u'%d,' % (i + 1),
},
} for i in range(limit)]
minutes = handler.stats_minute_cls.query().fetch()
self.assertEqual(expected, [d.to_dict() for d in minutes])
for m in minutes:
# These are left out from .to_dict().
self.assertEqual(now, m.created)
values.requests += 1
if entry.request.status >= 400:
values.failures += 1
for l in entry.entries:
if _parse_line(l, values):
total_lines += 1
else:
parse_errors += 1
logging.debug('_extract_snapshot_from_logs(%s, %s): %d lines, %d errors',
start_time, end_time, total_lines, parse_errors)
return values
### Public API
STATS_HANDLER = stats_framework.StatisticsFramework(
'global_stats', _Snapshot, _extract_snapshot_from_logs)
# Action to log.
STORE, RETURN, LOOKUP, DUPE = range(4)
def add_entry(action, number, where):
"""Formatted statistics log entry so it can be processed for daily stats.
The format is simple enough that it doesn't require a regexp for faster
processing.
"""
stats_framework.add_entry('%s; %d; %s' %
(_ACTION_NAMES[action], number, where))
