?
Referenced as Pull Request for: # 9421
avatar brianteeman
brianteeman
14 Mar 2016

Steps to reproduce the issue

1. Create a 3.4.8 site with a LOT of categories and articles (I used com_overload (https://github.com/nikosdion/com_overload) to create 53k articles in 1.1k categories or use this db dump https://www.dropbox.com/s/xpyij0bwuc2mohu/large-delete-passport.sql.zip?dl=0 (note it is half a gig extracted)

2. Enable debug and go to the category manager
My debug results were

Memory
Time: 1.3 ms / 1.3 ms Memory: 0.835 MB / 0.84 MB Application: afterLoad
Time: 80.6 ms / 81.8 ms Memory: 3.241 MB / 4.08 MB Application: afterInitialise
Time: 14.8 ms / 96.6 ms Memory: 0.399 MB / 4.48 MB Application: afterRoute
Time: 321.6 ms / 418.2 ms Memory: 5.485 MB / 9.96 MB Application: afterDispatch
Time: 6.9 ms / 425.1 ms Memory: 0.204 MB / 10.16 MB Application: beforeRenderModule mod_submenu (Admin Submenu)
Time: 3.5 ms / 428.5 ms Memory: 0.045 MB / 10.21 MB Application: afterRenderModule mod_submenu (Admin Submenu)
Time: 4.1 ms / 432.7 ms Memory: 0.040 MB / 10.25 MB Application: beforeRenderModule mod_status (User Status)
Time: 4.8 ms / 437.4 ms Memory: 0.063 MB / 10.31 MB Application: afterRenderModule mod_status (User Status)
Time: 0.3 ms / 437.7 ms Memory: 0.000 MB / 10.31 MB Application: beforeRenderModule mod_version (Joomla Version)
Time: 2.3 ms / 440.0 ms Memory: 0.013 MB / 10.32 MB Application: afterRenderModule mod_version (Joomla Version)
Time: 0.3 ms / 440.3 ms Memory: 0.000 MB / 10.32 MB Application: beforeRenderModule mod_toolbar (Toolbar)
Time: 29.1 ms / 469.4 ms Memory: 0.089 MB / 10.41 MB Application: afterRenderModule mod_toolbar (Toolbar)
Time: 0.3 ms / 469.7 ms Memory: 0.000 MB / 10.41 MB Application: beforeRenderModule mod_title (Title)
Time: 2.1 ms / 471.8 ms Memory: 0.006 MB / 10.42 MB Application: afterRenderModule mod_title (Title)
Time: 0.3 ms / 472.1 ms Memory: 0.001 MB / 10.42 MB Application: beforeRenderModule mod_menu (Admin Menu)
Time: 47.7 ms / 519.8 ms Memory: 0.322 MB / 10.74 MB Application: afterRenderModule mod_menu (Admin Menu)
Time: 3.1 ms / 522.9 ms Memory: 0.242 MB / 10.98 MB Application: afterRender

Database queries total: 46.3 ms

and the relevant query

Query Time: 13.28 ms After last query: 0.80 ms Query memory: 0.021 MB Memory before query: 6.075 MB Rows returned: 1
SELECT COUNT(*)
FROM lwp30_categories AS a
LEFT JOIN lwp30_languages AS l
ON l.lang_code = a.language
LEFT JOIN lwp30_users AS uc
ON uc.id=a.checked_out
LEFT JOIN lwp30_viewlevels AS ag
ON ag.id = a.access
LEFT JOIN lwp30_users AS ua
ON ua.id = a.created_user_id
WHERE a.extension = 'com_content'
AND (a.published IN (0, 1))

and

Query Time: 2.03 ms After last query: 0.41 ms Query memory: 0.026 MB Memory before query: 6.086 MB Rows returned: 20
SELECT a.id, a.title, a.alias, a.note, a.published, a.access, a.checked_out, a.checked_out_time, a.created_user_id, a.path, a.parent_id, a.level, a.lft, a.rgt, a.language,l.title AS language_title,uc.name AS editor,ag.title AS access_level,ua.name AS author_name
FROM lwp30_categories AS a
LEFT JOIN lwp30_languages AS l
ON l.lang_code = a.language
LEFT JOIN lwp30_users AS uc
ON uc.id=a.checked_out
LEFT JOIN lwp30_viewlevels AS ag
ON ag.id = a.access
LEFT JOIN lwp30_users AS ua
ON ua.id = a.created_user_id
WHERE a.extension = 'com_content'
AND (a.published IN (0, 1))
ORDER BY a.lft asc
LIMIT 0, 20

3. Upgrade the site to 3.5rc2 and go to category manager again
Expected behaviour is to see the new category count feature from #6916
Actual behaviour - it gets there eventually but takes a very long time

My debug results were

Memory
Time: 18.76 ms / 18.76 ms Memory: 0.678 MB / 0.90 MB Application: afterLoad
Time: 78.50 ms / 97.26 ms Memory: 3.355 MB / 4.26 MB Application: afterInitialise
Time: 0.09 ms / 97.35 ms Memory: 0.002 MB / 4.26 MB Application: afterRoute
Time: 17.39 ms / 114.74 ms Memory: 0.518 MB / 4.78 MB Application: beforeRenderComponent com_categories
Time: 31775.29 ms / 31890.02 ms Memory: 5.560 MB / 10.34 MB Application: afterRenderComponent com_categories
Time: 1.34 ms / 31891.36 ms Memory: 0.005 MB / 10.34 MB Application: afterDispatch
Time: 10.32 ms / 31901.68 ms Memory: 0.211 MB / 10.55 MB Application: beforeRenderModule mod_submenu (Admin Submenu)
Time: 4.83 ms / 31906.51 ms Memory: 0.047 MB / 10.60 MB Application: afterRenderModule mod_submenu (Admin Submenu)
Time: 6.94 ms / 31913.45 ms Memory: 0.036 MB / 10.64 MB Application: beforeRenderModule mod_status (User Status)
Time: 7.01 ms / 31920.46 ms Memory: 0.064 MB / 10.70 MB Application: afterRenderModule mod_status (User Status)
Time: 0.27 ms / 31920.73 ms Memory: 0.000 MB / 10.70 MB Application: beforeRenderModule mod_version (Joomla Version)
Time: 3.86 ms / 31924.59 ms Memory: 0.012 MB / 10.71 MB Application: afterRenderModule mod_version (Joomla Version)
Time: 0.33 ms / 31924.92 ms Memory: 0.000 MB / 10.71 MB Application: beforeRenderModule mod_toolbar (Toolbar)
Time: 35.71 ms / 31960.63 ms Memory: 0.096 MB / 10.80 MB Application: afterRenderModule mod_toolbar (Toolbar)
Time: 0.21 ms / 31960.84 ms Memory: 0.000 MB / 10.80 MB Application: beforeRenderModule mod_title (Title)
Time: 2.16 ms / 31963.00 ms Memory: 0.005 MB / 10.81 MB Application: afterRenderModule mod_title (Title)
Time: 0.27 ms / 31963.26 ms Memory: 0.001 MB / 10.81 MB Application: beforeRenderModule mod_menu (Admin Menu)
Time: 52.10 ms / 32015.37 ms Memory: 0.337 MB / 11.15 MB Application: afterRenderModule mod_menu (Admin Menu)
Time: 4.31 ms / 32019.67 ms Memory: 0.290 MB / 11.44 MB Application: afterRender

Database queries total: 31358.46 ms
and the relevant query

Query Time: 18140.48 ms After last query: 0.95 ms Query memory: 0.237 MB Memory before query: 6.292 MB Rows returned: 1111
SELECT a.id, a.title, a.alias, a.note, a.published, a.access, a.checked_out, a.checked_out_time, a.created_user_id, a.path, a.parent_id, a.level, a.lft, a.rgt, a.language,l.title AS language_title, l.image AS language_image,uc.name AS editor,ag.title AS access_level,ua.name AS author_name,COUNT(DISTINCT cp.id) AS count_published,COUNT(DISTINCT cu.id) AS count_unpublished,COUNT(DISTINCT ca.id) AS count_archived,COUNT(DISTINCT ct.id) AS count_trashed
FROM lwp30_categories AS a
LEFT JOIN lwp30_languages AS l
ON l.lang_code = a.language
LEFT JOIN lwp30_users AS uc
ON uc.id=a.checked_out
LEFT JOIN lwp30_viewlevels AS ag
ON ag.id = a.access
LEFT JOIN lwp30_users AS ua
ON ua.id = a.created_user_id
LEFT JOIN lwp30_content AS cp
ON cp.catid = a.id
AND cp.state = 1
LEFT JOIN lwp30_content AS cu
ON cu.catid = a.id
AND cu.state = 0
LEFT JOIN lwp30_content AS ca
ON ca.catid = a.id
AND ca.state = 2
LEFT JOIN lwp30_content AS ct
ON ct.catid = a.id
AND ct.state = -2
WHERE a.extension = 'com_content'
AND (a.published IN (0, 1))
GROUP BY a.id,
a.title,
a.alias,
a.note,
a.published,
a.access,
a.checked_out,
a.checked_out_time,
a.created_user_id,
a.path,
a.parent_id,
a.level,
a.lft,
a.rgt,
a.language,
l.title,
l.image,
uc.name,
ag.title,
ua.name
ORDER BY a.lft asc

and

Query Time: 13171.82 ms After last query: 4.23 ms Query memory: 0.028 MB Memory before query: 6.294 MB Rows returned: 20
SELECT a.id, a.title, a.alias, a.note, a.published, a.access, a.checked_out, a.checked_out_time, a.created_user_id, a.path, a.parent_id, a.level, a.lft, a.rgt, a.language,l.title AS language_title, l.image AS language_image,uc.name AS editor,ag.title AS access_level,ua.name AS author_name,COUNT(DISTINCT cp.id) AS count_published,COUNT(DISTINCT cu.id) AS count_unpublished,COUNT(DISTINCT ca.id) AS count_archived,COUNT(DISTINCT ct.id) AS count_trashed
FROM lwp30_categories AS a
LEFT JOIN lwp30_languages AS l
ON l.lang_code = a.language
LEFT JOIN lwp30_users AS uc
ON uc.id=a.checked_out
LEFT JOIN lwp30_viewlevels AS ag
ON ag.id = a.access
LEFT JOIN lwp30_users AS ua
ON ua.id = a.created_user_id
LEFT JOIN lwp30_content AS cp
ON cp.catid = a.id
AND cp.state = 1
LEFT JOIN lwp30_content AS cu
ON cu.catid = a.id
AND cu.state = 0
LEFT JOIN lwp30_content AS ca
ON ca.catid = a.id
AND ca.state = 2
LEFT JOIN lwp30_content AS ct
ON ct.catid = a.id
AND ct.state = -2
WHERE a.extension = 'com_content'
AND (a.published IN (0, 1))
GROUP BY a.id,
a.title,
a.alias,
a.note,
a.published,
a.access,
a.checked_out,
a.checked_out_time,
a.created_user_id,
a.path,
a.parent_id,
a.level,
a.lft,
a.rgt,
a.language,
l.title,
l.image,
uc.name,
ag.title,
ua.name
ORDER BY a.lft asc
LIMIT 0, 20

avatar brianteeman brianteeman - open - 14 Mar 2016
avatar wilsonge
wilsonge - comment - 14 Mar 2016

@alikon Can you look into this please?

avatar brianteeman
brianteeman - comment - 14 Mar 2016

If you just want to test with 3.5rc2 without doing the upgrade you can grab the db dump here https://www.dropbox.com/s/uc5l57f5x4hmco6/large-delete-passport.sql%202.zip?dl=0 (again remember it is 500mb extracted)


This comment was created with the J!Tracker Application at issues.joomla.org/joomla-cms/9420.

avatar Wertos
Wertos - comment - 14 Mar 2016

@brianteeman i have about the same log. Data Base 1.4Gb
sorry for my English

avatar andrepereiradasilva
andrepereiradasilva - comment - 14 Mar 2016

From: 321.6 ms
To: 31775.29 ms

"just" 31 seconds more ...
this has something to do with the new category articles count, right?

avatar pe7er
pe7er - comment - 14 Mar 2016

@brianteeman Thanks for reproducing the error.
I'll try to look into this problem later this week.

I assume that the "COUNT(DISTINCT" that is used 4 times in the query (in the helper file
https://github.com/joomla/joomla-cms/blob/staging/administrator/components/com_content/helpers/content.php )
might cause this performance issue.

Maybe we could rewrite the COUNT(DISTINCT into subqueries like described here:
https://www.periscopedata.com/blog/use-subqueries-to-count-distinct-50x-faster.html

If not, or if keeps being a bottleneck for websites with large quantities of categories and articles, we could add a parameter to switch it off.

avatar alikon alikon - reference | 81bab83 - 14 Mar 16
avatar alikon alikon - reference | 04b0193 - 14 Mar 16
avatar alikon alikon - reference | 7c8dafe - 14 Mar 16
avatar brianteeman brianteeman - close - 14 Mar 2016
avatar brianteeman brianteeman - change - 14 Mar 2016
Status New Closed
Closed_Date 0000-00-00 00:00:00 2016-03-14 15:06:01
Closed_By brianteeman
avatar brianteeman brianteeman - close - 14 Mar 2016
avatar brianteeman
brianteeman - comment - 14 Mar 2016

Please test #9421


This comment was created with the J!Tracker Application at issues.joomla.org/joomla-cms/9420.

avatar brianteeman
brianteeman - comment - 14 Mar 2016

@wertos can you test #9421 please - looks great to me but we need two tests


This comment was created with the J!Tracker Application at issues.joomla.org/joomla-cms/9420.

avatar Wertos
Wertos - comment - 14 Mar 2016

@brianteeman Excellent work! Page opens almost instantly.
Total SQL-queries: 14.74 ms

It would be more output at the bottom the total number of materials

avatar brianteeman
brianteeman - comment - 14 Mar 2016

@wertos please record your test result at #9421

On 14 March 2016 at 15:23, Wertos notifications@github.com wrote:

@brianteeman https://github.com/brianteeman Excellent work! Page opens
almost instantly.
Total SQL-queries: 14.74 ms


Reply to this email directly or view it on GitHub
#9420 (comment).

Brian Teeman
Co-founder Joomla! and OpenSourceMatters Inc.
http://brian.teeman.net/

Add a Comment

Login with GitHub to post a comment