2

I'm hoping someone can explain this behaviour, or if it's maybe a bug in .NET.

Moving backwards in time due to daylight savings means that NetworkStream pays no attention to its property ReadTimeout, and in the case of this code causes the loops to spin. (This is just an example to prove it's happening).

To reproduce the problem I am seeing, you will need to be set to a timezone that uses daylight savings, e.g. The United Kingdom.

  1. Set your TimeZone to UTC London and make sure the daylight savings time is ticked.
  2. Change your date back to 29th October 2017
  3. Set your time to 01:58:50 am
  4. Run code below and watch it spin when it applies the daylight saving time at what would be 2am, if it applies it correctly time should move back to 1am.
  5. Make sure you wait, it can take up to 30 seconds for it to start spinning.

Edit: After deeping investigation, after 1 hour, it stops spinning and the behaviour returns to normal and honours the ReadTimeout.

Any thoughts would be appreciated!

Client code:

class Program
{
    static bool running = false;

    static void Main(string[] args)
    {
        running = true;
        Task.Factory.StartNew(() => Run());

        Console.ReadKey();

        running = false;
    }


    static void Run()
    {
        TcpClient connection = new TcpClient("127.0.0.1", 1234);

        while (running)
        {
            if (connection != null && connection.Connected)
            {
                try
                {
                    NetworkStream stream = connection.GetStream();
                    stream.ReadTimeout = 1000;

                    byte[] buffer = new byte[1024];
                    int readCount = stream.Read(buffer, 0, 1024); // Should block here for the ReadTimeout duration if nothing received
                                                                  // However when daylight savings is applied and time moves backwards an hour, the stream.ReadTimeout = 1000; 
                                                                  // is not honoured and it falls through and spins

                    if (readCount > 0)
                    {
                        Console.WriteLine("Received some data");
                        //process read here
                    }
                    else
                    {
                        Console.WriteLine("ReadTimeout was not honoured");
                    }
                }
                catch (IOException)
                {
                    Console.WriteLine("Read timed out");
                }
            }
        }
    }
}

Server Code:

class Program
    {
        static bool running = false;

        public static void Main()
        {
            TcpListener server = null;
            try
            {
                // Set the TcpListener on port 13000.
                Int32 port = 5000;
                IPAddress localAddr = IPAddress.Parse("192.168.1.69");

                // TcpListener server = new TcpListener(port);
                server = new TcpListener(localAddr, port);

                // Start listening for client requests.
                server.Start();

                // Enter the listening loop.
                while (true)
                {
                    Console.Write("Waiting for a connection... ");

                    // Perform a blocking call to accept requests.
                    // You could also user server.AcceptSocket() here.
                    TcpClient client = server.AcceptTcpClient();
                    Console.WriteLine("Connected!");


                    // Get a stream object for reading and writing
                    NetworkStream stream = client.GetStream();

                    running = true;

                    Task.Factory.StartNew(() => Run(stream));


                    Console.ReadKey();

                    // Shutdown and end connection
                    client.Close();
                }
            }
            catch (SocketException e)
            {
                Console.WriteLine("SocketException: {0}", e);
            }
            finally
            {
                // Stop listening for new clients.
                server.Stop();
            }


            Console.WriteLine("\nHit enter to continue...");
            Console.Read();
        }

        static async Task Run(NetworkStream stream)
        {
            byte[] stuffToSend = Encoding.ASCII.GetBytes("Stuff to send");
            while (running)
            {
                stream.Write(stuffToSend, 0, stuffToSend.Length);
                await Task.Delay(1000);
            }
        }
    }
MikeDev
  • 23
  • 6
  • Just to be sure, you're saying the failure is repeated return of a negative value with no exception? – Ben Voigt Feb 09 '18 at 16:53
  • The failure is a return of value == 0, because it has not waited at all and not read any data at all. – MikeDev Feb 09 '18 at 16:56
  • 4
    A return value of `0` typically means the connection has been closed, cleanly. Verify that that's not actually the case (possibly as a result of something reacting to the time changing). It is theoretically possible for this to be a .NET bug, but *extremely* unlikely, because all that setting `ReadTimeout` does is invoke the native `setsockopt` with the `SO_RCVTIMEO` option. It's entirely unclear why the kernel should even care about relative system time in relation to network timeouts. – Jeroen Mostert Feb 09 '18 at 17:00
  • I can absolutely guarantee the connection has not dropped, I edited the post so it's here as well. You can still send data to the tcpclient and it still reads it when it is in this state. After 1 hour, so 2am, it returns to normal. It's honestly starting to feel like a bug in .NET – MikeDev Feb 09 '18 at 17:10
  • @MikeDev: Still, you have a connection to localhost, so both ends of the connection are experiencing a time change. Can you instead open a connection to something else under your control, perhaps a Raspberry Pi or similar, so that only your .NET code experiences a time change and the other side does not? – Ben Voigt Feb 09 '18 at 17:12
  • 1
    If you haven't already done so, repro this on another machine as well, preferably a clean VM with only Windows installed to minimize any possible shenanigans with the network stack. Furthermore, see if you can post the code of whatever you have listening on port `1234` so we have a complete repro. If you can't, try making it something inoffensive and trivial, like `netcat` (or your own simple `TcpListener` loop). If you *can* repro this with only `localhost` and trivial network code, this should be a bug in Windows itself, not merely .NET. That's why it's so unlikely (but not impossible). – Jeroen Mostert Feb 09 '18 at 17:16
  • Note that the bug in .NET would be using `DateTime.Now` (which the Socket stack never seems to hit - it's relying on the OS for timeouts, as it should). The "current time" for your machine _never actually changes_ - Windows should be using what amounts to UTC for everything internally, same for framework timing code - only what it reports to the user actually changes. – Clockwork-Muse Feb 09 '18 at 17:19
  • @Jeroen Mostert This has already been reproduced on multiple machines. I'll have to write something quickly to simulate the other side as it's part of a much larger project, give me a few... – MikeDev Feb 09 '18 at 17:25
  • The code reads the start time once then for timeout does a delta time from current time - start time = 1000. So when you change the time backwards the delta from current time to start time becomes negative So probably the Net Library is making an error and ending up with a very large positive number instaed of a negative number. You may be getting an exception due to negative time. – jdweng Feb 09 '18 at 17:29
  • @jdweng: What code does that? – Ben Voigt Feb 09 '18 at 17:32
  • The timeout function inside the stream class. – jdweng Feb 09 '18 at 17:40
  • I've tried to reproduce this connecting to an external machine and it appears to be okay, it looks like the problem only occurs when using the localhost. I've edited my post to include a simple TcpListener so you have server and client. – MikeDev Feb 09 '18 at 17:58
  • @jdweng this is overriden in the NetworkStream class – MikeDev Feb 09 '18 at 20:09
  • @MikeDev: Any difference between 127.0.0.1 and the external address of the local machine? And your test server uses `await Task.Delay()` which is just as likely to have a clock-change bug as `ReadTimeout`. But that's easier to test too... – Ben Voigt Feb 09 '18 at 22:58
  • @jdweng - yeah no. Not at all. You seem to be assuming it's doing some sort of polling/busy waiting; that has terrible performance characteristics for something at that level. Instead, It does what any sane network/socket code does: [it sets the timeout on the OS-provided socket](http://referencesource.microsoft.com/#System/net/System/Net/Sockets/NetworkStream.cs,267) and lets the OS handle it (probably via driver interrupt). There's no clock checking I can see . – Clockwork-Muse Feb 11 '18 at 06:30
  • The op needs to add an exception handler (try/catch) to see exactly which error is occurring. – jdweng Feb 11 '18 at 09:01
  • The op doesn't need to that because there is no error occuring. – MikeDev Feb 15 '18 at 15:51

3 Answers3

0

There are some very important notes in the OS documentation that aren't mentioned in the .NET ReadTimeout property:

SO_RCVTIMEO and SO_SNDTIMEO

When using the recv function, if no data arrives during the period specified in SO_RCVTIMEO, the recv function completes. In Windows versions prior to Windows 2000, any data received subsequently fails with WSAETIMEDOUT. In Windows 2000 and later, if no data arrives within the period specified in SO_RCVTIMEO, the recv function returns WSAETIMEDOUT, and if data is received, recv returns SUCCESS.

If a send or receive operation times out on a socket, the socket state is indeterminate, and should not be used; TCP sockets in this state have a potential for data loss, since the operation could be canceled at the same moment the operation was to be completed.

Currently, after each timeout you are looping and trying another receive operation on the same socket. But this note makes it very clear that you need to create a new connection.

Ben Voigt
  • 277,958
  • 43
  • 419
  • 720
  • Hi @Ben Voigt, just to make it clear, you can still receive data on this socket, even when it is "spinning". After 1 hour, when the time is then "greater" than it was before the daylight savings was applied, it stops "spinning" and returns to waiting on "read" for the specified ReadTimeout. This isn't a question of whether each one should be a new connection, but a question whether anyone has seen the behaviour before, and if anyone knows why it happens. Thanks – MikeDev Feb 10 '18 at 07:54
  • @MikeDev: But what the documentation says is that after the first timeout, all operations (receiving and further timeouts) will be unreliable :( – Ben Voigt Feb 10 '18 at 14:33
  • they're all very reliable except for that one hour a year. :( – MikeDev Feb 10 '18 at 22:38
  • @MikeDev: Have you checked whether other methods of reading from a TCP stream with a time limit on blocking might work for you? In the underlying API, two valid approaches would be (1) set non-blocking mode and call `select()` or `poll()` with a timeout, then call `recv()` only when data is known to be available (based on the select result) or (2) set up an OVERLAPPED `WSARecv` call with an event, and pass a timeout when waiting on the event. Both of these let you have a timeout in the application without actually producing a socket error. In C#, using `BeginRead` would be equivalent. – Ben Voigt Feb 10 '18 at 23:04
  • You would then get the `WaitHandle` and wait on it with a timeout. The overall effect would be the same as OVERLAPPED in the underlying API -- when the timeout happens, the receive continues in the background, but your application isn't blocked beyond your time limit. When you want to wait for data again, you just wait on the pending operation for an additional time, and only call `BeginRead` to start a new operation pending once the previous one has completed. – Ben Voigt Feb 10 '18 at 23:07
  • this isn't a major problem and have worked around it already, was mainly wondering why for this 1 hour of a year it does not work. No one seems to know the answer. :( – MikeDev Feb 12 '18 at 13:00
-2

Please read this. https://msdn.microsoft.com/en-us/library/ms973825.aspx

In general, if you are dealing with absolute elapsed time, such as measuring a timeout, performing arithmetic, or doing comparisons of different DateTime values, you should try and use a Universal time value if possible so that you get the best possible accuracy without effects of time zone and/or daylight savings having an impact.

Just adjust the thread to use universal time.

Edit 1.

I failed to understand your question. You did not want a workaround. Its a known bug related to how .net manages the, and related discussion has been done before here.

Cache.Add absolute expiration - UTC based or not?

During one hour at the end of daylight savings time, your local time is ambiguous, so you can get unexpected results, i.e. the absolute expiration can be one hour longer than expected.

Edit 2. Added another discussion thread more in context with the OP question.

https://social.msdn.microsoft.com/Forums/vstudio/en-US/cb0369f4-8c96-484a-a33e-5e4c850b995e/wcf-channels-and-datetime-change?forum=wcf

  • 1
    The OP is clearly not using a relative stamp themself. Anything that is would be from the framework (and thus potentially a bug in .NET) – Clockwork-Muse Feb 09 '18 at 16:41
  • I failed to understand the OP question. Edited, cause its a known bug and has been posted here before. – Salvador Ruiz Guevara Feb 09 '18 at 16:52
  • Can you please show me where it has been posted before? I couldn't find any reference to it on here. – MikeDev Feb 09 '18 at 16:54
  • Done @MikeDev. Sorry for misunderstanding your question. Either way that is probably the reason they encourage you to use universal datetime. Since the machine does not know how to handle the change caused by the daylight time savings. – Salvador Ruiz Guevara Feb 09 '18 at 17:02
  • @SalvadorRuizGuevara: It's quite possible that there are system-clock-change bugs in portions of .NET, but nothing in your answer has any relevance to `NetworkStream`, which is what the question asks about. – Ben Voigt Feb 09 '18 at 17:10
  • ....and the cache stuff is converting to UTC internally, so that's a documentation bug more than anything else. – Clockwork-Muse Feb 09 '18 at 17:13
-2

Here is the sourced code :http://referencesource.microsoft.com/#mscorlib/system/io/stream.cs,f956b0c07e86df64

    [ComVisible(false)]
        public virtual int ReadTimeout {
            get {
                Contract.Ensures(Contract.Result<int>() >= 0);
                throw new InvalidOperationException(Environment.GetResourceString("InvalidOperation_TimeoutsNotSupported"));
            }
            set {
                throw new InvalidOperationException(Environment.GetResourceString("InvalidOperation_TimeoutsNotSupported"));
            }
        }

        [ComVisible(false)]
        public virtual int WriteTimeout {
            get {
                Contract.Ensures(Contract.Result<int>() >= 0);
                throw new InvalidOperationException(Environment.GetResourceString("InvalidOperation_TimeoutsNotSupported"));
            }
            set {
                throw new InvalidOperationException(Environment.GetResourceString("InvalidOperation_TimeoutsNotSupported"));
            }
        }
jdweng
  • 33,250
  • 2
  • 15
  • 20
  • No, it's here: http://referencesource.microsoft.com/#System/net/System/Net/Sockets/NetworkStream.cs,253 And here: http://referencesource.microsoft.com/#System/net/System/Net/Sockets/NetworkStream.cs,1272 Jeroen and I (and probably Clockwork) have already been looking at these, you've been wildly guessing. – Ben Voigt Feb 09 '18 at 17:48
  • ...that's not even a relevant piece of the source code you're quoting there. – Clockwork-Muse Feb 09 '18 at 17:48
  • @jdweng: Yes, but `NetworkStream.ReadTimeout` property getter and setter never call the base class version. – Ben Voigt Feb 09 '18 at 22:55
  • The exception is in the Close() method : if (timeout < -1) { throw new ArgumentOutOfRangeException("timeout"); The OP should be able to capture the exception and check the error message. You are correct the NetworkStream overrides the base class timeout. The stream timeout is virtual. – jdweng Feb 10 '18 at 06:35