RevokeEvent.to_dict() is very slow

[侯喆]

When our keystone to valid token , it cost too much time on function check_revocation.

In the path /keystone/revoke/backends/sql.py func list_events()

>
events = [revoke_model.RevokeEvent(**e.to_dict()) for e in query]

It cost about 3 second and our database on revocation_event table has 38596 row.

Query sql from this table cost 0.01 second,but transfer this to a dict cost 3s.

---------------
mysql> select count(*) from revocation_event;
+----------+
| count(*) |
+----------+
| 38596 |
+----------+

[Lance Bragstad (lbragstad)]

We have recently refactored this code and pushed some of the check into the SQL query itself [0]. Which version of keystone are you using?

[0] https://github.com/openstack/keystone/commit/9e84371461831880ce5736e9888c7d9648e3a77b

[Lance Bragstad (lbragstad)]

Another keystone developer did some performance testing prior to the patch landing that showed significant performance improvements with the patch mentioned above [0].

[0] https://gist.github.com/csrichard1/4b7b8527ee5a6565a84956cff33cf29b

[侯喆 (houzhe)]

I thing the bug #1524030 is add some index about table revocation_event. My problem is that

>
  query = session.query(RevocationEvent).order_by(
                RevocationEvent.revoked_at)

  just exec 0.1 second. Database is ok.
  But, this function,

>
events = [revoke_model.RevokeEvent(**e.to_dict()) for e in query]

  It need 3 second when the length of query more than 30,000.

[Lance Bragstad (lbragstad)]

I believe you specifically referencing this code:

https://github.com/openstack/keystone/blob/1254ac028332778d086a7884aab1fe7c60748590/keystone/revoke/backends/sql.py#L116-L125

There seems to be some overlapping context between this report and bug #1524030. If we reduce the number of revocation events to only the events we absolutely need there will be less bloat in the revocation event table overall.

How long does it take your deployment to generate 30,000 revocation events (days, weeks, months)?

[侯喆 (houzhe)]

It takes about two months to generate 30,000 revocation events.In out deployment has 40 compute nodes and 4 controller nodes. We have a script to clean expired token every fifteen minutes which stored in mysql. However the databases encountered a deadlock problem and the script does not take effect. Finally, we found that our api response need about 6 seconds. We check code found there were 30,000 revocation events in our database.And keystone read it from mysql take 0.1second but convert these to dict in mem need 3seconds.

[Lance Bragstad (lbragstad)]

Every time a new revocation event is created - the sql driver will remove expired revocation events [0]. Is this true for your deployment? It is my understanding that revocation events should expire after some time.

[0] https://github.com/openstack/keystone/blob/e49a95ff6e25c25e6c6c5ceb6350666e35056dd3/keystone/revoke/backends/sql.py#L70-L91

[Richard (csravelar)]

As lbragstad mentioned, it looks like you are calling
https://github.com/openstack/keystone/blob/1254ac028332778d086a7884aab1fe7c60748590/keystone/revoke/backends/sql.py#L116-L125

Look inside revoke/core.py where the method 'check_token' is and make sure the call to list events is invoked so that it can call _list_token_events instead of _list_last_fetch_events.

https://github.com/openstack/keystone/blob/1254ac028332778d086a7884aab1fe7c60748590/keystone/revoke/backends/sql.py#L127-L131
So you would pass a token into list_events and then list events checks token is set to call
https://github.com/openstack/keystone/blob/1254ac028332778d086a7884aab1fe7c60748590/keystone/revoke/backends/sql.py#L93-L114