[4.x]: unserialize() Error at offset #13164

croxton · 2023-05-06T11:31:30Z

What happened?

Description

The storage/runtime cache becomes corrupted when saving an entry using the keyboard (control-s) when Craft is in the middle of auto-saving the entry. The entire site is broken until the cache is deleted.

This problem seems to have emerged with the latest (or a recent) version of Craft, but I may have just missed it previously.

Steps to reproduce

Make an edit to an entry with a lot of field data, and quickly hit control-s while the auto-save is spinning; this will trigger the error.

Expected behavior

Manual saving should be disabled during autosave, or the manual save should be queued.

Actual behavior

Entire site breaks!

Craft CMS version

4.4.9

PHP version

8.1.10 (MAMP Pro on OSX)

Operating system and version

OSX

Database type and version

mysql 5.7.34 (MAMP Pro on OSX)

Image driver and version

No response

Installed plugins and versions

Calendar Links
Control Panel JS
Element API
Environment Label
Feed Me
Field Manager
Freeform
Google Maps
Help Links
Hyper
Image Resizer
Imgixer
Matrix Mate
Navigation
Postmark
Read Time
Redactor
SEOmatic
Servd Assets & Helpers
Sherlock
Similar
Sprig
Super Table
Table Maker
Template Select

The text was updated successfully, but these errors were encountered:

croxton · 2023-05-06T12:03:29Z

When the cache is corrupted, there is a unusually large .bin file in storage/runtime/cache/8e (always the same subdirectory 8e) with a huge block of <0x00>s in it (but not in the same place):

croxton · 2023-05-06T12:15:33Z

That Yii caching code looks like it should be more error tolerant when unserializing whatever the cause of this is, no?

brandonkelly · 2023-05-06T14:50:46Z

The only cache-related thing Craft does when saving an entry is invalidate existing caches for the element, which doesn’t actually touch the element caches at all—only cache tag caches are updated, which are very small cache files that only contain a timestamp. So whatever caused this corruption, it wasn’t caused by saving an entry twice in quick succession (at least directly).

That cache looks like it contains a serialized field layout. Probably from an entire entry getting cached? It’s generally not a good idea to cache instantiated PHP objects unless the object’s class was clearly coded for it (e.g. with __sleep() and __wakeup() methods), which FieldLayout and Entry were not. The cache data would be significantly larger than typical caches, and more error-prone if changes occur in any of the serialized classes between the time the cache is created and retrieved.

So you should probably try to track down why the field layout/entry is getting cached in the first place, and cache the specific data you need from it instead.

That Yii caching code looks like it should be more error tolerant when unserializing whatever the cause of this is, no?

Yeah, wrapping that code in a try/catch wouldn’t hurt. Just PR’d that change: yiisoft/yii2#19827

croxton · 2023-05-06T15:11:08Z

So you should probably try to track down why the field layout/entry is getting cached in the first place, and cache the specific data you need from it instead.

This isn't something I'm doing anywhere (in my own code at least), so maybe it's one of those plugins. I'll see if I can track down the culprit.

Yeah, wrapping that code in a try/catch wouldn’t hurt. Just PR’d that change: yiisoft/yii2#19827

Great, thank you!

croxton · 2023-05-06T15:37:17Z

Sorry Brandon, I disabled plugins in the config ('disabledPlugins' => '*') and found that a 1.1Mb file was still generated in the storage/runtime/cache/8e folder, which I assume must be generated by Craft's own code? Checking other projects running the latest Craft I also see a similar file in that same folder (looks like a field layout), but not on projects running slightly older version of Craft. I'm going to roll back to a previous version of this project and an older version of Craft to see if that file is still generated.

croxton · 2023-05-06T16:54:20Z

Went back to Craft 4.3.6.1 and that 1.1Mb cache file is still generated in that version of Craft. As far as I can see this is a cache file generated by Craft itself for all of the field layouts. It has an expiry time of 1 day. If I delete it, Craft will recreate it on any request in the CP or frontend, or just by running ./craft on the command line. Presumably an entry save could trigger a recreation of this cache if it was the first request after it has expired. Could that cause a race condition?

brandonkelly · 2023-05-06T18:33:49Z

Hm, I’m not seeing the same behavior on my end.

Try the following:

Change your craftcms/cms requirement in composer.json to dev-develop#385516ee99b8b4b5105d62ae32bbadb9bda6a7d5 (so you can get the new ArrayHelper::containsRecursive() method I just added in 385516e)

Open vendor/yiisoft/yii2/caching/Cache.php and add the following code to the beginning of the set() method:

if (
    $value instanceof \craft\base\ElementInterface ||
    $value instanceof \craft\base\FieldInterface ||
    (
        is_array($value) &&
        \craft\helpers\ArrayHelper::containsRecursive($value, fn($e) => 
            $e instanceof \craft\base\ElementInterface ||
            $e instanceof \craft\base\FieldInterface
        )
    )
) {
    \Craft::$app->getErrorHandler()->logException(new \Exception('CACHE ISSUE'));
}

Clear caches and save an entry or whatever causes the value to get cached.
Search your logs in storage/logs/ for CACHE ISSUE.

There should be a stack trace along with the log message. Can you post it here?

If the exception isn’t getting logged, maybe some other object is getting cached that contains the field layout. You could change the code to this:

```php
if (
    (
        $value instanceof \yii\base\BaseObject &&
        !$value instanceof \yii\web\UrlRule
    ) ||
    (
        is_array($value) &&
        \craft\helpers\ArrayHelper::containsRecursive($value, fn($e) =>
            $e instanceof \yii\base\BaseObject &&
            !$e instanceof \yii\web\UrlRule
        )
    )
) {
    \Craft::$app->getErrorHandler()->logException(new \Exception('CACHE ISSUE'));
}
```

There could be additional noise with that code, though.

croxton · 2023-05-06T20:57:37Z

The second method identified nystudio107/craft-autocomplete:

2023-05-06 20:16:57 [console.ERROR] [Exception] Exception: CACHE ISSUE in [redacted]/vendor/yiisoft/yii2/caching/Cache.php:254
Stack trace:
#0 [redacted]/vendor/yiisoft/yii2/caching/Cache.php(624): yii\caching\Cache->set('seomatic_metaco...', Array, 30, Object(yii\caching\TagDependency))
#1 [redacted]/vendor/nystudio107/craft-seomatic/src/services/MetaContainers.php(444): yii\caching\Cache->getOrSet('seomatic_metaco...', Object(Closure), 30, Object(yii\caching\TagDependency))
#2 [redacted]/vendor/nystudio107/craft-seomatic/src/twigextensions/SeomaticTwigExtension.php(54): nystudio107\seomatic\services\MetaContainers->loadMetaContainers('/', 1)
#3 [redacted]/vendor/twig/twig/src/ExtensionSet.php(320): nystudio107\seomatic\twigextensions\SeomaticTwigExtension->getGlobals()
#4 [redacted]/vendor/twig/twig/src/Environment.php(789): Twig\ExtensionSet->getGlobals()
#5 [redacted]/vendor/nystudio107/craft-autocomplete/src/generators/AutocompleteVariableGenerator.php(80): Twig\Environment->getGlobals()
#6 [redacted]/vendor/nystudio107/craft-autocomplete/src/generators/AutocompleteVariableGenerator.php(57): nystudio107\autocomplete\generators\AutocompleteVariableGenerator::generateInternal()
#7 [redacted]/vendor/nystudio107/craft-autocomplete/src/Autocomplete.php(143): nystudio107\autocomplete\generators\AutocompleteVariableGenerator::generate()
#8 [internal function]: nystudio107\autocomplete\Autocomplete->generateAutocompleteClasses(Object(yii\base\Event))
#9 [redacted]/vendor/yiisoft/yii2/base/Event.php(312): call_user_func(Array, Object(yii\base\Event))
#10 [redacted]/vendor/yiisoft/yii2/base/Component.php(642): yii\base\Event::trigger('craft\\services\\...', 'afterLoadPlugin...', Object(yii\base\Event))
#11 [redacted]/vendor/craftcms/cms/src/services/Plugins.php(275): yii\base\Component->trigger('afterLoadPlugin...')
#12 [redacted]/vendor/craftcms/cms/src/base/ApplicationTrait.php(1554): craft\services\Plugins->loadPlugins()
#13 [redacted]/vendor/craftcms/cms/src/console/Application.php(52): craft\console\Application->_postInit()
#14 [redacted]/vendor/yiisoft/yii2/base/BaseObject.php(109): craft\console\Application->init()
#15 [redacted]/vendor/yiisoft/yii2/base/Application.php(204): yii\base\BaseObject->__construct(Array)
#16 [redacted]/vendor/yiisoft/yii2/console/Application.php(89): yii\base\Application->__construct(Array)
#17 [internal function]: yii\console\Application->__construct(Array)
#18 [redacted]/vendor/yiisoft/yii2/di/Container.php(419): ReflectionClass->newInstanceArgs(Array)
#19 [redacted]/vendor/yiisoft/yii2/di/Container.php(170): yii\di\Container->build('craft\\console\\A...', Array, Array)
#20 [redacted]/vendor/yiisoft/yii2/BaseYii.php(365): yii\di\Container->get('craft\\console\\A...', Array, Array)
#21 [redacted]/vendor/craftcms/cms/src/Craft.php(54): yii\BaseYii::createObject(Array, Array)
#22 [redacted]/vendor/craftcms/cms/bootstrap/bootstrap.php(252): Craft::createObject(Array)
#23 [redacted]/vendor/craftcms/cms/bootstrap/console.php(40): require('/Users/markcrox...')
#24 [redacted]/craft(12): require('/Users/markcrox...')
#25 {main} {"memory":57719088,"exception":"[object] (Exception(code: 0): CACHE ISSUE at [redacted]/vendor/yiisoft/yii2/caching/Cache.php:254)"} 
2023-05-06 20:16:57 [console.INFO] [nystudio107\autocomplete\Autocomplete::generateAutocompleteClasses] Autocomplete classes generated {"memory":59210424}

However, I uninstalled that from require-dev and ran it again. The large 1.1Mb is STILL generated. No CACHE ISSUE in logs for either of your methods so I just edited to throw an exception with no conditions just to see what was calling it, as there is only this one file being generated now. The stack trace indicates that craft\services\ProjectConfig->_loadInternalConfig() causes the the large cache file to be created in 8e:

2023-05-06 20:37:33 [console.ERROR] [Exception] Exception: CACHE ISSUE in [redacted]/vendor/yiisoft/yii2/caching/Cache.php:243
Stack trace:
#0 [redacted]/vendor/yiisoft/yii2/caching/Cache.php(613): yii\caching\Cache->set('projectConfig:i...', Array, NULL, Object(yii\caching\ExpressionDependency))
#1 [redacted]/vendor/craftcms/cms/src/services/ProjectConfig.php(1785): yii\caching\Cache->getOrSet('projectConfig:i...', Object(Closure), NULL, Object(yii\caching\ExpressionDependency))
#2 [redacted]/vendor/craftcms/cms/src/services/ProjectConfig.php(1707): craft\services\ProjectConfig->_loadInternalConfig()
#3 [redacted]/vendor/craftcms/cms/src/services/ProjectConfig.php(1721): craft\services\ProjectConfig->getInternalConfig()
#4 [redacted]/vendor/craftcms/cms/src/services/ProjectConfig.php(441): craft\services\ProjectConfig->getCurrentWorkingConfig()
#5 [redacted]/vendor/craftcms/cms/src/base/ApplicationTrait.php(1575): craft\services\ProjectConfig->get('system.timeZone')
#6 [redacted]/vendor/craftcms/cms/src/base/ApplicationTrait.php(1510): craft\console\Application->_setTimeZone()
#7 [redacted]/vendor/craftcms/cms/src/console/Application.php(50): craft\console\Application->_preInit()
#8 [redacted]/vendor/yiisoft/yii2/base/BaseObject.php(109): craft\console\Application->init()
#9 [redacted]/vendor/yiisoft/yii2/base/Application.php(204): yii\base\BaseObject->__construct(Array)
#10 [redacted]/vendor/yiisoft/yii2/console/Application.php(89): yii\base\Application->__construct(Array)
#11 [internal function]: yii\console\Application->__construct(Array)
#12 [redacted]/vendor/yiisoft/yii2/di/Container.php(419): ReflectionClass->newInstanceArgs(Array)
#13 [redacted]/vendor/yiisoft/yii2/di/Container.php(170): yii\di\Container->build('craft\\console\\A...', Array, Array)
#14 [redacted]/vendor/yiisoft/yii2/BaseYii.php(365): yii\di\Container->get('craft\\console\\A...', Array, Array)
#15 [redacted]/vendor/craftcms/cms/src/Craft.php(54): yii\BaseYii::createObject(Array, Array)
#16 [redacted]/vendor/craftcms/cms/bootstrap/bootstrap.php(252): Craft::createObject(Array)
#17 [redacted]/vendor/craftcms/cms/bootstrap/console.php(40): require('/Users/markcrox...')
#18 [redacted]/craft(12): require('/Users/markcrox...')
#19 {main} {"memory":22635624,"exception":"[object] (Exception(code: 0): CACHE ISSUE at [redacted]/vendor/yiisoft/yii2/caching/Cache.php:243)"} 
2023-05-06 20:37:33 [console.INFO] [modules\custommodule\CustomModule::init] custom module loaded {"memory":24671320}

I had project config disabled, but I tried it with it enabled (after making sure the project config yaml was rebuilt from the database) - and the large cache file is still created with the stack trace the same.

brandonkelly · 2023-05-07T00:33:13Z

Any chance you can send a database backup and your Composer files over to support@craftcms.com?

croxton · 2023-05-07T04:41:37Z

I've sent that over, let me know if you need anything else. Many thanks for taking a look.

brandonkelly · 2023-05-08T17:46:08Z

Looks like I was wrong, there aren’t any entries/field layouts getting cached. Just the field layout settings for an entry type, which is expected.

Still, saving an entry won’t touch your project config, so I don’t see how double-saving an entry would cause the project config cache to become corrupted. Probably just a coincidence.

The Yii PR was rejected since unserialize() will only trigger a PHP notice when there’s a problem, which isn’t supposed to halt execution.

So the real issue here is that Craft is being a little overzealous when it comes to error reporting. I’ve just toned that down for the next release. Going forward, PHP warnings and notices will no longer halt execution unless Dev Mode is disabled.

croxton · 2023-05-09T13:00:11Z

Thank you, that looks like the best solution possible for now.

For the record, this happened on three occasions when editing the same entry; each time the corrupted cache file had a modified date exactly 1 day after the time of the error - suggesting the file was indeed touched during the save process for the entry, inexplicable though that seems!

brandonkelly · 2023-05-09T22:02:23Z

4.4.10 is out with the warning and notice reporting changes.

croxton · 2023-07-20T07:27:30Z

Would you mind reopening this issue, if appropriate? We're seeing problems with another project where the project config cache file (always saved at storage/runtime/cache/8e) seems unreasonably large - 1.4Mb. When making any change in the CP that writes PC data (editing a field, adding a user group etc) we get a 500 error as Craft tries to rebuild the cache - we think because that file gets corrupted. Increasing PHP memory etc doesn't help. This seems like an architecture problem - should all that data really be serialised in one go, would it be better broken up into smaller caches?

croxton · 2023-07-20T07:34:35Z

The cache duration also seems short - one day. Why not a year? Regeneration of the cache is triggered by any request, so given the potential for that file to be corrupted we could see intermittent errors on the front end for an unlucky user.

#13164

brandonkelly · 2023-08-02T14:28:16Z

@croxton The cache stores the project config data verbatim, so it would only grow that large if your project config itself is that large. The best way to reduce that would be to simplify your content model. (We’re working to make that more doable in Craft 5.)

should all that data really be serialised in one go, would it be better broken up into smaller caches?

Not a bad idea. Would you mind loading your config/project/ folder into a tool like DaisyDisk and showing me a breakdown of its nested folder/file sizes?

The cache duration also seems short - one day. Why not a year?

It just uses the default cache duration, which probably makes sense to be 24h by default, considering the variety of things that get cached. But I just added a way to override it from config/app.php for Craft 4.5 (57df57b):

use craft\helpers\App;
use craft\helpers\ConfigHelper;

return [
    'components' => [
        'projectConfig' => fn() => Craft::createObject([
            'cacheDuration' => ConfigHelper::durationInSeconds('P1Y'),
        ] + App::projectConfigConfig()),
    ],
];

croxton · 2023-08-10T08:06:23Z

@brandonkelly thank you for allowing the cache duration to be configurable - that should help a lot.

Here's a breakdown:

Interestingly, looking at the largest files the yaml for Verbb's Hyper fields seems excessively verbose compared to other field types.

croxton · 2023-08-10T08:38:45Z

@brandonkelly If you are able to break the PC cache up into smaller files I think that could actually prove quite a crucial optimisation as the complexity of Craft fields (such as Hyper) increases. In terms of content model the sites in question are actually not as complex as other sites we have built (that remain on Craft 3).

brandonkelly · 2023-08-10T20:13:13Z

I take it the Hyper field(s) live within matrixBlockTypes and superTableBlockTypes?

croxton · 2023-08-11T05:36:46Z

Yes that's right.

croxton · 2023-08-14T09:57:53Z

Just to follow up: by default Hyper adds an 'Advanced' tab containing 3 fields to every link type within a field, and whether that link type is enabled or disabled the field layout is saved in project config. That adds an additional 30 fields for each Hyper field created in the CMS. For the project in question it was fine for us to remove this tab for most Hyper fields. This is the result:

A significant improvement I think. Thus far, I've not see any further 500 errors on cache generation following this change, and CP performance when making admin changes that write PC data is noticeably faster.

brandonkelly · 2023-08-22T17:53:25Z

Craft 4.5.0 is out with the ProjectConfig::$cacheDuration property.

croxton added bug craft4 labels May 6, 2023

brandonkelly closed this as completed May 6, 2023

brandonkelly reopened this May 7, 2023

brandonkelly mentioned this issue May 7, 2023

Catch unserialize() errors yiisoft/yii2#19827

Closed

brandonkelly closed this as completed in a1c2180 May 8, 2023

brandonkelly added a commit that referenced this issue Aug 2, 2023

ProjectConfig::$cacheDuration

57df57b

#13164

croxton mentioned this issue Aug 10, 2023

Very large project config generation verbb/hyper#9

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[4.x]: unserialize() Error at offset #13164

[4.x]: unserialize() Error at offset #13164

croxton commented May 6, 2023

croxton commented May 6, 2023 •

edited

croxton commented May 6, 2023

brandonkelly commented May 6, 2023 •

edited

croxton commented May 6, 2023

croxton commented May 6, 2023

croxton commented May 6, 2023

brandonkelly commented May 6, 2023

croxton commented May 6, 2023

brandonkelly commented May 7, 2023

croxton commented May 7, 2023

brandonkelly commented May 8, 2023

croxton commented May 9, 2023

brandonkelly commented May 9, 2023 •

edited

croxton commented Jul 20, 2023 •

edited

croxton commented Jul 20, 2023

brandonkelly commented Aug 2, 2023

croxton commented Aug 10, 2023

croxton commented Aug 10, 2023

brandonkelly commented Aug 10, 2023

croxton commented Aug 11, 2023

croxton commented Aug 14, 2023

brandonkelly commented Aug 22, 2023

[4.x]: unserialize() Error at offset #13164

[4.x]: unserialize() Error at offset #13164

Comments

croxton commented May 6, 2023

What happened?

Description

Steps to reproduce

Expected behavior

Actual behavior

Craft CMS version

PHP version

Operating system and version

Database type and version

Image driver and version

Installed plugins and versions

croxton commented May 6, 2023 • edited

croxton commented May 6, 2023

brandonkelly commented May 6, 2023 • edited

croxton commented May 6, 2023

croxton commented May 6, 2023

croxton commented May 6, 2023

brandonkelly commented May 6, 2023

croxton commented May 6, 2023

brandonkelly commented May 7, 2023

croxton commented May 7, 2023

brandonkelly commented May 8, 2023

croxton commented May 9, 2023

brandonkelly commented May 9, 2023 • edited

croxton commented Jul 20, 2023 • edited

croxton commented Jul 20, 2023

brandonkelly commented Aug 2, 2023

croxton commented Aug 10, 2023

croxton commented Aug 10, 2023

brandonkelly commented Aug 10, 2023

croxton commented Aug 11, 2023

croxton commented Aug 14, 2023

brandonkelly commented Aug 22, 2023

croxton commented May 6, 2023 •

edited

brandonkelly commented May 6, 2023 •

edited

brandonkelly commented May 9, 2023 •

edited

croxton commented Jul 20, 2023 •

edited