Motivation: speed up watchdog calls

watchdog uses module_implements, which is totally cached and knows that module_hook exists. module_invoke goes and calls module_hook which does another function_exists.

Since already know the function exists, how about just calling the function?

CommentFileSizeAuthor
#19 1861604-19.patch1.17 KBDavid_Rothstein
#18 1861604-18.patch648 bytesjoseph.olstad
#12 1861604-12.patch648 bytesSivaji_Ganesh_Jojodae
#11 drupal-watchdog-1861604-11.patch648 bytesmgifford
#9 drupal-watchdog-1861604-9.patch686 byteshefox
#5 drupal_watchdog-module_invoke-1861604-5.patch584 byteshefox
#2 drupal_watchdog-module_invoke-1861604-2.patch604 byteshefox
watchdog_module_invoke-6.x-do-not-test.patch499 byteshefox
watchdog_module_invoke.patch603 byteshefox
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

Status: Needs review » Needs work

The last submitted patch, watchdog_module_invoke.patch, failed testing.

hefox’s picture

hefox CreditAttribution: hefox commented
Status: Needs work » Needs review
FileSize
drupal_watchdog-module_invoke-1861604-2.patch604 bytes

Guess I could end the line with ;

marcingy’s picture

marcingy CreditAttribution: marcingy commented
Category: feature » task
Priority: Minor » Normal
Status: Needs review » Reviewed & tested by the community

Looks good.

webchick’s picture

webchick
she/they
Primary language English
Location Vancouver 🇨🇦
CreditAttribution: webchick commented
Status: Reviewed & tested by the community » Patch (to be ported)
Issue tags: +Performance, +Needs backport to D6, +Needs backport to D7

Makes sense to me.

Committed and pushed to 8.x. Moving to 7.x for backport and adding some tags.

hefox’s picture

hefox CreditAttribution: hefox commented
Version: 8.x-dev » 7.x-dev
FileSize
drupal_watchdog-module_invoke-1861604-5.patch584 bytes

:)

hefox’s picture

hefox CreditAttribution: hefox commented
Status: Patch (to be ported) » Needs review
tstoeckler’s picture

tstoeckler
he/him
Primary language German
Location Essen, Germany
CreditAttribution: tstoeckler commented
Version: 7.x-dev » 8.x-dev
Status: Needs review » Needs work

Sorry to re-open this, but it seems since nothing is done with the return value of the function call, a simple module_invoke_all('watchdog', $log_entry) would be enough. module_invoke_all() does the additional function_exists() as well, but at least it would be in-line with code elsewhere. We should then discuss whether to remove that function_exists() from module_invoke_all() in a follow-up issue. That would be a performance improvement across core. Also, someone should probably dig where and why this code was introduced, i.e. if this was intentional for some reason.

Edit: Fix arguments in example code.

hefox’s picture

hefox CreditAttribution: hefox commented

That was my first thought. My reasoning to do this instead:

1) Module_invoke_all uses call_user_func_array, which is significantly slower than $function()
2) Don't need any of the extra logic about return value/array_merge that module_invoke_all adds so might as well not do any extra.

#329012: Remove call_user_func_array() from ModuleHandler::invoke() + invokeAll() is issue to optimize module_invoke_all and does include the removal of function_exists (when that lands, reason 2 above is still the case).

(note: Can look to see how other's are using module_implements solo style by looking at http://api.drupal.org/api/drupal/core!includes!module.inc/function/calls... -- it is true most that are using it alone want to use the return value and add module implementing specific information)

hefox’s picture

hefox CreditAttribution: hefox commented
Status: Needs work » Needs review
FileSize
drupal-watchdog-1861604-9.patch686 bytes

I did some benchmarking like stuff a few weeks ago and concluded the savings isn't really worth it, so patch to change it to module_invoke_all (untested) attached

I did not touch

  if (!$in_error_state && function_exists('module_implements')) {

it looks like module_implements has moved to the same file as watchdog, so is there any reason for this function_exists?

ParisLiakos’s picture

ParisLiakos CreditAttribution: ParisLiakos commented
Version: 8.x-dev » 7.x-dev
Issue summary: View changes

No logger applies to D8, hook_watchdog is gone

mgifford’s picture

mgifford
he/him
Primary language English
CreditAttribution: mgifford commented
FileSize
drupal-watchdog-1861604-11.patch648 bytes

reroll.

Sivaji_Ganesh_Jojodae’s picture

Sivaji_Ganesh_Jojodae CreditAttribution: Sivaji_Ganesh_Jojodae commented
FileSize
1861604-12.patch648 bytes 
$ git apply -v drupal-watchdog-1861604-11.patch
Checking patch includes/bootstrap.inc...
Hunk #1 succeeded at 1732 (offset 1 line).
Applied patch includes/bootstrap.inc cleanly.

Patch #11 still applies but with offset so I have re-rolled the same.

  • webchick committed e200408 on 8.3.x 
    Issue #1861604 by hefox: Skip module_invoke()/module_hook() in calling...
  • webchick committed fcfd874 on 8.3.x
    Issue #1861604 follow-up: Now with a semi-colon. :P

  • webchick committed e200408 on 8.3.x 
    Issue #1861604 by hefox: Skip module_invoke()/module_hook() in calling...
  • webchick committed fcfd874 on 8.3.x
    Issue #1861604 follow-up: Now with a semi-colon. :P

  • webchick committed e200408 on 8.4.x 
    Issue #1861604 by hefox: Skip module_invoke()/module_hook() in calling...
  • webchick committed fcfd874 on 8.4.x
    Issue #1861604 follow-up: Now with a semi-colon. :P

  • webchick committed e200408 on 8.4.x 
    Issue #1861604 by hefox: Skip module_invoke()/module_hook() in calling...
  • webchick committed fcfd874 on 8.4.x
    Issue #1861604 follow-up: Now with a semi-colon. :P
dagmar’s picture

dagmar
Primary language Spanish
Location Argentina
CreditAttribution: dagmar as a volunteer and at Globant commented
Component: watchdog.module » dblog.module

Moved to dblog.module for future triage.

joseph.olstad’s picture

joseph.olstad
Primary language French
CreditAttribution: joseph.olstad commented
Status: Needs review » Reviewed & tested by the community
Issue tags: -Needs backport to D7 +Drupal 7.60 target
FileSize
1861604-18.patch648 bytes

Done in D8. So green light for D7

Patch #12 still applies but with offset so I have re-rolled the same.

***EDIT*** David Rothsteins patch below is the preferred.

David_Rothstein’s picture

David_Rothstein CreditAttribution: David_Rothstein as a volunteer commented
Status: Reviewed & tested by the community » Needs review
FileSize
1861604-19.patch1.17 KB

Shouldn't we change the function_exists() call earlier in watchdog() to check the function that we're now actually calling? See attached.

Otherwise, this looks fine to me and is a nice code cleanup, although I assume any performance benefit here is very very minor.

Pol’s picture

Pol
the/that
Location Brussels
CreditAttribution: Pol at European Commission and European Union Institutions, Agencies and Bodies for European Commission and European Union Institutions, Agencies and Bodies commented
Status: Needs review » Reviewed & tested by the community

Tested locally, working super fine.

joseph.olstad’s picture

joseph.olstad
Primary language French
CreditAttribution: joseph.olstad commented

yes David Rothstein to the rescue again
put it in, creds to David!

Slam dunk this.

Pol’s picture

Pol
the/that
Location Brussels
CreditAttribution: Pol at European Commission and European Union Institutions, Agencies and Bodies for European Commission and European Union Institutions, Agencies and Bodies commented
Issue tags: -Needs backport to D6 +Pending Drupal 7 commit
joseph.olstad’s picture

joseph.olstad
Primary language French
CreditAttribution: joseph.olstad commented
Issue tags: -Drupal 7.60 target +Drupal 7.61 target

Bumping to 7.61. This didn't make it into 7.60

joseph.olstad’s picture

joseph.olstad
Primary language French
CreditAttribution: joseph.olstad commented
Issue tags: -Drupal 7.61 target +Drupal 7.62 target
joseph.olstad’s picture

joseph.olstad
Primary language French
CreditAttribution: joseph.olstad commented
Issue tags: -Drupal 7.62 target +Drupal 7.64 target

  • Pol committed 902980e on 7.x 
    Issue #1861604 by hefox, joseph.olstad, Sivaji, mgifford, webchick: Skip...
Pol’s picture

Pol
the/that
Location Brussels
CreditAttribution: Pol at European Commission and European Union Institutions, Agencies and Bodies for European Commission and European Union Institutions, Agencies and Bodies commented
Status: Reviewed & tested by the community » Fixed
Issue tags: -Drupal 7.64 target, -Pending Drupal 7 commit +Drupal 7.67 target

Patch has been committed, thanks !

Status: Fixed » Closed (fixed)

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