Статьи

Отладка Hibernate Envers — Исторические данные

Недавно в нашем проекте мы сообщили о странной ошибке. В одном отчете, где мы отображаем исторические данные, предоставленные Hibernate Envers , пользователи обнаружили дублирующиеся записи в раскрывающемся списке , используемом для фильтрации. Мы попытались найти источник этой ошибки, но, потратив несколько часов на просмотр кода, ответственного за эту функциональность, нам пришлось отказаться и запросить дамп из производственной базы данных, чтобы проверить, что на самом деле хранится в одной таблице. И когда мы получили его и начали расследование, оказалось, что в Hibernate Envers 3.6 есть ошибка, которая является причиной наших проблем. Но, к счастью, после некоторого расследования и неоценимой помощи от Адама Варски (автора Envers) нам удалось решить эту проблему.

Ошибка сама

Давайте рассмотрим следующий сценарий:

  1. Транзакция начата. Мы вставляем некоторые проверенные объекты во время этого, а затем он откатывается.
  2. Тот же EntityManager используется повторно для запуска другой транзакции
  3. Вторая транзакция совершена

Но когда мы проверим таблицы аудита для сущностей, которые были созданы, а затем откатаны на первом этапе, мы заметим, что они все еще там и не были откачены, как мы ожидали. Мы смогли воспроизвести его в тесте на провал в нашем проекте, поэтому следующим шагом была подготовка теста на провал в Envers, чтобы мы могли проверить, работает ли наше исправление.

Провал тест

Простейшие тестовые примеры, уже присутствующие в Envers, находятся в классе Simple.java, и они выглядят довольно просто:

public class Simple extends AbstractEntityTest {
    private Integer id1;

    public void configure(Ejb3Configuration cfg) {
        cfg.addAnnotatedClass(IntTestEntity.class);
    }

    @Test
    public void initData() {
        EntityManager em = getEntityManager();
        em.getTransaction().begin();
        IntTestEntity ite = new IntTestEntity(10);
        em.persist(ite);
        id1 = ite.getId();
        em.getTransaction().commit();

        em.getTransaction().begin();
        ite = em.find(IntTestEntity.class, id1);
        ite.setNumber(20);
        em.getTransaction().commit();
    }

    @Test(dependsOnMethods = "initData")
    public void testRevisionsCounts() {
        assert Arrays.asList(1, 2).equals(getAuditReader().getRevisions(IntTestEntity.class, id1));
    }

    @Test(dependsOnMethods = "initData")
    public void testHistoryOfId1() {
        IntTestEntity ver1 = new IntTestEntity(10, id1);
        IntTestEntity ver2 = new IntTestEntity(20, id1);

        assert getAuditReader().find(IntTestEntity.class, id1, 1).equals(ver1);
        assert getAuditReader().find(IntTestEntity.class, id1, 2).equals(ver2);
    }
}

поэтому подготовка моего сценария неудачного выполнения теста, описанного выше, не была ракетостроением:

/**
 * @author Tomasz Dziurko (tdziurko at gmail dot com)
 */
public class TransactionRollbackBehaviour  extends AbstractEntityTest {
 
    public void configure(Ejb3Configuration cfg) {
        cfg.addAnnotatedClass(IntTestEntity.class);
    }
 
    @Test
    public void testAuditRecordsRollback() {
        // Given
        EntityManager em = getEntityManager();
        em.getTransaction().begin();
        IntTestEntity iteToRollback = new IntTestEntity(30);
        em.persist(iteToRollback);
        Integer rollbackedIteId = iteToRollback.getId();
        em.getTransaction().rollback();
 
        // When
        em.getTransaction().begin();
        IntTestEntity ite2 = new IntTestEntity(50);
        em.persist(ite2);
        Integer ite2Id = ite2.getId();
        em.getTransaction().commit();
 
        // Then
        List<Number> revisionsForSavedClass = getAuditReader().getRevisions(IntTestEntity.class, ite2Id);
        assertEquals(revisionsForSavedClass.size(), 1, "There should be one revision for inserted entity");
 
        List<Number> revisionsForRolledbackClass = getAuditReader().getRevisions(IntTestEntity.class, rollbackedIteId);
        assertEquals(revisionsForRolledbackClass.size(), 0, "There should be no revisions for insert that was rolled back");
    }
}

Теперь я мог убедиться, что тесты не пройдены на разветвленной ветке 3.6,  и проверить, что исправление, которое у нас было, делает этот тест зеленым.

Исправление

После написания неудачного теста в нашем проекте я поместил несколько точек останова в код Envers, чтобы лучше понять, что там не так. Но представьте, что вас бросают в проект, разработанный несколькими годами умнее, чем вы, программистов. Я чувствовал себя подавленным и понятия не имел, где следует применить исправление, а что именно не работает, как ожидалось. К счастью, в моей компании у нас на борту Адам Варски. Он является первым автором Envers, и на самом деле он указал нам решение.

Само исправление содержит только одну проверку, которая регистрирует процессы аудита, которые будут выполняться при завершении транзакции, только когда такие процессы все еще находятся в  Map <Transaction, AuditProcess> для данной транзакции. Это звучит сложно, но если вы посмотрите на класс AuditProcessManager в этом коммите, должно быть более понятно, что там происходит.

Официальный путь

Помимо обнаружения проблемы и ее устранения, есть еще несколько официальных шагов, которые необходимо выполнить, чтобы включить исправление в Envers.

Шаг 1. Создание проблемы JIRA с ошибкой —  https://hibernate.onjira.com/browse/HHH-7682

Шаг 2: Создайте локальную ветку Envers-bugfix-HHH-7682  из разветвленного Hibernate 3.6

Шаг 3. Подтвердите и отправьте неудачный тест и исправьте его в локальном и удаленном репозитории на Github.

Шаг 4. Создание запроса извлечения —  https://github.com/hibernate/hibernate-orm/pull/393

Шаг 5: дождаться слияния

И это все. Теперь исправление объединено с основным репозиторием, и у нас меньше одной ошибки в мире открытого исходного кода.:)