0%

一个偶现问题的分析

前言

前几天遇到一个偶现问题,比较奇怪,经过几轮分析定位后终于解决。现在记录一下。

由于信息安全,本文无法提供问题相关的现象截图及代码截图。只能文字描述。

问题现象

系统运行一段时间后,进入页面报错,后台只有简单的 serialize error,除此之外,并无其他异常信息。在重启服务器后,此问题消失,但是运行一段时间(具体多长时间未知)问题又出现。

问题分析

首先,根据日志找到打印日志的地方,发现异常被吞了(因为安全问题,堆栈中可能存在敏感信息,故没有打印),导致无法定位问题。修改代码,让其能够打印堆栈,以便定位问题。

加上打印堆栈的日志后,换到环境上重启,等待一段时间,环境终于报错了。不过,这异常堆栈还是无法定位,查看代码发现初始异常还是被吞掉了(还是因为安全原因,没把异常堆栈打出来)

再次修改代码,加上打印异常堆栈的日志,换到环境上,又经过一段时间等待,环境终于又报错了,此时终于答应出了原始异常。异常显示转 json 失败:com.fasterxml.jackson.core.JsonParseException: Illegal creater ((CTRL-CHAR, code 0)): only regular white space (\r, \n, \t) is allowed between tokens\n at [Source: (String)"";line 1, column: 2]

这日志还是不够分析问题,决定额外增加入参的日志,同时断点调试。经过一段时间等待,问题复现,断点看到函数的入参为空字符串,根据调用堆栈,找到入口,请求的参数为空字符串(RequestParam 接收的 String 参数)。但是查看前台发送的请求,是有参数的。

至此,常用的定位问题的步骤已经走完了,没找到问题原因,同时陷入困境:为什么前台请求有参数,但是后台接收的是空字符串,同时打印出来的值又是一连串的 \u0000

同事提醒,可能是前阵子安全整改,在请求处理完成后,把字符串的 value 都值为 00 了。

1
2
3
4
Field valueField = String.class.getDeclaredField("value");
valueField.setAccessible(true);
char[] value = (char[]) valueField.get(strObject);
Arrays.fill(value, (char) 0x00);

虽然说字符串是在常量池里面的,改变其 value 的值会影响到其他相同的 String 对象,但是这无法解释一下问题:

  • 环境刚重启,对于同个请求(参数一样),触发多次,也不会报错,但是运行一段时间后,可能就会报错(如果是常量池的值改变的话,应该第一次不会报错,第二次开始就会报错,与现象不符)
  • 报错的请求,也不是全部报错,而是部分报错,即使同样是 get 请求,也是部分成功部分失败(如果是常量池的话,应该是全部报错,而不是部分请求报错)

但是,从日志输出、调试输出以及其他版本的环境现象来看,极有可能就是因为字符串清零的动作引起的。

去除字符串清零的代码,换到环境上,运行一段时间,观察环境并无报错。

至此,陷入困境,疑惑重重,虽然怀疑是这段代码引起,但是并没有找到问题原因,也无法解释上面两个问题。在网上搜了大量字符串常量池的文章,仍然无法解释问题。因此,决定查看 spring 源码对请求参数的解析,分析其是否在解析过程中做了特殊处理。

首先,RequestParam 参数的解析在 org.springframework.web.method.annotation.RequestParamMethodArgumentResolver 类中,找到继承类的 resolveArgument 方法,主要看 resolveName 方法,这是一个抽象方法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
@Nullable
public final Object resolveArgument(MethodParameter parameter, @Nullable ModelAndViewContainer mavContainer, NativeWebRequest webRequest, @Nullable WebDataBinderFactory binderFactory) throws Exception {
AbstractNamedValueMethodArgumentResolver.NamedValueInfo namedValueInfo = this.getNamedValueInfo(parameter);
MethodParameter nestedParameter = parameter.nestedIfOptional();
Object resolvedName = this.resolveStringValue(namedValueInfo.name);
if (resolvedName == null) {
throw new IllegalArgumentException("Specified name must not resolve to null: [" + namedValueInfo.name + "]");
} else {
// 主要是这里解析的
Object arg = this.resolveName(resolvedName.toString(), nestedParameter, webRequest);
if (arg == null) {
if (namedValueInfo.defaultValue != null) {
arg = this.resolveStringValue(namedValueInfo.defaultValue);
} else if (namedValueInfo.required && !nestedParameter.isOptional()) {
this.handleMissingValue(namedValueInfo.name, nestedParameter, webRequest);
}

arg = this.handleNullValue(namedValueInfo.name, arg, nestedParameter.getNestedParameterType());
} else if ("".equals(arg) && namedValueInfo.defaultValue != null) {
arg = this.resolveStringValue(namedValueInfo.defaultValue);
}

if (binderFactory != null) {
WebDataBinder binder = binderFactory.createBinder(webRequest, (Object)null, namedValueInfo.name);

try {
arg = binder.convertIfNecessary(arg, parameter.getParameterType(), parameter);
} catch (ConversionNotSupportedException var11) {
throw new MethodArgumentConversionNotSupportedException(arg, var11.getRequiredType(), namedValueInfo.name, parameter, var11.getCause());
} catch (TypeMismatchException var12) {
throw new MethodArgumentTypeMismatchException(arg, var12.getRequiredType(), namedValueInfo.name, parameter, var12.getCause());
}
}

this.handleResolvedValue(arg, namedValueInfo.name, parameter, mavContainer, webRequest);
return arg;
}
}

回到 RequestParamMethodArgumentResolverresolveName,参数值解析在 request.getParameterValues 这里。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
@Nullable
protected Object resolveName(String name, MethodParameter parameter, NativeWebRequest request) throws Exception {
HttpServletRequest servletRequest = (HttpServletRequest)request.getNativeRequest(HttpServletRequest.class);
Object arg;
if (servletRequest != null) {
arg = MultipartResolutionDelegate.resolveMultipartArgument(name, parameter, servletRequest);
if (arg != MultipartResolutionDelegate.UNRESOLVABLE) {
return arg;
}
}

arg = null;
MultipartRequest multipartRequest = (MultipartRequest)request.getNativeRequest(MultipartRequest.class);
if (multipartRequest != null) {
List<MultipartFile> files = multipartRequest.getFiles(name);
if (!files.isEmpty()) {
arg = files.size() == 1 ? files.get(0) : files;
}
}

if (arg == null) {
// 参数值解析在这里
String[] paramValues = request.getParameterValues(name);
if (paramValues != null) {
arg = paramValues.length == 1 ? paramValues[0] : paramValues;
}
}

return arg;
}

进入函数,到 org.springframework.web.context.request.ServletWebRequest 类中

1
2
3
4
@Nullable
public String[] getParameterValues(String paramName) {
return this.getRequest().getParameterValues(paramName);
}

继续跟踪,到 org.apache.catalina.connector.RequestFacade#getParameterValues

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
public String[] getParameterValues(String name) {
if (this.request == null) {
throw new IllegalStateException(sm.getString("requestFacade.nullRequest"));
} else {
String[] ret = null;
if (SecurityUtil.isPackageProtectionEnabled()) {
ret = (String[])AccessController.doPrivileged(new RequestFacade.GetParameterValuePrivilegedAction(name));
if (ret != null) {
ret = (String[])ret.clone();
}
} else {
// 主要看这里
ret = this.request.getParameterValues(name);
}

return ret;
}
}

查看 getParameterValues 函数,这里面的 parseParametersgetParameterValues 都调用了 handleQueryParameters 这个函数,这个函数是处理参数值的主要逻辑。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
public String[] getParameterValues(String name) {
if (!this.parametersParsed) {
// 这个函数里面调用了 handleQueryParameters,是处理参数的主要逻辑
this.parseParameters();
}

// 这个函数里面也调用了 handleQueryParameters,是处理参数的主要逻辑
return this.coyoteRequest.getParameters().getParameterValues(name);
}

public String[] getParameterValues(String name) {
// 处理参数的主要逻辑
this.handleQueryParameters();
ArrayList<String> values = (ArrayList)this.paramHashValues.get(name);
return values == null ? null : (String[])values.toArray(new String[values.size()]);
}

protected void parseParameters() {
this.parametersParsed = true;
Parameters parameters = this.coyoteRequest.getParameters();
boolean success = false;

try {
parameters.setLimit(this.getConnector().getMaxParameterCount());
String enc = this.getCharacterEncoding();
boolean useBodyEncodingForURI = this.connector.getUseBodyEncodingForURI();
if (enc != null) {
parameters.setEncoding(enc);
if (useBodyEncodingForURI) {
parameters.setQueryStringEncoding(enc);
}
} else {
parameters.setEncoding("ISO-8859-1");
if (useBodyEncodingForURI) {
parameters.setQueryStringEncoding("ISO-8859-1");
}
}

// 处理参数的主要逻辑
parameters.handleQueryParameters();
if (this.usingInputStream || this.usingReader) {
success = true;
} else if (!this.getConnector().isParseBodyMethod(this.getMethod())) {
success = true;
} else {
String contentType = this.getContentType();
if (contentType == null) {
contentType = "";
}

int semicolon = contentType.indexOf(59);
if (semicolon >= 0) {
contentType = contentType.substring(0, semicolon).trim();
} else {
contentType = contentType.trim();
}

if ("multipart/form-data".equals(contentType)) {
this.parseParts(false);
success = true;
} else if (!"application/x-www-form-urlencoded".equals(contentType)) {
success = true;
} else {
int len = this.getContentLength();
if (len <= 0) {
if ("chunked".equalsIgnoreCase(this.coyoteRequest.getHeader("transfer-encoding"))) {
Object var21 = null;

Context context;
byte[] formData;
try {
formData = this.readChunkedPostBody();
} catch (IllegalStateException var17) {
parameters.setParseFailedReason(FailReason.POST_TOO_LARGE);
context = this.getContext();
if (context != null && context.getLogger().isDebugEnabled()) {
context.getLogger().debug(sm.getString("coyoteRequest.parseParameters"), var17);
}

return;
} catch (IOException var18) {
parameters.setParseFailedReason(FailReason.CLIENT_DISCONNECT);
context = this.getContext();
if (context != null && context.getLogger().isDebugEnabled()) {
context.getLogger().debug(sm.getString("coyoteRequest.parseParameters"), var18);
}

return;
}

if (formData != null) {
parameters.processParameters(formData, 0, formData.length);
}
}
} else {
int maxPostSize = this.connector.getMaxPostSize();
Context context;
if (maxPostSize >= 0 && len > maxPostSize) {
context = this.getContext();
if (context != null && context.getLogger().isDebugEnabled()) {
context.getLogger().debug(sm.getString("coyoteRequest.postTooLarge"));
}

this.checkSwallowInput();
parameters.setParseFailedReason(FailReason.POST_TOO_LARGE);
return;
}

context = null;
byte[] formData;
if (len < 8192) {
if (this.postData == null) {
this.postData = new byte[8192];
}

formData = this.postData;
} else {
formData = new byte[len];
}

try {
if (this.readPostBody(formData, len) != len) {
parameters.setParseFailedReason(FailReason.REQUEST_BODY_INCOMPLETE);
return;
}
} catch (IOException var19) {
Context context = this.getContext();
if (context != null && context.getLogger().isDebugEnabled()) {
context.getLogger().debug(sm.getString("coyoteRequest.parseParameters"), var19);
}

parameters.setParseFailedReason(FailReason.CLIENT_DISCONNECT);
return;
}

parameters.processParameters(formData, 0, len);
}

success = true;
}
}
} finally {
if (!success) {
parameters.setParseFailedReason(FailReason.UNKNOWN);
}

}
}

接下来分析 handleQueryParameters

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
public void handleQueryParameters() {
if (!this.didQueryParameters) {
this.didQueryParameters = true;
if (this.queryMB != null && !this.queryMB.isNull()) {
if (log.isDebugEnabled()) {
log.debug("Decoding query " + this.decodedQuery + " " + this.queryStringEncoding);
}

try {
// this.queryMB 这个值之前调试的时候发现是有数据的,跟前台传的值能对应上
this.decodedQuery.duplicate(this.queryMB);
} catch (IOException var2) {
var2.printStackTrace();
}

// 重点看这个函数
this.processParameters(this.decodedQuery, this.queryStringEncoding);
}
}
}

接下来看 this.processParameters(this.decodedQuery, this.queryStringEncoding)

1
2
3
4
5
6
7
8
9
10
11
12
public void processParameters(MessageBytes data, String encoding) {
if (data != null && !data.isNull() && data.getLength() > 0) {
if (data.getType() != 2) {
// 里面 byte 数组拿的是引用关系,不是深拷贝
data.toBytes();
}

ByteChunk bc = data.getByteChunk();
// 主要看这个函数
this.processParameters(bc.getBytes(), bc.getOffset(), bc.getLength(), this.getCharset(encoding));
}
}

接下来看 private void processParameters(byte[] bytes, int start, int len, Charset charset),函数很长,主要是解析 namevalue 的值。重点看 org.apache.tomcat.util.buf.ByteChunk#toString

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
private void processParameters(byte[] bytes, int start, int len, Charset charset) {
if (log.isDebugEnabled()) {
log.debug(sm.getString("parameters.bytes", new Object[]{new String(bytes, start, len, DEFAULT_CHARSET)}));
}

int decodeFailCount = 0;
int pos = start;
int end = start + len;

label172:
while(pos < end) {
int nameStart = pos;
int nameEnd = -1;
int valueStart = -1;
int valueEnd = -1;
boolean parsingName = true;
boolean decodeName = false;
boolean decodeValue = false;
boolean parameterComplete = false;

do {
switch(bytes[pos]) {
case 37:
case 43:
if (parsingName) {
decodeName = true;
} else {
decodeValue = true;
}

++pos;
break;
case 38:
if (parsingName) {
nameEnd = pos;
} else {
valueEnd = pos;
}

parameterComplete = true;
++pos;
break;
case 61:
if (parsingName) {
nameEnd = pos;
parsingName = false;
++pos;
valueStart = pos;
} else {
++pos;
}
break;
default:
++pos;
}
} while(!parameterComplete && pos < end);

if (pos == end) {
if (nameEnd == -1) {
nameEnd = pos;
} else if (valueStart > -1 && valueEnd == -1) {
valueEnd = pos;
}
}

if (log.isDebugEnabled() && valueStart == -1) {
log.debug(sm.getString("parameters.noequal", new Object[]{nameStart, nameEnd, new String(bytes, nameStart, nameEnd - nameStart, DEFAULT_CHARSET)}));
}

String message;
String value;
if (nameEnd <= nameStart) {
if (valueStart == -1) {
if (log.isDebugEnabled()) {
log.debug(sm.getString("parameters.emptyChunk"));
}
} else {
Mode logMode = userDataLog.getNextMode();
if (logMode != null) {
if (valueEnd > nameStart) {
value = new String(bytes, nameStart, valueEnd - nameStart, DEFAULT_CHARSET);
} else {
value = "";
}

message = sm.getString("parameters.invalidChunk", new Object[]{nameStart, valueEnd, value});
switch(logMode) {
case INFO_THEN_DEBUG:
message = message + sm.getString("parameters.fallToDebug");
case INFO:
log.info(message);
break;
case DEBUG:
log.debug(message);
}
}

this.setParseFailedReason(Parameters.FailReason.NO_NAME);
}
} else {
this.tmpName.setBytes(bytes, nameStart, nameEnd - nameStart);
if (valueStart >= 0) {
this.tmpValue.setBytes(bytes, valueStart, valueEnd - valueStart);
} else {
this.tmpValue.setBytes(bytes, 0, 0);
}

if (log.isDebugEnabled()) {
try {
this.origName.append(bytes, nameStart, nameEnd - nameStart);
if (valueStart >= 0) {
this.origValue.append(bytes, valueStart, valueEnd - valueStart);
} else {
this.origValue.append(bytes, 0, 0);
}
} catch (IOException var21) {
log.error(sm.getString("parameters.copyFail"), var21);
}
}

try {
if (decodeName) {
this.urlDecode(this.tmpName);
}

this.tmpName.setCharset(charset);
String name = this.tmpName.toString();
if (valueStart >= 0) {
if (decodeValue) {
this.urlDecode(this.tmpValue);
}

this.tmpValue.setCharset(charset);
// 主要看这个 toString 方法
value = this.tmpValue.toString();
} else {
value = "";
}

try {
// 这里就存起来了,这样在调用的地方获取就能拿到具体的值
this.addParameter(name, value);
} catch (IllegalStateException var22) {
Mode logMode = maxParamCountLog.getNextMode();
if (logMode != null) {
String message = var22.getMessage();
switch(logMode) {
case INFO_THEN_DEBUG:
message = message + sm.getString("parameters.maxCountFail.fallToDebug");
case INFO:
log.info(message);
break label172;
case DEBUG:
log.debug(message);
}
}
break;
}
} catch (IOException var23) {
this.setParseFailedReason(Parameters.FailReason.URL_DECODING);
++decodeFailCount;
if (decodeFailCount == 1 || log.isDebugEnabled()) {
if (log.isDebugEnabled()) {
log.debug(sm.getString("parameters.decodeFail.debug", new Object[]{this.origName.toString(), this.origValue.toString()}), var23);
} else if (log.isInfoEnabled()) {
Mode logMode = userDataLog.getNextMode();
if (logMode != null) {
message = sm.getString("parameters.decodeFail.info", new Object[]{this.tmpName.toString(), this.tmpValue.toString()});
switch(logMode) {
case INFO_THEN_DEBUG:
message = message + sm.getString("parameters.fallToDebug");
case INFO:
log.info(message);
break;
case DEBUG:
log.debug(message);
}
}
}
}
}

this.tmpName.recycle();
this.tmpValue.recycle();
if (log.isDebugEnabled()) {
this.origName.recycle();
this.origValue.recycle();
}
}
}

if (decodeFailCount > 1 && !log.isDebugEnabled()) {
Mode logMode = userDataLog.getNextMode();
if (logMode != null) {
String message = sm.getString("parameters.multipleDecodingFail", new Object[]{decodeFailCount});
switch(logMode) {
case INFO_THEN_DEBUG:
message = message + sm.getString("parameters.fallToDebug");
case INFO:
log.info(message);
break;
case DEBUG:
log.debug(message);
}
}
}

}

进入 toString 函数,看到 StringCache.toString,这里会进行缓存,那大概率就是这里的问题了。

1
2
3
4
5
6
7
public String toString() {
if (null == this.buff) {
return null;
} else {
return this.end - this.start == 0 ? "" : StringCache.toString(this);
}
}

接着分析 org.apache.tomcat.util.buf.StringCache#toString(org.apache.tomcat.util.buf.ByteChunk) 函数,函数比较长,主要是两个功能:如果有缓存则从缓存中拿数据,如果没有缓存则 new String 返回,同时将数据放入 map 中,等到积累到一定数量后,将这些数据构建缓存。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
public static String toString(ByteChunk bc) {
String value;
// 判断是否已经构建了缓存,如果已经构建缓存,则尝试从缓存中拿数据
if (bcCache != null) {
++accessCount;
// 查看是否在缓存中
value = find(bc);
// 如果不在缓存,则直接 new String 返回
if (value == null) {
return bc.toStringInternal();
} else {
// 如果在缓存中,则直接将缓存中的值返回
++hitCount;
return value;
}
} else {
// 缓存还没构建
value = bc.toStringInternal();
// 长度小于 maxStringSize 才会考虑将其放在缓存中,否则也是直接 new String 返回
// maxStringSize 的默认值是 128,可通过 tomcat.util.buf.StringCache.maxStringSize 进行配置
// protected static final int maxStringSize = Integer.parseInt(System.getProperty("tomcat.util.buf.StringCache.maxStringSize", "128"));
if (byteEnabled && value.length() < maxStringSize) {
synchronized(bcStats) {
if (bcCache != null) {
return value;
}

int size;
// 不会立即构建缓存,先将其放在 bcStats 中,等到达 trainThreshold 后,从中取出数据构建 bcCache 缓存
// trainThreshold 的默认值是 20000,可通过 tomcat.util.buf.StringCache.trainThreshold 进行配置
// protected static int trainThreshold = Integer.parseInt(System.getProperty("tomcat.util.buf.StringCache.trainThreshold", "20000"));
if (bcCount <= trainThreshold) {
++bcCount;
StringCache.ByteEntry entry = new StringCache.ByteEntry();
entry.value = value;
int[] count = (int[])bcStats.get(entry);
if (count == null) {
int end = bc.getEnd();
size = bc.getStart();
entry.name = new byte[bc.getLength()];
System.arraycopy(bc.getBuffer(), size, entry.name, 0, end - size);
entry.charset = bc.getCharset();
count = new int[]{1};
bcStats.put(entry, count);
} else {
int var10002 = count[0]++;
}
} else {
// 这部分就是构建缓存的部分
long t1 = System.currentTimeMillis();
TreeMap<Integer, ArrayList<StringCache.ByteEntry>> tempMap = new TreeMap();

StringCache.ByteEntry entry;
ArrayList list;
for(Iterator i$ = bcStats.entrySet().iterator(); i$.hasNext(); list.add(entry)) {
Entry<StringCache.ByteEntry, int[]> item = (Entry)i$.next();
entry = (StringCache.ByteEntry)item.getKey();
int[] countA = (int[])item.getValue();
Integer count = countA[0];
list = (ArrayList)tempMap.get(count);
if (list == null) {
list = new ArrayList();
tempMap.put(count, list);
}
}

size = bcStats.size();
if (size > cacheSize) {
size = cacheSize;
}

StringCache.ByteEntry[] tempbcCache = new StringCache.ByteEntry[size];
ByteChunk tempChunk = new ByteChunk();
int n = 0;

while(true) {
// 这里缓存就构建完成了,缓存中只有 bcStats 里面的数据
// 换句话说,也就是只有排在前面请求的数据,后面请求中的数据并不会被缓存,仍然是 new String 的方式返回
if (n >= size) {
bcCount = 0;
bcStats.clear();
bcCache = tempbcCache;
if (log.isDebugEnabled()) {
long t2 = System.currentTimeMillis();
log.debug("ByteCache generation time: " + (t2 - t1) + "ms");
}
break;
}

Object key = tempMap.lastKey();
list = (ArrayList)tempMap.get(key);

for(int i = 0; i < list.size() && n < size; ++i) {
StringCache.ByteEntry entry = (StringCache.ByteEntry)list.get(i);
tempChunk.setBytes(entry.name, 0, entry.name.length);
int insertPos = findClosest(tempChunk, tempbcCache, n);
if (insertPos == n) {
tempbcCache[n + 1] = entry;
} else {
System.arraycopy(tempbcCache, insertPos + 1, tempbcCache, insertPos + 2, n - insertPos - 1);
tempbcCache[insertPos + 1] = entry;
}

++n;
}

tempMap.remove(key);
}
}
}
}

return value;
}
}




// 查找缓存是否存在的函数,主要看 compare 函数
protected static final String find(ByteChunk name) {
int pos = findClosest(name, bcCache, bcCache.length);
return pos >= 0 && compare(name, bcCache[pos].name) == 0 && name.getCharset().equals(bcCache[pos].charset) ? bcCache[pos].value : null;
}

protected static final int findClosest(ByteChunk name, StringCache.ByteEntry[] array, int len) {
int a = 0;
int b = len - 1;
if (b == -1) {
return -1;
} else if (compare(name, array[0].name) < 0) {
return -1;
} else if (b == 0) {
return 0;
} else {
boolean var5 = false;

do {
int i = b + a >>> 1;
int result = compare(name, array[i].name);
if (result == 1) {
a = i;
} else {
if (result == 0) {
return i;
}

b = i;
}
} while(b - a != 1);

int result2 = compare(name, array[b].name);
if (result2 < 0) {
return a;
} else {
return b;
}
}
}

// 主要是判断 byte 数组中的数据是否相同
protected static final int compare(CharChunk name, char[] compareTo) {
int result = 0;
char[] c = name.getBuffer();
int start = name.getStart();
int end = name.getEnd();
int len = compareTo.length;
if (end - start < len) {
len = end - start;
}

for(int i = 0; i < len && result == 0; ++i) {
if (c[i + start] > compareTo[i]) {
result = 1;
} else if (c[i + start] < compareTo[i]) {
result = -1;
}
}

if (result == 0) {
if (compareTo.length > end - start) {
result = -1;
} else if (compareTo.length < end - start) {
result = 1;
}
}

return result;
}


public String toStringInternal() {
if (this.charset == null) {
this.charset = DEFAULT_CHARSET;
}

CharBuffer cb = this.charset.decode(ByteBuffer.wrap(this.buff, this.start, this.end - this.start));
return new String(cb.array(), cb.arrayOffset(), cb.length());
}

至此,可以解释上述的奇怪现象了:

  • 环境刚重启,对于同个请求(参数一样),触发多次,也不会出现错误,但是运行一段时间后,可能就会报错

    原因:环境运行前期,请求数量少,还没达到构建缓存的阈值,请求参数的值都是通过 new String 返回的,因此能够获取到正常的值,功能运行正常。环境运行一段时间后,请求数量变多,达到构建缓存的阈值,触发缓存构建,部分参数值放在缓存中,后续触发请求时,是从缓存中获取的 String 对象,由于请求处理完毕后,业务代码会对 String 对象执行清零动作,所以后续的请求中从缓存获取到的对象是被清零后的 String 对象,从容导致无法解析报错。

  • 报错的请求,也不是全部报错,而是部分报错,即使同样是 get 请求,也是部分成功部分失败

    原因:并不是所有的请求参数值都会放到缓存中,只有长度小于某个值、参数值靠前的才会被放在缓存中,其他的不会从缓存中获取,都是直接 new String 的,因此对于不在缓存中的参数,其请求是正常的。

问题修改

基于上述分析,此问题主要是因为 tomcat 对请求参数 String 进行缓存,同时业务代码中又对 String 进行清零动作导致的,因此只需要破坏其中一个条件即可解决问题。

基于安全及性能的考虑,建议修改方案:

  • 前台:对于某些需要后台配合执行清零动作的接口,请求中增加时间戳参数(目的:保证 String 对象转 byte 数组是唯一的,这样就不会被缓存)
  • 后台:基于请求参数,判断是否含有特定字段(前台加的时间戳参数,也标识着这是一个需要清零的接口),如果有则执行清零动作,否则不执行(目的:特殊数据不留内存,同时避免大范围新建对象对性能造成影响)