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).
Comment | File | Size | Author |
---|---|---|---|
#55 | locale.module_0.patch | 1.06 KB | smk-ka |
#49 | patched-i18n-files.zip | 8.02 KB | saml |
#44 | i18n.patch | 1.3 KB | smk-ka |
#43 | patch_51 | 1.58 KB | moshe weitzman |
#41 | patch_50 | 1.51 KB | moshe weitzman |
Comments
Comment #1
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedI 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.
Comment #2
smk-ka CreditAttribution: smk-ka commentedPlease, 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 ;)
Comment #3
smk-ka CreditAttribution: smk-ka commentedPatch 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.
Comment #4
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedbetter patch.
Comment #5
smk-ka CreditAttribution: smk-ka commentedNo, 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.Comment #6
smk-ka CreditAttribution: smk-ka commentedBecause 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.
Comment #7
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedok, this makes sense then.
Comment #8
Dries CreditAttribution: Dries commented* 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.
Comment #9
smk-ka CreditAttribution: smk-ka commented@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.
Comment #10
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedA 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.
Comment #11
pwolanin CreditAttribution: pwolanin commentedI 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?
Comment #12
smk-ka CreditAttribution: smk-ka commented@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.)
Comment #13
smk-ka CreditAttribution: smk-ka commented@pwolanin
Confirmed, this is a direct consequence of this bug.
Comment #14
smk-ka CreditAttribution: smk-ka commentedPatch using second solution - Drupal 4.7.1.
Comment #15
smk-ka CreditAttribution: smk-ka commentedSame for 4.6.7.
Comment #16
bwynants CreditAttribution: bwynants commentedHi,
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!
Comment #17
smk-ka CreditAttribution: smk-ka commentedForget 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 ;)
Comment #18
bwynants CreditAttribution: bwynants commented@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
Comment #19
smk-ka CreditAttribution: smk-ka commentedBert, 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).
Comment #20
Dries CreditAttribution: Dries commentedHi 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?
Comment #21
bwynants CreditAttribution: bwynants commented@smk-ka: I can follow what you mean, so definitely #19 is better as #15
Thanks!
Comment #22
vancelee CreditAttribution: vancelee commentedHi 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!
Comment #23
smk-ka CreditAttribution: smk-ka commented@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 thelocale()
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.
$locale
isn't available until after bootstrapping, particulary not during hook_init().$locale
available at the earliest point in time, that is, before callinghook_init()
. So any modules that exposehook_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.$locale
variable uninitialized untilt()
orlocale()
are first called. This is unacceptable, as no module can be sure l10n has been initialized before, and would have to check for itself.$locale
hook_init()
: when a module callst()
orlocale()
`by chance'hook_init()
: during normal bootstrappingThis means that, if a module wants to access
$locale
(but nott()
as in the caching example) duringhook_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:With the latter two patches,
$locale
isn't initialized during the very first call, so we're enteringlocale()
where we currently do not. Killes' idea of moving l10n initialization into thet()
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
Comment #24
smk-ka CreditAttribution: smk-ka commentedPatch #19 backported to 4.6.7
Comment #25
smk-ka CreditAttribution: smk-ka commentedThis 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).
Comment #26
Dries CreditAttribution: Dries commentedThis 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.
Comment #27
smk-ka CreditAttribution: smk-ka commentedSince 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.
Comment #28
ardas CreditAttribution: ardas commentedI have the problem which I described here http://drupal.org/node/66254
Please tell me is reason the same ?
Comment #29
smk-ka CreditAttribution: smk-ka commented@Duke
Yes, it is. Any patch from above will fix it (it doesn't matter which one).
Comment #30
adixon CreditAttribution: adixon commentedI'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).
Comment #31
adixon CreditAttribution: adixon commentedOkay, 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.
Comment #32
smk-ka CreditAttribution: smk-ka commentedFrom 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()
fromi18n.inc
and paste it to the end ofi18n.module
. This makes the required init code available when it's needed (no need for a module load order system here).Comment #33
adixon CreditAttribution: adixon commentedhmm, 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?)
Comment #34
Dries CreditAttribution: Dries commentedYes, 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 ...
Comment #35
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedThere is a suggestion pending that would most likely remove og's dependency on the init hook:
http://drupal.org/node/66155
Comment #36
adixon CreditAttribution: adixon commented1. hook_init - okay, perhaps the page here:
http://api.drupal.org/api/head/function/hook_init
can be more alarming. Something like:
Hmm, that could be more alarming.
2. og - yes, let's fix og_init, i've replied to your post.
Comment #37
pwolanin CreditAttribution: pwolanin commentedDoes 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.
Comment #38
Dries CreditAttribution: Dries commentedThere are quite a few modules that are incorrectly using the _init hook. Such modules hurt the performance of your site.
Comment #39
pwolanin CreditAttribution: pwolanin commentedSo, 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.
Comment #40
pwolanin CreditAttribution: pwolanin commentedattached 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.
Comment #41
moshe weitzman CreditAttribution: moshe weitzman commentedi 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.
Comment #42
Dries CreditAttribution: Dries commentedThe 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.
Comment #43
moshe weitzman CreditAttribution: moshe weitzman commentedi tried it with og and all is well now. patch attached has a tad more documentation
Comment #44
smk-ka CreditAttribution: smk-ka commentedOne 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.
Comment #45
Dries CreditAttribution: Dries commentedCommitted to DRUPAL-4-7 and CVS HEAD. Moving to il8n project?
Comment #46
SavoryMedia CreditAttribution: SavoryMedia commentedSo, 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.
Comment #47
pwolanin CreditAttribution: pwolanin commentedthe secret daily tarball of the latest 4.7:
http://ftp.osuosl.org/pub/drupal/files/projects/drupal-cvs-4-7.tar.gz
thanks to: http://drupal.org/node/62617#comment-118727
Comment #48
saml CreditAttribution: saml commentedCould 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":
Comment #49
saml CreditAttribution: saml commentedThis 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)
Comment #50
saml CreditAttribution: saml commentedAs 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):
(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)
Comment #51
adixon CreditAttribution: adixon commentedthe translation module depends on i18n - you'll have to disable it too.
Comment #52
saml CreditAttribution: saml commentedYes, true. Forgot to disable it.
Comment #53
Jose Reyero CreditAttribution: Jose Reyero commentedActually 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
Comment #54
(not verified) CreditAttribution: commentedComment #55
smk-ka CreditAttribution: smk-ka commentedSince 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:
To regain regular site performance you can open the file and replace
define(CONSTANT, t('blah'))
with justdefine(CONSTANT, 'blah')
, ie. strip thet()
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 everywhereCONSTANT
is used. (BTW, theCONSTANT
thing is just a recurring example of this bug, the thing you should really look for is thet()
call.)If you don't have that much programming experience file a bug for the module, ie. not here.
How to patch:
patch -i locale.module.patch
Comment #56
moshe weitzman CreditAttribution: moshe weitzman commentedI 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.
Comment #57
smk-ka CreditAttribution: smk-ka commentedYep, 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
Comment #58
Luneh CreditAttribution: Luneh commentedHi,
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...
Comment #59
smk-ka CreditAttribution: smk-ka commentedI'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.
Comment #60
ricmadeira CreditAttribution: ricmadeira commentedsmk-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.
Comment #61
jorisx CreditAttribution: jorisx commentedAt 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)
Comment #62
jorisx CreditAttribution: jorisx commentedI'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
Comment #63
csc4 CreditAttribution: csc4 commented@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?
Comment #64
dgtlmoon CreditAttribution: dgtlmoon commentedMy 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