Vendure: [Perf] Investigate slow Order mutations

Created on 10 Dec 2019  路  2Comments  路  Source: vendure-ecommerce/vendure

When changing the contents of an Order (adding/removing and item, updating quantity) the response time can get rather slow. One user reported up to 5 seconds with an Order with 200 lines to adjust a quantity.

The basic reason for this is that each of these operations triggers a call to this code:

https://github.com/vendure-ecommerce/vendure/blob/337762eeddb2a8a35b42c0c50dff115ae2b8612c/packages/core/src/service/helpers/order-calculator/order-calculator.ts#L34-L54

This code loops over every line and checks each line against tax rules and promotions. This has the result that the response time increases linearly with the number of lines in an Order.

As the user pointed out, some businesses such as an electronic components shop may have Orders with 1000s of lines. With an order of that size, Vendure might fail altogether.

Areas to investigate

SQL Queries

The user alerted me to a strange query being generated by TypeORM:

select
    distinct "distinctAlias"."ProductVariant_id" as "ids_ProductVariant_id"
from
    (
    select
        "ProductVariant"."createdAt" as "ProductVariant_createdAt",
        "ProductVariant"."updatedAt" as "ProductVariant_updatedAt",
        "ProductVariant"."deletedAt" as "ProductVariant_deletedAt",
        "ProductVariant"."enabled" as "ProductVariant_enabled",
        "ProductVariant"."sku" as "ProductVariant_sku",
        "ProductVariant"."lastPriceValue" as "ProductVariant_lastPriceValue",
        "ProductVariant"."productId" as "ProductVariant_productId",
        "ProductVariant"."stockOnHand" as "ProductVariant_stockOnHand",
        "ProductVariant"."trackInventory" as "ProductVariant_trackInventory",
        "ProductVariant"."id" as "ProductVariant_id",
        "ProductVariant"."featuredAssetId" as "ProductVariant_featuredAssetId",
        "ProductVariant"."taxCategoryId" as "ProductVariant_taxCategoryId",
        "ProductVariant"."customFieldsCf_externaluuid" as "ProductVariant_customFieldsCf_externaluuid",
        "ProductVariant_productVariantPrices"."createdAt" as "ProductVariant_productVariantPrices_createdAt",
        "ProductVariant_productVariantPrices"."updatedAt" as "ProductVariant_productVariantPrices_updatedAt",
        "ProductVariant_productVariantPrices"."price" as "ProductVariant_productVariantPrices_price",
        "ProductVariant_productVariantPrices"."id" as "ProductVariant_productVariantPrices_id",
        "ProductVariant_productVariantPrices"."channelId" as "ProductVariant_productVariantPrices_channelId",
        "ProductVariant_productVariantPrices"."variantId" as "ProductVariant_productVariantPrices_variantId",
        "ProductVariant_translations"."createdAt" as "ProductVariant_translations_createdAt",
        "ProductVariant_translations"."updatedAt" as "ProductVariant_translations_updatedAt",
        "ProductVariant_translations"."languageCode" as "ProductVariant_translations_languageCode",
        "ProductVariant_translations"."name" as "ProductVariant_translations_name",
        "ProductVariant_translations"."id" as "ProductVariant_translations_id",
        "ProductVariant_translations"."baseId" as "ProductVariant_translations_baseId",
        "ProductVariant__product"."createdAt" as "ProductVariant__product_createdAt",
        "ProductVariant__product"."updatedAt" as "ProductVariant__product_updatedAt",
        "ProductVariant__product"."deletedAt" as "ProductVariant__product_deletedAt",
        "ProductVariant__product"."enabled" as "ProductVariant__product_enabled",
        "ProductVariant__product"."id" as "ProductVariant__product_id",
        "ProductVariant__product"."featuredAssetId" as "ProductVariant__product_featuredAssetId",
        "ProductVariant__product"."customFieldsCf_alpharange" as "ProductVariant__product_customFieldsCf_alpharange",
        "ProductVariant__product"."customFieldsCf_country" as "ProductVariant__product_customFieldsCf_country",
        "ProductVariant__product"."customFieldsCf_characteristics" as "ProductVariant__product_customFieldsCf_characteristics",
        "ProductVariant__product"."customFieldsCf_flavourstrength" as "ProductVariant__product_customFieldsCf_flavourstrength",
        "ProductVariant__product"."customFieldsCf_variety" as "ProductVariant__product_customFieldsCf_variety",
        "ProductVariant__product_translations"."createdAt" as "ProductVariant__product_translations_createdAt",
        "ProductVariant__product_translations"."updatedAt" as "ProductVariant__product_translations_updatedAt",
        "ProductVariant__product_translations"."languageCode" as "ProductVariant__product_translations_languageCode",
        "ProductVariant__product_translations"."name" as "ProductVariant__product_translations_name",
        "ProductVariant__product_translations"."slug" as "ProductVariant__product_translations_slug",
        "ProductVariant__product_translations"."description" as "ProductVariant__product_translations_description",
        "ProductVariant__product_translations"."id" as "ProductVariant__product_translations_id",
        "ProductVariant__product_translations"."baseId" as "ProductVariant__product_translations_baseId",
        "ProductVariant__product__featuredAsset"."createdAt" as "ProductVariant__product__featuredAsset_createdAt",
        "ProductVariant__product__featuredAsset"."updatedAt" as "ProductVariant__product__featuredAsset_updatedAt",
        "ProductVariant__product__featuredAsset"."name" as "ProductVariant__product__featuredAsset_name",
        "ProductVariant__product__featuredAsset"."type" as "ProductVariant__product__featuredAsset_type",
        "ProductVariant__product__featuredAsset"."mimeType" as "ProductVariant__product__featuredAsset_mimeType",
        "ProductVariant__product__featuredAsset"."width" as "ProductVariant__product__featuredAsset_width",
        "ProductVariant__product__featuredAsset"."height" as "ProductVariant__product__featuredAsset_height",
        "ProductVariant__product__featuredAsset"."fileSize" as "ProductVariant__product__featuredAsset_fileSize",
        "ProductVariant__product__featuredAsset"."source" as "ProductVariant__product__featuredAsset_source",
        "ProductVariant__product__featuredAsset"."preview" as "ProductVariant__product__featuredAsset_preview",
        "ProductVariant__product__featuredAsset"."id" as "ProductVariant__product__featuredAsset_id",
        "ProductVariant__taxCategory"."createdAt" as "ProductVariant__taxCategory_createdAt",
        "ProductVariant__taxCategory"."updatedAt" as "ProductVariant__taxCategory_updatedAt",
        "ProductVariant__taxCategory"."name" as "ProductVariant__taxCategory_name",
        "ProductVariant__taxCategory"."id" as "ProductVariant__taxCategory_id"
    from
        "product_variant" "ProductVariant"
    left join "product_variant_price" "ProductVariant_productVariantPrices" on
        "ProductVariant_productVariantPrices"."variantId" = "ProductVariant"."id"
    left join "product_variant_translation" "ProductVariant_translations" on
        "ProductVariant_translations"."baseId" = "ProductVariant"."id"
    left join "product" "ProductVariant__product" on
        "ProductVariant__product"."id" = "ProductVariant"."productId"
    left join "product_translation" "ProductVariant__product_translations" on
        "ProductVariant__product_translations"."baseId" = "ProductVariant__product"."id"
    left join "asset" "ProductVariant__product__featuredAsset" on
        "ProductVariant__product__featuredAsset"."id" = "ProductVariant__product"."featuredAssetId"
    left join "tax_category" "ProductVariant__taxCategory" on
        "ProductVariant__taxCategory"."id" = "ProductVariant"."taxCategoryId"
    where
        "ProductVariant"."id" = $1) "distinctAlias"
order by
    "ProductVariant_id" asc
limit 1

which apparently is executed several times when calling addItemToOrder.

So I should analyze the SQL queries to ensure that no redundant expensive operations are taking place.

Optimize logic

The current implementation is rather naive. There is probably room for some optimization techniques - memoization or the like - which may radically improve the situation.

The main reason the logic is as it is currently has to do with the flexibility of the Promotion system. One thing to consider would be constraining what Promotions can do, if that enables a much more efficient price calculation algorithm.

@vendurcore

Most helpful comment

With the load test referenced above, we now have some baseline data which shows the performance characteristics of the current Order implementation.

The load test has a single user which continuously adds items to the order as fast as possible for 4 minutes. Here are the results on my machine (Dell XPS15, Intel i7 @ 2.8GHz, 16GB):

  {
    "timestamp": "2019-12-11T09:51:43.454Z",
    "script": "very-large-order",
    "productCount": 1000,
    "testDuration": 240.016,
    "requests": 212,
    "throughput": 0.8832744483701087,
    "requestDurationSummary": {
      "avg": 1119.3766084905653,
      "min": 105.4098,
      "max": 3159.544,
      "med": 955.8834,
      "p90": 2232.4990000000007,
      "p95": 2582.4781999999996,
      "p99": 2911.729316
  }

Here is a chart showing how response time increases with Order size (total items added by the end was 212):
vendure-load-test-orders-01

The chart shows worrying signs of exponential growth!

Let's see what can be done...

All 2 comments

With the load test referenced above, we now have some baseline data which shows the performance characteristics of the current Order implementation.

The load test has a single user which continuously adds items to the order as fast as possible for 4 minutes. Here are the results on my machine (Dell XPS15, Intel i7 @ 2.8GHz, 16GB):

  {
    "timestamp": "2019-12-11T09:51:43.454Z",
    "script": "very-large-order",
    "productCount": 1000,
    "testDuration": 240.016,
    "requests": 212,
    "throughput": 0.8832744483701087,
    "requestDurationSummary": {
      "avg": 1119.3766084905653,
      "min": 105.4098,
      "max": 3159.544,
      "med": 955.8834,
      "p90": 2232.4990000000007,
      "p95": 2582.4781999999996,
      "p99": 2911.729316
  }

Here is a chart showing how response time increases with Order size (total items added by the end was 212):
vendure-load-test-orders-01

The chart shows worrying signs of exponential growth!

Let's see what can be done...

Good progress has been made on this! Here's the latest benchmark with the above changes:

  {
    "timestamp": "2019-12-13T15:16:22.581Z",
    "script": "very-large-order",
    "productCount": 1000,
    "testDuration": 243.847,
    "requests": 749,
    "throughput": 3.0715981742650103,
    "requestDurationSummary": {
      "avg": 326.4335359145525,
      "min": 113.9034,
      "max": 4807.6961,
      "med": 318.1944,
      "p90": 413.01244,
      "p95": 433.239405,
      "p99": 516.0695559999999
    }
  }

vendure-load-test-orders-02

As you can see, that scary exponential curve has gone, and instead we have a O(log n) type of shape, which will scale much better.

The 90th percentile response time is now ~5.4x faster.

Was this page helpful?
0 / 5 - 0 ratings