False positives when identifying what is a placeholder, for deprecation error

This has become a much bigger problem, because this now generates an warning when running D10 (see #3295625: Remove deprecated code from FormattableMarkup → ), causing test failures.

I discuss in 📌 [10] Fix automated test results - Support for keys without a placeholder prefix is deprecated (Rules) Fixed why this core behavior is wrong:

I looked at this a bit and my impression is that this is a false positive caused by the difference between PSR-3 logging used by Symfony and Drupal logging. The former uses different placeholders and has different parameters, and Drupal core performs some gymnastics to bend its logging into the shape required for Symfony.

For example, the Symfony log($level, $message, array $context = []) requires that $message is a string with PSR-3 placeholders, and $context is an array of placeholder replacements and other things. While Drupal logging (e.g. the messenger service) requires a message string to be either a plain string or a FormattableMarkup object created by t($message, array $placehoders), but specifically there is no separate argument for placeholders.

It's those "other things" in $context that are causing a problem - they are not being passed as placeholders, but as additional data needed by the logger at a different point in the code. Thus they don't have prefixes like placeholders do, and they shouldn't need prefixes. It seems to me that the deprecation notice is being a little too aggressive when checking prefixes, because it's assuming everything in $context is a placeholder when that's not true.

Drupal does have a compatibility layer, which we use already. See for example this code in RulesLog:

     // Convert PSR3-style messages to \Drupal\Component\Render\FormattableMarkup
    // style, so they can be translated at runtime.
    $message_placeholders = $this->parser->parseMessagePlaceholders($message, $context);

There may be a workaround to avoid this deprecation notice by artificially renaming some of the keys in the $context array so that they look like placeholder keys, but that's not something I'm interested in investigating right now.

additionally mentioned in that issue:

From https://api.drupal.org/api/drupal/vendor%21psr%21log%21Psr%21Log%21Logge...

The context array can contain arbitrary data. The only assumption that can be made by implementors is that if an Exception instance is given to produce a stack trace, it MUST be in a key named "exception".

So in this case, the Symfony specification clearly states that $context is not used just for Drupal placeholders, meaning the keys do not have to conform to Drupal placeholder key names with prefix.

And specifically in some cases you MUST use a key named "exception", which would also trigger the above deprecation notice.

This strengthens my initial impression that this deprecation is a false positive in our case, caused by Drupal core being too aggressive at identifying what is a placeholder. So if I were going to work on this (which I'm not, at the moment), the way I would approach it is to investigate that core Drupal deprecation notice with the intention of rolling a patch for core to remove the assumption about the contents of the $context array.

Note since the time I originally posted this api.drupal.org has stopped hosting the API doc page for the Symfony LoggerInterface, so you'll have to find that on your own ...

I tried to duplicate this on D11 and it worked as expected, without warnings. What's a snippet that shows the problem?

\Drupal::logger('test')->info('test is @test', ['@test' => 'test', 'test' => 'test']);
\Drupal::logger('test')->log(1, 'test2 is @test', ['@test' => 'test', 'test' => 'test']);

I was able to see warnings by following the instructions at 🐛 D10 "Invalid placeholder (context) with string" error Fixed

The merge request I added to this issue only calls trigger_error if a key starts with a non-alphanumeric character. A key of context wouldn't cause a warning, but *context would.

Am i missing something? i see the issue fork, but no merge request/patch to test.

I might have done the merge request wrong, but the only file I changed is this:

https://git.drupalcode.org/issue/drupal-3173103/-/blob/3173103-false-pos...

I don't think that has changed much between versions so you can probably just post it into a D10/D11 installation.

Or, click 'Show commands' above and follow those instructions.

Thanks TolstoyDotCom. I'm using views_conditional and have been having issues with this ( https://www.drupal.org/project/views_conditional/issues/3347741#comment-... 🐛 D10 "Invalid placeholder (context) with string" error Fixed ), but can confirm that the changes in #15 stop the error messages that were flooding the logs. For the record, the site is using 10.0.9 and views_conditional 1.5.

#17 I created the MR, now you can put just the .diff :

https://git.drupalcode.org/project/drupal/-/merge_requests/4528.diff

Thanks!

Thanks. patch applied cleanly to 10.1.2

+1 patch works well for 10.1.2

Please note that the patch from #8 and my changes in #15 are different, mine is a more generalized solution.

I've since changed core/tests/Drupal/Tests/Component/Render/FormattableMarkupTest.php to deal with the changes to core/lib/Drupal/Component/Render/FormattableMarkup.php. Hopefully that will cause the test to succeed. If anyone has any ideas for other tests please let me know.

Is #15 a reasonable solution or does anyone have a better way to do this?

Nice addition of ctype_alnum.

Lets see what committers say!

Verified the tests fail without the fix too.

I think we could almost consider dropping the warning entirely, but there is some benefit in keeping it for users that previously were used to the ! syntax that is no longer allowed. As we ignore valid placeholders that aren't present in the string, ignoring entirely-invalid placeholders that don't begin with a special character also seems fine.

Backported to 10.1.x as a low risk bug fix.

Committed and pushed e1a599bedd to 11.x and 08fa3c2ea2 to 10.1.x. Thanks!

Automatically closed - issue fixed for 2 weeks with no activity.