6.0.0-beta1
7/5/25

[#11906] Theme cache 'appversion' support causes performance bug
Summary Theme cache 'appversion' support causes performance bug
Queue Horde Framework Packages
Queue Version Git master
Type Bug
State Resolved
Priority 1. Low
Owners slusarz (at) horde (dot) org
Requester thomas.jarosch (at) intra2net (dot) com
Created 12/20/2012 (4580 days ago)
Due
Updated 12/20/2012 (4580 days ago)
Assigned 12/20/2012 (4580 days ago)
Resolved 12/20/2012 (4580 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch No

History
12/20/2012 10:27:51 PM Michael Slusarz Comment #8
Taken from Horde DevelopersHorde Developers
State ⇒ Resolved
Reply to this comment
Fixed in Horde_Core 2.1.2.
12/20/2012 10:27:10 PM Git Commit Comment #7 Reply to this comment
Changes have been made in Git (master):

commit 7ebcb8b09bdc6f4fa7b3e196d547bae37d9130a0
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Dec 20 15:23:49 2012 -0700

     [mms] Fix restoring cached theme data (Bug #11906).

  framework/Core/lib/Horde/Themes/Cache.php |    6 +++++-
  framework/Core/package.xml                |    2 ++
  2 files changed, 7 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/7ebcb8b09bdc6f4fa7b3e196d547bae37d9130a0
12/20/2012 10:24:53 PM Michael Slusarz Comment #6 Reply to this comment
When the theme cache is loaded the first time, the horde registry is 
not fully initialized, so $registry->getVersion(appname) will return 
a different value than during writeout.
('unknown')
No - this isn't correct.  A version can always be returned from an 
app, even if the app is not initialized yet.  And we aren't doing 
themes caching until well after the registry is initialized.
12/20/2012 10:11:11 PM Michael Slusarz Comment #5 Reply to this comment
Do note that you should absolutely NOT be using 'appversion' if using 
development (i.e. non-package) releases.  That makes no sense.
12/20/2012 09:37:22 PM Michael Slusarz Assigned to Michael Slusarz
Assigned to Horde DevelopersHorde Developers
State ⇒ Assigned
 
12/20/2012 09:24:33 PM Git Commit Comment #4 Reply to this comment
Changes have been made in Git (master):

commit d3cc0e255d8cc06696ceaea079b2e5faf15a3ea3
Author: Thomas Jarosch <thomas.jarosch@intra2net.com>
Date:   Thu Dec 20 15:57:33 2012 +0100

     Extend information why a theme cache is invalid

     Signed-off-by: Michael M Slusarz <slusarz@horde.org>
     See Bug #11906

  framework/Core/lib/Horde/Themes/Cache.php |    2 +-
  1 files changed, 1 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/d3cc0e255d8cc06696ceaea079b2e5faf15a3ea3
12/20/2012 03:10:51 PM Thomas Jarosch Comment #3 Reply to this comment
* Collected debug output *

Save of the theme cache during shutdown(), it dumps "$sig" and the 
computed version id:
shutdown() saving nag|intranator: v:H5 (4.0.2-git)|5.0.3-git
shutdown() saving horde|intranator: v:5.0.3-git
shutdown() saving turba|intranator: v:H5 (4.0.2-git)|5.0.3-git
shutdown() saving intranator|intranator: v:unknown|5.0.3-git
shutdown() saving kronolith|intranator: v:H5 (4.0.3-git)|5.0.3-git
shutdown() saving mnemo|intranator: v:H5 (4.0.2-git)|5.0.3-git
shutdown() saving imp|intranator: v:H5 (6.0.3-git)|5.0.3-git
shutdown() saving administration|intranator: v:unknown|5.0.3-git
shutdown() saving settings|intranator: v:unknown|5.0.3-git


Exceptions thrown on next click:
unserialize failed for horde|intranator: Cache invalidated for horde: 
v:5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git
unserialize failed for intranator|intranator: Cache invalidated for 
intranator: v:unknown|5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git
unserialize failed for kronolith|intranator: Cache invalidated for 
kronolith: v:H5 (4.0.3-git)|5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git
unserialize failed for imp|intranator: Cache invalidated for imp: v:H5 
(6.0.3-git)|5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git
unserialize failed for administration|intranator: Cache invalidated 
for administration: v:unknown|5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git
unserialize failed for settings|intranator: Cache invalidated for 
settings: v:unknown|5.0.3-git != v:H5 (4.0.2-git)|5.0.3-git


The problem is a bit hidden by Horde_Registry::getVersion():

If $app is null, which it is during the init/load phase, it will get 
the last app from the app stack.
Looking at the output for "kronolith" above one can see that the 
(cumputed) version number changes from 4.0.3 to 4.0.2.

12/20/2012 02:59:33 PM Thomas Jarosch Comment #2
New Attachment: 0001-Extend-information-why-a-theme-cache-is-invalid.patch Download
Reply to this comment
Attached is a small patch to improve diagnostics
in case the theme cache is invalidated.

12/20/2012 02:55:35 PM Thomas Jarosch Comment #1
Milestone ⇒
State ⇒ Unconfirmed
Patch ⇒ No
Queue ⇒ Horde Framework Packages
Summary ⇒ Theme cache 'appversion' support causes performance bug
Type ⇒ Bug
Priority ⇒ 1. Low
Reply to this comment
Hi,

I've installed the xhprof PHP profiler and played around with it.
While looking at the output, I noticed that 28% of the total time
on an average click was spent on building the theme cache.

-> Something had to be wrong

I've added debug logging and identified the 'appversion' version check 
mechanism
in Themes/Cache.php to be the problem.

Take a look at the Horde_Themes_Cache::getCacheId() function in 
Themes/Cache.php. It computes a cache version id consisting of the 
version of the current app + the horde version.

When the cache is written by 
Horde_Core_Factory_ThemesCache::shutdown(), the Horde registry is 
fully initialized. The cache version id of the theme will include a 
proper app version.


When the theme cache is loaded the first time, the horde registry is 
not fully initialized, so $registry->getVersion(appname) will return a 
different value than during writeout.
('unknown')

-> The cache gets thrown away and rebuild.
This is a huge performance drain.

Workaround: Don't use the "appversion" version check mechanism.

Saved Queries