【发布时间】:2021-05-14 21:12:21
【问题描述】:
我有一个 Shopify 的 webhook api 处理程序,它使用 json 主体调用以下控制器操作。它立即失败,因为除了 OnException 方法中的日志之外,没有任何 log4net 日志被访问和记录,并出现以下错误。
问题 1:
Elmah 日志中的堆栈跟踪没有帮助,因为它没有深入到足以显示代码中的哪一行引发了错误。为什么是这样?我注意到async 错误...他们似乎更难确定代码中的根本原因行。也许我现在应该让它成为一个同步方法?也许我应该摆脱 OnException 方法,因为它可能会掩盖更多信息?
问题 2:
在执行任何代码之前点击控制器操作可能会立即导致此错误?此控制器继承了 asp.net mvc Controller,构造函数中的唯一代码是创建 DBContext 和 log4net _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 个键的 lowercase 和 TitleCase 版本。
这些键的完整路径是:
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