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

Poor Performance of the Roles and Permissions Page #2073

Closed
ohappykust opened this issue Jun 29, 2023 · 4 comments · Fixed by #2209
Closed

Poor Performance of the Roles and Permissions Page #2073

ohappykust opened this issue Jun 29, 2023 · 4 comments · Fixed by #2209

Comments

@ohappykust
Copy link

ohappykust commented Jun 29, 2023

Hello!
I am engaged with the team in a small customization of Superset, where Flask Appbuilder is used as the basis. Roles and rights there are used stock from this library. When adding a large number of roles and permissions, the page starts to load unrealistically long. It can reach about 5-10 minutes.
When debugging through the SQLAlchemy logger, you can see a huge number of the same type of queries to the database.
I tried to understand the library code, but I could not quite understand where this problem is.

Environment

Flask-Appbuilder version: 4.3.3

pip freeze output:

apispec==6.3.0
attrs==23.1.0
Babel==2.12.1
blinker==1.6.2
click==8.1.3
colorama==0.4.6
Deprecated==1.2.14
dnspython==2.3.0
email-validator==1.3.1
Flask==2.3.2
Flask-AppBuilder==4.3.3
Flask-Babel==2.0.0
Flask-JWT-Extended==4.5.2
Flask-Limiter==3.3.1
Flask-Login==0.6.2
Flask-SQLAlchemy==2.5.1
Flask-WTF==1.1.1
greenlet==2.0.2
idna==3.4
importlib-resources==5.12.0
itsdangerous==2.1.2
Jinja2==3.1.2
jsonschema==4.17.3
limits==3.5.0
markdown-it-py==3.0.0
MarkupSafe==2.1.3
marshmallow==3.19.0
marshmallow-sqlalchemy==0.26.1
mdurl==0.1.2
ordered-set==4.1.0
packaging==23.1
prison==0.2.1
psycopg2-binary==2.9.6
Pygments==2.15.1
PyJWT==2.7.0
pyrsistent==0.19.3
python-dateutil==2.8.2
pytz==2023.3
PyYAML==6.0
rich==13.4.2
six==1.16.0
SQLAlchemy==1.4.48
SQLAlchemy-Utils==0.41.1
typing_extensions==4.7.0
Werkzeug==2.3.6
wrapt==1.15.0
WTForms==3.0.1

Describe the expected results

In my opinion, the number of requests should be minimal and optimized. I think it can be optimized.
In console we can see something like this:

2023-06-29 16:42:43,384:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,384:INFO:sqlalchemy.engine.Engine:[cached since 0.6591s ago] {'pk_1': 94}
2023-06-29 16:42:43,385:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,386:DEBUG:sqlalchemy.engine.Engine:Row (94, '[examples].[messages_channels](id:15)')
2023-06-29 16:42:43,387:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,387:INFO:sqlalchemy.engine.Engine:[cached since 0.6617s ago] {'pk_1': 95}
2023-06-29 16:42:43,388:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,389:DEBUG:sqlalchemy.engine.Engine:Row (95, '[examples].[FCC 2018 Survey](id:16)')
2023-06-29 16:42:43,390:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,390:INFO:sqlalchemy.engine.Engine:[cached since 0.6648s ago] {'pk_1': 96}
2023-06-29 16:42:43,391:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,392:DEBUG:sqlalchemy.engine.Engine:Row (96, '[examples].[threads](id:17)')
2023-06-29 16:42:43,392:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,393:INFO:sqlalchemy.engine.Engine:[cached since 0.6675s ago] {'pk_1': 97}
2023-06-29 16:42:43,394:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,394:DEBUG:sqlalchemy.engine.Engine:Row (97, '[examples].[channel_members](id:18)')
2023-06-29 16:42:43,395:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,395:INFO:sqlalchemy.engine.Engine:[cached since 0.6702s ago] {'pk_1': 98}
2023-06-29 16:42:43,397:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,397:DEBUG:sqlalchemy.engine.Engine:Row (98, '[examples].[video_game_sales](id:19)')
2023-06-29 16:42:43,398:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,398:INFO:sqlalchemy.engine.Engine:[cached since 0.673s ago] {'pk_1': 99}
2023-06-29 16:42:43,400:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,400:DEBUG:sqlalchemy.engine.Engine:Row (99, '[examples].[messages](id:20)')
2023-06-29 16:42:43,401:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,401:INFO:sqlalchemy.engine.Engine:[cached since 0.6761s ago] {'pk_1': 100}
2023-06-29 16:42:43,402:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,403:DEBUG:sqlalchemy.engine.Engine:Row (100, '[examples].[cleaned_sales_data](id:21)')
2023-06-29 16:42:43,403:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,404:INFO:sqlalchemy.engine.Engine:[cached since 0.6785s ago] {'pk_1': 101}
2023-06-29 16:42:43,405:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,405:DEBUG:sqlalchemy.engine.Engine:Row (101, '[examples].[users](id:22)')
2023-06-29 16:42:43,406:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,406:INFO:sqlalchemy.engine.Engine:[cached since 0.6812s ago] {'pk_1': 102}
2023-06-29 16:42:43,408:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,459:DEBUG:sqlalchemy.engine.Engine:Row (102, '[examples].[members_channels_2](id:23)')
2023-06-29 16:42:43,461:INFO:sqlalchemy.engine.Engine:SELECT ab_permission.id AS ab_permission_id, ab_permission.name AS ab_permission_name 
FROM ab_permission 
WHERE ab_permission.id = %(pk_1)s
2023-06-29 16:42:43,461:INFO:sqlalchemy.engine.Engine:[cached since 2.806s ago] {'pk_1': 102}
2023-06-29 16:42:43,464:DEBUG:sqlalchemy.engine.Engine:Col ('ab_permission_id', 'ab_permission_name')
2023-06-29 16:42:43,464:DEBUG:sqlalchemy.engine.Engine:Row (102, 'can_read_folder')
2023-06-29 16:42:43,465:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,465:INFO:sqlalchemy.engine.Engine:[cached since 0.7398s ago] {'pk_1': 105}
2023-06-29 16:42:43,467:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,467:DEBUG:sqlalchemy.engine.Engine:Row (105, '[Root](id:3)')
2023-06-29 16:42:43,468:INFO:sqlalchemy.engine.Engine:SELECT ab_permission.id AS ab_permission_id, ab_permission.name AS ab_permission_name 
FROM ab_permission 
WHERE ab_permission.id = %(pk_1)s
2023-06-29 16:42:43,468:INFO:sqlalchemy.engine.Engine:[cached since 2.813s ago] {'pk_1': 103}
2023-06-29 16:42:43,470:DEBUG:sqlalchemy.engine.Engine:Col ('ab_permission_id', 'ab_permission_name')
2023-06-29 16:42:43,470:DEBUG:sqlalchemy.engine.Engine:Row (103, 'can_write_folder')
2023-06-29 16:42:43,471:INFO:sqlalchemy.engine.Engine:SELECT ab_permission.id AS ab_permission_id, ab_permission.name AS ab_permission_name 
FROM ab_permission 
WHERE ab_permission.id = %(pk_1)s
2023-06-29 16:42:43,471:INFO:sqlalchemy.engine.Engine:[cached since 2.816s ago] {'pk_1': 105}
2023-06-29 16:42:43,472:DEBUG:sqlalchemy.engine.Engine:Col ('ab_permission_id', 'ab_permission_name')
2023-06-29 16:42:43,473:DEBUG:sqlalchemy.engine.Engine:Row (105, 'can_delete_folder')
2023-06-29 16:42:43,474:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,474:INFO:sqlalchemy.engine.Engine:[cached since 0.7487s ago] {'pk_1': 106}
2023-06-29 16:42:43,475:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,476:DEBUG:sqlalchemy.engine.Engine:Row (106, '[Child One](id:4)')
2023-06-29 16:42:43,477:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,477:INFO:sqlalchemy.engine.Engine:[cached since 0.7516s ago] {'pk_1': 107}
2023-06-29 16:42:43,479:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,479:DEBUG:sqlalchemy.engine.Engine:Row (107, '[Child Two](id:5)')
2023-06-29 16:42:43,480:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,480:INFO:sqlalchemy.engine.Engine:[cached since 0.7549s ago] {'pk_1': 108}
2023-06-29 16:42:43,482:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,482:DEBUG:sqlalchemy.engine.Engine:Row (108, '[Child OneTwoThree](id:6)')
2023-06-29 16:42:43,483:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,484:INFO:sqlalchemy.engine.Engine:[cached since 0.7585s ago] {'pk_1': 109}
2023-06-29 16:42:43,486:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,486:DEBUG:sqlalchemy.engine.Engine:Row (109, '[rewrewrewrewrewrew](id:8)')
2023-06-29 16:42:43,487:INFO:sqlalchemy.engine.Engine:SELECT ab_permission.id AS ab_permission_id, ab_permission.name AS ab_permission_name 
FROM ab_permission 
WHERE ab_permission.id = %(pk_1)s
2023-06-29 16:42:43,487:INFO:sqlalchemy.engine.Engine:[cached since 2.832s ago] {'pk_1': 106}
2023-06-29 16:42:43,489:DEBUG:sqlalchemy.engine.Engine:Col ('ab_permission_id', 'ab_permission_name')
2023-06-29 16:42:43,490:DEBUG:sqlalchemy.engine.Engine:Row (106, 'can_chart')
2023-06-29 16:42:43,491:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,491:INFO:sqlalchemy.engine.Engine:[cached since 0.7656s ago] {'pk_1': 111}
2023-06-29 16:42:43,494:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,495:DEBUG:sqlalchemy.engine.Engine:Row (111, 'UserStatsChartView')
2023-06-29 16:42:43,496:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,496:INFO:sqlalchemy.engine.Engine:[cached since 0.7714s ago] {'pk_1': 112}
2023-06-29 16:42:43,500:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,500:DEBUG:sqlalchemy.engine.Engine:Row (112, "User's Statistics")
2023-06-29 16:42:43,501:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,501:INFO:sqlalchemy.engine.Engine:[cached since 0.7761s ago] {'pk_1': 113}
2023-06-29 16:42:43,503:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,504:DEBUG:sqlalchemy.engine.Engine:Row (113, 'PermissionModelView')
2023-06-29 16:42:43,504:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,505:INFO:sqlalchemy.engine.Engine:[cached since 0.7795s ago] {'pk_1': 114}
2023-06-29 16:42:43,506:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,507:DEBUG:sqlalchemy.engine.Engine:Row (114, 'Base Permissions')
2023-06-29 16:42:43,508:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,508:INFO:sqlalchemy.engine.Engine:[cached since 0.7826s ago] {'pk_1': 115}
2023-06-29 16:42:43,510:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,511:DEBUG:sqlalchemy.engine.Engine:Row (115, 'ViewMenuModelView')
2023-06-29 16:42:43,512:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,512:INFO:sqlalchemy.engine.Engine:[cached since 0.7867s ago] {'pk_1': 116}
2023-06-29 16:42:43,514:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,514:DEBUG:sqlalchemy.engine.Engine:Row (116, 'Views/Menus')
2023-06-29 16:42:43,515:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,516:INFO:sqlalchemy.engine.Engine:[cached since 0.7905s ago] {'pk_1': 117}
2023-06-29 16:42:43,518:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,518:DEBUG:sqlalchemy.engine.Engine:Row (117, 'PermissionViewModelView')
2023-06-29 16:42:43,519:INFO:sqlalchemy.engine.Engine:SELECT ab_view_menu.id AS ab_view_menu_id, ab_view_menu.name AS ab_view_menu_name 
FROM ab_view_menu 
WHERE ab_view_menu.id = %(pk_1)s
2023-06-29 16:42:43,520:INFO:sqlalchemy.engine.Engine:[cached since 0.7945s ago] {'pk_1': 118}
2023-06-29 16:42:43,522:DEBUG:sqlalchemy.engine.Engine:Col ('ab_view_menu_id', 'ab_view_menu_name')
2023-06-29 16:42:43,523:DEBUG:sqlalchemy.engine.Engine:Row (118, 'Permission on Views/Menus')

Describe the actual results

A lot of requests of the same type are sent to the database, which greatly slows down the page with a large number of new roles and permissions.

Steps to reproduce

  1. Generate a new app through flask fab create-app
  2. Paste logging.getLogger('sqlalchemy.engine').setLevel(logging.DEBUG) to 17 line into init.py file to see all debug info from SQLAlchemy
  3. Run application
  4. Go to the /roles/list and see into the console log
@tirkarthi
Copy link
Contributor

See also

#796
#875

@Paulo456
Copy link

problem in representation:
class PermissionView(Model):
....
return str(self.permission).replace("_", " ") + " on " + str(self.view_menu)

from this point we have big amount of queries to two tables ab_view_menu and ab_permission

@Paulo456
Copy link

Paulo456 commented Jul 11, 2023

in log sqlalchemy looks good if u change model PermissionView to this:

- permission = relationship("Permission")
+ permission = relationship("Permission", lazy="joined")
view_menu_id = Column(Integer, ForeignKey("ab_view_menu.id"))
- view_menu = relationship("ViewMenu")
+ view_menu = relationship("ViewMenu", lazy="joined")

@ohappykust
Copy link
Author

@Paulo456 thanks, it works!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants