Poison

String Concatenation

今天看了个因字符串拼接导致的 CPU 高的问题,首先是监控 Agent 持续对一个实例进行告警,并抓取到了 CPU 高的相关 Java 线程:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
lwpId: 17, CPU usage: 52.9
"G1 Concurrent Refinement Thread#0" os_prio=0 tid=0x00007fa73002e000 nid=0x11 runnable

lwpId: 198, CPU usage: 47.1
"http-nio-80-exec-42" #188 daemon prio=5 os_prio=0 tid=0x00007fa71409e800 nid=0xc6 runnable [0x00007fa6c942b000]
java.lang.Thread.State: RUNNABLE
at java.util.Arrays.copyOf(Arrays.java:3332)
at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124)
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:448)
at java.lang.StringBuilder.append(StringBuilder.java:136)
at me.tianshuang.tool.StringUtil.listToString(StringUtil.java:433)
at sun.reflect.GeneratedMethodAccessor1008.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)

乍一看好像没有问题,即正常的字符串拼接而已,且使用了 StringBuilder,但是监控持续告警,每次采集的高 CPU 线程都指向了同一段业务代码。于是我摘掉了此实例的流量并抓取了一个堆转储,看到需要拼接为一个字符串的 List<String> 中共有 210 万个字符串,是因为数量太多导致需要执行很久吗?于是我查看了 StringUtil.listToString 中的源码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
package me.tianshuang.tool;

import java.util.List;

public class StringUtil {

public static String listToString(List list, String separator) {
if (list == null || list.size() == 0) {
return null;
}
String result = list.get(0) + "";
for (int i = 1; i < list.size(); i++) {
result = result + separator + list.get(i);
}
return result;
}

}

其中的 + 引起了我的注意,但是印象中 + 会被编译器优化为 StringBuilderappend 实现,从 Agent 抓取到的栈帧来看也确实进行了优化,我们可以通过查看反汇编的代码来验证,首先我们执行 javac me/tianshuang/tool/StringUtil.java 对以上代码进行编译,然后执行 javap -c -l me.tianshuang.tool.StringUtil 打印出反汇编的代码,即组成 Java 字节码的指令:

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
Compiled from "StringUtil.java"
public class me.tianshuang.tool.StringUtil {
public me.tianshuang.tool.StringUtil();
Code:
0: aload_0
1: invokespecial #1 // Method java/lang/Object."<init>":()V
4: return
LineNumberTable:
line 5: 0

public static java.lang.String listToString(java.util.List, java.lang.String);
Code:
0: aload_0
1: ifnull 13
4: aload_0
5: invokeinterface #2, 1 // InterfaceMethod java/util/List.size:()I
10: ifne 15
13: aconst_null
14: areturn
15: new #3 // class java/lang/StringBuilder
18: dup
19: invokespecial #4 // Method java/lang/StringBuilder."<init>":()V
22: aload_0
23: iconst_0
24: invokeinterface #5, 2 // InterfaceMethod java/util/List.get:(I)Ljava/lang/Object;
29: invokevirtual #6 // Method java/lang/StringBuilder.append:(Ljava/lang/Object;)Ljava/lang/StringBuilder;
32: ldc #7 // String
34: invokevirtual #8 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
37: invokevirtual #9 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
40: astore_2
41: iconst_1
42: istore_3
43: iload_3
44: aload_0
45: invokeinterface #2, 1 // InterfaceMethod java/util/List.size:()I
50: if_icmpge 88
53: new #3 // class java/lang/StringBuilder
56: dup
57: invokespecial #4 // Method java/lang/StringBuilder."<init>":()V
60: aload_2
61: invokevirtual #8 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
64: aload_1
65: invokevirtual #8 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
68: aload_0
69: iload_3
70: invokeinterface #5, 2 // InterfaceMethod java/util/List.get:(I)Ljava/lang/Object;
75: invokevirtual #6 // Method java/lang/StringBuilder.append:(Ljava/lang/Object;)Ljava/lang/StringBuilder;
78: invokevirtual #9 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
81: astore_2
82: iinc 3, 1
85: goto 43
88: aload_2
89: areturn
LineNumberTable:
line 8: 0
line 9: 13
line 11: 15
line 12: 41
line 13: 53
line 12: 82
line 15: 88
}

可以看出,确实是被优化为了 StringBuilder 实现。但是仔细观察以上代码不难发现共有两处创建了 StringBuilder 实例,其中一处位于 for 循环外侧,另一处位于 for 循环内侧,即 for 循环内外并未共用一个 StringBuilder 实例,而是 for 循环外侧创建了一个 StringBuilder 实例用于拼接 list.get(0)"",拼接完成后调用了 StringBuilder 实例的 toString 方法并赋值给变量 result,for 循环内侧每次执行时创建了一个 StringBuilder 实例用于拼接 resultseparatorlist.get(i),且拼接完成后调用了 StringBuilder 实例的 toString 方法并赋值给变量 result。不难发现,此实现需创建 StringBuilder 实例的个数与 for 循环需执行的次数成正比,且 for 循环内侧当循环次数越大时首次 append 的字符串长度也越大,导致需要拷贝的字符也越多。从内存层面上看,因为创建了大量的 StringBuilder 实例,会增大 GC 的压力,但是不存在内存泄漏的问题。

我们可以编写的简单的测试代码来进行验证,通过生成 10 万个 UUID 字符串并使用以上代码进行拼接:

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
package me.tianshuang.tool;

import java.util.ArrayList;
import java.util.List;
import java.util.UUID;
import java.util.concurrent.TimeUnit;

public class StringUtil {

public static String listToString(List list, String separator) {
if (list == null || list.size() == 0) {
return null;
}
String result = list.get(0) + "";
for (int i = 1; i < list.size(); i++) {
result = result + separator + list.get(i);
}
return result;
}

public static void main(String[] args) {
int size = 100_000;
List<String> uuidList = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
uuidList.add(UUID.randomUUID().toString());
}

long startNanos = System.nanoTime();
listToString(uuidList, ",");
System.out.println(TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos) + "ms");
}

}

以上代码,在本地测试时耗时 135390ms,我们将以上代码调整为通过我们分析反汇编的代码实现并再次测试:

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
package me.tianshuang.tool;

import java.util.ArrayList;
import java.util.List;
import java.util.UUID;
import java.util.concurrent.TimeUnit;

public class StringUtil {

public static String listToString(List list, String separator) {
if (list == null || list.size() == 0) {
return null;
}
String result = new StringBuilder().append(list.get(0)).append("").toString();
for (int i = 1; i < list.size(); i++) {
result = new StringBuilder().append(result).append(separator).append(list.get(i)).toString();
}
return result;
}

public static void main(String[] args) {
int size = 100_000;
List<String> uuidList = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
uuidList.add(UUID.randomUUID().toString());
}

long startNanos = System.nanoTime();
listToString(uuidList, ",");
System.out.println(TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos) + "ms");
}

}

以上代码耗时 142860ms,可以看出耗时没有明显差异。我们再将 listToString 实现优化为基于一个 StringBuilder 实例的实现并再次进行测试:

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
package me.tianshuang.tool;

import java.util.ArrayList;
import java.util.List;
import java.util.UUID;
import java.util.concurrent.TimeUnit;

public class StringUtil {

public static String listToString(List list, String separator) {
if (list == null || list.size() == 0) {
return null;
}

StringBuilder sb = new StringBuilder();
sb.append(list.get(0));
for (int i = 1; i < list.size(); i++) {
sb.append(separator).append(list.get(i));
}
return sb.toString();
}

public static void main(String[] args) {
int size = 100_000;
List<String> uuidList = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
uuidList.add(UUID.randomUUID().toString());
}

long startNanos = System.nanoTime();
listToString(uuidList, ",");
System.out.println(TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos) + "ms");
}

}

时间降低至 32ms。当然,还可以通过空间预分配等措施继续优化,亦可参考 Apache Commons 中 StringUtils 中的拼接实现。

Reference

Using += for strings in a loop, is it bad practice? - Stack Overflow
Java Compiler Optimization for String Concatenation | by Vaibhav Singh | Javarevisited | Medium
JEP 280: Indify String Concatenation