Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

What causes Spring Boot Fail-safe cleanup (collections) to occur

I have a Java Spring Boot application with the following entities related to the below exception

SProduct

@Entity
@Table(
        name = "product",
        indexes = @Index(
                name = "idx_asin",
                columnList = "asin",
                unique = true
        )
)
public class SProduct implements Serializable {

    @Id
    @GeneratedValue(strategy = GenerationType.AUTO)
    private long id;
    @Column(name = "asin", unique = false, nullable = false, length = 10)
    private String asin;
    @Column(name = "rootcategory")
    private Long rootcategory;
    @Column(name = "imageCSV", unique = false, nullable = true, length = 350)
    private String imagesCSV;
    @Column(name = "title", unique = false, nullable = true, length = 350)
    private String title;
    private Date created;
    @OneToMany(fetch = FetchType.EAGER, mappedBy = "mainProduct", cascade = CascadeType.ALL)
    private Set<FBT> fbts;
    @OneToOne(fetch = FetchType.EAGER, mappedBy = "downloadProductId", cascade = CascadeType.ALL)
    private Download download;

FBT

@Entity
@Table(
    name = "fbt",
    uniqueConstraints={@UniqueConstraint(columnNames = {"main_product_id" , "collection"})},
    indexes = {@Index(
        name = "idx_main_product_id",
        columnList = "main_product_id",
        unique = false),
        @Index(
        name = "idx_product_fbt1id",
        columnList = "product_fbt1_id",
        unique = false),
        @Index(
        name = "idx_product_fbt2id",
        columnList = "product_fbt2_id",
        unique = false)
        }
)
public class FBT implements Serializable {

    @Id
    @GeneratedValue(strategy = GenerationType.AUTO)
    private long id;
    @ManyToOne
    @JoinColumn(name = "main_product_id")
    private SProduct mainProduct;
    @ManyToOne
    @JoinColumn(name = "product_fbt1_id")
    private SProduct sproductFbt1;
    @ManyToOne
   
    @JoinColumn(name = "product_fbt2_id")
    private SProduct sproductFbt2;
    @Column(name = "bsr", nullable = false)
    private int bsr;
    private Date collection;

I had the following query in my fbt repository

  FBT findByMainProductAndCollection(SProduct mainProduct,Date collection);

which caused the following messages to be output exception when the data exists in the database for the mainProduct and collection but returns null otherwise.

  <message>HHH000100: Fail-safe cleanup (collections) : org.hibernate.engine.loading.internal.CollectionLoadContext@69b7fcfc&lt;rs=HikariProxyResultSet@325408381 wrapping com.mysql.jdbc.JDBC42ResultSet@108693fa&gt;</message>
  <message>HHH000160: On CollectionLoadContext#cleanup, localLoadingCollectionKeys contained [1] entries</message>
  <message>HHH000100: Fail-safe cleanup (collections) : org.hibernate.engine.loading.internal.CollectionLoadContext@47c40535&lt;rs=HikariProxyResultSet@2005129089 wrapping com.mysql.jdbc.JDBC42ResultSet@9894f70&gt;</message>
  <message>HHH000160: On CollectionLoadContext#cleanup, localLoadingCollectionKeys contained [1] entries</message>
  <message>HHH000100: Fail-safe cleanup (collections) : org.hibernate.engine.loading.internal.CollectionLoadContext@5b0cd175&lt;rs=HikariProxyResultSet@1598144514 wrapping com.mysql.jdbc.JDBC42ResultSet@6a7ff475&gt;</message>
  <message>HHH000160: On CollectionLoadContext#cleanup, localLoadingCollectionKeys contained [1] entries</message>
  <message>HHH000100: Fail-safe cleanup (collections) : org.hibernate.engine.loading.internal.CollectionLoadContext@f67e2cc&lt;rs=HikariProxyResultSet@319200129 wrapping com.mysql.jdbc.JDBC42ResultSet@215b8a6&gt;</message>
  <message>HHH000160: On CollectionLoadContext#cleanup, localLoadingCollectionKeys contained [1] entries</message>
  <message>HHH000100: Fail-safe cleanup (collections) : org.hibernate.engine.loading.internal.CollectionLoadContext@5961afc0&lt;rs=HikariProxyResultSet@1772496904 wrapping com.mysql.jdbc.JDBC42ResultSet@5956a59b&gt;</message>
  <message>HHH000160: On CollectionLoadContext#cleanup, localLoadingCollectionKeys contained [1] entries</message>
  <message>HHH000100: Fail-safe cleanup (collections) : 

I decided to abandon the above and write a @query to count as I only need to determine if the data exists or not and this has prevented the issue which is making me think I should change all my code to use @query.

 @Query("select count(*) as count from FBT where main_product_id = :id and collection= :collection")
    int countByMainProductIdAndCollection(@Param("id") long id, @Param("collection") Date collection);

Although this similarly also occurs seemingly randomly on updates into the database of one SProduct when the product exists in the database already.

SProductRepo.saveAndFlush(s);

I say randomly as 11 applications running the same code exit at random intervals with the above messages. There are no exceptions generated by the code and 10000's of successful database updates occur with the same code that leads to the failure. The code stops when trying to update the database where it has worked previously.

""2018-12-28 00:56:06 [KeepaAPI-RetryScheduler] WARN  org.hibernate.engine.loading.internal.LoadContexts - HHH000100: Fail-safe cleanup (collections) : org.hibernate.eng
ine.loading.internal.CollectionLoadContext@5c414639<rs=HikariProxyResultSet@1241510017 wrapping Result set representing update count of 13>
""2018-12-28 00:56:06 [KeepaAPI-RetryScheduler] WARN  org.hibernate.engine.loading.internal.CollectionLoadContext - HHH000160: On CollectionLoadContext#cleanup, localLoa
dingCollectionKeys contained [1] entries
""2018-12-28 00:56:06 [KeepaAPI-RetryScheduler] WARN  org.hibernate.engine.loading.internal.LoadContexts - HHH000100: Fail-safe cleanup (collections) : org.hibernate.eng
ine.loading.internal.CollectionLoadContext@5595c065<rs=HikariProxyResultSet@2140082434 wrapping Result set representing update count of 14>
""2018-12-28 00:56:06 [KeepaAPI-RetryScheduler] WARN  org.hibernate.engine.loading.internal.CollectionLoadContext - HHH000160: On CollectionLoadContext#cleanup, localLoa
dingCollectionKeys contained [1] entries
""2018-12-28 00:56:06 [KeepaAPI-RetryScheduler] WARN  org.hibernate.engine.loading.internal.LoadContexts - HHH000100: Fail-safe cleanup (collections) : org.hibernate.eng
ine.loading.internal.CollectionLoadContext@2956fe24<rs=HikariProxyResultSe

Additionally the SProduct findByAsin(String asin) query cause the same problem however the query in the database works perfectly and this used to work in spring boot.

mysql> select * from product where asin="B004FXJOQO";
| id | asin       | created    | imagecsv                                                                        | rootcategory | title                                                                                                        |  9 | B004FXJOQO | 2018-08-04 | 41T0ZwTvSSL.jpg,61V90AZKbGL.jpg,51AdEGCTZqL.jpg,51LDnCYfR0L.jpg,71bbIw43PjL.jpg |       228013 | Dual Voltage Tester, Non Contact Tester for High and Low Voltage with 3-m Drop Protection Klein Tools NCVT-2 |
1 row in set (0.00 sec)

What I would like to know is what are the general reasons this kind of messages get generated?

Why do they stop my application despite try catch statements around my insertion statements that are the last executed statements in my code?

Are there log debugging settings useful to determine the exact reason for why the messages are generated?

Is there a way to turn off or control this functionality?

Pom

  <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.1.1.RELEASE</version>
        <relativePath/> <!-- lookup parent from repository -->
    </parent>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>1.8</java.version>
        <maven-dependency-plugin.version>2.10</maven-dependency-plugin.version>
        <maven.test.skip>true</maven.test.skip>
    </properties>
    <repositories>
        <repository>
            <id>Keepa</id>
            <name>Keepa Repository</name>
            <url>https://keepa.com/maven/</url>
        </repository>
    </repositories>
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-jpa</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
        </dependency> 
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-devtools</artifactId>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-integration</artifactId>
        </dependency>
        
        <dependency>
            <groupId>javax.mail</groupId>
            <artifactId>mail</artifactId>
            <version>1.4.7</version>
        </dependency>
        <dependency>
            <groupId>commons-io</groupId>
            <artifactId>commons-io</artifactId>
            <version>2.6</version>
        </dependency>
        <dependency>
            <groupId>org.apache.commons</groupId>
            <artifactId>commons-compress</artifactId>
            <version>1.18</version>
        </dependency>
        <dependency>
            <groupId>com.google.api-client</groupId>
            <artifactId>google-api-client</artifactId>
            <version>1.22.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.oauth-client</groupId>
            <artifactId>google-oauth-client-jetty</artifactId>
            <version>1.22.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.apis</groupId>
            <artifactId>google-api-services-oauth2</artifactId>
            <version>v1-rev120-1.22.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.oauth-client</groupId>
            <artifactId>google-oauth-client-java6</artifactId>
            <version>1.22.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.oauth-client</groupId>
            <artifactId>google-oauth-client</artifactId>
            <version>1.22.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.apis</groupId>
            <artifactId>google-api-services-gmail</artifactId>
            <version>v1-rev48-1.22.0</version>
        </dependency>
        <dependency>
            <groupId>org.codehaus.mojo</groupId>
            <artifactId>exec-maven-plugin</artifactId>
            <version>1.5.0</version>
            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-nop</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>com.jcraft</groupId>
            <artifactId>jsch</artifactId>
            <version>0.1.54</version>
        </dependency>
        <dependency>
            <groupId>com.myjeeva.digitalocean</groupId>
            <artifactId>digitalocean-api-client</artifactId>
            <version>2.16</version>
        </dependency>
        <dependency>
            <groupId>com.google.code.gson</groupId>
            <artifactId>gson</artifactId>
        </dependency>
        <dependency>
            <groupId>com.keepa.api</groupId>
            <artifactId>backend</artifactId>
            <version>LATEST</version>
        </dependency>
        <dependency>
            <groupId>org.jdeferred</groupId>
            <artifactId>jdeferred-core</artifactId>
            <version>1.2.6</version>
        </dependency>
        <dependency>
            <groupId>com.google.guava</groupId>
            <artifactId>guava</artifactId>
            <version>22.0</version>
        </dependency>
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <scope>runtime</scope>
        </dependency>

    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build

I increased the memory from 1gb to 2gb however the memory is only 30% of what is available.

Any thoughts as to what the issue is?

like image 805
conteh Avatar asked Nov 29 '18 13:11

conteh


2 Answers

In my case it was because of entities calling each other's hashcode recursively, if you use lombock remove it and make it yourself.Put breakpoint of debugger on the methods of two hashcodes. You'll sea that they are calling each other. Remove for example from the first entity's hashcode method second entity's link.

like image 176
Vahan Yeghyan Avatar answered Sep 17 '22 04:09

Vahan Yeghyan


Firstly, it is a Hibernate Error handled by org.hibernate.engine and has nothing to do with Spring Boot.

It can occur if you're fetching large amounts of data, like tens of thousands of entities with your HQL queries.

This can also be the case if you have mapped a one-to-many association which has many of child entities and due to bi-directional mapping the result-set is replicating infinitely.

Refer to link below for high performance JPA Tips.

https://vladmihalcea.com/14-high-performance-java-persistence-tips/

like image 36
apoorvakash Avatar answered Sep 20 '22 04:09

apoorvakash