Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
JamesLAllen opened this issue Jan 25, 2024 · 12 comments
Open

Comments

@JamesLAllen
Copy link

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.

image
@michaelbromley
Copy link
Member

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

@JamesLAllen
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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.

image

@JamesLAllen
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

image

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

@michaelbromley
Copy link
Member

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants