add log, add time check when refresh rsList

Author: JackShi148

src/main/java/com/alipay/oceanbase/rpc/ObTableClient.java

@@ -95,7 +95,7 @@ public class ObTableClient extends AbstractObTableClient implements Lifecycle {
                                                                                                           Constants.PROXY_SYS_USER_NAME,
                                                                                                           "");
 
-    private TableRoute                                        tableRoute                              = null;
+    private volatile TableRoute                                        tableRoute                              = null;
 
     private volatile RunningMode                              runningMode                             = RunningMode.NORMAL;
 
@@ -880,6 +880,13 @@ public void syncRefreshMetadata(boolean forceRenew) throws Exception {// do not
         }
         try {
             // double check timestamp
+            if (System.currentTimeMillis() - lastRefreshMetadataTimestamp < 5000L) {
+                logger
+                        .warn(
+                                "have to wait for more than 5 seconds to refresh metadata, it has refreshed at: {}",
+                                lastRefreshMetadataTimestamp);
+                return;
+            }
             if (!forceRenew
                     && System.currentTimeMillis() - lastRefreshMetadataTimestamp < metadataRefreshInterval) {
                 logger

src/main/java/com/alipay/oceanbase/rpc/bolt/transport/ObTableConnection.java

@@ -230,6 +230,7 @@ public void checkStatus() throws Exception {
             reconnect("Check connection is null");
         }
         if (connection.getChannel() == null || !connection.getChannel().isActive()) {
+            LOGGER.warn("[latency monitor] need to reconnect server: {}:{}", obTable.getIp(), obTable.getPort());
             reconnect("Check connection failed for address: " + connection.getUrl());
         }
         if (!connection.getChannel().isWritable()) {

src/main/java/com/alipay/oceanbase/rpc/bolt/transport/ObTableRemoting.java

@@ -84,7 +84,7 @@ public ObPayload invokeSync(final ObTableConnection conn, final ObPayload reques
             return null;
         } else if (!response.isSuccess()) {
             String errMessage = TraceUtil.formatTraceMessage(conn, request,
-                "get an error response: " + response.getMessage());
+                "get an error response: " + response.getMessage() + ", transportCode: " + response.getTransportCode());
             logger.warn(errMessage);
             response.releaseByteBuf();
             ExceptionUtil.throwObTableTransportException(errMessage, response.getTransportCode());

src/main/java/com/alipay/oceanbase/rpc/location/model/RouteTableRefresher.java

@@ -44,6 +44,7 @@ public RouteTableRefresher(ObTableClient tableClient) {
      * */
     private void doRsListCheck() {
         try {
+            logger.info("[latency monitor] background refresher start");
             TableRoute tableRoute = tableClient.getTableRoute();
             ConfigServerInfo configServer = tableRoute.getConfigServerInfo();
             List<ObServerAddr> oldRsList = configServer.getRsList();
@@ -52,6 +53,7 @@ private void doRsListCheck() {
                 tableClient.getRsListAcquireConnectTimeout(),
                 tableClient.getRsListAcquireReadTimeout(), tableClient.getRsListAcquireTryTimes(),
                 tableClient.getRsListAcquireRetryInterval());
+            logger.info("[latency monitor] finish loadRsListForConfigServerInfo");
             List<ObServerAddr> newRsList = newConfigServer.getRsList();
             boolean needRefresh = false;
             if (oldRsList.size() != newRsList.size()) {
@@ -71,6 +73,7 @@ private void doRsListCheck() {
                     }
                 }
             }
+            logger.info("[latency monitor] finish needRefresh checking, needRefresh: {}", needRefresh);
             if (needRefresh) {
                 newConfigServer = LocationUtil.refreshIDC2RegionMapFroConfigServerInfo(
                     newConfigServer, tableClient.getParamURL(),
@@ -81,6 +84,7 @@ private void doRsListCheck() {
                 tableRoute.setConfigServerInfo(newConfigServer);
                 tableRoute.refreshRosterByRsList(newRsList);
             }
+            logger.info("[latency monitor] finish doRsListCheck");
         } catch (Exception e) {
             logger.warn("RouteTableRefresher::doRsListCheck fail", e);
         }

src/main/java/com/alipay/oceanbase/rpc/location/model/TableRoute.java

@@ -64,7 +64,7 @@ public class TableRoute {
     private OdpInfo                   odpInfo                = null;
     private RouteTableRefresher       routeRefresher         = null;
 
-    public Lock                       refreshTableRosterLock = new ReentrantLock();
+    public final Lock                 refreshTableRosterLock = new ReentrantLock();
 
     public TableRoute(ObTableClient tableClient, ObUserAuth sysUA) {
         this.tableClient = tableClient;
@@ -656,6 +656,7 @@ public ObTableParam getTableParam(String tableName, Row rowkey) throws Exception
 
     public ObTableParam getTableParamWithRoute(String tableName, Row rowkey, ObServerRoute route)
                                                                                                  throws Exception {
+        logger.info("[latency monitor] start to execute getTableParamWithRoute");
         TableEntry tableEntry = getTableEntry(tableName);
         if (tableEntry == null) {
             logger.error("tableEntry is null, tableName: {}", tableName);
@@ -807,13 +808,14 @@ private ObTableParam getTableInternal(String tableName, TableEntry tableEntry, l
             tableClient.syncRefreshMetadata(true);
             // the addr is wrong, need to refresh location
             if (logger.isInfoEnabled()) {
-                logger.info("Cannot get ObTable by addr {}, refreshing metadata.", addr);
+                logger.info("Cannot get ObTable by addr {}, refreshing metadata, tryTimes: {}.", addr, retryTimes);
             }
             // refresh tablet location based on the latest roster, in case that some of the observers have been killed
             // and used the old location
             tableEntry = refreshPartitionLocation(tableName, tabletId, tableEntry);
             obPartitionLocationInfo = getOrRefreshPartitionInfo(tableEntry, tableName, tabletId);
             replica = getPartitionLocation(obPartitionLocationInfo, route);
+            logger.warn("[latency monitor] new replica location, {}:{}", replica.getAddr().getIp(), replica.getAddr().getSvrPort());
 
             if (replica == null) {
                 RUNTIME.error("Cannot get replica by tabletId: " + tabletId);

src/main/java/com/alipay/oceanbase/rpc/table/ObTableClientLSBatchOpsImpl.java

@@ -480,6 +480,7 @@ private LsOperationsMap prepareByFirstOperation(LsOperationsMap lsOperationsMap,
 
     private LsOperationsMap prepareByEachOperation(LsOperationsMap lsOperationsMap,
                          BatchIdxOperationPairList operationsWithIndex) throws Exception {
+        logger.info("[latency monitor] start to execute prepareByEachOperation");
         for (int i = 0; i < operationsWithIndex.size(); i++) {
             ObPair<Integer, ObTableSingleOp> operation = operationsWithIndex.get(i);
             Row rowKey = calculateRowKey(operation);
@@ -534,6 +535,7 @@ public LsOperationsMap partitionPrepare()
     public void partitionExecute(ObTableSingleOpResult[] results,
                                  Map.Entry<Long, TabletOperationsMap> lsOperation)
             throws Exception {
+        logger.info("[latency monitor] start to execute partitionExecute");
         long lsId = lsOperation.getKey();
         TabletOperationsMap tabletOperationsMap = lsOperation.getValue();
         if (tabletOperationsMap.isEmpty()) {
@@ -729,6 +731,7 @@ public void partitionExecute(ObTableSingleOpResult[] results,
                     } else {
                         if (ex instanceof ObTableTransportException &&
                                 ((ObTableTransportException) ex).getErrorCode() == TransportCodes.BOLT_TIMEOUT) {
+                            logger.warn("[latency monitor] meet BOLT_TIMEOUT, need to syncRefreshMetadata, tryTimes: {}", tryTimes);
                             obTableClient.syncRefreshMetadata(true);
                         }
                         obTableClient.calculateContinuousFailure(realTableName, ex.getMessage());