Drupal suffers under certain circumstances from a heavy loss of performance.

The issue appears when a module loads a node within module_init(), with the locale module enabled and displaying a page in a language other than English. One example for such a module is the Organic Groups module.

I will outline the execution tree for a typical page request:
Starting with _drupal_bootstrap_full(), where module_init() is called before locale_initialize(), which is bad as we'll see later on.
module_init() calls then hook_init(). Now our 3pd module comes into play: og_init() causes the node (assuming we're on /node/something) to be loaded (in og_theme() -> og_set_theme()). node_load() subsequently calls hook_node_info(), which, in turn, calls t(). But, as $locale is neither initialized at that point nor is it checked if it is initialized, this causes locale() to fetch all language strings one by one from the database (Devel module is your friend).

Possible resolutions:
- move locale_initialize() into module_init(), after loading the module list and before invoking hook_init()

  global $locale;
  // Load all the modules that have been enabled in the system table.
  foreach (module_list(TRUE, FALSE) as $module) {
    drupal_load('module', $module);
  }
  $locale = locale_initialize();
  module_invoke_all('init');

- check if $locale is initialized before accessing the cache in locale()

  // Store database cached translations in a static var.
  if (!isset($locale_t)) {
    if (!isset($locale)) {
      $locale = locale_initialize();
    }
    $cache = cache_get("locale:$locale");

Two locations to patch are probably overkill, but funny enough the smtp module does exactly what would still not be allowed: it calls t() in the global namespace, ie. when it is include()d. The second patch would allow exactly that. (Although I had already submitted a patch for smtp's issue, I have never heard something again).

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

killes@www.drop.org’s picture

I think the best thing would be that og,module rethinks the way it uses the init hook, current usage seems to be a bg sink of ressources.... I can however see that moving locale_initialize before invoking the init hook would make sense. However, I am not sure that no module depends on the current order, maybe i18n woudl be affected.

smk-ka’s picture

Please, this bug report shouldn't be about og, it's about using t() from hook_init().

From a quick peek at i18n, there doesn't speak anything against defining $locale before hook_init(), as $locale isn't touched.

The execution times mentioned in this thread (#24 and #29) remind me somewhat of this bug. Execution times above 1500ms fell down to 50-100ms, even with the "bloated" Organic Groups installed ;)

smk-ka’s picture

FileSize
1.14 KB

Patch against 4.7.1 and applying only the first solution (read: using t() outside a function or before hook_init() isn't supported). Those suffering from high execution times and are using localization together with Organic Groups should definitly test this patch. Those using SMTP support module need to do further patching.

killes@www.drop.org’s picture

Status: Active » Needs review
FileSize
829 bytes

better patch.

smk-ka’s picture

No, localization_init() checks if a user defined function i18n_get_lang() exists, that's why I've moved it between the loading of the modules and the hook_init() calls.

smk-ka’s picture

FileSize
880 bytes

Because of the high relevance of the bug (another candidate possibly affected, if he's using og on a localized site), I've backported the patch for 4.6.7.

killes@www.drop.org’s picture

ok, this makes sense then.

Dries’s picture

* smk-ka's patch is a bit of hack. Adding locale specific code to module.inc is not an option. Sorry.

* Gerhard: fix_gpc_magic() might need to be called before calling locale_initialize()?

* I don't understand how this patch obtains a performance improvement. module_init() loads all the modules, including locale.module? How can you move locale_initialize before the loading of the locale module? Please elaborate on how this improves performance? Thanks.

smk-ka’s picture

FileSize
4.39 KB

@Dries
locale_initialize() isn't moved before the loading of the modules, it is moved before hook_init() gets called on all modules. This is because when a module now uses the t() function (by loading a node, for example, because this invokes node_info() and that's where t() is used), $locale isn't set. The uninitialized $locale variable is then passed to the cache handler in locale(): $cache = cache_get("locale:$locale");. The cache handler, in turn, doesn't find a cache for cid='locale:', which causes the localization cache to be invalidated(?) and read again from the source table (I didn't further investigate why locale() behaves the way it does, the error happens before).

I've attached two SQL dumps from the Devel module, maybe this makes understanding the impact of this bug a bit easier, as it is really hard to describe.

killes@www.drop.org’s picture

A simple fix would be to check if $locale is set before calling locale() inside t(). then t() would not be avilable from the init hook. Not sure this would be a problem, though.

pwolanin’s picture

I posted an issue a while back because I found that node_get_types() does not return t-ified node names:

http://drupal.org/node/63033

The usage was from within organic groups, so this thread caught my eye. I'm wondering if this bug has the same root cause?

smk-ka’s picture

@Killes
Nah, that would add a lot of overhead (think about the frequency of t() calls). The second solution that I offered in my initial post did nearly the same, but more efficiently: it checks if $locale is properly initialized only when locale() is called the very first time, that is, when the cache hasn't been read, yet (ie, the static variable $locale_t isn't set).

Thinking again about it, it seems that the second solution is probably the better one, as it keeps localization specific code together and is efficient.
(The reason why I initially preferred the first solution was based on a false assumption: I thought it would be possible that a module relies on $locale to be defined within its hook_init() implementation, but the point of this whole issue is that $locale never was available at that point in time. So the first solution would add more than exists now.)

smk-ka’s picture

@pwolanin
Confirmed, this is a direct consequence of this bug.

smk-ka’s picture

FileSize
1.1 KB

Patch using second solution - Drupal 4.7.1.

smk-ka’s picture

FileSize
1003 bytes

Same for 4.6.7.

bwynants’s picture

Hi,

I tested the second solution and pageloads went from 5648.55 to 391.77!

I also applied the indexing described on http://drupal.org/node/42463#comment-84014 and it became 367.73 ms so it's not really needed to do that

BTW: I have both og and locale enabled!

Thanks for the tip!

smk-ka’s picture

Forget the patch files #14 and #15. They only seem to work, but in reality add inconsistent behavior concerning the initialization of the $locale variable. SOrry for that..

@Bert
Please use the patch from #3 or #6, respectively, results are the same ;)

bwynants’s picture

@smk-ka can you explain what goes wrong with that? From the code it looks clean and correct.... Where do you see problems with that patch?

BTW: what changed in 4.7 about tracker? since a week the threads I replied to are not add to my tracker anymore... http://drupal.org/tracker/17123

smk-ka’s picture

FileSize
1.02 KB

Bert, it will most likely work *now*, but may break in the future. That's because currently, the localization system is initialized right after the modules have been initialized. Patch files #14/15 move l10n init into the t() function, so now it is initialized when t() is called for the first time. Which simply isn't predictable and could easily introduce new bugs, when a module relies on the global $locale variable, for example.

@all
I've made a new patch, which is a combination of the original code, and the patch from #14. It does circumvent the above said by duplicating a bit of code, that is, by checking in both common.inc and the locale.module if l10n has already been initialized (and doing so if not).

Dries’s picture

Hi smk-ka, I like the patch in #15 but don't understand why it might cause problems. I tried to come up with a scenario that would introduce bugs, but couldn't. Can you think of any?

bwynants’s picture

@smk-ka: I can follow what you mean, so definitely #19 is better as #15

Thanks!

vancelee’s picture

Hi smk-ka, I am reading about your new patch as in #19, it seems like it's a 4.7.1 patch right? So what does we finally need to do with 4.6.7?
Thank you very much for your kind help!

smk-ka’s picture

@Dries et al
Let me try to summarize the differences of the three patches. First, keep the following in mind:
The root of this issue was the use of the localization system at a point when it was still not initialized. In particular, the uninitialized global variable $locale causes the caching in the locale() function to fail:
$cache = cache_get("locale:$locale").
A similar line could easily (and legally) be used by any 3rd party module to store l10n specific cache data.

The question now is, when should we initialize the l10n system, and by which method.

  • currently $locale isn't available until after bootstrapping, particulary not during hook_init().
  • #3 is - after all - still my favorite, because it makes $locale available at the earliest point in time, that is, before calling hook_init(). So any modules that expose hook_init() can be sure the localization system has already been initialized and make use of it. That's in fact the biggest difference from the following patches.
  • #14 leaves the $locale variable uninitialized until t() or locale() are first called. This is unacceptable, as no module can be sure l10n has been initialized before, and would have to check for itself.
  • #19 sets $locale
    • during hook_init(): when a module calls t() or locale() `by chance'
    • after hook_init(): during normal bootstrapping

    This means that, if a module wants to access $locale (but not t() as in the caching example) during hook_init(), it *still* cannot do so, but would have to initialize l10n `by hand'. (Admittedly, I do not know any module that tries to do that, but it's IMO just a matter of time until that happens...)

Then, there is still this line in the t() function:

if (function_exists('locale') && $locale != 'en') {
  $string = locale($string);
}

With the latter two patches, $locale isn't initialized during the very first call, so we're entering locale() where we currently do not. Killes' idea of moving l10n initialization into the t() function would be a solution (see #10).

Probably the cleanest solution would be to allow accessing $locale only through a getter function that would take care of initialization (which unfortunately cannot be done before 4.8).

I hope this round-up helped a bit,
Stefan

smk-ka’s picture

Patch #19 backported to 4.6.7

smk-ka’s picture

This is what the API could look like in the future: no more global $locale, but a nice getter function. IMO we should concentrate on that, and choose whatever patch does the trick for now (Possibly #19 but moving the $locale-check from locale() into t(), like Killes suggested).

Dries’s picture

This is unacceptable, as no module can be sure l10n has been initialized before, and would have to check for itself.

I don't understand this part. I'm still trying to understand why/when #14 will fail.

smk-ka’s picture

Since the locale init was removed from bootstrap and moved into t(), it would fail if a module relies on the $locale variable, but t() has never been called before.
For example on a fresh Drupal installation without any 3dp modules, I couldn't tell you when t() is first called: not during hook_init(), also not during bootstrapping because it's been removed, so I guess it must be somewhere within the menu system code... Contrary to the current code, where you can be sure $locale is initialized after bootstrapping.

ardas’s picture

I have the problem which I described here http://drupal.org/node/66254
Please tell me is reason the same ?

smk-ka’s picture

@Duke
Yes, it is. Any patch from above will fix it (it doesn't matter which one).

adixon’s picture

I'm happy to see this discussion, thanks Stefan. I'd also noticed the problem (http://drupal.org/node/64336) but hadn't gotten around to doing anything about it except the mysql amelioration solution (i.e. add an index).

Although this discussion is a general one about hook_init and the t() function, I think the example of og is a good one, because it runs quite a lot of code in og_init, which also triggered a different bug here: http://drupal.org/node/66331. So, maybe some of this og_init code should be in the hook_menu (yeah, a different discussion), but the point being that the world of hook_init is pretty unpredictable, which sounds like a recipe for unstable code.

So:

1. if we knew locale ran it's hook_init first, that might solve the problem, but I get the feeling that's a bad thing. Or is it? i18n and og also are negotiating about setting locale (yes, later on), and there's og negotiating with simple_access and lots of other modules about the node_access rules. Maybe this is the place where such negotiations should happen? Allow sites to set module "weights" (and allow modules to provide default weights) that determine the order of the hook invocations? In this case, locale would typically be weighted at -8, say, and i18n at -7, og at -1, and simple_access at -5? But if you wanted the permission features of og that could be overridden by simple_access, you could move simple_access up? Yeah, i'm probably missing some historical context here ...

2. maybe we just need more clarity for developers about the world of hook_init (i.e. more rigor about what functions can be accessed, what kind of side effects can be allowed).

3. i wonder if moshe can give us some insight into why he put so much code into hook_init and whether there's a way to move some of it elsewhere (and return to a purer, simpler world in the hook_init phase).

adixon’s picture

Okay, since you said #3 was your favourite, and also because it was the simplest, i just tested patch #6 on 4.6 (technically, civicspace 8.3) site with i18n, og modules installed and caching turned on. I'll probe more, but on first test, the patch breaks some i18n stuff: one example is the i18nmenu module (a module that allows you to translate your menus). i18nmenu doesn't implement hook_init, so I suspect something about the locale being cached is getting broken.

smk-ka’s picture

From a closer look at i18n, it seems that currently all patches break i18nmenu.
However, it's easy to fix this by cutting the function i18n_get_lang() from i18n.inc and paste it to the end of i18n.module. This makes the required init code available when it's needed (no need for a module load order system here).

adixon’s picture

hmm, well it wasn't giving an error, it just wasn't working (e.g., when i switched to french, the menus didn't switch). I followed your suggestion and it still doesn't (but maybe you were only solving part of the problem?)

Dries’s picture

Yes, the _init is special, and prone to mistakes. The fact that _init is called before the modules are actually loaded is documented (it's a very important feature). Using the _init hook also negatively effects page caching (also an important feature).

It's best if this problem can be resolved in og.module. If we fix it in Drupal core, it might affect the page generation time of both cached and non-cached pages.

Let's wait for Moshe's opinion on this. I'm tempted to mark this "won't fix", but that doesn't prevent the same mistakes from being made again ...

killes@www.drop.org’s picture

There is a suggestion pending that would most likely remove og's dependency on the init hook:

http://drupal.org/node/66155

adixon’s picture

1. hook_init - okay, perhaps the page here:
http://api.drupal.org/api/head/function/hook_init
can be more alarming. Something like:

For example, any code that might trigger a call to the translation function t() will cause lots of uncached mysql calls to try and translate strings.

Hmm, that could be more alarming.

2. og - yes, let's fix og_init, i've replied to your post.

pwolanin’s picture

Does this issue really just apply to OG? Above: http://drupal.org/node/65801#comment-103536
suggests it also applies to the path access module, and there may be others as well.

Dries’s picture

There are quite a few modules that are incorrectly using the _init hook. Such modules hurt the performance of your site.

pwolanin’s picture

So, I'm looking at the og.module code, and it looks as though the main function (as dicussed above) being implemented through hook_init is setting the theme. Would this work if it was done in hook_menu? I just townloaded the taxonomy_theme module, and the theme switching does seem to be done in hook_menu there.

pwolanin’s picture

FileSize
1.32 KB

attached is a patch for og.module that moves the the setting of the theme to hook_menu from hook_init as per suggestion above. Initial testing looks fine- the custom group theme is still loaded, and the problem I referenced in http://drupal.org/node/65801#comment-102515 of the content names not being translated is solved.

I will cross-post this in the og issue queue.

moshe weitzman’s picture

Title: Performance issue » locale initialization slowness
FileSize
1.51 KB

i looked at this for quite a while today.

i agree with smk-ka and killes that modules should know that locale has been initialized before they run their init hooks. the unintialized locale variable is what causes the extra queries. so patch #3 is almost ideal. it only falls down because of prettiness objection of locale specific code in module.inc. so i propose the attached patch which keeps module.inc clean in favor of reordering in in common.inc. the order is

1. load all modules
2. initialize locale system
3. invoke hook_init() for all

patch attached. please test.

Dries’s picture

The code could do with a tad more documentation (eg. to explain why we load first and initialize later). There is also a typo in one of the code comments: reqest -> request.

Tested and benchmarked Moshe's patch and everything looks well. I couldn't spot a performance degradation. Haven't tried it with the og.module. If someone reports success, it can be committed.

Great work Moshe; it's clean and elegant.

moshe weitzman’s picture

Status: Needs review » Reviewed & tested by the community
FileSize
1.58 KB

i tried it with og and all is well now. patch attached has a tad more documentation

smk-ka’s picture

FileSize
1.3 KB

1. load all modules
2. initialize locale system
3. invoke hook_init() for all

One note about modules that provide a i18n_get_lang() function: they must make it available (ie. have it loaded) after 1) completes. OG plays nice here, i18n does not.

The attached patch makes i18n compatible with the patched core by making its i18n_get_lang() earlier available and by moving its init routine. I've tried to make it backwards compatible with the unpatched core, but haven't verified that. If I'm not totally wrong, then i18n should be the only module that needs patching.

I'm successfully testing the following setup: Drupal 4.7.2 + Moshe's patch, 2 languages, i18n + patch, og (og's i18n_get_lang() commented out). path_access has been mentioned to be affected and seems to work, too.

Congrats for a clean solution.

Dries’s picture

Project: Drupal core » Internationalization
Version: x.y.z » master
Component: base system » Code

Committed to DRUPAL-4-7 and CVS HEAD. Moving to il8n project?

SavoryMedia’s picture

So, this has been committed to the latest 4.7.2 tar.gz? Or do I need to hit up the 4-7 branch of CVS to get this? If so, which files do I need to DL and replace?

Because, seriously, using locale, OG and views as absolutely EATING my dev site's lunch. We're talking routinely 20 second to 2 *minute* page load times.

pwolanin’s picture

saml’s picture

Could anyone used to patching provide with a patched version of i18n.module please?!

(I don't succeed patching i18n.module (The latest one, Id: i18n.module,v 1.30 2006/05/31 21:50:16) with CYGWIN, using the i18n.patch above.)

In case anyone can find out what's going wrong, this is what happens:

It says: "Hunk #1 Failed at 242 -- saving rejects to file...", and saves the following code to a file named "i18n.module.rej":

***************
*** 242,260 ****
   */
  
  /**
-  * This one expects to be called first from common.inc
-  */
- function i18n_get_lang() {
-   static $i18n_language;
-   //see if the language is already set.
-   if ($i18n_language) {
-     return $i18n_language;
-   } else {
-     return $i18n_language = _i18n_get_lang();
-   }
- }
- 
- /**
   * Produces i18n paths, with language prefix
   * If path is empty or site frontpage, path = 'lang'
   * Check for frontpage and search for alias before adding language
--- 242,247 ----
   */
  
  /**
   * Produces i18n paths, with language prefix
   * If path is empty or site frontpage, path = 'lang'
   * Check for frontpage and search for alias before adding language
saml’s picture

FileSize
8.02 KB

This was all a blunder of mine. I didn't see that the patchfile wants to patch both i18n.module and i18n.inc, so I was trying to apply it only on i18n.module.
(Patched versions of i18n.inc and i18n.module attached)

saml’s picture

As I mention in http://drupal.org/node/73841 I got it working fine with Drupal-CVS of 14:th July (later versions crash my site: http://drupal.org/node/74349) and i18n.module,v 1.30 patched with the patch above.

But if I disable the i18n-modules the site is totally unreachable and I only get (on a blank page):

Fatal error: Call to undefined function: i18n_get_lang() in E:\xampplite\htdocs\herrsnellmantest\modules\i18n\translation.module on line 639

(Running XAMPP Lite version 1.4.16, which includes: Apache 2.0.54, MySQL 4.1.14 and PHP 5.0.5 + PEAR (basis package)

adixon’s picture

the translation module depends on i18n - you'll have to disable it too.

saml’s picture

Yes, true. Forgot to disable it.

Jose Reyero’s picture

Status: Reviewed & tested by the community » Fixed

Actually it was not that simple.
We still need to have some hook implementations in a separate file, because otherwise they willbreak the module administration page.

I've reorganized a lot of stuff in the module files, so it should be fixed now in 4.7

Anonymous’s picture

Status: Fixed » Closed (fixed)
smk-ka’s picture

FileSize
1.06 KB

Since every few weeks there are new reports about slow Drupal installations, I've written a small back tracer for the locale.module. It displays a message when the condition is met that leads to the performance degradation. This is the case when a buggy 3rd party module calls t() outside of a function, ie. in the global namespace.

If the slowness comes from a buggy module, you will get a Drupal error message like this:

t() called before locale finished initializing. This is a bug in the following module:
...\sites\all\modules\foo\foo.module on line xy

To regain regular site performance you can open the file and replace define(CONSTANT, t('blah')) with just define(CONSTANT, 'blah'), ie. strip the t() function call. But this means that the string 'blah' won't be translated anymore, so to completely fix the module, t() has to be called everywhere CONSTANT is used. (BTW, the CONSTANT thing is just a recurring example of this bug, the thing you should really look for is the t() call.)

If you don't have that much programming experience file a bug for the module, ie. not here.

How to patch:

  • Download the patch and copy to modules/locale/locale.module.patch
  • Execute patch -i locale.module.patch
moshe weitzman’s picture

I experienced this same slowdown when I used t() during code executed in global scope. It can happen to anyone. The patch here is more like debug code than a prod patch but still useful.

smk-ka’s picture

Yep, that's what it is intended for. I will direct people who could possibly be affected here if required. If they know how to patch, they will get an immediate result for whether it has something to do with this issue.
--
Stefan Kudwien
www.unleashedmind.com

Luneh’s picture

Hi,

My website (www.hyboria.info) is really slow as well and I am wondering if it is because of localisation.

I wanted to patch locale.module with your patch but, I don't know why, the system does not like it and keep telling me that it is not valid. So I decided that I would look at the modules manually.

Could you please explain if the problem is only with define(SOMETHING, t('blah')) functions or with other functions as well (that are not define(...) )?

Or alternatively give me a way to install the patch...

I developped everything in local and everything was fine but now that I have uploaded on the server, it is just a nightmare...

smk-ka’s picture

I've just verified that the patch still works with the latest stable Drupal release (5.1). That's what I did:
* Downloaded the patch to modules/locale
* cd modules/locale
* patch < locale.module_0.patch

Looking for define()s at the start of files sometimes works, sometimes not, it depends on the complexity of the module.

Apart from that, your site seems to be running normally, so these issues seem (likely) not to be linked.

ricmadeira’s picture

smk-ka, many thanks for the patch! It worked perfectly for me on Drupal 4.7, and it helped me identify a serious issue with a 3rd-party module, subscriptions.module, that was hanging up my site and I believe is what got me into serious trouble with my previous hosting company, leading to a great loss of money and time.

This should really be commited to core. Like Moshe said, it does not solve any problems, but it does let the user know there is one... a serious one. Like in my case, I've been using subscriptions.module since the beginning, and I would never have suspected its latest update could have messed up my site so; it can indeed happen to anyone.

jorisx’s picture

At least I know now why my site is very very slow when locale.module is enabeld
but maybe it's good to keep track of the modules that combined with locale.module makes these site's very slow ?
or is there already some list ?

my site(5.1) is running really really slow with locale enabeld but I need it (it's a dutch site with lot's of dutch users ... toppop.nl)

jorisx’s picture

I've tried the patch locale.module_0.patch but the site is still runninig very slowly when using an other language.
I'm using these aditional modules, maybe some one has an idea why my site is tunning so slow ...

avatar_selection
devel (switched off)
image
inline
mimemail
scheduler
sfir
simplenews
simplenews_template
taxonomy_theme
update_status
video
views
webform

csc4’s picture

@ricmadeira - have you any details on the problem with the subscription module? I've got a site which seems to have suddenly slowed down for no obvious reason and I do use subscription but not locale - could it be subscription?

dgtlmoon’s picture

My devel site was hitting around 2,500 SQL queries for the location/locale's stuff , but this seems to have fixed it, is this the same issue you are having ?

Try my patch and log analyses here if it helps http://drupal.org/node/160540#comment-718579