Clients infinitely trying to reconnect to Azure App service

bgiromini · February 13, 2020, 3:34pm

I have a client that attempts to connect to a service hosted on Azure App Service. Testing locally works great ( of course!) however it will constantly try to reconnect every second. When I dig into the source code I see that public void ProcessResponse(Stream stream) is being passed an EmptyReadStream and that seems to be what causes the client to constantly reconnect. When I review the connections in Dev Tools, I see the event stream getting a 200 ok response from the service but nothing else.

Any ideas what could be causing this?

mythz · February 13, 2020, 4:09pm

If the Stream is empty it suggests no content is being returned from the stream, have you had a look at WireShark or Fiddler to see exactly what’s being returned to the client?

bgiromini · February 13, 2020, 4:21pm

I will do that. Microsoft says App Service is supposed to let you focus on your code and not the infrastructure, well they lied!

bgiromini · February 13, 2020, 5:26pm

Fiddler and Wireshark need more tweaking as I had a hard time with finding the connections and then dealing with SSL. In Dev Tools however I see the following:

I am going to try a Windows App Service and see if I get different results.

mythz · February 14, 2020, 12:34am

You can also try seeing if you can detect any behavioral differences by loading the Request URL to /event-stream?... locally vs over Azure. It should be a long-lived HTTP Response, if it terminates early or doesn’t return anything it’s a problem.

bgiromini · February 14, 2020, 3:25am

I turned on App Service Logs and that helped me fix a outdated database column that was not being used. I can now get the onConnect to work, but I then get the following exception in the ServerEventsFeature

2020-02-14T03:17:20.708325402Z       Request starting HTTP/1.1 GET http://myapp.azurewebsites.net/event-stream?channels=ui&t=1581650198609
2020-02-14T03:17:20.758378811Z 2020-02-14 03:17:20.757 +00:00 [WRN] Could not publish notification to:
2020-02-14T03:17:20.758418011Z
2020-02-14T03:17:20.758424811Z System.ObjectDisposedException: IFeatureCollection has been disposed.
2020-02-14T03:17:20.758429811Z Object name: 'Collection'.
2020-02-14T03:17:20.758434511Z    at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
2020-02-14T03:17:20.763837644Z    at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_Body()
2020-02-14T03:17:20.763853145Z    at ServiceStack.ServerEventsFeature.<>c.<<-ctor>b__96_1>d.MoveNext() in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 93
2020-02-14T03:17:20.763859845Z --- End of stack trace from previous location where exception was thrown ---
2020-02-14T03:17:20.763864645Z    at ServiceStack.EventSubscription.PublishRawAsync(String frame, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 591
2020-02-14T03:17:20.766310860Z  {"SourceContext": "ServiceStack.EventSubscription", "MachineName": "ef4499fac378", "ExceptionDetail": {"HResult": -2146232798, "Message": "IFeatureCollection has been disposed.\nObject name: 'Collection'.", "Source": "Microsoft.AspNetCore.Http.Features", "StackTrace": "   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()\n   at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_Body()\n   at ServiceStack.ServerEventsFeature.<>c.<<-ctor>b__96_1>d.MoveNext() in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 93\n--- End of stack trace from previous location where exception was thrown ---\n   at ServiceStack.EventSubscription.PublishRawAsync(String frame, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 591", "ObjectName": "Collection", "Type": "System.ObjectDisposedException"}}2020-02-14 03:17:20.759 +00:00 [ERR] Register: Exception has been thrown by the target of an invocation.
2020-02-14T03:17:20.766331860Z System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
2020-02-14T03:17:20.767081864Z  ---> System.InvalidOperationException: Method may only be called on a Type for which Type.IsGenericParameter is true.
2020-02-14T03:17:20.767096365Z    at System.RuntimeType.get_DeclaringMethod()
2020-02-14T03:17:20.767101465Z    --- End of inner exception stack trace ---
2020-02-14T03:17:20.767105865Z    at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)
2020-02-14T03:17:20.767110565Z    at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
2020-02-14T03:17:20.767115165Z    at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 403
2020-02-14T03:17:20.772800900Z    at ServiceStack.Text.TypeSerializer.<HasCircularReferences>g__CheckValue|32_0(Object key, <>c__DisplayClass32_0& ) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 364
2020-02-14T03:17:20.772853200Z    at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 404
2020-02-14T03:17:20.772860900Z    at ServiceStack.Text.TypeSerializer.<HasCircularReferences>g__CheckValue|32_0(Object key, <>c__DisplayClass32_0& ) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 364
2020-02-14T03:17:20.772866500Z    at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 404
2020-02-14T03:17:20.772871400Z    at ServiceStack.Text.TypeSerializer.SerializeAndFormat[T](T instance) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 311
2020-02-14T03:17:20.772876200Z    at ServiceStack.Text.TypeSerializer.PrintDump[T](T instance) in C:\BuildAgent\work\912418dcce86a188\src\ServiceStack.Text\TypeSerializer.cs:line 282
2020-02-14T03:17:20.772880900Z    at Alert.Web.ConfigureServerEvents.<>c.<Configure>b__5_0(IEventSubscription subscription, Exception exception) in D:\a\1\s\Alert.Web\Configure.ServerEvents.cs:line 34
2020-02-14T03:17:20.773178702Z    at ServiceStack.EventSubscription.HandleWriteExceptionAsync(String frame, Exception ex, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 663
2020-02-14T03:17:20.773190502Z    at ServiceStack.EventSubscription.PublishRawAsync(String frame, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 591
2020-02-14T03:17:20.773195802Z    at ServiceStack.MemoryServerEvents.FlushNopAsync(ConcurrentDictionary`2 map, String key, String channel, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 1116
2020-02-14T03:17:20.773200602Z    at ServiceStack.MemoryServerEvents.FlushNopToChannelsAsync(String[] channels, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 1417
2020-02-14T03:17:20.773468404Z    at ServiceStack.MemoryServerEvents.RegisterAsync(IEventSubscription subscription, Dictionary`2 connectArgs, CancellationToken token) in C:\BuildAgent\work\3481147c480f4a2f\src\ServiceStack\ServerEventsFeature.cs:line 1395
2020-02-14T03:17:20.781774255Z  {"SourceContext": "ServiceStack.MemoryServerEvents", "MachineName": "ef4499fac378", "ExceptionDetail": {"Type": "System.Reflection.TargetInvocationException", "HResult": -2146232828, "Message": "Exception has been thrown by the target of an invocation.", "Source": "System.Private.CoreLib", "StackTrace": "   at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)\n   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)\n   at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 403\n   at ServiceStack.Text.TypeSerializer.<HasCircularReferences>g__CheckValue|32_0(Object key, <>c__DisplayClass32_0& ) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 364\n   at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 404\n   at ServiceStack.Text.TypeSerializer.<HasCircularReferences>g__CheckValue|32_0(Object key, <>c__DisplayClass32_0& ) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 364\n   at ServiceStack.Text.TypeSerializer.HasCircularReferences(Object value, Stack`1 parentValues) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 404\n   at ServiceStack.Text.TypeSerializer.SerializeAndFormat[T](T instance) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 311\n   at ServiceStack.Text.TypeSerializer.PrintDump[T](T instance) in C:\\BuildAgent\\work\\912418dcce86a188\\src\\ServiceStack.Text\\TypeSerializer.cs:line 282\n   at Alert.Web.ConfigureServerEvents.<>c.<Configure>b__5_0(IEventSubscription subscription, Exception exception) in D:\\a\\1\\s\\Alert.Web\\Configure.ServerEvents.cs:line 34\n   at ServiceStack.EventSubscription.HandleWriteExceptionAsync(String frame, Exception ex, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 663\n   at ServiceStack.EventSubscription.PublishRawAsync(String frame, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 591\n   at ServiceStack.MemoryServerEvents.FlushNopAsync(ConcurrentDictionary`2 map, String key, String channel, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 1116\n   at ServiceStack.MemoryServerEvents.FlushNopToChannelsAsync(String[] channels, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 1417\n   at ServiceStack.MemoryServerEvents.RegisterAsync(IEventSubscription subscription, Dictionary`2 connectArgs, CancellationToken token) in C:\\BuildAgent\\work\\3481147c480f4a2f\\src\\ServiceStack\\ServerEventsFeature.cs:line 1395", "InnerException": {"Type": "System.InvalidOperationException", "HResult": -2146233079, "Message": "Method may only be called on a Type for which Type.IsGenericParameter is true.", "Source": "System.Private.CoreLib", "StackTrace": "   at System.RuntimeType.get_DeclaringMethod()"}}}

mythz · February 14, 2020, 4:34am

Never seen this Exception before, what do you have in Alert.Web.ConfigureServerEvents that’s calling PrintDump()? Is the method you trying to dump have circular dependencies?

bgiromini · February 14, 2020, 4:57am

Yes, after I posted the reply I looked through the stacktrace more in depth and noticed the printDump. What is weird is the code was in the Exception code, but once I changed it to use Log.Error() it started working again. All is well again and the stream is working as expected. Sorry for the false alarm.