【问题标题】:JsonValueProviderFactory: System.ArgumentException: An item with the same key has already been addedJsonValueProviderFactory:System.ArgumentException:已添加具有相同键的项
【发布时间】:2021-05-14 21:12:21
【问题描述】:

我有一个 Shopify 的 webhook api 处理程序,它使用 json 主体调用以下控制器操作。它立即失败,因为除了 OnException 方法中的日志之外,没有任何 log4net 日志被访问和记录,并出现以下错误。

问题 1:

Elmah 日志中的堆栈跟踪没有帮助,因为它没有深入到足以显示代码中的哪一行引发了错误。为什么是这样?我注意到async 错误...他们似乎更难确定代码中的根本原因行。也许我现在应该让它成为一个同步方法?也许我应该摆脱 OnException 方法,因为它可能会掩盖更多信息?

问题 2:

在执行任何代码之前点击控制器操作可能会立即导致此错误?此控制器继承了 asp.net mvc Controller,构造函数中的唯一代码是创建 DBContextlog4net _logger 的实例。

堆栈跟踪:

Controllers.ShopWebhooksController.OnException(C:\inetpub\wwwroot\Controllers\ShopWebhooksController.cs:44)
System.ArgumentException: An item with the same key has already been added.
       at System.ThrowHelper.ThrowArgumentException(ExceptionResource resource)
       at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.AddToBackingStore(EntryLimitedDictionary backingStore, String prefix, Object value)
       at System.Web.Mvc.JsonValueProviderFactory.GetValueProvider(ControllerContext controllerContext)
       at System.Web.Mvc.ValueProviderFactoryCollection.GetValueProvider(ControllerContext controllerContext)
       at System.Web.Mvc.ControllerBase.get_ValueProvider()
       at System.Web.Mvc.ControllerActionInvoker.GetParameterValue(ControllerContext controllerContext, ParameterDescriptor parameterDescriptor)
       at System.Web.Mvc.ControllerActionInvoker.GetParameterValues(ControllerContext controllerContext, ActionDescriptor actionDescriptor)
       at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_1.<BeginInvokeAction>b__0(AsyncCallback asyncCallback, Object asyncState)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)
       at System.Web.Mvc.Async.AsyncControllerActionInvoker.BeginInvokeAction(ControllerContext controllerContext, String actionName, AsyncCallback callback, Object state)
       at System.Web.Mvc.Controller.<>c.<BeginExecuteCore>b__152_0(AsyncCallback asyncCallback, Object asyncState, ExecuteCoreState innerState)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallBeginDelegate(AsyncCallback callback, Object callbackState)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)
       at System.Web.Mvc.Controller.BeginExecuteCore(AsyncCallback callback, Object state)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)
       at System.Web.Mvc.Controller.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)
       at System.Web.Mvc.MvcHandler.<>c.<BeginProcessRequest>b__20_0(AsyncCallback asyncCallback, Object asyncState, ProcessRequestState innerState)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallBeginDelegate(AsyncCallback callback, Object callbackState)
       at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)
       at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContextBase httpContext, AsyncCallback callback, Object state)
       at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
       at System.Web.HttpApplication.<>c__DisplayClass285_0.<ExecuteStepImpl>b__0()
       at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)
       at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

这里是 Controller,OrderUpdate 是被调用的 Action:

public class ShopWebhooksController : Controller
{
private readonly ILog _logger;
private readonly InventoryMgmtContext _dbContext;

public ShopWebhooksController()
{
    _logger = LogManager.GetLogger(GetType());
    _dbContext = new InventoryMgmtContext();
}

protected override void OnException(ExceptionContext filterContext)
{
    Exception ex = filterContext.Exception;
    var action = filterContext.RouteData.Values["action"];
    // TODO: Log or report your exception.
    string msg = $"Exception in shopify webhook controller action: {action}. Message: {ex.Message}. Stack: {ex.StackTrace}.";
    _logger.Error(msg); **<---- this is being logged**

    filterContext.Result = new HttpStatusCodeResult(HttpStatusCode.OK, msg);

    //Let the base controller finish this execution
    base.OnException(filterContext);
}      


[HttpPost]
public async Task<ActionResult> OrderUpdated (int storefrontId)
{
    string msg = "Successfully submitted update request to Mozzo.";
    string webhook = "orders/updated";
    _logger.Debug($"Shopify {webhook} request received."); **<-- not being logged**

    try
    {
        var validationResult = await ValidateStorefrontWebhook(webhook, storefrontId);
        if (!validationResult.WasSuccessful) return new HttpStatusCodeResult(HttpStatusCode.OK, validationResult.Message);

        var orderSyncAppServ = new SyncErpWithPlacedOrdersTask();
        Hangfire.BackgroundJob.Enqueue(() => orderSyncAppServ.UpdateOrderFromWebhook(validationResult.Value, storefrontId));
    }
    catch (Exception e)
    {
        msg = $"Exception webhook: {webhook} for storefront Id: {storefrontId}. {e.Message}.";
        _logger.Error(msg);
    }
    return new HttpStatusCodeResult(HttpStatusCode.OK, msg);
}

#endregion

#region Private Methods


/// <summary>
/// Validates the webhook is authentic and returns the body of the request as a string
/// </summary>
/// <param name="webhook"></param>
/// <param name="storefrontId"></param>
/// <returns>request body (string version of an order, etc.</returns>
private async Task<ActionConfirmation<string>> ValidateStorefrontWebhook(string webhook, int storefrontId)
{
    string returnMessage = "";     

    //log request
    //get the request body (a json string of an order, product, etc coming from shopify.
    string jsonObject = await GetRequestBody();

    //wrap in brackets to make it an array of one because our import takes an array or orders
    jsonObject = $"[ {jsonObject} ]";

    //get storefront
    var storefront = await _dbContext.StoreFronts.Where(s => s.Id == storefrontId).SingleOrDefaultAsync();
    if (storefront == null) {
        returnMessage = $"Shopify {webhook} webhook request for Storefront Id: {storefront.Id} - storefront not found!";
        _logger.Error($"{LogHelper.GetCurrentMethodName()}: {returnMessage}");
        return ActionConfirmation<string>.CreateFailureConfirmation(returnMessage, "", false);
    }

    log4net.LogicalThreadContext.Properties["AccountId"] = storefront.Company.AccountId;
    log4net.LogicalThreadContext.Properties["CompanyId"] = storefront.CompanyId;
    log4net.LogicalThreadContext.Properties["FacilityId"] = null;
    log4net.LogicalThreadContext.Properties["UserId"] = null;

    string shopDomain = storefront.APIUrl;
    string shopSecretKey = storefront.StoreFrontTypeId == (int)StoreFront.StoreFrontTypes.ShopifyPrivate
        ? storefront.AccessToken
        : AppSettings.ShopifySecretKey;

    _logger.Debug("About to check if webhook is authentic");

    var isValidRequest = await AuthorizationService.IsAuthenticWebhook(
        Request.Headers.ToKvps(),
        Request.InputStream,
        shopSecretKey);

    if (!isValidRequest)
    {
        returnMessage = $"Shopify {webhook} webhook request for Storefront Id: {storefront.Id} is not authentic!";
        _logger.Error($"{LogHelper.GetCurrentMethodName()}: {returnMessage}"); 
        return ActionConfirmation<string>.CreateFailureConfirmation(returnMessage, "", false);
    }

    returnMessage = $"Shopify {webhook} webhook request for Storefront Id: {storefront.Id} is authentic!";
    _logger.Info($"{LogHelper.GetCurrentMethodName()}: {returnMessage}");            

    return ActionConfirmation<string>.CreateSuccessConfirmation(returnMessage, jsonObject, false);
}

private async Task<string> GetRequestBody()
{
    _logger.Debug($"{LogHelper.GetCurrentMethodName()}: Attempting to get request body.");

    //ShopifySharp has just read the input stream. We must always reset the inputstream
    //before reading it again.
    Request.InputStream.Position = 0;

    //Do not dispose the StreamReader or input stream. The controller will do that itself.
    string bodyText = await new StreamReader(Request.InputStream).ReadToEndAsync();

    _logger.Debug($"{LogHelper.GetCurrentMethodName()}: Request body: {bodyText}.");

    return bodyText;
}
#endregion  

更新 - 问题和解决方案

问题确实是 Shopify Order webhook JSON 对象包含重复的键,因为它们在同一对象包装器中具有 4 个键的 lowercaseTitleCase 版本。

这些键的完整路径是:

order,refunds,0,transactions,0,receipt,version
order,refunds,0,transactions,0,receipt,timestamp
order,refunds,0,transactions,0,receipt,ack
order,refunds,0,transactions,0,receipt,build

我所做的确切代码更改如下。我确实按照下面提供的答案添加了我自己的JsonValueProviderFactory 类,但是没有提供的是要进行的确切更改……因为这取决于您要如何处理它。就我而言,此更改会导致任何后续的同名键被丢弃。因此,如果您想以不同的方式处理它,则需要根据需要进行处理:

/// <summary>
/// Modified this to handle duplicate keys
/// </summary>
/// <param name="key"></param>
/// <param name="value"></param>
public void Add(string key, object value)
{
    if (++_itemCount > _maximumDepth)
    {
        throw new InvalidOperationException("The JSON request was too large to be deserialized.");
    }

    // Add the following if block so if the key already exists, just return instead of trying to add it to the dictionary which will throw an error.
    if (_innerDictionary.ContainsKey(key))
    {
        return;
    }

    _innerDictionary.Add(key, value);
}

【问题讨论】:

  • 你的hangfire配置是什么?一台服务器一台数据库?
  • @cdev hangfire 在同一台服务器上运行,但在一个单独的数据库上。仅供参考,我更新了问题以反映新信息,因为我一直在缩小范围。
  • 您的 JSON 有效负载很可能存在问题。看看这个答案:https://stackoverflow.com/a/36024415/7392651
  • @xcskilab 这就是我的想法,因为它依赖于数据,因为大多数 JSON 发布到此操作都可以正常工作,只有少数会导致问题。现在我只需要找到一种方法在错误之前捕获它,这样我就可以向我和 Shopify 证明它!
  • 这不止一个(甚至两个)问题。

标签: c# asp.net-mvc rest log4net elmah.mvc


【解决方案1】:

我不确定我的理解是否正确,但请尝试将后台调用临时包装在带有日志记录的附加方法中并尝试捕获:

BackgroundJob.Enqueue(() => UpdateOrderFromWebhookWithLogging(_logger, validationResult.Value, storefrontId));

并将此方法添加到您的控制器:

// I don't know types to write correct signature
private void UpdateOrderFromWebhookWithLogging(_logger, orderSyncAppServ, validationResult.Value, storefrontId)
        {
            try
            {
                orderSyncAppServ.UpdateOrderFromWebhook(validationResult.Value, storefrontId)
            }
            catch (Exception ex)
            {
                _logger.Error(ex);
                throw;
            }
        }

【讨论】:

  • 好的,我已经把它放进去,我会监控看看并通知你。
  • 很遗憾,这没有奏效,这个错误仍然没有被捕获,正在被 Elmah 发现。
  • 它不应该被捕获,因为它在后台执行,但它应该记录任何你想要的细节
【解决方案2】:

我认为你的设计没有问题,但你的一个类可能有重复的属性,这会导致运行时异常。

例如

public int storefrontId {get; set;}
public int StorefrontId {get; set;}

您需要配置 log4net 来记录您的操作调用。 例如:

2021-02-16 10:24:17.5632|2|INFO|Microsoft.AspNetCore.Hosting.Diagnostics|Request finished in 141.7419ms 200  |url: http://myapp/OrderUpdated|action:

编辑 以下是使用 DelegatingHandler 进行请求日志的方法

public class RequestLogHandler : DelegatingHandler
{
    private static readonly ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
    
    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        if (request.Content != null)
        {
            string requestBody = await request.Content.ReadAsStringAsync();
            log.Info($"url {request.RequestUri} body = {requestBody}");
        }
        //// let other handlers process the request
        var result = await base.SendAsync(request, cancellationToken);

        return result;
    }
}

在配置中注册处理程序

config.MessageHandlers.Add(new RequestLogHandler());

这将为您提供如下所示的内容。

此外,我将介绍覆盖 JsonValueProviderFactory AddToBackingStore 方法的步骤。您可以使用它来查找导致此问题的属性。

  1. here获取源代码。

  2. 添加类 MyJsonValueProviderFactory.cs

  3. 在 Global.asax.cs 中的 JsonValueProviderFactoruy 之前注册您的新课程

    ValueProviderFactories.Factories.Insert(0, new MyJsonValueProviderFactory());

或先删除原件并使用您的。

ValueProviderFactories.Factories.Remove(ValueProviderFactories.Factories.OfType<JsonValueProviderFactory>().FirstOrDefault());
ValueProviderFactories.Factories.Add(new MyJsonValueProviderFactory());

玩一下这个类的异常捕获,你会发现问题出在哪里,你可以从EntryLimitedDictionary类的Add方法开始。

再次使用下面的链接来全局注册错误处理。 https://docs.microsoft.com/en-us/aspnet/web-api/overview/error-handling/exception-handling

【讨论】:

  • 感谢您的想法。几乎我做的第一件事就是从操作方法中记录调用:_logger.Debug($"Shopify {webhook} request received.");,这并没有受到打击。我如何像您提到的那样在更高级别登录?另外,因为它在任何逻辑完成之前就失败了,所以不确定哪个类可能具有重复的属性名称,因为它甚至从未达到反序列化的逻辑......并且这是在单独的 Hangfire 作业中完成的。
  • 我无法准确回忆 asp.net 方法。 (使用 .net 核心),但您将能够使用 X_BeginRequest 操作捕获请求,并且您可以在启动时拥有一个全局异常捕获器,称为 application_onerror。由于该错误,它不会进入您的操作,无论您做什么,它都不会发生。也许我稍后会尝试给你一个样本。我现在的机器没有asp.net。
【解决方案3】:

看起来JsonValueProviderFactory.AddToBackingStore 正在遍历 JSON 输入并将每个叶值放入字典中。字典的键是叶节点的路径。如果遍历遇到具有相同路径的两个叶节点,则会发生该异常。

我认为您需要检查 JSON 输入数据 - 也许它有重复的键。例如。这是有效的 JSON:

{
    "id": 1,
    "name": "Some Name"
}

而这不是:

{
    "id": 1,
    "name": "Some Name",
    "id": 2
}

因为“id”键出现了不止一次。这可能会导致您看到的错误。

【讨论】:

    猜你喜欢
    • 2017-08-20
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2017-04-15
    相关资源
    最近更新 更多