Maximum execution time exceeded in HtmlFilter.php

Created on 28 October 2023, about 1 year ago
Updated 11 November 2023, about 1 year ago

Problem/Motivation

Setup

  • Solr version:
  • Drupal Core version:9.5.11
  • Search API version:1.30.0
  • Search API Solr version:4.3.0
  • Configured Solr Connector:

Issue

I have a search api solr system that's been running for a while on 1.29.0. I just upgraded from Drupal 9.5.9 to 9.5.11.

- Upgrading drupal/search_api (1.29.0 => 1.30.0)
- Upgrading drupal/search_api_solr (4.2.10 => 4.3.0)
- Upgrading drupal/search_api_attachments (dev-9.0.x 2e29312 => dev-9.0.x 0d4f5a5)

I created a new solr core and downloaded configs.zip files to it's /conf directory before connecting it to Drupal app. Search Solr API says it can reach it.

Since this upgrade, I am getting these timeouts pretty consistently:

[Fri Oct 27 21:38:57.415327 2023] [php:error] [pid 2594] [client 172.31.29.184:57214] PHP Fatal error:  Maximum execution time of 600 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 255, referer: https://demo9.mysite.com/batch?id=285&op=start
[Fri Oct 27 21:39:15.770739 2023] [php:error] [pid 4789] [client 172.31.29.184:24808] PHP Fatal error:  Maximum execution time of 240 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 244, referer: https://demo9.mysite.com/admin/reports/dblog
[Fri Oct 27 21:41:22.826438 2023] [php:error] [pid 4843] [client 172.31.29.184:48294] PHP Fatal error:  Maximum execution time of 600 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 257, referer: https://demo9.mysite.com/batch?id=287&op=start
[Fri Oct 27 21:45:02.948096 2023] [php:error] [pid 2837] [client 172.31.29.184:3918] PHP Fatal error:  Maximum execution time of 600 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 255, referer: https://demo9.mysite.com/batch?id=289&op=start
[Fri Oct 27 21:48:08.510133 2023] [php:error] [pid 4843] [client 172.31.29.184:60288] PHP Fatal error:  Maximum execution time of 240 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 257, referer: https://demo9.mysite.com/admin/config/search/search-api
[Fri Oct 27 21:52:21.345170 2023] [php:error] [pid 5980] [client 172.31.29.184:42414] PHP Fatal error:  Maximum execution time of 240 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 244, referer: https://demo9.mysite.com/admin/reports/auditfiles/notindatabase

I can't figure out why? I did search the issue queue for HtmlFilter.php, but see no issue regarding timeout.

Steps to reproduce

Updated Drupal core from 9.5.9 to 9.5.11

Upgraded these search api modules, created new solr core using updated config.zip:

- Upgrading drupal/search_api (1.29.0 => 1.30.0)
- Upgrading drupal/search_api_solr (4.2.10 => 4.3.0)
- Upgrading drupal/search_api_attachments (dev-9.0.x 2e29312 => dev-9.0.x 0d4f5a5)

Now, every time I try to index the Solr index, the screen stays frozen on "initializing" and eventually times out with this error on screen:

An AJAX HTTP error occurred.
HTTP Result Code: 504
Debugging information follows.
Path: /batch?id=279&op=do_nojs&op=do
StatusText: error
ResponseText: 
504 Gateway Time-out
504 Gateway Time-out

No errors in dblog, but I see a variety of these in the web server logs: HtmlFilter.php errors on lines 255, 244, 257.

[Fri Oct 27 21:38:57.415327 2023] [php:error] [pid 2594] [client 172.31.29.184:57214] PHP Fatal error:  Maximum execution time of 600 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 255, referer: https://demo9.mysite.com/batch?id=285&op=start
[Fri Oct 27 21:39:15.770739 2023] [php:error] [pid 4789] [client 172.31.29.184:24808] PHP Fatal error:  Maximum execution time of 240 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 244, referer: https://demo9.mysite.com/admin/reports/dblog
[Fri Oct 27 21:41:22.826438 2023] [php:error] [pid 4843] [client 172.31.29.184:48294] PHP Fatal error:  Maximum execution time of 600 seconds exceeded in /var/www/html/websites/drupal9/demo9/web/modules/contrib/search_api/src/Plugin/search_api/processor/HtmlFilter.php on line 257, referer: https://demo9.mysite.com/batch?id=287&op=start

Proposed resolution

I posted an issue in the solr_search_attachments issue queue thinking the problem was there since it was the only module reporting anything: https://www.drupal.org/project/search_api_attachments/issues/3397369 πŸ› Text extraction failed after 5 attempts Fixed

But now, I'm thinking this may be the root cause of the problem.

Remaining tasks

I have no idea why these started occurring upon update of modules, or what to do about it. Any suggestions appreciated!

πŸ’¬ Support request
Status

Fixed

Version

1.30

Component

General code

Created by

πŸ‡ΊπŸ‡ΈUnited States somebodysysop

Live updates comments and jobs are added and updated live.
Sign in to follow issues

Comments & Activities

  • Issue created by @somebodysysop
  • πŸ‡ΊπŸ‡ΈUnited States somebodysysop

    Here is where it gets confusing.

    In my dblog I get:

    type: search_api
    location: search_api_attachments
    message: Could not load the following items on index Solr sbn01 index: "entity:file/28364:en".

    I get the message for file entities 28363 through 28369.

    The problem is, my file fids end at 28362. There are no fids in my file_usage or file_managed tables with these fids. I have repeatedly cleared the queue before re-indexing, but keep getting the same timeouts.

    I don't know if this is an issue with search_api or search_api_attachments.

    In any event, I can't get anywhere because the htmlfilter keeps crashing the site.

  • Status changed to Fixed about 1 year ago
  • πŸ‡ΊπŸ‡ΈUnited States somebodysysop

    So, this is not a bug, per se, but a problem, I assume, with the size of my index.

    This was not actually the entire solution, but was part of it:

    https://www.drupal.org/forum/support/post-installation/2018-10-03/attemp... β†’

    Exact steps to resolve:

    Increase timeout in /etc/php.ini and httpd.conf

    Restart web server

    drush sqlq "DELETE FROM semaphore WHERE name = 'cron';" --uri=master1and1-9.schoolboard.net

    Gets rid of the cron semaphores in database

    https://www.drupal.org/forum/support/post-installation/2018-10-03/attem β†’ …

    drush cr --uri=master1and1-9.schoolboard.net

    Clears cache so that next cron run will read most current /etc/php.ini maximum execution time

    Reduce Index batch size.

    The default is 300 but I reduced it to 5.

    Re-Index

    Had to repeat the above a few times, but eventually it got through the indexing.

  • πŸ‡¦πŸ‡ΉAustria drunken monkey Vienna, Austria

    Seems like this might be the same problem as reported in πŸ› Performance issues after fixing 'PHP 8.1 preg_replace()' issue Needs review . Please try whether the patch I posted there resolves the problem for you.
    It’s good you were able to work around it, but such an immense decrease in indexing performance is still not acceptable.

  • πŸ‡ΊπŸ‡ΈUnited States somebodysysop

    Thank you! I've got 8 more sites to go, so this will be extremely helpful.

  • πŸ‡¨πŸ‡¦Canada nruest

    Applying the patch mentioned in #4 solved the issue for me.

  • πŸ‡ΊπŸ‡ΈUnited States somebodysysop

    I got this error when trying to install Search API 8.x-1.x-dev in Drupal 9.5.11:

    Problem 1
    - drupal/search_api[dev-1.x, 1.x-dev] require drupal/core ^10.0 -> found drupal/core[10.0.0-beta1, ..., 10.1.6] but the package is fixed to 9.5.11 (lock file version) by a partial update and that version does not match. Make sure you list it as an argument for the update command.
    - drupal/search_api 1.x-dev is an alias of drupal/search_api dev-1.x and thus requires it to be installed too.
    - Root composer.json requires drupal/search_api 1.x-dev@dev -> satisfiable by drupal/search_api[1.x-dev (alias of dev-1.x)].

    Use the option --with-all-dependencies (-W) to allow upgrades, downgrades and removals for packages currently locked to specific versions.

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

Production build 0.71.5 2024