diff --git a/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs b/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs index 039ce58318..8560a7bbbd 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs @@ -54,6 +54,7 @@ namespace Microsoft.AspNet.Server.Kestrel.Http private readonly UvStreamHandle _socket; private Frame _frame; + long _connectionId; public Connection(ListenerContext context, UvStreamHandle socket) : base(context) { @@ -63,6 +64,8 @@ namespace Microsoft.AspNet.Server.Kestrel.Http public void Start() { + KestrelTrace.Log.ConnectionStart(_connectionId); + SocketInput = new SocketInput(Memory); SocketOutput = new SocketOutput(Thread, _socket); _frame = new Frame(this); @@ -85,6 +88,11 @@ namespace Microsoft.AspNet.Server.Kestrel.Http if (nread == 0) { SocketInput.RemoteIntakeFin = true; + KestrelTrace.Log.ConnectionReadFin(_connectionId); + } + else + { + KestrelTrace.Log.ConnectionRead(_connectionId, nread); } _frame.Consume(); @@ -92,11 +100,13 @@ namespace Microsoft.AspNet.Server.Kestrel.Http void IConnectionControl.Pause() { + KestrelTrace.Log.ConnectionPause(_connectionId); _socket.ReadStop(); } void IConnectionControl.Resume() { + KestrelTrace.Log.ConnectionResume(_connectionId); _socket.ReadStart(_allocCallback, _readCallback, this); } @@ -105,25 +115,37 @@ namespace Microsoft.AspNet.Server.Kestrel.Http switch (endType) { case ProduceEndType.SocketShutdownSend: + KestrelTrace.Log.ConnectionWriteFin(_connectionId, 0); Thread.Post( x => { + KestrelTrace.Log.ConnectionWriteFin(_connectionId, 1); var self = (Connection)x; var shutdown = new UvShutdownReq(); shutdown.Init(self.Thread.Loop); - shutdown.Shutdown(self._socket, (req, status, state) => req.Dispose(), null); + shutdown.Shutdown(self._socket, (req, status, state) => + { + KestrelTrace.Log.ConnectionWriteFin(_connectionId, 1); + req.Dispose(); + }, null); }, this); break; case ProduceEndType.ConnectionKeepAlive: + KestrelTrace.Log.ConnectionKeepAlive(_connectionId); _frame = new Frame(this); Thread.Post( x => ((Frame)x).Consume(), _frame); break; case ProduceEndType.SocketDisconnect: + KestrelTrace.Log.ConnectionDisconnect(_connectionId); Thread.Post( - x => ((UvHandle)x).Dispose(), + x => + { + KestrelTrace.Log.ConnectionStop(_connectionId); + ((UvHandle)x).Dispose(); + }, _socket); break; } diff --git a/src/Microsoft.AspNet.Server.Kestrel/Http/Frame.cs b/src/Microsoft.AspNet.Server.Kestrel/Http/Frame.cs index c9966e085c..2104952722 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Http/Frame.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Http/Frame.cs @@ -321,8 +321,8 @@ namespace Microsoft.AspNet.Server.Kestrel.Http ConnectionControl.End(ProduceEndType.SocketShutdownSend); } - _messageBody.Drain(() => - ConnectionControl.End(_keepAlive ? ProduceEndType.ConnectionKeepAlive : ProduceEndType.SocketDisconnect)); + //NOTE: must finish reading request body + ConnectionControl.End(_keepAlive ? ProduceEndType.ConnectionKeepAlive : ProduceEndType.SocketDisconnect); } diff --git a/src/Microsoft.AspNet.Server.Kestrel/Http/MessageBody.cs b/src/Microsoft.AspNet.Server.Kestrel/Http/MessageBody.cs index a4ab91cedc..a77bda0f6b 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Http/MessageBody.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Http/MessageBody.cs @@ -3,13 +3,12 @@ using System; using System.Collections.Generic; +using System.Threading; namespace Microsoft.AspNet.Server.Kestrel.Http { public abstract class MessageBody : MessageBodyExchanger { - private Action _continuation = () => { }; - public bool RequestKeepAlive { get; protected set; } protected MessageBody(FrameContext context) : base(context) @@ -24,10 +23,6 @@ namespace Microsoft.AspNet.Server.Kestrel.Http public void IntakeFin(int count) { Transfer(count, true); - if (_continuation != null) - { - _continuation.Invoke(); - } } public abstract void Consume(); @@ -90,12 +85,6 @@ namespace Microsoft.AspNet.Server.Kestrel.Http return true; } - public void Drain(Action continuation) - { - _continuation = continuation; - _continuation.Invoke(); - } - class ForRemainingData : MessageBody { diff --git a/src/Microsoft.AspNet.Server.Kestrel/Http/SocketOutput.cs b/src/Microsoft.AspNet.Server.Kestrel/Http/SocketOutput.cs index d3381f22fe..fb1aa9cc0b 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Http/SocketOutput.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Http/SocketOutput.cs @@ -28,6 +28,7 @@ namespace Microsoft.AspNet.Server.Kestrel.Http public void Write(ArraySegment buffer, Action callback, object state) { + KestrelTrace.Log.ConnectionWrite(0, buffer.Count); var req = new ThisWriteReq(); req.Init(_thread.Loop); req.Contextualize(this, _socket, buffer, callback, state); @@ -87,6 +88,7 @@ namespace Microsoft.AspNet.Server.Kestrel.Http private void OnWrite(UvWriteReq req, int status) { _pin.Free(); + KestrelTrace.Log.ConnectionWriteCallback(0, status); //NOTE: pool this? Dispose(); _callback(_state); diff --git a/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs new file mode 100644 index 0000000000..907567bb82 --- /dev/null +++ b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs @@ -0,0 +1,83 @@ +using System; +using System.Diagnostics.Tracing; + +namespace Microsoft.AspNet.Server.Kestrel +{ + /// + /// Summary description for KestrelTrace + /// + public class KestrelTrace : EventSource + { + public static KestrelTrace Log = new KestrelTrace(); + static EventTask Connection = (EventTask)1; + static EventTask Frame = (EventTask)1; + + + [Event(13, Level = EventLevel.Informational, Message = "Id {0}")] + public void ConnectionStart(long connectionId) + { + WriteEvent(13, connectionId); + } + + [Event(14, Level = EventLevel.Informational, Message = "Id {0}")] + public void ConnectionStop(long connectionId) + { + WriteEvent(14, connectionId); + } + + + [Event(4, Message = "Id {0} Status {1}")] + internal void ConnectionRead(long connectionId, int status) + { + WriteEvent(4, connectionId, status); + } + + [Event(5, Message = "Id {0}")] + internal void ConnectionPause(long connectionId) + { + WriteEvent(5, connectionId); + } + + [Event(6, Message = "Id {0}")] + internal void ConnectionResume(long connectionId) + { + WriteEvent(6, connectionId); + } + + [Event(7, Message = "Id {0}")] + internal void ConnectionReadFin(long connectionId) + { + WriteEvent(7, connectionId); + } + + [Event(8, Message = "Id {0} Step {1}")] + internal void ConnectionWriteFin(long connectionId, int step) + { + WriteEvent(8, connectionId, step); + } + + [Event(9, Message = "Id {0}")] + internal void ConnectionKeepAlive(long connectionId) + { + WriteEvent(9, connectionId); + } + + [Event(10, Message = "Id {0}")] + internal void ConnectionDisconnect(long connectionId) + { + WriteEvent(10, connectionId); + } + + [Event(11, Message = "Id {0} Count {1}")] + internal void ConnectionWrite(long connectionId, int count) + { + WriteEvent(11, connectionId, count); + } + + [Event(12, Message = "Id {0} Status {1}")] + internal void ConnectionWriteCallback(long connectionId, int status) + { + WriteEvent(12, connectionId, status); + } + } +} diff --git a/src/Microsoft.AspNet.Server.Kestrel/Microsoft.AspNet.Server.Kestrel.kproj b/src/Microsoft.AspNet.Server.Kestrel/Microsoft.AspNet.Server.Kestrel.kproj index 112e8fd2ab..9ba02d48db 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Microsoft.AspNet.Server.Kestrel.kproj +++ b/src/Microsoft.AspNet.Server.Kestrel/Microsoft.AspNet.Server.Kestrel.kproj @@ -42,6 +42,7 @@ + @@ -54,4 +55,4 @@ - + \ No newline at end of file diff --git a/src/Microsoft.AspNet.Server.Kestrel/project.json b/src/Microsoft.AspNet.Server.Kestrel/project.json index 591be84f59..6dba34e730 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/project.json +++ b/src/Microsoft.AspNet.Server.Kestrel/project.json @@ -12,7 +12,8 @@ "System.Threading.Thread": "4.0.0.0", "System.Diagnostics.TraceSource": "4.0.0.0", "System.Text.Encoding": "4.0.20.0", - "System.Threading.Tasks": "4.0.10.0" + "System.Threading.Tasks": "4.0.10.0", + "System.Diagnostics.Tracing": "4.0.10.0" } } }, diff --git a/test/Microsoft.AspNet.Server.KestralTests/EngineTests.cs b/test/Microsoft.AspNet.Server.KestralTests/EngineTests.cs index 56c8e551c1..414e825277 100644 --- a/test/Microsoft.AspNet.Server.KestralTests/EngineTests.cs +++ b/test/Microsoft.AspNet.Server.KestralTests/EngineTests.cs @@ -95,226 +95,204 @@ namespace Microsoft.AspNet.Server.KestralTests [Fact] public async Task Http10() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(App); - - Transceive( -@"POST / HTTP/1.0 - -Hello World", -@"HTTP/1.0 200 OK - -Hello World"); - started.Dispose(); - engine.Stop(); + using (var server = new TestServer(App)) + { + using (var connection = new TestConnection()) + { + await connection.SendEnd( + "POST / HTTP/1.0", + "", + "Hello World"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "", + "Hello World"); + } + } } + [Fact] + public async Task Http11() + { + using (var server = new TestServer(AppChunked)) + { + using (var connection = new TestConnection()) + { + await connection.SendEnd( + "GET / HTTP/1.1", + "", + "GET / HTTP/1.1", + "Connection: close", + "", + "Goodbye"); + await connection.ReceiveEnd( + "HTTP/1.1 200 OK", + "Content-Length: 0", + "", + "HTTP/1.1 200 OK", + "Content-Length: 7", + "Connection: close", + "", + "Goodbye"); + } + } + } + + [Fact] public async Task Http10ContentLength() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(App); - - Transceive( -@"POST / HTTP/1.0 -Content-Length: 11 - -Hello World", -@"HTTP/1.0 200 OK - -Hello World"); - started.Dispose(); - engine.Stop(); + using (var server = new TestServer(App)) + { + using (var connection = new TestConnection()) + { + await connection.Send( + "POST / HTTP/1.0", + "Content-Length: 11", + "", + "Hello World"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "", + "Hello World"); + } + } } [Fact] public async Task Http10TransferEncoding() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(App); - - using (var connection = new TestConnection()) + using (var server = new TestServer(App)) { - await connection.Send( - "POST / HTTP/1.0", - "Transfer-Encoding: chunked", - "", - "5", "Hello", "6", " World", "0\r\n"); - await connection.ReceiveEnd( - "HTTP/1.0 200 OK", - "", - "Hello World"); + using (var connection = new TestConnection()) + { + await connection.Send( + "POST / HTTP/1.0", + "Transfer-Encoding: chunked", + "", + "5", "Hello", "6", " World", "0\r\n"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "", + "Hello World"); + } } - - - - started.Dispose(); - engine.Stop(); } [Fact] public async Task Http10KeepAlive() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(AppChunked); - - using (var connection = new TestConnection()) + using (var server = new TestServer(AppChunked)) { - await connection.SendEnd( - "GET / HTTP/1.0", - "Connection: keep-alive", - "", - "POST / HTTP/1.0", - "", - "Goodbye"); - await connection.Receive( - "HTTP/1.0 200 OK", - "Content-Length: 0", - "Connection: keep-alive", - "\r\n"); - await connection.ReceiveEnd( - "HTTP/1.0 200 OK", - "Content-Length: 7", - "", - "Goodbye"); + using (var connection = new TestConnection()) + { + await connection.SendEnd( + "GET / HTTP/1.0", + "Connection: keep-alive", + "", + "POST / HTTP/1.0", + "", + "Goodbye"); + await connection.Receive( + "HTTP/1.0 200 OK", + "Content-Length: 0", + "Connection: keep-alive", + "\r\n"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "Content-Length: 7", + "", + "Goodbye"); + } } - - started.Dispose(); - engine.Stop(); } [Fact] public async Task Http10KeepAliveContentLength() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(AppChunked); - - using (var connection = new TestConnection()) + using (var server = new TestServer(AppChunked)) { - await connection.SendEnd( - "POST / HTTP/1.0", - "Connection: keep-alive", - "Content-Length: 11", - "", - "Hello WorldPOST / HTTP/1.0", - "", - "Goodbye"); - await connection.Receive( - "HTTP/1.0 200 OK", - "Content-Length: 11", - "Connection: keep-alive", - "", - "Hello World"); - await connection.ReceiveEnd( - "HTTP/1.0 200 OK", - "Content-Length: 7", - "", - "Goodbye"); + using (var connection = new TestConnection()) + { + await connection.SendEnd( + "POST / HTTP/1.0", + "Connection: keep-alive", + "Content-Length: 11", + "", + "Hello WorldPOST / HTTP/1.0", + "", + "Goodbye"); + await connection.Receive( + "HTTP/1.0 200 OK", + "Content-Length: 11", + "Connection: keep-alive", + "", + "Hello World"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "Content-Length: 7", + "", + "Goodbye"); + } } - started.Dispose(); - engine.Stop(); } [Fact] public async Task Http10KeepAliveTransferEncoding() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(AppChunked); - - using (var connection = new TestConnection()) + using (var server = new TestServer(AppChunked)) { - await connection.SendEnd( - "POST / HTTP/1.0", - "Transfer-Encoding: chunked", - "Connection: keep-alive", - "", - "5", "Hello", "6", " World", "0", - "POST / HTTP/1.0", - "", - "Goodbye"); - await connection.Receive( - "HTTP/1.0 200 OK", - "Content-Length: 11", - "Connection: keep-alive", - "", - "Hello World"); - await connection.ReceiveEnd( - "HTTP/1.0 200 OK", - "Content-Length: 7", - "", - "Goodbye"); + using (var connection = new TestConnection()) + { + await connection.SendEnd( + "POST / HTTP/1.0", + "Transfer-Encoding: chunked", + "Connection: keep-alive", + "", + "5", "Hello", "6", " World", "0", + "POST / HTTP/1.0", + "", + "Goodbye"); + await connection.Receive( + "HTTP/1.0 200 OK", + "Content-Length: 11", + "Connection: keep-alive", + "", + "Hello World"); + await connection.ReceiveEnd( + "HTTP/1.0 200 OK", + "Content-Length: 7", + "", + "Goodbye"); + } } - - started.Dispose(); - engine.Stop(); } [Fact] public async Task Expect100ContinueForBody() { - var engine = new KestrelEngine(); - engine.Start(1); - var started = engine.CreateServer(AppChunked); - - using (var connection = new TestConnection()) + using (var server = new TestServer(AppChunked)) { - await connection.Send( - "POST / HTTP/1.1", - "Expect: 100-continue", - "Content-Length: 11", - "Connection: close", - "\r\n"); - await connection.Receive("HTTP/1.1 100 Continue", "\r\n"); - await connection.SendEnd("Hello World"); - await connection.Receive( - "HTTP/1.1 200 OK", - "Content-Length: 11", - "Connection: close", - "", - "Hello World"); + using (var connection = new TestConnection()) + { + await connection.Send( + "POST / HTTP/1.1", + "Expect: 100-continue", + "Content-Length: 11", + "Connection: close", + "\r\n"); + await connection.Receive("HTTP/1.1 100 Continue", "\r\n"); + await connection.SendEnd("Hello World"); + await connection.Receive( + "HTTP/1.1 200 OK", + "Content-Length: 11", + "Connection: close", + "", + "Hello World"); + } } - - started.Dispose(); - engine.Stop(); } - private void Transceive(string send, string expected) - { - var socket = new Socket(AddressFamily.InterNetwork, SocketType.Stream, ProtocolType.Tcp); - socket.Connect(new IPEndPoint(IPAddress.Loopback, 4001)); - - var stream = new NetworkStream(socket, false); - Task.Run(async () => - { - try - { - var writer = new StreamWriter(stream, Encoding.ASCII); - foreach (var ch in send) - { - await writer.WriteAsync(ch); - await writer.FlushAsync(); - await Task.Delay(TimeSpan.FromMilliseconds(5)); - } - writer.Flush(); - stream.Flush(); - socket.Shutdown(SocketShutdown.Send); - } - catch (Exception ex) - { - } - }); - - var reader = new StreamReader(stream, Encoding.ASCII); - var actual = reader.ReadToEnd(); - - Assert.Equal(expected, actual); - } } } diff --git a/test/Microsoft.AspNet.Server.KestralTests/TestConnection.cs b/test/Microsoft.AspNet.Server.KestralTests/TestConnection.cs index a53d2594de..d07e0e4925 100644 --- a/test/Microsoft.AspNet.Server.KestralTests/TestConnection.cs +++ b/test/Microsoft.AspNet.Server.KestralTests/TestConnection.cs @@ -1,4 +1,5 @@ using System; +using System.Diagnostics; using System.IO; using System.Net; using System.Net.Sockets; @@ -40,8 +41,9 @@ namespace Microsoft.AspNet.Server.KestralTests { var text = String.Join("\r\n", lines); var writer = new StreamWriter(_stream, Encoding.ASCII); - foreach (var ch in text) + for (var index = 0; index != text.Length; ++index) { + var ch = text[index]; await writer.WriteAsync(ch); await writer.FlushAsync(); await Task.Delay(TimeSpan.FromMilliseconds(5)); @@ -64,7 +66,10 @@ namespace Microsoft.AspNet.Server.KestralTests while (offset < expected.Length) { var task = _reader.ReadAsync(actual, offset, actual.Length - offset); -// Assert.True(task.Wait(1000), "timeout"); + if (!Debugger.IsAttached) + { + Assert.True(task.Wait(1000), "timeout"); + } var count = await task; if (count == 0) { diff --git a/test/Microsoft.AspNet.Server.KestralTests/TestServer.cs b/test/Microsoft.AspNet.Server.KestralTests/TestServer.cs new file mode 100644 index 0000000000..4291532317 --- /dev/null +++ b/test/Microsoft.AspNet.Server.KestralTests/TestServer.cs @@ -0,0 +1,34 @@ +using Microsoft.AspNet.Server.Kestrel; +using System; +using System.Threading.Tasks; + +namespace Microsoft.AspNet.Server.KestralTests +{ + /// + /// Summary description for TestServer + /// + public class TestServer : IDisposable + { + private KestrelEngine _engine; + private IDisposable _server; + + public TestServer(Func app) + { + Create(app); + } + + public void Create(Func app) + { + _engine = new KestrelEngine(); + _engine.Start(1); + _server = _engine.CreateServer(app); + + } + + public void Dispose() + { + _server.Dispose(); + _engine.Stop(); + } + } +} \ No newline at end of file