Actions
Defect #23275
open
Issue open takes too much time when member blongs many projects
Added by Wadim Incognito almost 8 years ago. Updated almost 7 years ago.
Status:
New
Priority:
Normal
Assignee:
-
Category:
Performance
Target version:
-
Start date:
Due date:
% Done:
0%
Estimated time:
Resolution:
Affected version:
Description
When user is a member of many open projects (about 3000), each issue takes about 7 seconds to open. When user is a member of several projects (about 10-20), each issue takes about 3 seconds to open.
Top indicates, that most of time taken by "ruby" process, so it's not a database issue.
Updated by Toshi MARUYAMA almost 8 years ago
- Category changed from Issues to Performance
Updated by Toshi MARUYAMA almost 8 years ago
- Status changed from New to Needs feedback
Please give us your information, ref: submissions and #11904.
Updated by Wadim Incognito almost 8 years ago
Hi !
Environment: Redmine version 3.2.1.stable Ruby version 2.1.2-p95 (2014-05-08) [x86_64-linux] Rails version 4.2.5.2 Environment production Database adapter Mysql2 SCM: Subversion 1.6.11 Git 1.7.1 Filesystem
About #11904 - it's different. In my case - there is a single user which is a member of many projects, not a lot of users in single project.
Updated by Wadim Incognito almost 8 years ago
Yes, but it's doesn't matter - because without plugins behaviour is the same
Here is list of plugins:
Redmine plugins: a_common_libs 2.1.5 ajax_counters 1.4.0 clear_plan 2.1.9 easy_gantt 1.2 global_roles 2.1.0 luxury_buttons 3.6.8 redmine_favorite_projects 2.0.2 redmine_issue_tabs 1.1.1 redmine_my_page 0.1.9 unread_issues 2.0.0 usability 2.0.0
Updated by Toshi MARUYAMA almost 8 years ago
- Status changed from Needs feedback to New
Updated by Jean-Philippe Lang almost 8 years ago
How many projects do you have in your database? Could you also give the application log for displaying an issue. It gives usefull information about rendering times.
Updated by Wadim Incognito almost 8 years ago
Hi !
In our database - there is 3928 projects, 3208 is active.
I am a member of 3199 projects.
Opening an issue takes about 6 seconds. Log follows:
Started GET "/issues/58028" for 192.168.21.190 at 2016-07-13 12:03:35 +0300
Processing by IssuesController#show as HTML
Parameters: {"id"=>"58028"}
Current user: Surkov.V (id=419)
Rendered issues/_action_menu.html.erb (38.5ms)
Rendered plugins/clear_plan/app/views/clear_plan/hooks/_issue_bottom_details.html.erb (0.4ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_timelog.html.erb (0.7ms)
Rendered common/_tabs.html.erb (2.0ms)
Rendered plugins/redmine_issue_tabs/app/views/hooks/redmine_issue_tabs/_rm_history_tabs.html.erb (2.5ms)
Rendered plugins/unread_issues/app/views/hooks/unread_isues/_issue_bottom_details.html.erb (0.2ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_button_bar.html.erb (0.3ms)
Rendered issue_relations/_form.html.erb (1.1ms)
Rendered issues/_relations.html.erb (1.7ms)
Rendered plugins/luxury_buttons/app/views/issues/_relations.html.erb (2.0ms)
Rendered issues/_action_menu.html.erb (1.9ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_view_issues_form_details_top.html.erb (0.0ms)
Rendered issues/_form_custom_fields.html.erb (31.1ms)
Rendered issues/_attributes.html.erb (46.5ms)
Rendered issues/_form.html.erb (441.6ms)
Rendered attachments/_form.html.erb (1.3ms)
Rendered issues/_edit.html.erb (450.1ms)
Rendered issues/_sidebar.html.erb (3.8ms)
Rendered watchers/_watchers.html.erb (2.0ms)
Rendered plugins/luxury_buttons/app/views/watchers/_watchers.html.erb (2.5ms)
Rendered issues/show.html.erb (552.2ms)
Rendered plugins/luxury_buttons/app/views/issues/show.html.erb within layouts/base (553.3ms)
Rendered plugins/a_common_libs/app/views/hooks/a_common_libs/_html_head.html.erb (1.2ms)
Rendered plugins/ajax_counters/app/views/hooks/ajax_counters/_html_head.html.erb (0.2ms)
Rendered plugins/clear_plan/app/views/clear_plan/hooks/_html_head.html.erb (0.2ms)
Rendered plugins/global_roles/app/views/hooks/global_roles/_head.html.erb (0.0ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_page_header.html.erb (1.6ms)
Rendered plugins/unread_issues/app/views/hooks/unread_isues/_add_css.html.erb (0.1ms)
Rendered plugins/usability/app/views/hooks/usability/_html_head.html.erb (0.7ms)
Rendered plugins/global_roles/app/views/hooks/global_roles/_view_layouts_base_body_bottom.html.erb (0.1ms)
Rendered plugins/usability/app/views/hooks/usability/_body_bottom.html.erb (0.1ms)
Completed 200 OK in 2794ms (Views: 2552.9ms | ActiveRecord: 168.0ms)
Started GET "/issue_reads/count/updated?counter_id=87c0bb8d4cc3be31f4dea0e60883eb72&period=0" for 192.168.21.190 at 2016-07-13 12:03:40 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"87c0bb8d4cc3be31f4dea0e60883eb72", "period"=>"0", "req"=>"updated"}
Current user: Surkov.V (id=419)
Completed 200 OK in 807ms (Views: 0.3ms | ActiveRecord: 25.5ms)
Started GET "/issue_reads/count/unread?counter_id=c4aad251ee5e7ded9635ffe658447e92&period=0" for 192.168.21.190 at 2016-07-13 12:03:41 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"c4aad251ee5e7ded9635ffe658447e92", "period"=>"0", "req"=>"unread"}
Current user: Surkov.V (id=419)
Completed 200 OK in 1477ms (Views: 0.2ms | ActiveRecord: 23.9ms)
Started GET "/issue_reads/count/assigned?counter_id=e0c20af0ad02031c9b817fab3ea7c6e3&period=0" for 192.168.21.190 at 2016-07-13 12:03:42 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"e0c20af0ad02031c9b817fab3ea7c6e3", "period"=>"0", "req"=>"assigned"}
Current user: Surkov.V (id=419)
Completed 200 OK in 892ms (Views: 0.2ms | ActiveRecord: 33.8ms)
Now, I'm a member of 79 projects. Issue opens for 3 seconds. Log follows:
Started GET "/issues/58028" for 192.168.21.190 at 2016-07-13 13:00:02 +0300
Processing by IssuesController#show as HTML
Parameters: {"id"=>"58028"}
Current user: Surkov.V (id=419)
Rendered issues/_action_menu.html.erb (23.5ms)
Rendered plugins/clear_plan/app/views/clear_plan/hooks/_issue_bottom_details.html.erb (0.3ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_blank.html.erb (0.0ms)
Rendered plugins/redmine_issue_tabs/app/views/redmine_issue_tabs/_timelog.html.erb (0.9ms)
Rendered common/_tabs.html.erb (2.0ms)
Rendered plugins/redmine_issue_tabs/app/views/hooks/redmine_issue_tabs/_rm_history_tabs.html.erb (2.4ms)
Rendered plugins/unread_issues/app/views/hooks/unread_isues/_issue_bottom_details.html.erb (0.2ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_button_bar.html.erb (0.3ms)
Rendered issue_relations/_form.html.erb (0.9ms)
Rendered issues/_relations.html.erb (1.6ms)
Rendered plugins/luxury_buttons/app/views/issues/_relations.html.erb (1.9ms)
Rendered issues/_action_menu.html.erb (1.8ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_view_issues_form_details_top.html.erb (0.1ms)
Rendered issues/_form_custom_fields.html.erb (30.2ms)
Rendered issues/_attributes.html.erb (47.5ms)
Rendered issues/_form.html.erb (374.7ms)
Rendered attachments/_form.html.erb (1.5ms)
Rendered issues/_edit.html.erb (383.3ms)
Rendered issues/_sidebar.html.erb (4.1ms)
Rendered watchers/_watchers.html.erb (2.4ms)
Rendered plugins/luxury_buttons/app/views/watchers/_watchers.html.erb (3.1ms)
Rendered issues/show.html.erb (460.9ms)
Rendered plugins/luxury_buttons/app/views/issues/show.html.erb within layouts/base (461.4ms)
Rendered plugins/a_common_libs/app/views/hooks/a_common_libs/_html_head.html.erb (1.2ms)
Rendered plugins/ajax_counters/app/views/hooks/ajax_counters/_html_head.html.erb (0.2ms)
Rendered plugins/clear_plan/app/views/clear_plan/hooks/_html_head.html.erb (0.2ms)
Rendered plugins/global_roles/app/views/hooks/global_roles/_head.html.erb (0.0ms)
Rendered plugins/luxury_buttons/app/views/hooks/lu_buttons/_page_header.html.erb (1.8ms)
Rendered plugins/unread_issues/app/views/hooks/unread_isues/_add_css.html.erb (0.1ms)
Rendered plugins/usability/app/views/hooks/usability/_html_head.html.erb (0.8ms)
Rendered plugins/global_roles/app/views/hooks/global_roles/_view_layouts_base_body_bottom.html.erb (0.1ms)
Rendered plugins/usability/app/views/hooks/usability/_body_bottom.html.erb (0.1ms)
Completed 200 OK in 1352ms (Views: 1192.9ms | ActiveRecord: 102.1ms)
Started GET "/issue_reads/count/updated?counter_id=87c0bb8d4cc3be31f4dea0e60883eb72&period=0" for 192.168.21.190 at 2016-07-13 13:00:05 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"87c0bb8d4cc3be31f4dea0e60883eb72", "period"=>"0", "req"=>"updated"}
Current user: Surkov.V (id=419)
Completed 200 OK in 1022ms (Views: 0.3ms | ActiveRecord: 24.0ms)
Started GET "/issue_reads/count/unread?counter_id=c4aad251ee5e7ded9635ffe658447e92&period=0" for 192.168.21.190 at 2016-07-13 13:00:07 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"c4aad251ee5e7ded9635ffe658447e92", "period"=>"0", "req"=>"unread"}
Current user: Surkov.V (id=419)
Completed 200 OK in 843ms (Views: 0.2ms | ActiveRecord: 27.7ms)
Started GET "/issue_reads/count/assigned?counter_id=e0c20af0ad02031c9b817fab3ea7c6e3&period=0" for 192.168.21.190 at 2016-07-13 13:00:08 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"e0c20af0ad02031c9b817fab3ea7c6e3", "period"=>"0", "req"=>"assigned"}
Current user: Surkov.V (id=419)
Completed 200 OK in 1258ms (Views: 0.2ms | ActiveRecord: 40.4ms)
Updated by Toshi MARUYAMA over 7 years ago
- Subject changed from Issue open takes too much time. to Issue open takes too much time when member blongs many projects
Updated by Wadim Incognito over 7 years ago
Hi !
Any progress, plans, or anyting else ?
Can I help you in resolving this issue ?
Updated by Stephane Evr over 7 years ago
It seems that 50% of your performance problems are coming from this plugin "unread_issues":
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"87c0bb8d4cc3be31f4dea0e60883eb72", "period"=>"0", "req"=>"updated"}
Current user: Surkov.V (id=419)
Completed 200 OK in 807ms (Views: 0.3ms | ActiveRecord: 25.5ms)
Started GET "/issue_reads/count/unread?counter_id=c4aad251ee5e7ded9635ffe658447e92&period=0" for 192.168.21.190 at 2016-07-13 12:03:41 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"c4aad251ee5e7ded9635ffe658447e92", "period"=>"0", "req"=>"unread"}
Current user: Surkov.V (id=419)
Completed 200 OK in 1477ms (Views: 0.2ms | ActiveRecord: 23.9ms)
Started GET "/issue_reads/count/assigned?counter_id=e0c20af0ad02031c9b817fab3ea7c6e3&period=0" for 192.168.21.190 at 2016-07-13 12:03:42 +0300
Processing by IssueReadsController#count as JSON
Parameters: {"counter_id"=>"e0c20af0ad02031c9b817fab3ea7c6e3", "period"=>"0", "req"=>"assigned"}
Current user: Surkov.V (id=419)
Completed 200 OK in 892ms (Views: 0.2ms | ActiveRecord: 33.8ms)
3176 ms spent in IssueReadsController#count alone!
Updated by Wadim Incognito over 7 years ago
You right, but this is not a problem, because as you see, this plugin works in async mode - it don't suspends main page rendering.
Updated by Wadim Incognito over 7 years ago
Hi !!
Any progress ?
May I help you ?
Updated by Matthew Paul almost 7 years ago
I dont know if this is still an issue for you, but I wanted to update the ticket here with a solution so it can be closed out. The problem I think you are having is with redmine+ unread_issues.
If you look at that plugin, it creates a table, issue_reads with no indexes. This is a table of who viewed what issues.
So, the solution is to add an index like -
create index index_issue_reads_on_issue_id on issue_reads(issue_id);
That took my updates/views etc down from 30 seconds to around 4
Updated by Wadim Incognito almost 7 years ago
Hi !!
Unfortunately, we always have this index.
And as I've mentioned earlier #23275#note-5 without plugins we have the same behavior.
So no, it's not unread_issues problem - it's in redmine's core.
Actions