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.

Sign up for GitHub

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

Jump to bottom

Add New Provider page is slow #70

Closed
cben opened this issue Jan 4, 2017 · 4 comments
Closed

Add New Provider page is slow #70

cben opened this issue Jan 4, 2017 · 4 comments
Labels
performance stale

Comments

@cben
Copy link
Contributor

cben commented Jan 4, 2017

E.g. GET for /ems_container/new takes 3–9 seconds — before loading any linked assets!
Is it "standard developement mode slowness"? Feels unreasonable for just loading an empty form, would like to understand.

Might be result of sharing logic for all provider types (selected by ng-if)?
it shows some unrelevant DB queries for Openstack, but those are quick don't explain the slowness.

Then tons of assets get loaded more or less in parallel,
then there is ~5sec gap (I suppose JS runs?),
then it requests OpenSans, /api/notifications and several notifications .htmls,
and finally /ems_container/ems_container_form_fields/new — ideally should happen early, not sure if blocks rendering.

Around that time, timeline shows couple >1second "Parse HTML" which actually constists of running JS -> miqBootstrap...

[----] D, [2017-01-04T16:23:33.151067 #13684:2aabaf6240f0] DEBUG -- : PostgreSQLAdapter#log_after_checkin, connection_pool: size: 5, connections: 5, in use: 0, waiting_in_queue: 0
[----] D, [2017-01-04T16:23:34.738222 #13684:3faf3a003f24] DEBUG -- : PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 5, in use: 1, waiting_in_queue: 0
[----] I, [2017-01-04T16:23:34.739324 #13684:3faf3a003f24]  INFO -- : Started GET "/ems_container/new" for ::1 at 2017-01-04 16:23:34 +0200
[----] I, [2017-01-04T16:23:34.881941 #13684:3faf3a003f24]  INFO -- : Processing by EmsContainerController#new as HTML
[----] D, [2017-01-04T16:23:34.909980 #13684:3faf3a003f24] DEBUG -- :   User Load (3.9ms)  SELECT  "users".* FROM "users" WHERE ("users"."id" BETWEEN $1 AND $2) AND "users"."userid" = $3 LIMIT $4  [["id", 0], ["id", 999999999999], ["userid", "admin"], ["LIMIT", 1]]
[----] D, [2017-01-04T16:23:34.914627 #13684:3faf3a003f24] DEBUG -- :   User Inst Including Associations (1.8ms - 1rows)
[----] D, [2017-01-04T16:23:34.927031 #13684:3faf3a003f24] DEBUG -- :   MiqGroup Load (2.2ms)  SELECT  "miq_groups".* FROM "miq_groups" WHERE "miq_groups"."id" = $1 LIMIT $2  [["id", 2], ["LIMIT", 1]]
[----] D, [2017-01-04T16:23:34.930932 #13684:3faf3a003f24] DEBUG -- :   MiqGroup Inst Including Associations (2.4ms - 1rows)
[----] D, [2017-01-04T16:23:34.947414 #13684:3faf3a003f24] DEBUG -- :   Tenant Load (1.7ms)  SELECT  "tenants".* FROM "tenants" WHERE "tenants"."id" = $1 LIMIT $2  [["id", 1], ["LIMIT", 1]]
[----] D, [2017-01-04T16:23:34.948427 #13684:3faf3a003f24] DEBUG -- :   Tenant Inst Including Associations (0.4ms - 1rows)
[----] D, [2017-01-04T16:23:34.962532 #13684:3faf3a003f24] DEBUG -- :   MiqUserRole Load (1.3ms)  SELECT  "miq_user_roles".* FROM "miq_user_roles" INNER JOIN "entitlements" ON "miq_user_roles"."id" = "entitlements"."miq_user_role_id" WHERE "entitlements"."miq_group_id" = $1 LIMIT $2  [["miq_group_id", 2], ["LIMIT", 1]]
[----] D, [2017-01-04T16:23:34.966377 #13684:3faf3a003f24] DEBUG -- :   MiqUserRole Inst Including Associations (1.5ms - 1rows)
[----] D, [2017-01-04T16:23:34.984036 #13684:3faf3a003f24] DEBUG -- :   MiqProductFeature Load (4.5ms)  SELECT "miq_product_features".* FROM "miq_product_features" INNER JOIN "miq_roles_features" ON "miq_product_features"."id" = "miq_roles_features"."miq_product_feature_id" WHERE "miq_roles_features"."miq_user_role_id" = $1  [["miq_user_role_id", 1]]
[----] D, [2017-01-04T16:23:34.987674 #13684:3faf3a003f24] DEBUG -- :   MiqProductFeature Inst Including Associations (2.3ms - 1rows)
[----] D, [2017-01-04T16:23:35.009070 #13684:3faf3a003f24] DEBUG -- :   Zone Load (3.6ms)  SELECT "zones".* FROM "zones" ORDER BY lower(description)
[----] D, [2017-01-04T16:23:35.009768 #13684:3faf3a003f24] DEBUG -- :   Zone Inst Including Associations (0.2ms - 1rows)
[----] D, [2017-01-04T16:23:35.012825 #13684:3faf3a003f24] DEBUG -- :    (0.4ms)  SELECT "providers"."name", "providers"."id" FROM "providers" WHERE "providers"."type" IN ('ManageIQ::Providers::Openstack::Provider')
[----] D, [2017-01-04T16:23:35.034810 #13684:3faf3a003f24] DEBUG -- :   CACHE (0.4ms)  SELECT "zones".* FROM "zones" ORDER BY lower(description)
[----] D, [2017-01-04T16:23:35.035476 #13684:3faf3a003f24] DEBUG -- :   Zone Inst Including Associations (0.1ms - 1rows)
[----] D, [2017-01-04T16:23:35.047611 #13684:3faf3a003f24] DEBUG -- :   ManageIQ::Providers::Openstack::Provider Load (2.0ms)  SELECT "providers".* FROM "providers" WHERE "providers"."type" IN ('ManageIQ::Providers::Openstack::Provider') ORDER BY lower(name)
[----] D, [2017-01-04T16:23:35.050584 #13684:3faf3a003f24] DEBUG -- :   ManageIQ::Providers::Openstack::Provider Inst Including Associations (0.1ms - 0rows)
[----] I, [2017-01-04T16:23:35.059027 #13684:3faf3a003f24]  INFO -- :   Rendering /home/bpaskinc/miq/manageiq-ui-classic/app/views/ems_container/new.html.haml within layouts/application
[----] I, [2017-01-04T16:23:35.061917 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_flash_msg.html.haml (0.1ms)
[----] I, [2017-01-04T16:23:35.067094 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_endpoints_angular.html.haml (1.7ms)
[----] I, [2017-01-04T16:23:35.071626 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (0.5ms)
[----] I, [2017-01-04T16:23:35.071957 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_auth_credentials_angular_bootstrap.html.haml (3.4ms)
[----] I, [2017-01-04T16:23:35.076233 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (0.5ms)
[----] I, [2017-01-04T16:23:35.076519 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_auth_service_account_angular.html.haml (3.3ms)
[----] I, [2017-01-04T16:23:35.084601 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_endpoints_angular.html.haml (6.5ms)
[----] I, [2017-01-04T16:23:35.093502 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_endpoints_angular.html.haml (3.0ms)
[----] I, [2017-01-04T16:23:35.096510 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (0.3ms)
[----] I, [2017-01-04T16:23:35.096792 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_auth_credentials_angular_bootstrap.html.haml (1.9ms)
[----] I, [2017-01-04T16:23:35.100037 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (0.4ms)
[----] I, [2017-01-04T16:23:35.100335 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_auth_credentials_angular_bootstrap.html.haml (2.2ms)
[----] I, [2017-01-04T16:23:35.110479 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (1.0ms)
[----] I, [2017-01-04T16:23:35.114273 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_auth_credentials_angular_bootstrap.html.haml (9.3ms)
[----] I, [2017-01-04T16:23:35.124857 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular-bootstrap/_endpoints_angular.html.haml (3.6ms)
[----] I, [2017-01-04T16:23:35.131805 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_form_buttons_verify_angular.html.haml (1.3ms)
[----] I, [2017-01-04T16:23:35.133796 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_multi_auth_credentials.html.haml (69.7ms)
[----] I, [2017-01-04T16:23:35.140605 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/angular/_x_edit_buttons_angular.html.haml (2.6ms)
[----] I, [2017-01-04T16:23:35.141532 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/ems_container/_form.html.haml (80.5ms)
[----] I, [2017-01-04T16:23:35.144816 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/ems_container/new.html.haml within layouts/application (85.1ms)
[----] I, [2017-01-04T16:23:35.152028 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_doctype.html.haml (0.5ms)
[----] I, [2017-01-04T16:23:35.668647 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/stylesheets/_template50.html.haml (0.1ms)
[----] I, [2017-01-04T16:23:37.613053 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_i18n_js.html.haml (0.5ms)
[----] I, [2017-01-04T16:23:37.631720 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_about_modal.html.haml (12.3ms)
[----] D, [2017-01-04T16:23:37.662229 #13684:3faf3a003f24] DEBUG -- :   MiqGroup Load (5.0ms)  SELECT "miq_groups".* FROM "miq_groups" INNER JOIN "miq_groups_users" ON "miq_groups"."id" = "miq_groups_users"."miq_group_id" WHERE "miq_groups_users"."user_id" = $1  [["user_id", 1]]
[----] D, [2017-01-04T16:23:37.666294 #13684:3faf3a003f24] DEBUG -- :   MiqGroup Inst Including Associations (2.5ms - 1rows)
[----] I, [2017-01-04T16:23:37.670259 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_user_options.html.haml (26.2ms)
[----] I, [2017-01-04T16:23:37.671624 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_spinner.html.haml (0.1ms)
[----] I, [2017-01-04T16:23:37.672949 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_lightbox_panel.html.haml (0.1ms)
[----] I, [2017-01-04T16:23:37.676480 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_notifications_drawer.html.haml (1.0ms)
[----] I, [2017-01-04T16:23:37.680316 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_toast_list.html.haml (0.4ms)
[----] I, [2017-01-04T16:23:37.681372 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_header.html.haml (64.7ms)
[----] D, [2017-01-04T16:23:37.719558 #13684:3faf3a003f24] DEBUG -- :    (3.2ms)  SELECT "ext_management_systems"."id" FROM "ext_management_systems" WHERE "ext_management_systems"."type" IN ('ManageIQ::Providers::Openstack::InfraManager')
[----] D, [2017-01-04T16:23:37.726315 #13684:3faf3a003f24] DEBUG -- :   CACHE (0.3ms)  SELECT "ext_management_systems"."id" FROM "ext_management_systems" WHERE "ext_management_systems"."type" IN ('ManageIQ::Providers::Openstack::InfraManager')
[----] I, [2017-01-04T16:23:37.761911 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_vertical_navbar.html.haml (75.2ms)
[----] I, [2017-01-04T16:23:37.764116 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_breadcrumbs.html.haml (0.1ms)
[----] I, [2017-01-04T16:23:37.768922 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_tabs.html.haml (0.8ms)
[----] I, [2017-01-04T16:23:37.771488 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_content.html.haml (86.9ms)
[----] I, [2017-01-04T16:23:37.779658 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_adv_search.html.haml (0.5ms)
[----] I, [2017-01-04T16:23:37.820526 #13684:3faf3a003f24]  INFO -- :   Rendered /home/bpaskinc/miq/manageiq-ui-classic/app/views/layouts/_footer.html.haml (44.8ms)
[----] D, [2017-01-04T16:23:44.590627 #13684:3faedcd83c0c] DEBUG -- : PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 5, in use: 3, waiting_in_queue: 0
Session:	 Hash of Size 11809, Elements 31
=================================[----] I, [2017-01-04T16:23:44.616863 #13684:3faedcd83c0c]  INFO -- : Finished "/ws/notifications" [WebSocket] for ::1 at 2017-01-04 16:23:44 +0200
[----] I, [2017-01-04T16:23:44.618004 #13684:3faedcd83c0c]  INFO -- : NotificationChannel stopped streaming from notifications_1
[----] D, [2017-01-04T16:23:44.618467 #13684:3faf3a003e98] DEBUG -- : PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 5, in use: 3, waiting_in_queue: 0
[----] D, [2017-01-04T16:23:44.619814 #13684:3faedcd83c0c] DEBUG -- : PostgreSQLAdapter#log_after_checkin, connection_pool: size: 5, connections: 5, in use: 2, waiting_in_queue: 0
[----] I, [2017-01-04T16:23:44.628717 #13684:3faf3a003e98]  INFO -- : Started GET "/ws/notifications" for ::1 at 2017-01-04 16:23:44 +0200

[----] I, [2017-01-04T16:23:44.796030 #13684:3faf3a003f24]  INFO -- : Completed 200 OK in 9912ms (Views: 2756.9ms | ActiveRecord: 28.5ms)

@miq-bot add-label performance
@miq-bot
Copy link
Member

miq-bot commented Jan 5, 2017

@cben Cannot apply the following label because they are not recognized: performance

@cben cben changed the title And New Provider page is slow Add New Provider page is slow Jan 5, 2017
@miq-bot
Copy link
Member

miq-bot commented Dec 25, 2017

This issue has been automatically marked as stale because it has not been updated for at least 6 months.

If you can still reproduce this issue on the current release or on master, please reply with all of the information you have about it in order to keep the issue open.

Thank you for all your contributions!

@miq-bot miq-bot added the stale label Dec 25, 2017
@JPrause
Copy link
Member

JPrause commented Jan 28, 2019

@cben is this still a valid issue? If yes, lease remove the stale label. If not can you close.
If there's no update by next week, I'll be closing this issue.

@JPrause
Copy link
Member

JPrause commented Feb 6, 2019

Closing issue. If you feel the issue needs to remain open, please either reopen or let me know and it will be reopened.
@miq-bot close_issue

@miq-bot miq-bot closed this as completed Feb 6, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
performance stale
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@martinpovolny @cben @miq-bot @JPrause