0

I have a pretty simple audit table with about 8 million rows in it. No row is ever updated, but new rows get added all the time. Table definition is below:

-- auto-generated definition
create table audit
(
    id           bigint auto_increment
        primary key,
    className    varchar(511)  not null,
    createdTime  datetime      not null,
    auditable_id bigint        not null,
    user_id      bigint        null,
    userName     varchar(255)  null,
    auditType    varchar(255)  not null,
    properties   varchar(4095) null,
    url          varchar(2047) null
);

create index idx_class_createdTime_entityId
    on audit (className, createdTime, auditable_id);

create index idx_createdTime
    on audit (createdTime);

When I run this query

select  audit0_.id as id1_7_, audit0_.auditType as audittyp2_7_,
        audit0_.auditable_id as auditabl3_7_, audit0_.className as classnam4_7_,
        audit0_.createdTime as createdt5_7_, audit0_.properties as properti6_7_,
        audit0_.url as url7_7_, audit0_.user_id as user_id8_7_,
        audit0_.userName as username9_7_
    from  audit audit0_
    where  audit0_.className='CLASS_HERE'
      and  audit0_.auditable_id=3129943
      and  (audit0_.createdTime between '2021-07-29 20:11:39.319'
                                    AND '2021-10-29 20:11:39.319')

from DataGrip (not directly on the server, but remotely connected to it), it is fast and responds in about the time I would expect (< 1 second). When the application runs the identical query it takes 60+ seconds.

The explain shows it using the index, but the app server is still really slow. I know the app server is running the exact same query because I got the query from the show full processlist and directly ran it. This happens basically everytime the app server runs a query like this, but the console is always fast. The number of records returned for a query like this is going to be 2-20, it's always a pretty small number.

id select_type table partitions type possible_keys key key_len ref rows filtered Extra
1 SIMPLE audit0_ NULL ALL idx_class_createdTime_entityId,idx_createdTime NULL NULL NULL 8724876 5 Using where

I've been banging my head against this problem on and off for months, and have not been able to come up with any explanation why this would be as slow as it is. I tried changing the isoloation level to READ_UNCOMMITED thinking maybe a lock was causing an issue, but that didn't help. Also tried adding and removing transactions alltogether, but again no difference. This is about as simple of a table and complex index and query as you can get, so most of the stuff I've read in other threads didn't seem to fit my scenario.

The application code is using Spring Boot / Hibernate talking to MySql 8.

4
  • "The explain shows it using the index" -- I'd argue that it does not. The difference in performance probably can be attributed to the Hibernate using bind variables (vs. you using literals when you run it in DataGrip).
    – mustaccio
    Oct 27, 2021 at 21:14
  • @Zipper The explain shows the 'possible_keys' list and the next 3 column in the explain when all NULL are confirming there is no appropriate key to assist with an index. Please post TEXT result of SHOW CREATE TABLE audit0_; so we can see how this table is defined and indexed today. Posting last 400 lines of SLOW QUERY LOG should be able to confirm what is actually being processed by MySQL when your application runs this query. Oct 28, 2021 at 12:51
  • I think I figured it out, I believe the index had the class then time then entity, but that was too inclusive of the table, so MySql did a scan instead, added another index with the entity id first and now it's fast. So the core problem appeared to be due index not getting specific early enough
    – Zipper
    Oct 28, 2021 at 17:57
  • @Zipper Congrats on improving the index needed to improve speed of completion. For your Slow Query Log to be enhanced in > 8.0.13 in your config, log_slow_extra=ON will likely be helpful to you. Oct 28, 2021 at 19:13

1 Answer 1

0

Add this composite index to the table:

INDEX(className, auditable_id, createdTime)

It's probably not a big deal, but you have an extra second here (because BETWEEN is inclusive):

  and  (audit0_.createdTime between '2021-07-29 20:11:39.319'
                                AND '2021-10-29 20:11:39.319')

I prefer:

  and  (    audit0_.createdTime >= '2021-07-29 20:11:39.319'
        and audit0_.createdTime  < '2021-07-29 20:11:39.319' + INTERVAL 3 DAY
       )

If that datetime is the current datetime, then simply say NOW() instead of going to the effort of providing the value.

And that may be the crux of the problem -- Certain bindings defeat optimization.

Perhaps this is what you need?

  and  (    audit0_.createdTime >= NOW() - INTERVAL 3 DAY
        and audit0_.createdTime  < NOW()
       )

(That also works with my index suggestion.)

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.