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

Q: SlowQueryListener couldn't record bind values #1857

Closed
ethanyhwang opened this issue Nov 9, 2019 · 5 comments
Closed

Q: SlowQueryListener couldn't record bind values #1857

ethanyhwang opened this issue Nov 9, 2019 · 5 comments
Assignees
Milestone

Comments

@ethanyhwang
Copy link

i want to record slow sql with bind values like ebean debug sql. for example " DEBUG io.ebean.SQL - txn[1016] select t0.relationId, t0.accountId, t0.advertiserType, t0.advertiserId, t0.status, t0.relationType, t0.inviteCode, t0.inviteTime, t0.deleteStatus, t0.ukSuffix, t0.createdTime, t0.lastModifiedTime from TOneAdvertiserRelation t0 where accountId = ? and t0.deleteStatus = ? and t0.relationType in (? ) order by t0.relationId; --bind(183061,false,Array[1]={0}) "

how can i do it

@rbygrave
Copy link
Member

rbygrave commented Nov 9, 2019 via email

@rbygrave rbygrave changed the title SlowQueryListener couldn't record bind values Q: SlowQueryListener couldn't record bind values Nov 11, 2019
@ethanyhwang
Copy link
Author

ethanyhwang commented Nov 12, 2019

I need to know bind values of the slow query to better analyze why it is slow

@rbygrave
Copy link
Member

Note that I am working on the metrics reporting service which has the potential to enable the collection of query plans (in a click a button on a dashboard kind of way).

So working on that and looking to come back to this when that is further on (so maybe a few weeks).

@rbygrave
Copy link
Member

Documentation update:

To enable query plan capture:

  • DatabaseConfig.setCollectQueryPlans(true)
  • DatabaseConfig.setCollectQueryPlanThresholdMicros(50_000); // 50_000 = 50 milliseconds

This means that the internal ebean query plans are setup to capture bind values (for the purpose of obtaining query explain plans). The threshold is the minimum query execution time required to capture bind values in microseconds (not millis).

Once bind values are captured they are captured again if the query time is 1.3 * larger than the currently captured query time. (I'll change this to 1.5 times).

Periodically we then capture query plans in the background. When we do this we give the maximum number of plans to capture and or the maximum amount of time we allow query plan capture to take.

    // obtains db query plans ...
    QueryPlanRequest request = new QueryPlanRequest();
    request.setMaxCount(5); // max number of plans we will capture
    request.setMaxTimeMillis(1_000); // max time after which we don't continue collecting plans

    // collect the query plans ... (executes the query using **explain** with the latest captured bind values)
    List<MetaQueryPlan> plans =database.getMetaInfoManager().queryPlanCollectNow(request);

   // we can then log the plans ...
   for (MetaQueryPlan plan : plans) {

     String rawPlan = plan.getPlan();
     String sql = plan.getSql();
     String bindLog = plan.getBind();
     String label = plan.getLabel();
     long queryTimeMicros = plan.getQueryTimeMicros();
     ProfileLocation profileLocation = plan.getProfileLocation();
      
      ...
   }

  // to run a period task like this we could ...
   DB.getBackgroundExecutor().scheduleWithFixedDelay(...)

FYI @xu1009

rbygrave added a commit that referenced this issue Mar 25, 2024
- changes SqlQueryEvent into an interface.
- captures the bind values the slow query used and makes those available via SlowQueryEvent
- also makes the query label and profileLocation available via SlowQueryEvent
rbygrave added a commit that referenced this issue Mar 30, 2024
…ture

#1857 Add bind values capture for SlowQueryEvent / SlowQueryListener
@rbygrave rbygrave self-assigned this Apr 5, 2024
@rbygrave rbygrave added this to the 14.1.0 milestone Apr 5, 2024
@rbygrave
Copy link
Member

rbygrave commented Apr 5, 2024

This feature is now in 14.1.0, where we can access the bind values used in the slow query.

@rbygrave rbygrave closed this as completed Apr 5, 2024
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

No branches or pull requests

2 participants