A story about how I found logs with the help of logs

I want to share a simple, but, in my opinion, an interesting way to search for places of generation of memory eaters 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 for tens of thousands of users. When operating the system for several months, we faced a situation where the server simply did not have enough memory, despite the fact that there were no changes in the system that could be caught. Yes, and a test copy of the system does not cause suspicion.

The memory profiling option failed - too many objects are created in the system, and it is impossible to remove the profiler snapshot in a meaningful time. The removal of several heap dumps and their manual comparison gave a clue - there is an unexpectedly large number of instances of the same Hibernate entity in the system (just over a million). Great ! But how do you know where such a large number of objects originate? Search by code? Not an option, you have to do a search on the entire system, but time is running out - the customer is already all blue.

The following solution came to mind: why not insert the call stack logging into the entity class constructor? The idea is interesting ... A constructor was created with the following code:
')

 ...
 protected static final Logger LOGGER = Logger.getLogger (Payment.class);

 public Payment ()
 {
	 // TODO: CLEAR!  ONLY FOR SEARCHING MEMORY LEAKAGE!
	 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 industrial system and left overnight. The next morning, we received impressive logs of ~ 40 GB in size. Well, let's get started.

For a start, we had to cut logs into pieces of 200 MB each, since otherwise, such a volume simply does not open. A quick run through the logs immediately made it possible to allocate a call stack, which occurs very often. By the call stack, we found a class that calls the Hibernate functions, and here it is ! Here it is - our ill-fated class. In one of its methods, a list of all records from a table is pulled out (and the number of records in it has exceeded 2 million) - and this is the creation of instances of our entity. Further, the code goes even worse: this entire list gets over in a loop and is compared by one field - a sort of filter implementation. Of course, the code was immediately rewritten (by inserting the condition in the HQL where clause), and its author was immediately dissected by the order. That's all - with such “old-fashioned” method a very “piquant” problem was solved.

As an output : if you sat down to write code to work with a database, learn SQL! (do not know the language of simple queries - it is better not to go to the street database). And the second is that in order to solve a difficult task at first, it is not at all necessary to have “tricked” tools.