From b68cd2e14cb4a4a8ff4d75b05e66158693f11371 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E9=98=BF=E9=AD=81?= <670569467@qq.com> Date: Fri, 3 Nov 2023 15:20:33 +0800 Subject: [PATCH] [ISSUE #11325]Fix logging for Config pull events. --- .../server/controller/ConfigServletInner.java | 44 +++++++------------ .../remote/ConfigQueryRequestHandler.java | 22 +++------- .../service/trace/ConfigTraceService.java | 8 ++-- 3 files changed, 25 insertions(+), 49 deletions(-) diff --git a/config/src/main/java/com/alibaba/nacos/config/server/controller/ConfigServletInner.java b/config/src/main/java/com/alibaba/nacos/config/server/controller/ConfigServletInner.java index bd01bbea6f3..d307cde6318 100755 --- a/config/src/main/java/com/alibaba/nacos/config/server/controller/ConfigServletInner.java +++ b/config/src/main/java/com/alibaba/nacos/config/server/controller/ConfigServletInner.java @@ -148,10 +148,7 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon String tenant, String tag, String isNotify, String clientIp, boolean isV2) throws IOException, ServletException { - boolean notify = false; - if (StringUtils.isNotBlank(isNotify)) { - notify = Boolean.parseBoolean(isNotify); - } + boolean notify = StringUtils.isNotBlank(isNotify) && Boolean.parseBoolean(isNotify); String acceptCharset = ENCODE_UTF8; @@ -167,7 +164,6 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon final String requestIp = RequestUtil.getRemoteIp(request); boolean isBeta = false; - boolean isSli = false; if (lockResult > 0) { // LockResult > 0 means cacheItem is not null and other thread can`t delete this cacheItem try { @@ -178,28 +174,27 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon && cacheItem.getIps4Beta().contains(clientIp)) { isBeta = true; } - + final String configType = (null != cacheItem.getType()) ? cacheItem.getType() : FileTypeEnum.TEXT.getFileType(); - response.setHeader("Config-Type", configType); + response.setHeader(com.alibaba.nacos.api.common.Constants.CONFIG_TYPE, configType); FileTypeEnum fileTypeEnum = FileTypeEnum.getFileTypeEnumByFileExtensionOrFileType(configType); String contentTypeHeader = fileTypeEnum.getContentType(); response.setHeader(HttpHeaderConsts.CONTENT_TYPE, contentTypeHeader); - + if (isV2) { response.setHeader(HttpHeaderConsts.CONTENT_TYPE, MediaType.APPLICATION_JSON); } - - String pullEvent = ConfigTraceService.PULL_EVENT; + + String pullEvent; String content = null; ConfigInfoBase configInfoBase = null; - PrintWriter out; if (isBeta) { ConfigCache configCacheBeta = cacheItem.getConfigCacheBeta(); pullEvent = ConfigTraceService.PULL_EVENT_BETA; md5 = configCacheBeta.getMd5(acceptCharset); lastModified = configCacheBeta.getLastModifiedTs(); - + if (PropertyUtil.isDirectRead()) { configInfoBase = configInfoBetaPersistService.findConfigInfo4Beta(dataId, group, tenant); } else { @@ -248,7 +243,6 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon return get404Result(response, isV2); } - isSli = true; } } else { md5 = cacheItem.getTagMd5(tag, acceptCharset); @@ -264,7 +258,7 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon // FIXME CacheItem // No longer exists. It is impossible to simply calculate the push delayed. Here, simply record it as - 1. ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, -1, pullEvent, - ConfigTraceService.PULL_TYPE_NOTFOUND, -1, requestIp, notify && isSli, "http"); + ConfigTraceService.PULL_TYPE_NOTFOUND, -1, requestIp, notify, "http"); // pullLog.info("[client-get] clientIp={}, {}, // no data", @@ -283,7 +277,7 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon response.setHeader("Cache-Control", "no-cache,no-store"); response.setDateHeader("Last-Modified", lastModified); putEncryptedDataKeyHeader(response, tag, clientIp, acceptCharset, cacheItem, isBeta, autoTag); - + PrintWriter out; if (PropertyUtil.isDirectRead()) { Pair pair = EncryptionHandler.decryptHandler(dataId, configInfoBase.getEncryptedDataKey(), configInfoBase.getContent()); @@ -306,20 +300,12 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon } out.flush(); out.close(); - + LogUtil.PULL_CHECK_LOG.warn("{}|{}|{}|{}", groupKey, requestIp, md5, TimeUtils.getCurrentTimeStr()); - - final long delayed = System.currentTimeMillis() - lastModified; - - if (notify) { - - ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, - ConfigTraceService.PULL_TYPE_OK, delayed, requestIp, true, "http"); - } else { - ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, - ConfigTraceService.PULL_TYPE_OK, -1, requestIp, false, "http"); - } - + + final long delayed = notify ? -1 : System.currentTimeMillis() - lastModified; + ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, + ConfigTraceService.PULL_TYPE_OK, delayed, clientIp, notify, "http"); } finally { releaseConfigReadLock(groupKey); } @@ -327,7 +313,7 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon // FIXME CacheItem No longer exists. It is impossible to simply calculate the push delayed. Here, simply record it as - 1. ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, -1, ConfigTraceService.PULL_EVENT, - ConfigTraceService.PULL_TYPE_NOTFOUND, -1, requestIp, notify && isSli, "http"); + ConfigTraceService.PULL_TYPE_NOTFOUND, -1, requestIp, notify, "http"); return get404Result(response, isV2); diff --git a/config/src/main/java/com/alibaba/nacos/config/server/remote/ConfigQueryRequestHandler.java b/config/src/main/java/com/alibaba/nacos/config/server/remote/ConfigQueryRequestHandler.java index c556874d426..28c5fdc40d6 100644 --- a/config/src/main/java/com/alibaba/nacos/config/server/remote/ConfigQueryRequestHandler.java +++ b/config/src/main/java/com/alibaba/nacos/config/server/remote/ConfigQueryRequestHandler.java @@ -43,7 +43,6 @@ import com.alibaba.nacos.plugin.auth.constant.SignType; import org.springframework.stereotype.Component; -import java.io.PrintWriter; import java.net.URLEncoder; import static com.alibaba.nacos.config.server.constant.Constants.ENCODE_UTF8; @@ -109,7 +108,6 @@ private ConfigQueryResponse getContext(ConfigQueryRequest configQueryRequest, Re int lockResult = tryConfigReadLock(groupKey); String pullEvent = ConfigTraceService.PULL_EVENT; boolean isBeta = false; - boolean isSli = false; if (lockResult > 0) { try { String md5 = Constants.NULL; @@ -125,7 +123,6 @@ private ConfigQueryResponse getContext(ConfigQueryRequest configQueryRequest, Re } String content = null; ConfigInfoBase configInfoBase = null; - PrintWriter out = null; if (isBeta) { md5 = cacheItem.getConfigCacheBeta().getMd5(acceptCharset); lastModified = cacheItem.getConfigCacheBeta().getLastModifiedTs(); @@ -176,8 +173,6 @@ private ConfigQueryResponse getContext(ConfigQueryRequest configQueryRequest, Re response.setErrorInfo(ConfigQueryResponse.CONFIG_NOT_FOUND, "config data not exist"); return response; } - isSli = true; - } } else { if (cacheItem != null) { @@ -227,19 +222,12 @@ private ConfigQueryResponse getContext(ConfigQueryRequest configQueryRequest, Re return response; } } - + LogUtil.PULL_CHECK_LOG.warn("{}|{}|{}|{}", groupKey, clientIp, md5, TimeUtils.getCurrentTimeStr()); - - final long delayed = System.currentTimeMillis() - lastModified; - - if (notify) { - - ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, - ConfigTraceService.PULL_TYPE_OK, delayed, clientIp, notify, "grpc"); - } else { - ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, - ConfigTraceService.PULL_TYPE_OK, System.currentTimeMillis(), clientIp, notify, "grpc"); - } + + final long delayed = notify ? -1 : System.currentTimeMillis() - lastModified; + ConfigTraceService.logPullEvent(dataId, group, tenant, requestIpApp, lastModified, pullEvent, + ConfigTraceService.PULL_TYPE_OK, delayed, clientIp, notify, "grpc"); } finally { releaseConfigReadLock(groupKey); } diff --git a/config/src/main/java/com/alibaba/nacos/config/server/service/trace/ConfigTraceService.java b/config/src/main/java/com/alibaba/nacos/config/server/service/trace/ConfigTraceService.java index 940345779a0..93d5048b2ba 100644 --- a/config/src/main/java/com/alibaba/nacos/config/server/service/trace/ConfigTraceService.java +++ b/config/src/main/java/com/alibaba/nacos/config/server/service/trace/ConfigTraceService.java @@ -17,11 +17,11 @@ package com.alibaba.nacos.config.server.service.trace; import com.alibaba.nacos.common.utils.MD5Utils; +import com.alibaba.nacos.common.utils.StringUtils; import com.alibaba.nacos.config.server.constant.Constants; import com.alibaba.nacos.config.server.monitor.MetricsMonitor; import com.alibaba.nacos.config.server.utils.LogUtil; import com.alibaba.nacos.sys.utils.InetUtils; -import com.alibaba.nacos.common.utils.StringUtils; import org.springframework.stereotype.Service; import java.util.concurrent.TimeUnit; @@ -272,6 +272,8 @@ public static void logDumpAllEvent(String dataId, String group, String tenant, S * @param type type * @param delayed delayed * @param clientIp clientIp + * @param isNotify isNotify + * @param model model */ public static void logPullEvent(String dataId, String group, String tenant, String requestIpAppName, long ts, String event, String type, long delayed, String clientIp, boolean isNotify, String model) { @@ -286,8 +288,8 @@ public static void logPullEvent(String dataId, String group, String tenant, Stri if (isNotify && delayed < 0) { delayed = 0; } - - //localIp | dataid | group | tenant| requestIpAppName| ts | event | type | [delayed] |clientIp| mode,http/grpc + + // localIp | dataid | group | tenant| requestIpAppName| ts | event | type | [delayed] |clientIp| isNotify | mode（http/grpc) LogUtil.TRACE_LOG.info("{}|{}|{}|{}|{}|{}|{}|{}|{}|{}|{}|{}", InetUtils.getSelfIP(), dataId, group, tenant, requestIpAppName, ts, event, type, delayed, clientIp, isNotify, model); }