Periodically getting this exception #53

Closed
andreybalogh opened this Issue Oct 28, 2015 · 7 comments

Projects

None yet

4 participants

@andreybalogh

Hi - Not really sure what this means - any help would be appreciated.
Thanks
Andy

Exception:

System.InvalidOperationException: Already receiving or accepting
at Nowin.SaeaLayerCallback.StartReceive(Byte[] buffer, Int32 offset, Int32 length)
at Nowin.Transport2HttpHandler.StartNextReceive()
at System.Net.Sockets.SocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs e)
at System.Net.Sockets.SocketAsyncEventArgs.FinishOperationSuccess(SocketError socketError, Int32 bytesTransferred, SocketFlags flags)
at System.Net.Sockets.SocketAsyncEventArgs.CompletionPortCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)

@Bobris
Owner
Bobris commented Oct 28, 2015

It should never happen ... Can you create simple repro? Or you can enable detailed logging ...
What version of Nowin, what framework, OS version?

@zegreatclan

Hi ! I reproduce it using nowin + nancyFx, I think it happens when chrome aborts requests. (I only reproduce it when loading it pressing f5 like a mad)

@andreybalogh

Hi - nowin 0.19.0, .net 4.5, windows 7 Pro SP1

The following is a test that reproduces quickly (within the first or second run).

using System;
using System.Text;
using System.Net.Sockets;
using System.Net;

namespace NowinCancelTest
{
class Program
{
static void Main(string[] args)
{
byte[] bytes = Encoding.ASCII.GetBytes(string.Format("OPTIONS /api/v1/sessions/1/ixnetwork/topology/deviceGroup/ethernet/dhcp4client HTTP/1.1{0}Connection: keepalive{1}Cache-Control: no-cache{2}{3}",
Environment.NewLine,
Environment.NewLine,
Environment.NewLine,
Environment.NewLine));

        for (int i = 0; i < 10; i++)
            Request(bytes, false);

        for (int i = 0; i < 2; i++)
            Request(bytes, true);

        for (int i = 0; i < 20; i++)
            Request(bytes, false);

        for (int i = 0; i < 2; i++)
            Request(bytes, true);
    }

    static void Request(byte[] bytes, bool receive)
    { 
        try
        {
            Socket socket = new Socket(SocketType.Stream, ProtocolType.Tcp);
            socket.Connect(IPAddress.Loopback, 12345);

            if (receive)
            {
                socket.Send(bytes);
                byte[] recvBytes = new byte[32767];
                int count = socket.Receive(recvBytes);
                System.Diagnostics.Debug.WriteLine(Encoding.ASCII.GetString(recvBytes, 0, count));
            }
            else
            {
                socket.BeginSend(bytes, 0, bytes.Length, SocketFlags.None, null, null);
            }

            socket.Shutdown(SocketShutdown.Both);
            socket.Close();
            socket = null;
        }
        catch(Exception e)
        {
            System.Diagnostics.Debug.WriteLine(e.ToString());
        }
    }
}

}

@Bobris
Owner
Bobris commented Nov 2, 2015

Thanks for repro, will try to investigate tomorrow...

@adamburgess

Also happening for me (I'm using Heroku, running on the latest mono release)

2015-11-03T02:13:11.148046+00:00 heroku[router]: at=info method=POST path="/" host=blender-cycles-sharing.herokuapp.com request_id=eda1a912-9e12-4e78-9855-e4764fb2929d fwd="54.235.201.241" dyno=web.1 connect=1ms service=112ms status=200 bytes=164
2015-11-03T02:13:11.159933+00:00 app[web.1]:
2015-11-03T02:13:11.159937+00:00 app[web.1]: Unhandled Exception:
2015-11-03T02:13:11.159939+00:00 app[web.1]: System.InvalidOperationException: Already receiving or accepting
2015-11-03T02:13:11.159940+00:00 app[web.1]:   at Nowin.SaeaLayerCallback.StartAccept (System.Byte[] buffer, Int32 offset, Int32 length) <0x4175b8c0 + 0x00189> in <filename unknown>:0
2015-11-03T02:13:11.159941+00:00 app[web.1]:   at Nowin.Transport2HttpHandler.RealPrepareAccept () <0x4175b870 + 0x0003d> in <filename unknown>:0
2015-11-03T02:13:11.159941+00:00 app[web.1]:   at Nowin.Transport2HttpHandler.PrepareAccept () <0x4175b6b0 + 0x00064> in <filename unknown>:0
2015-11-03T02:13:11.159942+00:00 app[web.1]:   at Nowin.SaeaLayerCallback.ProcessDisconnect () <0x41762480 + 0x00138> in <filename unknown>:0
2015-11-03T02:13:11.159943+00:00 app[web.1]:   at Nowin.SaeaLayerCallback.IoCompleted (System.Object sender, System.Net.Sockets.SocketAsyncEventArgs e) <0x4175e940 + 0x000ec> in <filename unknown>:0
2015-11-03T02:13:11.159948+00:00 app[web.1]:   at System.Net.Sockets.SocketAsyncEventArgs.OnCompleted (System.Net.Sockets.SocketAsyncEventArgs e) <0x4175e900 + 0x0002e> in <filename unknown>:0
2015-11-03T02:13:11.159949+00:00 app[web.1]:   at System.Net.Sockets.SocketAsyncEventArgs.Complete () <0x4175e8e0 + 0x00013> in <filename unknown>:0
2015-11-03T02:13:11.159949+00:00 app[web.1]:   at System.Net.Sockets.Socket.<DisconnectAsyncCallback>m__5 (IAsyncResult ares) <0x41762150 + 0x001ee> in <filename unknown>:0
2015-11-03T02:13:11.159961+00:00 app[web.1]:   at System.Net.Sockets.SocketAsyncResult+<Complete>c__AnonStorey0.<>m__0 (System.Object _) <0x416d8620 + 0x0001d> in <filename unknown>:0
2015-11-03T02:13:11.159961+00:00 app[web.1]:   at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem () <0x7f88da099eb0 + 0x0002f> in <filename unknown>:0
2015-11-03T02:13:11.159962+00:00 app[web.1]:   at System.Threading.ThreadPoolWorkQueue.Dispatch () <0x7f88da098460 + 0x001d6> in <filename unknown>:0
2015-11-03T02:13:11.159963+00:00 app[web.1]:   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () <0x7f88da099d30 + 0x00008> in <filename unknown>:0
2015-11-03T02:13:11.943222+00:00 heroku[web.1]: Process exited with status 255
2015-11-03T02:13:11.955972+00:00 heroku[web.1]: State changed from up to crashed
@Bobris
Owner
Bobris commented Nov 4, 2015

I can reproduce it and working on fix ... It is very complex to synchronize all these async operations happening in parallel in multiple threads... Actually I have code which does not show problem, but it regressed one test (only in release, not in debug :-( )

@Bobris Bobris closed this in 9932e44 Nov 4, 2015
@Bobris
Owner
Bobris commented Nov 4, 2015

Published in nuget as 0.20.0. I cannot reproduce problem anymore even after 10 minutes of run of provided test. Also all tests passing repeatedly without problems.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment