.NET client: OnError can be raised when stopping SSE connection #1600

Closed
davidfowl opened this Issue Feb 27, 2013 · 7 comments

Projects

None yet

4 participants

@davidfowl
Member
System.ObjectDisposedException : Cannot access a disposed object. Object
name: 'System.Net.Sockets.NetworkStream'. at System.Net.ConnectStream.EndRead(IAsyncResult asyncResult) at
Microsoft.AspNet.SignalR.Infrastructure.StreamExtensions.<>c__DisplayClass4.<ReadAsync>b__1(IAsyncResult ar)
in
d:\BuildAgent\work\82493505bcab1c9e\src\Microsoft.AspNet.SignalR.Client\Infrastructure\StreamExtensions.cs:line
20 at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1
endAction, Task`1 promise, Boolean requiresSynchronization)   
@davidfowl davidfowl was assigned Mar 1, 2013
@davidfowl
Member

This is fixed.

@Xiaohongt
Member

verified

@Xiaohongt Xiaohongt closed this Mar 8, 2013
@davidfowl davidfowl reopened this Mar 15, 2013
@jcondex
jcondex commented Mar 15, 2013

This is still not fixed propperly. We ran into this in the HighClientThreadPoolUse stress scenario.

13f2ffe

@jcondex
jcondex commented Mar 19, 2013

Here's some more info on this:

        [StressVariation(TimeoutInSeconds = 300)]
        public void RunVariation()
        {
            Log.Verbose("New iteration");

            HubConnection connection = new HubConnection(Properties.HubUrl);

            connection.Error += (e) =>
                {
                    Log.Critical("Error in ConnectionId: {0}", connection.ConnectionId);
                    Log.Critical(e);
                    Debugger.Break();
                };

            IHubProxy hubProxy = connection.CreateHubProxy(HubName);

            string cid = string.Empty;

            IClientTransport transport = new ServerSentEventsTransport(new DefaultHttpClient());

            connection.Start(transport).Wait();

            cid = connection.ConnectionId;

            Log.Verbose("Established connection: {0}", cid);

            connection.Disconnect();

            Log.Information("Disconnect({0})", cid);
        }

This is what a successful iteration looks like:

StressTestLogger Verbose: 5 : RunVariation : [16:17:00] New iteration
ChangeState(New connection, Disconnected, Connecting)
EventSourceReader: Connection Closed 
SSE: GET http://CSVM1072701-TA/SignalR.Stress.AbortStopOrDisconnect/signalr/connect?transport=serverSentEvents&connectionToken=KM_oH12zO6fa0gGvslEg53RDrQxNNF32eQd5RXDKJAVPYrcmfXMipw7ri9szEIaXo2Ou_uJ3qYxl3eD8D5_UcWpoZRWaeZvcpFptID5su9x-LUAQldoEpkHzDQ8lCRWL0&connectionData=[{"Name":"AbortStopOrDisconnectHub"}]
EventSourceReader: Connection Opened 348d5ff6-d782-47ea-a21d-7796cfee87f3
ChangeState(348d5ff6-d782-47ea-a21d-7796cfee87f3, Connecting, Connected)
SSE: OnMessage(348d5ff6-d782-47ea-a21d-7796cfee87f3, Data: initialized)
StressTestLogger Verbose: 5 : RunVariation : [16:17:00] Established connection: 348d5ff6-d782-47ea-a21d-7796cfee87f3
Disconnect(348d5ff6-d782-47ea-a21d-7796cfee87f3)
Closed(348d5ff6-d782-47ea-a21d-7796cfee87f3)
StressTestLogger Information: 5 : RunVariation : [16:17:00] Disconnect(348d5ff6-d782-47ea-a21d-7796cfee87f3)

Here is what a failed iteration looks like:

StressTestLogger Verbose: 5 : RunVariation : [16:17:00] New iteration
ChangeState(New connection, Disconnected, Connecting)
(520.3d4): CLR exception - code e0434352 (first chance)
'System.ObjectDisposedException hit'
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
KERNELBASE!RaiseException+0x68:
000007f9`0cca89cc 488b8c24c0000000 mov     rcx,qword ptr [rsp+0C0h] ss:00000017`1a9aee60=00002b953793fb56
0:013> !clrstack
OS Thread Id: 0x3d4 (13)
        Child SP               IP Call Site
000000171a9af068 000007f90cca89cc [HelperMethodFrame: 000000171a9af068] 
000000171a9af150 000007f8a8cd60fa System.Net.Sockets.NetworkStream.EndRead(System.IAsyncResult)
000000171a9af1b0 000007f8a8e992e1 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a9af200 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a9af260 000007f8a8ad7d75 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a9af3c0 000007f8a8ad65e9 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a9af3f0 000007f8a8ad651f System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000171a9af440 000007f8a8c06e42 System.Net.ContextAwareResult.Complete(IntPtr)
000000171a9af4a0 000007f8a8cd3c21 System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a9af520 000007f8a8cd37d6 System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a9af6d8 000007f907dc9bb3 [GCFrame: 000000171a9af6d8] 
000000171a9af8a8 000007f907dc9bb3 [DebuggerU2MCatchHandlerFrame: 000000171a9af8a8] 
0:013> g
(520.3d4): CLR exception - code e0434352 (first chance)
CLR exception type: System.ObjectDisposedException
    "Cannot access a disposed object."
EventSourceReader: Connection Closed 
SSE: GET http://CSVM1072701-TA/SignalR.Stress.AbortStopOrDisconnect/signalr/connect?transport=serverSentEvents&connectionToken=S6-alPZCtSHqGImTCqs0SsEEyjED9TKWWTg1gz1sam28TtuNF6TIT2gRGHPz-Nr8j6JWZmKperksRwlpdKscElt6jp-pYyamALd68w9wQxgjz_x03Pv8iGJutKVyrc0u0&connectionData=[{"Name":"AbortStopOrDisconnectHub"}]
EventSourceReader: Connection Opened b955676a-2c04-4f7f-b38a-34fc368e98e6
ChangeState(b955676a-2c04-4f7f-b38a-34fc368e98e6, Connecting, Connected)
SSE: OnMessage(b955676a-2c04-4f7f-b38a-34fc368e98e6, Data: initialized)
StressTestLogger Verbose: 5 : RunVariation : [16:17:05] Established connection: b955676a-2c04-4f7f-b38a-34fc368e98e6
Disconnect(b955676a-2c04-4f7f-b38a-34fc368e98e6)
(520.254): CLR exception - code e0434352 (first chance)
'System.ObjectDisposedException hit'
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
KERNELBASE!RaiseException+0x68:
000007f9`0cca89cc 488b8c24c0000000 mov     rcx,qword ptr [rsp+0C0h] ss:00000017`1a8ae7c0=00002b953783f1f6
0:011> !clrstack
OS Thread Id: 0x254 (11)
        Child SP               IP Call Site
000000171a8ae9c8 000007f90cca89cc [HelperMethodFrame: 000000171a8ae9c8] 
000000171a8aeab0 000007f8a8cd60fa System.Net.Sockets.NetworkStream.EndRead(System.IAsyncResult)
000000171a8aeb10 000007f8a8e992e1 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a8aeb60 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a8aebc0 000007f8a8ad7d75 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed20 000007f8a8ad65e9 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed50 000007f8a8ad651f System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000171a8aeda0 000007f8a8c06e42 System.Net.ContextAwareResult.Complete(IntPtr)
000000171a8aee00 000007f8a8cd3c21 System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8aee80 000007f8a8cd37d6 System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8af038 000007f907dc9bb3 [GCFrame: 000000171a8af038] 
000000171a8af208 000007f907dc9bb3 [DebuggerU2MCatchHandlerFrame: 000000171a8af208] 
0:011> g
(520.254): CLR exception - code e0434352 (first chance)
CLR exception type: System.ObjectDisposedException
    "Cannot access a disposed object."
'System.ObjectDisposedException hit'
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
KERNELBASE!RaiseException+0x68:
000007f9`0cca89cc 488b8c24c0000000 mov     rcx,qword ptr [rsp+0C0h] ss:00000017`1a8ac560=00002b953783d256
0:011> !clrstack
OS Thread Id: 0x254 (11)
        Child SP               IP Call Site
000000171a8ac768 000007f90cca89cc [HelperMethodFrame: 000000171a8ac768] 
000000171a8ac850 000007f8a8e82aa0 System.Net.ConnectStream.EndRead(System.IAsyncResult)
000000171a8ac8e0 000007f8a8e82632 Microsoft.AspNet.SignalR.Infrastructure.StreamExtensions+<>c__DisplayClass4.<ReadAsync>b__1(System.IAsyncResult) [c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Infrastructure\StreamExtensions.cs @ 20]
000000171a8ac930 000007f8a8e82111 System.Threading.Tasks.TaskFactory`1[[System.Int32, mscorlib]].FromAsyncCoreLogic(System.IAsyncResult, System.Func`2<System.IAsyncResult,Int32>, System.Action`1<System.IAsyncResult>, System.Threading.Tasks.Task`1<Int32>, Boolean)
000000171a8ac9e0 000007f8a8e8205f System.Threading.Tasks.TaskFactory`1+<>c__DisplayClass7[[System.Int32, mscorlib]].<FromAsyncImpl>b__5(System.IAsyncResult)
000000171a8aca30 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a8aca90 000007f8a8e993e0 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a8ae9c8 000007f907eb5f6d [HelperMethodFrame: 000000171a8ae9c8] 
000000171a8aeab0 000007f8a8cd60fa System.Net.Sockets.NetworkStream.EndRead(System.IAsyncResult)
000000171a8aeb10 000007f8a8e992e1 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a8aeb60 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a8aebc0 000007f8a8ad7d75 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed20 000007f8a8ad65e9 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed50 000007f8a8ad651f System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000171a8aeda0 000007f8a8c06e42 System.Net.ContextAwareResult.Complete(IntPtr)
000000171a8aee00 000007f8a8cd3c21 System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8aee80 000007f8a8cd37d6 System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8af038 000007f907dc9bb3 [GCFrame: 000000171a8af038] 
000000171a8af208 000007f907dc9bb3 [DebuggerU2MCatchHandlerFrame: 000000171a8af208] 
0:011> g
EventSourceReader: Connection Closed b955676a-2c04-4f7f-b38a-34fc368e98e6
OnError(System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.NetworkStream'.
   at System.Net.ConnectStream.EndRead(IAsyncResult asyncResult)
   at Microsoft.AspNet.SignalR.Infrastructure.StreamExtensions.<>c__DisplayClass4.<ReadAsync>b__1(IAsyncResult ar) in c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Infrastructure\StreamExtensions.cs:line 20
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization))
StressTestLogger Critical: 41 : [16:17:17] Error in ConnectionId: b955676a-2c04-4f7f-b38a-34fc368e98e6
StressTestLogger Critical: 41 : [16:17:17] System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.NetworkStream'.
   at System.Net.ConnectStream.EndRead(IAsyncResult asyncResult)
   at Microsoft.AspNet.SignalR.Infrastructure.StreamExtensions.<>c__DisplayClass4.<ReadAsync>b__1(IAsyncResult ar) in c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Infrastructure\StreamExtensions.cs:line 20
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
(520.254): Break instruction exception - code 80000003 (first chance)
KERNELBASE!DebugBreak+0x2:
000007f9`0cd343da cc              int     3
0:011> !clrstack
OS Thread Id: 0x254 (11)
        Child SP               IP Call Site
000000171a8abf98 000007f90cd343da [HelperMethodFrame: 000000171a8abf98] System.Diagnostics.Debugger.BreakInternal()
000000171a8ac080 000007f8a8e9b446 System.Diagnostics.Debugger.Break()
000000171a8ac0d0 000007f8a8e9b28b *** WARNING: Unable to verify checksum for C:\eth\b9f4d897-9898-4609-b92a-1ccc94a2dddf\SignalR.Stress.AbortStopOrDisconnect.exe
SignalR.Stress.AbortStopOrDisconnect.Program+<>c__DisplayClass2.<RunVariation>b__0(System.Exception) [c:\Users\jconde\Desktop\Stress\SignalR.Stress.AbortStopOrDisconnect\SignalR.Stress.AbortStopOrDisconnect\Program.cs @ 54]
000000171a8ac120 000007f8a8e99c1c Microsoft.AspNet.SignalR.Client.Connection.Microsoft.AspNet.SignalR.Client.IConnection.OnError(System.Exception) [c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Connection.cs @ 556]
000000171a8ac170 000007f8a8e94d6c Microsoft.AspNet.SignalR.Client.Transports.ServerSentEventsTransport+<>c__DisplayClassf+<>c__DisplayClass13.<OpenConnection>b__8(System.Exception) [c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Transports\ServerSentEventsTransport.cs @ 183]
000000171a8ac210 000007f8a8e9499c Microsoft.AspNet.SignalR.Client.Transports.ServerSentEvents.EventSourceStreamReader.Close(System.Exception) [c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Transports\ServerSentEvents\EventSourceStreamReader.cs @ 223]
000000171a8ac2d0 000007f8a8e99551 Microsoft.AspNet.SignalR.Client.Transports.ServerSentEvents.EventSourceStreamReader.<ReadAsync>b__3(System.Threading.Tasks.Task`1<Int32>) [c:\Users\jconde\Documents\GitHub\SignalR\src\Microsoft.AspNet.SignalR.Client\Transports\ServerSentEvents\EventSourceStreamReader.cs @ 141]
000000171a8ac350 000007f8a8ce178e System.Threading.Tasks.Task.Execute()
000000171a8ac3c0 000007f8a8ad7d75 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8ac520 000007f8a8ad65e9 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8ac550 000007f8a8ce12da System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef)
000000171a8ac640 000007f8a8ce0cb0 System.Threading.Tasks.Task.ExecuteEntry(Boolean)
000000171a8ac680 000007f8a8e838d5 System.Threading.Tasks.ThreadPoolTaskScheduler.TryExecuteTaskInline(System.Threading.Tasks.Task, Boolean)
000000171a8ac6d0 000007f8a8e836a3 System.Threading.Tasks.TaskScheduler.TryRunInline(System.Threading.Tasks.Task, Boolean)
000000171a8ac750 000007f8a8e83437 System.Threading.Tasks.TaskContinuation.InlineIfPossibleOrElseQueue(System.Threading.Tasks.Task, Boolean)
000000171a8ac7f0 000007f8a8bd4401 System.Threading.Tasks.Task.FinishContinuations()
000000171a8ac880 000007f8a8ce230c System.Threading.Tasks.Task.Finish(Boolean)
000000171a8ac8e0 000007f8a8e9081a System.Threading.Tasks.Task`1[[System.Int32, mscorlib]].TrySetException(System.Object)
000000171a8ac930 000007f8a8e8218d System.Threading.Tasks.TaskFactory`1[[System.Int32, mscorlib]].FromAsyncCoreLogic(System.IAsyncResult, System.Func`2<System.IAsyncResult,Int32>, System.Action`1<System.IAsyncResult>, System.Threading.Tasks.Task`1<Int32>, Boolean)
000000171a8ac9e0 000007f8a8e8205f System.Threading.Tasks.TaskFactory`1+<>c__DisplayClass7[[System.Int32, mscorlib]].<FromAsyncImpl>b__5(System.IAsyncResult)
000000171a8aca30 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a8aca90 000007f8a8e993e0 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a8ae9c8 000007f907eb5f6d [HelperMethodFrame: 000000171a8ae9c8] 
000000171a8aeab0 000007f8a8cd60fa System.Net.Sockets.NetworkStream.EndRead(System.IAsyncResult)
000000171a8aeb10 000007f8a8e992e1 System.Net.ChunkParser.ReadCallback(System.IAsyncResult)
000000171a8aeb60 000007f8a8c06f48 System.Net.LazyAsyncResult.Complete(IntPtr)
000000171a8aebc0 000007f8a8ad7d75 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed20 000007f8a8ad65e9 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000171a8aed50 000007f8a8ad651f System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000171a8aeda0 000007f8a8c06e42 System.Net.ContextAwareResult.Complete(IntPtr)
000000171a8aee00 000007f8a8cd3c21 System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8aee80 000007f8a8cd37d6 System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)
000000171a8af038 000007f907dc9bb3 [GCFrame: 000000171a8af038] 
000000171a8af208 000007f907dc9bb3 [DebuggerU2MCatchHandlerFrame: 000000171a8af208]
@halter73 halter73 was assigned Mar 21, 2013
@davidfowl
Member

I believe it's because of the connection slow event. I just saw this happen after LostConnection was called.

@jcondex jcondex was assigned Mar 27, 2013
@davidfowl
Member

@jcondex What's the status of this?

@jcondex
jcondex commented Apr 9, 2013

This is now fixed and the issue can be closed.

@davidfowl davidfowl closed this Apr 9, 2013
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment