[Bug]: The timeout configuration completes too early

[HofmeisterAn]

Question

Which library version?

System.Reactive 6.0.0

What are the platform(s), environment(s) and related component version(s)?

Windows 10, Ubuntu 22.04

What is the context of your question or problem?

Together with a colleague, we were looking at an implementation that relies on Rx.NET. We encountered an issue that we cannot comprehend or explain. Both of us have limited knowledge about Rx.NET, and we are unsure if our usage is incorrect or if it might be a bug in Rx.NET. We have created a reproducer that demonstrates the issue, hoping that someone could assist and guide us in the right direction.

Do you have a code snippet or project that reproduces the problem?

The following test is designed to run into a timeout. The test fails after several runs (run until failure). Surprisingly, the measured total elapsed milliseconds are smaller than the expected timeout. This is confusing, as we expect it to be larger than 15 milliseconds. This issue occurs even with larger values (the shorter timeout makes it just more likely to fail).

const double period = 10;

const double timeout = 15;

var stopWatch = Stopwatch.StartNew();

_ = await Observable
    .Interval(TimeSpan.FromMilliseconds(period))
    .Where(interval => interval < 0)
    .Timeout(TimeSpan.FromMilliseconds(timeout), Observable.Return(long.MinValue))
    .FirstAsync();

stopWatch.Stop();

Assert.True(stopWatch.Elapsed.TotalMilliseconds > timeout, string.Join("=", "Elapsed total milliseconds", stopWatch.Elapsed.TotalMilliseconds));

This test fails after a couple of runs, for example, with the following error:

Elapsed total milliseconds=12,5797

What is the question or problem you try to solve?

Why is the measured total elapsed milliseconds of the StopWatch smaller than the set timeout of 15 milliseconds? How can we ensure that Rx.NET considers the actual set timeout?

What were the (original) requirements you tried to solve?

-

What have you tried so far, what code have you written so far?

At first, we thought this might be an issue with the accuracy and ticks per second used by the StopWatch and TimeSpan. We double-checked both, and they use the same configuration (value) on our system.