CMS MADE SIMPLE FORGE

CMS Made Simple Core

 

[#9549] CMSMS 1.11.8 performance regression

avatar
Created By: Fred Polizo (fredp)
Date Submitted: Fri Sep 20 01:03:30 -0400 2013

Assigned To:
Version: None
CMSMS Version: None
Severity: None
Resolution: Fixed
State: Closed
Summary:
CMSMS 1.11.8 performance regression
Detailed Description:
I found a performance regression after upgrading from 1.11.7 to 1.11.8.  I
posted about this on the Installation/Upgrade forum with details:
http://forum.cmsmadesimple.org/viewtopic.php?f=3&t=67857

After some debugging, I isolated the problem to this bit of code, which appears
twice, in lib/class.contentoperations.inc.php:
                                $contentprops = array();
                                for( $i = 0; $i < count($contentrows); $i++ ) {
$content_id =
$contentrows[$i]['content_id'];
                                        $t2 = array();
                                        for( $j = 0; $j < count($tmp); $j++ ) {
if( $tmp[$j]['content_id'] ==
$content_id ) {
                                                        $t2[] = $tmp[$j];
                                                }
                                        }
                                        $contentprops[$content_id] = $t2;
                                }

This can result in millions of iterations. Unless I'm missing something, the
following code should do the same thing:
                                $contentprops = array();
                                for( $i = 0; $i < count($tmp); $i++ )
                                        {
$contentprops[$tmp[$i]['content_id']][] = $tmp[$i];
                                        }


I'm running with this change and it seems to work.  Performance is now faster
than 1.11.7:
<!-- 1.467798 / 36 / 56919712 / 77902336 -->


Here's the change in "patch" format, if you want to give it a try:
--- class.contentoperations.inc.php.ORIG        2013-09-20 02:02:04.400887376
+0000
+++ class.contentoperations.inc.php     2013-09-20 04:55:43.267819506 +0000
@@ -660,18 +660,9 @@
                    if( $tmp )
                      {
                                  $contentprops = array();
-                                 for( $i = 0; $i < count($contentrows); $i++ )
+                                 for( $i = 0; $i < count($tmp); $i++ ) 
                                          {
-                                                 $content_id =
$contentrows[$i]['content_id'];
-                                                 $t2 = array();
-                                                 for( $j = 0; $j < count($tmp);
$j++ )
-                                                         {
-                                                                 if(
$tmp[$j]['content_id'] == $content_id )
-                                                                         {
-                                                                               
$t2[] = $tmp[$j];
-                                                                         }
-                                                         }
-                                                 $contentprops[$content_id] =
$t2;
+                                              
$contentprops[$tmp[$i]['content_id']][] = $tmp[$i];
                                          }
                      }
                  }
@@ -773,16 +764,10 @@
// re-organize the tmp data into a hash of arrays of
properties for each content id.
                    if( $tmp ) {
                                $contentprops = array();
-                               for( $i = 0; $i < count($contentrows); $i++ ) {
-                                       $content_id =
$contentrows[$i]['content_id'];
-                                       $t2 = array();
-                                       for( $j = 0; $j < count($tmp); $j++ ) {
-                                               if( $tmp[$j]['content_id'] ==
$content_id ) {
-                                                       $t2[] = $tmp[$j];
-                                               }
+                               for( $i = 0; $i < count($tmp); $i++ )
+                                       {
+                                              
$contentprops[$tmp[$i]['content_id']][] = $tmp[$i];
                                        }
-                                       $contentprops[$content_id] = $t2;
-                               }
                        }
                }


History

Comments
avatar
Date: 2013-09-20 12:38
Posted By: Rolf (rolf1)

fixed in SVN
      
avatar
Date: 2013-09-20 12:49
Posted By: Robert Campbell (calguy1000)

Note 1:
A: This code did not change from 1.11.7 to 1.11.8 ... it was duplicated into a
new function LoadAllContent()
B: This code (in both circumstances) only gets called if loadprops is true
C: loadprops is ONLY true when building navigations (I tested) or if you are
calling some special code in a UDT, custom plugin, or
      module. which you did not describe at all.
D: If you are building a navigation with ~700 items in it (or even if 600 of
those 700 items are disabled/inactive/hidden from menu) then you need to do some
re-analysis of the site.
E: With ~700 content items the only way you could get 'millions of iterations'
is if you had thousands of content properties

CMSMS is not designed (and will not be changed) to be efficient with an extreme
amount of content properties.   A few dozen would be reasonable.

Therefore:

This was a very LOW Priority item for 99.9% of the sites and for the way CMSMS
is designed.   It was 'fixed', but in our opinion didn't really need to be.  I
think you need to re-analyze your site.
      
avatar
Date: 2013-09-21 00:40
Posted By: Fred Polizo (fredp)

Thanks for the fix.  First, let me say that I always viewed this
as a edge case since it *only* happens on my site-map page, nowhere else.
In fact, I left the BR Priority unset so that you could set it to
whatever you saw fit. 

Second, allow me to respond to some of calguy1000's remarks:

>A: This code did not change from 1.11.7 to 1.11.8 ... 

To be clear, I didn't say this code changed, only that performance changed.

>B: This code (in both circumstances) only gets called if loadprops is true

Doh! Thanks for pointing this out! Somehow the loadprops=0 parameter was
removed from the {menu...} call on the site-map page. From backups, it seems
this happened months ago and I didn't catch it, since the page continued to
render correctly without a noticeable drop in performance. Then, I missed it
when pasting the {menu...} call into the forum article. 

I'll update my forum post to note that the missing loadprops=0 was triggering
this performance problem. I agree this is even more of an edge case than I
originally thought.

>C: loadprops is ONLY true when building navigations (I tested) or if you are
>calling some special code in a UDT, custom plugin, or
>      module. which you did not describe at all.

To be clear, all 3rd Party modules were deactivated during my tests,
including my own and UDT's were renamed to disable them.

...

>E: With ~700 content items the only way you could get 'millions of iterations'
>is if you had thousands of content properties
>
>CMSMS is not designed (and will not be changed) to be efficient with an extreme
>amount of content properties.   A few dozen would be reasonable.

Perhaps you misapprehend what I mean by "iterations". Here's an example:
Say you have 600 pages with an average of 12 content properties per page.
Then, the db query will return ~7200 rows into the $tmp array. 
The outer loop (at line 776) iterates over all 600 pages and
the inner loop (at line 779) iterates over all 7200 $tmp elements
yielding a total of 4.32 million iterations:
    600 outer loops  * 7200 inner loops = 4,320,000 inner iterations.

Again, thanks for all your efforts.
      
avatar
Date: 2013-09-21 17:44
Posted By: Fred Polizo (fredp)

I just pulled class.contentoperations.php from SVN (r8982).  It indeed resolved
my reported problem.

PLEASE NOTE: This fix resolves more that just my original problem!

Last night, after using 1.11.8 a bit more, I noticed another area of performance
regression... in the Admin console: EditPage startup.

After selecting a page to edit from the "Content>>Pages" (listcontent.php)
output, 1.11.7 would take a couple of seconds to fully render the
"Content>>Pages>>Edit Page" (editcontent.php) page.  However, 1.11.8 was taking
~14 seconds to render the
page editor page.

After installing the class.contentoperations.php from SVN, Edit Page startup
time is restored and perhaps even faster than 1.11.7!

So, it seems this is not be as much of an edge case as first thought.
      
avatar
Date: 2013-09-21 18:00
Posted By: Fred Polizo (fredp)

Supplement to my last comment: 

I'm using TinyMCE for a WYSIWYG editor. If I switch back to MicroTiny, there is
no Edit Page performance regression in 1.11.8.



      
avatar
Date: 2013-10-03 03:26
Posted By: Fred Polizo (fredp)

After upgrading the site to CMSMS 1.11.9, the reported problem was resolved.

Thanks again for the fix! 
      
Updates

Updated: 2013-10-19 07:33
state: Open => Closed

Updated: 2013-09-20 12:38
resolution_id: 5 => 7

Updated: 2013-09-20 03:10
description: I found a performance regression after upgrading from 1.11.7 to 1.11.8. I posted about this on the Installation/Upgrade forum with details: http://forum.cmsmadesimple.org/viewtopic.php?f=3&t=67857 After some debugging, I isolated the problem to this b => I found a performance regression after upgrading from 1.11.7 to 1.11.8. I posted about this on the Installation/Upgrade forum with details: http://forum.cmsmadesimple.org/viewtopic.php?f=3&t=67857 After some debugging, I isolated the problem to this b
resolution_id: => 5