.NET NetworkStream Read slowness

Question

I've got some network code to process an arbitary TCP connection.

It all seems to work as expected but seems slow. When i've profiled the code the it seems to spend a good 600 ms in NetworkStream.Read() and I'm wondering how to improve it. I've fiddled with the buffer sizes and alternated between a massive buffer to read all of the data in one go or a small one which should concatenate the data into a StringBuilder. Currently the client i'm using is a web-browser but this code is generic and it may well not be HTTP data that is being sent to it. Any ideas?

My code is this:

    public void StartListening()
    {
        try
        {
            lock (oSyncRoot)
            {
                oTCPListener = new TcpListener(oIPaddress, nPort);

                // fire up the server
                oTCPListener.Start();

                // set listening bit
                bIsListening = true;
            }

            // Enter the listening loop.
            do
            {
                // Wait for connection
                TcpClient newClient = oTCPListener.AcceptTcpClient();

                // queue a request to take care of the client
                oThreadPool.QueueUserWorkItem(new WaitCallback(ProcessConnection), newClient);
            }
            while (bIsListening);
        }
        catch (SocketException se)
        {
            Logger.Write(new TCPLogEntry("SocketException: " + se.ToString()));
        }
        finally
        {
            // shut it down
            StopListening();
        }
    }

    private void ProcessConnection(object oClient)
    {

        TcpClient oTCPClient = (TcpClient)oClient;
        try
        {
            byte[] abBuffer = new byte[1024];
            StringBuilder sbReceivedData = new StringBuilder();

            using (NetworkStream oNetworkStream = oTCPClient.GetStream())
            {
                // set initial read timeout to nInitialTimeoutMS to allow for connection
                oNetworkStream.ReadTimeout = nInitialTimeoutMS;

                int nBytesRead = 0;

                do
                {
                    try
                    {
                        bool bDataAvailable = oNetworkStream.DataAvailable;

                        while (!bDataAvailable)
                        {
                           Thread.Sleep(5);
                           bDataAvailable = oNetworkStream.DataAvailable;
                        }

                        nBytesRead = oNetworkStream.Read(abBuffer, 0, abBuffer.Length);

                        if (nBytesRead > 0)
                        {
                            // Translate data bytes to an ASCII string and append
                            sbReceivedData.Append(Encoding.UTF8.GetString(abBuffer, 0, nBytesRead));
                            // decrease read timeout to nReadTimeoutMS second now that data is coming in
                            oNetworkStream.ReadTimeout = nReadTimeoutMS;

                        }
                    }
                    catch (IOException)
                    {
                        // read timed out, all data has been retrieved
                        nBytesRead = 0;
                    }
                }
                while (nBytesRead > 0);

                //send the data to the callback and get the response back
                byte[] abResponse = oClientHandlerDelegate(sbReceivedData.ToString(), oTCPClient);
                if (abResponse != null)
                {
                    oNetworkStream.Write(abResponse, 0, abResponse.Length);
                    oNetworkStream.Flush();
                }
            }
        }
        catch (Exception e)
        {
            Logger.Write(new TCPLogEntry("Caught Exception " + e.StackTrace));
        }
        finally
        {
            // stop talking to client
            if (oTCPClient != null)
            {
                oTCPClient.Close();
            }
        }
    }

Edit: I get roughly the same figures on two entirely seperate machines (my XP development machine and a 2003 box in a colo). I've put some timing into the code around the relevant parts (using System.Diagnostic.StopWatch) and dump it to a log:

7/6/2009 3:44:50 PM : Debug : While DataAvailable took 0 ms
7/6/2009 3:44:50 PM : Debug : Read took 531 ms
7/6/2009 3:44:50 PM : Debug : ProcessConnection took 577 ms

Answer 1

I recommend you use Microsoft Network Monitor or something like it to see what's going on in terms of those 600ms. NetworkStream is a piece of networking software - when looking at its behavior, always consider what the network is doing.

Answer 2

Another vote for the use of network monitoring software. Either Network Monitor or WireShark should do. Make sure you record what time the networkstream.read call begins and ends in your program so you can know where in the recorded network traffic your program events happened.

Also, I'd recommend waiting for the NetworkStream.DataAvailable property to become true before you call the Read method, and record the time it becomes true as well. If your network monitor shows data arriving 600 ms before your program indicates it can be read, something else on your computer may be holding up the packet - e.g. antivirus or your firewall.

Addendum 2009/7/6 3:12 PM EDT:

The extra timing information you posted is interesting. If data is available, why is it taking so long to read? I ran your code on my development machine, and both waiting for dataavailable and the read function itself comes out as 0 milliseconds. Are you sure you have the latest service packs, etc. installed? I'm running Visual Studio Professional 2005 with .NET 2.0.50727. I also have .NET 3.0 and 3.5 installed, but I don't think VS 2005 is using those. Do you have a fresh OS installation (real or virtual machine) with no extra programs (even/especially ones "required" by corporate IT) that you could try this on?

Here's the code I ran:

using System;
using System.Collections.Generic;
using System.Text;
using System.Net;
using System.Net.Sockets;
using System.IO;
using System.Threading;
using System.Diagnostics;

namespace stackoverflowtest
{
    class Program
    {

        static private object oSyncRoot = new object();

        static private TcpListener oTCPListener;

        static private IPAddress oIPaddress = IPAddress.Parse("10.1.1.109");

        static private int nPort = 8009;

        static bool bIsListening = true;





        static void Main(string[] args)
        {
            StartListening();
            Thread.Sleep(500000);
            bIsListening = false;
        }

        public static void StartListening()
        {
            try
            {
                lock (oSyncRoot)
                {
                    oTCPListener = new TcpListener(oIPaddress, nPort);

                    // fire up the server
                    oTCPListener.Start();

                    // set listening bit
                    bIsListening = true;
                }

                // Enter the listening loop.
                do
                {
                    // Wait for connection
                    TcpClient newClient = oTCPListener.AcceptTcpClient();



                    // queue a request to take care of the client
                    ThreadPool.QueueUserWorkItem(new WaitCallback(ProcessConnection), newClient);
                }
                while (bIsListening);
            }
            catch (SocketException se)
            {
                Console.WriteLine("SocketException: " + se.ToString());
            }
            finally
            {
                // shut it down
                //StopListening();
            }
        }

        private static void ProcessConnection(object oClient)
        {

            TcpClient oTCPClient = (TcpClient)oClient;
            try
            {
                byte[] abBuffer = new byte[1024];
                StringBuilder sbReceivedData = new StringBuilder();

                using (NetworkStream oNetworkStream = oTCPClient.GetStream())
                {
                    int nInitialTimeoutMS = 1000;
                    // set initial read timeout to nInitialTimeoutMS to allow for connection
                    oNetworkStream.ReadTimeout = nInitialTimeoutMS;

                    int nBytesRead = 0;

                    do
                    {
                        try
                        {
                            bool bDataAvailable = oNetworkStream.DataAvailable;
                            Stopwatch sw = new Stopwatch();
                            while (!bDataAvailable)
                            {
                                Thread.Sleep(5);
                                bDataAvailable = oNetworkStream.DataAvailable;
                            }
                            Console.WriteLine("DataAvailable loop took " + sw.ElapsedMilliseconds);

                            sw.Reset();
                            nBytesRead = oNetworkStream.Read(abBuffer, 0, abBuffer.Length);
                            Console.WriteLine("Reading " + nBytesRead + " took " + sw.ElapsedMilliseconds);
                            if (nBytesRead > 0)
                            {
                                // Translate data bytes to an ASCII string and append
                                sbReceivedData.Append(Encoding.UTF8.GetString(abBuffer, 0, nBytesRead));
                                // decrease read timeout to nReadTimeoutMS second now that data is coming in
                                int nReadTimeoutMS = 100;
                                oNetworkStream.ReadTimeout = nReadTimeoutMS;

                            }
                        }
                        catch (IOException)
                        {
                            // read timed out, all data has been retrieved
                            nBytesRead = 0;
                        }
                    }
                    while (nBytesRead > 0);

                    byte[] abResponse = new byte[1024];
                    for (int i = 0; i < abResponse.Length; i++)
                    {
                        abResponse[i] = (byte)i;
                    }
                    oNetworkStream.Write(abResponse, 0, abResponse.Length);
                    oNetworkStream.Flush();

                    //send the data to the callback and get the response back
                    //byte[] abResponse = oClientHandlerDelegate(sbReceivedData.ToString(), oTCPClient);
                    //if (abResponse != null)
                    //{
                    //    oNetworkStream.Write(abResponse, 0, abResponse.Length);
                    //    oNetworkStream.Flush();
                    //}
                }
            }
            catch (Exception e)
            {
                Console.WriteLine("Caught Exception " + e.StackTrace);
            }
            finally
            {
                // stop talking to client
                if (oTCPClient != null)
                {
                    oTCPClient.Close();
                }
            }
        }

    }
}

Answer 3

After some more research it seems that the only way to speed this up is to break after the first x bytes have been read. The delay seems to be on the second read. If I change the buffer to be 8096 bytes (probably the max my application will be sent at any one go) and break here:

        if (nBytesRead > 0)
        {
             // Translate data bytes to an ASCII string and append
             sbReceivedData.Append(Encoding.UTF8.GetString(abBuffer, 0, nBytesRead));

            if (bTurboMode)
            {
                  break;
            }
            else
            {
                  // decrease read timeout to nReadTimeoutMS second now that data is coming in
                  oNetworkStream.ReadTimeout = nReadTimeoutMS;
            }
        }

Then the response time goes from 600ms to about 80ms. This is an acceptable solution for me currently. I can toggle the bTurboMode from the calling application and speed things up substantially for this case