2009-07-07 15 views
5

He estado usando Yourkit 8.0 para perfilar una aplicación matemáticamente intensiva que se ejecuta bajo Mac OS X (10.5.7, Apple JDK 1.6.0_06-b06-57), y he notado algunas extrañas comportamiento en los resultados de perfiles de CPU.Perfilado de métodos nativos en Java - resultados extraños

Por ejemplo, hice una ejecución de generación de perfiles utilizando muestreo, que informó que el 40% del tiempo de ejecución de 10 minutos de la aplicación se gastó en el método StrictMath.atan. Encontré esto desconcertante, pero lo tomé por su palabra y pasé un poco de tiempo reemplazando atan con un ajuste polinomial extremadamente simple.

Cuando volví a ejecutar la aplicación, me tomó casi exactamente el mismo tiempo que antes (10 minutos), pero mi reemplazo atan no apareció en ninguna parte en los resultados del perfilado. En cambio, los porcentajes de tiempo de ejecución de los otros puntos de acceso principales simplemente aumentaron para compensarlo.

Para resumir:

resultados con StrictMath.atan (método nativo)
tiempo de ejecución total: 10 minutos
Método 1: 20%
Método 2: 20%
Método 3: 20%
StrictMath.atan: 40%

RESULTADOS CON simplificada de Java, pura atan
tiempo de ejecución total: 10 minu tes
Método 1: 33%
Método 2: 33%
Método 3: 33%

(Métodos 1,2,3 no realizan ninguna llamada atan)

Cualquier idea de lo que es con este comportamiento? Obtuve los mismos resultados usando el JProfiler de EJ-Technologies. Parece que la API de creación de perfiles JDK informa resultados inexactos para los métodos nativos, al menos en OS X.

+0

No me sorprendería si 'atan' fuera intrínseco: en lugar de llamar a un método, el código de máquina equivalente se inyecta en línea. –

+0

He experimentado esto también con varios métodos en StrictMath en Mac OS X 10.7 (y versiones anteriores también). –

+0

Entonces, ¿hay alguna solución a este problema? – ziggystar

Respuesta

3

Esto puede suceder debido a las inconsistencias de cuando se toman las muestras. Entonces, por ejemplo, si un método usa una cantidad de tiempo razonable, pero no tarda mucho en ejecutarse, es posible que el muestreo lo pierda. Además, creo que la recolección de basura nunca ocurre durante una muestra, pero si algún código provoca una gran cantidad de recolección de basura, puede contribuir en gran medida a una desaceleración sin aparecer en la muestra.

En una situación similar, me ha resultado muy útil ejecutar dos veces, una con rastreo y otra con muestreo. Si aparece un método en ambos, es probable que utilice una gran cantidad de CPU, de lo contrario, podría ser un artefacto del proceso de muestreo.

0

Me parece que YourKit exagera mucho el costo de llamar a los submétodos (debido a su método de registro, supongo). Si solo sigue los consejos que le da el perfil, terminará fusionando funciones sin ninguna ganancia real, ya que el HotSpot generalmente lo hace de manera excelente.

Por lo tanto, recomendaría probar lotes completamente fuera de los perfiles, para tener una mejor idea de si los cambios son realmente beneficiosos (puede parecer obvio, pero esto me costó algo de tiempo de desarrollo).

0

Dado que está utilizando una Mac, puede probar Apple's Shark profiler (descarga gratuita desde ADC) que tiene compatibilidad con Java y el grupo de rendimiento de Apple ha invertido una gran cantidad de tiempo en la herramienta.

Como señaló Nick, el muestreo puede ser engañoso si el intervalo de muestra es lo suficientemente cercano al tiempo de ejecución de la función y el perfilador rara vez verifica cuando la función realmente se está ejecutando. No sé si YourKit admite esto, pero en Shark puede cambiar el intervalo de muestreo a algo diferente a los 10 ms predeterminados y ver si los resultados son sustancialmente diferentes. También hay un modo de seguimiento de llamadas separado que registrará cada función de entrada/retorno; esto evita por completo la posibilidad de errores de alias, pero recoge una tonelada de datos y una sobrecarga superior, lo que podría importar si su aplicación realiza algún tipo de actividad en tiempo real tratamiento.

0

Es posible que desee consultar los parámetros que se pasan a los tres métodos. Puede ser que el tiempo se esté gastando generando valores devueltos o en métodos que están creando una gran cantidad de objetos temporales.

-1

Los perfiladores pueden ser así.

This is the method I use.

funciona todo el tiempo.

And this is why.

+0

¿Quiere explicar por qué esto conduce a resultados diferentes a los de un generador de perfiles de muestreo que automatiza este proceso? – ziggystar

+0

@ziggystar: Algunos perfiladores de muestreo automatizan la mitad del proceso, es decir, los que muestrean toda la pila, en el reloj de pared (no en la CPU). La mitad del proceso que no automatizan es el descubrimiento de problemas de rendimiento que puede solucionar. Si una declaración o función tiene un% inclusivo pequeño, entonces el problema está en otra parte, pero eso no se reduce donde el problema es mucho. Simplemente saber que una línea de código, función o "ruta" está "caliente" no le dice mucho. Es más revelador si puede examinar muestras representativas específicas, en su totalidad. ... –

+0

@ziggystar: ... El resultado diferente al que esto conduce es que encuentras aceleraciones que no encontrarás incluso con un muy buen perfilador. Cuando arreglas eso y repites el proceso, los problemas que antes eran pequeños ahora son un% más grande porque el programa toma menos tiempo. Entonces, uno por uno, arregla esto, y la aceleración compuesta puede ser sorprendente. ¿Cuánta aceleración obtuviste con un generador de perfiles? Si la respuesta es más del 40%, me sorprendería. –

0

Es digno de mención que los métodos de Java pueden ser inline si son lo suficientemente pequeñas, sin embargo los métodos nativos son inline bajo diferentes reglas. Si un método está en línea, no aparece en el generador de perfiles (ciertamente no en YourKit)

Cuestiones relacionadas