def add_talisker_context(data):
rid = talisker.request_id.get()
if rid:
data['tags']['request_id'] = rid
data['extra'].update(talisker.logs.logging_context.flat)
user = data.get('user')
if user:
user.pop('email', None)
user.pop('username', None)
breadcrumbs = data.get('breadcrumbs', {}).get('values', [])
start_time = data['extra'].get('start_time')
sql_crumbs = []
for crumb in breadcrumbs:
if start_time:
crumb['data']['start'] = get_rounded_ms(
start_time, crumb['timestamp']
)
if crumb['category'] == 'sql':
sql_crumbs.append(crumb)
if sql_crumbs:
summary = sql_summary(sql_crumbs, data['extra'].get('start_time'))
data['extra']['sql summary'] = summary
def add_talisker_context(data):
rid = talisker.request_id.get()
if rid:
data['tags']['request_id'] = rid
data['extra'].update(talisker.logs.logging_context.flat)
user = data.get('user')
if user:
user.pop('email', None)
user.pop('username', None)
breadcrumbs = data.get('breadcrumbs', {}).get('values', [])
start_time = data['extra'].get('start_time')
if start_time is not None:
try:
start_time = float(start_time)
except ValueError:
start_time = None
sql_crumbs = []
for crumb in breadcrumbs:
if start_time:
crumb['data']['start'] = get_rounded_ms(
start_time, crumb['timestamp']
)
if crumb['category'] == 'sql':
sql_crumbs.append(crumb)
if sql_crumbs:
summary = sql_summary(sql_crumbs, start_time)
data['extra']['sql summary'] = summary
def callproc(self, procname, vars=None):
timestamp = time.time()
try:
return super(TaliskerCursor, self).callproc(procname, vars)
finally:
duration = get_rounded_ms(timestamp)
# no query parameters, cannot safely record
self.connection._record(
'stored proc: {}'.format(procname), None, duration)
def execute(self, query, vars=None):
timestamp = time.time()
try:
return super(TaliskerCursor, self).execute(query, vars)
finally:
duration = get_rounded_ms(timestamp)
if vars is None:
query = None
self.connection._record('query', query, duration)
def callproc(self, procname, vars=None):
timestamp = time.time()
try:
return super(TaliskerCursor, self).callproc(procname, vars)
finally:
duration = get_rounded_ms(timestamp)
# no query parameters, cannot safely record
self.connection._record(
'stored proc: {}'.format(procname), None, duration)
def execute(self, query, vars=None):
timestamp = time.time()
try:
return super(TaliskerCursor, self).execute(query, vars)
finally:
duration = get_rounded_ms(timestamp)
if vars is None:
query = None
self.connection._record('query', query, duration)
def execute(self, query, vars=None):
extra = collections.OrderedDict()
timeout = self.apply_timeout()
if timeout is not None:
extra['timeout'] = timeout
timestamp = time.time()
try:
return super().execute(query, vars)
except psycopg2.OperationalError as exc:
extra['pgcode'] = exc.pgcode
extra['pgerror'] = exc.pgerror
if exc.pgcode == '57014':
extra['timedout'] = True
raise
finally:
duration = get_rounded_ms(timestamp)
self.connection._record('query', query, vars, duration, extra)
def callproc(self, procname, vars=None):
extra = collections.OrderedDict()
timeout = self.apply_timeout()
if timeout is not None:
extra['timeout'] = timeout
timestamp = time.time()
try:
return super().callproc(procname, vars)
except psycopg2.OperationalError as exc:
extra['pgcode'] = exc.pgcode
extra['pgerror'] = exc.pgerror
if exc.pgcode == '57014':
extra['timedout'] = True
raise
finally:
duration = get_rounded_ms(timestamp)
# no query parameters, cannot safely record
self.connection._record(
'stored proc: {}'.format(procname),
None,
vars,
duration,
extra,
)
def test_get_rounded_ms():
assert util.get_rounded_ms(time.time() - 1.0) == 1000
assert util.get_rounded_ms(time.time() - 123.0) == 123000
assert util.get_rounded_ms(time.time() - 0.123) == 123
assert util.get_rounded_ms(time.time() - 0.123456789) == 123.457
assert util.get_rounded_ms(0.1, 0.3) == 200.0
def _log(self, *args, **kwargs):
t = time.time()
super()._log(*args, **kwargs)
track_request_metric('logging', get_rounded_ms(t))
def _log(self, *args, **kwargs):
t = time.time()
super()._log(*args, **kwargs)
Context.track('logging', get_rounded_ms(t))