humanmade / tachyon-plugin

WordPress plugin for Tachyon
https://engineering.hmn.md/projects/tachyon/
82 stars 15 forks source link

Illegal string offset #60

Open pdewouters opened 4 years ago

pdewouters commented 4 years ago
[14-Aug-2020 10:20:42 UTC] PHP Warning:  Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 667undefined
pdewouters commented 4 years ago

I get the same when importing posts with WP CLI

Processing post #61218 ("john-lynch") (post_type: attachment)
-- 85 of 9,269 (in file example.wordpress.2020-08-21.000.xml)
-- Fri, 21 Aug 2020 13:16:42 +0000
Warning: Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 588
Warning: Illegal string offset 'height' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 589
Warning: Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 592
Warning: Illegal string offset 'height' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 592
Warning: Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 610
Warning: Illegal string offset 'height' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 610
kadamwhite commented 3 years ago

This has started to occur dozens to hundreds of times each minute in a production environment following the deployment of Altis 5.

PHP Warning:  Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 588
PHP Warning:  Illegal string offset 'height' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 589
PHP Warning:  Illegal string offset 'width' in /usr/src/app/vendor/humanmade/tachyon-plugin/inc/class-tachyon.php on line 592

same spread of warnings experienced by @pdewouters

Lines 587 through 592 of that file:

// Prevent upscaling.
$image_args['width'] = min( (int) $image_args['width'], (int) $full_size_meta['width'] );
$image_args['height'] = min( (int) $image_args['height'], (int) $full_size_meta['height'] );

// Respect $content_width settings.
list( $width, $height ) = image_constrain_size_for_editor( $image_meta['width'], $image_meta['height'], $size, 'display' );

This error is correlated in logs with the following errors within WP core's media code:

PHP Warning:  A non-numeric value encountered in /usr/src/app/wordpress/wp-includes/media.php on line 458
PHP Warning:  A non-numeric value encountered in /usr/src/app/wordpress/wp-includes/media.php on line 467
PHP Warning:  A non-numeric value encountered in /usr/src/app/wordpress/wp-includes/media.php on line 468

The relevant lines are within the wp_constrain_dimensions function. wp_constrain_dimensions is called from within image_constrain_size_for_editor, and the error occurs because invalid values are being passed as the width and height. There

kadamwhite commented 3 years ago

@nathanielks' investigation of the production spike we saw in these after deploy was because object cache had an empty value for certain records. We believe that wp_cache_delete( {id}, 'post_meta' ) on the affected records resolves the issue.

nathanielks commented 3 years ago

To add on the above, this is what I did to discover the issue. It starts with this script:

wp db query \
  "select id from wp_posts where post_type = 'attachment' and post_mime_type like 'image/%' order by post_modified_gmt desc limit 1000;" \
  --skip-column-names \
  --silent \
| xargs -I % -P 8 bash -c \
  'FOO=%; exec > >(sed "s/^/$FOO: /"); exec 2> >(sed "s/^/$FOO: /"); wp eval-file /tmp/detect-warnings.php $FOO'

The above script will spawn up to 8 parallel executions of wp eval-file, otherwise this would take forever. The script depends on /tmp/detect-warnings.php existing:

<?php
error_reporting(E_ALL);

if ( ! $args[0] ) {
    die();
}
echo 'processing' . PHP_EOL;
$image_meta = wp_get_attachment_metadata( $args[0] );
$image_meta['width'];

This will produce log output like:

286690: processing
286686: processing
286682: processing
286678: processing
286653: processing
286639: processing
286639: 286639: Warning: Illegal string offset 'width' in phar:///usr/local/bin/wp/vendor/wp-cli/eval-command/src/EvalFile_Command.php(76) : eval()'d code on line 9
286639: 286639: Notice: Uninitialized string offset: 0 in phar:///usr/local/bin/wp/vendor/wp-cli/eval-command/src/EvalFile_Command.php(76) : eval()'d code on line 9

The ID of the attachment is prepended to each log item, which I could then use for testing a specific post attachment.

I queried a specific post to see if attachment metadata existed in the database, and it did:

select * from wp_posts p join wp_postmeta pm on p.ID = pm.post_id where p.ID = <ID in question>;

This led me to think it was an object cache issue. Sure enough:

$ wp shell
wp> $attachment_id = 289380;
=> int(289380)
wp> $image_meta = wp_get_attachment_metadata($attachment_id)
=> string(0) ""
wp> wp_cache_delete( $attachment_id, 'post_meta' )
nathanielks commented 3 years ago

I hit enter before I could complete. All that to say, clearing the object cache should resolve these errors/warnings. That said, I do not presently know why the object cache was filled with an empty value. That remains to be investigated.