Все запросы Hibernate мрут на одной и той же табличке (из других тулз - нет)

 
 
 
Сообщения:37
Приветствую. Столкнулся с какой-то не понятной для меня странностью Hibernate+Postgres, которую даже не знаю как описать. Есть табличка из 37 колонок и 400 000 строк.
Несколько потоков в Java одновременно работают с ней через Hibernate. В основном на SELECT. Потоки получают сессию через sessionFactory.getCurrentSession(), начинают транзакцию, выполняют выборку и делают коммит транзакции (session.beginTransaction() / session.createQuery() / session.getTransaction().commit()).

Конфиг:
Quote:
<session-factory>
<property name="connection.url">jdbc:postgresql://localhost:5432/dbname</property>
<property name="connection.driver_class">org.postgresql.Driver</property>
<property name="connection.username">name</property>
<property name="connection.password">pass</property>
<property name="hibernate.current_session_context_class">thread</property>
<property name="hibernate.cache.use_query_cache">false</property>
...дальше маппинг...
</session-factory>


Пример проблемного кода:
    public static List<WebStruct> getReadyToContentLinksParse() {
        Session session = HibernateUtil.getSession();
        session.beginTransaction();
        List<WebStruct> result = session.createQuery(
                "FROM WebStruct w WHERE w.contentLength != w.contentLengthLinksParsed"
        )
                .setMaxResults(50)
                .getResultList();
        session.getTransaction().commit();
        return result;
    }


Беда вот в чём. Какое-то время назад, постепенно, потоки связанные с этой единственной табличкой стали тормозить. Сейчас уже тормозят очень заметно (на 1 простой запрос 30-40 минут, как раз та функция выше выполняется это время). Пытаюсь дебажить так :
- Беру тормозящий запрос, пишу его руками (в коде он в HQL) и пихаю в pgadmin/psql. Работает отлично, миллисекунды.
- Делаю show_sql=true, беру запрос прям от Гибернейта, сую в pgadmin/psql - всё идеально.
- Когда поток(и) виснет на запросе, иду смотреть pg_stat_activity. Запроса там нет.
- Когда поток(и) виснет на запросе, иду выполнять его же в psql/pgadmin (подозрение на блок таблицы) - всё идеально.
- В логе медленных запросов (>10 сек) всех проблемных запросов к табличке тоже нет.

Из этого делаю вывод, что проблема не в бд. Остаётся сам гибернейт. Как понять куда он девает такое огромное кол-во времени получив 50 строчек из таблицы и так и не заканчивая работу 40 минут?
P.S. Эти 50 строчек (из примера кода выше) не имеют через чур длинных полей (бинарные, лонгтексты и пр.). Это набор интов и varchar-ов до 100 символов длиною.
Изменен:06 июн 2020 06:38
 
 
Сообщения:9995
Всякий раз когда есть проблемы с производительностью, первое что лучше предпринимать - это снимать thread dump. Тогда будет видно в каких методах счас находятся потоки.

Твоя проблема в том что ты вытаскиваешь много entities. Все эти сущности помещаются в Session (а точнее в PersistenceContext) и живут там пока сессия либо не закроется, либо не будет сделан session.clear(). Эти сущности отдаются наружу (в твой код) и ты с ними можешь работать, в том числе модифицировать. Хиб также хранит копию всех этих данных, и когда ты меняешь объекты он может сравнить изначальные данные с сущностями которые были отданы в клиентский код. Это называется dirty checks, и так Хиб определяет нужно ли производить UPDATE. И если они поменялись, то Хиб таки производит этот UPDATE.

Все эти UPDATE/INSERT запросы Хиб откладывает пока может. Т.е. если меняется какая-то сущность, то UPDATE не произойдет сразу - Хиб даже и не знает пока что что-то поменялось. Есть два события которые провоцируют flush (и соответственно dirty checks) - это коммит транзакции либо select запрос. Т.е.:
1. Вытаскиваются 100 сущностей, допустим 50 из них обновилось. Пока Хиб ничего не знает об этом.
2. Клиентский код говорит Хибу закоммитить транзакцию (либо делает select запрос)
3. Хиб вынужден сделать flush() и соответственно dirty checks. Он проходится по 100 сущностям, сравнивает с изначальными данными
4. Видит что 50 из них обновилось - генерирует 50 UPDATE'ов
5. Ну а затем уже делает что попросил пользователь - коммитит транзакцию или делает select запрос

100 сущностей проверятся быстро, но 10000 сущностей.. Это займет время. И имей в виду что сессия не закрывается по коммиту транзакции. Т.е. если после этого начнется еще одна транзакция и будут вытаскиваться еще 10000 сущностей, то в сессии окажутся их уже 20000. И будет два dirty check'a - сначала перед select'ом, а затем перед коммитом.

Чтоб избежать этой проблемы нужно выгребать сущности пачками, затем вручную вызывать session.clear().

PS: все это справедливо для дефолтного FlushMode=AUTO, есть и другие которые реагируют на другие события либо вообще не реагируют ни на что. Например, если выставишь MANUAL (NEVER), то не важно - select или commit - Хиб не будет делать dirty checks & flush(). В таком случае ты сам должен контролировать флуш.
 
 
Сообщения:37
Староверъ:
Всякий раз когда есть проблемы с производительностью, первое что лучше предпринимать - это снимать thread dump. Тогда будет видно в каких методах счас находятся потоки.

Твоя проблема в том что ты вытаскиваешь много entities. Все эти сущности помещаются в Session (а точнее в PersistenceContext) и живут там пока сессия либо не закроется, либо не будет сделан session.clear(). Эти сущности отдаются наружу (в твой код) и ты с ними можешь работать, в том числе модифицировать. Хиб также хранит копию всех этих данных, и когда ты меняешь объекты он может сравнить изначальные данные с сущностями которые были отданы в клиентский код. Это называется dirty checks, и так Хиб определяет нужно ли производить UPDATE. И если они поменялись, то Хиб таки производит этот UPDATE.

Все эти UPDATE/INSERT запросы Хиб откладывает пока может. Т.е. если меняется какая-то сущность, то UPDATE не произойдет сразу - Хиб даже и не знает пока что что-то поменялось. Есть два события которые провоцируют flush (и соответственно dirty checks) - это коммит транзакции либо select запрос. Т.е.:
1. Вытаскиваются 100 сущностей, допустим 50 из них обновилось. Пока Хиб ничего не знает об этом.
2. Клиентский код говорит Хибу закоммитить транзакцию (либо делает select запрос)
3. Хиб вынужден сделать flush() и соответственно dirty checks. Он проходится по 100 сущностям, сравнивает с изначальными данными
4. Видит что 50 из них обновилось - генерирует 50 UPDATE'ов
5. Ну а затем уже делает что попросил пользователь - коммитит транзакцию или делает select запрос

100 сущностей проверятся быстро, но 10000 сущностей.. Это займет время. И имей в виду что сессия не закрывается по коммиту транзакции. Т.е. если после этого начнется еще одна транзакция и будут вытаскиваться еще 10000 сущностей, то в сессии окажутся их уже 20000. И будет два dirty check'a - сначала перед select'ом, а затем перед коммитом.

Чтоб избежать этой проблемы нужно выгребать сущности пачками, затем вручную вызывать session.clear().

PS: все это справедливо для дефолтного FlushMode=AUTO, есть и другие которые реагируют на другие события либо вообще не реагируют ни на что. Например, если выставишь MANUAL (NEVER), то не важно - select или commit - Хиб не будет делать dirty checks & flush(). В таком случае ты сам должен контролировать флуш.


Благодарю. Верно ли я понимаю, что нужно стараться уходить от повсеместного юза Entity и юзать простые выборки отдельных полей по возможности? Особенно если апдейта инфы не намечается.

Сделал дамп, но не пойму в чём там дело. Всё висит после вызова получения одной конкретной Entity по id.

Quote:
"Thread-584" #615 daemon prio=5 os_prio=0 tid=0x00007f94f9252800 nid=0x276 runnable [0x00007f9315213000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431)
at sun.security.ssl.OutputRecord.write(OutputRecord.java:417)
at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:886)
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:857)
at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:123)
- locked <0x000000031649ca80> (a sun.security.ssl.AppOutputStream)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
- locked <0x000000031649cb00> (a java.io.BufferedOutputStream)
at org.postgresql.core.PGStream.flush(PGStream.java:527)
at org.postgresql.core.v3.QueryExecutorImpl.sendSync(QueryExecutorImpl.java:1365)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306)
- locked <0x00000003164815b8> (a org.postgresql.core.v3.QueryExecutorImpl)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:143)
at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:106)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:353)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:71)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.getResultSet(AbstractLoadPlanBasedLoader.java:434)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:186)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:121)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at org.hibernate.loader.collection.plan.AbstractLoadPlanBasedCollectionInitializer.initialize(AbstractLoadPlanBasedCollectionInitializer.java:87)
at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:688)
at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:75)
at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:2183)
at org.hibernate.collection.internal.AbstractPersistentCollection$4.doWork(AbstractPersistentCollection.java:565)
at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:247)
at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:561)
at org.hibernate.collection.internal.AbstractPersistentCollection.forceInitialization(AbstractPersistentCollection.java:729)
at org.hibernate.engine.internal.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistenceContext.java:926)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:149)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:167)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4073)
at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:508)
at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:478)
at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:219)
at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:262)
at org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:121)
at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:89)
at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1237)
at org.hibernate.internal.SessionImpl.access$1900(SessionImpl.java:203)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.doLoad(SessionImpl.java:2798)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2772)
at org.hibernate.internal.SessionImpl.get(SessionImpl.java:1073)
at sun.reflect.GeneratedMethodAccessor412.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.hibernate.context.internal.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:355)
at com.sun.proxy.$Proxy34.get(Unknown Source)
at Services.SessionService.get(SessionService.java:51)
at Services.WebStructService.getParentOfStruct(WebStructService.java:32)
at Services.WebStructService.getPathOfStruct(WebStructService.java:55)
at Services.WebStructService.getUrlOfStruct(WebStructService.java:81)
at Services.WebStructService.getOrCreateStructOfSiteByNameAndParent(WebStructService.java:129)
at Services.WebStructService.addUrlAsWebStructs(WebStructService.java:673)
at Services.WebStructService.addUrlsAsWebStructs(WebStructService.java:621)
at Threads.ContentLinksParserThread.run(ContentLinksParserThread.java:36)


Вот метод SessionService.get()

    public static <T> T get(Class<T> classvar, int id) {
        Session session = HibernateUtil.getSession();
        session.beginTransaction();
        T result = session.get(classvar, id);
        session.getTransaction().commit();
        return result;
    }


Верна ли моя догадка, что пытаясь получить сущность с конкретным ID оказывается что она занята и поток подвисает в ожидании того как сущность станет свободной? Также странно что в конце трейса стоит запись в сокет...
 
 
Сообщения:9995
Kuzya59:
Верно ли я понимаю, что нужно стараться уходить от повсеместного юза Entity и юзать простые выборки отдельных полей по возможности?
Так тоже можно, но можно просто уменьшить размер батчей, поменять flush mode и/или делать session.clear().

По тред дампу - в этот момент явно jdbc driver шлет запрос в БД. Дамп снят во время зависшего потока? Можешь еще пару раз снять и убедиться что застревает там. Если это так, то все что я писал (что проблема с dirty checks) - это не правда для твоего случая.

Kuzya59:
Верна ли моя догадка, что пытаясь получить сущность с конкретным ID оказывается что она занята и поток подвисает в ожидании того как сущность станет свободной? Также странно что в конце трейса стоит запись в сокет...
Нет, сущность не может быть "занятой". Она может быть заблокированной - записи и таблицы БД могут блокироваться во время UPDATE/INSERT, однако на SELECT это не влияет. Но ты говорил что у тебя нет записи в БД, а значит некому блокировать. А вот выполняя SELECT FOR UPDATE можно блокировать чтение, но такого у тебя вроде нет.
Изменен:08 июн 2020 11:41
 
Модераторы:Нет
Сейчас эту тему просматривают:Нет