The story of how I with the help of the logs found a "devourer" of memory
I want to share a simple, but, in my opinion, interesting way to search for the places where memory-eaters can be found using the minimum set of tools that are always available at hand — logs and jVisualVM.
We are developing an electronic document management system that is designed to work for tens of thousands of users. During the operation of the system, for several months we were faced with a situation where the server simply ran out of memory, despite the fact that there were no changes in the system that could catch on. And the test copy of the system is not suspicious.
The memory profiling option has failed - too many objects are created in the system, and it is simply not possible to remove the profiler snapshot in a meaningful time. Removing several heap dumps and manually comparing them gave a clue - the system contains an unexpectedly large number of instances of the same Hibernate entity (just over a million). Wow ! But how do you know where so many objects are generated? Search by code? Not an option, you have to do a search throughout the system, but time is running out - the customer is already turning blue.
The following solution came to mind: why not insert call stack logging into the constructor of the entity class? An interesting idea ... A constructor was created with the following code:
Updated the industrial system and left overnight. In the morning we received impressive logs of ~ 40 GB in size. Well, let's get started.
First I had to cut the logs into pieces of 200 MB, because otherwise, such a volume simply cannot be opened. A quick run through the logs immediately made it possible to isolate the call stack, which is very common. On the stack call found a class that calls Hibernate functions, and here it is! Here it is - our ill-fated class. In one of his methods, a list of all records from the table is pulled (and the number of records in it has exceeded 2 million) - and this is the creation of instances of our essence. Further, the code goes even worse: this whole list is looped through and compared by one field - a sort of filter implementation. Of course, the code was immediately rewritten (by inserting a condition in the where of the HQL query), and its author was immediatelydissected . That’s all - with this “old-fashioned” method a very “piquant” problem was solved.
As a conclusion : if you sat down to write code to work with the database, learn SQL! (you don’t know the language of simple queries - it’s better not to go outside the database). And the second - to solve at first glance a difficult task, it is not at all necessary to have “sophisticated” tools.
We are developing an electronic document management system that is designed to work for tens of thousands of users. During the operation of the system, for several months we were faced with a situation where the server simply ran out of memory, despite the fact that there were no changes in the system that could catch on. And the test copy of the system is not suspicious.
The memory profiling option has failed - too many objects are created in the system, and it is simply not possible to remove the profiler snapshot in a meaningful time. Removing several heap dumps and manually comparing them gave a clue - the system contains an unexpectedly large number of instances of the same Hibernate entity (just over a million). Wow ! But how do you know where so many objects are generated? Search by code? Not an option, you have to do a search throughout the system, but time is running out - the customer is already turning blue.
The following solution came to mind: why not insert call stack logging into the constructor of the entity class? An interesting idea ... A constructor was created with the following code:
...
protected static final Logger LOGGER = Logger.getLogger (Payment.class);
public Payment ()
{
// TODO: CLEAR! ONLY TO SEARCH FOR A MEMORY Leak!
StringBuilder stringBuilder = new StringBuilder ();
stringBuilder.append ("MEMLEAK_TEST: Payment () \ n");
StackTraceElement [] stackTraceElements = Thread.currentThread (). GetStackTrace ();
for (StackTraceElement stackTraceElement: stackTraceElements)
{
stringBuilder.append ("at"
+ stackTraceElement.getClassName ()
+ "." + stackTraceElement.getMethodName ()
+ "(" + stackTraceElement.getFileName () + ":" + stackTraceElement.getLineNumber () + "\ n");
}
LOGGER.info (stringBuilder.toString ());
}
...
Updated the industrial system and left overnight. In the morning we received impressive logs of ~ 40 GB in size. Well, let's get started.
First I had to cut the logs into pieces of 200 MB, because otherwise, such a volume simply cannot be opened. A quick run through the logs immediately made it possible to isolate the call stack, which is very common. On the stack call found a class that calls Hibernate functions, and here it is! Here it is - our ill-fated class. In one of his methods, a list of all records from the table is pulled (and the number of records in it has exceeded 2 million) - and this is the creation of instances of our essence. Further, the code goes even worse: this whole list is looped through and compared by one field - a sort of filter implementation. Of course, the code was immediately rewritten (by inserting a condition in the where of the HQL query), and its author was immediately
As a conclusion : if you sat down to write code to work with the database, learn SQL! (you don’t know the language of simple queries - it’s better not to go outside the database). And the second - to solve at first glance a difficult task, it is not at all necessary to have “sophisticated” tools.