Windows VS2010. Intermittent test failure in timeo

[nickva]

Test fails intermittently. Maybe 1 in 10 times.

Context of code that fails (timeo.c):

rc = nn_recv (s, buf, sizeof (buf), 0);
elapsed = nn_stopwatch_term (&stopwatch);
errno_assert (rc < 0 && nn_errno () == EAGAIN);
time_assert (elapsed, 100000); // <- FAILS HERE

Opening in debugger and inspecting local variable shows these values:

elapsed = 90536
rc = -1

Another time elapsed was 94034

Additional info:

Commit:
git hash 6a333ae (Dec 17, 2014)

Windows 7, VS2010 SP1, x64

[gdamore]

I'm pretty sure I've seen one failure in AppVeyor that looked like this.

[gdamore]

Confirming that this is still a problem.

[gdamore]

Problem may be insufficient tolerance:

/* Check whether measured time is the expected time (in microseconds).
The upper tolerance is 50ms so that the test doesn't fail even on
very slow or very loaded systems. */
#define time_assert(actual,expected)
nn_assert (actual > ((expected) - 5000) && actual < ((expected) + 50000));

[gdamore]

Looking at this, we are firing up to, but not more than, 10 msec early. This looks like a possible bug in the Windows timing subsystem. We are using select() here, so can WSA select fire early?

[JackDunaway]

Problem may be insufficient tolerance

Sometimes, but not all the time.

Looking at this, we are firing up to, but not more than, 10 msec early. This looks like a possible bug in the Windows timing subsystem. We are using select() here, so can WSA select fire early?

This is indeed one distinct failure mode ...

but https://ci.appveyor.com/project/gdamore/nanomsg/build/1.0.113/job/7stq1bsk17bwb9h1 shows another distinct failure mode. In this test result, it appears the test got hung, then aborted by the test framework at the 30sec testing limit.

It's possible that this second failure (the 30sec timeout) is due to some upstream failure, say tcp_shutdown test.

[gdamore]

Yeah, I'd be inclined to believe that tcp_shutdown test is causing cascade failures.

[gdamore]

What I don't understand is how we can return early. This really really feels like it can only be due to a bug in the select() implementation on Windows; unless there is some way for a socket event to occur without actually having I/O on that socket?

[gdamore]

The other thing is that the tcp_shutdown.c (and all of the tests and all instances of nanomsg on windows) use the global mutex to create a private TCP/IP socket for signaling operations. This is the hackery that is created to make a select()-capable socket. I truly despise this. What's worse, because only winsock sockets are able to support select() on Windows, I can see no better alternative -- e.g. it isn't possible (that I can see) to create some non-IP based socket to (such as a private NamedPipe or somesuch) to do this.

The Winsock select() compatible semantic is IMO libnanomsg's single biggest weakness. It makes it easy for some developers to build on top of, but it comes at this hideous complexity, fragility, and frankly at a non-trivial latency cost as well.

[JackDunaway]

select() compatible semantic is IMO libnanomsg's single biggest weakness

Shall we open a new issue on this? That would be a better place to discuss. Briefly, I don't use select() on multiple nanomsg sockets, because the value proposition of a "nanomsg socket" already seamlessly and beautifully multiplexes N underlying sockets (endpoints). Using select() on top of M nanomsg sockets thus provides MxN sockets, which actually adds more rigidity at the application layer (e.g., I choose not to use it because I see more negative value than potential positive value).

If you think this feature is truly what's blocking other more real issues (e.g., tcp_shutdown), then I would be in strong favor of re-evaluating select() prior to v1.0.0. It would be helpful to have @sustrik chime in on how strongly original design goals still stand, and cross those with lessons learned since v0.1

[gdamore]

At this point, I don't want to break the semantic, because it would likely break too many library consumers who've come to depend on that functionality. It works now; albeit not at best performance.

[gdamore]

I'm pretty sure that the granularity of select() on Windows is system ticks, which are probably 10 msec by default. The problem is that the time out should really be ticks + 1, rather than ticks, because the timeout should normally timeout after at least x ticks, but the way the Windows documentation calls it out it says "maximum time".

I think the solution here is going to be to just widen the test tolerance to 10 msec. We should probably give advice that on some platforms cough Windows cough timeouts can fire up to a system tick early (10 msec), therefore programs should be a little pessimistic when setting timeouts.