The phenomenon of

  • QA students complained that they could not log in to the server

Troubleshoot Problem 1 – Log levels

  • Check the log, found that when a player login throws a Java lang. OutOfMemoryError

  • The code probably serialized a PlayerMirror to Redis, but there was an error in json.tojsonString. When serializing, expandCapacity is out of memory.

  • Looking at the log again, there are several OutofMemoryErrors, similar to those reported when serializing PlayerMirror with FastJSON

  • Again carefully look at the directory server, found several. Hprof, that did happen heap memory, because the launch parameters increased ‘- XX: + HeapDumpOnOutOfMemoryError’

at java.lang.OutOfMemoryError.<init>()V (OutOfMemoryError.java:48) at com.alibaba.fastjson.serializer.SerializeWriter.expandCapacity(I)V (SerializeWriter.java:249)Copy the code

-rw------- 1 xx xx 2043416350 Nov 24 11:37 java_pid8068.hprof-rw------- 1 xx xx 2028797313 Nov 24 11:17 java_pid4671.hprof-rw------- 1 xx xx 1477222612 Nov 23 23:25 java_pid31563.hprofCopy the code

Troubleshoot Problem 2 – JVM command level

Initial troubleshooting was performed using the JVM command jstat -gcutil PID

jstat -gc pid

jmap -histo pid

jmap -heap pid

Jstat saw that the old age was almost full

Char [] and Object[]

num #instances #bytes class name---------------------------------------------- 1: 146219 741203672 [Ljava.lang.Object; 2: 2842356 639498168 [CCopy the code

Troubleshooting Problem 3 – Professional tool level

Because of hprof, we just need to use the professional memory analysis tool MAT #Open Heap Dump, after loading, we will get a Getting Started Wizard#Leak Suspects Report, select Finish Two questionable questions:

  • One instance of JSONArray takes up about 700M of memory

  • Another is that the thread’s Local Variables take up 500 MB of memory

! [](https://static001.geekbang.org/infoq/2b/2b3ba8fa68a26cf4f75ef7c8dcabea31.png)

It opens at question 1 details, found the JSONArray is configuration class PersonalityStrengthenConfig# cost field, a closer look at the JSONArray# list# elementData array length is 183842095.

! [](https://static001.geekbang.org/infoq/49/495dd7a5eaea42baa6a87d47fe8e7c10.png)

The buf#char[] in SerializeWriter is 262012306. The second figure of stack information can see is the serialization PersonalityStrengthenConfig thrown out of memory.

! [](https://static001.geekbang.org/infoq/13/13e9c1b295795561739de5eca12b7cd3.png)
! [](https://static001.geekbang.org/infoq/83/831be69aa9b2485fb4ea1c76642e7c6f.png)

Combined with the two problems, is easy to think of the answer, cost of PersonalityStrengthenConfig field (JSONArray) occupies a lot of memory, Part and player offline or online to serialize the data to redis, including the PersonalityStrengthenConfig, so also to serialize the super big cost, serialization to apply for the space, so it is out of memory.

Analyze q.1 – Observe data

Why PersonalityStrengthenConfig will be serialized data configuration class, Because when a Player offline need to serialize a Player image data to the redis Player – > Hero – > HeroPersonality – > getConfig (PersonalityStrengthenConfig) HeroPersonality have a get method, and serialization of the classmate forget SerializerFeature. IgnoreNonFieldGetter this parameter, so lead to this config object is serialized in getConfig in, After modifying the code, all the problems are gone.

Need to confirm: PersonalityStrengthenConfig# cost accounts for the JsonArray why so big space, can have a look at what is inside?

Doubts in the mat, the first report click PersonalityStrengthenConfig @ 0 x8140c468 object, on the left side of the page Inspector have a Attributes, find the cost Objects – > right click – > List are with outgoing references

As you can see from the following figure, the JSONAray contains the first element, which is a normal JSONObject, and all other elements are null. Of course you can Copy buf#char[] data from SerializeWriter from the second suspect report -> click ->Copy->Save Value to File. Of course, the file is hundreds of megabytes (and only one line), so big that a normal text editor wouldn’t even see it (I used tail on Linux and then clicked CTRL + C to finally see the beginning of the data), and there was only one normal data when serialized to the config#cost field, The cost field is null except for a normal JSONObject, and the rest are null.

! [](https://static001.geekbang.org/infoq/a4/a46502f3719c17698bc71ec7c48e92c7.png)

Analyze problem 2 – try to reproduce it

The initial solution was simply to try to replicate it in code

New HeroPersonality, which has a getConfig inside, serializes it without IgnoreNonFieldGetter to see if it will cause a large memory footprint

Unfortunately, it could not be reproduced

HeroPersonality hp = new HeroPersonality(); hp.setPersonalityLevel(1); String str = JSON.toJSONString(hp);Copy the code

Then try to restore the recent versions of the value table to see if there is any problem. This is suspected that there is something wrong with the planning configuration table, which causes the cost field to become very large when loading as possible under some special circumstances. Unfortunately, it failed to reappear.

The cost field is large after analyzing the source code to see if it is possible to start loading the configuration table

Debug DataConfigService found the first problem is that this class uses jSON-lib and Fastjson (this framework has been updated, our project has not been updated). There is a bug in json-lib. The process of finding deserialization is JSONLexer# scanning such as braces, commas, square brackets. When the first JSONObject is found, add it to the COST array (note that the underlying array size of JSONArray# List has expanded to length 10).

Seeing this gives me an idea of whether it is possible to encounter special characters such as circular references in Fastjson

And then guess whether the formula was configured when planning the configuration? In addition, I also tried to add various special characters to the COST field of JSON. Unfortunately, it failed to reproduce after verification.

Try carefully looked at the pile of snapshot, 10 object PersonalityStrengthenConfig internal data is checked, and planning a table compares the SVN, confirmed that is a version of the data. This version of the data in the local test is no problem, excluding planning configuration data problems.

Analysis question 3 – Mountains and rivers doubt there is no way

When I wrote the native test code recurrence, I wrote an example of deserializing HeroPersonality, serializing HeroPersonality to a bunch of strings, and then trying to add some extra information to the bunch of strings, and then deserializing, When deserializing HeroPersonality and then serializing the original HeroPersonality again, I was surprised to find that the serialized COST field had a null. And then I’m going to put the deserialization code in the loop and print it out again and find that the COST field has been added a lot of null.

Pseudo test code

PersonalityStrengthenConfig config = DataConfigService.getSettingById(PersonalityStrengthenConfig.class, 1); System.out.println("dcs.config1:" + config.cost); System.out.println("dcs.config1:" + config.attr_num); for (int i = 0; i < 10; i++) { String str1 = "{... } "; JSON.parseObject(str1, HeroPersonality.class); }System.out.println("dcs.config2:" + config.cost); System.out.println("dcs.config2:" + config.attr_num);Copy the code

Result output:

! [](https://static001.geekbang.org/infoq/55/554c286057feb504a63b479d0bd920c6.png)

This result surprised me and made me very sure that a large number of null in cost was generated in this way. Moreover, I suspected that there were some problems with some non-serialized GET methods in HeroPersonality at the first time. Attr_num is also of type JSONArray, so there is no problem. The problem is initially locked to a get method in HeroPersonality.

Analysis problem 4 – source code tracing

Source code debug is required. Why cost is added with a large number of null values during the continuous call of deserialization? As you can see, getNextTrainCost calls the getConfig field cost. From the perspective of source code debug, we can see why there are many more null values in each deserialization. First, the nextTrainCost in the getter getNextTrainCost is treated as a field because its return value is a JSONArray, which itself can be used as a setter. Deserialization, with json “nextTrainCost” relative deserialization

The string is [{“.config.cost[0]”} using a fastjson loop reference, which is deserialized to [null] (because config itself is not field at all, just a get method).

Then I call the setter(which is itself a setter), get cost, and I add this [null] to cost

Add a [NULL] to cost every time you deserialize it, making it bigger and bigger.

public JSONArray getNextTrainCost() { return ((PersonalityStrengthenConfig) getConfig()).cost; }@Overridepublic DataConfigItem getConfig() { return DataConfigService.getSettingById(PersonalityStrengthenConfig.class,  personalityLevel); }Copy the code

Deserialize nextTrainCost

// FieldDeserializer#setValue method getNextTrainCost() and nullCollection collection = (collection) method.invoke(object); if (collection ! = null) { collection.addAll((Collection) value); }Copy the code

Analysis question 5 – A preliminary summary of the problem

The first problem is that getNextTrainCost in HeroPersonality refers to cost in getConfig. Will lead to every time when the deserialization json# nextTrainCost deserialized from JSONArray# add to the cost (the equivalent of calling the setter method)

Note that even if json#nextTrainCost is not a circular reference (fastjson can be turned off) and the value is the reference’s config#cost value, each deserialization will also add the deserialized JSONArray# to cost, but this time it will not be null. The second problem is that we started with the IgnoreNonFieldGetter parameter when we serialize normally, don’t serialize non-field get methods, and when we add the parameter, Serialized JSON will not have nextTrainCost, so there will be no deserialization problem, because it cannot be scanned at all. Of course, HeroPersonality getNextTrainCost is also quite strange, using the method of reference, which is completely unnecessary, so you can consider eliminating it.

Solve problem 1 – Why is the cost so large

We were pretty sure that deserialization in the wrong mode would cause the cost field to get bigger and bigger, so it wouldn’t be hundreds of millions of times, would it? This I have looked up the code, most likely the friend recommendation module and related modules. The code requires frequent deserialization of offline images or the presence of similar heartbeat services

The solution

Easy, just remember to serialize FastJSON with IgnoreNonFieldGetter.

extension

Mat also has many powerful uses:

  • Hisogram: list Number of instances per class

  • Dominator: TreeList the biggest objects and what they keep alive

  • Top Consumers: Print the most expensive objects grouped by class and by package

  • List Objects…

You can also view threads, Class Loader Explorer, and more

! [](https://static001.geekbang.org/infoq/e8/e89ee5b5558c9ada160d9d592c1e2316.png)

Three things to watch ❤️

If you find this article helpful, I’d like to invite you to do three small favors for me:

  1. Like, forward, have your “like and comment”, is the motivation of my creation.

  2. Follow the public account “Java rotten pigskin” and share original knowledge from time to time.

  3. Also look forward to the follow-up article ing🚀

Author: landon30

Reference: club.perfma.com/article/165…