Not responding - UvException: Error -107 ENOTCONN socket is not connected

[khancyai]

Hi, Kestrel http server behind of nginx (centOS), sometimes randomly hanging not responding.

This time a got this error message ;

fail: Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv[0]
May 17 05:36:39 myserver[11532]: Listener.OnConnection
May 17 05:36:39 myserver[11532]: Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.UvException: Error -107 ENOTCONN socket is not connected
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.LibuvFunctions.ThrowError(Int32 statusCode)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.LibuvFunctions.tcp_getpeername(UvTcpHandle handle, SockAddr& addr, Int32& namelen)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.UvTcpHandle.GetPeerIPEndPoint()
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.LibuvConnection..ctor(ListenerContext context, UvStreamHandle socket)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Listener.DispatchConnection(UvStreamHandle socket)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Listener.OnConnection(UvStreamHandle listenSocket, Int32 status)
May 17 05:36:39 myserver[11532]: fail: Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv[0]
May 17 05:36:39 myserver[11532]: Listener.OnConnection
May 17 05:36:39 myserver[11532]: Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.UvException: Error -107 ENOTCONN socket is not connected
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.LibuvFunctions.ThrowError(Int32 statusCode)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.LibuvFunctions.tcp_getpeername(UvTcpHandle handle, SockAddr& addr, Int32& namelen)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Networking.UvTcpHandle.GetPeerIPEndPoint()
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.LibuvConnection..ctor(ListenerContext context, UvStreamHandle socket)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Listener.DispatchConnection(UvStreamHandle socket)
May 17 05:36:39 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal.Listener.OnConnection(UvStreamHandle listenSocket, Int32 status)
May 17 05:36:46 myserver[11532]: info: Microsoft.AspNetCore.Server.Kestrel[17]

May 17 05:36:46 myserver[11532]: Connection id "0HLDRI6731JP6" bad request data: "Invalid request line: '\x0D\x0A'"
May 17 05:36:46 myserver[11532]: Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Invalid request line: '\x0D\x0A'
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpParser`1.RejectRequestLine(Byte* requestLine, Int32 length)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpParser`1.GetUnknownMethod(Byte* data, Int32 length, Int32& methodLength)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpParser`1.ParseRequestLine(TRequestHandler handler, Byte* data, Int32 length)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpParser`1.ParseRequestLine(TRequestHandler handler, ReadableBuffer buffer, ReadCursor& consumed, ReadCursor& examined)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame.TakeStartLine(ReadableBuffer buffer, ReadCursor& consumed, ReadCursor& examined)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame.ParseRequest(ReadableBuffer buffer, ReadCursor& consumed, ReadCursor& examined)
May 17 05:36:46 myserver[11532]: at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1.<ProcessRequestsAsync>d__2.MoveNext()
May 17 05:36:46 myserver[11532]: info: Microsoft.AspNetCore.Server.Kestrel[17]

[halter73]

The ENOTCONN is a badly reported connection reset that happens almost immediately after the connection is established. We're cleaning up the logging for this with #2547.

The following log is more interesting:

Microsoft.AspNetCore.Server.Kestrel[17] May 17 05:36:46 myserver[11532]: Connection id "0HLDRI6731JP6" bad request data: "Invalid request line: '\x0D\x0A'" May 17 05:36:46 myserver[11532]: Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Invalid request line: '\x0D\x0A'

This is saying that a carriage return line feed (\r\n) was received at the start of the request instead of the expected HTTP method (e.g. GET). This is invalid HTTP so the request is rejected. This can be caused by any random misbehaving client which is why it's logged with a relatively low "info" severity, but if the invalid request is coming from your client, that could explain the observed hang.

[halter73]

#2547 is in dev which should fix the error reporting for the ENOTCONN. Are you still seeing BadHttpRequestException?

[halter73]

Didn't mean to close.

[shirhatti]

Hi. We're closing this issue as no response or updates have been provided in a timely manner and we have been unable to reproduce it. If you have more details and are encountering this issue please add a new reply and re-open the issue.

[khancyai]

Hi, thank you for efforts, didn't understand how do i fix the problem?

[halter73]

@khancyai Upgrading to ASP.NET Core 2.1 should remove the ENOTCONN logs you're seeing. As for the BadHttpRequestException, I'll quote my previous response:

This is saying that a carriage return line feed (\r\n) was received at the start of the request instead of the expected HTTP method (e.g. GET). This is invalid HTTP so the request is rejected. This can be caused by any random misbehaving client which is why it's logged with a relatively low "info" severity, but if the invalid request is coming from your client, that could explain the observed hang.

If you're still seeing BadHttpRequestExceptions and you think that the client is in fact sending valid requests, we'll need some more details about what client you're using (browser, c# HttpClient, etc...) and how you're using it. As far as I'm aware no one else has reported this kind of BadHttpRequestException before so I'm guessing there must be something fairly unusual going on.