Spring JPA: Как я могу увидеть, как коммиты выдаются в журналах?

Question

У меня есть приложение Spring Batch, которое обрабатывает 1000 строк данных в пакетах по 20 (throttle-limit на поток). commit-interval в конфигурации пакета также равно 20. Обработанные данные хранятся в подробной таблице, отражающей их статус (в базе данных Postgresql).

Я обнаружил, что чем больше данных я добавьте в приложение, последние несколько пакетов не фиксируются в таблице сведений, хотя процессы в пакете были выполнены успешно. Так что сейчас я прочесываю логи, чтобы увидеть, где происходят коммиты, но не могу найти подходящего логгера. В моем файле свойств у меня есть spring.jpa.properties.hibernate.type=trace, и вот мои регистраторы:

  <logger name="org.springframework.orm.jpa" level="DEBUG">
    <appender-ref ref="STDOUT" />
  </logger>

  <logger name="org.springframework.transaction" level="TRACE">
    <appender-ref ref="STDOUT" />
  </logger>

  <logger name="org.springframework.jdbc" level="TRACE">
    <appender-ref ref="STDOUT" />
  </logger>

  <logger name="org.hibernatec" level="TRACE">
    <appender-ref ref="STDOUT" />
  </logger>

А вот метод, который выдает операторы, которые не всегда фиксируются:

@Transactional(propagation = Propagation.REQUIRES_NEW)
@Override
public void updateJobDetail(String jobId, String domainCode, String codesDelimited, Date effectiveDate,
                                   StatusEnum status, String userId) {

        [business logic]

        detailRepository.save(entities);
        detailRepository.flush();
        entityManager.clear();
}

Я предполагаю, что у меня двоякий вопрос: почему база данных может не отражать последние несколько пакетов, и как я могу увидеть в журналах, если выполняются коммиты?

Обновление: Вот что показывают журналы. Интересно, почему заявления регистрируются дважды?

15:35:02.288 [ThreadPoolExecutor-26] INFO  c.e.s.i.DetailServiceImpl - updateDetail - exit in 101 ms
15:35:02.288 [ThreadPoolExecutor-26] TRACE o.s.t.i.TransactionInterceptor - Completing transaction for [com.erd.service.impl.DetailServiceImpl.updateDetail]
15:35:02.288 [ThreadPoolExecutor-26] TRACE o.s.t.i.TransactionInterceptor - Completing transaction for [com.erd.service.impl.DetailServiceImpl.updateDetail]

Answer 1

Я использую REQUIRES_NEW, потому что мне нужно сразу увидеть результаты в БД, иначе мы не сможем увидеть подробный результат, пока не закончится весь пакет.

Я не вижу действительных причина для этого. Зачем тогда использовать шаг, ориентированный на чанк? Шаг, ориентированный на порцию, используется, когда порция записей предназначена для обработки и записи как единица (на границах транзакции порции), то есть семантика "все или ничего".

Итак, попытка чтобы обойти это, если вложенные меньшие транзакции внутри той, что управляется Spring Batch, в первую очередь работают против цели обработки, ориентированной на куски.

Я рекомендую изменить ваш подход, удалив @Transactional(propagation = Propagation.REQUIRES_NEW) и выбрав меньшую размер чанка, если вы хотите, чтобы больше записей фиксировалось в базу данных чаще.

Как я могу видеть, что коммиты выдают в журналах?

В дополнение к настройке уровень журнала для отладки для Spring Batch и Spring JDB C, я использую p6spy , чтобы увидеть все операторы, отправленные в базу данных. Это даст вам что-то вроде:

1543399291411|0|statement|connection0|select BATCH_STEP_EXECUTION_SEQ.nextval from dual
1543399291412|0|statement|connection0|INSERT into BATCH_STEP_EXECUTION(STEP_EXECUTION_ID, VERSION, STEP_NAME, JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED) values(1, 0, 'step', 1, '28-Nov-18', NULL, 'STARTING', 0, 0, 0, 0, 'EXECUTING', '', 0, 0, 0, 0, '28-Nov-18')
1543399291413|0|statement|connection0|INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES('{}', NULL, 1)
1543399291413|0|commit|connection0|