554a21e · searx · git.iko.soy

git.iko.soy/searx

[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.

commit554a21e1d07f3b434b5097b4e3d49e1403be7527 authorAlexandre Flament <alex@al-f.net> dateWed 17 Jul 2019, 10:38 (7 years ago) parentcfcbc3a

4 files changed+71−16

compare with master

unifiedsplit

searx/results.py+11 searx/search.py+24−15 searx/webapp.py+21 tests/unit/test_webapp.py+15−1

searx/results.py+11

@@ -136,6 +136,7 @@ class ResultContainer(object):

136136 self._ordered = False

137137 self.paging = False

138138 self.unresponsive_engines = set()

139+ self.timings = []

139140

140141 def extend(self, engine_name, results):

141142 for result in list(results):

@@ -319,3 +320,13 @@ class ResultContainer(object):

319320

320321 def add_unresponsive_engine(self, engine_error):

321322 self.unresponsive_engines.add(engine_error)

323+

324+ def add_timing(self, engine_name, engine_time, page_load_time):

325+ self.timings.append({

326+ 'engine': engines[engine_name].shortcut,

327+ 'total': engine_time,

328+ 'load': page_load_time

329+ })

330+

331+ def get_timings(self):

332+ return self.timings

searx/search.py+24−15

@@ -74,10 +74,10 @@ def search_one_request(engine, query, request_params):

7474

7575 # ignoring empty urls

7676 if request_params['url'] is None:

77− return []

77+ return None

7878

7979 if not request_params['url']:

80− return []

80+ return None

8181

8282 # send request

8383 response = send_http_request(engine, request_params)

@@ -103,20 +103,29 @@ def search_one_request_safe(engine_name, query, request_params, result_container

103103 # send requests and parse the results

104104 search_results = search_one_request(engine, query, request_params)

105105

106− # add results

107− result_container.extend(engine_name, search_results)

108−

109− # update engine time when there is no exception

110− with threading.RLock():

111− engine.stats['engine_time'] += time() - start_time

112− engine.stats['engine_time_count'] += 1

113− # update stats with the total HTTP time

114− engine.stats['page_load_time'] += requests_lib.get_time_for_thread()

115− engine.stats['page_load_count'] += 1

106+ # check if the engine accepted the request

107+ if search_results is not None:

108+ # yes, so add results

109+ result_container.extend(engine_name, search_results)

110+

111+ # update engine time when there is no exception

112+ engine_time = time() - start_time

113+ page_load_time = requests_lib.get_time_for_thread()

114+ result_container.add_timing(engine_name, engine_time, page_load_time)

115+ with threading.RLock():

116+ engine.stats['engine_time'] += engine_time

117+ engine.stats['engine_time_count'] += 1

118+ # update stats with the total HTTP time

119+ engine.stats['page_load_time'] += page_load_time

120+ engine.stats['page_load_count'] += 1

116121

117122 except Exception as e:

118− search_duration = time() - start_time

123+ # Timing

124+ engine_time = time() - start_time

125+ page_load_time = requests_lib.get_time_for_thread()

126+ result_container.add_timing(engine_name, engine_time, page_load_time)

119127

128+ # Record the errors

120129 with threading.RLock():

121130 engine.stats['errors'] += 1

122131

@@ -125,14 +134,14 @@ def search_one_request_safe(engine_name, query, request_params, result_container

125134 # requests timeout (connect or read)

126135 logger.error("engine {0} : HTTP requests timeout"

127136 "(search duration : {1} s, timeout: {2} s) : {3}"

128− .format(engine_name, search_duration, timeout_limit, e.__class__.__name__))

137+ .format(engine_name, engine_time, timeout_limit, e.__class__.__name__))

129138 requests_exception = True

130139 elif (issubclass(e.__class__, requests.exceptions.RequestException)):

131140 result_container.add_unresponsive_engine((engine_name, gettext('request exception')))

132141 # other requests exception

133142 logger.exception("engine {0} : requests exception"

134143 "(search duration : {1} s, timeout: {2} s) : {3}"

135− .format(engine_name, search_duration, timeout_limit, e))

144+ .format(engine_name, engine_time, timeout_limit, e))

136145 requests_exception = True

137146 else:

138147 result_container.add_unresponsive_engine((

searx/webapp.py+21

@@ -43,6 +43,7 @@ except:

4343 exit(1)

4444from cgi import escape

4545from datetime import datetime, timedelta

46+from time import time

4647from werkzeug.contrib.fixers import ProxyFix

4748from flask import (

4849 Flask, request, render_template, url_for, Response, make_response,

@@ -402,6 +403,8 @@ def render(template_name, override_theme=None, **kwargs):

402403

403404@app.before_request

404405def pre_request():

406+ request.start_time = time()

407+ request.timings = []

405408 request.errors = []

406409

407410 preferences = Preferences(themes, list(categories.keys()), engines, plugins)

@@ -437,6 +440,21 @@ def pre_request():

437440 request.user_plugins.append(plugin)

438441

439442

443+@app.after_request

444+def post_request(response):

445+ total_time = time() - request.start_time

446+ timings_all = ['total;dur=' + str(round(total_time * 1000, 3))]

447+ if len(request.timings) > 0:

448+ timings = sorted(request.timings, key=lambda v: v['total'])

449+ timings_total = ['total_' + str(i) + '_' + v['engine'] +

450+ ';dur=' + str(round(v['total'] * 1000, 3)) for i, v in enumerate(timings)]

451+ timings_load = ['load_' + str(i) + '_' + v['engine'] +

452+ ';dur=' + str(round(v['load'] * 1000, 3)) for i, v in enumerate(timings)]

453+ timings_all = timings_all + timings_total + timings_load

454+ response.headers.add('Server-Timing', ', '.join(timings_all))

455+ return response

456+

457+

440458def index_error(output_format, error_message):

441459 if output_format == 'json':

442460 return Response(json.dumps({'error': error_message}),

@@ -515,6 +533,9 @@ def index():

515533 # UI

516534 advanced_search = request.form.get('advanced_search', None)

517535

536+ # Server-Timing header

537+ request.timings = result_container.get_timings()

538+

518539 # output

519540 for result in results:

520541 if output_format == 'html':

tests/unit/test_webapp.py+15−1

@@ -33,6 +33,19 @@ class ViewsTestCase(SearxTestCase):

3333 },

3434 ]

3535

36+ timings = [

37+ {

38+ 'engine': 'startpage',

39+ 'total': 0.8,

40+ 'load': 0.7

41+ },

42+ {

43+ 'engine': 'youtube',

44+ 'total': 0.9,

45+ 'load': 0.6

46+ }

47+ ]

48+

3649 def search_mock(search_self, *args):

3750 search_self.result_container = Mock(get_ordered_results=lambda: self.test_results,

3851 answers=set(),

@@ -42,7 +55,8 @@ class ViewsTestCase(SearxTestCase):

4255 unresponsive_engines=set(),

4356 results=self.test_results,

4457 results_number=lambda: 3,

45− results_length=lambda: len(self.test_results))

58+ results_length=lambda: len(self.test_results),

59+ get_timings=lambda: timings)

4660

4761 Search.search = search_mock

4862