tools/chrome_proxy/integration_tests/chrome_proxy_metrics.py

   1 # Copyright 2014 The Chromium Authors. All rights reserved.
   2 # Use of this source code is governed by a BSD-style license that can be
   3 # found in the LICENSE file.
   4
   5 import logging
   6 import time
   7
   8 from integration_tests import network_metrics
   9 from telemetry.page import page_test
  10 from telemetry.value import scalar
  11
  12
  13 class ChromeProxyMetricException(page_test.MeasurementFailure):
  14   pass
  15
  16
  17 CHROME_PROXY_VIA_HEADER = 'Chrome-Compression-Proxy'
  18
  19
  20 class ChromeProxyResponse(network_metrics.HTTPResponse):
  21   """ Represents an HTTP response from a timeleine event."""
  22   def __init__(self, event):
  23     super(ChromeProxyResponse, self).__init__(event)
  24
  25   def ShouldHaveChromeProxyViaHeader(self):
  26     resp = self.response
  27     # Ignore https and data url
  28     if resp.url.startswith('https') or resp.url.startswith('data:'):
  29       return False
  30     # Ignore 304 Not Modified and cache hit.
  31     if resp.status == 304 or resp.served_from_cache:
  32       return False
  33     # Ignore invalid responses that don't have any header. Log a warning.
  34     if not resp.headers:
  35       logging.warning('response for %s does not any have header '
  36                       '(refer=%s, status=%s)',
  37                       resp.url, resp.GetHeader('Referer'), resp.status)
  38       return False
  39     return True
  40
  41   def HasChromeProxyViaHeader(self):
  42     via_header = self.response.GetHeader('Via')
  43     if not via_header:
  44       return False
  45     vias = [v.strip(' ') for v in via_header.split(',')]
  46     # The Via header is valid if it has a 4-character version prefix followed by
  47     # the proxy name, for example, "1.1 Chrome-Compression-Proxy".
  48     return any(v[4:] == CHROME_PROXY_VIA_HEADER for v in vias)
  49
  50   def IsValidByViaHeader(self):
  51     return (not self.ShouldHaveChromeProxyViaHeader() or
  52             self.HasChromeProxyViaHeader())
  53
  54   def GetChromeProxyClientType(self):
  55     """Get the client type directive from the Chrome-Proxy request header.
  56
  57     Returns:
  58         The client type directive from the Chrome-Proxy request header for the
  59         request that lead to this response. For example, if the request header
  60         "Chrome-Proxy: c=android" is present, then this method would return
  61         "android". Returns None if no client type directive is present.
  62     """
  63     if 'Chrome-Proxy' not in self.response.request_headers:
  64       return None
  65
  66     chrome_proxy_request_header = self.response.request_headers['Chrome-Proxy']
  67     values = [v.strip() for v in chrome_proxy_request_header.split(',')]
  68     for value in values:
  69       kvp = value.split('=', 1)
  70       if len(kvp) == 2 and kvp[0].strip() == 'c':
  71         return kvp[1].strip()
  72     return None
  73
  74   def HasChromeProxyLoFi(self):
  75     if 'Chrome-Proxy' not in self.response.request_headers:
  76       return False
  77     chrome_proxy_request_header = self.response.request_headers['Chrome-Proxy']
  78     values = [v.strip() for v in chrome_proxy_request_header.split(',')]
  79     for value in values:
  80       if len(value) == 5 and value == 'q=low':
  81         return True
  82     return False
  83
  84 class ChromeProxyMetric(network_metrics.NetworkMetric):
  85   """A Chrome proxy timeline metric."""
  86
  87   def __init__(self):
  88     super(ChromeProxyMetric, self).__init__()
  89     self.compute_data_saving = True
  90
  91   def SetEvents(self, events):
  92     """Used for unittest."""
  93     self._events = events
  94
  95   def ResponseFromEvent(self, event):
  96     return ChromeProxyResponse(event)
  97
  98   def AddResults(self, tab, results):
  99     raise NotImplementedError
 100
 101   def AddResultsForDataSaving(self, tab, results):
 102     resources_via_proxy = 0
 103     resources_from_cache = 0
 104     resources_direct = 0
 105
 106     super(ChromeProxyMetric, self).AddResults(tab, results)
 107     for resp in self.IterResponses(tab):
 108       if resp.response.served_from_cache:
 109         resources_from_cache += 1
 110       if resp.HasChromeProxyViaHeader():
 111         resources_via_proxy += 1
 112       else:
 113         resources_direct += 1
 114
 115     if resources_from_cache + resources_via_proxy + resources_direct == 0:
 116       raise ChromeProxyMetricException, (
 117           'Expected at least one response, but zero responses were received.')
 118
 119     results.AddValue(scalar.ScalarValue(
 120         results.current_page, 'resources_via_proxy', 'count',
 121         resources_via_proxy))
 122     results.AddValue(scalar.ScalarValue(
 123         results.current_page, 'resources_from_cache', 'count',
 124         resources_from_cache))
 125     results.AddValue(scalar.ScalarValue(
 126         results.current_page, 'resources_direct', 'count', resources_direct))
 127
 128   def AddResultsForHeaderValidation(self, tab, results):
 129     via_count = 0
 130
 131     for resp in self.IterResponses(tab):
 132       if resp.IsValidByViaHeader():
 133         via_count += 1
 134       else:
 135         r = resp.response
 136         raise ChromeProxyMetricException, (
 137             '%s: Via header (%s) is not valid (refer=%s, status=%d)' % (
 138                 r.url, r.GetHeader('Via'), r.GetHeader('Referer'), r.status))
 139
 140     if via_count == 0:
 141       raise ChromeProxyMetricException, (
 142           'Expected at least one response through the proxy, but zero such '
 143           'responses were received.')
 144     results.AddValue(scalar.ScalarValue(
 145         results.current_page, 'checked_via_header', 'count', via_count))
 146
 147   def AddResultsForLatency(self, tab, results):
 148     # TODO(bustamante): This is a hack to workaround crbug.com/467174,
 149     #   once fixed just pull down window.performance.timing object and
 150     #   reference that everywhere.
 151     load_event_start = tab.EvaluateJavaScript(
 152         'window.performance.timing.loadEventStart')
 153     navigation_start = tab.EvaluateJavaScript(
 154         'window.performance.timing.navigationStart')
 155     dom_content_loaded_event_start = tab.EvaluateJavaScript(
 156         'window.performance.timing.domContentLoadedEventStart')
 157     fetch_start = tab.EvaluateJavaScript(
 158         'window.performance.timing.fetchStart')
 159     request_start = tab.EvaluateJavaScript(
 160         'window.performance.timing.requestStart')
 161     domain_lookup_end = tab.EvaluateJavaScript(
 162         'window.performance.timing.domainLookupEnd')
 163     domain_lookup_start = tab.EvaluateJavaScript(
 164         'window.performance.timing.domainLookupStart')
 165     connect_end = tab.EvaluateJavaScript(
 166         'window.performance.timing.connectEnd')
 167     connect_start = tab.EvaluateJavaScript(
 168         'window.performance.timing.connectStart')
 169     response_end = tab.EvaluateJavaScript(
 170         'window.performance.timing.responseEnd')
 171     response_start = tab.EvaluateJavaScript(
 172         'window.performance.timing.responseStart')
 173
 174     # NavigationStart relative markers in milliseconds.
 175     load_start = (float(load_event_start) - navigation_start)
 176     results.AddValue(scalar.ScalarValue(
 177         results.current_page, 'load_start', 'ms', load_start))
 178
 179     dom_content_loaded_start = (
 180       float(dom_content_loaded_event_start) - navigation_start)
 181     results.AddValue(scalar.ScalarValue(
 182         results.current_page, 'dom_content_loaded_start', 'ms',
 183         dom_content_loaded_start))
 184
 185     fetch_start = (float(fetch_start) - navigation_start)
 186     results.AddValue(scalar.ScalarValue(
 187         results.current_page, 'fetch_start', 'ms', fetch_start,
 188         important=False))
 189
 190     request_start = (float(request_start) - navigation_start)
 191     results.AddValue(scalar.ScalarValue(
 192         results.current_page, 'request_start', 'ms', request_start,
 193         important=False))
 194
 195     # Phase measurements in milliseconds.
 196     domain_lookup_duration = (float(domain_lookup_end) - domain_lookup_start)
 197     results.AddValue(scalar.ScalarValue(
 198         results.current_page, 'domain_lookup_duration', 'ms',
 199         domain_lookup_duration, important=False))
 200
 201     connect_duration = (float(connect_end) - connect_start)
 202     results.AddValue(scalar.ScalarValue(
 203         results.current_page, 'connect_duration', 'ms', connect_duration,
 204         important=False))
 205
 206     request_duration = (float(response_start) - request_start)
 207     results.AddValue(scalar.ScalarValue(
 208         results.current_page, 'request_duration', 'ms', request_duration,
 209         important=False))
 210
 211     response_duration = (float(response_end) - response_start)
 212     results.AddValue(scalar.ScalarValue(
 213         results.current_page, 'response_duration', 'ms', response_duration,
 214         important=False))
 215
 216   def AddResultsForClientVersion(self, tab, results):
 217     via_count = 0
 218     for resp in self.IterResponses(tab):
 219       r = resp.response
 220       if resp.response.status != 200:
 221         raise ChromeProxyMetricException, ('%s: Response is not 200: %d' %
 222                                            (r.url, r.status))
 223       if not resp.IsValidByViaHeader():
 224         raise ChromeProxyMetricException, ('%s: Response missing via header' %
 225                                            (r.url))
 226       via_count += 1
 227
 228     if via_count == 0:
 229       raise ChromeProxyMetricException, (
 230           'Expected at least one response through the proxy, but zero such '
 231           'responses were received.')
 232     results.AddValue(scalar.ScalarValue(
 233         results.current_page, 'responses_via_proxy', 'count', via_count))
 234
 235   def GetClientTypeFromRequests(self, tab):
 236     """Get the Chrome-Proxy client type value from requests made in this tab.
 237
 238     Returns:
 239         The client type value from the first request made in this tab that
 240         specifies a client type in the Chrome-Proxy request header. See
 241         ChromeProxyResponse.GetChromeProxyClientType for more details about the
 242         Chrome-Proxy client type. Returns None if none of the requests made in
 243         this tab specify a client type.
 244     """
 245     for resp in self.IterResponses(tab):
 246       client_type = resp.GetChromeProxyClientType()
 247       if client_type:
 248         return client_type
 249     return None
 250
 251   def AddResultsForClientType(self, tab, results, client_type,
 252                               bypass_for_client_type):
 253     via_count = 0
 254     bypass_count = 0
 255
 256     for resp in self.IterResponses(tab):
 257       if resp.HasChromeProxyViaHeader():
 258         via_count += 1
 259         if client_type.lower() == bypass_for_client_type.lower():
 260           raise ChromeProxyMetricException, (
 261               '%s: Response for client of type "%s" has via header, but should '
 262               'be bypassed.' % (
 263                   resp.response.url, bypass_for_client_type, client_type))
 264       elif resp.ShouldHaveChromeProxyViaHeader():
 265         bypass_count += 1
 266         if client_type.lower() != bypass_for_client_type.lower():
 267           raise ChromeProxyMetricException, (
 268               '%s: Response missing via header. Only "%s" clients should '
 269               'bypass for this page, but this client is "%s".' % (
 270                   resp.response.url, bypass_for_client_type, client_type))
 271
 272     if via_count + bypass_count == 0:
 273       raise ChromeProxyMetricException, (
 274           'Expected at least one response that was eligible to be proxied, but '
 275           'zero such responses were received.')
 276
 277     results.AddValue(scalar.ScalarValue(
 278         results.current_page, 'via', 'count', via_count))
 279     results.AddValue(scalar.ScalarValue(
 280         results.current_page, 'bypass', 'count', bypass_count))
 281
 282   def AddResultsForLoFi(self, tab, results):
 283     lo_fi_count = 0
 284
 285     for resp in self.IterResponses(tab):
 286       if resp.HasChromeProxyLoFi():
 287         lo_fi_count += 1
 288       else:
 289         raise ChromeProxyMetricException, (
 290             '%s: LoFi not in request header.' % (resp.response.url))
 291
 292       if resp.content_length > 100:
 293         raise ChromeProxyMetricException, (
 294             'Image %s is %d bytes. Expecting less than 100 bytes.' %
 295             (resp.response.url, resp.content_length))
 296
 297     if lo_fi_count == 0:
 298       raise ChromeProxyMetricException, (
 299           'Expected at least one LoFi response, but zero such responses were '
 300           'received.')
 301
 302     results.AddValue(scalar.ScalarValue(
 303         results.current_page, 'lo_fi', 'count', lo_fi_count))
 304     super(ChromeProxyMetric, self).AddResults(tab, results)
 305
 306   def AddResultsForBypass(self, tab, results):
 307     bypass_count = 0
 308
 309     for resp in self.IterResponses(tab):
 310       if resp.HasChromeProxyViaHeader():
 311         r = resp.response
 312         raise ChromeProxyMetricException, (
 313             '%s: Should not have Via header (%s) (refer=%s, status=%d)' % (
 314                 r.url, r.GetHeader('Via'), r.GetHeader('Referer'), r.status))
 315       bypass_count += 1
 316
 317     if bypass_count == 0:
 318       raise ChromeProxyMetricException, (
 319           'Expected at least one response to be bypassed, but zero such '
 320           'responses were received.')
 321     results.AddValue(scalar.ScalarValue(
 322         results.current_page, 'bypass', 'count', bypass_count))
 323
 324   def AddResultsForCorsBypass(self, tab, results):
 325     eligible_response_count = 0
 326     bypass_count = 0
 327     bypasses = {}
 328     for resp in self.IterResponses(tab):
 329       logging.warn('got a resource %s' % (resp.response.url))
 330
 331     for resp in self.IterResponses(tab):
 332       if resp.ShouldHaveChromeProxyViaHeader():
 333         eligible_response_count += 1
 334         if not resp.HasChromeProxyViaHeader():
 335           bypass_count += 1
 336         elif resp.response.status == 502:
 337           bypasses[resp.response.url] = 0
 338
 339     for resp in self.IterResponses(tab):
 340       if resp.ShouldHaveChromeProxyViaHeader():
 341         if not resp.HasChromeProxyViaHeader():
 342           if resp.response.status == 200:
 343             if (bypasses.has_key(resp.response.url)):
 344               bypasses[resp.response.url] = bypasses[resp.response.url] + 1
 345
 346     for url in bypasses:
 347       if bypasses[url] == 0:
 348         raise ChromeProxyMetricException, (
 349               '%s: Got a 502 without a subsequent 200' % (url))
 350       elif bypasses[url] > 1:
 351         raise ChromeProxyMetricException, (
 352               '%s: Got a 502 and multiple 200s: %d' % (url, bypasses[url]))
 353     if bypass_count == 0:
 354       raise ChromeProxyMetricException, (
 355           'At least one response should be bypassed. '
 356           '(eligible_response_count=%d, bypass_count=%d)\n' % (
 357               eligible_response_count, bypass_count))
 358
 359     results.AddValue(scalar.ScalarValue(
 360         results.current_page, 'cors_bypass', 'count', bypass_count))
 361
 362   def AddResultsForBlockOnce(self, tab, results):
 363     eligible_response_count = 0
 364     bypass_count = 0
 365
 366     for resp in self.IterResponses(tab):
 367       if resp.ShouldHaveChromeProxyViaHeader():
 368         eligible_response_count += 1
 369         if not resp.HasChromeProxyViaHeader():
 370           bypass_count += 1
 371
 372     if eligible_response_count <= 1:
 373       raise ChromeProxyMetricException, (
 374           'There should be more than one DRP eligible response '
 375           '(eligible_response_count=%d, bypass_count=%d)\n' % (
 376               eligible_response_count, bypass_count))
 377     elif bypass_count != 1:
 378       raise ChromeProxyMetricException, (
 379           'Exactly one response should be bypassed. '
 380           '(eligible_response_count=%d, bypass_count=%d)\n' % (
 381               eligible_response_count, bypass_count))
 382     else:
 383       results.AddValue(scalar.ScalarValue(
 384           results.current_page, 'eligible_responses', 'count',
 385           eligible_response_count))
 386       results.AddValue(scalar.ScalarValue(
 387           results.current_page, 'bypass', 'count', bypass_count))
 388
 389   def AddResultsForSafebrowsingOn(self, tab, results):
 390     results.AddValue(scalar.ScalarValue(
 391         results.current_page, 'safebrowsing', 'timeout responses', 1))
 392
 393   def AddResultsForSafebrowsingOff(self, tab, results):
 394     response_count = 0
 395     for resp in self.IterResponses(tab):
 396       # Data reduction proxy should return the real response for sites with
 397       # malware.
 398       response_count += 1
 399       if not resp.HasChromeProxyViaHeader():
 400         r = resp.response
 401         raise ChromeProxyMetricException, (
 402             '%s: Safebrowsing feature should be off for desktop and webview.\n'
 403             'Reponse: status=(%d, %s)\nHeaders:\n %s' % (
 404                 r.url, r.status, r.status_text, r.headers))
 405
 406     if response_count == 0:
 407       raise ChromeProxyMetricException, (
 408           'Safebrowsing test failed: No valid responses received')
 409
 410     results.AddValue(scalar.ScalarValue(
 411         results.current_page, 'safebrowsing', 'responses', response_count))
 412
 413   def AddResultsForHTTPFallback(self, tab, results):
 414     via_fallback_count = 0
 415
 416     for resp in self.IterResponses(tab):
 417       if resp.ShouldHaveChromeProxyViaHeader():
 418         # All responses should have come through the HTTP fallback proxy, which
 419         # means that they should have the via header, and if a remote port is
 420         # defined, it should be port 80.
 421         if (not resp.HasChromeProxyViaHeader() or
 422             (resp.remote_port and resp.remote_port != 80)):
 423           r = resp.response
 424           raise ChromeProxyMetricException, (
 425               '%s: Should have come through the fallback proxy.\n'
 426               'Reponse: remote_port=%s status=(%d, %s)\nHeaders:\n %s' % (
 427                   r.url, str(resp.remote_port), r.status, r.status_text,
 428                   r.headers))
 429         via_fallback_count += 1
 430
 431     if via_fallback_count == 0:
 432       raise ChromeProxyMetricException, (
 433           'Expected at least one response through the fallback proxy, but zero '
 434           'such responses were received.')
 435     results.AddValue(scalar.ScalarValue(
 436         results.current_page, 'via_fallback', 'count', via_fallback_count))
 437
 438   def AddResultsForHTTPToDirectFallback(self, tab, results,
 439                                         fallback_response_host):
 440     via_fallback_count = 0
 441     bypass_count = 0
 442     responses = self.IterResponses(tab)
 443
 444     # The first response(s) coming from fallback_response_host should be
 445     # through the HTTP fallback proxy.
 446     resp = next(responses, None)
 447     while resp and fallback_response_host in resp.response.url:
 448       if fallback_response_host in resp.response.url:
 449         if (not resp.HasChromeProxyViaHeader() or resp.remote_port != 80):
 450           r = resp.response
 451           raise ChromeProxyMetricException, (
 452               'Response for %s should have come through the fallback proxy.\n'
 453               'Response: remote_port=%s status=(%d, %s)\nHeaders:\n %s' % (
 454                 r.url, str(resp.remote_port), r.status, r.status_text,
 455                 r.headers))
 456         else:
 457           via_fallback_count += 1
 458       resp = next(responses, None)
 459
 460     # All other responses should be bypassed.
 461     while resp:
 462       if resp.HasChromeProxyViaHeader():
 463         r = resp.response
 464         raise ChromeProxyMetricException, (
 465             'Response for %s should not have via header.\n'
 466             'Response: status=(%d, %s)\nHeaders:\n %s' % (
 467                 r.url, r.status, r.status_text, r.headers))
 468       else:
 469         bypass_count += 1
 470       resp = next(responses, None)
 471
 472     # At least one response should go through the http proxy and be bypassed.
 473     if via_fallback_count == 0 or bypass_count == 0:
 474       raise ChromeProxyMetricException(
 475           'There should be at least one response through the fallback proxy '
 476           '(actual %s) and at least one bypassed response (actual %s)' %
 477           (via_fallback_count, bypass_count))
 478
 479     results.AddValue(scalar.ScalarValue(
 480         results.current_page, 'via_fallback', 'count', via_fallback_count))
 481     results.AddValue(scalar.ScalarValue(
 482         results.current_page, 'bypass', 'count', bypass_count))
 483
 484   def AddResultsForReenableAfterBypass(
 485       self, tab, results, bypass_seconds_min, bypass_seconds_max):
 486     """Verify results for a re-enable after bypass test.
 487
 488     Args:
 489         tab: the tab for the test.
 490         results: the results object to add the results values to.
 491         bypass_seconds_min: the minimum duration of the bypass.
 492         bypass_seconds_max: the maximum duration of the bypass.
 493     """
 494     bypass_count = 0
 495     via_count = 0
 496
 497     for resp in self.IterResponses(tab):
 498       if resp.HasChromeProxyViaHeader():
 499         r = resp.response
 500         raise ChromeProxyMetricException, (
 501             'Response for %s should not have via header.\n'
 502             'Reponse: status=(%d, %s)\nHeaders:\n %s' % (
 503                 r.url, r.status, r.status_text, r.headers))
 504       else:
 505         bypass_count += 1
 506
 507     # Wait until 30 seconds before the bypass should expire, and fetch a page.
 508     # It should not have the via header because the proxy should still be
 509     # bypassed.
 510     time.sleep(bypass_seconds_min - 30)
 511
 512     tab.ClearCache(force=True)
 513     before_metrics = ChromeProxyMetric()
 514     before_metrics.Start(results.current_page, tab)
 515     tab.Navigate('http://chromeproxy-test.appspot.com/default')
 516     tab.WaitForJavaScriptExpression('performance.timing.loadEventStart', 10)
 517     before_metrics.Stop(results.current_page, tab)
 518
 519     for resp in before_metrics.IterResponses(tab):
 520       if resp.HasChromeProxyViaHeader():
 521         r = resp.response
 522         raise ChromeProxyMetricException, (
 523             'Response for %s should not have via header; proxy should still '
 524             'be bypassed.\nReponse: status=(%d, %s)\nHeaders:\n %s' % (
 525                 r.url, r.status, r.status_text, r.headers))
 526       else:
 527         bypass_count += 1
 528     if bypass_count == 0:
 529       raise ChromeProxyMetricException, (
 530           'Expected at least one response to be bypassed before the bypass '
 531           'expired, but zero such responses were received.')
 532
 533     # Wait until 30 seconds after the bypass should expire, and fetch a page. It
 534     # should have the via header since the proxy should no longer be bypassed.
 535     time.sleep((bypass_seconds_max + 30) - (bypass_seconds_min - 30))
 536
 537     tab.ClearCache(force=True)
 538     after_metrics = ChromeProxyMetric()
 539     after_metrics.Start(results.current_page, tab)
 540     tab.Navigate('http://chromeproxy-test.appspot.com/default')
 541     tab.WaitForJavaScriptExpression('performance.timing.loadEventStart', 10)
 542     after_metrics.Stop(results.current_page, tab)
 543
 544     for resp in after_metrics.IterResponses(tab):
 545       if not resp.HasChromeProxyViaHeader():
 546         r = resp.response
 547         raise ChromeProxyMetricException, (
 548             'Response for %s should have via header; proxy should no longer '
 549             'be bypassed.\nReponse: status=(%d, %s)\nHeaders:\n %s' % (
 550                 r.url, r.status, r.status_text, r.headers))
 551       else:
 552         via_count += 1
 553     if via_count == 0:
 554       raise ChromeProxyMetricException, (
 555           'Expected at least one response through the proxy after the bypass '
 556           'expired, but zero such responses were received.')
 557
 558     results.AddValue(scalar.ScalarValue(
 559         results.current_page, 'bypass', 'count', bypass_count))
 560     results.AddValue(scalar.ScalarValue(
 561         results.current_page, 'via', 'count', via_count))