Networkstream irregular speed

Question

I'm coding a client-server communication.The client is asking something to the server and then the server is responding every few ms (50 in my problem case).

I'm using a TcpClient to connect the client and the server, and using BinaryWriter/Reader to write and read on the TcpClient stream (networkstream).

I send ~100 ko of data every 50 ms (I try to, in fact), which is ~2000 mo / s. Client and server are connected with a rj45 wire and client firewall is disabled.

My problem is that the BinaryWriter.Write(myString) takes a minimum of 5 ms and a maximum of 2500 ms. So I tried to increase TcpClient Send/ReceiveBufferSize to 20MB (default is 8MB) and NoDelay = true, it's a bit better than before (was taking up to 5 seconds before that) but not that good yet.

The fact the writing is so irregular made me think the buffer is full and the BinaryWriter is waiting for it to empty a bit so on the client side I execute ReadString on the stream then process data in a thread but the problem is still there.

Code:

Server side:

private void traitementEnvois() 
{
    while (true) 
    {
        //some processing and wait for data to send

        NetworkStream stream = Client.GetStream();
        using (BinaryWriter writer = new BinaryWriter(stream, Encoding.UTF8, true)) 
        {
            while (!_envoisATraiter.IsEmpty) //ConcurrentQueue for data to send                     
            { 
                String jsonAEnvoyer;
                _envoisATraiter.TryDequeue(out jsonAEnvoyer);
                if (jsonAEnvoyer != null) 
                {
                    Stopwatch chrono = new Stopwatch();
                    chrono.Start();
                    writer.Write(jsonAEnvoyer);
                    long elaspedMs = chrono.ElapsedMilliseconds;
                    chrono.Stop();
                    EcritureEvenement.loggerEvenement("written in " + elaspedMs, TypesEvenements.DEBUG, "EnvoiParClient.traitementEnvois"); //log the event
                }
            }
        }
    }
}

Client side:

private void traitementStreamServeur(TcpClient server) 
{
    NetworkStream stream = server.GetStream();
    BinaryReader reader = new BinaryReader(stream);
    while (true) 
    {
        if (stream.DataAvailable) 
        {
            String messageJson = reader.ReadString(); //read data from the stream
            new Thread(() => traiterMessageRecu(messageJson)).Start(); //process data
        } 
        else 
        {
            Thread.Sleep(10);
        }
    }
}

Typical log:

DEBUG 04-23-2014 14:18:50.332 written in 9 ms DEBUG 04-23-2014 14:18:50.485 written in 8 ms DEBUG 04-23-2014 14:18:50.658 written in 9 ms DEBUG 04-23-2014 14:18:50.816 written in 6 ms DEBUG 04-23-2014 14:18:51.009 written in 4 ms DEBUG 04-23-2014 14:18:51.153 written in 24 ms DEBUG 04-23-2014 14:18:51.305 written in 4 ms DEBUG 04-23-2014 14:18:51.456 written in 9 ms DEBUG 04-23-2014 14:18:51.638 written in 14 ms DEBUG 04-23-2014 14:18:51.797 written in 62 ms DEBUG 04-23-2014 14:18:51.955 written in 63 ms DEBUG 04-23-2014 14:18:52.066 written in 13 ms DEBUG 04-23-2014 14:18:52.309 written in 77 ms DEBUG 04-23-2014 14:18:52.508 written in 58 ms DEBUG 04-23-2014 14:18:52.643 written in 81 ms DEBUG 04-23-2014 14:18:52.750 written in 18 ms DEBUG 04-23-2014 14:18:53.007 written in 108 ms DEBUG 04-23-2014 14:18:53.201 written in 124 ms DEBUG 04-23-2014 14:18:53.300 written in 27 ms DEBUG 04-23-2014 14:18:53.477 written in 49 ms DEBUG 04-23-2014 14:18:53.615 written in 56 ms DEBUG 04-23-2014 14:18:53.871 written in 129 ms DEBUG 04-23-2014 14:18:53.922 written in 36 ms DEBUG 04-23-2014 14:18:54.196 written in 121 ms DEBUG 04-23-2014 14:18:54.361 written in 101 ms DEBUG 04-23-2014 14:18:54.580 written in 148 ms DEBUG 04-23-2014 14:18:54.773 written in 154 ms DEBUG 04-23-2014 14:18:54.784 written in 11 ms DEBUG 04-23-2014 14:18:55.077 written in 103 ms DEBUG 04-23-2014 14:18:55.327 written in 192 ms DEBUG 04-23-2014 14:18:55.475 written in 147 ms DEBUG 04-23-2014 14:18:55.501 written in 25 ms DEBUG 04-23-2014 14:18:55.703 written in 92 ms DEBUG 04-23-2014 14:18:56.326 written in 578 ms DEBUG 04-23-2014 14:18:56.953 written in 626 ms DEBUG 04-23-2014 14:18:57.400 written in 447 ms DEBUG 04-23-2014 14:18:58.049 written in 648 ms DEBUG 04-23-2014 14:18:58.238 written in 189 ms DEBUG 04-23-2014 14:18:58.952 written in 713 ms DEBUG 04-23-2014 14:18:59.646 written in 694 ms DEBUG 04-23-2014 14:18:59.995 written in 348 ms DEBUG 04-23-2014 14:19:00.518 written in 523 ms DEBUG 04-23-2014 14:19:01.350 written in 831 ms DEBUG 04-23-2014 14:19:01.620 written in 270 ms DEBUG 04-23-2014 14:19:02.220 written in 599 ms DEBUG 04-23-2014 14:19:02.516 written in 295 ms DEBUG 04-23-2014 14:19:02.689 written in 172 ms DEBUG 04-23-2014 14:19:02.880 written in 191 ms DEBUG 04-23-2014 14:19:04.308 written in 1427 ms DEBUG 04-23-2014 14:19:04.331 written in 23 ms DEBUG 04-23-2014 14:19:04.345 written in 13 ms DEBUG 04-23-2014 14:19:04.351 written in 6 ms DEBUG 04-23-2014 14:19:04.370 written in 18 ms DEBUG 04-23-2014 14:19:04.477 written in 107 ms DEBUG 04-23-2014 14:19:05.553 written in 1075 ms DEBUG 04-23-2014 14:19:06.903 written in 1350 ms DEBUG 04-23-2014 14:19:07.168 written in 264 ms DEBUG 04-23-2014 14:19:07.565 written in 396 ms DEBUG 04-23-2014 14:19:09.073 written in 1507 ms DEBUG 04-23-2014 14:19:09.934 written in 861 ms DEBUG 04-23-2014 14:19:10.676 written in 742 ms DEBUG 04-23-2014 14:19:11.794 written in 1118 ms DEBUG 04-23-2014 14:19:12.247 written in 452 ms DEBUG 04-23-2014 14:19:13.171 written in 924 ms DEBUG 04-23-2014 14:19:13.514 written in 342 ms DEBUG 04-23-2014 14:19:13.779 written in 265 ms DEBUG 04-23-2014 14:19:14.762 written in 983 ms DEBUG 04-23-2014 14:19:14.799 written in 36 ms DEBUG 04-23-2014 14:19:16.525 written in 1726 ms DEBUG 04-23-2014 14:19:17.029 written in 503 ms DEBUG 04-23-2014 14:19:17.545 written in 515 ms DEBUG 04-23-2014 14:19:17.624 written in 79 ms DEBUG 04-23-2014 14:19:17.959 written in 335 ms DEBUG 04-23-2014 14:19:18.864 written in 904 ms DEBUG 04-23-2014 14:19:20.285 written in 1420 ms DEBUG 04-23-2014 14:19:20.307 written in 21 ms DEBUG 04-23-2014 14:19:20.359 written in 52 ms DEBUG 04-23-2014 14:19:20.722 written in 363 ms DEBUG 04-23-2014 14:19:21.172 written in 449 ms DEBUG 04-23-2014 14:19:21.824 written in 652 ms DEBUG 04-23-2014 14:19:22.000 written in 176 ms DEBUG 04-23-2014 14:19:22.499 written in 498 ms DEBUG 04-23-2014 14:19:23.368 written in 869 ms DEBUG 04-23-2014 14:19:23.773 written in 404 ms DEBUG 04-23-2014 14:19:24.835 written in 1062 ms DEBUG 04-23-2014 14:19:24.927 written in 91 ms DEBUG 04-23-2014 14:19:24.995 written in 68 ms DEBUG 04-23-2014 14:19:25.514 written in 518 ms DEBUG 04-23-2014 14:19:27.232 written in 1718 ms

Maybe your stopwatch includes flushing time of streams and execution of kernel´s time... — user35443

Unknown Unknown · Accepted Answer · 2014-04-23T12:51:06

Ok I figured out the processing on client side was HUGE. Didn't really tested it before that so I didn't know it took so long.

The process in the thread is taking ~29 seconds, after I commented the data process, here is how the log looks:

DEBUG 04-23-2014 14:45:53.112 written in 4 ms DEBUG 04-23-2014 14:45:53.276 written in 6 ms DEBUG 04-23-2014 14:45:53.449 written in 8 ms DEBUG 04-23-2014 14:45:53.636 written in 17 ms DEBUG 04-23-2014 14:45:53.813 written in 4 ms DEBUG 04-23-2014 14:45:54.022 written in 5 ms DEBUG 04-23-2014 14:45:54.180 written in 7 ms DEBUG 04-23-2014 14:45:54.352 written in 6 ms DEBUG 04-23-2014 14:45:54.529 written in 19 ms DEBUG 04-23-2014 14:45:54.733 written in 6 ms DEBUG 04-23-2014 14:45:54.905 written in 7 ms DEBUG 04-23-2014 14:45:55.088 written in 14 ms DEBUG 04-23-2014 14:45:55.281 written in 3 ms DEBUG 04-23-2014 14:45:55.442 written in 4 ms DEBUG 04-23-2014 14:45:55.621 written in 4 ms DEBUG 04-23-2014 14:45:55.819 written in 7 ms DEBUG 04-23-2014 14:45:56.007 written in 7 ms DEBUG 04-23-2014 14:45:56.175 written in 5 ms DEBUG 04-23-2014 14:45:56.363 written in 18 ms DEBUG 04-23-2014 14:45:56.581 written in 7 ms DEBUG 04-23-2014 14:45:56.759 written in 7 ms DEBUG 04-23-2014 14:45:56.939 written in 16 ms DEBUG 04-23-2014 14:45:57.161 written in 5 ms DEBUG 04-23-2014 14:45:57.304 written in 5 ms DEBUG 04-23-2014 14:45:57.488 written in 7 ms DEBUG 04-23-2014 14:45:57.642 written in 8 ms DEBUG 04-23-2014 14:45:57.837 written in 4 ms DEBUG 04-23-2014 14:45:57.991 written in 7 ms DEBUG 04-23-2014 14:45:58.148 written in 4 ms DEBUG 04-23-2014 14:45:58.361 written in 6 ms DEBUG 04-23-2014 14:45:58.534 written in 5 ms DEBUG 04-23-2014 14:45:58.737 written in 21 ms DEBUG 04-23-2014 14:45:58.888 written in 5 ms DEBUG 04-23-2014 14:45:59.094 written in 5 ms DEBUG 04-23-2014 14:45:59.276 written in 4 ms DEBUG 04-23-2014 14:45:59.451 written in 5 ms DEBUG 04-23-2014 14:45:59.629 written in 4 ms DEBUG 04-23-2014 14:45:59.813 written in 6 ms DEBUG 04-23-2014 14:45:59.994 written in 11 ms DEBUG 04-23-2014 14:46:00.162 written in 5 ms DEBUG 04-23-2014 14:46:00.367 written in 4 ms DEBUG 04-23-2014 14:46:00.560 written in 12 ms DEBUG 04-23-2014 14:46:00.738 written in 5 ms DEBUG 04-23-2014 14:46:00.932 written in 7 ms DEBUG 04-23-2014 14:46:01.120 written in 6 ms DEBUG 04-23-2014 14:46:01.311 written in 8 ms DEBUG 04-23-2014 14:46:01.483 written in 4 ms DEBUG 04-23-2014 14:46:01.671 written in 4 ms DEBUG 04-23-2014 14:46:01.864 written in 7 ms DEBUG 04-23-2014 14:46:02.078 written in 4 ms DEBUG 04-23-2014 14:46:02.237 written in 6 ms DEBUG 04-23-2014 14:46:02.415 written in 18 ms DEBUG 04-23-2014 14:46:02.612 written in 7 ms DEBUG 04-23-2014 14:46:02.789 written in 4 ms DEBUG 04-23-2014 14:46:02.941 written in 4 ms DEBUG 04-23-2014 14:46:03.111 written in 4 ms DEBUG 04-23-2014 14:46:03.293 written in 5 ms DEBUG 04-23-2014 14:46:03.477 written in 5 ms DEBUG 04-23-2014 14:46:03.609 written in 5 ms DEBUG 04-23-2014 14:46:03.791 written in 5 ms DEBUG 04-23-2014 14:46:03.956 written in 4 ms DEBUG 04-23-2014 14:46:04.140 written in 18 ms DEBUG 04-23-2014 14:46:04.319 written in 7 ms DEBUG 04-23-2014 14:46:04.466 written in 5 ms DEBUG 04-23-2014 14:46:04.630 written in 5 ms DEBUG 04-23-2014 14:46:04.785 written in 17 ms DEBUG 04-23-2014 14:46:04.938 written in 5 ms DEBUG 04-23-2014 14:46:05.094 written in 7 ms DEBUG 04-23-2014 14:46:05.277 written in 7 ms DEBUG 04-23-2014 14:46:05.383 written in 9 ms DEBUG 04-23-2014 14:46:05.539 written in 4 ms DEBUG 04-23-2014 14:46:05.705 written in 4 ms DEBUG 04-23-2014 14:46:05.920 written in 8 ms DEBUG 04-23-2014 14:46:06.133 written in 4 ms DEBUG 04-23-2014 14:46:06.301 written in 5 ms DEBUG 04-23-2014 14:46:06.443 written in 8 ms DEBUG 04-23-2014 14:46:06.661 written in 6 ms DEBUG 04-23-2014 14:46:06.855 written in 5 ms DEBUG 04-23-2014 14:46:07.048 written in 6 ms DEBUG 04-23-2014 14:46:07.242 written in 21 ms DEBUG 04-23-2014 14:46:07.440 written in 8 ms DEBUG 04-23-2014 14:46:07.619 written in 5 ms DEBUG 04-23-2014 14:46:07.792 written in 17 ms DEBUG 04-23-2014 14:46:07.988 written in 3 ms DEBUG 04-23-2014 14:46:08.163 written in 4 ms DEBUG 04-23-2014 14:46:08.343 written in 4 ms DEBUG 04-23-2014 14:46:08.509 written in 7 ms DEBUG 04-23-2014 14:46:08.703 written in 5 ms DEBUG 04-23-2014 14:46:08.906 written in 6 ms DEBUG 04-23-2014 14:46:09.108 written in 5 ms DEBUG 04-23-2014 14:46:09.257 written in 5 ms DEBUG 04-23-2014 14:46:09.466 written in 6 ms DEBUG 04-23-2014 14:46:09.636 written in 6 ms DEBUG 04-23-2014 14:46:09.821 written in 5 ms DEBUG 04-23-2014 14:46:10.011 written in 8 ms DEBUG 04-23-2014 14:46:10.167 written in 12 ms DEBUG 04-23-2014 14:46:10.406 written in 24 ms DEBUG 04-23-2014 14:46:10.511 written in 4 ms DEBUG 04-23-2014 14:46:10.691 written in 4 ms DEBUG 04-23-2014 14:46:10.894 written in 5 ms DEBUG 04-23-2014 14:46:11.113 written in 9 ms DEBUG 04-23-2014 14:46:11.286 written in 5 ms DEBUG 04-23-2014 14:46:11.469 written in 15 ms DEBUG 04-23-2014 14:46:11.669 written in 4 ms DEBUG 04-23-2014 14:46:11.826 written in 7 ms DEBUG 04-23-2014 14:46:12.008 written in 9 ms DEBUG 04-23-2014 14:46:12.142 written in 11 ms DEBUG 04-23-2014 14:46:12.322 written in 4 ms DEBUG 04-23-2014 14:46:12.508 written in 7 ms DEBUG 04-23-2014 14:46:12.673 written in 13 ms DEBUG 04-23-2014 14:46:12.836 written in 5 ms DEBUG 04-23-2014 14:46:13.018 written in 6 ms DEBUG 04-23-2014 14:46:13.191 written in 4 ms DEBUG 04-23-2014 14:46:13.359 written in 5 ms DEBUG 04-23-2014 14:46:13.529 written in 4 ms DEBUG 04-23-2014 14:46:13.679 written in 5 ms DEBUG 04-23-2014 14:46:13.849 written in 10 ms DEBUG 04-23-2014 14:46:14.036 written in 7 ms DEBUG 04-23-2014 14:46:14.218 written in 6 ms DEBUG 04-23-2014 14:46:14.406 written in 14 ms DEBUG 04-23-2014 14:46:14.613 written in 5 ms DEBUG 04-23-2014 14:46:14.785 written in 4 ms DEBUG 04-23-2014 14:46:14.972 written in 6 ms DEBUG 04-23-2014 14:46:15.136 written in 5 ms DEBUG 04-23-2014 14:46:15.333 written in 5 ms DEBUG 04-23-2014 14:46:15.481 written in 4 ms DEBUG 04-23-2014 14:46:15.619 written in 3 ms DEBUG 04-23-2014 14:46:15.833 written in 5 ms DEBUG 04-23-2014 14:46:16.034 written in 6 ms DEBUG 04-23-2014 14:46:16.199 written in 5 ms DEBUG 04-23-2014 14:46:16.425 written in 5 ms DEBUG 04-23-2014 14:46:16.583 written in 4 ms DEBUG 04-23-2014 14:46:16.755 written in 7 ms DEBUG 04-23-2014 14:46:16.939 written in 6 ms DEBUG 04-23-2014 14:46:17.126 written in 5 ms DEBUG 04-23-2014 14:46:17.278 written in 5 ms DEBUG 04-23-2014 14:46:17.426 written in 6 ms DEBUG 04-23-2014 14:46:17.632 written in 4 ms DEBUG 04-23-2014 14:46:17.776 written in 5 ms DEBUG 04-23-2014 14:46:17.960 written in 13 ms DEBUG 04-23-2014 14:46:18.129 written in 4 ms DEBUG 04-23-2014 14:46:18.306 written in 4 ms DEBUG 04-23-2014 14:46:18.500 written in 3 ms DEBUG 04-23-2014 14:46:18.670 written in 26 ms DEBUG 04-23-2014 14:46:18.832 written in 4 ms DEBUG 04-23-2014 14:46:19.017 written in 5 ms DEBUG 04-23-2014 14:46:19.203 written in 18 ms DEBUG 04-23-2014 14:46:19.399 written in 24 ms DEBUG 04-23-2014 14:46:19.531 written in 4 ms DEBUG 04-23-2014 14:46:19.701 written in 5 ms DEBUG 04-23-2014 14:46:19.881 written in 21 ms DEBUG 04-23-2014 14:46:20.063 written in 6 ms DEBUG 04-23-2014 14:46:20.217 written in 5 ms DEBUG 04-23-2014 14:46:20.372 written in 5 ms DEBUG 04-23-2014 14:46:20.536 written in 4 ms DEBUG 04-23-2014 14:46:20.701 written in 3 ms DEBUG 04-23-2014 14:46:20.899 written in 4 ms DEBUG 04-23-2014 14:46:21.096 written in 4 ms DEBUG 04-23-2014 14:46:21.263 written in 5 ms DEBUG 04-23-2014 14:46:21.473 written in 8 ms DEBUG 04-23-2014 14:46:21.645 written in 17 ms DEBUG 04-23-2014 14:46:21.861 written in 15 ms DEBUG 04-23-2014 14:46:22.024 written in 5 ms DEBUG 04-23-2014 14:46:22.226 written in 11 ms DEBUG 04-23-2014 14:46:22.395 written in 7 ms DEBUG 04-23-2014 14:46:22.560 written in 5 ms DEBUG 04-23-2014 14:46:22.758 written in 8 ms DEBUG 04-23-2014 14:46:22.889 written in 11 ms DEBUG 04-23-2014 14:46:23.042 written in 5 ms DEBUG 04-23-2014 14:46:23.263 written in 4 ms DEBUG 04-23-2014 14:46:23.468 written in 33 ms DEBUG 04-23-2014 14:46:24.622 written in 9 ms DEBUG 04-23-2014 14:46:24.812 written in 24 ms DEBUG 04-23-2014 14:46:24.947 written in 4 ms DEBUG 04-23-2014 14:46:25.149 written in 4 ms DEBUG 04-23-2014 14:46:25.315 written in 7 ms DEBUG 04-23-2014 14:46:25.490 written in 5 ms DEBUG 04-23-2014 14:46:25.670 written in 12 ms DEBUG 04-23-2014 14:46:25.838 written in 3 ms DEBUG 04-23-2014 14:46:25.995 written in 6 ms DEBUG 04-23-2014 14:46:26.199 written in 4 ms DEBUG 04-23-2014 14:46:26.402 written in 5 ms DEBUG 04-23-2014 14:46:26.576 written in 7 ms DEBUG 04-23-2014 14:46:26.753 written in 6 ms DEBUG 04-23-2014 14:46:26.936 written in 7 ms DEBUG 04-23-2014 14:46:27.144 written in 6 ms DEBUG 04-23-2014 14:46:27.320 written in 6 ms DEBUG 04-23-2014 14:46:27.486 written in 11 ms DEBUG 04-23-2014 14:46:27.703 written in 7 ms

Looks pretty great. The client had trouble handling so many threads and so much memory/cpu use.

Thank you all for reading my problem.

Networkstream irregular speed

1 Answers