3.5-beta3: Errors for "Updating search indexes"-jobs for Assets

[FreekVR]

Description

Since updating to the beta of 3.5 I am getting search indexing errors on my Assets on a Craft multisite.

Trying to get property 'language' of non-object

Additional info

• Craft version: 3.5-beta3
• PHP version: 7.2
• Database driver & version: MySQL 5.7
• Plugins & versions:

[brandonkelly]

We have fixed a couple asset-related bugs since 3.5 Beta 3 was released, so this may already be fixed. Please try changing your craftcms/cms constraint in composer.json to 3.5.x-dev, and then run composer update.

If you’re still seeing the error, search for it in your storage/logs/web.log or queue.log files, and post the full error log including its stack trace.

[FreekVR]

Hey @brandonkelly,

Thanks, we're running into this issue on a staging environment, so as this isn't a critical issue for us, I'll hold off on testing until there's a new beta out, rather than taking a gamble on a dev version ;)

I'll let you know whether that fixes the issue for us after it comes out.

[brandonkelly]

Sounds good. Will close this for the time being.

[jsunsawyer]

I'm seeing this error (Trying to get property 'language' of non-object) come up on a multi-site setup for Canada where we have English and French sites, with French currently disabled.

Mine is not related to assets though, but entries in general.

It's been inconsistent, but occurs when clicking New entry in a channel or structure. I immediately see a failed task. Navigating to it shows the following.

This is only happening in our production environment (Servd), and I have limited access to log files. Not seeing much that'd be helpful in the live logs.

Running Craft 3.6.7

[brandonkelly]

@jsunsawyer Do you see that error logged in storage/logs/queue.log? What’s the stack trace?

[jsunsawyer]

@brandonkelly Sorry, I don't have direct access to that due to how Servd works.

I downloaded the live logs and this stack trace comes up frequently:

Stack trace:
#0 /var/www/html/vendor/craftcms/cms/src/web/Controller.php(138): yii\web\Controller->beforeAction(Object(yii\base\InlineAction))
#1 /var/www/html/vendor/craftcms/cms/src/controllers/BaseElementsController.php(32): craft\web\Controller->beforeAction(Object(yii\base\InlineAction))
#2 /var/www/html/vendor/craftcms/cms/src/controllers/ElementIndexesController.php(88): craft\controllers\BaseElementsController->beforeAction(Object(yii\base\InlineAction))
#3 /var/www/html/vendor/yiisoft/yii2/base/Controller.php(179): craft\controllers\ElementIndexesController->beforeAction(Object(yii\base\InlineAction))
#4 /var/www/html/vendor/craftcms/cms/src/web/Controller.php(190): yii\base\Controller->runAction('get-elements', Array)
#5 /var/www/html/vendor/yiisoft/yii2/base/Module.php(534): craft\web\Controller->runAction('get-elements', Array)
#6 /var/www/html/vendor/craftcms/cms/src/web/Application.php(274): yii\base\Module->runAction('element-indexes...', Array)
#7 /var/www/html/vendor/craftcms/cms/src/web/Application.php(577): craft\web\Application->runAction('element-indexes...', Array)
#8 /var/www/html/vendor/craftcms/cms/src/web/Application.php(253): craft\web\Application->_processActionRequest(Object(craft\web\Request))
#9 /var/www/html/vendor/yiisoft/yii2/base/Application.php(392): craft\web\Application->handleRequest(Object(craft\web\Request))
#10 /var/www/html/web/index.php(22): yii\base\Application->run()
#11 {main}
2021-02-26 11:21:40 [-][1][-][info][application] $_GET = [
    'v' => '1614367300732'
]
$_POST = []
$_FILES = []
$_COOKIE = [
    '1031b8c41dfff97a311a7ac99863bdc5_username' => '38513538585172b0b7f03e074f137b4f9085aed786b8525af8737bc26ab8afe7a:2:{i:0;s:41:\"1031b8c41dfff97a311a7ac99863bdc5_username\";i:1;s:11:\"humanshapes\";}'
    'month' => '01'
    'day' => '01'
    'year' => '1984'
    'location' => 'AB'
    '1031b8c41dfff97a311a7ac99863bdc5_identity' => '28bd6e65140c9a516e5088972534e001c55a75f3e6e9e445e96bfebe3b2698e5a:2:{i:0;s:41:\"1031b8c41dfff97a311a7ac99863bdc5_identity\";i:1;s:249:\"[1,\"[\\\"wupoPikSo90h0gU1HoSUXgmlkx0gweGFu5aIK1i3L7Fr6tvJwY7uMKZfXw35AhDf3a0Th8854642mgQoRl8Bj7806vr5eMp_PJc0\\\",null,\\\"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.192 Safari/537.36\\\"]\",86400]\";}'
    'CraftSessionId' => '5b19b712bc4dca03974dede79db623f3'
    'CRAFT_CSRF_TOKEN' => '•••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••'
]
$_SESSION = [
    'bd62416aa8538ede709019a5e113eea5__flash' => []
    '1031b8c41dfff97a311a7ac99863bdc5__token' => '••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••'
    '1031b8c41dfff97a311a7ac99863bdc5__id' => 1
    '1031b8c41dfff97a311a7ac99863bdc5__expire' => 1614453700
    'bd62416aa8538ede709019a5e113eea5__auth_access' => [
        0 => 'editStructure:3'
        1 => 'previewDraft:70'
        2 => 'previewDraft:71'
        3 => 'saveAssetInVolume:1'
        4 => 'previewDraft:72'
        5 => 'previewDraft:73'
        6 => 'previewDraft:74'
        7 => 'editStructure:1'
        8 => 'previewDraft:75'
        9 => 'previewElement:1797'
        10 => 'previewDraft:76'
        11 => 'previewDraft:77'
        12 => 'previewDraft:78'
        13 => 'previewDraft:79'
        14 => 'previewDraft:80'
        15 => 'previewDraft:81'
    ]
    '__elevated_timeout' => 1614367030
]

Here's a portion of the log around this error:

2021-02-26 10:12:18 [-][-][-][info][nystudio107\seomatic\Seomatic::init] SEO plugin loaded
2021-02-26 10:12:18 [-][-][-][info][nystudio107\typogrify\Typogrify::init] Typogrify plugin loaded
2021-02-26 10:12:18 [-][-][-][info][nystudio107\cookies\Cookies::init] Cookies plugin loaded
2021-02-26 10:12:18 [-][-][-][info][nystudio107\seomatic\services\{closure}] Meta container cache miss: sitemaps-1-section-categories-1-sitemap.xml/1
2021-02-26 10:12:18 [-][-][-][info][craft\queue\QueueLogBehavior::beforeExec]  [3590] Updating element slugs and URIs (attempt: 1) - Started
2021-02-26 10:12:18 [-][-][-][info][craft\queue\QueueLogBehavior::afterExec]  [3590] Updating element slugs and URIs (attempt: 1) - Done (time: 0.005s)
2021-02-26 10:12:18 [-][-][-][info][craft\queue\QueueLogBehavior::beforeExec]  [3591] Updating search indexes (attempt: 1) - Started
2021-02-26 10:12:18 [-][-][-][error][craft\queue\QueueLogBehavior::afterError]  [3591] Updating search indexes (attempt: 1) - Error (time: 0.011s): Trying to get property 'language' of non-object

Let me know if there's anything else I can provide. Again, this is inconsistent.

[brandonkelly]

What is the actual error reported above that stack trace?

[jsunsawyer]

Oops, here you go.

2021-02-26 11:21:40 [-][1][-][error][yii\web\HttpException:400] yii\web\BadRequestHttpException: Unable to verify your data submission. in /var/www/html/vendor/yiisoft/yii2/web/Controller.php:209

[brandonkelly]

That’s just a standard CSRF error. Probably caused by an automated vulnerability probe that’s sending a POST request to your homepage.

[jsunsawyer]

Well, if this is unrelated to the Trying to get property 'language' of non-object issue, I'm not seeing any other stack traces show up.

[jsunsawyer]

@brandonkelly By any chance, could there be an issue with the following combination of settings?

In Site settings: English: language = en (enabled) French: language = fr (disabled)

On a section's settings: English: default status = enabled French: default status = disabled

On this section's entry type settings: Title Translation Method = Translate for each language

The different propagation methods we're using depending on the section: Propagation Method = Save entries to all sites enabled for this section (taxonomies - should apply to all sites) Propagation Method = Let each entry choose which sites it should be saved to (posts - can be site specific)

For some reason, after I made some adjustments to the Propagation Method (allowing some content to be site specific), I noticed fewer issues.

[brandonkelly]

@jsunsawyer without being able to see a stack trace for the actual error you’re getting, I’m not really sure what to think. Maybe @mattgrayisok can shed some light on how Servd logs work? (We’re trying to track down the stack trace for an exception which would normally get logged to storage/logs/queue.log.)

[mattgrayisok]

Hey both.

Servd just adds a log target which sends everything to stdout and then it collects them up for display and download in the Servd dash.

I can see the error coming out in those logs, but without a stack trace. Poking around at the files inside the running container I can see Craft has also been writing logs to the filesystem as expected and that file does contain the stack trace. So there's something there for me to have a look into.

But the stack trace for this exception is....

2021-02-26 11:16:24 [-][-][-][error][yii\base\ErrorException:8] yii\base\ErrorException: Trying to get property 'language' of non-object in /var/www/html/vendor/craftcms/cms/src/services/Search.php:376
Stack trace:
#0 /var/www/html/vendor/craftcms/cms/src/web/ErrorHandler.php(76): yii\base\ErrorHandler->handleError(8, 'Trying to get p...', '/var/www/html/v...', 376)
#1 /var/www/html/vendor/craftcms/cms/src/services/Search.php(376): craft\web\ErrorHandler->handleError(8, 'Trying to get p...', '/var/www/html/v...', 376, Array)
#2 /var/www/html/vendor/craftcms/cms/src/services/Search.php(156): craft\services\Search->_indexElementKeywords(1811, 'slug', '0', 2, '__temp_ncujbenl...')
#3 /var/www/html/vendor/craftcms/cms/src/queue/jobs/UpdateSearchIndex.php(60): craft\services\Search->indexElementAttributes(Object(craft\elements\Entry), Array)
#4 /var/www/html/vendor/yiisoft/yii2-queue/src/Queue.php(246): craft\queue\jobs\UpdateSearchIndex->execute(Object(craft\queue\Queue))
#5 /var/www/html/vendor/yiisoft/yii2-queue/src/cli/Queue.php(147): yii\queue\Queue->handleMessage('3904', 'O:34:"craft\\que...', '300', 1)
#6 /var/www/html/vendor/craftcms/cms/src/queue/Queue.php(127): yii\queue\cli\Queue->handleMessage('3904', 'O:34:"craft\\que...', '300', 1)
#7 /var/www/html/vendor/nystudio107/craft-seomatic/src/helpers/Queue.php(58): craft\queue\Queue->run()
#8 /var/www/html/vendor/nystudio107/craft-seomatic/src/models/SitemapTemplate.php(162): nystudio107\seomatic\helpers\Queue::run()
#9 /var/www/html/vendor/nystudio107/craft-seomatic/src/services/Sitemaps.php(187): nystudio107\seomatic\models\SitemapTemplate->render(Array)
#10 /var/www/html/vendor/nystudio107/craft-seomatic/src/controllers/SitemapController.php(131): nystudio107\seomatic\services\Sitemaps->renderTemplate('SeomaticSitemap...', Array)
#11 [internal function]: nystudio107\seomatic\controllers\SitemapController->actionSitemap(1, 'section', 'categories', 1)
#12 /var/www/html/vendor/yiisoft/yii2/base/InlineAction.php(57): call_user_func_array(Array, Array)
#13 /var/www/html/vendor/yiisoft/yii2/base/Controller.php(181): yii\base\InlineAction->runWithParams(Array)
#14 /var/www/html/vendor/craftcms/cms/src/web/Controller.php(190): yii\base\Controller->runAction('sitemap', Array)
#15 /var/www/html/vendor/yiisoft/yii2/base/Module.php(534): craft\web\Controller->runAction('sitemap', Array)
#16 /var/www/html/vendor/craftcms/cms/src/web/Application.php(274): yii\base\Module->runAction('seomatic/sitema...', Array)
#17 /var/www/html/vendor/yiisoft/yii2/web/Application.php(104): craft\web\Application->runAction('seomatic/sitema...', Array)
#18 /var/www/html/vendor/craftcms/cms/src/web/Application.php(259): yii\web\Application->handleRequest(Object(craft\web\Request))
#19 /var/www/html/vendor/yiisoft/yii2/base/Application.php(392): craft\web\Application->handleRequest(Object(craft\web\Request))
#20 /var/www/html/web/index.php(22): yii\base\Application->run()

I'll have a quick go at decoding that to make sure it's nothing on my side

[mattgrayisok]

There's an element in the database which references a Site object which doesn't exist I think.

[mattgrayisok]

The site does exist in the database, but it is disabled:

This might be an issue with seomatic trying to include entries in sitemaps for sites which are disabled. Resulting in this line in Search.php returning null:

https://github.com/craftcms/cms/blob/e18321039c1a20529d4b80db0d3adb0dd339bf88/src/services/Search.php#L373

because it doesn't set $withDisabled.

Speculatively paging @khalwat for his opinion

@brandonkelly I guess it might be worth guarding against this unhandled exception occurring within Search.php, or by setting $withDisabled to true on getSiteById() if it doesn't break anything?

I notice there's a few @throws SiteNotFoundException in there but it isn't actually being thrown anywhere within that file that I can see, or within getSiteById() - might be somewhere lower down though.

[jsunsawyer]

@mattgrayisok Thanks for digging into that for me! So much good support in this community.

[khalwat]

mmmm nope I don't think so @mattgrayisok -- I didn't look into it deeply, but the only reason SEOmatic is in the stack frame there is it is pushing a job into the queue to regenerate the sitemaps, and then attempting to run the queue immediately... which then runs the jobs that are already in the queue, the search index jobs.

I can look into it further if SEOmatic is further implicated tho!

[mattgrayisok]

Thanks. Will await @brandonkelly 's opinion

[jsunsawyer]

@khalwat @mattgrayisok I just deployed a quick test where I disabled our language picker manually, then enabled the French version of the site.

I attempted to reproduce the error by adding new entries, then going back in the browser.

This resulted in the banner message A server error occurred, any existing entries in my section going away, and the control panel debug toolbar missing. Refreshing the browser brought back the entries.

@brandonkelly The errors in my logs still seem to line up with the initial stack trace I posted above.

Possibly multiple issues that are somehow all intertwined? Above my skillset, but happy to test things out and provide any additional information.

[brandonkelly]

Thanks @mattgrayisok! That stack trace was a big help. Just got that fixed for the next release.

[brandonkelly]

Craft 3.6.8 is out now with this fix. Thanks for reporting @FreekVR, and thanks again for the assist, @mattgrayisok!