Fixing a header parsing bug

When request header data arrives with \r\n split across packets

src/Microsoft.AspNet.Server.Kestrel/Http/Frame.cs

@@ -614,9 +614,9 @@ namespace Microsoft.AspNet.Server.Kestrel.Http
                         chFirst = scan.Take(); // expecting: /r
                         chSecond = scan.Take(); // expecting: /n
 
-                        if (chSecond == '\r')
+                        if (chSecond != '\n')
                         {
-                            // special case, "\r\r". move to the 2nd "\r" and try again
+                            // "\r" was all by itself, move just after it and try again 
                             scan = endValue;
                             scan.Take();
                             continue;
@@ -633,6 +633,9 @@ namespace Microsoft.AspNet.Server.Kestrel.Http
                         }
 
                         var name = beginName.GetArraySegment(endName);
+#if DEBUG
+                        var nameString = beginName.GetString(endName);
+#endif
                         var value = beginValue.GetString(endValue);
                         if (wrapping)
                         {

src/Microsoft.AspNet.Server.Kestrel/Http/Listener.cs

@@ -13,7 +13,8 @@ namespace Microsoft.AspNet.Server.Kestrel.Http
     /// </summary>
     public abstract class Listener : ListenerContext, IDisposable
     {
-        protected Listener(ServiceContext serviceContext) : base(serviceContext)
+        protected Listener(ServiceContext serviceContext) 
+            : base(serviceContext)
         {
             Memory2 = new MemoryPool2();
         }

src/Microsoft.AspNet.Server.Kestrel/Http/ListenerContext.cs

@@ -7,17 +7,19 @@ using Microsoft.AspNet.Server.Kestrel.Infrastructure;
 
 namespace Microsoft.AspNet.Server.Kestrel.Http
 {
-    public class ListenerContext
+    public class ListenerContext : ServiceContext
     {
-        public ListenerContext() { }
+        public ListenerContext()
-
+        {
-        public ListenerContext(ServiceContext serviceContext)
+        }
+
+        public ListenerContext(ServiceContext serviceContext) 
+            : base(serviceContext)
         {
-            Memory = serviceContext.Memory;
-            Log = serviceContext.Log;
         }
 
         public ListenerContext(ListenerContext listenerContext)
+            : base(listenerContext)
         {
             Thread = listenerContext.Thread;
             Application = listenerContext.Application;
@@ -30,10 +32,6 @@ namespace Microsoft.AspNet.Server.Kestrel.Http
 
         public Func<Frame, Task> Application { get; set; }
 
-        public IMemoryPool Memory { get; set; }
-
         public MemoryPool2 Memory2 { get; set; }
-
-        public IKestrelTrace Log { get; }
     }
-}
+}

src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelThread.cs

@@ -33,11 +33,11 @@ namespace Microsoft.AspNet.Server.Kestrel
         private ExceptionDispatchInfo _closeError;
         private IKestrelTrace _log;
 
-        public KestrelThread(KestrelEngine engine, ServiceContext serviceContext)
+        public KestrelThread(KestrelEngine engine)
         {
             _engine = engine;
-            _appShutdown = serviceContext.AppShutdown;
+            _appShutdown = engine.AppShutdown;
-            _log = serviceContext.Log;
+            _log = engine.Log;
             _loop = new UvLoopHandle(_log);
             _post = new UvAsyncHandle(_log);
             _thread = new Thread(ThreadStart);

src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs

@@ -12,87 +12,87 @@ namespace Microsoft.AspNet.Server.Kestrel
     /// </summary>
     public class KestrelTrace : IKestrelTrace
     {
-        private readonly ILogger _logger;
+        protected readonly ILogger _logger;
 
         public KestrelTrace(ILogger logger)
         {
             _logger = logger;
         }
 
-        public void ConnectionStart(long connectionId)
+        public virtual void ConnectionStart(long connectionId)
         {
             _logger.LogDebug(1, @"Connection id ""{ConnectionId}"" started.", connectionId);
         }
 
-        public void ConnectionStop(long connectionId)
+        public virtual void ConnectionStop(long connectionId)
         {
             _logger.LogDebug(2, @"Connection id ""{ConnectionId}"" stopped.", connectionId);
         }
 
-        public void ConnectionRead(long connectionId, int count)
+        public virtual void ConnectionRead(long connectionId, int count)
         {
             // Don't log for now since this could be *too* verbose.
             // Reserved: Event ID 3
         }
 
-        public void ConnectionPause(long connectionId)
+        public virtual void ConnectionPause(long connectionId)
         {
             _logger.LogDebug(4, @"Connection id ""{ConnectionId}"" paused.", connectionId);
         }
 
-        public void ConnectionResume(long connectionId)
+        public virtual void ConnectionResume(long connectionId)
         {
             _logger.LogDebug(5, @"Connection id ""{ConnectionId}"" resumed.", connectionId);
         }
 
-        public void ConnectionReadFin(long connectionId)
+        public virtual void ConnectionReadFin(long connectionId)
         {
             _logger.LogDebug(6, @"Connection id ""{ConnectionId}"" received FIN.", connectionId);
         }
 
-        public void ConnectionWriteFin(long connectionId)
+        public virtual void ConnectionWriteFin(long connectionId)
         {
             _logger.LogDebug(7, @"Connection id ""{ConnectionId}"" sending FIN.", connectionId);
         }
 
-        public void ConnectionWroteFin(long connectionId, int status)
+        public virtual void ConnectionWroteFin(long connectionId, int status)
         {
             _logger.LogDebug(8, @"Connection id ""{ConnectionId}"" sent FIN with status ""{Status}"".", connectionId, status);
         }
 
-        public void ConnectionKeepAlive(long connectionId)
+        public virtual void ConnectionKeepAlive(long connectionId)
         {
             _logger.LogDebug(9, @"Connection id ""{ConnectionId}"" completed keep alive response.", connectionId);
         }
 
-        public void ConnectionDisconnect(long connectionId)
+        public virtual void ConnectionDisconnect(long connectionId)
         {
             _logger.LogDebug(10, @"Connection id ""{ConnectionId}"" disconnected.", connectionId);
         }
 
-        public void ConnectionWrite(long connectionId, int count)
+        public virtual void ConnectionWrite(long connectionId, int count)
         {
             // Don't log for now since this could be *too* verbose.
             // Reserved: Event ID 11
         }
 
-        public void ConnectionWriteCallback(long connectionId, int status)
+        public virtual void ConnectionWriteCallback(long connectionId, int status)
         {
             // Don't log for now since this could be *too* verbose.
             // Reserved: Event ID 12
         }
 
-        public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func<object, Exception, string> formatter)
+        public virtual void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func<object, Exception, string> formatter)
         {
             _logger.Log(logLevel, eventId, state, exception, formatter);
         }
 
-        public bool IsEnabled(LogLevel logLevel)
+        public virtual bool IsEnabled(LogLevel logLevel)
         {
             return _logger.IsEnabled(logLevel);
         }
 
-        public IDisposable BeginScopeImpl(object state)
+        public virtual IDisposable BeginScopeImpl(object state)
         {
             return _logger.BeginScopeImpl(state);
         }

src/Microsoft.AspNet.Server.Kestrel/KestrelEngine.cs

@@ -13,12 +13,10 @@ using Microsoft.Framework.Logging;
 
 namespace Microsoft.AspNet.Server.Kestrel
 {
-    public class KestrelEngine : IDisposable
+    public class KestrelEngine : ServiceContext, IDisposable
     {
-        private readonly ServiceContext _serviceContext;
+        public KestrelEngine(ILibraryManager libraryManager, ServiceContext context)
-
+            : this(context)
-        public KestrelEngine(ILibraryManager libraryManager, IApplicationShutdown appShutdownService, ILogger logger)
-            : this(appShutdownService, logger)
         {
             Libuv = new Libuv();
 
@@ -63,21 +61,15 @@ namespace Microsoft.AspNet.Server.Kestrel
         }
 
         // For testing
-        internal KestrelEngine(Libuv uv, IApplicationShutdown appShutdownService, ILogger logger)
+        internal KestrelEngine(Libuv uv, ServiceContext context)
-           : this(appShutdownService, logger)
+           : this(context)
         {
             Libuv = uv;
         }
 
-        private KestrelEngine(IApplicationShutdown appShutdownService, ILogger logger)
+        private KestrelEngine(ServiceContext context)
+            : base(context)
         {
-            _serviceContext = new ServiceContext
-            {
-                AppShutdown = appShutdownService,
-                Memory = new MemoryPool(),
-                Log = new KestrelTrace(logger)
-            };
-
             Threads = new List<KestrelThread>();
         }
 
@@ -88,7 +80,7 @@ namespace Microsoft.AspNet.Server.Kestrel
         {
             for (var index = 0; index != count; ++index)
             {
-                Threads.Add(new KestrelThread(this, _serviceContext));
+                Threads.Add(new KestrelThread(this));
             }
 
             foreach (var thread in Threads)
@@ -128,16 +120,16 @@ namespace Microsoft.AspNet.Server.Kestrel
                     if (single)
                     {
                         var listener = usingPipes ? 
-                            (Listener) new PipeListener(_serviceContext) : 
+                            (Listener) new PipeListener(this) : 
-                            new TcpListener(_serviceContext);
+                            new TcpListener(this);
                         listeners.Add(listener);
                         listener.StartAsync(scheme, host, port, thread, application).Wait();
                     }
                     else if (first)
                     {
                         var listener = usingPipes
-                            ? (ListenerPrimary) new PipeListenerPrimary(_serviceContext)
+                            ? (ListenerPrimary) new PipeListenerPrimary(this)
-                            : new TcpListenerPrimary(_serviceContext);
+                            : new TcpListenerPrimary(this);
 
                         listeners.Add(listener);
                         listener.StartAsync(pipeName, scheme, host, port, thread, application).Wait();
@@ -145,8 +137,8 @@ namespace Microsoft.AspNet.Server.Kestrel
                     else
                     {
                         var listener = usingPipes
-                            ? (ListenerSecondary) new PipeListenerSecondary(_serviceContext)
+                            ? (ListenerSecondary) new PipeListenerSecondary(this)
-                            : new TcpListenerSecondary(_serviceContext);
+                            : new TcpListenerSecondary(this);
                         listeners.Add(listener);
                         listener.StartAsync(pipeName, thread, application).Wait();
                     }

src/Microsoft.AspNet.Server.Kestrel/ServerFactory.cs

@@ -53,14 +53,14 @@ namespace Microsoft.AspNet.Server.Kestrel
             try
             {
                 var information = (KestrelServerInformation)serverFeatures.Get<IKestrelServerInformation>();
-                var engine = new KestrelEngine(_libraryManager, _appShutdownService, _logger);
+                var engine = new KestrelEngine(_libraryManager, new ServiceContext { AppShutdown = _appShutdownService, Log = new KestrelTrace(_logger) });
 
                 disposables.Push(engine);
 
                 if (information.ThreadCount < 0)
                 {
-                    throw new ArgumentOutOfRangeException(nameof(information.ThreadCount), 
+                    throw new ArgumentOutOfRangeException(nameof(information.ThreadCount),
-                        information.ThreadCount, 
+                        information.ThreadCount,
                         "ThreadCount cannot be negative");
                 }
 

src/Microsoft.AspNet.Server.Kestrel/ServiceContext.cs

@@ -9,6 +9,18 @@ namespace Microsoft.AspNet.Server.Kestrel
 {
     public class ServiceContext
     {
+        public ServiceContext()
+        {
+            Memory = new MemoryPool();
+        }
+
+        public ServiceContext(ServiceContext context)
+        {
+            AppShutdown = context.AppShutdown;
+            Memory = context.Memory;
+            Log = context.Log;
+        }
+
         public IApplicationShutdown AppShutdown { get; set; }
 
         public IMemoryPool Memory { get; set; }

test/Microsoft.AspNet.Server.KestrelTests/EngineTests.cs

@@ -61,19 +61,20 @@ namespace Microsoft.AspNet.Server.KestrelTests
 
         private async Task AppChunked(Frame frame)
         {
+            Console.WriteLine($"----");
+            Console.WriteLine($"{frame.Method} {frame.RequestUri} {frame.HttpVersion}");
             foreach (var h in frame.RequestHeaders)
             {
                 Console.WriteLine($"{h.Key}: {h.Value}");
             }
             Console.WriteLine($"");
 
-            frame.ResponseHeaders.Clear();
             var data = new MemoryStream();
-            while(true)
+            await frame.RequestBody.CopyToAsync(data);
-            {
-                await frame.RequestBody.CopyToAsync(data);
-            }
             var bytes = data.ToArray();
+            Console.WriteLine($"{Encoding.ASCII.GetString(bytes)}");
+
+            frame.ResponseHeaders.Clear();
             frame.ResponseHeaders["Content-Length"] = new[] { bytes.Length.ToString() };
             await frame.ResponseBody.WriteAsync(bytes, 0, bytes.Length);
         }
@@ -87,7 +88,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
         [Fact]
         public void EngineCanStartAndStop()
         {
-            var engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            var engine = new KestrelEngine(LibraryManager, new TestServiceContext());
             engine.Start(1);
             engine.Dispose();
         }
@@ -95,7 +96,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
         [Fact]
         public void ListenerCanCreateAndDispose()
         {
-            var engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            var engine = new KestrelEngine(LibraryManager, new TestServiceContext());
             engine.Start(1);
             var started = engine.CreateServer("http", "localhost", 54321, App);
             started.Dispose();
@@ -106,7 +107,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
         [Fact]
         public void ConnectionCanReadAndWrite()
         {
-            var engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            var engine = new KestrelEngine(LibraryManager, new TestServiceContext());
             engine.Start(1);
             var started = engine.CreateServer("http", "localhost", 54321, App);
 

test/Microsoft.AspNet.Server.KestrelTests/MultipleLoopTests.cs

@@ -15,11 +15,12 @@ namespace Microsoft.AspNet.Server.KestrelTests
     public class MultipleLoopTests
     {
         private readonly Libuv _uv;
-        private readonly IKestrelTrace _logger = new KestrelTrace(new TestLogger());
+        private readonly IKestrelTrace _logger;
         public MultipleLoopTests()
         {
-            var engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            var engine = new KestrelEngine(LibraryManager, new TestServiceContext());
             _uv = engine.Libuv;
+            _logger = engine.Log;
         }
 
         ILibraryManager LibraryManager
@@ -81,7 +82,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
                     return;
                 }
 
-                var writeRequest = new UvWriteReq(new KestrelTrace(new TestLogger()));
+                var writeRequest = new UvWriteReq(new KestrelTrace(new TestKestrelTrace()));
                 writeRequest.Init(loop);
                 writeRequest.Write(
                     serverConnectionPipe,
@@ -100,7 +101,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
             {
                 var loop2 = new UvLoopHandle(_logger);
                 var clientConnectionPipe = new UvPipeHandle(_logger);
-                var connect = new UvConnectRequest(new KestrelTrace(new TestLogger()));
+                var connect = new UvConnectRequest(new KestrelTrace(new TestKestrelTrace()));
 
                 loop2.Init(_uv);
                 clientConnectionPipe.Init(loop2, true);
@@ -174,7 +175,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
 
                 serverConnectionPipeAcceptedEvent.WaitOne();
 
-                var writeRequest = new UvWriteReq(new KestrelTrace(new TestLogger()));
+                var writeRequest = new UvWriteReq(new KestrelTrace(new TestKestrelTrace()));
                 writeRequest.Init(loop);
                 writeRequest.Write2(
                     serverConnectionPipe,
@@ -196,7 +197,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
             {
                 var loop2 = new UvLoopHandle(_logger);
                 var clientConnectionPipe = new UvPipeHandle(_logger);
-                var connect = new UvConnectRequest(new KestrelTrace(new TestLogger()));
+                var connect = new UvConnectRequest(new KestrelTrace(new TestKestrelTrace()));
 
                 loop2.Init(_uv);
                 clientConnectionPipe.Init(loop2, true);

test/Microsoft.AspNet.Server.KestrelTests/NetworkingTests.cs

@@ -21,11 +21,12 @@ namespace Microsoft.AspNet.Server.KestrelTests
     public class NetworkingTests
     {
         private readonly Libuv _uv;
-        private readonly IKestrelTrace _logger = new KestrelTrace(new TestLogger());
+        private readonly IKestrelTrace _logger;
         public NetworkingTests()
         {
-            var engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            var engine = new KestrelEngine(LibraryManager, new TestServiceContext());
             _uv = engine.Libuv;
+            _logger = engine.Log;
         }
 
         ILibraryManager LibraryManager
@@ -208,7 +209,7 @@ namespace Microsoft.AspNet.Server.KestrelTests
                         {
                             for (var x = 0; x != 2; ++x)
                             {
-                                var req = new UvWriteReq(new KestrelTrace(new TestLogger()));
+                                var req = new UvWriteReq(new KestrelTrace(new TestKestrelTrace()));
                                 req.Init(loop);
                                 req.Write(
                                     tcp2,

test/Microsoft.AspNet.Server.KestrelTests/SocketOutputTests.cs

@@ -32,13 +32,13 @@ namespace Microsoft.AspNet.Server.KestrelTests
                 }
             };
 
-            using (var kestrelEngine = new KestrelEngine(mockLibuv, new ShutdownNotImplemented(), new TestLogger()))
+            using (var kestrelEngine = new KestrelEngine(mockLibuv, new TestServiceContext()))
             {
                 kestrelEngine.Start(count: 1);
 
                 var kestrelThread = kestrelEngine.Threads[0];
-                var socket = new MockSocket(kestrelThread.Loop.ThreadId, new KestrelTrace(new TestLogger()));
+                var socket = new MockSocket(kestrelThread.Loop.ThreadId, new KestrelTrace(new TestKestrelTrace()));
-                var trace = new KestrelTrace(new TestLogger());
+                var trace = new KestrelTrace(new TestKestrelTrace());
                 var socketOutput = new SocketOutput(kestrelThread, socket, 0, trace);
 
                 // I doubt _maxBytesPreCompleted will ever be over a MB. If it is, we should change this test.
@@ -77,13 +77,13 @@ namespace Microsoft.AspNet.Server.KestrelTests
                 }
             };
 
-            using (var kestrelEngine = new KestrelEngine(mockLibuv, new ShutdownNotImplemented(), new TestLogger()))
+            using (var kestrelEngine = new KestrelEngine(mockLibuv, new TestServiceContext()))
             {
                 kestrelEngine.Start(count: 1);
 
                 var kestrelThread = kestrelEngine.Threads[0];
-                var socket = new MockSocket(kestrelThread.Loop.ThreadId, new KestrelTrace(new TestLogger()));
+                var socket = new MockSocket(kestrelThread.Loop.ThreadId, new KestrelTrace(new TestKestrelTrace()));
-                var trace = new KestrelTrace(new TestLogger());
+                var trace = new KestrelTrace(new TestKestrelTrace());
                 var socketOutput = new SocketOutput(kestrelThread, socket, 0, trace);
 
                 var bufferSize = maxBytesPreCompleted;

test/Microsoft.AspNet.Server.KestrelTests/TestLogger.cs

@@ -4,20 +4,44 @@ using Microsoft.Framework.Logging;
 
 namespace Microsoft.AspNet.Server.KestrelTests
 {
-    public class TestLogger : ILogger
+    public class TestKestrelTrace : KestrelTrace
     {
-        public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func<object, Exception, string> formatter)
+        public TestKestrelTrace() : base(new TestLogger())
         {
+
         }
 
-        public bool IsEnabled(LogLevel logLevel)
+        public override void ConnectionRead(long connectionId, int count)
         {
-            return false;
+            _logger.LogDebug(1, @"Connection id ""{ConnectionId}"" recv {count} bytes.", connectionId, count);
         }
 
-        public IDisposable BeginScopeImpl(object state)
+        public override void ConnectionWrite(long connectionId, int count)
         {
-            return new Disposable(() => { });
+            _logger.LogDebug(1, @"Connection id ""{ConnectionId}"" send {count} bytes.", connectionId, count);
+        }
+
+        public override void ConnectionWriteCallback(long connectionId, int status)
+        {
+            _logger.LogDebug(1, @"Connection id ""{ConnectionId}"" send finished with status {status}.", connectionId, status);
+        }
+
+        public class TestLogger : ILogger
+        {
+            public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func<object, Exception, string> formatter)
+            {
+                Console.WriteLine($"Log {logLevel}[{eventId}]: {formatter(state, exception)} {exception?.Message}");
+            }
+
+            public bool IsEnabled(LogLevel logLevel)
+            {
+                return true;
+            }
+
+            public IDisposable BeginScopeImpl(object state)
+            {
+                return new Disposable(() => { });
+            }
         }
     }
 }

test/Microsoft.AspNet.Server.KestrelTests/TestServer.cs

@@ -27,25 +27,29 @@ namespace Microsoft.AspNet.Server.KestrelTests
         {
             get
             {
-                try{
+                try
+                {
                     var locator = CallContextServiceLocator.Locator;
-                    if (locator == null) 
+                    if (locator == null)
                     {
                         return null;
                     }
                     var services = locator.ServiceProvider;
-                    if (services == null) 
+                    if (services == null)
                     {
                         return null;
                     }
                     return (ILibraryManager)services.GetService(typeof(ILibraryManager));
-                } catch (NullReferenceException) { return null; }
+                }
+                catch (NullReferenceException) { return null; }
             }
         }
 
         public void Create(Func<Frame, Task> app)
         {
-            _engine = new KestrelEngine(LibraryManager, new ShutdownNotImplemented(), new TestLogger());
+            _engine = new KestrelEngine(
+                LibraryManager, 
+                new TestServiceContext());
             _engine.Start(1);
             _server = _engine.CreateServer(
                 "http",

test/Microsoft.AspNet.Server.KestrelTests/TestServiceContext.cs

@@ -0,0 +1,13 @@
+using Microsoft.AspNet.Server.Kestrel;
+
+namespace Microsoft.AspNet.Server.KestrelTests
+{
+    public class TestServiceContext : ServiceContext
+    {
+        public TestServiceContext()
+        {
+            AppShutdown = new ShutdownNotImplemented();
+            Log = new TestKestrelTrace();
+        }
+    }
+}