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

Deed list takes too long to render; causes outages #3776

Closed
benwbrum opened this issue Sep 7, 2023 · 2 comments · Fixed by #3777
Closed

Deed list takes too long to render; causes outages #3776

benwbrum opened this issue Sep 7, 2023 · 2 comments · Fixed by #3777

Comments

@benwbrum
Copy link
Owner

benwbrum commented Sep 7, 2023

We experienced our first outage in quite a while yesterday. When searching for long-running processes, the culprit may be the new deed list, perhaps with all deeds selected.

Example excerpts from the log file:

I, [2023-09-06T20:08:22.824119 #23053]  INFO -- : Started GET "/deed/list?user_id=yale" for 85.208.96.194 at 2023-09-06 20:08:22 +0000
I, [2023-09-06T20:08:22.826499 #23053]  INFO -- : Processing by DeedController#list as HTML
I, [2023-09-06T20:08:22.826828 #23053]  INFO -- :   Parameters: {"user_id"=>"yale"}
I, [2023-09-06T20:08:22.828276 #23053]  INFO -- : [ahoy] Visit excluded
I, [2023-09-06T20:08:22.836318 #23053]  INFO -- :   Rendering deed/list.html.slim within layouts/application
I, [2023-09-06T20:09:45.078987 #23053]  INFO -- :   Rendered shared/_profile_picture.html.slim (Duration: 0.5ms | Allocations: 232)
I, [2023-09-06T20:10:38.857330 #23053]  INFO -- :   Rendered deed/_deed.html.slim (Duration: 53772.6ms | Allocations: 7124)
I, [2023-09-06T20:10:38.863752 #23053]  INFO -- :   Rendered shared/_profile_picture.html.slim (Duration: 0.8ms | Allocations: 231)
I, [2023-09-06T20:10:38.876435 #23053]  INFO -- :   Rendered deed/_deed.html.slim (Duration: 2.9ms | Allocations: 1148)

[eight dozen lines omitted]

I, [2023-09-06T20:10:39.266820 #23053]  INFO -- :   Rendered shared/_profile_picture.html.slim (Duration: 0.3ms | Allocations: 231)
I, [2023-09-06T20:10:39.271649 #23053]  INFO -- :   Rendered deed/_deed.html.slim (Duration: 2.0ms | Allocations: 1002)
I, [2023-09-06T20:10:39.273876 #23053]  INFO -- :   Rendered shared/_profile_picture.html.slim (Duration: 0.2ms | Allocations: 231)
I, [2023-09-06T20:10:39.278322 #23053]  INFO -- :   Rendered deed/_deed.html.slim (Duration: 1.7ms | Allocations: 1150)
I, [2023-09-06T20:10:39.283671 #23053]  INFO -- :   Rendered shared/_profile_picture.html.slim (Duration: 0.5ms | Allocations: 231)
I, [2023-09-06T20:10:39.290992 #23053]  INFO -- :   Rendered deed/_deed.html.slim (Duration: 2.4ms | Allocations: 1150)
I, [2023-09-06T20:10:39.292866 #23053]  INFO -- :   Rendered deed/list.html.slim within layouts/application (Duration: 136456.1ms | Allocations: 326929)
I, [2023-09-06T20:10:39.294707 #23053]  INFO -- :   Rendered layouts/_ga.erb (Duration: 0.1ms | Allocations: 35)
I, [2023-09-06T20:10:39.295436 #23053]  INFO -- :   Rendered layouts/_mixpanel.erb (Duration: 0.1ms | Allocations: 34)
I, [2023-09-06T20:10:39.296181 #23053]  INFO -- :   Rendered layouts/_fb_pixel.erb (Duration: 0.1ms | Allocations: 34)
I, [2023-09-06T20:10:39.301498 #23053]  INFO -- :   Rendered shared/_breadcrumbs.html.slim (Duration: 0.2ms | Allocations: 37)
I, [2023-09-06T20:10:39.302239 #23053]  INFO -- :   Rendered shared/_user_collection_footer.html.slim (Duration: 0.1ms | Allocations: 33)
I, [2023-09-06T20:10:39.304551 #23053]  INFO -- : [ahoy] Event excluded
I, [2023-09-06T20:10:39.305441 #23053]  INFO -- : Completed 200 OK in 136478ms (Views: 452.1ms | ActiveRecord: 136017.9ms | Allocations: 337867)
I, [2023-09-06T20:10:39.305819 #23053]  INFO -- : Oink Action: deed#list
I, [2023-09-06T20:10:39.306067 #23053]  INFO -- : Memory usage: 4017540 | PID: 23053
I, [2023-09-06T20:10:39.306260 #23053]  INFO -- : Instantiation Breakdown: Total: 304 | Collection: 100 | User: 51 | Deed: 50 | Work: 50 | Page: 50 | PageBlock: 3
I, [2023-09-06T20:10:39.306380 #23053]  INFO -- : Oink Log Entry Complete

Another problem at the same time may have been from a different process waiting on the DB?

I, [2023-09-06T20:09:11.386824 #23124]  INFO -- : Started GET "/woodruff/woodruffpapers/review" for 159.118.13.218 at 2023-09-06 20:09:11 +0000
I, [2023-09-06T20:09:11.389029 #23124]  INFO -- : Processing by CollectionController#reviewer_dashboard as HTML
I, [2023-09-06T20:09:11.389293 #23124]  INFO -- :   Parameters: {"user_slug"=>"woodruff", "collection_id"=>"woodruffpapers"}
I, [2023-09-06T20:09:12.193769 #23124]  INFO -- :   Rendering collection/reviewer_dashboard.html.slim within layouts/application
I, [2023-09-06T20:09:12.201845 #23124]  INFO -- :   Rendered shared/_collection_tabs.html.slim (Duration: 7.1ms | Allocations: 3659)
I, [2023-09-06T20:09:12.202637 #23124]  INFO -- :   Rendered shared/_review_breadcrumbs.html.slim (Duration: 0.2ms | Allocations: 64)
I, [2023-09-06T20:10:51.855774 #23124]  INFO -- :   Rendered collection/reviewer_dashboard.html.slim within layouts/application (Duration: 99661.3ms | Allocations: 314697)
I, [2023-09-06T20:10:51.857659 #23124]  INFO -- :   Rendered layouts/_ga.erb (Duration: 0.1ms | Allocations: 35)
I, [2023-09-06T20:10:51.858445 #23124]  INFO -- :   Rendered layouts/_mixpanel.erb (Duration: 0.1ms | Allocations: 34)
I, [2023-09-06T20:10:51.859403 #23124]  INFO -- :   Rendered layouts/_fb_pixel.erb (Duration: 0.1ms | Allocations: 33)
I, [2023-09-06T20:10:51.865284 #23124]  INFO -- :   Rendered shared/_breadcrumbs.html.slim (Duration: 1.4ms | Allocations: 557)
I, [2023-09-06T20:10:51.866283 #23124]  INFO -- :   Rendered shared/_user_collection_footer.html.slim (Duration: 0.2ms | Allocations: 39)
I, [2023-09-06T20:10:51.869368 #23124]  INFO -- :   Rendered shared/_intercom_customer.html.erb (Duration: 0.3ms | Allocations: 56)
I, [2023-09-06T20:10:51.878302 #23124]  INFO -- : Completed 200 OK in 100489ms (Views: 246.5ms | ActiveRecord: 100212.0ms | Allocations: 352141)
I, [2023-09-06T20:10:51.878725 #23124]  INFO -- : Oink Action: collection#reviewer_dashboard
I, [2023-09-06T20:10:51.878942 #23124]  INFO -- : Memory usage: 2713160 | PID: 23124
I, [2023-09-06T20:10:51.879109 #23124]  INFO -- : Instantiation Breakdown: Total: 85 | User: 81 | Collection: 1 | SearchAttempt: 1 | Visit: 1 | Ahoy::Event: 1
I, [2023-09-06T20:10:51.879268 #23124]  INFO -- : Oink Log Entry Complete
@benwbrum
Copy link
Owner Author

benwbrum commented Sep 8, 2023

See relevant charts from New Relic:
![https://gorgon.nr-assets.net/image/a2e8000b-5973-4bc2-8802-1afae238811d?type=area]

@benwbrum
Copy link
Owner Author

benwbrum commented Sep 8, 2023

image

@benwbrum benwbrum linked a pull request Sep 8, 2023 that will close this issue
benwbrum added a commit that referenced this issue Sep 8, 2023
Only use datatables on collection notes list for #3776
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant