【 使用环境 】 测试环境
【 OB 版本】社区 4.1.0.0 版本
【 OBLogProxy 版本】oblogproxy-1.1.0-1.el8.x86_64
【问题描述】尝试使用 oblogclient 订阅增量数据，但是显示 Failed to fetch peer info of fd:8, errno:9, error:Bad file descriptor，因此 Java 代码中无法订阅到数据。
【复现路径】
我创建了一个 MySQL 租户 test，密码如代码所示，并且关掉了 obproxy 的 auth（否则会有问题）。
代码中，一开始我用系统租户，所以失败，这个我改过来了。
但是后来我重新创建了一个租户，config.setUsername("root@test"); 和 config.setUsername("test"); 我都试过，但是都是一样的报错。
package org.example;
import com.oceanbase.clogproxy.client.LogProxyClient;
import com.oceanbase.clogproxy.client.config.ObReaderConfig;
import com.oceanbase.clogproxy.client.exception.LogProxyClientException;
import com.oceanbase.clogproxy.client.listener.RecordListener;
import com.oceanbase.oms.logmessage.LogMessage;
// Press Shift twice to open the Search Everywhere dialog and type `show whitespaces`,
// then press Enter. You can now see whitespace characters in your code.
public class Main {
public static void main(String[] args) {
ObReaderConfig config = new ObReaderConfig();
// 设置OceanBase root server 地址列表，格式为（可以支持多个，用';'分隔）：ip1:rpc_port1:sql_port1;ip2:rpc_port2:sql_port2
config.setRsList("175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881");
// 设置用户名和密码（非系统租户）
config.setUsername("root@test");
config.setPassword("OB-pwd-123");
// 设置启动位点（UNIX时间戳，单位s）, 0表示从当前时间启动。
config.setStartTimestamp(0L);
// 设置订阅表白名单，格式为：tenant.db.table, '*'表示通配.
config.setTableWhiteList("sys.*.*");
// 指定oblogproxy服务地址，创建实例.
LogProxyClient client = new LogProxyClient("175.27.169.129", 2983, config);
// 添加 RecordListener
client.addListener(new RecordListener() {
@Override
public void notify(LogMessage message) {
System.out.println(message);
}
@Override
public void onException(LogProxyClientException e) {
// 处理错误
if (e.needStop()) {
// 不可恢复异常，需要停止Client
System.out.println(e);
client.stop();
}
}
});
// 启动
client.start();
client.join();
}
}
附上 oblogproxy 日志：
I20230718 01:30:59.605816 397397 comm.cpp:165] On connect from '183.156.100.47:51231, fd: 8
I20230718 01:30:59.605846 397397 comm.cpp:197] Add channel, peer: id:3415026730604101640, fd:8, addr:795122871, port:51231
I20230718 01:30:59.605866 397397 comm.cpp:214] Add read channel to Communicator with peer: id:3415026730604101640, fd:8, addr:795122871, port:51231
I20230718 01:30:59.605888 397397 comm.cpp:228] On event fd: 8 got channel, peer: id:3415026730604101640, fd:8, addr:795122871, port:51231
I20230718 01:30:59.605919 397397 msg_buf.cpp:117] got EOF while call next
I20230718 01:30:59.605932 397397 arranger.cpp:74] Arranger on_msg fired: id:3415026730604101640, fd:8, addr:795122871, port:51231
I20230718 01:30:59.605938 397397 arranger.cpp:81] Handshake request from peer: id:3415026730604101640, fd:8, addr:795122871, port:51231, msg: log_type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , enable_monitor:0,
I20230718 01:30:59.605986 397397 arranger.cpp:93] ObConfig from peer: id:3415026730604101640, fd:8, addr:795122871, port:51231 after resolve: cluster_id:,cluster_password:pwd-ob-123,cluster_url:,cluster_user:root@test,first_start_timestamp:0,first_start_timestamp_us:0,id:,rootserver_list:175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881,sys_password:,sys_user:,tb_white_list:sys.*.*,
I20230718 01:30:59.606258 397397 io.cpp:119] Connect to server success after poll. host=175.27.169.129,port=2881
I20230718 01:30:59.606281 397397 mysql_protocol.cpp:51] Connect to server success: 175.27.169.129:2881, user: root
I20230718 01:30:59.606514 397397 mysql_protocol.cpp:82] Receive handshake packet from server: 175.27.169.129:2881, user: root
I20230718 01:30:59.606528 397397 ob_mysql_packet.cpp:256] Observer version: 5.7.25
I20230718 01:30:59.606534 397397 ob_mysql_packet.cpp:264] Connection id: 3221713027
I20230718 01:30:59.606539 397397 ob_mysql_packet.cpp:355] Auth plugin name: mysql_native_password
I20230718 01:30:59.606568 397397 ob_mysql_packet.cpp:589] Handshake response packet len: 80
I20230718 01:30:59.607388 397397 mysql_protocol.cpp:122] Auth user success of server: 175.27.169.129:2881, user: root
I20230718 01:30:59.607401 397397 mysql_protocol.cpp:214] Query obmysql SQL:SELECT svr_min_log_timestamp FROM oceanbase.__all_virtual_server_clog_stat WHERE zone_status='ACTIVE';
I20230718 01:30:59.608139 397397 ob_mysql_packet.cpp:220] Error packet: [31487][#42S02] Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist
E20230718 01:30:59.608148 397397 mysql_protocol.cpp:239] Failed to query observer:Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist, unexpected column count: 0
E20230718 01:30:59.608166 397397 clog_meta_routine.cpp:45] Failed to check the existence of svr_min_log_timestamp column in __all_virtual_server_clog_stat, disable clog check
I20230718 01:30:59.608215 397397 arranger.cpp:223] Client connecting: type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , pid:0, peer:fd:8, register_time:1689615059, enable_monitor:0, packet_version:2,
I20230718 01:30:59.609450 397397 source_invoke.cpp:75] +++ Created oblogreader with pid: 416392
I20230718 01:30:59.609493 397397 comm.cpp:324] Try close Channel of peer: id:3415026730604101640, fd:8, addr:795122871, port:51231
I20230718 01:30:59.609535 397397 channel.h:46] Closed fd: 8
I20230718 01:30:59.609556 397397 arranger.cpp:241] Remove peer: id:3415026730604101640, fd:8, addr:795122871, port:51231 after source invoked, current channel count:0
I20230718 01:30:59.609576 397397 arranger.cpp:246] Client connected: 172.20.144.1_12736_1689615003 with peer: id:3415026730604101640, fd:8, addr:795122871, port:51231
W20230718 01:31:00.109701 397397 arranger.cpp:327] Exited oblogreader of pid: 416392 with clientId: 172.20.144.1_12736_1689615003 of peer:id:3415026730604101640, fd:8, addr:795122871, port:51231
W20230718 01:31:00.109756 397397 arranger.cpp:342] Failed to fetch peer info of fd:8, errno:9, error:Bad file descriptor
W20230718 01:31:00.109764 397397 arranger.cpp:349] Try to shutdown fd: 8
W20230718 01:31:00.109768 397397 arranger.cpp:351] Shutdown fd: 8
I20230718 01:31:01.610038 397397 comm.cpp:165] On connect from '183.156.100.47:58050, fd: 8
I20230718 01:31:01.610074 397397 comm.cpp:197] Add channel, peer: id:3415026731050991624, fd:8, addr:795122871, port:58050
I20230718 01:31:01.610112 397397 comm.cpp:214] Add read channel to Communicator with peer: id:3415026731050991624, fd:8, addr:795122871, port:58050
I20230718 01:31:01.610128 397397 comm.cpp:228] On event fd: 8 got channel, peer: id:3415026731050991624, fd:8, addr:795122871, port:58050
I20230718 01:31:01.610177 397397 msg_buf.cpp:117] got EOF while call next
I20230718 01:31:01.610216 397397 arranger.cpp:74] Arranger on_msg fired: id:3415026731050991624, fd:8, addr:795122871, port:58050
I20230718 01:31:01.610231 397397 arranger.cpp:81] Handshake request from peer: id:3415026731050991624, fd:8, addr:795122871, port:58050, msg: log_type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , enable_monitor:0,
I20230718 01:31:01.610299 397397 arranger.cpp:93] ObConfig from peer: id:3415026731050991624, fd:8, addr:795122871, port:58050 after resolve: cluster_id:,cluster_password:pwd-ob-123,cluster_url:,cluster_user:root@test,first_start_timestamp:0,first_start_timestamp_us:0,id:,rootserver_list:175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881,sys_password:,sys_user:,tb_white_list:sys.*.*,
I20230718 01:31:01.611836 397397 io.cpp:119] Connect to server success after poll. host=175.27.169.129,port=2881
I20230718 01:31:01.611871 397397 mysql_protocol.cpp:51] Connect to server success: 175.27.169.129:2881, user: root
I20230718 01:31:01.613315 397397 mysql_protocol.cpp:82] Receive handshake packet from server: 175.27.169.129:2881, user: root
I20230718 01:31:01.613334 397397 ob_mysql_packet.cpp:256] Observer version: 5.7.25
I20230718 01:31:01.613341 397397 ob_mysql_packet.cpp:264] Connection id: 3221713498
I20230718 01:31:01.613368 397397 ob_mysql_packet.cpp:355] Auth plugin name: mysql_native_password
I20230718 01:31:01.613382 397397 ob_mysql_packet.cpp:589] Handshake response packet len: 80
I20230718 01:31:01.616580 397397 mysql_protocol.cpp:122] Auth user success of server: 175.27.169.129:2881, user: root
I20230718 01:31:01.616598 397397 mysql_protocol.cpp:214] Query obmysql SQL:SELECT svr_min_log_timestamp FROM oceanbase.__all_virtual_server_clog_stat WHERE zone_status='ACTIVE';
I20230718 01:31:01.619791 397397 ob_mysql_packet.cpp:220] Error packet: [31487][#42S02] Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist
E20230718 01:31:01.619807 397397 mysql_protocol.cpp:239] Failed to query observer:Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist, unexpected column count: 0
E20230718 01:31:01.619827 397397 clog_meta_routine.cpp:45] Failed to check the existence of svr_min_log_timestamp column in __all_virtual_server_clog_stat, disable clog check
I20230718 01:31:01.619889 397397 arranger.cpp:223] Client connecting: type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , pid:0, peer:fd:8, register_time:1689615061, enable_monitor:0, packet_version:2,
I20230718 01:31:01.620965 397397 source_invoke.cpp:75] +++ Created oblogreader with pid: 416437
I20230718 01:31:01.621011 397397 comm.cpp:324] Try close Channel of peer: id:3415026731050991624, fd:8, addr:795122871, port:58050
I20230718 01:31:01.621064 397397 channel.h:46] Closed fd: 8
I20230718 01:31:01.621076 397397 arranger.cpp:241] Remove peer: id:3415026731050991624, fd:8, addr:795122871, port:58050 after source invoked, current channel count:0
I20230718 01:31:01.621098 397397 arranger.cpp:246] Client connected: 172.20.144.1_12736_1689615003 with peer: id:3415026731050991624, fd:8, addr:795122871, port:58050
W20230718 01:31:02.121224 397397 arranger.cpp:327] Exited oblogreader of pid: 416437 with clientId: 172.20.144.1_12736_1689615003 of peer:id:3415026731050991624, fd:8, addr:795122871, port:58050
W20230718 01:31:02.121273 397397 arranger.cpp:342] Failed to fetch peer info of fd:8, errno:9, error:Bad file descriptor
W20230718 01:31:02.121280 397397 arranger.cpp:349] Try to shutdown fd: 8
W20230718 01:31:02.121289 397397 arranger.cpp:351] Shutdown fd: 8
I20230718 01:31:03.621547 397397 comm.cpp:165] On connect from '183.156.100.47:51233, fd: 8
I20230718 01:31:03.621596 397397 comm.cpp:197] Add channel, peer: id:3415026730604232712, fd:8, addr:795122871, port:51233
I20230718 01:31:03.621836 397397 comm.cpp:214] Add read channel to Communicator with peer: id:3415026730604232712, fd:8, addr:795122871, port:51233
I20230718 01:31:03.621863 397397 comm.cpp:228] On event fd: 8 got channel, peer: id:3415026730604232712, fd:8, addr:795122871, port:51233
I20230718 01:31:03.621899 397397 msg_buf.cpp:117] got EOF while call next
I20230718 01:31:03.621920 397397 arranger.cpp:74] Arranger on_msg fired: id:3415026730604232712, fd:8, addr:795122871, port:51233
I20230718 01:31:03.621933 397397 arranger.cpp:81] Handshake request from peer: id:3415026730604232712, fd:8, addr:795122871, port:51233, msg: log_type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , enable_monitor:0,
I20230718 01:31:03.622011 397397 arranger.cpp:93] ObConfig from peer: id:3415026730604232712, fd:8, addr:795122871, port:51233 after resolve: cluster_id:,cluster_password:pwd-ob-123,cluster_url:,cluster_user:root@test,first_start_timestamp:0,first_start_timestamp_us:0,id:,rootserver_list:175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881,sys_password:,sys_user:,tb_white_list:sys.*.*,
I20230718 01:31:03.622395 397397 io.cpp:119] Connect to server success after poll. host=175.27.169.129,port=2881
I20230718 01:31:03.622407 397397 mysql_protocol.cpp:51] Connect to server success: 175.27.169.129:2881, user: root
I20230718 01:31:03.622560 397397 mysql_protocol.cpp:82] Receive handshake packet from server: 175.27.169.129:2881, user: root
I20230718 01:31:03.622577 397397 ob_mysql_packet.cpp:256] Observer version: 5.7.25
I20230718 01:31:03.622583 397397 ob_mysql_packet.cpp:264] Connection id: 3221714035
I20230718 01:31:03.622593 397397 ob_mysql_packet.cpp:355] Auth plugin name: mysql_native_password
I20230718 01:31:03.622640 397397 ob_mysql_packet.cpp:589] Handshake response packet len: 80
I20230718 01:31:03.625078 397397 mysql_protocol.cpp:122] Auth user success of server: 175.27.169.129:2881, user: root
I20230718 01:31:03.625093 397397 mysql_protocol.cpp:214] Query obmysql SQL:SELECT svr_min_log_timestamp FROM oceanbase.__all_virtual_server_clog_stat WHERE zone_status='ACTIVE';
I20230718 01:31:03.625895 397397 ob_mysql_packet.cpp:220] Error packet: [31487][#42S02] Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist
E20230718 01:31:03.625909 397397 mysql_protocol.cpp:239] Failed to query observer:Table 'oceanbase.__all_virtual_server_clog_stat' doesn't exist, unexpected column count: 0
E20230718 01:31:03.625950 397397 clog_meta_routine.cpp:45] Failed to check the existence of svr_min_log_timestamp column in __all_virtual_server_clog_stat, disable clog check
I20230718 01:31:03.626015 397397 arranger.cpp:223] Client connecting: type:0, id:172.20.144.1_12736_1689615003, ip:172.20.144.1, version:1.0.7, configuration:tb_white_list=sys.*.* cluster_user=root@test tb_black_list=| timezone=+8:00 working_mode=storage rootserver_list=175.27.169.129:2882:2881;175.27.241.31:2882:2881;119.45.142.75:2882:2881 first_start_timestamp=0 cluster_password=1DB266597DA11E6F2B684F72A034339BAB5A85B5 , pid:0, peer:fd:8, register_time:1689615063, enable_monitor:0, packet_version:2,
I20230718 01:31:03.627111 397397 source_invoke.cpp:75] +++ Created oblogreader with pid: 416486
I20230718 01:31:03.627177 397397 comm.cpp:324] Try close Channel of peer: id:3415026730604232712, fd:8, addr:795122871, port:51233
I20230718 01:31:03.627521 397397 channel.h:46] Closed fd: 8
I20230718 01:31:03.627532 397397 arranger.cpp:241] Remove peer: id:3415026730604232712, fd:8, addr:795122871, port:51233 after source invoked, current channel count:0
I20230718 01:31:03.627553 397397 arranger.cpp:246] Client connected: 172.20.144.1_12736_1689615003 with peer: id:3415026730604232712, fd:8, addr:795122871, port:51233
W20230718 01:31:04.127681 397397 arranger.cpp:327] Exited oblogreader of pid: 416486 with clientId: 172.20.144.1_12736_1689615003 of peer:id:3415026730604232712, fd:8, addr:795122871, port:51233
W20230718 01:31:04.127727 397397 arranger.cpp:342] Failed to fetch peer info of fd:8, errno:9, error:Bad file descriptor
W20230718 01:31:04.127777 397397 arranger.cpp:349] Try to shutdown fd: 8
W20230718 01:31:04.127784 397397 arranger.cpp:351] Shutdown fd: 8