cms icon indicating copy to clipboard operation
cms copied to clipboard

False 404 pages after stache:warm

Open heidkaemper opened this issue 1 year ago • 38 comments

Bug description

This is a strange one, sorry! :-)

After the update to 5.x, everything looked okay at first. After a few hours, however, 404 pages for published entries appeared in production. Clearing the cache helped at first, but after a while the 404 pages were back again.

I have since been able to reproduce the behavior with two projects in development as well. PHP version and collection settings do not seem to matter.

Rob also has this problem randonly with his projects, but cannot reproduce it reliably.

Any ideas? Unintentional behavior of the stache perhaps?!

How to reproduce

  • Run php please stache:warm
  • Try to view an entry in your browser
  • On the first try a Call to a member function requiresSlugs() on null error occurs
  • On the second try (refresh) a 404 page shows up

Logs

[2024-07-08 16:29:51] local.ERROR: Call to a member function requiresSlugs() on null {"exception":"[object] (Error(code: 0): Call to a member function requiresSlugs() on null at /web/vendor/statamic/cms/src/Stache/Stores/CollectionEntriesStore.php:87)
[stacktrace]
#0 /web/vendor/statamic/cms/src/Stache/Stores/Store.php(283): Statamic\\Stache\\Stores\\CollectionEntriesStore->makeItemFromFile('/web/content/co...', '---\\nid: 0efe9e6...')
#1 /web/vendor/statamic/cms/src/Stache/Stores/Store.php(230): Statamic\\Stache\\Stores\\Store->getItemFromModifiedPath('/web/content/co...')
#2 [internal function]: Statamic\\Stache\\Stores\\Store->Statamic\\Stache\\Stores\\{closure}(1683730144, '/web/content/co...')
#3 /web/vendor/laravel/framework/src/Illuminate/Collections/Arr.php(605): array_map(Object(Closure), Array, Array)
#4 /web/vendor/laravel/framework/src/Illuminate/Collections/Collection.php(759): Illuminate\\Support\\Arr::map(Array, Object(Closure))
#5 /web/vendor/laravel/framework/src/Illuminate/Collections/Traits/EnumeratesValues.php(423): Illuminate\\Support\\Collection->map(Object(Closure))
#6 /web/vendor/statamic/cms/src/Stache/Stores/Store.php(229): Illuminate\\Support\\Collection->flatMap(Object(Closure))
#7 /web/vendor/statamic/cms/src/Stache/Stores/Store.php(45): Statamic\\Stache\\Stores\\Store->handleFileChanges()
#8 /web/vendor/statamic/cms/src/Stache/Stores/CollectionsStore.php(88): Statamic\\Stache\\Stores\\Store->index('uri')
#9 /web/vendor/statamic/cms/src/Stache/Repositories/CollectionRepository.php(101): Statamic\\Stache\\Stores\\CollectionsStore->updateEntryUris(Object(Statamic\\Entries\\Collection), NULL)
#10 /web/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php(357): Statamic\\Stache\\Repositories\\CollectionRepository->updateEntryUris(Object(Statamic\\Entries\\Collection), NULL)
#11 /web/vendor/statamic/cms/src/Entries/Collection.php(506): Illuminate\\Support\\Facades\\Facade::__callStatic('updateEntryUris', Array)
#12 /web/vendor/statamic/cms/src/Stache/Stores/CollectionsStore.php(142): Statamic\\Entries\\Collection->updateEntryUris()
#13 /web/vendor/statamic/cms/src/Stache/Stores/Store.php(288): Statamic\\Stache\\Stores\\CollectionsStore->handleFileChanges()
#14 /web/vendor/statamic/cms/src/Stache/Repositories/CollectionRepository.php(29): Statamic\\Stache\\Stores\\Store->paths()
#15 /web/vendor/statamic/cms/src/Stache/Repositories/CollectionRepository.php(76): Statamic\\Stache\\Repositories\\CollectionRepository->all()
#16 /web/vendor/spatie/blink/src/Blink.php(306): Statamic\\Stache\\Repositories\\CollectionRepository->Statamic\\Stache\\Repositories\\{closure}()
#17 /web/vendor/statamic/cms/src/Support/Blink.php(18): Spatie\\Blink\\Blink->once('collection-hand...', Object(Closure))
#18 /web/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php(357): Statamic\\Support\\Blink->__call('once', Array)
#19 /web/vendor/statamic/cms/src/Stache/Repositories/CollectionRepository.php(75): Illuminate\\Support\\Facades\\Facade::__callStatic('once', Array)
#20 /web/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php(357): Statamic\\Stache\\Repositories\\CollectionRepository->handles()
#21 /web/vendor/statamic/cms/src/Stache/Query/EntryQueryBuilder.php(61): Illuminate\\Support\\Facades\\Facade::__callStatic('handles', Array)
#22 /web/vendor/statamic/cms/src/Stache/Query/Builder.php(27): Statamic\\Stache\\Query\\EntryQueryBuilder->getFilteredKeys()
#23 /web/vendor/statamic/cms/src/Stache/Query/Builder.php(46): Statamic\\Stache\\Query\\Builder->resolveKeys()
#24 /web/vendor/statamic/cms/src/Query/Concerns/FakesQueries.php(18): Statamic\\Stache\\Query\\Builder->Statamic\\Stache\\Query\\{closure}()
#25 /web/vendor/statamic/cms/src/Stache/Query/Builder.php(45): Statamic\\Query\\Builder->withFakeQueryLogging(Object(Closure))
#26 /web/vendor/statamic/cms/src/Query/Builder.php(584): Statamic\\Stache\\Query\\Builder->Statamic\\Stache\\Query\\{closure}()
#27 /web/vendor/statamic/cms/src/Stache/Query/Builder.php(45): Statamic\\Query\\Builder->onceWithColumns(Array, Object(Closure))
#28 /web/vendor/statamic/cms/src/Query/Builder.php(539): Statamic\\Stache\\Query\\Builder->get()
#29 /web/vendor/statamic/cms/src/Stache/Repositories/EntryRepository.php(81): Statamic\\Query\\Builder->first()
#30 /web/vendor/statamic/cms/src/Data/DataRepository.php(70): Statamic\\Stache\\Repositories\\EntryRepository->findByUri('/', 'default')
#31 /web/vendor/statamic/cms/src/Data/DataRepository.php(41): Statamic\\Data\\DataRepository->attemptAllRepositories('findByUri', '/', 'default')
#32 /web/vendor/statamic/cms/src/Data/DataRepository.php(60): Statamic\\Data\\DataRepository->findByUri('/', 'default')
#33 /web/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php(357): Statamic\\Data\\DataRepository->findByRequestUrl('/')
#34 /web/vendor/statamic/cms/src/Http/Controllers/FrontendController.php(30): Illuminate\\Support\\Facades\\Facade::__callStatic('findByRequestUr...', Array)
#35 /web/vendor/laravel/framework/src/Illuminate/Routing/Controller.php(54): Statamic\\Http\\Controllers\\FrontendController->index(Object(Illuminate\\Http\\Request))
#36 /web/vendor/laravel/framework/src/Illuminate/Routing/ControllerDispatcher.php(43): Illuminate\\Routing\\Controller->callAction('index', Array)
#37 /web/vendor/laravel/framework/src/Illuminate/Routing/Route.php(260): Illuminate\\Routing\\ControllerDispatcher->dispatch(Object(Illuminate\\Routing\\Route), Object(Statamic\\Http\\Controllers\\FrontendController), 'index')
#38 /web/vendor/laravel/framework/src/Illuminate/Routing/Route.php(206): Illuminate\\Routing\\Route->runController()
#39 /web/vendor/laravel/framework/src/Illuminate/Routing/Router.php(806): Illuminate\\Routing\\Route->run()
#40 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\\Routing\\Router->Illuminate\\Routing\\{closure}(Object(Illuminate\\Http\\Request))
#41 /web/vendor/statamic/cms/src/StaticCaching/Middleware/Cache.php(63): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#42 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\StaticCaching\\Middleware\\Cache->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#43 /web/vendor/statamic/cms/src/Http/Middleware/AuthGuard.php(14): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#44 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\AuthGuard->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#45 /web/vendor/statamic/cms/src/Http/Middleware/AddViewPaths.php(19): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#46 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\AddViewPaths->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#47 /web/vendor/statamic/cms/src/Http/Middleware/Localize.php(38): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#48 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\Localize->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#49 /web/vendor/statamic/cms/src/Http/Middleware/HandleToken.php(13): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#50 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\HandleToken->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#51 /web/vendor/statamic/cms/src/Http/Middleware/StacheLock.php(29): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#52 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\StacheLock->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#53 /web/vendor/heidkaemper/statamic-toolbar/src/Middleware/InjectToolbar.php(18): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#54 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Heidkaemper\\Toolbar\\Middleware\\InjectToolbar->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#55 /web/vendor/laravel/framework/src/Illuminate/Routing/Middleware/SubstituteBindings.php(50): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#56 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Routing\\Middleware\\SubstituteBindings->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#57 /web/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/AddQueuedCookiesToResponse.php(37): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#58 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Cookie\\Middleware\\AddQueuedCookiesToResponse->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#59 /web/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/EncryptCookies.php(75): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#60 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Cookie\\Middleware\\EncryptCookies->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#61 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#62 /web/vendor/laravel/framework/src/Illuminate/Routing/Router.php(805): Illuminate\\Pipeline\\Pipeline->then(Object(Closure))
#63 /web/vendor/laravel/framework/src/Illuminate/Routing/Router.php(784): Illuminate\\Routing\\Router->runRouteWithinStack(Object(Illuminate\\Routing\\Route), Object(Illuminate\\Http\\Request))
#64 /web/vendor/laravel/framework/src/Illuminate/Routing/Router.php(748): Illuminate\\Routing\\Router->runRoute(Object(Illuminate\\Http\\Request), Object(Illuminate\\Routing\\Route))
#65 /web/vendor/laravel/framework/src/Illuminate/Routing/Router.php(737): Illuminate\\Routing\\Router->dispatchToRoute(Object(Illuminate\\Http\\Request))
#66 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(200): Illuminate\\Routing\\Router->dispatch(Object(Illuminate\\Http\\Request))
#67 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(144): Illuminate\\Foundation\\Http\\Kernel->Illuminate\\Foundation\\Http\\{closure}(Object(Illuminate\\Http\\Request))
#68 /web/vendor/statamic/cms/src/Http/Middleware/StopImpersonating.php(12): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#69 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\StopImpersonating->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#70 /web/vendor/statamic/cms/src/Http/Middleware/DisableFloc.php(17): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#71 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\DisableFloc->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#72 /web/vendor/statamic/cms/src/Http/Middleware/CheckMultisite.php(15): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#73 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\CheckMultisite->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#74 /web/vendor/statamic/cms/src/Http/Middleware/CheckComposerJsonScripts.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#75 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\CheckComposerJsonScripts->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#76 /web/vendor/statamic/cms/src/Http/Middleware/PoweredByHeader.php(18): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#77 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Statamic\\Http\\Middleware\\PoweredByHeader->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#78 /web/vendor/barryvdh/laravel-debugbar/src/Middleware/InjectDebugbar.php(59): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#79 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Barryvdh\\Debugbar\\Middleware\\InjectDebugbar->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#80 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#81 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ConvertEmptyStringsToNull.php(31): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#82 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Foundation\\Http\\Middleware\\ConvertEmptyStringsToNull->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#83 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#84 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TrimStrings.php(51): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#85 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Foundation\\Http\\Middleware\\TrimStrings->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#86 /web/vendor/laravel/framework/src/Illuminate/Http/Middleware/ValidatePostSize.php(27): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#87 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Http\\Middleware\\ValidatePostSize->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#88 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/PreventRequestsDuringMaintenance.php(110): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#89 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Foundation\\Http\\Middleware\\PreventRequestsDuringMaintenance->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#90 /web/vendor/laravel/framework/src/Illuminate/Http/Middleware/HandleCors.php(49): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#91 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Http\\Middleware\\HandleCors->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#92 /web/vendor/laravel/framework/src/Illuminate/Http/Middleware/TrustProxies.php(57): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#93 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(183): Illuminate\\Http\\Middleware\\TrustProxies->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#94 /web/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(119): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#95 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(175): Illuminate\\Pipeline\\Pipeline->then(Object(Closure))
#96 /web/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(144): Illuminate\\Foundation\\Http\\Kernel->sendRequestThroughRouter(Object(Illuminate\\Http\\Request))
#97 /web/vendor/laravel/framework/src/Illuminate/Foundation/Application.php(1183): Illuminate\\Foundation\\Http\\Kernel->handle(Object(Illuminate\\Http\\Request))
#98 /web/public/index.php(17): Illuminate\\Foundation\\Application->handleRequest(Object(Illuminate\\Http\\Request))
#99 {main}
"}

Environment

Environment
Application Name: NEW DATA SERVICES
Laravel Version: 11.14.0
PHP Version: 8.3.9
Composer Version: 2.7.1
Environment: local
Debug Mode: ENABLED
URL: nds-statamic.heidkaemper.nds-dev.de/
Maintenance Mode: OFF
Timezone: Europe/Berlin
Locale: de

Cache
Config: NOT CACHED
Events: NOT CACHED
Routes: NOT CACHED
Views: CACHED

Drivers
Broadcasting: null
Cache: file
Database: mysql
Logs: debug / single
Mail: sendmail
Queue: sync
Session: file

Statamic
Addons: 4
Sites: 1
Stache Watcher: Enabled
Static Caching: Disabled
Version: 5.13.0 PRO

Statamic Addons
heidkaemper/statamic-toolbar: 1.2.0
jacksleight/statamic-bard-texstyle: 3.2.2
ndx/statamic-bard-color-picker: 2.0.0
spatie/statamic-responsive-images: 5.0.0

Installation

Other (please explain)

Additional details

Plain statamic/statamic site, update from 4.x to 5.x

heidkaemper avatar Jul 08 '24 14:07 heidkaemper

Would you be able to provide a repo where this behavior happens?

jasonvarga avatar Jul 08 '24 17:07 jasonvarga

I think ours are separate issues @heidkaemper. It looks like #10412 solves the issue I was running into. As this project I'm noticing it on features both structured collections and static caching (also locally because I was testing stuff).

robdekort avatar Jul 08 '24 17:07 robdekort

Yea that's right. We do use static caching (half) in production but certainly not in development.

@jasonvarga We have to prepare a repo without client data. But we can manage that, I'll get back to you on that!

heidkaemper avatar Jul 08 '24 18:07 heidkaemper

We are experiencing this same random behaviour (on v5). Also half page caching using the redis application cache driver. After the requiresSlugs() error the sites throws a lot of Call to a member function routeData() on null errors and pages are no longer reachable. Redeploying fixes it most of the times.

JorisOrangeStudio avatar Jul 09 '24 10:07 JorisOrangeStudio

An update from me as well: The 404 pages in Production could have something to do with #10412 for us as well. Cuz we run cache:clear and static:warm one after the other in deployment pipelines. So that would at least explain some of it.

The other part of the issue is probably related to our development environment. Because I did:

  • Clone the statamic/statamic repo
  • Ran composer install and set an app key
  • Ran artisan cache:clear followed by please stache:warm

When I tried to open the page at first the requiresSlugs() on null error came up. And after reload a 404 page. However, I then did exactly the same thing locally in a Laravel Herd environment. And lo and behold, no errors at all, everything worked just fine!

I dived in a little deeper and looked at the stache files. After a stache:warm, they appear to be identical in both of my development environments. Here for example the storage/framework/cache/data/stache/keys/entries file:

9999999999a:1:{s:4:"home";s:79:"/home/heidkaemper/code/local/vanilla-statamic/content/collections/pages/home.md";}

After I opened that page in the browser the stache key in my Laravel Herd environment remained unchanged. The file in our regular development environment does not:

9999999999a:0:{}

I have to say that the stache behavior goes a bit over my head. :-) But I'm glad that at least a fix for #10412 ist in sight.

heidkaemper avatar Jul 09 '24 12:07 heidkaemper

We also have this same problem, locally (with no caching) and on production (with "half"-measure caching). The issue seems to appear a few hours after the last deployment but we couldn't reliably reproduce it.

schwemmer avatar Jul 17 '24 13:07 schwemmer

Just had this issue after the last release. Had to revert to v5.14.0

I'm using STATAMIC_STATIC_CACHING_STRATEGY="full" in my env and php please static:clear && php please static:warm --queue in deployment.

Happy yo test things if needed!

SRWieZ avatar Jul 17 '24 17:07 SRWieZ

Okay, I think I found the problem for our setup. And it's quite clearly our own fault..

We use a docker setup for local development. And we often run console commands from outside the container. But things like the Stache Watcher obviously run inside the docker container. And although both work, there is one important difference: the base_path() is different!

For example, when I run stache:warm from outside the container, the Stache file looks something like this:

9999999999a:1:{s:5:"pages";s:76:"/home/heidkaemper/code/local/vanilla-statamic/content/collections/pages.yaml";}

The same command from inside the container generates a Stache file like this:

9999999999a:1:{s:5:"pages";s:35:"/web/content/collections/pages.yaml";}

I'm pretty sure this causes empty stache files. And it also explains why we could not reliably reproduce the error in production.

This could possibly be fixed by not saving absolute paths in the stache. However, in my opinion this is an edge case and probably not worth the time and effort. Or what do you think @jasonvarga?

As far as I'm concerned, we can close this issue. However, I am unsure whether the problems mentioned in the other comments are still valid. They sound more like issues with static caching?!

heidkaemper avatar Jul 30 '24 19:07 heidkaemper

@heidkaemper We are seeing this issue locally (using docker) as well as on production (not using docker). So I don't think the issue is docker. It might be one of the ways to cause this but not the only one.

schwemmer avatar Jul 30 '24 21:07 schwemmer

Okay, it's still valid than. Do you get the same requiresSlugs() errors with the newest Statamic version? Or just 404 pages?

heidkaemper avatar Jul 31 '24 08:07 heidkaemper

I think we were getting a Call to a member function routeData() on null. I will make sure to take a note of the detailed error message next time it occurs.

schwemmer avatar Jul 31 '24 15:07 schwemmer

I think this issue is still valid in general, but the path issue @heidkaemper outlined I wouldn't consider an issue. You should run the commands in the docker container. 👍

jasonvarga avatar Jul 31 '24 20:07 jasonvarga

Chiming in that we appear to be running into this on almost every deploy and it's not a good time!

I'd thought I resolved it by updating our pipeline to use the more aggressive cache clear of artisan optimize like so: php artisan optimize && php please static:warm but it is continuing to happen. We see 404's on all URL's and this is resolved by clearing the application cache via the Statamic CP.

PHP 8.3.9 Statamic 5.18.0

benlilley avatar Aug 02 '24 04:08 benlilley

I think its also related to this one, i have the same problem. https://github.com/statamic/cms/issues/10025

jbreuer95 avatar Aug 05 '24 08:08 jbreuer95

We separated the stache from the application cache so we won't have to clear the stache and warm it again on each deployment. After this change, our application did not have the 404 problems for about 2 weeks, over multiple deploys. Today, however, I had to run php please stache:clear and the problem immediately returned. Last time this happened, it was caused by php artisan optimize:clear and fixed by reloading PHP FPM Workers. This time, it was caused by stache:clear and not fixed by reloading FPM workers but by running artisan optimize:clear twice. Very strange! When the 404s happened, I noticed, that a segment was missing from the URL. The URL is something like domain/en/projects/project_name/about and it was missing the "projects" part. The entire sub-navigation was also gone and came back after running optimize:clear twice. We only see the 404s on pages that are nested 2 levels in the collection tree. My wild guess is, that clearing the stache messes up the URL structure somehow.

I hope this helps with debugging this mysterious issues. Would be great, if we didn't have to worry anymore about broken production sites.

schwemmer avatar Aug 07 '24 10:08 schwemmer

Another observation on this behaviour is that it appears to be time based in some way? I need to do more testing to confirm but we get 404's across entire sites on the first deploy in a certain period but subsequent deploys within an hour or two do not exhibit the same behaviour even though they go through the exact same pipeline commands.

I'll also note that we're seeing these site wide 404s on all of our Statamic V5 projects (didn't happen on V4) with manually clearing the Application Cache being the only resolution which is problematic when we have various people triggering deploys at times, including content editors.

benlilley avatar Aug 09 '24 05:08 benlilley

Is there any update on this? One of our production sites still breaks on every deploy until we manually refresh the stache multiple times.

schwemmer avatar Aug 28 '24 15:08 schwemmer

Sorry, we don't have any updates on this since we haven't been able to reproduce it ourselves. Is anyone able to reproduce the issue reliably and is able to provide acess to their site for debugging?

duncanmcclean avatar Aug 28 '24 17:08 duncanmcclean

Thanks, @duncanmcclean. I can give you access to our staging server or our repo to test it locally.

I'm not sure if this is related, but it might be. Lately I am getting this error when run php please stache:clear locally:

php please stache:clear
php a
   Error

  Call to a member function id() on null

  at vendor/statamic/cms/src/Stache/Repositories/EntryRepository.php:163
    159▕
    160▕     public function applySubstitutions($items)
    161▕     {
    162▕         return $items->map(function ($item) {
  ➜ 163▕             return $this->substitutionsById[$item->id()] ?? $item;
    164▕         });
    165▕     }
    166▕
    167▕     public function updateUris($collection, $ids = null)

  1   [internal]:0
      Statamic\Stache\Repositories\EntryRepository::Statamic\Stache\Repositories\{closure}()
      +64 vendor frames

  66  [internal]:0
      Statamic\Stache\Query\EntryQueryBuilder::Statamic\Stache\Query\{closure}("publications")

You would think this is a data issue (and maybe it is), but when I run the same command again a second time, it passes with no errors. So maybe there is some sort of race condition going on.

schwemmer avatar Aug 28 '24 20:08 schwemmer

While I can't open up our sites for debugging purposes I have managed to work around this for now. From Statamic 3-4 our pipeline looked like this (simplified for clarity):

- composer install
- npm ci --cache .npm && npm run build
- php artisan route:clear
- php artisan cache:clear
- rsync files to server
- ssh user@server cd /application && sed -i cache_timestamp .env &&
- && php please static:warm

This worked reliably for a couple of years, but after Statamic 5 this resulted in a 404 on every single page post deploy which would be fixed after clearing cache via the CP. After various attempts to resolve this I found the following process works reliably across all of our sites (simplified again):

- composer install
- npm ci --cache .npm && npm run build
- rsync files to server
- ssh user@server cd /application && sed -i cache_timestamp .env &&
- php artisan optimize:clear && 
- php artisan optimize && 
- php please stache:refresh && 
- php please static:warm"

TL;DR since Statamic 5 we have needed to refresh all Laravel caches, and the stache after the rsync to the server, and then finally warm the static cache.

Hopefully this helps other people at least avoid this issue/bug for now and potentially gives a reproduction path.

benlilley avatar Aug 28 '24 22:08 benlilley

@schwemmer Access to a repository would be great, thanks!

duncanmcclean avatar Aug 29 '24 09:08 duncanmcclean

@duncanmcclean I'll send you the details.

schwemmer avatar Aug 29 '24 13:08 schwemmer

@duncanmcclean I have the same bug. Steps to reproduce:

  1. install composer global require statamic/cli
  2. statamic new {project-name} --> Statamic v5.25.0
  3. install [Afan417/blogo-starter-kit] starterkit
  4. php please multisite
  5. add one more language (english)
  6. Add English to Pages collection + propagate=true
  7. Create a page
  8. Clear all cache via admin panel
  9. Change a pages structure with nested pages (without saving)
  10. Remove the created page
  11. Save the structure changes + accept english version removing (Localizations=delete) via popup
  12. open Any page ---> 404 error (page exist in CP)
  13. only cache clear or stache warm helps

Note: I can reproduce the bug for Statamic v5.02 and v5.25.0

OleksiiBrylin avatar Sep 12 '24 15:09 OleksiiBrylin

I added some fix before it will be fixed. (Note: it can hit performance, as it calls multiply times per collection tree saving) app/Providers/AppServiceProvider.php

use Statamic\Events\CollectionTreeSaved;
use Illuminate\Support\Facades\Event;
use Statamic\Facades\Stache;

public function boot(): void
    {
        Event::listen(function (CollectionTreeSaved $event) {
            Stache::warm();
        });
    }
    

OleksiiBrylin avatar Sep 13 '24 08:09 OleksiiBrylin

In one project, we now have problems with 404 pages several times a week.

Setup:

  • Statamic 5.30.0
  • Multisite
  • Stache Watcher set to false
  • PHP 8.3

In the project a queued job runs every morning and updates many entries. We use Entry::saveQuietly() and Entry::delete($entry) methods to not trigger any listeners.

And at the very end, just before that job completes, we run Artisan::call('statamic:static:clear') and Artisan::call('cache:clear') to clear the cache and force stache and static cache to rebuild.

Sometimes this works just fine. And sometimes the website only has 404 pages afterwards. There are no errors in log files.

I noticed one particular thing: stache:refresh seems not work in a queued job. In a synced job or a command, however, it works without any problems.

I am currently considering switching from flat file to elequent to avoid the problem.

heidkaemper avatar Oct 23 '24 07:10 heidkaemper

Sometimes this works just fine. And sometimes the website only has 404 pages afterwards. There are no errors in log files.

We're also still experiencing the same issue. Can't put a finger on when it happens, but looks like it is sometimes after a deployment. The deployment script runs statamic:stache:warm.

  • Statamic 5.30.0
  • Multisite
  • Stache Watcher set to false
  • PHP 8.3

Setup is the same as @heidkaemper, except for Statamic being version 5.25.0 and static caching set to half. Clearing the cache manually one more time solves the 404 pages, but of course not the ideal situation.

Hopefully this information can help debugging the issue.

JorisOrangeStudio avatar Oct 23 '24 07:10 JorisOrangeStudio

@duncanmcclean Have you been able to look into this? We are still having this issue, every once in a while after a deploy, random pages don't work anymore and it's a pretty big problem. Production sites stop functioning properly.

schwemmer avatar Nov 23 '24 14:11 schwemmer

Sorry, I haven't yet. I'll see if I can find some time in the next week or so to take a look.

duncanmcclean avatar Nov 23 '24 15:11 duncanmcclean

I had a look into this for a few hours last week but I couldn't manage to reproduce the 404s... both using the repo provided & following the reproduction steps on a fresh install.

I remember trying various things to break it but I never saw any false 404s. I'll try and loop back to this at some point with a fresh head and try again.

duncanmcclean avatar Dec 03 '24 12:12 duncanmcclean

@duncanmcclean in this issue https://github.com/statamic/cms/issues/10025 (that is prob the same issue as this one) there are some more people who outlined steps to reproduce it, if you are having trouble with it.

jbreuer95 avatar Dec 16 '24 11:12 jbreuer95