fix Timestamp issue caused by creating the metric context too early

Author: jaredcnance

aws_embedded_metrics/metric_scope/__init__.py

@@ -18,12 +18,12 @@
 
 
 def metric_scope(fn):  # type: ignore
-    logger = create_metrics_logger()
 
     if asyncio.iscoroutinefunction(fn):
 
         @wraps(fn)
         async def wrapper(*args, **kwargs):  # type: ignore
+            logger = create_metrics_logger()
             if "metrics" in inspect.signature(fn).parameters:
                 kwargs["metrics"] = logger
             try:
@@ -38,6 +38,7 @@ async def wrapper(*args, **kwargs):  # type: ignore
 
         @wraps(fn)
         def wrapper(*args, **kwargs):  # type: ignore
+            logger = create_metrics_logger()
             if "metrics" in inspect.signature(fn).parameters:
                 kwargs["metrics"] = logger
             try:

tests/logger/test_metrics_context.py

@@ -1,24 +1,13 @@
 from aws_embedded_metrics import config
 from aws_embedded_metrics.logger.metrics_context import MetricsContext
-from aws_embedded_metrics import utils
 from aws_embedded_metrics.constants import DEFAULT_NAMESPACE
-from _pytest.monkeypatch import MonkeyPatch
-import pytest
 from importlib import reload
 from faker import Faker
 
 fake = Faker()
 
 
-@pytest.fixture
-def mock_time():
-    expected_time = fake.random.randrange(0, 1000)
-    monkeypatch = MonkeyPatch()
-    monkeypatch.setattr(utils, "now", lambda: expected_time)
-    return expected_time
-
-
-def test_can_create_context_with_no_arguments(mock_time):
+def test_can_create_context_with_no_arguments():
     # reload the configuration module since it is loaded on
     # startup and cached
     reload(config)
@@ -29,13 +18,13 @@ def test_can_create_context_with_no_arguments(mock_time):
 
     # assert
     assert context.namespace == DEFAULT_NAMESPACE
-    assert context.meta == {"Timestamp": mock_time}
+    assert context.meta["Timestamp"] > 0
     assert context.properties == {}
     assert context.dimensions == []
     assert context.default_dimensions == {}
 
 
-def test_can_set_property(mock_time):
+def test_can_set_property():
     # arrange
     context = MetricsContext()
 
@@ -49,7 +38,7 @@ def test_can_set_property(mock_time):
     assert context.properties == {property_key: property_value}
 
 
-def test_put_dimension_adds_to_dimensions(mock_time):
+def test_put_dimension_adds_to_dimensions():
     # arrange
     context = MetricsContext()
 

tests/metric_scope/test_metric_scope.py

@@ -1,6 +1,7 @@
 from aws_embedded_metrics.metric_scope import metric_scope
 from aws_embedded_metrics.logger.metrics_logger import MetricsLogger
 import asyncio
+import time
 import pytest
 
 flush_invocations = []
@@ -149,6 +150,24 @@ def my_handler(metrics):
     assert InvocationTracker.invocations == 1
 
 
+def test_sync_scope_sets_time_based_on_when_wrapped_fcn_is_called(mock_logger):
+    # arrange
+    sleep_duration_sec = 3
+
+    @metric_scope
+    def my_handler(metrics):
+        return metrics
+
+    time.sleep(sleep_duration_sec)
+
+    # act
+    expected_timestamp_second = int(round(time.time()))
+    logger = my_handler()
+
+    # assert
+    actual_timestamp_second = int(round(logger.context.meta["Timestamp"] / 1000))
+    assert expected_timestamp_second == actual_timestamp_second
+
 # Test helpers