search

apache / superset

Apache Superset is a Data Visualization and Data Exploration Platform
https://superset.apache.org/
Apache License 2.0
62.17k stars 13.65k forks source link

Superset very slow when FAB DB hosted on separate server #2907

Closed BobSaintClare closed 6 years ago

BobSaintClare commented 7 years ago

Superset version

0.17.5

Context:

OS: OS X 10.10.5 (my local machine); or AWS EC2/ECS t2.medium with Docker image DB is hosted on AWS: I've tried Postgres via Heroku, Postgres directly on AWS RDS, and MySQL on AWS - all behave the same. Server is running locally under a virtual env (setup via instructions on https://github.com/airbnb/superset/blob/master/CONTRIBUTING.md) Tried also Docker image created off https://hub.docker.com/r/amancevice/superset/ and hosted on AWS EC2 (via ECS)

My superset_config.py is as follow

MAPBOX_API_KEY = os.getenv('MAPBOX_API_KEY', '')
CACHE_CONFIG = {
    'CACHE_TYPE': 'redis',
    'CACHE_DEFAULT_TIMEOUT': 300,
    'CACHE_KEY_PREFIX': 'superset_',
    'CACHE_REDIS_HOST': 'redis',
    'CACHE_REDIS_PORT': 6379,
    'CACHE_REDIS_DB': 1,
    'CACHE_REDIS_URL': 'redis://redis:6379/1'}
SQLALCHEMY_DATABASE_URI = "postgresql+psycopg2://userid:password@ec2-XXX.compute-1.amazonaws.com:5432/mypostgresdb"
SECRET_KEY = "SecretKey"
SUPERSET_WEBSERVER_TIMEOUT = 120

Issue:

Under my configuration, the server takes minutes to initialize, and once initialized, navigating to any page on superset takes 10+ seconds. Everything is blazing fast when the FAB DB is hosted on the same machine as the superset server - using either SQLite or Postgres.

Additional Info:

I've put on tracing at the SQLAlchemy level (via SQLALCHEMY_ECHO) and tried different pool size configurations. I've also put event listeners for most SQLA events http://docs.sqlalchemy.org/en/latest/core/events.html. What I'm seeing is that: . Initial class registration (which invokes register_sources) is part of a single DB transaction and takes minutes . When I add some test select statements in superset' init.py - initial connection to DB takes a couple of seconds, but subsequent calls use the connection pool and are much faster (100s of ms) . Overall - the app is too slow to be usable under this configuration - navigating to any page takes 10+ seconds

Questions:

  1. Is the FAB DB even intended to be on a separate server? (see https://stackoverflow.com/questions/41526926/how-to-cache-flask-app-builder-views)
  2. Or, do I have something off or missing in my configuration (e.g. cache, or pooling config)?

Any additional pointer appreciated. I can also share my logging code and output if needed.

xrmx commented 7 years ago

Look at your http proxy configuration.

BobSaintClare commented 7 years ago

What about it?

screen shot 2017-06-05 at 7 48 37 am

Also have the same issue with dockerized instance on EC2. Or did you mean some other proxy config?

xrmx commented 7 years ago

I mean http proxy on ec2: elb or whatever you have in front of the superset instance. You are not the first to report high latency and everytime it was a misconfiguration on the proxy :)

xrmx commented 7 years ago

Also if it takes minutes to load, how many workers are you loading? Do you have enough memory?

BobSaintClare commented 7 years ago

Thanks for the super-quick response.

. re: "how many workers are you loading? Do you have enough memory?" I'm using the default config: SUPERSET_WORKERS = 2 - I've also tried 1 and 4. I think I have enough memory - because everything runs super-fast when I'm accessing the DB on localhost (either sqlite or postgres)

. re: "I mean http proxy on ec2: elb or whatever you have in front of the superset instance" I'm sure I'm missing something obvious; but I don't think I have anything in front of my superset instance -especially when running it on my mac-, and I don't think I have anything in front of my DB instances hosted on aws -especially when spinned via Heroku-. I don't have any ELB anywhere.

But bottom-line: you're saying it should run just fine if the FAB DB is hosted on a separate server and there's probably something wrong in my network config somewhere. So if I just create a loop in py to connect/query via SQLAlchemy to those DBs I should experience similar latency. Or are there gunicorn or what-not configs I should also look into?

rumbin commented 7 years ago

@BobSaintClare Could you give it a try using superset==0.15.4? I remember that in my tests with recent versions, they seemed to load much slower than 0.15.4 which is installed on our productive system.

I would check it by myself, if I weren't on holidays right now...

BobSaintClare commented 7 years ago

Thanks @rumbin

Just tried - no luck. I've added some DB tracing - providing more details below:

  1. To trace DB events, I've created sqla_utils.py 
    
import logging
from sqlalchemy import event

def trace_db_events(logger, db_engine): @event.listens_for(db_engine.pool, 'checkin') def receive_checkin(dbapi_connection, connection_record): logger.info("trace_db_events - db_engine.pool - CHECKIN")

@event.listens_for(db_engine.pool, 'checkout')
def receive_checkout(dbapi_connection, connection_record, connection_proxy):
    logger.info("trace_db_events - db_engine.pool - CHECKOUT")

@event.listens_for(db_engine.pool, 'connect')
def receive_connect(dbapi_connection, connection_record):
    logger.info("trace_db_events - db_engine.pool - CONNECT")

@event.listens_for(db_engine.pool, 'first_connect')
def receive_first_connect(dbapi_connection, connection_record):
    logger.info("trace_db_events - db_engine.pool - FIRST_CONNECT")

@event.listens_for(db_engine.pool, 'invalidate')
def receive_invalidate(dbapi_connection, connection_record, exception):
    logger.info("trace_db_events - db_engine.pool - INVALIDATE")

@event.listens_for(db_engine.pool, 'reset')
def receive_reset(dbapi_connection, connection_record):
    logger.info("trace_db_events - db_engine.pool - RESET")

@event.listens_for(db_engine.pool, 'soft_invalidate')
def receive_soft_invalidate(dbapi_connection, connection_record, exception):
    logger.info("trace_db_events - db_engine.pool - SOFT_INVALIDATE")

@event.listens_for(db_engine, 'begin')
def receive_begin(conn):
    logger.info("trace_db_events - db_engine - begin")

@event.listens_for(db_engine, 'dbapi_error')
def receive_dbapi_error(conn, cursor, statement, parameters, context, exception):
    logger.info("trace_db_events - db_engine - dbapi_error")

@event.listens_for(db_engine, 'engine_connect')
def receive_engine_connect(conn, branch):
    logger.info("trace_db_events - db_engine - engine_connect")

@event.listens_for(db_engine, 'engine_disposed')
def receive_engine_disposed(engine):
    logger.info("trace_db_events - db_engine - engine_disposed")

@event.listens_for(db_engine, 'handle_error')
def receive_handle_error(exception_context):
    logger.info("trace_db_events - db_engine - handle_error")

@event.listens_for(db_engine, 'prepare_twophase')
def receive_prepare_twophase(conn, xid):
    logger.info("trace_db_events - db_engine - prepare_twophase")

@event.listens_for(db_engine, 'rollback')
def receive_rollback(conn):
    logger.info("trace_db_events - db_engine - rollback")

@event.listens_for(db_engine, 'rollback_twophase')
def receive_rollback_twophase(conn, xid, is_prepared):
    logger.info("trace_db_events - db_engine - rollback_twophase")

@event.listens_for(db_engine, 'set_connection_execution_options')
def receive_set_connection_execution_options(conn, opts):
    logger.info("trace_db_events - db_engine - set_connection_execution_options")

@event.listens_for(db_engine, 'set_engine_execution_options')
def receive_set_engine_execution_options(engine, opts):
    logger.info("trace_db_events - db_engine - set_engine_execution_options")

@event.listens_for(db_engine, 'do_connect')
def receive_do_connect(dialect, conn_rec, cargs, cparams):
    logger.info("trace_db_events - db_engine - do_connect")

2. I'm calling trace_db_events in superset' __init__
Just after `db = SQLA(app)`
![screen shot 2017-06-07 at 10 30 37 am](https://user-images.githubusercontent.com/3517109/26892203-65f5333a-4b6c-11e7-838a-1c4ac977290b.png)

3. Here is the trace I get when starting the server via `superset runserver`

/Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_SQLAlchemy-2.0-py3.6.egg/flask_sqlalchemy/init.py:30: ExtDeprecationWarning: Importing flask.ext.sqlalchemy is deprecated, use flask_sqlalchemy instead. from flask.ext.sqlalchemy._compat import iteritems, itervalues, xrange, \ /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Migrate-1.5.1-py3.6.egg/flask_migrate/init.py:4: ExtDeprecationWarning: Importing flask.ext.script is deprecated, use flask_script instead. from flask.ext.script import Manager Loaded your LOCAL configuration /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Cache-0.13.1-py3.6.egg/flask_cache/jinja2ext.py:33: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead. from flask.ext.cache import make_template_fragment_key 2017-06-07 10:20:31,628:INFO:root:trace_db_events - db_engine - do_connect 2017-06-07 10:20:33,889:INFO:root:trace_db_events - db_engine.pool - FIRST_CONNECT 2017-06-07 10:20:33,889:INFO:root:trace_db_events - db_engine.pool - CONNECT 2017-06-07 10:20:33,889:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:20:33,988:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:20:33,988:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:20:34,086:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:20:34,087:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:20:34,285:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:20:34,389:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:20:34,490:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:20:34,491:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:20:34,688:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:20:34,688:INFO:root:trace_db_events - db_engine - begin 2017-06-07 10:20:34,992:INFO:flask_appbuilder.base:Registering class MyIndexView on menu 2017-06-07 10:20:35,197:INFO:flask_appbuilder.base:Registering class UtilView on menu 2017-06-07 10:20:35,400:INFO:flask_appbuilder.base:Registering class LocaleView on menu 2017-06-07 10:20:35,603:INFO:flask_appbuilder.base:Registering class ResetPasswordView on menu 2017-06-07 10:20:36,231:INFO:flask_appbuilder.base:Registering class ResetMyPasswordView on menu 2017-06-07 10:20:36,916:INFO:flask_appbuilder.base:Registering class UserInfoEditView on menu 2017-06-07 10:20:37,535:INFO:flask_appbuilder.base:Registering class AuthDBView on menu 2017-06-07 10:20:37,744:INFO:flask_appbuilder.base:Registering class UserDBModelView on menu List Users 2017-06-07 10:20:40,027:INFO:flask_appbuilder.base:Registering class RoleModelView on menu List Roles 2017-06-07 10:20:41,971:INFO:flask_appbuilder.base:Registering class UserStatsChartView on menu User's Statistics 2017-06-07 10:20:43,317:INFO:flask_appbuilder.base:Registering class PermissionModelView on menu Base Permissions 2017-06-07 10:20:44,649:INFO:flask_appbuilder.base:Registering class ViewMenuModelView on menu Views/Menus 2017-06-07 10:20:45,979:INFO:flask_appbuilder.base:Registering class PermissionViewModelView on menu Permission on Views/Menus 2017-06-07 10:20:51,246:INFO:flask_appbuilder.base:Registering class TableColumnInlineView on menu 2017-06-07 10:20:52,283:INFO:flask_appbuilder.base:Registering class DruidColumnInlineView on menu 2017-06-07 10:20:53,335:INFO:flask_appbuilder.base:Registering class SqlMetricInlineView on menu 2017-06-07 10:20:54,372:INFO:flask_appbuilder.base:Registering class DruidMetricInlineView on menu 2017-06-07 10:20:56,347:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:20:56,349:INFO:flask_appbuilder.base:Registering class DatabaseView on menu Databases 2017-06-07 10:20:58,306:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:20:58,308:INFO:flask_appbuilder.base:Registering class DatabaseAsync on menu 2017-06-07 10:20:59,473:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:20:59,476:INFO:flask_appbuilder.base:Registering class DatabaseTablesAsync on menu 2017-06-07 10:21:00,622:INFO:flask_appbuilder.base:Registering class TableModelView on menu Tables 2017-06-07 10:21:02,569:INFO:flask_appbuilder.base:Registering class AccessRequestsModelView on menu Access requests 2017-06-07 10:21:04,501:INFO:flask_appbuilder.base:Registering class DruidClusterModelView on menu Druid Clusters 2017-06-07 10:21:06,558:INFO:flask_appbuilder.base:Registering class SliceModelView on menu Slices 2017-06-07 10:21:08,087:INFO:flask_appbuilder.base:Registering class SliceAsync on menu 2017-06-07 10:21:09,222:INFO:flask_appbuilder.base:Registering class SliceAddView on menu 2017-06-07 10:21:10,352:INFO:flask_appbuilder.base:Registering class DashboardModelView on menu Dashboards 2017-06-07 10:21:12,039:INFO:flask_appbuilder.base:Registering class DashboardModelViewAsync on menu 2017-06-07 10:21:13,287:INFO:flask_appbuilder.base:Registering class LogModelView on menu Action Log 2017-06-07 10:21:15,117:INFO:flask_appbuilder.base:Registering class QueryView on menu Queries 2017-06-07 10:21:17,024:INFO:flask_appbuilder.base:Registering class DruidDatasourceModelView on menu Druid Datasources 2017-06-07 10:21:18,949:INFO:flask_appbuilder.base:Registering class R on menu 2017-06-07 10:21:19,155:INFO:flask_appbuilder.base:Registering class Superset on menu 2017-06-07 10:21:24,262:INFO:flask_appbuilder.base:Registering class CssTemplateModelView on menu CSS Templates 2017-06-07 10:21:26,313:INFO:flask_appbuilder.base:Registering class CssTemplateAsyncModelView on menu Starting server with command: gunicorn -w 2 --timeout 120 -b 0.0.0.0:8088 --limit-request-line 0 --limit-request-field_size 0 superset:app [2017-06-07 10:21:29 -0700] [46032] [INFO] Starting gunicorn 19.6.0 [2017-06-07 10:21:29 -0700] [46032] [INFO] Listening at: http://0.0.0.0:8088 (46032) [2017-06-07 10:21:29 -0700] [46032] [INFO] Using worker: sync [2017-06-07 10:21:29 -0700] [46035] [INFO] Booting worker with pid: 46035 [2017-06-07 10:21:29 -0700] [46036] [INFO] Booting worker with pid: 46036 /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_SQLAlchemy-2.0-py3.6.egg/flask_sqlalchemy/init.py:30: ExtDeprecationWarning: Importing flask.ext.sqlalchemy is deprecated, use flask_sqlalchemy instead. from flask.ext.sqlalchemy._compat import iteritems, itervalues, xrange, \ /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_SQLAlchemy-2.0-py3.6.egg/flask_sqlalchemy/init.py:30: ExtDeprecationWarning: Importing flask.ext.sqlalchemy is deprecated, use flask_sqlalchemy instead. from flask.ext.sqlalchemy._compat import iteritems, itervalues, xrange, \ /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Migrate-1.5.1-py3.6.egg/flask_migrate/init.py:4: ExtDeprecationWarning: Importing flask.ext.script is deprecated, use flask_script instead. from flask.ext.script import Manager /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Migrate-1.5.1-py3.6.egg/flask_migrate/init.py:4: ExtDeprecationWarning: Importing flask.ext.script is deprecated, use flask_script instead. from flask.ext.script import Manager Loaded your LOCAL configuration Loaded your LOCAL configuration /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Cache-0.13.1-py3.6.egg/flask_cache/jinja2ext.py:33: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead. from flask.ext.cache import make_template_fragment_key /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_Cache-0.13.1-py3.6.egg/flask_cache/jinja2ext.py:33: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead. from flask.ext.cache import make_template_fragment_key 2017-06-07 10:21:30,910:INFO:root:trace_db_events - db_engine - do_connect 2017-06-07 10:21:30,912:INFO:root:trace_db_events - db_engine - do_connect 2017-06-07 10:21:32,693:INFO:root:trace_db_events - db_engine.pool - FIRST_CONNECT 2017-06-07 10:21:32,694:INFO:root:trace_db_events - db_engine.pool - CONNECT 2017-06-07 10:21:32,694:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:32,713:INFO:root:trace_db_events - db_engine.pool - FIRST_CONNECT 2017-06-07 10:21:32,713:INFO:root:trace_db_events - db_engine.pool - CONNECT 2017-06-07 10:21:32,713:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:32,792:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:32,793:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:21:32,813:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:32,814:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:21:32,889:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:21:32,889:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:32,910:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:21:32,911:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:33,092:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:33,107:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:33,192:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:21:33,208:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:21:33,289:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:21:33,290:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:33,318:INFO:root:trace_db_events - db_engine.pool - CHECKIN 2017-06-07 10:21:33,319:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:21:33,483:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:33,483:INFO:root:trace_db_events - db_engine - begin 2017-06-07 10:21:33,516:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:21:33,516:INFO:root:trace_db_events - db_engine - begin 2017-06-07 10:21:33,785:INFO:flask_appbuilder.base:Registering class MyIndexView on menu 2017-06-07 10:21:33,818:INFO:flask_appbuilder.base:Registering class MyIndexView on menu 2017-06-07 10:21:33,989:INFO:flask_appbuilder.base:Registering class UtilView on menu 2017-06-07 10:21:34,023:INFO:flask_appbuilder.base:Registering class UtilView on menu 2017-06-07 10:21:34,194:INFO:flask_appbuilder.base:Registering class LocaleView on menu 2017-06-07 10:21:34,226:INFO:flask_appbuilder.base:Registering class LocaleView on menu 2017-06-07 10:21:34,398:INFO:flask_appbuilder.base:Registering class ResetPasswordView on menu 2017-06-07 10:21:34,431:INFO:flask_appbuilder.base:Registering class ResetPasswordView on menu 2017-06-07 10:21:35,022:INFO:flask_appbuilder.base:Registering class ResetMyPasswordView on menu 2017-06-07 10:21:35,052:INFO:flask_appbuilder.base:Registering class ResetMyPasswordView on menu 2017-06-07 10:21:35,640:INFO:flask_appbuilder.base:Registering class UserInfoEditView on menu 2017-06-07 10:21:35,674:INFO:flask_appbuilder.base:Registering class UserInfoEditView on menu 2017-06-07 10:21:36,374:INFO:flask_appbuilder.base:Registering class AuthDBView on menu 2017-06-07 10:21:36,423:INFO:flask_appbuilder.base:Registering class AuthDBView on menu 2017-06-07 10:21:36,580:INFO:flask_appbuilder.base:Registering class UserDBModelView on menu List Users 2017-06-07 10:21:36,634:INFO:flask_appbuilder.base:Registering class UserDBModelView on menu List Users 2017-06-07 10:21:38,816:INFO:flask_appbuilder.base:Registering class RoleModelView on menu List Roles 2017-06-07 10:21:38,908:INFO:flask_appbuilder.base:Registering class RoleModelView on menu List Roles 2017-06-07 10:21:40,759:INFO:flask_appbuilder.base:Registering class UserStatsChartView on menu User's Statistics 2017-06-07 10:21:40,867:INFO:flask_appbuilder.base:Registering class UserStatsChartView on menu User's Statistics 2017-06-07 10:21:42,085:INFO:flask_appbuilder.base:Registering class PermissionModelView on menu Base Permissions 2017-06-07 10:21:42,195:INFO:flask_appbuilder.base:Registering class PermissionModelView on menu Base Permissions 2017-06-07 10:21:43,426:INFO:flask_appbuilder.base:Registering class ViewMenuModelView on menu Views/Menus 2017-06-07 10:21:43,534:INFO:flask_appbuilder.base:Registering class ViewMenuModelView on menu Views/Menus 2017-06-07 10:21:44,841:INFO:flask_appbuilder.base:Registering class PermissionViewModelView on menu Permission on Views/Menus 2017-06-07 10:21:44,965:INFO:flask_appbuilder.base:Registering class PermissionViewModelView on menu Permission on Views/Menus 2017-06-07 10:21:50,958:INFO:flask_appbuilder.base:Registering class TableColumnInlineView on menu 2017-06-07 10:21:51,075:INFO:flask_appbuilder.base:Registering class TableColumnInlineView on menu 2017-06-07 10:21:52,002:INFO:flask_appbuilder.base:Registering class DruidColumnInlineView on menu 2017-06-07 10:21:52,142:INFO:flask_appbuilder.base:Registering class DruidColumnInlineView on menu 2017-06-07 10:21:53,050:INFO:flask_appbuilder.base:Registering class SqlMetricInlineView on menu 2017-06-07 10:21:53,181:INFO:flask_appbuilder.base:Registering class SqlMetricInlineView on menu 2017-06-07 10:21:54,087:INFO:flask_appbuilder.base:Registering class DruidMetricInlineView on menu 2017-06-07 10:21:54,229:INFO:flask_appbuilder.base:Registering class DruidMetricInlineView on menu 2017-06-07 10:21:55,970:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:55,975:INFO:flask_appbuilder.base:Registering class DatabaseView on menu Databases 2017-06-07 10:21:56,195:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:56,198:INFO:flask_appbuilder.base:Registering class DatabaseView on menu Databases 2017-06-07 10:21:57,928:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:57,932:INFO:flask_appbuilder.base:Registering class DatabaseAsync on menu 2017-06-07 10:21:58,141:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:58,145:INFO:flask_appbuilder.base:Registering class DatabaseAsync on menu 2017-06-07 10:21:59,098:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:59,100:INFO:flask_appbuilder.base:Registering class DatabaseTablesAsync on menu 2017-06-07 10:21:59,314:WARNING:flask_appbuilder.models.filters:Filter type not supported for column: password 2017-06-07 10:21:59,317:INFO:flask_appbuilder.base:Registering class DatabaseTablesAsync on menu 2017-06-07 10:22:00,231:INFO:flask_appbuilder.base:Registering class TableModelView on menu Tables 2017-06-07 10:22:00,452:INFO:flask_appbuilder.base:Registering class TableModelView on menu Tables 2017-06-07 10:22:02,225:INFO:flask_appbuilder.base:Registering class AccessRequestsModelView on menu Access requests 2017-06-07 10:22:02,486:INFO:flask_appbuilder.base:Registering class AccessRequestsModelView on menu Access requests 2017-06-07 10:22:04,168:INFO:flask_appbuilder.base:Registering class DruidClusterModelView on menu Druid Clusters 2017-06-07 10:22:04,448:INFO:flask_appbuilder.base:Registering class DruidClusterModelView on menu Druid Clusters 2017-06-07 10:22:06,189:INFO:flask_appbuilder.base:Registering class SliceModelView on menu Slices 2017-06-07 10:22:06,484:INFO:flask_appbuilder.base:Registering class SliceModelView on menu Slices 2017-06-07 10:22:07,752:INFO:flask_appbuilder.base:Registering class SliceAsync on menu 2017-06-07 10:22:08,058:INFO:flask_appbuilder.base:Registering class SliceAsync on menu 2017-06-07 10:22:08,897:INFO:flask_appbuilder.base:Registering class SliceAddView on menu 2017-06-07 10:22:09,207:INFO:flask_appbuilder.base:Registering class SliceAddView on menu 2017-06-07 10:22:10,029:INFO:flask_appbuilder.base:Registering class DashboardModelView on menu Dashboards 2017-06-07 10:22:10,348:INFO:flask_appbuilder.base:Registering class DashboardModelView on menu Dashboards 2017-06-07 10:22:11,675:INFO:flask_appbuilder.base:Registering class DashboardModelViewAsync on menu 2017-06-07 10:22:11,995:INFO:flask_appbuilder.base:Registering class DashboardModelViewAsync on menu 2017-06-07 10:22:12,909:INFO:flask_appbuilder.base:Registering class LogModelView on menu Action Log 2017-06-07 10:22:13,221:INFO:flask_appbuilder.base:Registering class LogModelView on menu Action Log 2017-06-07 10:22:14,794:INFO:flask_appbuilder.base:Registering class QueryView on menu Queries 2017-06-07 10:22:15,088:INFO:flask_appbuilder.base:Registering class QueryView on menu Queries 2017-06-07 10:22:16,752:INFO:flask_appbuilder.base:Registering class DruidDatasourceModelView on menu Druid Datasources 2017-06-07 10:22:17,054:INFO:flask_appbuilder.base:Registering class DruidDatasourceModelView on menu Druid Datasources 2017-06-07 10:22:18,693:INFO:flask_appbuilder.base:Registering class R on menu 2017-06-07 10:22:18,897:INFO:flask_appbuilder.base:Registering class Superset on menu 2017-06-07 10:22:19,002:INFO:flask_appbuilder.base:Registering class R on menu 2017-06-07 10:22:19,303:INFO:flask_appbuilder.base:Registering class Superset on menu 2017-06-07 10:22:25,347:INFO:flask_appbuilder.base:Registering class CssTemplateModelView on menu CSS Templates 2017-06-07 10:22:25,382:INFO:flask_appbuilder.base:Registering class CssTemplateModelView on menu CSS Templates 2017-06-07 10:22:27,338:INFO:flask_appbuilder.base:Registering class CssTemplateAsyncModelView on menu 2017-06-07 10:22:27,421:INFO:flask_appbuilder.base:Registering class CssTemplateAsyncModelView on menu 

I'm not sure I'm looking at the right thing... but overall what I'm reading here is time to establish DB connection is 2+s and subsequent (pooled) operations are on the order of 100 ms.
FAB class registration is part of one db transaction and takes a while.

4. I hit http://0.0.0.0:8088/superset/welcome

2017-06-07 10:23:31,830:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:23:31,831:INFO:root:trace_db_events - db_engine - rollback 2017-06-07 10:23:31,930:INFO:root:trace_db_events - db_engine.pool - CHECKIN /Users/david/dev/superset/env/lib/python3.6/site-packages/SQLAlchemy-1.0.13-py3.6-macosx-10.10-x86_64.egg/sqlalchemy/sql/compiler.py:575: SAWarning: Can't resolve label reference 'changed_on desc'; converting to text() (this warning may be suppressed after 10 occurrences) util.ellipses_string(element.element)) 2017-06-07 10:23:37,183:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:23:37,184:INFO:root:trace_db_events - db_engine - rollback 2017-06-07 10:23:37,281:INFO:root:trace_db_events - db_engine.pool - CHECKIN

This is where we seem to be spending 6 seconds on that rollback/checkin/reset.
This (https://github.com/Kotti/Kotti/issues/445) seems to be saying I shouldn't worry about the SAWarning

5. I hit http://0.0.0.0:8088/databaseview/list/

2017-06-07 10:24:07,961:INFO:root:trace_db_events - db_engine.pool - CHECKOUT 2017-06-07 10:24:08,255:INFO:root:trace_db_events - db_engine - engine_connect 2017-06-07 10:24:08,256:INFO:root:trace_db_events - db_engine - begin /Users/david/dev/superset/env/lib/python3.6/site-packages/SQLAlchemy-1.0.13-py3.6-macosx-10.10-x86_64.egg/sqlalchemy/sql/compiler.py:575: SAWarning: Can't resolve label reference 'changed_on desc'; converting to text() (this warning may be suppressed after 10 occurrences) util.ellipses_string(element.element)) /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_AppBuilder-1.8.1-py3.6.egg/flask_appbuilder/forms.py:245: FlaskWTFDeprecationWarning: "flask_wtf.Form" has been renamed to "FlaskForm" and will be removed in 1.0. form = self(obj=obj) /Users/david/dev/superset/env/lib/python3.6/site-packages/Flask_AppBuilder-1.8.1-py3.6.egg/flask_appbuilder/fields.py:152: UserWarning: allow_blank=True does not do anything for QuerySelectMultipleField. warnings.warn('allow_blank=True does not do anything for QuerySelectMultipleField.') 2017-06-07 10:24:16,706:INFO:root:trace_db_events - db_engine.pool - RESET 2017-06-07 10:24:16,706:INFO:root:trace_db_events - db_engine - rollback 2017-06-07 10:24:16,805:INFO:root:trace_db_events - db_engine.pool - CHECKIN


Again - a whole 8 seconds where I'm not understanding what's going on with that db transaction starting and apparently being rolled back.

I get the exact same set of events when I run on a local sqlite or postgres db - except it's blazing fast.

For now, I'll move onto a configuration where my db will be on the same (dockerized) network as my server...
riteshemigo commented 6 years ago

@BobSaintClare Did you find any permanent resolution for this. I am also facing the same issue.

BobSaintClare commented 6 years ago

I haven't...

sjmeyer commented 6 years ago

Any updates on this issue? We are facing the same problem. When running Superset in a container with a local SQLite DB it's blazing fast. When swapping out the SQLite DB for a MySql DB running on AWS, it's extremely slow. It takes 10+ minutes to run the update/migrate process. Once that's finally done, the front end is extremely slow. Takes around 10 seconds to log in, from a container with no load and a database with only my container connected to it.

It's not a networking issue, since I download files from Amazon S3 as part of my init script and that runs at normal speed, in other words, fast. Just to be sure though, I started a container and ssh'ed into it, installed mysql-server, and connected to the remote database on AWS from the command line. That works perfectly fine and as speedy as you'd expect.

mistercrunch commented 6 years ago

Closing since this isn't a Superset issue and related to environment, we're welcoming the conversation on this [now closed] issue though.

coffenbacher commented 4 years ago

I'm also seeing this - I'm still trying Superset out so I'm not yet invested enough to dig in deeply to this, but it is bizarrely slow when using a remote database server. Like @sjmeyer , I can run all sorts of things with excellent performance against the same database host. I'm not sure this is "not a Superset issue" - I've never seen anything quite like this, whatever it is. It works, it's just unconscionably slow at every turn.

mistercrunch commented 4 years ago

Any data on network health [bandwidth / ping] between the server and db? It's a pretty clear best practice to have an OLTP database colocated with the app it serves.

dubin555 commented 3 years ago

to anyone who had same issue: maybe this is due to the docker network config, the following steps worked for me! you can do the following check: inside the docker container -->

  1. telnet {{your mysql address}} {{your mysql port}}, e.g. telnet 192.168.x.x 3306, fast to reponse: if Yes, go to 2
  2. ping {{your mysql address}}, shows 100% loss: if Yes, go to 3
  3. following the https://docs.docker.com/network/bridge/#enable-forwarding-from-docker-containers-to-the-outside-world to fix the connection issue