[enh] Add Server-Timing header (#1637)

Server Timing specification: https://www.w3.org/TR/server-timing/

In the browser Dev Tools, focus on the main request, there are the responses per engine in the Timing tab.
This commit is contained in:
Alexandre Flament 2019-07-17 10:38:45 +02:00 committed by GitHub
parent cfcbc3a5c3
commit 554a21e1d0
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 70 additions and 15 deletions

View File

@ -136,6 +136,7 @@ class ResultContainer(object):
self._ordered = False
self.paging = False
self.unresponsive_engines = set()
self.timings = []
def extend(self, engine_name, results):
for result in list(results):
@ -319,3 +320,13 @@ class ResultContainer(object):
def add_unresponsive_engine(self, engine_error):
self.unresponsive_engines.add(engine_error)
def add_timing(self, engine_name, engine_time, page_load_time):
self.timings.append({
'engine': engines[engine_name].shortcut,
'total': engine_time,
'load': page_load_time
})
def get_timings(self):
return self.timings

View File

@ -74,10 +74,10 @@ def search_one_request(engine, query, request_params):
# ignoring empty urls
if request_params['url'] is None:
return []
return None
if not request_params['url']:
return []
return None
# send request
response = send_http_request(engine, request_params)
@ -103,20 +103,29 @@ def search_one_request_safe(engine_name, query, request_params, result_container
# send requests and parse the results
search_results = search_one_request(engine, query, request_params)
# add results
result_container.extend(engine_name, search_results)
# check if the engine accepted the request
if search_results is not None:
# yes, so add results
result_container.extend(engine_name, search_results)
# update engine time when there is no exception
with threading.RLock():
engine.stats['engine_time'] += time() - start_time
engine.stats['engine_time_count'] += 1
# update stats with the total HTTP time
engine.stats['page_load_time'] += requests_lib.get_time_for_thread()
engine.stats['page_load_count'] += 1
# update engine time when there is no exception
engine_time = time() - start_time
page_load_time = requests_lib.get_time_for_thread()
result_container.add_timing(engine_name, engine_time, page_load_time)
with threading.RLock():
engine.stats['engine_time'] += engine_time
engine.stats['engine_time_count'] += 1
# update stats with the total HTTP time
engine.stats['page_load_time'] += page_load_time
engine.stats['page_load_count'] += 1
except Exception as e:
search_duration = time() - start_time
# Timing
engine_time = time() - start_time
page_load_time = requests_lib.get_time_for_thread()
result_container.add_timing(engine_name, engine_time, page_load_time)
# Record the errors
with threading.RLock():
engine.stats['errors'] += 1
@ -125,14 +134,14 @@ def search_one_request_safe(engine_name, query, request_params, result_container
# requests timeout (connect or read)
logger.error("engine {0} : HTTP requests timeout"
"(search duration : {1} s, timeout: {2} s) : {3}"
.format(engine_name, search_duration, timeout_limit, e.__class__.__name__))
.format(engine_name, engine_time, timeout_limit, e.__class__.__name__))
requests_exception = True
elif (issubclass(e.__class__, requests.exceptions.RequestException)):
result_container.add_unresponsive_engine((engine_name, gettext('request exception')))
# other requests exception
logger.exception("engine {0} : requests exception"
"(search duration : {1} s, timeout: {2} s) : {3}"
.format(engine_name, search_duration, timeout_limit, e))
.format(engine_name, engine_time, timeout_limit, e))
requests_exception = True
else:
result_container.add_unresponsive_engine((

View File

@ -43,6 +43,7 @@ except:
exit(1)
from cgi import escape
from datetime import datetime, timedelta
from time import time
from werkzeug.contrib.fixers import ProxyFix
from flask import (
Flask, request, render_template, url_for, Response, make_response,
@ -402,6 +403,8 @@ def render(template_name, override_theme=None, **kwargs):
@app.before_request
def pre_request():
request.start_time = time()
request.timings = []
request.errors = []
preferences = Preferences(themes, list(categories.keys()), engines, plugins)
@ -437,6 +440,21 @@ def pre_request():
request.user_plugins.append(plugin)
@app.after_request
def post_request(response):
total_time = time() - request.start_time
timings_all = ['total;dur=' + str(round(total_time * 1000, 3))]
if len(request.timings) > 0:
timings = sorted(request.timings, key=lambda v: v['total'])
timings_total = ['total_' + str(i) + '_' + v['engine'] +
';dur=' + str(round(v['total'] * 1000, 3)) for i, v in enumerate(timings)]
timings_load = ['load_' + str(i) + '_' + v['engine'] +
';dur=' + str(round(v['load'] * 1000, 3)) for i, v in enumerate(timings)]
timings_all = timings_all + timings_total + timings_load
response.headers.add('Server-Timing', ', '.join(timings_all))
return response
def index_error(output_format, error_message):
if output_format == 'json':
return Response(json.dumps({'error': error_message}),
@ -515,6 +533,9 @@ def index():
# UI
advanced_search = request.form.get('advanced_search', None)
# Server-Timing header
request.timings = result_container.get_timings()
# output
for result in results:
if output_format == 'html':

View File

@ -33,6 +33,19 @@ class ViewsTestCase(SearxTestCase):
},
]
timings = [
{
'engine': 'startpage',
'total': 0.8,
'load': 0.7
},
{
'engine': 'youtube',
'total': 0.9,
'load': 0.6
}
]
def search_mock(search_self, *args):
search_self.result_container = Mock(get_ordered_results=lambda: self.test_results,
answers=set(),
@ -42,7 +55,8 @@ class ViewsTestCase(SearxTestCase):
unresponsive_engines=set(),
results=self.test_results,
results_number=lambda: 3,
results_length=lambda: len(self.test_results))
results_length=lambda: len(self.test_results),
get_timings=lambda: timings)
Search.search = search_mock