fix(sdk-metrics): fix flaky LastValueAggregator test by using fake timer

[pichlermarc]

Which problem is this PR solving?

This PR fixes the flaky test described in #3572 by using fake timers instead of setting and awaiting timeouts.

Fixes #3572

Type of change

Please delete options that are not relevant.

• Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

• Locally tests in a loop

Checklist:

• Followed the style guidelines of this project
• Unit tests have been added
• Documentation has been updated

[codecov]

Codecov Report

Merging #3587 (9f99a84) into main (2b59c28) will decrease coverage by 3.07%.
The diff coverage is n/a.

❗ Current head 9f99a84 differs from pull request most recent head f62ab0d. Consider uploading reports for the commit f62ab0d to get more accurate results

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #3587      +/-   ##
==========================================
- Coverage   93.90%   90.84%   -3.07%     
==========================================
  Files         255       77     -178     
  Lines        7763     1671    -6092     
  Branches     1613      339    -1274     
==========================================
- Hits         7290     1518    -5772     
+ Misses        473      153     -320     

Impacted Files	Coverage Δ
api/src/platform/node/globalThis.ts	0.00% <0.00%> (-100.00%)	⬇️
...lemetry-resources/src/detectors/ProcessDetector.ts	31.81% <0.00%> (-68.19%)	⬇️
packages/opentelemetry-sdk-trace-web/src/utils.ts	65.83% <0.00%> (-29.20%)	⬇️
...lemetry-resources/src/detectors/BrowserDetector.ts	93.33% <0.00%> (-6.67%)	⬇️
api/src/baggage/utils.ts	100.00% <0.00%> (ø)
...es/opentelemetry-context-zone-peer-dep/src/util.ts
...ges/opentelemetry-exporter-zipkin/src/transform.ts
packages/sdk-metrics/src/Instruments.ts
...s/opentelemetry-core/src/platform/node/sdk-info.ts
...opentelemetry-core/src/platform/node/globalThis.ts
... and 174 more

[naseemkullah]

👍

[legendecas]

According to the logs in #3572, LastValueAggregator.merge returned the value of accumulation2, which is supposed to be sampled earlier than accumulation1.

LastValueAggregator.merge returns the value of the second parameter, when the sample time of the second accumulation is greater than or equal to the first parameter: https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/sdk-metrics/src/aggregator/LastValue.ts#L71. That is to say, when the accumulation2's sample time is equal to accumulation1's, accumulation2's value is returned.

The timeout is used to verify the sample time of the accumulation. In #3572, I found that the merged last value accumulation has a sample time of milliseconds precision. I'd think that the flakiness is introduced in #3514, which changed the sample time precision to milliseconds. In the tests, we use sleep 1ms to increase the sample time of the updated accumulation. Although I can not reproduce the flaky issue locally, I think we should loosen the 1ms sleep too.

[pichlermarc]

According to the logs in #3572, LastValueAggregator.merge returned the value of accumulation2, which is supposed to be sampled earlier than accumulation1.

LastValueAggregator.merge returns the value of the second parameter, when the sample time of the second accumulation is greater than or equal to the first parameter: main/packages/sdk-metrics/src/aggregator/LastValue.ts#L71. That is to say, when the accumulation2's sample time is equal to accumulation1's, accumulation2's value is returned.

The timeout is used to verify the sample time of the accumulation. In #3572, I found that the merged last value accumulation has a sample time of milliseconds precision. I'd think that the flakiness is introduced in #3514, which changed the sample time precision to milliseconds. In the tests, we use sleep 1ms to increase the sample time of the updated accumulation. Although I can not reproduce the flaky issue locally, I think we should loosen the 1ms sleep too.

Thank you for the input 🙂 If I understand correctly, this was exactly the case in my testing. Both aggregations had the same timestamp. My guess is that the reason is that setTimeout() in Node.js is not precise enough when invoked with 1ms delay. From the documentaiton:

The callback will likely not be invoked in precisely delay milliseconds. Node.js makes no guarantees about the exact timing of when callbacks will fire, nor of their ordering. The callback will be called as close as possible to the time specified.

If I loosen the sleep to 100ms (or even 2ms without using fake timers) the failures don't occur anymore. I have changed the sleep to be 100ms even with the fake timer in f62ab0d 🙂

[legendecas]

Thanks! LGTM