Нарушение ограничения Hibernate Sequence с помощью объединенных в пул, оптимизаторов loo поверх Postgresql - PullRequest
0 голосов
/ 14 мая 2018

Недавно мне пришлось разделить одну из больших таблиц PostgreSql в моем проекте, и из-за этого мне пришлось изменить стратегию сгенерированных значений для нее с IDENTITY на SEQUENCE.После этого у меня возникла проблема с генерацией последовательности, которая использовалась Hibernate по умолчанию.Я использую Hibernate 5.2.17-Final , и по умолчанию я получил: use_new_id_generator_mappings = true .Мой объект сущности находится в состоянии покоя:

@Setter
@Getter
@ToString(of = { "id", "msisdnA", "msisdnB", "voiceChannel", "idMelody" })
/*@SequenceGenerator(name="id_generator", sequenceName="report_calls_idreportcall_seq")*/
@SQLInsert(sql = "INSERT INTO public.report_calls (dateadded, dateend, datestart, idmelody, idregion, idmelodytype, msisdn_a, msisdn_b, idvoicechannel, idreportcall) " +
           "VALUES (?,?,?,?,?,?,?,?,?,?)", check= ResultCheckStyle.NONE)
@Entity
@Table(schema = "public", name = "report_calls")
public class ReportCall {
@Id
@GenericGenerator(name="sequence_generator", strategy="enhanced-sequence",
                  parameters = {@org.hibernate.annotations.Parameter(name = "sequence_name", value = "report_calls_idreportcall_seq"),
                                @org.hibernate.annotations.Parameter(name = "optimizer",      value="pooled-lo"),
                                @org.hibernate.annotations.Parameter(name = "initial_value",  value = "1"),
                                @org.hibernate.annotations.Parameter(name = "increment_size", value = "10")})
@GeneratedValue(strategy = GenerationType.SEQUENCE, generator = "sequence_generator")
@Column(name = "idreportcall", nullable = false)
private long          id;

@Column(name = "dateadded")
private LocalDateTime dateAdded = LocalDateTime.now();

@Column(name = "datestart")
private LocalDateTime dateStart;
...

}

Моя конфигурация Hibernate:

@Bean
public EntityManagerFactory entityManagerFactoryBilling() {
    log.debug("###Configuring EntityManager for billing");

    LocalContainerEntityManagerFactoryBean emf = new LocalContainerEntityManagerFactoryBean();
    emf.setPersistenceProvider(new HibernatePersistenceProvider());
    emf.setPersistenceUnitName("billingUnit");
    emf.setJpaDialect(new HibernateJpaDialect());
    emf.setJpaVendorAdapter(new HibernateJpaVendorAdapter());
    emf.setDataSource(dataSourceBilling());
    emf.setJpaProperties(jpaProperties());
    emf.setPackagesToScan("ru.intech.rbt.common.entity.billing");


    emf.afterPropertiesSet();
    return emf.getObject();
}

private Properties jpaProperties() {
    Properties props = new Properties();

    props.put(DIALECT, env.getProperty("hibernate.dialect"));
    props.put(DRIVER, env.getProperty("hibernate.driver"));
    props.put(USE_NEW_ID_GENERATOR_MAPPINGS, env.getProperty("billing.hibernate.use_new_id_generator_mappings", Boolean.class));


    props.put(SHOW_SQL, env.getProperty("billing.hibernate.show_sql", Boolean.class));
    props.put(FORMAT_SQL, env.getProperty("billing.hibernate.format_sql", Boolean.class));
    props.put(USE_SQL_COMMENTS, env.getProperty("billing.hibernate.use_sql_comments", Boolean.class));

    props.put(CACHE_REGION_FACTORY, env.getProperty("billing.hibernate.cache.region.factory_class"));
    props.put(DEFAULT_CACHE_CONCURRENCY_STRATEGY, env.getProperty("billing.hibernate.cache.default_cache_concurrency_strategy"));
    props.put(USE_SECOND_LEVEL_CACHE, env.getProperty("billing.hibernate.cache.use_second_level_cache", Boolean.class));
    props.put(USE_QUERY_CACHE, env.getProperty("billing.hibernate.cache.use_query_cache", Boolean.class));
    props.put(GENERATE_STATISTICS, env.getProperty("billing.hibernate.generate_statistics", Boolean.class));

    log.info("###billingJpaProperties:" + props);

    return props;
}

, где файл свойств:

billing.hibernate.use_new_id_generator_mappings=true
billing.hibernate.generate_statistics=false
billing.hibernate.show_sql=false
billing.hibernate.format_sql=true
billing.hibernate.use_sql_comments=true

billing.hibernate.cache.use_query_cache=false
billing.hibernate.cache.use_second_level_cache=true
billing.hibernate.cache.default_cache_concurrency_strategy=READ_WRITE
billing.hibernate.cache.region.factory_class=org.hibernate.cache.ehcache.SingletonEhCacheRegionFactory

После изменения генерации последовательностиВ своей стратегии я запустил свое приложение и протестировал его с помощью 11 вызовов операции save () упомянутой сущности через EntityManager, которую я получил из "billingUnit" модуля персистентности.Первые 10 звонков были сохранены правильно, проблем не наблюдалось, но 11-й звонок не удался.Существуют трассировки отладки Hibernate: 1 вызов сохранения ()

2018-05-14 13:28:13,144 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - begin
2018-05-14 13:28:13,156 [992937304751>222[IVR] IVR] DEBUG org.hibernate.SQL -
    select
        nextval ('report_calls_idreportcall_seq')
2018-05-14 13:28:13,164 [992937304751>222[IVR] IVR] DEBUG o.h.id.enhanced.SequenceStructure - Sequence value obtained: 219049790
2018-05-14 13:28:13,164 [992937304751>222[IVR] IVR] DEBUG o.h.r.j.i.ResourceRegistryStandardImpl - HHH000387: ResultSet's statement was not registered
2018-05-14 13:28:13,164 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractSaveEventListener - Generated identifier: 219049790, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2018-05-14 13:28:13,182 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - committing
2018-05-14 13:28:13,182 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2018-05-14 13:28:13,183 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2018-05-14 13:28:13,185 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2018-05-14 13:28:13,185 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2018-05-14 13:28:13,187 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2018-05-14 13:28:13,187 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - ru.intech.rbt.common.entity.billing.ReportCall{dateStart=2018-05-14T13:28:10.591, msisdnA=992937304751, melodyType=NO_TYPE, idRegion=1, msisdnB=222, idMelody=0, id=219049790, dateEnd=2018-05-14T13:28:13.142, voiceChannel=SIP_IVR, dateAdded=2018-05-14T13:28:13.142}
2018-05-14 13:28:13,195 [992937304751>222[IVR] IVR] DEBUG org.hibernate.SQL -
    INSERT
    INTO
        public.report_calls
        (dateadded, dateend, datestart, idmelody, idregion, idmelodytype, msisdn_a, msisdn_b, idvoicechannel, idreportcall)
    VALUES
        (?,?,?,?,?,?,?,?,?,?)

2 вызов вызова ()

2018-05-14 13:29:09,136 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - begin
2018-05-14 13:29:09,137 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractSaveEventListener - Generated identifier: 219049791, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - committing
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2018-05-14 13:29:09,138 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - ru.intech.rbt.common.entity.billing.ReportCall{dateStart=2018-05-14T13:29:06.538, msisdnA=992937304751, melodyType=NO_TYPE, idRegion=1, msisdnB=222, idMelody=0, id=219049791, dateEnd=2018-05-14T13:29:09.135, voiceChannel=SIP_IVR, dateAdded=2018-05-14T13:29:09.135}
2018-05-14 13:29:09,139 [992937304751>222[IVR] IVR] DEBUG org.hibernate.SQL -
    INSERT
    INTO
        public.report_calls
        (dateadded, dateend, datestart, idmelody, idregion, idmelodytype, msisdn_a, msisdn_b, idvoicechannel, idreportcall)
    VALUES
        (?,?,?,?,?,?,?,?,?,?)

... и т. Д. До 11-го вызова, где возникает проблема:

2018-05-14 13:35:47,871 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - begin
2018-05-14 13:35:47,873 [992937304751>222[IVR] IVR] DEBUG org.hibernate.SQL -
    select
        nextval ('report_calls_idreportcall_seq')
2018-05-14 13:35:47,875 [992937304751>222[IVR] IVR] DEBUG o.h.id.enhanced.SequenceStructure - Sequence value obtained: 219049791
2018-05-14 13:35:47,875 [992937304751>222[IVR] IVR] DEBUG o.h.r.j.i.ResourceRegistryStandardImpl - HHH000387: ResultSet's statement was not registered
2018-05-14 13:35:47,875 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractSaveEventListener - Generated identifier: 219049791, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.e.t.internal.TransactionImpl - committing
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Processing flush-time cascades
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Dirty checking collections
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.e.i.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2018-05-14 13:35:47,876 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - Listing entities:
2018-05-14 13:35:47,877 [992937304751>222[IVR] IVR] DEBUG o.h.internal.util.EntityPrinter - ru.intech.rbt.common.entity.billing.ReportCall{dateStart=2018-05-14T13:35:43.831, msisdnA=992937304751, melodyType=NO_TYPE, idRegion=1, msisdnB=222, idMelody=0, id=219049791, dateEnd=2018-05-14T13:35:47.870, voiceChannel=SIP_IVR, dateAdded=2018-05-14T13:35:47.870}
2018-05-14 13:35:47,877 [992937304751>222[IVR] IVR] DEBUG org.hibernate.SQL -
    INSERT
    INTO
        public.report_calls
        (dateadded, dateend, datestart, idmelody, idregion, idmelodytype, msisdn_a, msisdn_b, idvoicechannel, idreportcall)
    VALUES
        (?,?,?,?,?,?,?,?,?,?)
2018-05-14 13:35:47,891 [992937304751>222[IVR] IVR] DEBUG o.h.e.jdbc.spi.SqlExceptionHelper - could not execute statement [n/a]
org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "report_calls_pkey"
  Detail: Key (idreportcall)=(219049791) already exists.
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2455)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2155)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:288)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:430)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:356)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:168)
        at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:135)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3032)
        at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3547)
        at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:89)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:600)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:474)
        at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:494)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3245)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2451)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
        at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68)
        at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:504)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:292)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
        at ru.intech.rbt.common.dao.service.ReportService$$EnhancerBySpringCGLIB$$b718a67e.save(<generated>)
        at ru.intech.rbt.common.dao.reserve.proxy.ReportServiceProxy.save(ReportServiceProxy.java:88)
        at ru.intech.rbt.common.context.SubscriberContext.createReport(SubscriberContext.java:568)
        at ru.intech.ivr.box.threads.CallProcessor.processCDR(CallProcessor.java:466)
        at ru.intech.ivr.box.threads.IvrProcessor.run(IvrProcessor.java:184)
        at java.lang.Thread.run(Thread.java:745)
2018-05-14 13:35:47,892 [992937304751>222[IVR] IVR] WARN  o.h.e.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 23505
2018-05-14 13:35:47,892 [992937304751>222[IVR] IVR] ERROR o.h.e.jdbc.spi.SqlExceptionHelper - ERROR: duplicate key value violates unique constraint "report_calls_pkey"
  Detail: Key (idreportcall)=(219049791) already exists.
2018-05-14 13:35:47,898 [992937304751>222[IVR] IVR] DEBUG o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl - JDBC transaction marked for rollback-only (exception provided for stack trace)
java.lang.Exception: exception just for purpose of providing stack trace

Кто-нибудь может объяснить мне такое странное поведение фреймворка Hibernate, пожалуйста?Я не понимаю, почему он генерирует тот же идентификатор, что и метод Postgres nextval () , используя мой report_calls_idreportcall_seq ?Кстати, последовательность изначально (до теста) выглядела так:

  • текущее значение: 219049790
  • приращение: 1
  • минимум: 1
  • максимум: 9223372036854775807
  • кэш: 1
  • циклично: НЕТ

Если я установил increment_size = 1 в качестве параметра @GenericGenerator, то все становится хорошо, но яЯ не хочу этого делать, и поскольку это приведет к снижению производительности из-за того, что hibernate будет попадать в базу данных каждый раз, когда ему необходимо сохранить новый report_call, а в производственной среде у меня есть около 300 потоков, которые в параллельном режиме сохраняют эти элементы всевремя.Есть ли шанс избежать установки increment_size = 1 или optimizer = "hi / lo" (как я вижу, он также попадает в базу данных, чтобы каждый раз получать новый идентификатор с помощью nextval ())?

1 Ответ

0 голосов
/ 14 мая 2018

Кажется, я понял основную причину моей проблемы.Я заставил Hibernate использовать increment_size = 10 и в то же время сконфигурировал мою последовательность Postgres для увеличения нового идентификатора первичного ключа со значением 1, и Postgres не поощрялся, когда Hibernate пытался сохранить элемент со значением id, когда 10 значений больше id уже были сохранены.

Таким образом, не было ничего особенного в том, что Hibernate принял именно то значение, которое ему предоставляет последовательность db, поскольку ожидалось, что db также настроен для увеличения значения pk до того же промежутка => 10.Когда я изменил «приращение» моего report_calls_idreportcall_seq , все стало хорошо, и Hibernate больше не генерирует исключения, и в то же время он ударил по БД с помощью запроса nextval () один раз в 10сохранить () звонки.

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...