johnbillion / query-monitor

The developer tools panel for WordPress
https://querymonitor.com
GNU General Public License v2.0
1.59k stars 208 forks source link

QM contributes to infinite redirect loop at /wp-admin/ (when index.php is missing) #807

Closed MadtownLems closed 11 months ago

MadtownLems commented 1 year ago

Hello again.

You might remember me from such annoying and seemingly-unreproducible issues as https://github.com/johnbillion/query-monitor/issues/798 and https://github.com/johnbillion/query-monitor/issues/676.

I thought I had reasonable workaround for the latter above, but more and more QM-related issues popped up (see the former) so I've spent a TON of time trying to get to the root issue. I've put together what I hope is enough information that you can point me in the right direction or suggest some future debugging steps.

The issue: In our MultiSites, visiting the /wp-admin/ screen of the dashboard of the main site or any subsite that has QM activated results in an infinite redirect loop - but only when the "index.php" portion of the dashboard is not present.

Examples: mysite.edu/wp-admin/ is an infinite loop mysite.edu/wp-admin/index.php works fine mysite.edu/subsite/wp-admin is an infinite loop mysite.edu/subsite/wp-admin/index.php works fine

The environment: WordPress 6.2.2, Apache 2.4, PHP 8.0. Twenty Twenty-two theme No other plugins (including mu-plugins)

An important note is that we have several networks across two servers. On Dev, we cannot reproduce this issue at all. It just never happens. On Prod, the issue exists on every network there. All networks run from the same codebase.

I have done my absolute best to find what might be different between the two servers (diff-ing apache and php configuration files, etc) and I've got nothing, but obviously the fact that it works on one server and not the other (and seemingly nobody else has the problem) sure leads me to thinking it's directly related something at the server level.

So, what happens when you visit /wp-admin/ without the index.php?

You end up in a series of infinite 302 redirects with the following properties: X-Qm-Redirects-Redirect-Trace: wp_redirect_admin_locations(), do_action('template_redirect') X-Redirect-By: WordPress

I hacked up this installation to add an aggressive amount of logging and have compared the working /wp-admin/index.php request to the not-working /wp-admin/ version.

The working (/wp-admin/index.php) version looks like you'd expect, going through all the normal steps: wp-admin/index.php wp-admin/admin.php yadda yadda then the shutdown action hook fires, QM does its varying dispatching, and we're done.

The non-working (/wp-admin/) version looks identical for the first 309 steps I've logged (including reaching the very end of /wp-admin/index.php)... but then goes on to load wp-blog-header.php as if it were doing a front-end request (???). And we are now in infinite loop land, where it looks like the front end processing stuff thinks "hey this should be redirected to the admin!" but at the end of that admin request, it shoots us ovre to wp-blog-header.php again and away we go. I am baffled.

In an earlier ticket, you mentioned I could try removing various collectors until the problem went away, so I tried that again here.

QM hacks that make the page load:

1) Deleting query-monitor/collectors/assets_scripts.php makes the page load as expected. Restoring the file breaks it again. I tried to hack up assets_scripts.php to figure out exactly what part of it was making things wonky, but I tried just about everything I can think of, basically returning empty arrays instead of the lists of actions/filters, and trying to comment out individual actions/filters, but the only hacks that ever made it work were either just removing the registration of the collector. (Note that removing assets_styles.php does NOT fix the issue, but assets_scripts.php does).

2) Hacking Collector_Assets.php in one of two ways

2a. function actionhead() If I "return;" just before $dependencies = $GLOBALS[ "wp{$type}" ]; - the page loads. If I instead comment out that line - the page loads.

Note that the line seems to "work". If I tell it loop over the newly fetched $dependencies and log them, it can. For example, $dependencies->done includes: 'jquery-core', 'jquery-migrate', etc.

OR (meaning doing either hack 2a or 2b makes the page load; it doesn't have to be both)

2b. function action_print_footer_scripts() If I "return;" any time before $this->data->footer = array_diff( $dependencies->done, $this->data->header ); - the page loads. Trying to return after it does not.

Note that, again, the lines seem to 'work'. If I loop over the data and log them, i get stuff like: $dependencies->done includes 'jquery-core', 'jquery-migrate'... $this->data->header includes 'jquery-core', 'jquery-migrate', 'jquery', 'utils', 'query-monitor' $this->data->footer includes 'hoverIntent', 'wp-polyfill-inert'

So, after what I'm guessing is ~75 hours of trying to figure out what the heck is going on, that's what I've got. I'm hoping that the details laid out here might give some possible idea of what I could try exploring next to get to a solution. Query Monitor is an essential development and debugging tool, so I realllly want to get it functioning again. As always, I'm very thankful for your time and expertise, and I'm (clearly) more than happy to try any additional debugging steps or provide additional information you think might be useful.

Cheers and thanks 🙏

MadtownLems commented 1 year ago

Another morning of debugging, and just wanted to add a few more notes:

I'm still wracking my brain figuring out how requests without index.php seem to "magically" move on to requesting the front-end of the site. The request sure looks to reach the end of /wp-admin/index.php, with a status code of 200, and no Location headers set.

[11-Aug-2023 16:41:54 UTC] wp-admin/index.php - Very end of file
[11-Aug-2023 16:41:54 UTC] Shutdown_action_hook - just BEFORE do_action shutdown
[11-Aug-2023 16:41:54 UTC] Looping over headers_list()
[11-Aug-2023 16:41:54 UTC] Header: Expires: Wed, 11 Jan 1984 05:00:00 GMT
[11-Aug-2023 16:41:54 UTC] Header: Cache-Control: no-cache, must-revalidate, max-age=0
[11-Aug-2023 16:41:54 UTC] Header: Referrer-Policy: strict-origin-when-cross-origin
[11-Aug-2023 16:41:54 UTC] Header: X-Frame-Options: SAMEORIGIN
[11-Aug-2023 16:41:54 UTC] Header: Content-Type: text/html; charset=UTF-8
[11-Aug-2023 16:41:54 UTC] Header: Set-Cookie: wp-settings-2=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/; secure
[11-Aug-2023 16:41:54 UTC] Header: Set-Cookie: wp-settings-time-2=1691772114; expires=Sat, 10-Aug-2024 16:41:54 GMT; Max-Age=31536000; path=/; secure
[11-Aug-2023 16:41:54 UTC] Query Monitor:Overview.php - START of process_timing
[11-Aug-2023 16:41:54 UTC] Query Monitor:Overview.php - END of process_timing
[11-Aug-2023 16:41:54 UTC] Query Monitor:AJAX.php - START of dispatch
[11-Aug-2023 16:41:54 UTC] Query Monitor:AJAX.php - not dipatching
[11-Aug-2023 16:41:54 UTC] wp_ob_end_flush_all START
[11-Aug-2023 16:41:54 UTC] wp_ob_end_flush_all END
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php -> START of dispatch()
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php - START of before_output
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php - END of before_output
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php - START of after_output
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php - END of after_output
[11-Aug-2023 16:41:54 UTC] Query Monitor:Html.php -> END of dispatch()
[11-Aug-2023 16:41:54 UTC] load.php - Shutdown_action_hook - just AFTER do_action shutdown
[11-Aug-2023 16:41:54 UTC] Looping over headers_list()
[11-Aug-2023 16:41:54 UTC] Header: Expires: Wed, 11 Jan 1984 05:00:00 GMT
[11-Aug-2023 16:41:54 UTC] Header: Cache-Control: no-cache, must-revalidate, max-age=0
[11-Aug-2023 16:41:54 UTC] Header: Referrer-Policy: strict-origin-when-cross-origin
[11-Aug-2023 16:41:54 UTC] Header: X-Frame-Options: SAMEORIGIN
[11-Aug-2023 16:41:54 UTC] Header: Content-Type: text/html; charset=UTF-8
[11-Aug-2023 16:41:54 UTC] Header: Set-Cookie: wp-settings-2=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/; secure
[11-Aug-2023 16:41:54 UTC] Header: Set-Cookie: wp-settings-time-2=1691772114; expires=Sat, 10-Aug-2024 16:41:54 GMT; Max-Age=31536000; path=/; secure
[11-Aug-2023 16:41:54 UTC] Status Code: 200 // from http_response_code

The only notable difference is that requests that lack the "index.php" string in the URL continue on to....

[11-Aug-2023 16:41:54 UTC] wp-blog-header: BEFORE wp()
[11-Aug-2023 16:41:54 UTC] class-wp.php: start of main(). just before init
[11-Aug-2023 16:41:54 UTC] class-wp.php: just after init

and thus the infinite redirect loop begins.

One interesting note is that when I watch the network tab of Chrome dev tools, there isn't a single response with the 200 status code. The very first request to /wp-admin/ returns 302 with the Location Headers as mentioned in yesterday's post.

So what could possibly be happening after confirming we've reached the end of the /wp-admin/index.php file with a status code of 200 AND after looking at (I believe) everything that's been registered as a shutdown function?

For completeness sake, here is the .htaccess file for the network:

RewriteEngine On
RewriteRule .* - [E=HTTP_AUTHORIZATION:%{HTTP:Authorization}]
RewriteBase /
RewriteRule ^index\.php$ - [L]

RewriteRule ^([_0-9a-zA-Z-]+/)?wp-admin$ $1wp-admin/ [R=301,L]

RewriteCond %{REQUEST_FILENAME} -f [OR]
RewriteCond %{REQUEST_FILENAME} -d
RewriteRule ^ - [L]
RewriteRule ^([_0-9a-zA-Z-]+/)?(wp-(content|admin|includes).*) $2 [L]
RewriteRule ^([_0-9a-zA-Z-]+/)?(.*\.php)$ $2 [L]
RewriteRule . index.php [L]

<IfModule mime_module>
  AddHandler application/x-httpd-ea-php80 .php .php8 .phtml
</IfModule>
MadtownLems commented 11 months ago

This has been resolved by increasing ModSecurity's SecRequestBodyLimit. See more in https://github.com/johnbillion/query-monitor/issues/798