Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

New category count feature performance degrade #9420

Closed
brianteeman opened this issue Mar 14, 2016 · 9 comments
Closed

New category count feature performance degrade #9420

brianteeman opened this issue Mar 14, 2016 · 9 comments

Comments

@brianteeman
Copy link
Contributor

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

@wilsonge
Copy link
Contributor

@alikon Can you look into this please?

@brianteeman
Copy link
Contributor Author

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.

@Wertos
Copy link

Wertos commented Mar 14, 2016

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

@andrepereiradasilva
Copy link
Contributor

From: 321.6 ms
To: 31775.29 ms

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

@pe7er
Copy link
Contributor

pe7er commented Mar 14, 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.

@brianteeman
Copy link
Contributor Author

Please test #9421


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

@brianteeman
Copy link
Contributor Author

@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.

@Wertos
Copy link

Wertos commented Mar 14, 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

@brianteeman
Copy link
Contributor Author

@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/

wilsonge pushed a commit that referenced this issue Mar 14, 2016
New category count feature performance degrade
mdrews21 pushed a commit to mdrews21/joomla-cms that referenced this issue Mar 17, 2016
New category count feature performance degrade
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants