Skip to content

Commit

Permalink
[ISSUE #11325]Fix logging for Config pull events.
Browse files Browse the repository at this point in the history
  • Loading branch information
@stone-98
stone-98 committed Nov 3, 2023
1 parent e7e3824 commit b68cd2e
Show file tree
Hide file tree
Showing 3 changed files with 25 additions and 49 deletions.
44 changes: 15 additions & 29 deletions config/src/main/java/com/alibaba/nacos/config/server/controller/ConfigServletInner.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand All @@ -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 {
Expand All @@ -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 {
Expand Down Expand Up @@ -248,7 +243,6 @@ public String doGetConfig(HttpServletRequest request, HttpServletResponse respon

return get404Result(response, isV2);
}
isSli = true;
}
} else {
md5 = cacheItem.getTagMd5(tag, acceptCharset);
Expand All @@ -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",
Expand All @@ -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<String, String> pair = EncryptionHandler.decryptHandler(dataId,
configInfoBase.getEncryptedDataKey(), configInfoBase.getContent());
Expand All @@ -306,28 +300,20 @@ 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);
}
} else if (lockResult == 0) {

// 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);

Expand Down
22 changes: 5 additions & 17 deletions config/src/main/java/com/alibaba/nacos/config/server/remote/ConfigQueryRequestHandler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand All @@ -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();
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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);
}
Expand Down
8 changes: 5 additions & 3 deletions config/src/main/java/com/alibaba/nacos/config/server/service/trace/ConfigTraceService.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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) {
Expand All @@ -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);
}
Expand Down

0 comments on commit b68cd2e

Please sign in to comment.