[4.x]: Internal Server Error when creating new fields

stevefloat commented 1 year ago

What happened?

Description

When creating a new field, the browser hangs and finally returns an Internal Server Error. This is not a Craft error but a (MAMP) server error. Here's the error from my Apache log:

[Fri Mar 17 11:48:43.486687 2023] [fastcgi:error] [pid 40930] [client ::1:56351] FastCGI: comm with server "/Applications/MAMP/fcgi-bin/php8.0.24.fcgi" aborted: idle timeout (30 sec), referer: http://xxx/admin/settings/fields/new?groupId=3&site=default
[Fri Mar 17 11:48:43.495330 2023] [fastcgi:error] [pid 40930] [client ::1:56351] FastCGI: incomplete headers (0 bytes) received from server "/Applications/MAMP/fcgi-bin/php8.0.24.fcgi", referer: http://xxx/admin/settings/fields/new?groupId=3&site=default

Note that for PHP 8.0.24 I have a max_execution_time set to 120

It appears the field has been created when I reload the Fields page. I'm just not sure if everything has been correctly written out to the project config.

Steps to reproduce

Create a new field and press save

Expected behavior

Should return successful

Actual behavior

Server responds with an Internal Server Error after approx 30 secs

Craft CMS version

Craft Pro 4.3.10

PHP version

8.0.24

Operating system and version

Darwin 19.6.0 (MacOS 10.15 running MAMP Pro 6.8)

Database type and version

MySQL 5.7.39

Image driver and version

Imagick 3.5.1 (ImageMagick 6.9.6-2)

Installed plugins and versions

Multi-site is enabled with one additional site.

brandonkelly commented 1 year ago

Does this occur regardless of which field type you create? Or just certain ones (like a large Matrix / Super Table / Neo field)?

stevefloat commented 1 year ago

Thanks @brandonkelly. It occurs regardless of field type, even on simple fields. And also happened today when creating a new Section.

It happens after submitting the form. And the field/section is still created, despite the internal server error.

brandonkelly commented 1 year ago

Hm, there’s no reason those requests should take 30+ seconds. It’s got to be something environmental, external to Craft.

Do you know if you have Xdebug enabled? Sometimes we see unexpected timeouts like that if Xdebug is holding up the request, even if there’s no active listeners.

My personal experience has been that MAMP works great, until it doesn’t, due to some weird issue that suddenly crops up like this one, and it’s never very clear where to look or how to fix. (Which is why we recommend going with DDEV instead.)

angrybrad commented 1 year ago

@stevefloat +1 for the DDEV recommendation - Maybe try swapping from Apache to nginx in MAMP and see if that helps?

stevefloat commented 1 year ago

Thanks both

Xdebug is not enabled.

I appreciate DDEV may be a good/better dev environment, however I'm running lots of projects and now is not really a good time to be updating to a new workflow.

I guess I need to try and understand at what point things are failing. So I know where to look. For this project I've just gone from Craft 3 -> 4, PHP 7 -> 8 and MAMP 5 -> 6.

As I mentioned the new Craft fields/sections are being saved, and it looks like any new project-config file are being generated.

Would you be able to suggest where to look, thinking about what Craft does next after writing out the project config? For instance something missing in PHP, a permission issue, or something else?

And can I rule out the fact that I'm running a multi-site Craft project?

I'll continue looking myself but any insight would be appreciated.

Thanks!

brandonkelly commented 1 year ago

As I mentioned the new Craft fields/sections are being saved, and it looks like any new project-config file are being generated.

Interesting. In that case I’d guess that the request isn’ getting terminated properly by craft\web\Response::sendAndClose(), which is called before Craft starts processing new queue jobs that were added during the request.

Try setting runQueueAutomatically to false in config/general.php, and see if that helps. If it does, you will need to keep track of whether there are new queue jobs pending, and run the queue manually when needed:

php craft queue/run --verbose

stevefloat commented 1 year ago

Thanks @brandonkelly.

I've just tried setting runQueueAutomatically to false, however the same thing still happens.

Page takes over 20 secs to respond then I see Internal Server Error. New section is created once I go back in and there's a project-config file present for the newly created section.

angrybrad commented 1 year ago

@stevefloat does swapping from Apache to nginx for that site in MAMP change the behavior?

stevefloat commented 1 year ago

Haven't tried Nginx yet

However, after coming across this article: https://documentation-5.mamp.info/en/MAMP-PRO-Mac/Troubleshooting/General/I-am-getting-the-following-errors-in-my-PHP-error-log-FastCGI-incomplete-headers-0-bytes-received-from-server/index.html

I've enabled Xdebug in MAMP. As the error outlined in that article is exactly what I was seeing.

This now prevents the Internal Server Error and the page load completes. However, it took 47 seconds to load - this was a request to create a new Single section.

It's like by enabling Xdebug, the 30 second timeout has been removed, therefore preventing the error.

47 seconds does feel like an awfully long time for this action to complete!

brandonkelly commented 1 year ago

47 seconds does feel like an awfully long time for this action to complete!

It certainly is.

I wonder if any plugins or modules may be interfering with the operation, which is causing the longer delay. You could try it with all plugins disabled by setting the disabledPlugins config setting to '*' in config/general.php.

If you have any custom modules installed, you would need to remove those manually by commenting out your modules and bootstrap settings in config/app.php.

stevefloat commented 1 year ago

Thanks @brandonkelly

I've just tried adding disabledPlugins => '*' to the general config (and could see plugins had disappeared from left menu), however the request to create a new single section still took 44 seconds.

So it doesn't seem like this is the issue.

stevefloat commented 1 year ago

Not sure if this is relevant, however I wanted to add that the Craft build is not a new Craft 4 project. But one that was originally Craft 3 and was recently upgraded to 4 (following the guidance at https://craftcms.com/docs/4.x/upgrade.html)

brandonkelly commented 1 year ago

The more I think about it, the more I think this must be some sort of internal request routing issue in MAMP.

Craft doesn’t update project config YAML files until the very end of the request. So if you’re getting updated YAML even when the request was timing out, then the request handling must be getting fully wrapped up by Craft (including writing to YAML) before the request starts to hang on something.

I agree with @angrybrad that switching to Nginx would be a good first step.

pc-erin commented 1 year ago

We have this issue on a site as well.

We had some issues migrating to 4, where it appeared to work in staging, then after the database was moved to the prod server it said it needed to be migrated again, which had some errors. We tried a couple more times and it eventually seemed to work. Not sure if that's related or a different bug.

When I tried to pull a copy of the current db down to staging for testing on the field creation issue, I noticed that I couldn't import it. Postgres said it was trying to create indexes without columns. I checked the SQL file and the index creations for users looks like this:

CREATE INDEX "idx_cnyqkpsokdnezgbvskfpgqwpwzstpthjaaio" ON "public"."users" USING btree ("pending");

CREATE INDEX "idx_gywikzgjhdgzanacprxbuxqnbzerllyskhcm" ON "public"."users" USING btree ("active");

CREATE INDEX "idx_kozyjrxhnjoyyupktlabxxbjkzvyfrpnsmtn" ON "public"."users" USING btree ("verificationCode");

CREATE INDEX "idx_qfwkkzncoivsotpggxlxfkofnevwbhrblzdz" ON "public"."users" USING btree ("");

CREATE INDEX "idx_rtgswaoqieqmstndvqukrpcerdfscjzcwsdj" ON "public"."users" USING btree ("");

CREATE INDEX "idx_wsbvycdyvjhwnnmakvoulekhkbqbljthagda" ON "public"."users" USING btree ("suspended");

CREATE INDEX "idx_yvaizgulbdekqatzokfuqnicnsslzfngessy" ON "public"."users" USING btree ("locked");

There's an even odder one on elements_sites:

CREATE INDEX "idx_cfgzquspjawitjhycpbsjomvwzntpkevncrt" ON "public"."elements_sites" USING btree ("", "siteId");

CREATE INDEX "idx_iemztniaixqyvlwbqmjavqyndiupawcntbhq" ON "public"."elements_sites" USING btree ("siteId");

CREATE INDEX "idx_mkcsiaplancrniewkaiqojivwwhdxtkueaan" ON "public"."elements_sites" USING btree ("slug", "siteId");

CREATE INDEX "idx_rrqszgbzvkjcvqkukawlvwuhsyvcfaalelmb" ON "public"."elements_sites" USING btree ("enabled");

Again, not sure if this is related, but it seems like it's also a problem. Gonna try to clear and recreate the indexes and see if that helps.

brandonkelly commented 1 year ago

@pc-erin Email support@craftcms.com if you need any help with it!

craftcms / cms