Skip to content

Commit 909708c

Browse files
emdnetoocelotl
emdneto
and
ocelotl
authored
Reset start_time_unix_nano in _ViewInstrumentMatch for aggregation creation (open-telemetry#4137)
* test to fail * Use current time when creating an aggregation in _ViewInstrumentMatch * add changelog and improve test * fix changelog * fix test Signed-off-by: emdneto <[email protected]> --------- Signed-off-by: emdneto <[email protected]> Co-authored-by: Diego Hurtado <[email protected]>
1 parent b380e53 commit 909708c

File tree

4 files changed

+123
-15
lines changed

4 files changed

+123
-15
lines changed

‎CHANGELOG.md‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
99

1010
- Implementation of Events API
1111
([#4054](https://github.com/open-telemetry/opentelemetry-python/pull/4054))
12-
- Make log sdk add `exception.message` to logRecord for exceptions whose argument
12+
- Make log sdk add `exception.message` to logRecord for exceptions whose argument
1313
is an exception not a string message
1414
([#4122](https://github.com/open-telemetry/opentelemetry-python/pull/4122))
1515
- Fix use of `link.attributes.dropped`, which may not exist
@@ -31,6 +31,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
3131
([#4134](https://github.com/open-telemetry/opentelemetry-python/pull/4134))
3232
- Implement Client Key and Certificate File Support for All OTLP Exporters
3333
([#4116](https://github.com/open-telemetry/opentelemetry-python/pull/4116))
34+
- Remove `_start_time_unix_nano` attribute from `_ViewInstrumentMatch` in favor
35+
of using `time_ns()` at the moment when the aggregation object is created
36+
([#4137](https://github.com/open-telemetry/opentelemetry-python/pull/4137))
3437

3538
## Version 1.26.0/0.47b0 (2024-07-25)
3639

‎opentelemetry-sdk/src/opentelemetry/sdk/metrics/_internal/_view_instrument_match.py‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,6 @@ def __init__(
4040
instrument: Instrument,
4141
instrument_class_aggregation: Dict[type, Aggregation],
4242
):
43-
self._start_time_unix_nano = time_ns()
4443
self._view = view
4544
self._instrument = instrument
4645
self._attributes_aggregation: Dict[frozenset, _Aggregation] = {}
@@ -107,7 +106,7 @@ def consume_measurement(self, measurement: Measurement) -> None:
107106
self._view._aggregation._create_aggregation(
108107
self._instrument,
109108
attributes,
110-
self._start_time_unix_nano,
109+
time_ns(),
111110
)
112111
)
113112
else:
@@ -116,7 +115,7 @@ def consume_measurement(self, measurement: Measurement) -> None:
116115
]._create_aggregation(
117116
self._instrument,
118117
attributes,
119-
self._start_time_unix_nano,
118+
time_ns(),
120119
)
121120
self._attributes_aggregation[aggr_key] = aggregation
122121

‎opentelemetry-sdk/tests/metrics/integration_test/test_time_align.py‎

Lines changed: 32 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,11 @@
2626

2727

2828
class TestTimeAlign(TestCase):
29+
30+
# This delay is needed for these tests to pass when they are run in
31+
# Windows.
32+
delay = 0.001
33+
2934
def test_time_align_cumulative(self):
3035
reader = InMemoryMetricReader()
3136
meter_provider = MeterProvider(metric_readers=[reader])
@@ -36,9 +41,11 @@ def test_time_align_cumulative(self):
3641
counter_1 = meter.create_counter("counter_1")
3742

3843
counter_0.add(10, {"label": "value1"})
44+
sleep(self.delay)
3945
counter_0.add(10, {"label": "value2"})
40-
sleep(0.5)
46+
sleep(self.delay)
4147
counter_1.add(10, {"label": "value1"})
48+
sleep(self.delay)
4249
counter_1.add(10, {"label": "value2"})
4350

4451
metrics = reader.get_metrics_data()
@@ -55,12 +62,14 @@ def test_time_align_cumulative(self):
5562
.metrics[1]
5663
.data.data_points
5764
)
65+
self.assertEqual(len(data_points_0_0), 2)
66+
self.assertEqual(len(data_points_0_1), 2)
5867

59-
self.assertEqual(
68+
self.assertLess(
6069
data_points_0_0[0].start_time_unix_nano,
6170
data_points_0_0[1].start_time_unix_nano,
6271
)
63-
self.assertEqual(
72+
self.assertLess(
6473
data_points_0_1[0].start_time_unix_nano,
6574
data_points_0_1[1].start_time_unix_nano,
6675
)
@@ -83,9 +92,11 @@ def test_time_align_cumulative(self):
8392
)
8493

8594
counter_0.add(10, {"label": "value1"})
95+
sleep(self.delay)
8696
counter_0.add(10, {"label": "value2"})
87-
sleep(0.5)
97+
sleep(self.delay)
8898
counter_1.add(10, {"label": "value1"})
99+
sleep(self.delay)
89100
counter_1.add(10, {"label": "value2"})
90101

91102
metrics = reader.get_metrics_data()
@@ -103,11 +114,14 @@ def test_time_align_cumulative(self):
103114
.data.data_points
104115
)
105116

106-
self.assertEqual(
117+
self.assertEqual(len(data_points_1_0), 2)
118+
self.assertEqual(len(data_points_1_1), 2)
119+
120+
self.assertLess(
107121
data_points_1_0[0].start_time_unix_nano,
108122
data_points_1_0[1].start_time_unix_nano,
109123
)
110-
self.assertEqual(
124+
self.assertLess(
111125
data_points_1_1[0].start_time_unix_nano,
112126
data_points_1_1[1].start_time_unix_nano,
113127
)
@@ -161,9 +175,11 @@ def test_time_align_delta(self):
161175
counter_1 = meter.create_counter("counter_1")
162176

163177
counter_0.add(10, {"label": "value1"})
178+
sleep(self.delay)
164179
counter_0.add(10, {"label": "value2"})
165-
sleep(0.5)
180+
sleep(self.delay)
166181
counter_1.add(10, {"label": "value1"})
182+
sleep(self.delay)
167183
counter_1.add(10, {"label": "value2"})
168184

169185
metrics = reader.get_metrics_data()
@@ -180,12 +196,14 @@ def test_time_align_delta(self):
180196
.metrics[1]
181197
.data.data_points
182198
)
199+
self.assertEqual(len(data_points_0_0), 2)
200+
self.assertEqual(len(data_points_0_1), 2)
183201

184-
self.assertEqual(
202+
self.assertLess(
185203
data_points_0_0[0].start_time_unix_nano,
186204
data_points_0_0[1].start_time_unix_nano,
187205
)
188-
self.assertEqual(
206+
self.assertLess(
189207
data_points_0_1[0].start_time_unix_nano,
190208
data_points_0_1[1].start_time_unix_nano,
191209
)
@@ -208,9 +226,11 @@ def test_time_align_delta(self):
208226
)
209227

210228
counter_0.add(10, {"label": "value1"})
229+
sleep(self.delay)
211230
counter_0.add(10, {"label": "value2"})
212-
sleep(0.5)
231+
sleep(self.delay)
213232
counter_1.add(10, {"label": "value1"})
233+
sleep(self.delay)
214234
counter_1.add(10, {"label": "value2"})
215235

216236
metrics = reader.get_metrics_data()
@@ -227,6 +247,8 @@ def test_time_align_delta(self):
227247
.metrics[1]
228248
.data.data_points
229249
)
250+
self.assertEqual(len(data_points_1_0), 2)
251+
self.assertEqual(len(data_points_1_1), 2)
230252

231253
self.assertEqual(
232254
data_points_1_0[0].start_time_unix_nano,

‎opentelemetry-sdk/tests/metrics/test_view_instrument_match.py‎

Lines changed: 85 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,8 +14,9 @@
1414

1515
# pylint: disable=protected-access
1616

17+
from time import time_ns
1718
from unittest import TestCase
18-
from unittest.mock import MagicMock, Mock
19+
from unittest.mock import MagicMock, Mock, patch
1920

2021
from opentelemetry.sdk.metrics._internal._view_instrument_match import (
2122
_ViewInstrumentMatch,
@@ -214,6 +215,89 @@ def test_collect(self):
214215
self.assertEqual(number_data_point.attributes, {"c": "d"})
215216
self.assertEqual(number_data_point.value, 0)
216217

218+
@patch(
219+
"opentelemetry.sdk.metrics._internal._view_instrument_match.time_ns",
220+
side_effect=[0, 1, 2],
221+
)
222+
def test_collect_resets_start_time_unix_nano(self, mock_time_ns):
223+
instrument = Mock(name="instrument")
224+
instrument.instrumentation_scope = self.mock_instrumentation_scope
225+
view_instrument_match = _ViewInstrumentMatch(
226+
view=View(
227+
instrument_name="instrument",
228+
name="name",
229+
aggregation=self.mock_aggregation_factory,
230+
),
231+
instrument=instrument,
232+
instrument_class_aggregation=MagicMock(
233+
**{"__getitem__.return_value": DefaultAggregation()}
234+
),
235+
)
236+
start_time_unix_nano = 0
237+
self.assertEqual(mock_time_ns.call_count, 0)
238+
239+
# +1 call to _create_aggregation
240+
view_instrument_match.consume_measurement(
241+
Measurement(
242+
value=0, instrument=instrument, attributes={"foo": "bar0"}
243+
)
244+
)
245+
view_instrument_match._view._aggregation._create_aggregation.assert_called_with(
246+
instrument, {"foo": "bar0"}, start_time_unix_nano
247+
)
248+
collection_start_time_unix_nano = time_ns()
249+
collected_data_points = view_instrument_match.collect(
250+
AggregationTemporality.CUMULATIVE, collection_start_time_unix_nano
251+
)
252+
self.assertIsNotNone(collected_data_points)
253+
self.assertEqual(len(collected_data_points), 1)
254+
255+
# +1 call to _create_aggregation
256+
view_instrument_match.consume_measurement(
257+
Measurement(
258+
value=0, instrument=instrument, attributes={"foo": "bar1"}
259+
)
260+
)
261+
view_instrument_match._view._aggregation._create_aggregation.assert_called_with(
262+
instrument, {"foo": "bar1"}, 1
263+
)
264+
collection_start_time_unix_nano = time_ns()
265+
collected_data_points = view_instrument_match.collect(
266+
AggregationTemporality.CUMULATIVE, collection_start_time_unix_nano
267+
)
268+
self.assertIsNotNone(collected_data_points)
269+
self.assertEqual(len(collected_data_points), 2)
270+
collected_data_points = view_instrument_match.collect(
271+
AggregationTemporality.CUMULATIVE, collection_start_time_unix_nano
272+
)
273+
# +1 call to create_aggregation
274+
view_instrument_match.consume_measurement(
275+
Measurement(
276+
value=0, instrument=instrument, attributes={"foo": "bar"}
277+
)
278+
)
279+
view_instrument_match._view._aggregation._create_aggregation.assert_called_with(
280+
instrument, {"foo": "bar"}, 2
281+
)
282+
# No new calls to _create_aggregation because attributes remain the same
283+
view_instrument_match.consume_measurement(
284+
Measurement(
285+
value=0, instrument=instrument, attributes={"foo": "bar"}
286+
)
287+
)
288+
view_instrument_match.consume_measurement(
289+
Measurement(
290+
value=0, instrument=instrument, attributes={"foo": "bar"}
291+
)
292+
)
293+
# In total we have 5 calls for _create_aggregation
294+
# 1 from the _ViewInstrumentMatch initialization and 4
295+
# from the consume_measurement calls with different attributes
296+
self.assertEqual(
297+
view_instrument_match._view._aggregation._create_aggregation.call_count,
298+
5,
299+
)
300+
217301
def test_data_point_check(self):
218302
instrument1 = _Counter(
219303
"instrument1",

0 commit comments

Comments
 (0)