Errors in `ms-files.php` aren't logged

[iandunn]

r12936 added error_reporting(0) to ms-files.php. This makes troubleshooting problems like #53492 much harder.

I haven't groked #11742 yet, but 11742.2.diff describes the reason as:

Sets error_reporting to 0, removing requirement for a new SHORTLOAD constant and error suppression operators.

My guess is that the goal is to prevent PHP notices/warnings from breaking the image output. That makes sense, but it could be accomplished with ini_set( 'display_errors', 'off' ), without hiding errors from logs.

[iandunn]

ticket:11742#comment:8 adds more context. Before 11742.2.diff, 11742.diff had taken this approach:

In order to be completely backwards compatible, I needed to create a new SHORTLOAD constant that is identical to SHORTINIT. This prevents an existing blogs.php drop-in that defines SHORTINIT from generating an unsuppressed E_NOTICE for redefining a constant.

So when error_reporting(0) was added in 11742.2.diff, the goal was really just to hide those specific notices.

However, 12742.5.diff intended it to hide all notices, similar to what the REST API, admin-alax.php, and XML-RPC do today:

Return error_reporting(0) to ms-files.php, reverting [13038]. Remove deprecated warnings as it breaks media file handling, and no translation support exists, reverting part of [12977].

[iandunn]

Added a PR in ​https://github.com/WordPress/wordpress-develop/pull/1437, but it doesn't look like prbot pulled it in.

FYI @desrosj, @noisysocks

[iandunn]

it doesn't look like prbot pulled it in

Oh, it looks like it saw two Trac links, and chose the first and ignored the second. That makes sense.

[iandunn]

#53492 has reproduction steps

[iandunn]

In 51358:

Multisite: Log error/warnings/notices from ms-files.php.

Previously errors were not displayed or logged, but the original intention was only to prevent them from being displayed. Hiding them from logs makes problems like #53492 much harder to debug.

This makes the handling of errors in ms-files consistent with the REST API, admin-ajax, and XML-RPC.

Props iandunn, johnjamesjacoby.
Fixes #53493.

[hellofromTonya]

Reopening as errors reported during installation, see #54801. As 5.9 is in RC and this bug was not introduced in the 5.9 cycle, I propose reverting [51358] and moving to 6.0 cycle for further testing, db audit, and resolution with plenty of alpha/beta/rc soak time.

[iandunn]

Yeah, reverting sounds good to me if that's the most practical option. I am a confused by a few things, though:

• r51358 was only supposed to enable logging errors, not displaying them. Has this been reproduced in a browser, or just WP-CLI? If it's only WP-CLI, then it may be related to how ​it doesn't always respect WP_DEBUG.
• The change should also only effect ms-files.php (multisite media proxying), which doesn't seem related to wp core is-installed. Does reversing this commit locally fix that CLI command?
• The change was committed 6 months ago, at the start of the 5.9 cycle, so it seems odd that it wasn't discovered until just now.

Regardless, though, the most important thing is a smooth release, so if y'all are confident then reverting sounds good.

[schlessera]

Let me try to reply to the questions above.

Replying to iandunn:

• r51358 was only supposed to enable logging errors, not displaying them. Has this been reproduced in a browser, or just WP-CLI? If it's only WP-CLI, then it may be related to how ​it doesn't always respect WP_DEBUG.

What the change does is to go from suppressing errors in a specific context to not suppressing errors in a specific context. Whether they are sent to the logs, displayed or manipulated in some other way depends on the environment. However, no matter what the environment is, the previous behavior was to "not have errors at all", which now changed.

• The change should also only effect ms-files.php (multisite media proxying), which doesn't seem related to wp core is-installed. Does reversing this commit locally fix that CLI command?

Yes, reverting the commit fixes that command. The errors appear as soon as the MULTISITE define is found in the wp-config.php, which triggers loading the ms-files.php. Then, the multisite bootstrapping is supposed to figure out the exact topology from the database, which throws WPDB errors depending on the state of the site. These errors were always present, what were suppressed. The DB calls in Core that can potentially fail with an error but are necessary are all wrapped in a $wpdb->suppress_errors() structure, except for the multisite one in question here, as no one noticed they produced errors due to the error_reporting( 0 ).

• The change was committed 6 months ago, at the start of the 5.9 cycle, so it seems odd that it wasn't discovered until just now.

I have seem them much earlier, but the combination of PHP 8.1 and latest Core trunk has had so many breaking changes that it took quite a while to distill everything and figure out the root cause for everything. In the beginning, I assumed it was a typing error or similar.

[iandunn]

Ah, I see, thanks! 👍🏻

The only thing that still doesn't make sense to me is this:

The errors appear as soon as the MULTISITE define is found in the wp-config.php, which triggers loading the ms-files.php.

The only entrypoint I see to ms-files.php is by calling it directly w/ the /files/ rewrite endpoint.

But it sounds like you're saying it's include'ed by wp-load.php / ms-load.php? I'm sure you're right, I'm just curious about what I'm missing.

[schlessera]

Replying to iandunn:

The errors appear as soon as the MULTISITE define is found in the wp-config.php, which triggers loading the ms-files.php.

The only entrypoint I see to ms-files.php is by calling it directly w/ the /files/ rewrite endpoint.

Hmm, you're right, there's no reason why that should be triggered... Guess I have to continue the investigation!

[hellofromTonya]

Where do this stand for RC3? Tomorrow is currently the last RC release before final next week. Reverting removes the reported issue, though doesn't truly fix it.

@schlessera have you found more information?

[iandunn]

🤔, I'm not seeing the error locally w/ WP-CLI 2.5.0 and 5.9-beta4-52408-src. That's w/ PHP 8.0.6 and Multisite.

What are the steps/conditions to reproduce?

[hellofromTonya]

Re-reading @schlessera description in #54801, the 2 db errors are triggered on empty sites when using wp core is-installed command. @iandunn what happens for you when using this command?

[iandunn]

Ah, my bad, I was trying it w/ a DB_NAME that hadn't been created yet. The db needs to exist, but not have the WP tables in it. Thanks!

With that, I can see an error, but there're some differences from Alain's screenshot. I only see the wp_blogs error, not the wp_sitemeta one; and the stack trace is absent.

> wp core is-installed
Error: WordPress database error: [Table 'misc.wp_blogs' doesn't exist]
SELECT  wp_blogs.blog_id FROM wp_blogs  WHERE domain = 'wp-develop.test' AND path = '/'  ORDER BY wp_blogs.blog_id ASC LIMIT 1

I tried reverting r51358, but that didn't hide the error for me. I tried reverted back to 5.6 and still saw the error.

I also tried putting exit() statements in ms-files.php and wp_debug_mode(), to verify that they weren't being called, and neither statement was triggered. That makes sense, since ms-files.php is unrelated, and WP-CLI ​uses it's own error handling. Those are the only two things that r51358 touched, though.

[hellofromTonya]

Replying to schlessera:

Replying to iandunn:

The errors appear as soon as the MULTISITE define is found in the wp-config.php, which triggers loading the ms-files.php.

The only entrypoint I see to ms-files.php is by calling it directly w/ the /files/ rewrite endpoint.

Hmm, you're right, there's no reason why that should be triggered... Guess I have to continue the investigation!

As @schlessera and @iandunn discussed, changeset [51358] does not seem to be the root cause of the issue reported in #54801. And in additional investigative testing, @costdev and @peterwilsoncc also found db errors are reproducible going back to at least 4.2.

Reclosing this ticket as fixed. Thank you everyone for your care in discussing and investigating this issue.