search

putyourlightson / craft-blitz

Intelligent static page caching for creating lightning-fast sites with Craft CMS.
https://putyourlightson.com/plugins/blitz
Other
147 stars 35 forks source link

Error message while generating cache with LocalGenerator #672

Closed kbergha closed 2 weeks ago

kbergha commented 3 weeks ago

Support Request

Hi.

I'm running Craft on Docker / WSL2, and have Traefik in front, and I'm having an issue with the LocalGenerator.

Versions and setup:

The frontend and Craft CP is available on my host machine, but not in the running container(s) with my current setup.

Craft is available on: http://cms.projectname.localhost The frontend is available on: http://projectname.localhost

The containers serving Craft and the frontend is based on the Docker image php:8.3.8-apache-bookworm (linux/amd64) I have ->runQueueAutomatically(false) in config/general.php, and a dedicated queue runner that is based on php:8.3.8-cli-bookworm (linux/amd64).

PHP: 8.3.8 Craft: 5.0.3 Blitz: 5.3.1

Config:

This is the current Blitz config (I can attach the whole file from diagnostics if needed):

'cachingEnabled' => true,
'cacheGeneratorType' => 'putyourlightson\blitz\drivers\generators\LocalGenerator',
'debug' => true
'refreshMode' => SettingsModel::REFRESH_MODE_EXPIRE_AND_GENERATE
'cacheStorageType' => 'putyourlightson\blitz\drivers\storage\YiiCacheStorage',
'cacheGeneratorSettings' => ['concurrency' => 5],
'queryStringCaching' => 2,
'includedUriPatterns' => [
        [
            'siteId' => '',
            'uriPattern' => '.*',
        ],
        [
            'siteId' => '',
            'uriPattern' => '',
        ],
    ],
];

Diagnostics report

1 Tracked Page ( / ) 1 Tracked Element (the frontpage entry)

Log output

After changing the frontpage entry, and waiting for the queue to run, I get this in the log from the queue runner:

Craft log:

{"Source":"Craft CMS","DateTime":"2024-06-14T08:53:07Z","Level":4,"LevelName":"INFO","Category":"craft\\queue\\QueueLogBehavior::beforeExec","Message":" [110] Generating Blitz cache (attempt: 1, pid: 7) - Started"}
{"Source":"Craft CMS","DateTime":"2024-06-14T08:53:07Z","Level":4,"LevelName":"INFO","Category":"blitz","Message":"The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.loclhost/]"}
{"Source":"Craft CMS","DateTime":"2024-06-14T08:53:07Z","Level":4,"LevelName":"INFO","Category":"blitz","Message":"The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.loclhost/__home__/]"}
{"Source":"Craft CMS","DateTime":"2024-06-14T08:53:07Z","Level":4,"LevelName":"INFO","Category":"craft\\queue\\QueueLogBehavior::afterExec","Message":" [110] Generating Blitz cache (attempt: 1, pid: 7) - Done (time: 0.156s)"}

The same appears in the Blitz debug log:

$ cat blitz-2024-06-14.log
[2024-06-14 10:53:07] The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.loclhost/]
[2024-06-14 10:53:07] The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.loclhost/__home__/]

Summary

Looks to be related to some error generated by amphp/parallel. Do you have any idea what would cause this?

Plugin Version

5.3.1

bencroker commented 3 weeks ago

Do you have devMode enabled, and is there a stack trace in the log files that you could attach?

kbergha commented 3 weeks ago

I have have devMode set to true (and the environment var CRAFT_ENVIRONMENT set to dev). I'm not seeing any stack trace, probably due to it being classified as INFO and not error / exception.

I'll see if I can figure out something...

kbergha commented 3 weeks ago

I figured out that the error is from AbstractContext->recieve() And then I modified the try catch block in LocalGenerator->generateUrisWithProgress() to this:

try {
    $context->send($config);
    $result = $context->receive($canceller); <- This is line 91 in LocalGenerator.php
} catch (Throwable $exception) {
    Craft::error('OH NOES!', 'blitz');
    Craft::error($exception->getMessage(), 'blitz');
    Craft::error($exception->getTraceAsString(), 'blitz');
    Blitz::$plugin->debug($exception->getMessage(), [], $url);
    $result = false;
}

Exception stack trace + log output:

#0 /app/vendor/putyourlightson/craft-blitz/src/drivers/generators/LocalGenerator.php(91): Amp\Parallel\Context\Internal\AbstractContext->receive(Object(Amp\TimeoutCancellation))
#1 /app/vendor/putyourlightson/craft-blitz/src/jobs/GenerateCacheJob.php(72): putyourlightson\blitz\drivers\generators\LocalGenerator->generateUrisWithProgress(Array, Array)
#2 /app/vendor/yiisoft/yii2-queue/src/Queue.php(243): putyourlightson\blitz\jobs\GenerateCacheJob->execute(Object(craft\queue\Queue))
#3 /app/vendor/yiisoft/yii2-queue/src/cli/Queue.php(162): yii\queue\Queue->handleMessage('130', 'O:43:"putyourli...', '300', '1')
#4 /app/vendor/yiisoft/yii2-queue/src/cli/Command.php(146): yii\queue\cli\Queue->execute('130', 'O:43:"putyourli...', '300', '1', '7')
#5 [internal function]: yii\queue\cli\Command->actionExec('130', '300', '1', '7')
#6 /app/vendor/yiisoft/yii2/base/InlineAction.php(57): call_user_func_array(Array, Array)
#7 /app/vendor/yiisoft/yii2/base/Controller.php(178): yii\base\InlineAction->runWithParams(Array)
#8 /app/vendor/yiisoft/yii2/console/Controller.php(180): yii\base\Controller->runAction('exec', Array)
#9 /app/vendor/craftcms/cms/src/console/ControllerTrait.php(89): yii\console\Controller->runAction('exec', Array)
#10 /app/vendor/yiisoft/yii2/base/Module.php(552): craft\queue\Command->runAction('exec', Array)
#11 /app/vendor/yiisoft/yii2/console/Application.php(180): yii\base\Module->runAction('queue/exec', Array)
#12 /app/vendor/craftcms/cms/src/console/Application.php(91): yii\console\Application->runAction('queue/exec', Array)
#13 /app/vendor/yiisoft/yii2/console/Application.php(147): craft\console\Application->runAction('queue/exec', Array)
#14 /app/vendor/craftcms/cms/src/console/Application.php(122): yii\console\Application->handleRequest(Object(craft\console\Request))
#15 /app/vendor/yiisoft/yii2/base/Application.php(384): craft\console\Application->handleRequest(Object(craft\console\Request))
#16 /app/craft(13): yii\base\Application->run()
#17 {main}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":4,"LevelName":"INFO","Category":"craft\\queue\\QueueLogBehavior::beforeExec","Message":" [130] Generating Blitz cache (attempt: 1, pid: 7) - Started"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":4,"LevelName":"INFO","Category":"blitz","Message":"Rec - The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.localhost]"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":4,"LevelName":"INFO","Category":"blitz","Message":"Rec - The context stopped responding, potentially due to a fatal error or calling exit [http://projectname.localhost/__home__/]"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":4,"LevelName":"INFO","Category":"craft\\queue\\QueueLogBehavior::afterExec","Message":" [130] Generating Blitz cache (attempt: 1, pid: 7) - Done (time: 0.139s)"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":1,"LevelName":"ERROR","Category":"blitz","Message":"OH NOES!"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":1,"LevelName":"ERROR","Category":"blitz","Message":"Rec - The context stopped responding, potentially due to a fatal error or calling exit"}
2024-06-14 13:42:05 {"Source":"Craft CMS","DateTime":"2024-06-14T11:42:05Z","Level":1,"LevelName":"ERROR","Category":"blitz","Message":"#0 /app/vendor/putyourlightson/craft-blitz/src/drivers/generators/LocalGenerator.php(91): Amp\\Parallel\\Context\\Internal\\AbstractContext->receive(Object(Amp\\TimeoutCancellation))\n#1 /app/vendor/putyourlightson/craft-blitz/src/jobs/GenerateCacheJob.php(72): putyourlightson\\blitz\\drivers\\generators\\LocalGenerator->generateUrisWithProgress(Array, Array)\n#2 /app/vendor/yiisoft/yii2-queue/src/Queue.php(243): putyourlightson\\blitz\\jobs\\GenerateCacheJob->execute(Object(craft\\queue\\Queue))\n#3 /app/vendor/yiisoft/yii2-queue/src/cli/Queue.php(162): yii\\queue\\Queue->handleMessage('130', 'O:43:\"putyourli...', '300', '1')\n#4 /app/vendor/yiisoft/yii2-queue/src/cli/Command.php(146): yii\\queue\\cli\\Queue->execute('130', 'O:43:\"putyourli...', '300', '1', '7')\n#5 [internal function]: yii\\queue\\cli\\Command->actionExec('130', '300', '1', '7')\n#6 /app/vendor/yiisoft/yii2/base/InlineAction.php(57): call_user_func_array(Array, Array)\n#7 /app/vendor/yiisoft/yii2/base/Controller.php(178): yii\\base\\InlineAction->runWithParams(Array)\n#8 /app/vendor/yiisoft/yii2/console/Controller.php(180): yii\\base\\Controller->runAction('exec', Array)\n#9 /app/vendor/craftcms/cms/src/console/ControllerTrait.php(89): yii\\console\\Controller->runAction('exec', Array)\n#10 /app/vendor/yiisoft/yii2/base/Module.php(552): craft\\queue\\Command->runAction('exec', Array)\n#11 /app/vendor/yiisoft/yii2/console/Application.php(180): yii\\base\\Module->runAction('queue/exec', Array)\n#12 /app/vendor/craftcms/cms/src/console/Application.php(91): yii\\console\\Application->runAction('queue/exec', Array)\n#13 /app/vendor/yiisoft/yii2/console/Application.php(147): craft\\console\\Application->runAction('queue/exec', Array)\n#14 /app/vendor/craftcms/cms/src/console/Application.php(122): yii\\console\\Application->handleRequest(Object(craft\\console\\Request))\n#15 /app/vendor/yiisoft/yii2/base/Application.php(384): craft\\console\\Application->handleRequest(Object(craft\\console\\Request))\n#16 /app/craft(13): yii\\base\\Application->run()\n#17 {main}"}
bencroker commented 3 weeks ago

The local generator is notoriously difficult to troubleshoot, but my guess would be that your template has an error in it. Can you please test it with a stripped down test template and then build it back up from there? Be on the lookout for anything that can only work with web requests, since the local generator works using console requests.

kbergha commented 3 weeks ago

I changed the twig template to this:

<html>
  <body>
    <h1>Hello, can you see me?</h1>
  </body>
</html>

This renders without problems in frontend: Untitled

And it's stored in the Redis cache as:

projectname-redis:6379[3]> get fc1ec5ffd0648821c50dc6afe327e232
"a:2:{i:0;s:123:\"<html>\n  <body>\n    <h1>Hello, can you see me?</h1>\n  </body>\n</html>\n<!-- Cached by Blitz on 2024-06-14T14:38:35+02:00 -->\";i:1;N;}"
projectname-redis:6379[3]>

I'm still getting the same exception :( I'll try to debug some more on my end.

kbergha commented 2 weeks ago

I'm giving up (for now). I'll probably turn off caching, and let CloudFront handle that part, and will be using Blitz only for purging if that is possible.

bencroker commented 2 weeks ago

I recommend you use the HTTP Warmer in production, which tends to anyway be more reliable than the Local Warmer. You can use it local development too, but Docker doesn’t usually allow external requests, which is what the HTTP Warmer uses. Most people disable caching in their local development environment, as it slows down development and troubleshooting.