2012-08-28 35 views
14

Estoy usando Hibernate 4.1.6 y tengo problemas con la velocidad con la que se crea una lista. Estoy ejecutando la siguiente consulta.¿Por qué es lento Hibernate query.list()?

public void doQuery(final Baz baz){ 
    final Query query = getSessionFactory().getCurrentSession().createQuery(
      "select c.id, foo.someValue from Foo as foo "+ 
      "join foo.a as a"+ 
      "join foo.b as b "+ 
      "join b.c as c "+ 
      "where baz=:baz" 
     ); 
    query.setParameter("baz", baz); 
    Long start=System.currentTimeMillis(); 
    final List<Object[]> list = query.list(); 
    Long end=System.currentTimeMillis(); 
    System.out.println((end-start)); 
} 

Configuré la depuración de hibernación para obtener la consulta real que se envía a la base de datos. Ejecuté esa consulta directamente en la base de datos y devolvió 23,000 filas en 0.015 ms. Entonces, supongo que la consulta no es el problema. El ejemplo anterior muestra que tarda ~ 32 segundos en crear esa lista. ¿Hay algo que se pueda hacer para acelerar eso?

Actualización: Intenté usar el método createSQLQuery() usando la consulta de depuración de hibernación y se ejecutó tan lento como el método createQuery().

Actualización: Intenté usar una sesión sin estado, pero se ejecutó con la misma lentitud.

Actualización: Me emite algunas estadísticas (el establecimiento del indicador hibernate.generate_statistics true) pero nada parece alarmante para mí:

Hibernate SessionFactory Statistics [ 
    Number of connection requests[4] 
    Number of flushes done on the session (either by client code or by hibernate[3] 
    The number of completed transactions (failed and successful).[3] 
    The number of transactions completed without failure[3] 
    The number of sessions your code has opened.[4] 
    The number of sessions your code has closed.[3] 
    Total number of queries executed.[4] 
    Time of the slowest query executed.[28258] 
    the number of collections fetched from the DB.[6] 
    The number of collections loaded from the DB.[6] 
    The number of collections that were rebuilt[0] 
    The number of collections that were 'deleted' batch.[0] 
    The number of collections that were updated batch.[0] 
    The number of your objects deleted.[0] 
    The number of your objects fetched.[1] 
    The number of your objects actually loaded (fully populated).[204] 
    The number of your objects inserted.[1] 
    The number of your object updated.[0] 
] 

Hibernate SessionFactory Query Statistics [ 
    total hits on cache by this query[0] 
    total misses on cache by this query[0] 
    total number of objects put into cache by this query execution[0] 
    Number of times this query has been invoked[1] 
    average time for invoking this query.[28258] 
    maximum time incurred by query execution[28258] 
    minimum time incurred by query execution[28258] 
    Number of rows returned over all invocations of this query[23303] 
] 

Actualización: Veo la misma lentitud cuando se hace un lado() desde un ScrollableResults desde una consulta nativa Tenga en cuenta que no estoy haciendo nada en el bucle.

ScrollableResults results = query.scroll(); 
    Long start=System.currentTimeMillis(); 
    while (results.next()) { 
     //do nothing 
    } 
    Long end=System.currentTimeMillis(); 
    System.out.println((end-start)); 
+0

podría ser un uncommited transacción que contiene las obras. –

+1

Es posible que desee imprimir su sql de hibernación. Lo más probable es que tenga un problema de selección n + 1. –

+0

Jordan, no sé de ninguna transacción que contenga esta consulta. John, imprimí el sql como se menciona arriba y la consulta está bien. – user973479

Respuesta

7

no estoy 100% seguro en esta respuesta, ya que las cuestiones de sintonía/optimización son siempre tan difícil de determinar.

Sin embargo, basado en el hecho de que activó show_sql, extrajo la consulta y la ejecutó directamente contra la base de datos y vio resultados por debajo del segundo tiempo de ejecución a través de Hibernate Query, me estoy enfocando en la manera en que Hibernate construir e hidratar objetos que resultan de la llamada query.list().

Aquí hay otro usuario que menciona los problemas de rendimiento de consultas similares en hibernación, y se observó un aumento de rendimiento espectacular añadiendo constructores de conveniencia completos (constructores que aceptan un valor para cada campo) en el POJO: Simple hibernate query returning very slowly

suena como si tropezó con esta solución, y no había una comprensión clara de por qué funcionó. Hubo especulaciones sobre que Hibernate tuviera que usar la reflexión para detectar propiedades. Tengo curiosidad por mí mismo y estoy planeando profundizar en el código fuente de Hibernate para comprender mejor esto cuando tengo la oportunidad. Mientras tanto, sin embargo, es posible que desee considerar agregar estos constructores completos con parámetros para todos sus atributos de clase POJO y ver si eso hace la diferencia.

Háganme saber lo que encuentre, ya que estoy muy interesado en la optimización del rendimiento de Hibernate. ¡Gracias!

+0

Hola Philip, gracias por tu respuesta. Eché un vistazo a ese enlace y todos mis POJO tienen constructores completos. Lamentablemente, esa solución no se aplica a mi situación. – user973479

+0

Hmm, lástima, esperaba que eso ayudara. Parece que estás siendo muy cuidadoso en la solución de problemas, y realmente me gustaría ayudar. ¿Podrías publicar tus POJO? –

+0

Desafortunadamente no :( – user973479

4

Si las consultas (con show_sql) no parecen tener un problema, entonces tal vez esté en el código. Inicie VisualVM (viene con el JDK como jvisualvm) y use su perfilador de CPU para averiguar qué métodos toman más tiempo.

+0

Esta llamada particular a query.list es la culpable de la lentitud. Esperemos que alguien pueda proporcionar una idea de por qué ocurre este comportamiento y posiblemente una solución – user973479

+1

Quiero decir, ¿cuál de los métodos * llamado por * query.list() es el culpable? Excavar en el código de Hibernate para encontrar la causa raíz. –

+0

As mencionado anteriormente, no hay ninguno. – user973479

1

Ejecuté esa consulta directamente en la base de datos y devolvió 23,000 filas en 0.015 ms. Entonces, supongo que la consulta no es el problema.

Esto puede ser prematuro, ya que los tiempos de ejecución de la consulta dependen de mucho más que el texto de la consulta. Incluso si las consultas se ejecutan con los mismos datos, ¿cómo sabe que la base de datos utilizó el mismo plan de ejecución? ¿Cómo sabes que obtiene la misma cantidad de éxitos de caché en su caché de disco?Por ejemplo, hibernate usa declaraciones preparadas cuando habla con la base de datos, pero probablemente no. En Oracle, los planes de ejecución se almacenan en caché por texto de consulta, por lo que un texto de consulta diferente significa un plan de ejecución recién calculado. Como el plan de ejecución en caché puede haberse formado en función de diferentes parámetros de consulta, puede ser muy diferente, y eso puede cambiar los tiempos de ejecución en órdenes de magnitud. Tenga en cuenta que no estoy diciendo que es la base de datos, pero no descartaría la posibilidad.

Por lo tanto, lo primero que debe hacer es medir si la base de datos o algo que se ejecuta en su JVM está perdiendo todo ese tiempo. Una forma sencilla de hacerlo es observar el consumo de la CPU de las JVM a medida que se ejecuta la consulta. Si es significativamente menor que un hilo, la JVM está esperando algo, presumiblemente la base de datos.

Si se trata de la base de datos, use las herramientas de optimización de su base de datos para capturar el plan de ejecución y otras métricas de rendimiento relevantes.

Si está en la JVM, use un Analizador para identificar el cuello de botella de rendimiento.

0

Nos encontramos con un problema similar, no sé si está relacionado. Básicamente, desde que éramos Newing nuevas SessionFactorys una vez por consulta, que estaba haciendo preguntas como:

select streamref0_.UUID as UUID145_, streamref0_.Tape_TapeId as Tape2_145_ from StreamRefToTape streamref0_ where streamref0_.UUID=? 

Usted notará el gran número de allí. Resulta que se incrementa una vez por cada nueva sesión de fábrica. De todos modos, esto estaba causando que Oracle dedicara todo su tiempo a hacer un nuevo plan para cada consulta (informaba que la CPU estaba casi en un "análisis profundo" generando nuevos planes, supongo que Oracle tarda en generar planes que no ha visto). ¿antes de?). La solución en este caso particular era usar la misma fábrica en lugar de una nueva cada vez. Consulte también Hibernate produce different SQL for every query

http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:2588723819082 explica los análisis duros, que aparentemente son malos.

Otra posible solución es el uso de "SQL en bruto" (JDBC) o consultas SQL posiblemente primas dentro de hibernación, aunque eso no parece solucionar el problema en este caso particular de alguna manera ...