* Debug log exceptions in JsonInput deserializing

src/Microsoft.AspNet.Mvc.Formatters.Json/Internal/MvcJsonMvcOptionsSetup.cs

@@ -1,6 +1,7 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.OptionsModel;
 using Microsoft.Net.Http.Headers;
 using Newtonsoft.Json;
@@ -10,18 +11,23 @@ namespace Microsoft.AspNet.Mvc.Formatters.Json.Internal
 {
     public class MvcJsonMvcOptionsSetup : ConfigureOptions<MvcOptions>
     {
-        public MvcJsonMvcOptionsSetup(IOptions<MvcJsonOptions> jsonOptions)
+        public MvcJsonMvcOptionsSetup(ILoggerFactory loggerFactory, IOptions<MvcJsonOptions> jsonOptions)
-            : base((_) => ConfigureMvc(_, jsonOptions.Value.SerializerSettings))
+            : base((_) => ConfigureMvc(_, jsonOptions.Value.SerializerSettings, loggerFactory))
         {
         }
 
-        public static void ConfigureMvc(MvcOptions options, JsonSerializerSettings serializerSettings)
+        public static void ConfigureMvc(
+            MvcOptions options,
+            JsonSerializerSettings serializerSettings,
+            ILoggerFactory loggerFactory)
         {
+            var jsonInputLogger = loggerFactory.CreateLogger<JsonInputFormatter>();
+            var jsonInputPatchLogger = loggerFactory.CreateLogger<JsonPatchInputFormatter>();
+
             options.OutputFormatters.Add(new JsonOutputFormatter(serializerSettings));
-
+            options.InputFormatters.Add(new JsonInputFormatter(jsonInputLogger, serializerSettings));
-            options.InputFormatters.Add(new JsonInputFormatter(serializerSettings));
+            options.InputFormatters.Add(new JsonPatchInputFormatter(jsonInputPatchLogger, serializerSettings));
-            options.InputFormatters.Add(new JsonPatchInputFormatter(serializerSettings));
+            
-
             options.FormatterMappings.SetMediaTypeMappingForFormat("json", MediaTypeHeaderValue.Parse("application/json"));
 
             options.ValidationExcludeFilters.Add(typeof(JToken));

src/Microsoft.AspNet.Mvc.Formatters.Json/JsonInputFormatter.cs

@@ -2,12 +2,11 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
-using System.IO;
-using System.Text;
 using System.Threading.Tasks;
-using Microsoft.AspNet.Mvc.Infrastructure;
+using Microsoft.AspNet.Mvc.Formatters.Json.Logging;
 using Microsoft.AspNet.Mvc.Internal;
 using Microsoft.AspNet.Mvc.ModelBinding;
+using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
 
 namespace Microsoft.AspNet.Mvc.Formatters
@@ -15,19 +14,27 @@ namespace Microsoft.AspNet.Mvc.Formatters
     public class JsonInputFormatter : InputFormatter
     {
         private JsonSerializerSettings _serializerSettings;
+        private ILogger _logger;
 
-        public JsonInputFormatter()
+
-            : this(SerializerSettingsProvider.CreateSerializerSettings())
+        public JsonInputFormatter(ILogger logger)
+            : this(logger, SerializerSettingsProvider.CreateSerializerSettings())
         {
         }
 
-        public JsonInputFormatter(JsonSerializerSettings serializerSettings)
+        public JsonInputFormatter(ILogger logger, JsonSerializerSettings serializerSettings)
         {
             if (serializerSettings == null)
             {
                 throw new ArgumentNullException(nameof(serializerSettings));
             }
 
+            if (logger == null)
+            {
+                throw new ArgumentNullException(nameof(logger));
+            }
+
+            _logger = logger;
             _serializerSettings = serializerSettings;
 
             SupportedEncodings.Add(UTF8EncodingWithoutBOM);
@@ -107,6 +114,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
                         var metadata = GetPathMetadata(context.Metadata, eventArgs.ErrorContext.Path);
                         context.ModelState.TryAddModelError(key, eventArgs.ErrorContext.Error, metadata);
 
+                        _logger.JsonInputException(eventArgs.ErrorContext.Error);
+
                         // Error must always be marked as handled
                         // Failure to do so can cause the exception to be rethrown at every recursive level and
                         // overflow the stack for x64 CLR processes

src/Microsoft.AspNet.Mvc.Formatters.Json/JsonPatchInputFormatter.cs

@@ -6,19 +6,20 @@ using System.Reflection;
 using System.Threading.Tasks;
 using Microsoft.AspNet.JsonPatch;
 using Microsoft.AspNet.Mvc.Internal;
+using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
 
 namespace Microsoft.AspNet.Mvc.Formatters
 {
     public class JsonPatchInputFormatter : JsonInputFormatter
     {
-        public JsonPatchInputFormatter()
+        public JsonPatchInputFormatter(ILogger logger)
-            : this(SerializerSettingsProvider.CreateSerializerSettings())
+            : this(logger, SerializerSettingsProvider.CreateSerializerSettings())
         {
         }
 
-        public JsonPatchInputFormatter(JsonSerializerSettings serializerSettings)
+        public JsonPatchInputFormatter(ILogger logger, JsonSerializerSettings serializerSettings)
-            : base(serializerSettings)
+            : base(logger, serializerSettings)
         {
             // Clear all values and only include json-patch+json value.
             SupportedMediaTypes.Clear();

src/Microsoft.AspNet.Mvc.Formatters.Json/Logging/JsonInputFormatterLoggerExtensions.cs

@@ -0,0 +1,23 @@
+using System;
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.AspNet.Mvc.Formatters.Json.Logging
+{
+    internal static class JsonInputFormatterLoggerExtensions
+    {
+        private static readonly Action<ILogger, string, Exception> _jsonInputFormatterCrashed;
+
+        static JsonInputFormatterLoggerExtensions()
+        {
+            _jsonInputFormatterCrashed = LoggerMessage.Define<string>(
+                LogLevel.Verbose,
+                1,
+                "JSON input formatter threw an exception.");
+        }
+
+        public static void JsonInputException(this ILogger logger, Exception exception)
+        {
+            _jsonInputFormatterCrashed(logger, exception.ToString(), exception);
+        }
+    }
+}

test/Microsoft.AspNet.Mvc.Formatters.Json.Test/JsonInputFormatterTest.cs

@@ -9,6 +9,8 @@ using System.Text;
 using System.Threading.Tasks;
 using Microsoft.AspNet.Http;
 using Microsoft.AspNet.Mvc.ModelBinding;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Testing;
 using Moq;
 using Newtonsoft.Json;
 using Newtonsoft.Json.Serialization;
@@ -33,7 +35,9 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void CanRead_ReturnsTrueForAnySupportedContentType(string requestContentType, bool expectedCanRead)
         {
             // Arrange
-            var formatter = new JsonInputFormatter();
+            var loggerMock = GetLogger();
+
+            var formatter = new JsonInputFormatter(loggerMock);
             var contentBytes = Encoding.UTF8.GetBytes("content");
 
             var httpContext = GetHttpContext(contentBytes, contentType: requestContentType);
@@ -57,7 +61,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void DefaultMediaType_ReturnsApplicationJson()
         {
             // Arrange
-            var formatter = new JsonInputFormatter();
+            var loggerMock = GetLogger();
+            var formatter = new JsonInputFormatter(loggerMock);
 
             // Act
             var mediaType = formatter.SupportedMediaTypes[0];
@@ -82,7 +87,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public async Task JsonFormatterReadsSimpleTypes(string content, Type type, object expected)
         {
             // Arrange
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var httpContext = GetHttpContext(contentBytes);
@@ -108,7 +114,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         {
             // Arrange
             var content = "{name: 'Person Name', Age: '30'}";
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var httpContext = GetHttpContext(contentBytes);
@@ -136,7 +143,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         {
             // Arrange
             var content = "{name: 'Person Name', Age: 'not-an-age'}";
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var modelState = new ModelStateDictionary();
@@ -165,7 +173,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         {
             // Arrange
             var content = "[0, 23, 300]";
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var modelState = new ModelStateDictionary();
@@ -193,7 +202,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         {
             // Arrange
             var content = "[{name: 'Name One', Age: 30}, {name: 'Name Two', Small: 300}]";
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var modelState = new ModelStateDictionary();
@@ -222,7 +232,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         {
             // Arrange
             var content = "{name: 'Person Name', Age: 'not-an-age'}";
-            var formatter = new JsonInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonInputFormatter(logger);
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
             var modelState = new ModelStateDictionary();
@@ -254,8 +265,10 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void Creates_SerializerSettings_ByDefault()
         {
             // Arrange
+            var logger = GetLogger();
+
             // Act
-            var jsonFormatter = new JsonInputFormatter();
+            var jsonFormatter = new JsonInputFormatter(logger);
 
             // Assert
             Assert.NotNull(jsonFormatter.SerializerSettings);
@@ -265,9 +278,11 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void Constructor_UsesSerializerSettings()
         {
             // Arrange
+            var logger = GetLogger();
+
             // Act
             var serializerSettings = new JsonSerializerSettings();
-            var jsonFormatter = new JsonInputFormatter(serializerSettings);
+            var jsonFormatter = new JsonInputFormatter(logger, serializerSettings);
 
             // Assert
             Assert.Same(serializerSettings, jsonFormatter.SerializerSettings);
@@ -279,8 +294,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
             // Arrange
             // missing password property here
             var contentBytes = Encoding.UTF8.GetBytes("{ \"UserName\" : \"John\"}");
-
+            var logger = GetLogger();
-            var jsonFormatter = new JsonInputFormatter();
+            var jsonFormatter = new JsonInputFormatter(logger);
             // by default we ignore missing members, so here explicitly changing it
             jsonFormatter.SerializerSettings.MissingMemberHandling = MissingMemberHandling.Error;
 
@@ -312,8 +327,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
             // Arrange
             // missing password property here
             var contentBytes = Encoding.UTF8.GetBytes("{ \"UserName\" : \"John\"}");
-
+            var logger = GetLogger();
-            var jsonFormatter = new JsonInputFormatter();
+            var jsonFormatter = new JsonInputFormatter(logger);
             // by default we ignore missing members, so here explicitly changing it
             jsonFormatter.SerializerSettings = new JsonSerializerSettings()
             {
@@ -342,6 +357,11 @@ namespace Microsoft.AspNet.Mvc.Formatters
             Assert.Contains("Required property 'Password' not found in JSON", modelErrorMessage);
         }
 
+        private static ILogger GetLogger()
+        {
+            return NullLogger.Instance;
+        }
+
         private static HttpContext GetHttpContext(
             byte[] contentBytes,
             string contentType = "application/json")

test/Microsoft.AspNet.Mvc.Formatters.Json.Test/JsonOutputFormatterTests.cs

@@ -12,6 +12,8 @@ using Microsoft.AspNet.Mvc.Abstractions;
 using Microsoft.AspNet.Mvc.Internal;
 using Microsoft.AspNet.Routing;
 using Microsoft.AspNet.Testing;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Testing;
 using Microsoft.Net.Http.Headers;
 using Moq;
 using Newtonsoft.Json;
@@ -40,7 +42,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
             // Arrange
             // Act
             var serializerSettings = new JsonSerializerSettings();
-            var jsonFormatter = new JsonInputFormatter(serializerSettings);
+            var logger = GetLogger();
+            var jsonFormatter = new JsonInputFormatter(logger, serializerSettings);
 
             // Assert
             Assert.Same(serializerSettings, jsonFormatter.SerializerSettings);
@@ -290,6 +293,11 @@ namespace Microsoft.AspNet.Mvc.Formatters
             return encoding;
         }
 
+        private static ILogger GetLogger()
+        {
+            return NullLogger.Instance;
+        }
+
         private static OutputFormatterWriteContext GetOutputFormatterContext(
             object outputValue,
             Type outputType,

test/Microsoft.AspNet.Mvc.Formatters.Json.Test/JsonPatchInputFormatterTest.cs

@@ -8,6 +8,8 @@ using System.Threading.Tasks;
 using Microsoft.AspNet.Http;
 using Microsoft.AspNet.JsonPatch;
 using Microsoft.AspNet.Mvc.ModelBinding;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Testing;
 using Moq;
 using Xunit;
 
@@ -19,7 +21,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public async Task JsonPatchInputFormatter_ReadsOneOperation_Successfully()
         {
             // Arrange
-            var formatter = new JsonPatchInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonPatchInputFormatter(logger);
             var content = "[{\"op\":\"add\",\"path\":\"Customer/Name\",\"value\":\"John\"}]";
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
@@ -49,7 +52,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public async Task JsonPatchInputFormatter_ReadsMultipleOperations_Successfully()
         {
             // Arrange
-            var formatter = new JsonPatchInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonPatchInputFormatter(logger);
             var content = "[{\"op\": \"add\", \"path\" : \"Customer/Name\", \"value\":\"John\"}," +
                 "{\"op\": \"remove\", \"path\" : \"Customer/Name\"}]";
             var contentBytes = Encoding.UTF8.GetBytes(content);
@@ -86,7 +90,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void CanRead_ReturnsTrueOnlyForJsonPatchContentType(string requestContentType, bool expectedCanRead)
         {
             // Arrange
-            var formatter = new JsonPatchInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonPatchInputFormatter(logger);
             var content = "[{\"op\": \"add\", \"path\" : \"Customer/Name\", \"value\":\"John\"}]";
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
@@ -114,7 +119,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
         public void CanRead_ReturnsFalse_NonJsonPatchContentType(Type modelType)
         {
             // Arrange
-            var formatter = new JsonPatchInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonPatchInputFormatter(logger);
             var content = "[{\"op\": \"add\", \"path\" : \"Customer/Name\", \"value\":\"John\"}]";
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
@@ -143,7 +149,8 @@ namespace Microsoft.AspNet.Mvc.Formatters
             var exceptionMessage = "Cannot deserialize the current JSON array (e.g. [1,2,3]) into type " +
                 $"'{typeof(Customer).FullName}' because the type requires a JSON object ";
 
-            var formatter = new JsonPatchInputFormatter();
+            var logger = GetLogger();
+            var formatter = new JsonPatchInputFormatter(logger);
             var content = "[{\"op\": \"add\", \"path\" : \"Customer/Name\", \"value\":\"John\"}]";
             var contentBytes = Encoding.UTF8.GetBytes(content);
 
@@ -166,6 +173,11 @@ namespace Microsoft.AspNet.Mvc.Formatters
             Assert.Contains(exceptionMessage, modelState[""].Errors[0].Exception.Message);
         }
 
+        private static ILogger GetLogger()
+        {
+            return NullLogger.Instance;
+        }
+
         private static HttpContext GetHttpContext(
             byte[] contentBytes,
             string contentType = "application/json-patch+json")

test/Microsoft.AspNet.Mvc.IntegrationTests/ModelBindingTestHelper.cs

@@ -10,6 +10,7 @@ using Microsoft.AspNet.Mvc.ModelBinding;
 using Microsoft.AspNet.Mvc.ModelBinding.Validation;
 using Microsoft.AspNet.Routing;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.OptionsModel;
 
 namespace Microsoft.AspNet.Mvc.IntegrationTests
@@ -70,6 +71,7 @@ namespace Microsoft.AspNet.Mvc.IntegrationTests
 
             var serviceCollection = new ServiceCollection();
             serviceCollection.AddMvc();
+            serviceCollection.AddTransient<ILoggerFactory, LoggerFactory>();
 
             if (updateOptions != null)
             {

test/Microsoft.AspNet.Mvc.IntegrationTests/TestMvcOptions.cs

@@ -5,6 +5,7 @@ using Microsoft.AspNet.Mvc.DataAnnotations.Internal;
 using Microsoft.AspNet.Mvc.Formatters.Json.Internal;
 using Microsoft.AspNet.Mvc.Internal;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.OptionsModel;
 
 namespace Microsoft.AspNet.Mvc.IntegrationTests
@@ -19,7 +20,11 @@ namespace Microsoft.AspNet.Mvc.IntegrationTests
             MvcDataAnnotationsMvcOptionsSetup.ConfigureMvc(
                 Value,
                 collection.BuildServiceProvider());
-            MvcJsonMvcOptionsSetup.ConfigureMvc(Value, SerializerSettingsProvider.CreateSerializerSettings());
+
+            var loggerFactory = new LoggerFactory();
+            var serializerSettings = SerializerSettingsProvider.CreateSerializerSettings();
+
+            MvcJsonMvcOptionsSetup.ConfigureMvc(Value, serializerSettings, loggerFactory);
         }
 
         public MvcOptions Value { get; }

test/Microsoft.AspNet.Mvc.Test/MvcOptionsSetupTest.cs

@@ -18,6 +18,7 @@ using Microsoft.Extensions.OptionsModel;
 using Moq;
 using Newtonsoft.Json.Linq;
 using Xunit;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNet.Mvc
 {
@@ -191,7 +192,10 @@ namespace Microsoft.AspNet.Mvc
         public void Setup_JsonFormattersUseSerializerSettings()
         {
             // Arrange
-            var services = GetServiceProvider();
+            var services = GetServiceProvider(s =>
+            {
+                s.AddTransient<ILoggerFactory, LoggerFactory>();
+            });
 
             // Act
             var options = services.GetRequiredService<IOptions<MvcOptions>>().Value;
@@ -222,7 +226,7 @@ namespace Microsoft.AspNet.Mvc
         {
             var serviceCollection = new ServiceCollection();
             serviceCollection.AddMvc();
-
+            serviceCollection.AddTransient<ILoggerFactory, LoggerFactory>();
             if (action != null)
             {
                 action(serviceCollection);

test/WebSites/ApiExplorerWebSite/Startup.cs

@@ -2,9 +2,9 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using Microsoft.AspNet.Builder;
-using Microsoft.AspNet.Mvc;
 using Microsoft.AspNet.Mvc.Formatters;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 
 namespace ApiExplorerWebSite
 {
@@ -13,6 +13,7 @@ namespace ApiExplorerWebSite
         // Set up application services
         public void ConfigureServices(IServiceCollection services)
         {
+            services.AddTransient<ILoggerFactory, LoggerFactory>();
             services.AddMvc(options =>
             {
                 options.Filters.AddService(typeof(ApiExplorerDataFilter));

test/WebSites/BasicWebSite/Controllers/SpecificFormattersController.cs

@@ -5,6 +5,8 @@ using System;
 using Microsoft.AspNet.Mvc;
 using Microsoft.AspNet.Mvc.Filters;
 using Microsoft.AspNet.Mvc.Formatters;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
 using Newtonsoft.Json.Serialization;
 
@@ -61,8 +63,9 @@ namespace BasicWebSite
                 // Instead remove and add new formatters which only effects the controllers this
                 // attribute is decorated on.
                 context.InputFormatters.RemoveType<JsonInputFormatter>();
-                context.InputFormatters.Add(new JsonInputFormatter(_serializerSettings));
+                var loggerFactory = context.HttpContext.RequestServices.GetRequiredService<ILoggerFactory>();
-                
+                var logger = loggerFactory.CreateLogger<JsonInputFormatter>();
+                context.InputFormatters.Add(new JsonInputFormatter(logger ,_serializerSettings));
             }
 
             public void OnResultExecuted(ResultExecutedContext context)

test/WebSites/BasicWebSite/Startup.cs

@@ -16,7 +16,7 @@ namespace BasicWebSite
             {
                 options.Conventions.Add(new ApplicationDescription("This is a basic website."));
             });
-
+            services.AddLogging();
             services.AddSingleton<IActionDescriptorProvider, ActionDescriptorCreationCounter>();
         }