jooq 查询时间_如何使用jOOQ检测慢查询

jooq 查询时间

• 刚才，我们在jOOQ的代码生成器中实现了一个不错的小功能： https : //github.com/jOOQ/jOOQ/issues/4974

它会在jOOQ代码生成器运行慢速查询以反向工程模式元信息时进行检测。 为什么？

在我们的开发和集成测试环境中，我们没有适用于所有不同性能边缘情况的庞大架构。 例如，我们没有5000个Oracle同义词。 或10000个过程，每个过程具有500个参数。 我们确实涵盖了一些常见的极端情况，但并未涵盖所有数据库。

另一方面，用户往往会在一段时间后接受现状。 代码生成器是否运行缓慢？ 当然，因为我们有一个庞大的架构。 懒惰的接受阻碍了我们产品的质量。 我们希望用户报告他们遇到的各种问题，因此我们鼓励他们。

我们做到了

在即将到来的jOOQ版本3.8（以及3.5.5、3.6.5和3.7.3的修补程序版本）中，我们在jOOQ-meta中添加了一个漂亮的ExecuteListener ，大致如下所示：

class PerformanceListener 
    extends DefaultExecuteListener {

    StopWatch watch;
    class SQLPerformanceWarning 
        extends Exception {}

    @Override
    public void executeStart(ExecuteContext ctx) {
        super.executeStart(ctx);
        watch = new StopWatch();
    }

    @Override
    public void executeEnd(ExecuteContext ctx) {
        super.executeEnd(ctx);
        if (watch.split() > 5 * 1000 * 1000 * 1000)
            log.warn(
                "Slow SQL",
                "jOOQ Meta executed a slow query"
              + "\n\n"
              + "Please report this bug here: "
              + "https://github.com/jOOQ/jOOQ/issues/new\n\n"
              + formatted(ctx.query()),
                new SQLPerformanceWarning());
    }
}

非常简单 每次我们开始执行查询时，都会启动“秒表”。 每次结束执行时，我们都会检查手表是否经过了5秒以上。 如果是这样，我们将记录警告，问题跟踪器的链接，SQL查询的格式化版本以及堆栈跟踪，以帮助查找执行慢速语句的确切位置。

让我们运行

之所以这样做，是因为我们已经看到PostgreSQL代码生成器运行一个缓慢的查询来获取所有存储过程（并生成重载索引）。 产生的错误消息是：

[WARNING] Slow SQL                 : jOOQ Meta executed a slow query (slower than 5 seconds)

Please report this bug here: https://github.com/jOOQ/jOOQ/issues/new

select
  "r1"."routine_schema",
  "r1"."routine_name",
  "r1"."specific_name",
  case when exists (
        select 1 as "one"
        from "information_schema"."parameters"
        where (
          "information_schema"."parameters"."specific_schema" = "r1"."specific_schema"
          and "information_schema"."parameters"."specific_name" = "r1"."specific_name"
          and upper("information_schema"."parameters"."parameter_mode")  'IN'
        )
      ) then 'void'
       else "r1"."data_type"
  end as "data_type",
  "r1"."character_maximum_length",
  "r1"."numeric_precision",
  "r1"."numeric_scale",
  "r1"."type_udt_schema",
  "r1"."type_udt_name",
  case when exists (
        select 1 as "one"
        from "information_schema"."routines" as "r2"
        where (
          "r2"."routine_schema" in (
            'public', 'multi_schema', 'pg_catalog'
          )
          and "r2"."routine_schema" = "r1"."routine_schema"
          and "r2"."routine_name" = "r1"."routine_name"
          and "r2"."specific_name"  "r1"."specific_name"
        )
      ) then (
        select count(*)
        from "information_schema"."routines" as "r2"
        where (
          "r2"."routine_schema" in (
            'public', 'multi_schema', 'pg_catalog'
          )
          and "r2"."routine_schema" = "r1"."routine_schema"
          and "r2"."routine_name" = "r1"."routine_name"
          and "r2"."specific_name" <= "r1"."specific_name"
        )
      ) end as "overload",
  "pg_catalog"."pg_proc"."proisagg"
from "information_schema"."routines" as "r1"
  join "pg_catalog"."pg_namespace"
  on "pg_catalog"."pg_namespace"."nspname" = "r1"."specific_schema"
  join "pg_catalog"."pg_proc"
  on (
    "pg_catalog"."pg_proc"."pronamespace" = "pg_catalog"."pg_namespace".oid
    and (("pg_catalog"."pg_proc"."proname" || '_') || cast("pg_catalog"."pg_proc".oid as varchar)) = "r1"."specific_name"
  )
where (
  "r1"."routine_schema" in (
    'public', 'multi_schema', 'pg_catalog'
  )
  and not("pg_catalog"."pg_proc"."proretset")
)
order by
  "r1"."routine_schema" asc,
  "r1"."routine_name" asc,
  "overload" asc
org.jooq.util.AbstractDatabase$1$SQLPerformanceWarning
        at org.jooq.util.AbstractDatabase$1.executeEnd(AbstractDatabase.java:230)
        at org.jooq.impl.ExecuteListeners.executeEnd(ExecuteListeners.java:163)
        at org.jooq.impl.AbstractResultQuery.execute(AbstractResultQuery.java:269)
        at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:346)
        at org.jooq.impl.AbstractResultQuery.fetch(AbstractResultQuery.java:308)
        at org.jooq.impl.SelectImpl.fetch(SelectImpl.java:2703)
        at org.jooq.util.postgres.PostgresDatabase.getRoutines0(PostgresDatabase.java:707)
        at org.jooq.util.AbstractDatabase.getRoutines(AbstractDatabase.java:1131)
        at org.jooq.util.JavaGenerator.generate(JavaGenerator.java:417)
        at org.jooq.util.JavaGenerator.generate(JavaGenerator.java:314)
        at org.jooq.util.JavaGenerator.generate(JavaGenerator.java:279)
        at org.jooq.util.GenerationTool.run(GenerationTool.java:490)
        at org.jooq.util.GenerationTool.generate(GenerationTool.java:193)
        at org.jooq.util.maven.Plugin.execute(Plugin.java:131)
        ...

现在，我们可以轻松地修复查询。

你也可以做到的！

ExecuteListener的实现很简单。 您可以非常轻松地执行相同操作。 只需将一个简单的执行侦听器挂接到jOOQ Configuration ，即可测量执行速度并在完成阈值后记录警告。

调试愉快！

进一步阅读

巧合的是， Square的工程团队记录了一种非常类似的方法–查询狙击手： https ： //corner.squareup.com/2016/01/query-sniper.html

翻译自: https://www.javacodegeeks.com/2016/02/detect-slow-queries-jooq.html

jooq 查询时间