Skip to content
This repository was archived by the owner on Dec 19, 2018. It is now read-only.
This repository was archived by the owner on Dec 19, 2018. It is now read-only.

Log entry "Request finished in xx ms" displays a 200 status code when an exception happened #763

@nulltoken

Description

@nulltoken
dotnet --version
1.0.0-preview1-002702

Patching the sample ValuesController as follows

    [Route("api/[controller]")]
    public class ValuesController : Controller
    {
        // GET api/values
        [HttpGet]
        public IEnumerable<string> Get()
        {
            throw new ArgumentException("d");
            return new string[] { "value1", "value2" };
        }
[...]

and issueing two simple api calls generates the following log entries

PS C:\Users\em\Documents\Visual Studio 2015\Projects\WebApplication2\src\WebApplication2> dotnet run
Project WebApplication2 (.NETCoreApp,Version=v1.0) was previously compiled. Skipping compilation.
Hosting environment: Production
Content root path: C:\Users\em\Documents\Visual Studio 2015\Projects\WebApplication2\src\WebApplication2
Now listening on: http://localhost:5000
Application started. Press Ctrl+C to shut down.
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://localhost:5000/api/values/177
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method WebApplication2.Controllers.ValuesController.Get (WebApplication2) with arguments (177) - ModelState is Valid'
info: Microsoft.AspNetCore.Mvc.Internal.ObjectResultExecutor[1]
      Executing ObjectResult, writing value Microsoft.AspNetCore.Mvc.ControllerContext.
info: Microsoft.AspNetCore.Mvc.Internal.MvcRouteHandler[2]
      Executed action WebApplication2.Controllers.ValuesController.Get (WebApplication2) in 241.3732ms
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 529.7303ms 200 text/plain; charset=utf-8
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://localhost:5000/api/values/
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method WebApplication2.Controllers.ValuesController.Get (WebApplication2) with arguments () - ModelState is Valid'
fail: Microsoft.AspNetCore.Server.Kestrel, Version=1.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60[13]
      Connection id "0HKS2EAGK2HQR": An unhandled exception was thrown by the application.
System.ArgumentException: d
   at WebApplication2.Controllers.ValuesController.Get() in C:\Users\em\Documents\Visual Studio 2015\Projects\WebApplication2\src\WebApplication2\Controllers\ValuesController.cs:line 16
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.FilterActionInvoker.<InvokeActionFilterAsync>d__41.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Internal.FilterActionInvoker.<InvokeAsync>d__32.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.MvcRouteHandler.<InvokeActionAsync>d__8.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Server.Kestrel.Http.Frame`1.<RequestProcessingAsync>d__2.MoveNext()
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 18.6067ms 200

/api/values/177 logs Request finished in 529.7303ms 200 text/plain; charset=utf-8

whereas

/api/values logs Request finished in 18.6067ms **200**

I believe this last one should rather display a 500.

Metadata

Metadata

Assignees

Labels

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions