advanced-search-index Failed without any logs or details as to why

[JamesLAllen]

Every so often in a reindexing job, the job fails and the job error just says:

0 documents imported successfully, 1 documents failed during import. Use error.importResults from the raised exception to get a detailed error reason for each document.

[michaelbromley]

Hi James,
is there any log in the worker process when this occurs?

[JamesLAllen]

I did not see any errors which is why it was a little frustrating. I'm going to try and replicate this issue locally to see if I can see errors there.

[JamesLAllen]

Ok, the above issue I think is due to a custom field that I added to the index which expected an int32 but got a float. But there's now a new issue where the entire indexing job will fail at the very last moment because it throws an error, after 134 minutes indexing everything:

[worker] warn 1/26/24, 6:15 PM - [Typesense Client] Request #1706321684718: Request to Node 0 failed due to "ECONNABORTED timeout of 30000ms exceeded"
[worker] warn 1/26/24, 6:15 PM - [Typesense Client] Request #1706321684718: Sleeping for 0.1s and then retrying request...
[worker] error 1/26/24, 6:15 PM - [AdvancedSearchPlugin] Request failed with HTTP code 404 | Server said: No collection with name `vendure_products_1706300444890` found.
[worker] ObjectNotFound: Request failed with HTTP code 404 | Server said: No collection with name `vendure_products_1706300444890` found.
[worker]     at ObjectNotFound.TypesenseError [as constructor] (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/src/Typesense/Errors/TypesenseError.ts:6:5)
[worker]     at new ObjectNotFound (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/Errors/ObjectNotFound.js:25:42)
[worker]     at ApiCall.customErrorForResponse (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/src/Typesense/ApiCall.ts:411:15)
[worker]     at /Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/src/Typesense/ApiCall.ts:247:18
[worker]     at step (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/ApiCall.js:33:23)
[worker]     at Object.next (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/ApiCall.js:14:53)
[worker]     at step (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/ApiCall.js:18:139)
[worker]     at Object.next (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/ApiCall.js:14:53)
[worker]     at fulfilled (/Users/jamesallen/_WORK/InvoCure/_NEWDEV/invocure-commerce2/node_modules/typesense/lib/Typesense/ApiCall.js:5:58)
[worker]     at processTicksAndRejections (node:internal/process/task_queues:95:5)
[worker] warn 1/26/24, 6:15 PM - [Vendure Worker] Job 348 [advanced-search-index] failed (attempt 1 of 1)

[JamesLAllen]

I have a concerning feeling that despite indexing everything for the last 134 minutes, the alias was not accepted and so my products are not accurately indexed, which means that product searches will return old results and 404's if items have been disabled or moved in the meantime.

[JamesLAllen]

I've looked up my TypeSense collections and aliases, and it looks like it's found here:

{
        "created_at": 1706313645,
        "default_sorting_field": "customMapping_popularity",
        "enable_nested_fields": false,
        "fields": [
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "languageCode",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "channelId",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "channelIds",
                "optional": false,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "sku",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productVariantId",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productVariantName",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productId",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productName",
                "optional": false,
                "sort": true,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "slug",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "currencyCode",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "description",
                "optional": false,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "enabled",
                "optional": false,
                "sort": true,
                "type": "bool"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "price",
                "optional": false,
                "sort": true,
                "type": "float"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "priceWithTax",
                "optional": false,
                "sort": true,
                "type": "float"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "inStock",
                "optional": false,
                "sort": true,
                "type": "bool"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productInStock",
                "optional": false,
                "sort": true,
                "type": "bool"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "options",
                "optional": true,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "facetIds",
                "optional": false,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "facetValueIds",
                "optional": false,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "collectionIds",
                "optional": false,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": true,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "collectionSlugs",
                "optional": false,
                "sort": false,
                "type": "string[]"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productAssetId",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productPreview",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productPreviewFocalPoint",
                "optional": true,
                "sort": false,
                "type": "float[]"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productVariantAssetId",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productVariantPreview",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "productVariantPreviewFocalPoint",
                "optional": true,
                "sort": false,
                "type": "float[]"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_manufacturerId",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_cardinalId",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_mcKessonId",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_brand",
                "optional": true,
                "sort": false,
                "type": "string"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_popularity",
                "optional": false,
                "sort": true,
                "type": "int32"
            },
            {
                "facet": false,
                "index": true,
                "infix": false,
                "locale": "",
                "name": "customMapping_minUom",
                "optional": true,
                "sort": true,
                "type": "int32"
            }
        ],
        "name": "vendure_products_1706313645514",
        "num_documents": 213659,
        "symbols_to_index": [],
        "token_separators": []
    },

and the alias list is here:

{
    "aliases": [
        {
            "collection_name": "vendure_products_1706313645514",
            "name": "vendure_products"
        }
    ]
}

I'm not sure if I can see anything wrong here, but it's curious why there would be a timeout and 404 after 130 or so minutes.

[JamesLAllen]

Ok further debugging as I run the index, these are firing in the logs over and over again:

13|worker     |     "code": "INTERNAL_SERVER_ERROR"
13|worker     |   }
13|worker     | }
13|worker     | GraphQLError: error.no-price-found-for-channel
13|worker     |     at new I18nError (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/i18n/i18n-error.js:21:9)
13|worker     |     at new InternalServerError (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/common/error/errors.js:15:9)
13|worker     |     at ProductPriceApplicator.applyChannelPriceAndTax (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/service/helpers/product-price-applicator/product-price-applicator.js:63:19)
13|worker     |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
13|worker     | error 1/27/24, 3:37 AM - [AdvancedSearchPlugin] {
13|worker     |   "message": "error.no-price-found-for-channel",
13|worker     |   "extensions": {
13|worker     |     "code": "INTERNAL_SERVER_ERROR"
13|worker     |   }
13|worker     | }
13|worker     | GraphQLError: error.no-price-found-for-channel
13|worker     |     at new I18nError (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/i18n/i18n-error.js:21:9)
13|worker     |     at new InternalServerError (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/common/error/errors.js:15:9)
13|worker     |     at ProductPriceApplicator.applyChannelPriceAndTax (/var/www/prod.invocure.com/invocure-commerce/node_modules/@vendure/core/dist/service/helpers/product-price-applicator/product-price-applicator.js:63:19)
13|worker     |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)

It's odd because all of these products have prices so I'm not sure what's up there.

[JamesLAllen]

I realized I wasn't getting the no-price-found-for-channel errors locally, and after digging I realized locally I was running node v20 and on production it was still v16. I'm not sure what difference this would make, but I'm still getting failures after 3 or so hours of running. Still no logs though, which is one of the reasons for this ticket. We should have more incite into why something has failed.

[JamesLAllen]

I do see the error deleting synthetic variant for Products error, but it doesn't seem to impact the index.

2|worker   | info 1/28/24, 6:08 PM - [AdvancedSearchPlugin] Created new Typesense collection: "vendure_products_1706465331107"
2|worker   | info 1/28/24, 6:08 PM - [AdvancedSearchPlugin] Adding 213659 records
2|worker   | error 1/28/24, 6:09 PM - [AdvancedSearchPlugin] Error deleting synthetic variant for Products
2|worker   | RequestMalformed: Request failed with HTTP code 400
2|worker   |     at RequestMalformed.TypesenseError [as constructor] (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/Errors/TypesenseError.js:23:28)
2|worker   |     at new RequestMalformed (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/Errors/RequestMalformed.js:25:42)
2|worker   |     at ApiCall.customErrorForResponse (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:361:21)
2|worker   |     at /var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:220:98
2|worker   |     at step (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:33:23)
2|worker   |     at Object.next (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:14:53)
2|worker   |     at step (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:18:139)
2|worker   |     at Object.next (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:14:53)
2|worker   |     at fulfilled (/var/www/prod.invocure.com/invocure-commerce/node_modules/typesense/lib/Typesense/ApiCall.js:5:58)
2|worker   |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)

[JamesLAllen]

This is the extent of the failure error in my logs:

2|worker   | warn 1/28/24, 2:03 PM - [Vendure Worker] Job 364 [advanced-search-index] failed (attempt 0 of 1)

[JamesLAllen]

I think there are multiple issues here, one of them being a timeout on the entire process. Perhaps being able to split up the indexing into multiple jobs based on the number of items might be best, then it can pick up where it leaves off if there's an error and timeouts are not an issue. The other issues I think are related to differences between deployed environments, I believe I have figured them out.

[JamesLAllen]

This is very frustrating, to wait an entire 2 hours just to have it fail!!!

[michaelbromley]

Hi James, thanks for providing all the additional information, and I'm sorry that this is such a frustrating issue! I will look into this this week.