JNI多线程调用ojdbc报错问题排查

现象

c++内核多个连接分别通过oracle jdbc8连接和查询oracle11g。

只有主线程,也就是调用JNI_CreateJavaVM的线程能够正常连接,并执行查询返回结果集。

其他线程都会在连接的时候,也就是getConnection的时候报错,通过JNI的异常捕捉机制获取异常信息显示:

Exception in thread "Thread-3" java.sql.SQLException: No suitable driver found for jdbc:oracle:thin:@11.165.114.206:41521:xe
        at java.sql.DriverManager.getConnection(DriverManager.java:689)
        at java.sql.DriverManager.getConnection(DriverManager.java:247)

各个线程通过FindClass都能够找到DriverManager类,也能够找到getConnection方法,所以不存在多线程找不到类的问题。而且报错信息也不是找不到类。

如果主线程调用了DetachCurrentThread方法,那么调用之后连主线程自己也开始报这个No suitable driver的错。从这个现象看,跟线程有关。

分析

看了DriverManager的代码,getConnection的时候报错,有两种可能

  • registeredDrivers为空
  • 所有的driver都是isDriverAllowed为false
private static Connection getConnection(
    String url, java.util.Properties info, Class<?> caller) throws SQLException {
    /*
* When callerCl is null, we should check the application's
* (which is invoking this class indirectly)
* classloader, so that the JDBC driver class outside rt.jar
* can be loaded from here.
*/
    ClassLoader callerCL = caller != null ? caller.getClassLoader() : null;
    synchronized(DriverManager.class) {
        // synchronize loading of the correct classloader.
        if (callerCL == null) {
            callerCL = Thread.currentThread().getContextClassLoader();
        }
    }

    if(url == null) {
        throw new SQLException("The url cannot be null", "08001");
    }

    println("DriverManager.getConnection(\"" + url + "\")");

    // Walk through the loaded registeredDrivers attempting to make a connection.
    // Remember the first exception that gets raised so we can reraise it.
    SQLException reason = null;

    for(DriverInfo aDriver : registeredDrivers) {
        // If the caller does not have permission to load the driver then
        // skip it.
        if(isDriverAllowed(aDriver.driver, callerCL)) {
            try {
                println("    trying " + aDriver.driver.getClass().getName());
                Connection con = aDriver.driver.connect(url, info);
                if (con != null) {
                    // Success!
                    println("getConnection returning " + aDriver.driver.getClass().getName());
                    return (con);
                }
            } catch (SQLException ex) {
                if (reason == null) {
                    reason = ex;
                }
            }

        } else {
            println("    skipping: " + aDriver.getClass().getName());
        }

    }

    // if we got here nobody could connect.
    if (reason != null)    {
        println("getConnection failed: " + reason);
        throw reason;
    }

    println("getConnection: no suitable driver found for "+ url);
    throw new SQLException("No suitable driver found for "+ url, "08001");
}


}

首先怀疑第一个方向:registeredDrivers为空

registeredDrivers是一个类static变量,所以怀疑是不是多线程的时候,访问静态变量有问题。

怀疑是不是jdbc压根不能多线程调用

写了个java多线程程序,调用正常,这个怀疑不成立.

import java.sql.ResultSet;
import java.sql.ResultSetMetaData;
import java.sql.DriverManager;
import java.sql.Connection;
import java.sql.Statement;
import java.sql.SQLException;
import java.nio.charset.StandardCharsets;
import java.util.Enumeration;
import java.sql.Driver;


public class testmt extends Thread{
    public static void query() {
        String url = "jdbc:oracle:thin:@11.165.114.206:41521:xe";
        try {
                Connection conn1 = DriverManager.getConnection(url, "fareuser", "rohit123");
                System.out.println(conn1);
                Statement statement = conn1.createStatement();
                ResultSet rs = statement.executeQuery("select * from fareuser.table1");
                ResultSetMetaData rsmd = rs.getMetaData();
                int numCols = rsmd.getColumnCount();
                for (int i = 1; i <= numCols; i++) {
                        if (i > 1) {
                                System.out.print(",");
                        }
                        System.out.print(rsmd.getColumnLabel(i));
                }
                System.out.println("");
                while (rs.next()) {
                        for (int i = 1; i <= numCols; i++) {
                        if (i > 1) {
                                System.out.print(",");
                        }
                        System.out.print(rs.getString(i));
                }
                System.out.println("");
                }
                rs.close();
                statement.close();
                conn1.close();
        } catch (Exception e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        } finally {
            System.out.println("query finally");
        }
    }

    public void run() {
        java.sql.PreparedStatement ps = null;
        java.sql.Connection cn = null;
        ResultSet rs = null;

        try {
            java.lang.Class.forName("oracle.jdbc.driver.OracleDriver");

            String url = "jdbc:oracle:thin:@11.165.114.206:41521:xe";
            Connection conn = DriverManager.getConnection(url, "fareuser", "rohit123");
            System.out.println(conn);
            conn.setAutoCommit(false);
            System.out.println("set autocommit done");

            query();
            System.out.println("query1 done");

            query();
            System.out.println("query2 done");

        } catch (Exception e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        } finally {
            System.out.println("ok");
        }
    }

  public static void main(String[] args) {
        testmt mt1 = new testmt();
        testmt mt2 = new testmt();
        testmt mt3 = new testmt();
        mt1.start();
        System.out.println("conn1 start");
        mt2.start();
        System.out.println("conn2 start");
        mt3.start();
        System.out.println("conn3 start");
  }

}

怀疑是不是多个线程间没有同步registeredDrivers的值

整个进程用同一个DriverManager类

主线程FindClass之后把DriverManager类保存下来,各个线程都用这一个类。——无效

每个线程都调用Class.forName

包括主线程在内都调用失败,报错,原因未知

Exception in thread "Thread-3" java.lang.ClassNotFoundException: oracle/jdbc/driver/OracleDriver
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:264)
每个线程都调用registerDriver方法

不知道调用是否成功——无效。

怀疑isDriverAllowed为false

上大招,改写DriverManager.java,增加调试日志,重编jdk里的DriverManager

寻找DriverManager.java文件
[root]# find -name DriverManager.java
./home/java/jdk/jdk/src/share/classes/java/sql/DriverManager.java
添加调试信息

改掉日志打印函数

重编
javac DriverManager.java

有一坨warning,不用管,生成四个class:

DriverInfo.class  DriverManager$1.class  DriverManager$2.class  DriverManager.class
找到DriverManager.class所在的位置

在jvm的启动参数里增加-verbose:class参数,看看各个类都是怎么加载的。

从日志里看到DriverManager类在rt.jar中。

寻找rt.jar
[root@linkeonepounch-0-100083094089 /]# find -name rt.jar
./usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/lib/rt.jar
解压rt.jar

拷贝rt.jar到另一个文件夹,加压

jar -xvf rt.jar

得到六个文件夹 + META-INF

META-INF  com  java  javax  jdk  org  sun
替换.class

DriverManager.class放在java/sql下,直接替换即可

mv *.class ./test_jar/java/sql/
重新打包
jar -cvfm rt.jar META-INF/MANIFEST.MF com java javax jdk org sun
替换rt.jar
cp ./test_jar/rt.jar ./usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-1.el7_9.x86_64/jre/lib/rt.jar

重新跑看日志

DriverManager.initialize: jdbc.drivers = null
JDBC DriverManager initialized
registerDriver: oracle.jdbc.OracleDriver@3b9a45b3
2022-09-22T06:56:19.362518Z 8 [ERROR] [MY-013776] [Server] JClass (jclass.cc:51) Using global dm (global_class_path:/usr/lib64/mysql/plugin/:/jiamao_test/trypticon/build_docker/deps/desens/lib/slf4j-log4j12-1.7.21.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/com.springsource.org.apache.log4j-1.2.16.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/desensitization-sdk-0.7.4.20220816-SNAPSHOT.jar:/jiamao_test/trypticon/build_docker/deps/oracle/lib/ojdbc8.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/, class_name:java/sql/DriverManager, get_ENV():0x7f06800122d8)
getConnection: caller null
getConnection: caller null
getConnection: caller sun.misc.Launcher$AppClassLoader@764c12b6
getConnection: callername:sun.misc.Launcher$AppClassLoader
DriverManager.getConnection("jdbc:oracle:thin:@11.165.114.206:41521:xe")
getConnection current driver oracle.jdbc.OracleDriver
test driver allow oracle.jdbc.OracleDriver
using classLoader sun.misc.Launcher$AppClassLoader
oracle.jdbc.OracleDriver
oracle.jdbc.OracleDriver
    trying oracle.jdbc.OracleDriver
test driver allow oracle.jdbc.OracleDriver
using classLoader sun.misc.Launcher$AppClassLoader
oracle.jdbc.OracleDriver
oracle.jdbc.OracleDriver
SQLWarning: reason(ORA-28002: the password will expire within 4 days
) SQLState(99999) vendor code(28002)
getConnection returning oracle.jdbc.OracleDriver
2022-09-22T06:56:20.147836Z 8 [ERROR] [MY-013776] [Server] call (jclass.cc:1025) ==========>>>>>>>>>>call method end (obj:0x7f06800137a0, jvm_singleton:0x7f068002c360, VM:0x7f068002c360, jMain:0x7f0680273210)
2022-09-22T06:56:20.147876Z 8 [ERROR] [MY-013776] [Server] JClass (jclass.cc:54) Using new dm (global_class_path:/usr/lib64/mysql/plugin/:/jiamao_test/trypticon/build_docker/deps/desens/lib/slf4j-log4j12-1.7.21.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/com.springsource.org.apache.log4j-1.2.16.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/desensitization-sdk-0.7.4.20220816-SNAPSHOT.jar:/jiamao_test/trypticon/build_docker/deps/oracle/lib/ojdbc8.jar:/jiamao_test/trypticon/build_docker/deps/desens/lib/, class_name:java/sql/Connection, get_ENV():0x7f06800122d8)
2022-09-22T06:56:20.180290Z 9 [Warning] [MY-013360] [Server] Plugin sha256_password reported: ''sha256_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
2022-09-22T06:56:20.184455Z 9 [ERROR] [MY-013776] [Server] dispatch_command (sql_parse.cc:1909) etner COM_QUERY (ret:1521)
2022-09-22T06:56:20.186986Z 9 [ERROR] [MY-013776] [Server] dispatch_command (sql_parse.cc:1909) etner COM_QUERY (ret:1521)
2022-09-22T06:56:20.187564Z 9 [Warning] [MY-013776] [Server] query (oracle_engine.cc:209) not supported dameng set-attr statement. (ret:257)
2022-09-22T06:56:20.187813Z 9 [ERROR] [MY-013776] [Server] dispatch_command (sql_parse.cc:1909) etner COM_QUERY (ret:1521)
2022-09-22T06:56:20.188400Z 9 [Warning] [MY-013776] [Server] query (oracle_engine.cc:209) not supported dameng set-attr statement. (ret:257)
2022-09-22T06:56:20.188731Z 9 [ERROR] [MY-013776] [Server] dispatch_command (sql_parse.cc:1909) etner COM_QUERY (ret:1521)
2022-09-22T06:56:20.189324Z 9 [ERROR] [MY-013776] [Server] GetENV (jvm.h:63) 000000000000000000000000000000000000000000000 Attaching (res:-2)
getConnection: caller null
getConnection: caller null
getConnection: caller null
DriverManager.getConnection("jdbc:oracle:thin:@11.165.114.206:41521:xe")
getConnection current driver oracle.jdbc.OracleDriver
test driver allow oracle.jdbc.OracleDriver
Exception in thread "Thread-3" java.lang.NullPointerException
        at java.sql.DriverManager.isDriverAllowed(DriverManager.java:556)
        at java.sql.DriverManager.getConnection(DriverManager.java:674)
        at java.sql.DriverManager.getConnection(DriverManager.java:247)

从日志里可以看出,8号线程,也就是主线程在isDriverAllowed里传入的classLoader是有效的,而9号线成传入的则是null。同时加入的日志也证明了第一个猜想里的registeredDrivers不是空。

看代码为什么传入的classLoader是空?答案很明显了:Thread.currentThread().getContextClassLoader()返回值为null。

解决

直接原因明确了,google一下,相关答案不多:

JNI and reflection - Oracle Forums

Setting context class loader from jvm launcher - Oracle Forums

java native interface - Why do subsequent jni threads return null on currentThread().getClassLoader()? - Stack Overflow

在AttachCurrentThread完之后调用一下setContextClassLoader,把systemClassLoader设上,果然就可以了。

这个问题遇到的人很少,贴一下别人的惊奇:

  • 22
    点赞
  • 29
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值