diff --git a/contrib/opencensus-ext-azure/CHANGELOG.md b/contrib/opencensus-ext-azure/CHANGELOG.md index 9655e02e0..53175aa45 100644 --- a/contrib/opencensus-ext-azure/CHANGELOG.md +++ b/contrib/opencensus-ext-azure/CHANGELOG.md @@ -3,6 +3,8 @@ ## Unreleased - Standard metrics incoming requests per second ([#758](https://github.com/census-instrumentation/opencensus-python/pull/758)) +- Standard metrics incoming requests average execution rate + ([#773](https://github.com/census-instrumentation/opencensus-python/pull/773)) ## 0.7.0 Released 2019-07-31 diff --git a/contrib/opencensus-ext-azure/README.rst b/contrib/opencensus-ext-azure/README.rst index 451086d02..cdc5c955c 100644 --- a/contrib/opencensus-ext-azure/README.rst +++ b/contrib/opencensus-ext-azure/README.rst @@ -154,6 +154,7 @@ Below is a list of standard metrics that are currently available: - Available Memory (bytes) - CPU Processor Time (percentage) - Incoming Request Rate (per second) +- Incoming Request Average Execution Time (milliseconds) - Outgoing Request Rate (per second) - Process CPU Usage (percentage) - Process Private Bytes (bytes) diff --git a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/__init__.py b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/__init__.py index 162f015a0..fc6a1c235 100644 --- a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/__init__.py +++ b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/__init__.py @@ -24,6 +24,8 @@ import ProcessCPUMetric from opencensus.ext.azure.metrics_exporter.standard_metrics.process \ import ProcessMemoryMetric +from opencensus.ext.azure.metrics_exporter.standard_metrics.http_requests \ + import RequestsAvgExecutionMetric from opencensus.ext.azure.metrics_exporter.standard_metrics.http_requests \ import RequestsRateMetric @@ -33,6 +35,7 @@ ProcessCPUMetric, ProcessMemoryMetric, ProcessorTimeMetric, + RequestsAvgExecutionMetric, RequestsRateMetric] diff --git a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_dependency.py b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_dependency.py index ac4e3da37..4a00a4f5f 100644 --- a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_dependency.py +++ b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_dependency.py @@ -13,12 +13,14 @@ # limitations under the License. import requests +import threading import time from opencensus.metrics.export.gauge import DerivedDoubleGauge from opencensus.trace import execution_context dependency_map = dict() +_dependency_lock = threading.Lock() ORIGINAL_REQUEST = requests.Session.request @@ -26,8 +28,10 @@ def dependency_patch(*args, **kwargs): result = ORIGINAL_REQUEST(*args, **kwargs) # Only collect request metric if sent from non-exporter thread if not execution_context.is_exporter(): - count = dependency_map.get('count', 0) - dependency_map['count'] = count + 1 + # We don't want multiple threads updating this at once + with _dependency_lock: + count = dependency_map.get('count', 0) + dependency_map['count'] = count + 1 return result diff --git a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_requests.py b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_requests.py index 1a78da4fc..b19f77b55 100644 --- a/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_requests.py +++ b/contrib/opencensus-ext-azure/opencensus/ext/azure/metrics_exporter/standard_metrics/http_requests.py @@ -13,6 +13,7 @@ # limitations under the License. import sys +import threading import time from opencensus.metrics.export.gauge import DerivedDoubleGauge @@ -21,16 +22,32 @@ else: from http.server import HTTPServer +_requests_lock = threading.Lock() requests_map = dict() ORIGINAL_CONSTRUCTOR = HTTPServer.__init__ def request_patch(func): def wrapper(self=None): + start_time = time.time() func(self) + end_time = time.time() + + update_request_state(start_time, end_time) + + return wrapper + + +def update_request_state(start_time, end_time): + # Update requests state information + # We don't want multiple threads updating this at once + with _requests_lock: + # Update Count count = requests_map.get('count', 0) requests_map['count'] = count + 1 - return wrapper + # Update duration + duration = requests_map.get('duration', 0) + requests_map['duration'] = duration + (end_time - start_time) def server_patch(*args, **kwargs): @@ -59,6 +76,76 @@ def setup(): HTTPServer.__init__ = server_patch +def get_average_execution_time(): + last_average_duration = requests_map.get('last_average_duration', 0) + interval_duration = requests_map.get('duration', 0) \ + - requests_map.get('last_duration', 0) + interval_count = requests_map.get('count', 0) \ + - requests_map.get('last_count', 0) + try: + result = interval_duration / interval_count + requests_map['last_average_duration'] = result + requests_map['last_duration'] = requests_map.get('duration', 0) + # Convert to milliseconds + return result * 1000.0 + except ZeroDivisionError: + # If interval_count is 0, exporter call made too close to previous + # Return the previous result if this is the case + return last_average_duration * 1000.0 + + +def get_requests_rate(): + current_time = time.time() + last_rate = requests_map.get('last_rate', 0) + last_time = requests_map.get('last_time') + + try: + # last_rate_time is None the first time this function is called + if last_time is not None: + interval_time = current_time - requests_map.get('last_time', 0) + interval_count = requests_map.get('count', 0) \ + - requests_map.get('last_count', 0) + result = interval_count / interval_time + else: + result = 0 + requests_map['last_time'] = current_time + requests_map['last_count'] = requests_map.get('count', 0) + requests_map['last_rate'] = result + return result + except ZeroDivisionError: + # If elapsed_seconds is 0, exporter call made too close to previous + # Return the previous result if this is the case + return last_rate + + +class RequestsAvgExecutionMetric(object): + NAME = "\\ASP.NET Applications(??APP_W3SVC_PROC??)\\Request Execution Time" + + def __init__(self): + setup() + + @staticmethod + def get_value(): + return get_average_execution_time() + + def __call__(self): + """ Returns a derived gauge for incoming requests execution rate + + Calculated by getting the time it takes to make an incoming request + and dividing over the amount of incoming requests over an elapsed time. + + :rtype: :class:`opencensus.metrics.export.gauge.DerivedLongGauge` + :return: The gauge representing the incoming requests metric + """ + gauge = DerivedDoubleGauge( + RequestsAvgExecutionMetric.NAME, + 'Incoming Requests Average Execution Rate', + 'milliseconds', + []) + gauge.create_default_time_series(RequestsAvgExecutionMetric.get_value) + return gauge + + class RequestsRateMetric(object): NAME = "\\ASP.NET Applications(??APP_W3SVC_PROC??)\\Requests/Sec" @@ -67,28 +154,7 @@ def __init__(self): @staticmethod def get_value(): - current_count = requests_map.get('count', 0) - current_time = time.time() - last_count = requests_map.get('last_count', 0) - last_time = requests_map.get('last_time') - last_result = requests_map.get('last_result', 0) - - try: - # last_time is None the very first time this function is called - if last_time is not None: - elapsed_seconds = current_time - last_time - interval_count = current_count - last_count - result = interval_count / elapsed_seconds - else: - result = 0 - requests_map['last_time'] = current_time - requests_map['last_count'] = current_count - requests_map['last_result'] = result - return result - except ZeroDivisionError: - # If elapsed_seconds is 0, exporter call made too close to previous - # Return the previous result if this is the case - return last_result + return get_requests_rate() def __call__(self): """ Returns a derived gauge for incoming requests per second diff --git a/contrib/opencensus-ext-azure/tests/test_azure_standard_metrics.py b/contrib/opencensus-ext-azure/tests/test_azure_standard_metrics.py index f98df0c88..70aaf4e30 100644 --- a/contrib/opencensus-ext-azure/tests/test_azure_standard_metrics.py +++ b/contrib/opencensus-ext-azure/tests/test_azure_standard_metrics.py @@ -48,12 +48,12 @@ def test_producer_get_metrics(self): producer = standard_metrics.AzureStandardMetricsProducer() metrics = producer.get_metrics() - self.assertEqual(len(metrics), 6) + self.assertEqual(len(metrics), 7) def test_register_metrics(self): registry = standard_metrics.register_metrics() - self.assertEqual(len(registry.get_metrics()), 6) + self.assertEqual(len(registry.get_metrics()), 7) def test_get_available_memory_metric(self): metric = standard_metrics.AvailableMemoryMetric() @@ -201,6 +201,7 @@ def test_request_patch(self): new_func() self.assertEqual(map['count'], 1) + self.assertIsNotNone(map['duration']) self.assertEqual(len(func.call_args_list), 1) def test_server_patch(self): @@ -267,34 +268,60 @@ def test_server_patch_no_handler(self): self.assertEqual(r, None) - def test_get_request_rate_metric(self): + def test_get_requests_rate_metric(self): metric = standard_metrics.RequestsRateMetric() gauge = metric() name = '\\ASP.NET Applications(??APP_W3SVC_PROC??)\\Requests/Sec' self.assertEqual(gauge.descriptor.name, name) - def test_get_request_rate_first_time(self): - rate = standard_metrics.RequestsRateMetric.get_value() + def test_get_requests_rate_first_time(self): + rate = standard_metrics.http_requests.get_requests_rate() self.assertEqual(rate, 0) @mock.patch('opencensus.ext.azure.metrics_exporter' '.standard_metrics.http_requests.time') - def test_get_request_rate(self, time_mock): + def test_get_requests_rate(self, time_mock): time_mock.time.return_value = 100 standard_metrics.http_requests.requests_map['last_time'] = 98 standard_metrics.http_requests.requests_map['count'] = 4 - rate = standard_metrics.RequestsRateMetric.get_value() + rate = standard_metrics.http_requests.get_requests_rate() self.assertEqual(rate, 2) @mock.patch('opencensus.ext.azure.metrics_exporter' '.standard_metrics.http_requests.time') - def test_get_request_rate_error(self, time_mock): + def test_get_requests_rate_error(self, time_mock): time_mock.time.return_value = 100 - standard_metrics.http_requests.requests_map['last_result'] = 5 + standard_metrics.http_requests.requests_map['last_rate'] = 5 standard_metrics.http_requests.requests_map['last_time'] = 100 - result = standard_metrics.RequestsRateMetric.get_value() + result = standard_metrics.http_requests.get_requests_rate() self.assertEqual(result, 5) + + def test_get_requests_execution_metric(self): + metric = standard_metrics.RequestsAvgExecutionMetric() + gauge = metric() + + name = '\\ASP.NET Applications(??APP_W3SVC_PROC??)' \ + '\\Request Execution Time' + self.assertEqual(gauge.descriptor.name, name) + + def test_get_requests_execution(self): + map = standard_metrics.http_requests.requests_map + map['duration'] = 0.1 + map['count'] = 10 + map['last_count'] = 5 + result = standard_metrics.http_requests.get_average_execution_time() + + self.assertEqual(result, 20) + + def test_get_requests_execution_error(self): + map = standard_metrics.http_requests.requests_map + map['duration'] = 0.1 + map['count'] = 10 + map['last_count'] = 10 + result = standard_metrics.http_requests.get_average_execution_time() + + self.assertEqual(result, 0)