kaspterio code as a hacker

10 November 2016

问题发现

在维护的一个proxy服务的监控里发现一个现象: YoungGC的时间随着时间的推移稳定增长,直到触发一次fullgc,一直不知道是什么原因。

直到最近对这个服务用 JProfiler 做了一下 profile,结果发现了一个有趣的地方: jprofiler

整个服务的24.3%的时间都花在了CafeServiceImpl里,20.6%的时间都花在了 Jackson 的反序列化上。展开调用栈发现 Jackson 主要是在调用 String.intern()。

详细分析

关于 String.intern(),在美团技术博客上有一篇详细的文章:深入解析String#intern。其中这一段引起了我的注意:

要注意的是,String的String Pool是一个固定大小的Hashtable,默认值大小长度是1009,如果放进String Pool的String非常多,就会造成Hash冲突严重,从而导致链表会很长,而链表长了后直接会造成的影响就是当调用String.intern时性能会大幅下降(因为要一个一个找)。

会不会是因为缓存的 String 太多了导致性能下降耗时大幅增加呢?如果这样的话,禁止 Jackson使用 String.intern 应该就可以解决这个问题。

Google 了一下 Jackson disable intern 发现了这篇文档

  • CANONICALIZE_FIELD_NAMES (default: true)

    • Means that once name String is decoded from input (byte or char stream), it will be added in a symbol table, to reduce overhead of decoding same name next time it is seen (by any parser constructed by same factory)
  • INTERN_FIELD_NAMES (default: true)

    • If canonicalization is enabled, this feature determines whether String decoded is also interned (using String.intern()) or not – doing that can help further improve deserialization performance since identity comparison may be used.
    • If names are unlikely to repeat, or if sheer number of distinct names is huge (in tens of thousands or above), it may make sense to disable this feature.

也就是说,Jackson会用 String.intern() 来做字符串的缓存,这样重复的字符串就可以只存一份了。而Cafe服务返回的Json恰好符合这一句:If names are unlikely to repeat, or if sheer number of distinct names is huge (in tens of thousands or above), it may make sense to disable this feature. 因为返回的 Json 里的 Key 是 DealId,而DealId很少重复,所以导致缓存池里的字符串越积越多……直到GC的时候才会回收。

问题解决

所以果断禁用掉了 CANONICALIZE_FIELD_NAMES 。对代码做如下修改

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
import com.google.common.base.Joiner;
 import com.meituan.service.campaign.api.domain.CampaignBase;
@@ -30,6 +31,7 @@ class CafeServiceImpl implements CafeService {
     private final OkHttpClient httpClient;
     private final List<HttpUrl> hostList;
     private final ObjectMapper mapper;
+    private final JsonFactory jsonFactory;
  
     @Autowired
     public CafeServiceImpl(ConnectionPool pool, @Value("${cafe.url}") String url, @Value("${cafe.timeout:50}") int timeout, ObjectMapper mapper) {
@@ -44,6 +46,9 @@ class CafeServiceImpl implements CafeService {
                 .readTimeout(timeout, TimeUnit.MILLISECONDS)
                 .build();
         this.mapper = mapper;
+        this.jsonFactory = new JsonFactory()
+                .configure(JsonFactory.Feature.CANONICALIZE_FIELD_NAMES, false)
+                .setCodec(mapper);
     }
  
     private static HttpUrl getQueryHttpUrl(Map<String, Integer> query, HttpUrl host) {
@@ -80,7 +85,7 @@ class CafeServiceImpl implements CafeService {
                 response.body().close();
                 throw new CafeIOException(response.message());
             }
-            JsonNode node = mapper.readTree(response.body().bytes()).path("campaign");
+            TreeNode node = jsonFactory.createParser(response.body().byteStream()).readValueAsTree().path("campaign");
             return mapper.convertValue(node, LIST_TYPE_REFERENCE);
         } catch (IOException e) {
             throw new CafeIOException(e);
@@ -103,7 +108,7 @@ class CafeServiceImpl implements CafeService {
                 response.body().close();
                 throw new CafeIOException(response.message());
             }
-            JsonNode node = mapper.readTree(response.body().bytes()).path(type);
+            TreeNode node = jsonFactory.createParser(response.body().byteStream()).readValueAsTree().path(type);
             return mapper.convertValue(node, MAP_TYPE_REFERENCE);
         } catch (IOException e) {
             throw new CafeIOException(e);

再一次观察 JProfiler 的结果,这个热点已经没有了。 与此同时发现之前一直没解决的 YoungGC 的时间随着距离上次 FullGC 时间而增长的问题也没有了。从监控可以看到: falcon