Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

JPA AttributeConverter makes hibernate generate update statements on whole table in transaction

All code in this post can be found here: https://github.com/cuipengfei/gs-accessing-data-jpa/tree/master/complete

You can run this test to reproduce the problem: https://github.com/cuipengfei/gs-accessing-data-jpa/blob/master/complete/src/test/java/hello/T1ServiceTest.java

I have a domain model:

@Entity
@Table(name = "t1", schema = "test")
public class T1 extends BaseEntity {

  @Column(nullable = false)
  private UUID someField;

  @Column()
  private ZonedDateTime date;

  public T1(UUID someField, ZonedDateTime date) {
    this.someField = someField;
    this.date = date;
  }
}

It has a field typed as ZonedDateTime, so I have a converter to convert it to sql time stamp:

@Converter(autoApply = true)
public class ZonedDateTimeAttributeConverter
    implements AttributeConverter<ZonedDateTime, Timestamp> {

  @Override
  public Timestamp convertToDatabaseColumn(ZonedDateTime entityValue) {
    return (entityValue == null) ? null :
        valueOf(entityValue.withZoneSameInstant(of("UTC")).toLocalDateTime());
  }

  @Override
  public ZonedDateTime convertToEntityAttribute(Timestamp databaseValue) {
    return (databaseValue == null) ? null : databaseValue.toLocalDateTime().atZone(
        of("UTC"));
  }
}

When I try to create a lot of T1s in a transaction like this:

@Service
public class T1Service {
  private static final Logger log = LoggerFactory.getLogger(T1Service.class);

  @Autowired
  T1Repository t1Repository;

  @Transactional
  public void insertMany() {
    for (int i = 0; i < 1000; i++) {
      log.info("!!! " + (i + 1) + "th item start");

      UUID randomUUID = UUID.randomUUID();
      T1 foundT1 = tryToFindExistingT1(randomUUID);//certainly won't find

      if (foundT1 == null) {
        log.info("t1 not found");
        ZonedDateTime date = now();
        //date = null;
        //if you enable the line above, there won't be any update statements anymore
        //and find will also become faster
        T1 t1 = new T1(randomUUID, date);
        saveT1(t1);
      }

      log.info("!!! " + (i + 1) + "th item finished");
      log.info("====================================");
    }
  }

  private T1 tryToFindExistingT1(UUID someField) {
    long start = currentTimeMillis();
    T1 t1Id = t1Repository.findBySomeField(someField);
    //as nth item increases, the line above will become very very slow
    //and also, there will be more and more update statements
    //but if you set date of t1 to null, update statement will disappear and it'll not be slow
    log.info("find took: " + (currentTimeMillis() - start) + " milliseconds");
    return t1Id;
  }

  private T1 saveT1(T1 t1) {
    long start = currentTimeMillis();
    T1 savedT1 = t1Repository.save(t1);
    log.info("save took: " + (currentTimeMillis() - start) + " milliseconds");
    return savedT1;
  }

}

There will be update statements generated by hibernate for the whole t1 table.

Here is the log for the first a few rounds of the for loop:

2017-03-20 17:51:54.039  INFO 74789 --- [           main] hello.T1Service                          : !!! 1th item start
2017-03-20 17:51:54.052  INFO 74789 --- [           main] o.h.h.i.QueryTranslatorFactoryInitiator  : HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select t1x0_.id as id1_0_, t1x0_.date as date2_0_, t1x0_.some_field as some_fie3_0_ from test.t1 t1x0_ where t1x0_.some_field=?
2017-03-20 17:51:54.154  INFO 74789 --- [           main] hello.T1Service                          : find took: 114 milliseconds
2017-03-20 17:51:54.154  INFO 74789 --- [           main] hello.T1Service                          : t1 not found
2017-03-20 17:51:54.177  INFO 74789 --- [           main] hello.T1Service                          : save took: 15 milliseconds
2017-03-20 17:51:54.177  INFO 74789 --- [           main] hello.T1Service                          : !!! 1th item finished
2017-03-20 17:51:54.177  INFO 74789 --- [           main] hello.T1Service                          : ====================================
2017-03-20 17:51:54.177  INFO 74789 --- [           main] hello.T1Service                          : !!! 2th item start
Hibernate: insert into test.t1 (date, some_field, id) values (?, ?, ?)
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: select t1x0_.id as id1_0_, t1x0_.date as date2_0_, t1x0_.some_field as some_fie3_0_ from test.t1 t1x0_ where t1x0_.some_field=?
2017-03-20 17:51:54.194  INFO 74789 --- [           main] hello.T1Service                          : find took: 17 milliseconds
2017-03-20 17:51:54.194  INFO 74789 --- [           main] hello.T1Service                          : t1 not found
2017-03-20 17:51:54.195  INFO 74789 --- [           main] hello.T1Service                          : save took: 1 milliseconds
2017-03-20 17:51:54.195  INFO 74789 --- [           main] hello.T1Service                          : !!! 2th item finished
2017-03-20 17:51:54.195  INFO 74789 --- [           main] hello.T1Service                          : ====================================
2017-03-20 17:51:54.195  INFO 74789 --- [           main] hello.T1Service                          : !!! 3th item start
Hibernate: insert into test.t1 (date, some_field, id) values (?, ?, ?)
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: select t1x0_.id as id1_0_, t1x0_.date as date2_0_, t1x0_.some_field as some_fie3_0_ from test.t1 t1x0_ where t1x0_.some_field=?
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : find took: 4 milliseconds
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : t1 not found
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : save took: 0 milliseconds
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : !!! 3th item finished
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : ====================================
2017-03-20 17:51:54.200  INFO 74789 --- [           main] hello.T1Service                          : !!! 4th item start
Hibernate: insert into test.t1 (date, some_field, id) values (?, ?, ?)
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: update test.t1 set date=?, some_field=? where id=?
Hibernate: select t1x0_.id as id1_0_, t1x0_.date as date2_0_, t1x0_.some_field as some_fie3_0_ from test.t1 t1x0_ where t1x0_.some_field=?
2017-03-20 17:51:54.209  INFO 74789 --- [           main] hello.T1Service                          : find took: 9 milliseconds
2017-03-20 17:51:54.209  INFO 74789 --- [           main] hello.T1Service                          : t1 not found
2017-03-20 17:51:54.210  INFO 74789 --- [           main] hello.T1Service                          : save took: 1 milliseconds
2017-03-20 17:51:54.210  INFO 74789 --- [           main] hello.T1Service                          : !!! 4th item finished
2017-03-20 17:51:54.210  INFO 74789 --- [           main] hello.T1Service                          : ====================================

As you can see in the log, more and more update statements will be generated by hibernate.

It looks like the number of update statements is always same as how many rows of T1 waiting to be committed.

Now if I remove the converter, this problem goes away.

I can use hibernate-java8 lib instead of this converter to achieve the same effect, but why does this happen?

Why does JPA AttributeConverter make hibernate generate update statements on whole table in transaction?

like image 523
Cui Pengfei 崔鹏飞 Avatar asked Mar 20 '17 09:03

Cui Pengfei 崔鹏飞


1 Answers

I fixed this problem by applying the converter in the getter and setter methods and not as annotations. Like this:

@Entity
@Table(name = "t1", schema = "test")
public class T1 extends BaseEntity {

  @Column(nullable = false)
  private UUID someField;

  @Column()
  private Timestamp date;

  public T1(UUID someField, ZonedDateTime date) {
    this.someField = someField;
    this.date = date;
  }

    public void setDate(ZonedDateTime date) {
        this.date = new ZonedDateTimeAttributeConverter().convertToDatabaseColumn(date);
    }

    public ZonedDateTime getDate() {
        return new ZonedDateTimeAttributeConverter().convertToEntityAttribute(date);
    }
}
like image 115
Stephan Berg Avatar answered Oct 09 '22 14:10

Stephan Berg