【问题标题】:JDBC Instrumentation and ORA-01000: maximum open cursors exceededJDBC Instrumentation 和 ORA-01000:超过最大打开游标
【发布时间】:2017-02-21 21:02:51
【问题描述】:

当连接创建关闭时,我正在尝试更好地检测哪些 Web 应用程序在我们的 Tomcat JDBC 连接池中使用 Oracle (11g) 连接;这样,我们可以通过监视V$SESSION 表来查看哪些应用程序正在使用连接。这是有效的,但是自从添加了这个“仪器”后,我看到ORA-01000: maximum open cursors exceeded 错误被记录并注意到在负载测试期间一些连接被从池中删除(这可能很好,因为我启用了testOnBorrow,所以我假设连接被标记为无效并从池中删除)。

我花了一周的大部分时间在互联网上搜寻可能的答案。这是我尝试过的(一段时间后都导致打开游标错误)...

以下方法的调用方式都一样...

创建时

  1. 我们从池中获得一个连接
  2. 我们调用一个方法来执行以下代码,并传入 Web 应用程序的上下文名称

关闭时

  1. 我们已关闭连接(返回池)
  2. 在连接上发出close()之前,我们调用一个执行下面代码的方法,传入“Idle”作为名称存储在V$SESSION

方法一:

CallableStatement cs = connection.prepareCall("{call DBMS_APPLICATION_INFO.SET_MODULE(?,?)}");
try {
    cs.setString(1, appId);
    cs.setNull(2, Types.VARCHAR);
    cs.execute();
    log.trace(">>> Executed Oracle DBMS_APPLICATION_INFO.SET_MODULE with module_name of '" + appId + "'");
} catch (SQLException sqle) {
    log.error("Error trying to call DBMS_APPLICATION_INFO.SET_MODULE('" + appId + "')", sqle);
} finally {
    cs.close();
}

方法二:

我升级到了12c OJDBC驱动(ojdbc7),在连接上使用了原生的setClientInfo方法……

// requires ojdbc7.jar and oraclepki.jar to work (setEndToEndMetrics is deprecated in ojdbc7)
connection.setClientInfo("OCSID.CLIENTID", appId);

方法三:

我目前正在使用这种方法。

String[] app_instrumentation = new String[OracleConnection.END_TO_END_STATE_INDEX_MAX];
app_instrumentation[OracleConnection.END_TO_END_CLIENTID_INDEX] = appId;
connection.unwrap(OracleConnection.class).setEndToEndMetrics(app_instrumentation, (short)0);
// in order for this to be sent, a query needs to be sent to the database - this works fine when a 
// connection is created, but when it is closed, we need a little something to get the change into the db
// try using isValid()
connection.isValid(1);

方法四:

String[] app_instrumentation = new String[OracleConnection.END_TO_END_STATE_INDEX_MAX];
app_instrumentation[OracleConnection.END_TO_END_CLIENTID_INDEX] = appId;
connection.unwrap(OracleConnection.class).setEndToEndMetrics(app_instrumentation, (short)0);
// in order for this to be sent, a query needs to be sent to the database - this works fine when a 
// connection is created, but when it is closed, we need a little something to get the change into the db
if ("Idle".equalsIgnoreCase(appId)) {
    Statement stmt = null;
    ResultSet rs = null;
    try {
        stmt = connection.createStatement();
        rs = stmt.executeQuery("select 1 from dual");
    } finally {
        if (rs != null) {
            rs.close();
        }
        if (stmt != null) {
            stmt.close();
        }
    }
}

当我查询打开的游标时,我注意到池中正在使用的帐户(对于池中的每个连接)返回了以下 SQL...

select NULL NAME, -1 MAX_LEN, NULL DEFAULT_VALUE, NULL DESCR

这在我们的代码中没有明确存在,所以我只能假设它在运行验证查询时来自池(select 1 from dual)或来自setEndToEndMetrics 方法(或来自DBMS_APPLICATION_INFO.SET_MODULE proc,或来自isValid() 电话)。我试图在方法 1 和 4 中明确地创建和关闭 Statement (CallableStatement) 和 ResultSet 对象,但它们没有区别。

我不想增加允许的游标数量,因为这只会延迟不可避免的情况(在我添加“仪器”之前,我们从未遇到过这个问题)。

我已经阅读了出色的帖子 herejava.sql.SQLException: - ORA-01000: 超出了最大打开游标),但我仍然必须遗漏一些东西。任何帮助将不胜感激。

【问题讨论】:

  • 你怎么知道错误与仪器有关?没有对任何其他代码进行任何更改吗? v$session 为持有打开游标的会话显示什么 - 是为这些会话记录的 appId,还是来自其他地方?该查询看起来像是在获取虚假元数据;您是否还有其他代码可以查询真实元数据(来自*_tab_columns),可能来自您的 Tomcat 环境之外的脚本或客户端?
  • 未对其他代码进行任何更改。我正在使用目前在 prod 中仅针对两个 Web 应用程序的主干代码进行负载测试,因此我知道它是稳定的并且不会在 Prod 中导致此问题(我在测试时没有访问其他应用程序,并且我在每次测试之前重新启动 Tomcat) .此代码位于一个通用 DAO 类中,由 Tomcat 中运行的所有应用程序共享。池使用单个帐户,我可以在 V$SESSION 中看到 appId 名称 - 我记录了连接的 SID(在池中),并且在查看打开的游标时可以在 V$SESSION 中关联它。没有外部脚本正在使用池中使用的帐户。
  • 打开游标查询:select sid, sql_text, count(*) as "OPEN CURSORS", USER_NAME from v$open_cursor where user_name='<MY_POOL_ID>' group by sid, sql_text, user_name order by "OPEN CURSORS" DESC

标签: java oracle jdbc oracle11g


【解决方案1】:

所以 Poole 先生的声明:“那个查询看起来像是在获取虚假元数据”在我脑海中敲响了警钟。

我开始怀疑它是否是在池数据源的testOnBorrow 属性上运行的验证查询的一些未知残余(即使验证查询被定义为select 1 from dual)。我从配置中删除了它,但它没有效果。

然后我尝试删除在V$SESSION 中设置客户端信息的代码(上面的方法3); Oracle 继续显示该异常查询,仅几分钟后,会话将达到最大打开游标限制。

然后我发现我们的 DAO 类中有一个“记录”方法,它记录了连接对象中的一些元数据(当前自动提交、当前事务隔离级别、JDBC 驱动程序版本等设置的值)。在此日志记录中,对DatabaseMetaData 对象使用了getClientInfoProperties() 方法。当我查看这个方法的 JavaDocs 时,很清楚那个不寻常的查询是从哪里来的。看看吧……

ResultSet java.sql.DatabaseMetaData.getClientInfoProperties() throws SQLException

Retrieves a list of the client info properties that the driver supports. The result set contains the following columns 

1. NAME String=> The name of the client info property
2. MAX_LEN int=> The maximum length of the value for the property
3. DEFAULT_VALUE String=> The default value of the property
4. DESCRIPTION String=> A description of the property. This will typically contain information as to where this property is stored in the database. 

The ResultSet is sorted by the NAME column 

Returns:

A ResultSet object; each row is a supported client info property

您可以清楚地看到异常查询 (select NULL NAME, -1 MAX_LEN, NULL DEFAULT_VALUE, NULL DESCR) 与 JavaDocs 关于 DatabaseMetaData.getClientInfoProperties() 方法的说法相匹配。哇,对吧!?

这是执行该功能的代码。据我所知,从“关闭ResultSet”的角度来看,它看起来是正确的——不确定发生了什么会使ResultSet 保持打开状态——它显然在finally 块中被关闭。

log.debug(">>>>>> DatabaseMetaData Client Info Properties (jdbc driver)...");
ResultSet rsDmd = null;
try {
    boolean hasResults = false;
    rsDmd = dmd.getClientInfoProperties();
    while (rsDmd.next()) {
        hasResults = true;
        log.debug(">>>>>>>>> NAME = '" + rsDmd.getString("NAME") + "'; DEFAULT_VALUE = '" + rsDmd.getString("DEFAULT_VALUE") + "'; DESCRIPTION = '" + rsDmd.getString("DESCRIPTION") + "'");
    }
    if (!hasResults) {
        log.debug(">>>>>>>>> DatabaseMetaData Client Info Properties was empty (nothing returned by jdbc driver)");
    }
} catch (SQLException sqleDmd) {
    log.warn("DatabaseMetaData Client Info Properties (jdbc driver) not supported or no access to system tables under current id");
} finally {
    if (rsDmd != null) {
        rsDmd.close();
    }
}

查看日志,当使用 Oracle 连接时,>>>>>>>>> DatabaseMetaData Client Info Properties was empty (nothing returned by jdbc driver) 行被记录,因此没有抛出异常,但也没有返回记录。我只能假设 ojdbc6 (11.2.0.xx) 驱动程序不能正确支持 getClientInfoProperties() 方法 - 奇怪的是(我认为)没有抛出异常,因为查询本身缺少 @ 987654335@ 关键字(例如在 TOAD 中执行时不会运行)。无论如何,ResultSet 至少应该已经关闭(尽管连接本身仍然在使用中 - 也许这会导致 Oracle 不会释放游标,即使 ResultSet 已关闭)。

所以我所做的所有工作都在一个分支中(我在对原始问题的评论中提到我在主干中工作 - 我的错误 - 我在一个已经创建的分支中,认为它是基于主干的代码并且没有修改 - 我没有在这里做尽职调查),所以我检查了 SVN 提交历史,发现这个额外的日志记录功能是几周前由一个队友添加的(幸运的是它还没有被提升到主干或更高的环境 - 请注意此代码适用于我们的 Sybase 数据库)。我从 SVN 分支的更新引入了他的代码,但我从未真正关注过更新的内容(我的错)。我与他讨论了这段代码对 Oracle 的作用,我们同意从日志记录方法中删除该代码。我们还设置了一个检查,仅在我们的开发环境中记录连接元数据(他说他添加了这个代码来帮助解决他遇到的一些驱动程序版本和自动提交问题)。完成此操作后,我就能够运行负载测试,而不会出现任何打开的游标问题(成功!!!)。

无论如何,我想回答这个问题,因为当我搜索 select NULL NAME, -1 MAX_LEN, NULL DEFAULT_VALUE, NULL DESCRORA-01000 open cursors 时,没有返回可信的命中(返回的大多数命中是为了确保您正在关闭连接资源,即 @987654340 @s、Statements 等)。我认为这表明它是通过 JDBC 针对 Oracle 进行的数据库元数据查询是 ORA-01000 错误的罪魁祸首。我希望这对其他人有用。谢谢。

【讨论】:

    猜你喜欢
    • 1970-01-01
    • 2012-08-24
    相关资源
    最近更新 更多