2009-07-07 29 views
34

estoy tratando de comprender los valores que se muestran en kcachegrind en el panel izquierdoKCachegrind interpretación confusión

tengo Incl. (Que he leído en el manual es incluido), Ser, llama función

Ahora estoy analizando este archivo Cachegrind y tengo

Incl. ---- Self ---- Called ---- Function 

100.05 ---- 0.04 ---- (0) ---- {main} 

83.38 ---- 0.07 ---- 250 --- item->close 

78.85 ---- 78.85 ---- 10 067 ---- php::mysql_query 

y la lista continúa ..

Pero aquí es mi problema.

Creo que el elemento-> cerrar es mi cuello de botella, pero lo que no entiendo es cómo tiene 83.38 de Inclusive y luego 0.07 de Self y el comando mysql_query tiene el mismo en ambos.

¿Qué significa "sí" aquí?

¿Cómo se relacionan estos porcentajes entre sí? No entiendo cómo el Item-> unido ocupa el 83% y el 78% toma mysql_query

Gracias

Respuesta

55

"sí" significa que el tiempo empleado por esa función, pero no de cualquier función que llama. Si "sí mismo" es bajo y "incl." es alto, entonces el mejor lugar para optimizar es probablemente uno de los niños (por ejemplo, funciones llamadas). En este caso, parece que la consulta mysql toma la mayor parte del tiempo, por lo que probablemente desee optimizar la consulta (si es posible). La razón por la cual mysql_qeury tiene "self" == "incl." es que el generador de perfiles no puede ver la función, ya que está haciendo su trabajo fuera del php-runtime (por ejemplo, en la biblioteca del cliente mysql)

Podría agregar que 10067 llamadas a mysql_query se ven muy sospechosas. Una consulta de base de datos es una operación muy costosa. ¿Estás seguro de que no puedes reducir el número de consultas de alguna manera?

Editar:

puedo intentar. ¿Pero qué hay del Incl.? ¿Cómo es 80 en el cierre y luego 70 en la consulta de mysql cómo se relaciona eso con el porcentaje total que debe ser 100%

No es necesario que los números se sumen. Lo que estás viendo es una lista ordenada del tiempo del todo que toman estas funciones. No es un gráfico de llamadas (aunque a menudo sucederá que imita eso de alguna manera).

Supongamos el siguiente código:

function fn1() { 
    sleep(1); 
    fn2(); 
} 
function fn2() { 
    sleep(98); 
} 
function fn3() { 
    sleep(1); 
} 
fn1(); 
fn3(); 

Lo que podría generar el siguiente resultado: "incl"

name | incl. | self 
main | 100% | 0% 
fn1 | 99% | 1% 
fn2 | 98% | 98% 
fn3 | 1% | 1% 

Al ordenar la lista por, usted está buscando en las funciones que son lentos en total. En otras palabras, aquellos que puntúan alto aquí, no son necesariamente lentos, pero llaman a otras funciones que sí lo son. Si una función tiene un puntaje alto en "incl." y tiene muchas llamadas, debe buscar reducir la cantidad de llamadas a esta función o dejar que la función guarde su resultado (solo funciona si se trata de una consulta, no de una acción).

Cuando ordena por "sí mismo", verá las llamadas reales que ocupan más tiempo. Estas son las funciones que te gustaría ajustar. En la mayoría de los scripts de PHP, encontrará que mysql_query domina este campo. Si tiene muchas llamadas, nuevamente intente reducirlas o almacenarlas en caché. Si tiene pocas llamadas, entonces probablemente necesite optimizar la consulta sql. El depurador de PHP no puede ayudarte con esto. En su lugar, encuentre la consulta real y ejecute un explain en la consola mysql. Eso es todo un capítulo en sí mismo.

+0

puedo tratar. Pero ¿qué pasa con el Incl.? ¿Cómo es 80 al final y luego 70 en la consulta de MySQL? ¿Cómo se relaciona eso con el porcentaje total que debería ser del 100%? – AntonioCS

+0

¿Quería llamar a fn1() dentro de fn1()? Esto causará un bucle infinito – AntonioCS

+0

@Antonio: tienes razón, eso fue un error tipográfico. Lo he corregido ahora. – troelskn

12

Auto significa el tiempo dedicado a la función excluyendo las funciones que llama.

Por ejemplo:

function foo() 
{ 
    bar(); 
} 

function bar 
{ 
    sleep(1); 
} 

foo(); 

Esto le dará:

Incl Self Func 
1  0  foo 
1  0  bar 
1  1  sleep <- Here's the bottleneck! 
Cuestiones relacionadas