yahoo-eng-team team mailing list archive

[Steve Martinelli <1259827@xxxxxxxxxxxxxxxxxx>]

I am marking this as fix released based on
https://review.openstack.org/#/c/272007/ merging. We can open separate
bugs for new issues but having a large sweeping bug like this one will
cause us to never close it.

** Changed in: keystone
       Status: Triaged => Fix Released

** Changed in: keystone
     Assignee: (unassigned) => Morgan Fainberg (mdrnstm)

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Identity (keystone).
https://bugs.launchpad.net/bugs/1259827

Title:
  keystone execute SQL statements so many times?

Status in OpenStack Identity (keystone):
  Fix Released

Bug description:
  When I login horizon,I found keystone query database tables many
  times.

  From keystone.log,I can see the steps like this: 
  step1:keystone recieve request like this :{"auth": {"passwordCredentials":{"username": "admin", "password":"*"}}} step2:keystone query user table by username and domain id 
  stpe3:keystone query user table by user id 
  step4:keystone query user table by user id 
  step5:keystone query user_group_membership table 
  step6:keystone query domain table 
  step7:keystone create a new token and insert it into token table

  From above steps,we can see keystone query the user table tree times,I
  think once is enough. Especially the step3 and step4 are repeated.

  So many sql statments will reduce the performance of database.

  Here are the keystone logs:

  2013-12-11 09:41:21    DEBUG [keystone.common.wsgi] {"auth": {"passwordCredentials":{"username": "admin", "password":"***"}}}
  2013-12-11 09:41:21    DEBUG [keystone.common.wsgi]
  2013-12-11 09:41:21    DEBUG [keystone.common.wsgi] arg_dict: {}
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] SELECT user.id AS user_id, user.name AS user_name, user.domain_id AS user_domain_id, user.password AS user_password, user.enabled AS user_enabled, user.extra AS user_extra
  FROM user
  WHERE user.name = %s AND user.domain_id = %s
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('admin', 'default')
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] SELECT user.id AS user_id, user.name AS user_name, user.domain_id AS user_domain_id, user.password AS user_password, user.enabled AS user_enabled, user.extra AS user_extra
  FROM user
  WHERE user.id = %s
   LIMIT %s
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('5463d155acf642f1b0354036f7a8a84b', 1)
  2013-12-11 09:41:21     INFO [passlib.registry] registered crypt handler 'sha512_crypt': <class 'passlib.handlers.sha2_crypt.sha512_crypt'>
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] SELECT user.id AS user_id, user.name AS user_name, user.domain_id AS user_domain_id, user.password AS user_password, user.enabled AS user_enabled, user.extra AS user_extra
  FROM user
  WHERE user.id = %s
   LIMIT %s
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('5463d155acf642f1b0354036f7a8a84b', 1)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] SELECT user_group_membership.user_id AS user_group_membership_user_id, user_group_membership.group_id AS user_group_membership_group_id
  FROM user_group_membership
  WHERE user_group_membership.user_id = %s
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('5463d155acf642f1b0354036f7a8a84b',)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] SELECT domain.id AS domain_id, domain.name AS domain_name, domain.enabled AS domain_enabled, domain.extra AS domain_extra
  FROM domain
  WHERE domain.id = %s
   LIMIT %s
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('default', 1)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] BEGIN (implicit)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] INSERT INTO token (id, expires, extra, valid, user_id, trust_id) VALUES (%s, %s, %s, %s, %s, %s)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] ('903e4d7e80573b2ec4a6dbc7a285b219', datetime.datetime(2013, 12, 12, 1, 41, 21, 845497), '{"key": "MIICbgYJKoZIhvcNAQcCoIICXzCCAlsCAQExCTAHBgUrDgMCGjCCAUcGCSqGSIb3DQEHAaCCATgEggE0eyJhY2Nlc3MiOiB7InRva2VuIjogeyJpc3N1ZWRfYXQiOiAiMjAxMy0xMi0xMVQwMTo0MToyMS44NDg1MjEiLCAiZXhwaXJlcyI6ICIyMDEzLTEyLTEyVDAxOjQxOjIxWiIsICJpZCI6ICJwbGFjZWhvbGRlciJ9LCAic2VydmljZUNhdGFsb2ciOiBbXSwgInVzZXIiOiB7InVzZXJuYW1lIjogImFkbWluIiwgInJvbGVzX2xpbmtzIjogW10sICJpZCI6ICI1NDYzZDE1NWFjZjY0MmYxYjAzNTQwMzZmN2E4YTg0YiIsICJyb2xlcyI6IFtdLCAibmFtZSI6ICJhZG1pbiJ9LCAibWV0YWRhdGEiOiB7ImlzX2FkbWluIjogMCwgInJvbGVzIjogW119fX0xgf8wgfwCAQEwXDBXMQswCQYDVQQGEwJVUzEOMAwGA1UECBMFVW5zZXQxDjAMBgNVBAcTBVVuc2V0MQ4wDAYDVQQKEwVVbnNldDEYMBYGA1UEAxMPd3d3LmV4YW1wbGUuY29tAgEBMAcGBSsOAwIaMA0GCSqGSIb3DQEBAQUABIGAKxDfbLnxLg+pZ2aTM28JIFiZLfGbubbiM+Edg9wbE+wV5uB0C7Q8nHLQxaMrRtYmOUmLLPnvp8uBdEcxWtnTazgt5k1i4LOQyn+teWGcIQeyoC8kl4eNmIgBeT+PqFVKpss4uBAaVlXIuqVUJXBRQIY6GhrKz3BUnVl8+w4keTY=", "user": {"email": "admin@xxxxxxx", "tenantId": "d5030c82dca9485082920b9d123618f4", "enabled": true, "name": "admin", "id": "5463d155acf642f1b0354036f7a8a84b"}, "tenant": null, "metadata": {"roles": []}}', 1, '5463d155acf642f1b0354036f7a8a84b', None)
  2013-12-11 09:41:21     INFO [sqlalchemy.engine.base.Engine] COMMIT

To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1259827/+subscriptions