We're seeing the following error:
#0 [internal function]: field_tokens()
#1 /web/core/lib/Drupal/Core/Extension/ModuleHandler.php(403): call_user_func_array()
#2 /web/core/lib/Drupal/Core/Utility/Token.php(304): Drupal\Core\Extension\ModuleHandler->invokeAll()
#3 /web/modules/contrib/token/token.tokens.inc(937): Drupal\Core\Utility\Token->generate()
#4 [internal function]: token_tokens()
#5 /web/core/lib/Drupal/Core/Extension/ModuleHandler.php(403): call_user_func_array()
#6 /web/core/lib/Drupal/Core/Utility/Token.php(304): Drupal\Core\Extension\ModuleHandler->invokeAll()
#7 /web/modules/contrib/filelog/filelog.tokens.inc(135): Drupal\Core\Utility\Token->generate()
#8 [internal function]: filelog_tokens()
#9 /web/core/lib/Drupal/Core/Extension/ModuleHandler.php(403): call_user_func_array()
#10 /web/core/lib/Drupal/Core/Utility/Token.php(304): Drupal\Core\Extension\ModuleHandler->invokeAll()
#11 /web/core/lib/Drupal/Core/Utility/Token.php(196): Drupal\Core\Utility\Token->generate()
#12 /web/modules/contrib/filelog/src/Logger/FileLog.php(223): Drupal\Core\Utility\Token->replace()
#13 /web/modules/contrib/filelog/src/Logger/FileLog.php(157): Drupal\filelog\Logger\FileLog->render()
#14 /web/core/lib/Drupal/Core/Logger/LoggerChannel.php(127): Drupal\filelog\Logger\FileLog->log()
#15 /web/core/includes/errors.inc(175): Drupal\Core\Logger\LoggerChannel->log()
#16 /web/core/includes/errors.inc(83): _drupal_log_error()
#17 /web/core/includes/bootstrap.inc(346): _drupal_error_handler_real()
#18 /web/core/lib/Drupal/Core/Cache/DatabaseBackend.php(121): _drupal_error_handler()
#19 /web/core/lib/Drupal/Core/Cache/DatabaseBackend.php(92): Drupal\Core\Cache\DatabaseBackend->getMultiple()
#20 /web/core/modules/page_cache/src/StackMiddleware/PageCache.php(306): Drupal\Core\Cache\DatabaseBackend->get()
#21 /web/core/modules/page_cache/src/StackMiddleware/PageCache.php(124): Drupal\page_cache\StackMiddleware\PageCache->get()
#22 /web/core/modules/page_cache/src/StackMiddleware/PageCache.php(82): Drupal\page_cache\StackMiddleware\PageCache->lookup()
#23 /web/core/lib/Drupal/Core/StackMiddleware/ReverseProxyMiddleware.php(48): Drupal\page_cache\StackMiddleware\PageCache->handle()
#24 /web/core/lib/Drupal/Core/StackMiddleware/NegotiationMiddleware.php(51): Drupal\Core\StackMiddleware\ReverseProxyMiddleware->handle()
#25 /vendor/stack/builder/src/Stack/StackedHttpKernel.php(23): Drupal\Core\StackMiddleware\NegotiationMiddleware->handle()
#26 /web/core/lib/Drupal/Core/DrupalKernel.php(708): Stack\StackedHttpKernel->handle()
#27 /web/index.php(19): Drupal\Core\DrupalKernel->handle()
#28 {main}
When filelog module and page_cache is enabled and DatabaseBackend->getMultiple() throw's a fatal error.
This is the most similar error I've seen. It looks like when page_cache throws a fatal error (i.e. before a full bootstrap is done), file logging module calls token replace, which doesn't exist yet.
Maybe filelog should skip token hooks when logging page_cache errors?
| Comment | File | Size | Author |
|---|---|---|---|
| #4 | 3270867-call-to-undefined-function-_token_module-4.patch | 466 bytes | firewaller |
Show commandsStart within a Git clone of the project using the version control instructions.
Or, if you do not have SSH keys set up on git.drupalcode.org:
changes, plain diff MR !9changes, plain diff MR !5
Comments
Comment #2
firewaller commentedComment #3
cburschkaThis looks tough. There's nothing immediately going wrong when calling the token service; the failure is buried far down in the call-stack where it reaches the token contrib module. I'm not sure if this means the token service is generally unsafe to call in early bootstrap (which would mean we must check the bootstrap level before calling it), or only if specific contributed modules are installed.
As far as I'm aware though, undefined function errors *can* be caught by try-catch though, so this may be fixed by coding a bit more defensively: Wrapping the render() in a try-catch and falling back to skipping the log message entirely. (Rendering without tokens isn't useful; the output would simply be a copy of the template string. I suppose we could "defer" logging by storing the message in a state variable for later, but that'd be a substantial new feature for a later version.)
Comment #4
firewaller commentedSo something like this short-term and then adding a "defer" feature separately?
Comment #7
churel commentedHello,
Php 7 is able to catch errors but only if we catch them Error or Throwable. Added the render function in the try, and adding a catch for Throwable works for me
Comment #8
cburschkaIndeed; the undefined function error is not caught with \Exception.
Also note that the catch block should probably exit the function, as without rendering the log message cannot be logged.
Edit: I didn't see the merge request now has both the rendering and the file-writing in the try block, which fixes the above.
Comment #9
cburschka@churel, were you able to confirm that this fixes the problem when logging before the full bootstrap? I don't have a setup for reproducing this problem myself so I can't really test it.
Comment #10
churel commented@cburschka Yes, the fatal error got caught and the page displays correctly now for me.
Comment #11
mr_fenix commentedHello,
I have tested this with Drupal 9.3 (with a standard profile), PHP 7.4, and filelog 2.0.x-dev(Currently it also is applicable to other versions)
I was not able to reproduce the exactly same error inside the method cache Drupal\Core\Cache\DatabaseBackend->getMultiple() following the information given here, also it seems complex tokens of the type [log:user:url] were used. However,i am sure the idea is the filelog does not report errors from the PageCache MiddleWare service. Indeed this is the case - I've tested it.
When the Drupal\page_cache\StackMiddleware\PageCache->handle service is invoked, all services are initialized at this stage, but the files of type tokens.module (*.module) are not loaded yet (hook_tokens won't work in these files - core tokens functionality purely support early calls too), so this error is a result of the token module not supporting calls at early stages (as it uses functions from the token.module file), and you could test this simply by uninstalling the token module for example.
Also, there is another problem. When an error is logged from the PageCache MiddleWare service at this stage, the "public" Stream Wrapper is not initialized yet, and as a result, if the root directory is writable, a folder named logs will be created in the web root directory and all next errors in this request will be logged in logs/drupal.log in the web directory. Maybe a check needs to be done for the existence of the "public" Stream Wrapper before opening the file for writing.
Summarizing:
1. Early calls support seems to need to be fixed in the ,token module.
2. This patch is a partial solution, the error in the log file is still not logged when it appears at the early stages of PageCache MiddleWare Service.
3. When the public Stream Wrapper is not defined, errors are logged in a different place - web/logs/drupal.log
So, the patch #5 needs to be updated according to point (3) at least. Ideally, there should be a functionality to log to the drupal.log file (2), or get it ignored if the token module gets fixed and starts supporting calls from MiddleWare services (for those running before Drupal\Core\DrupalKernel MW) (1).
Also, I will add that after this patch implementation if an error occurs during token processing, that error will be logged only in the PHP error log instead of the drupal.log file, which also seems to need to be fixed. For this, the module's functionality might need to be changed to create its own token processing system, to be only partially dependent on the token functionality, and when there is an error in token parsing, to have the ability to log this also to the drupal.log file, using an alternative (implementable without the token module functionality) error message formatting.
Thanks
Comment #14
astonvictor commentedComment #17
astonvictor commentedwas not able to reproduce it with drupal 10.2. anyway added a try catch in case.