¿Qué mide exactamente la creación de perfiles de C++ (herramientas de rendimiento de CPU de Google)?

Question

Estoy intentando comenzar con Google Perf Tools para perfilar algunas aplicaciones que hacen un uso intensivo de la CPU.Es un cálculo estadístico que vuelca cada paso en un archivo usando "ofstream".No soy un experto en C++, por lo que me cuesta encontrar el cuello de botella.Mi primera pasada da resultados:

Total: 857 samples
     357  41.7%  41.7%      357  41.7% _write$UNIX2003
     134  15.6%  57.3%      134  15.6% _exp$fenv_access_off
     109  12.7%  70.0%      276  32.2% scythe::dnorm
     103  12.0%  82.0%      103  12.0% _log$fenv_access_off
      58   6.8%  88.8%       58   6.8% scythe::const_matrix_forward_iterator::operator*
      37   4.3%  93.1%       37   4.3% scythe::matrix_forward_iterator::operator*
      15   1.8%  94.9%       47   5.5% std::transform
      13   1.5%  96.4%      486  56.7% SliceStep::DoStep
      10   1.2%  97.5%       10   1.2% 0x0002726c
       5   0.6%  98.1%        5   0.6% 0x000271c7
       5   0.6%  98.7%        5   0.6% _write$NOCANCEL$UNIX2003

Esto es sorprendente, ya que todo el cálculo real ocurre en SliceStep::DoStep.El "_write$UNIX2003" (¿dónde puedo saber qué es esto?) parece provenir de la escritura del archivo de salida.Ahora, lo que me confunde es que si comento todos los outfile << "text" declaraciones y ejecute pprof, el 95% está en SliceStep::DoStep y `_write$UNIX2003' desaparece.Sin embargo, mi aplicación no se acelera, según lo medido por el tiempo total.Todo esto se acelera menos del 1 por ciento.

¿Qué me estoy perdiendo?

Agregado:La salida pprof sin el outfile << declaraciones es:

Total: 790 samples
     205  25.9%  25.9%      205  25.9% _exp$fenv_access_off
     170  21.5%  47.5%      170  21.5% _log$fenv_access_off
     162  20.5%  68.0%      437  55.3% scythe::dnorm
      83  10.5%  78.5%       83  10.5% scythe::const_matrix_forward_iterator::operator*
      70   8.9%  87.3%       70   8.9% scythe::matrix_forward_iterator::operator*
      28   3.5%  90.9%       78   9.9% std::transform
      26   3.3%  94.2%       26   3.3% 0x00027262
      12   1.5%  95.7%       12   1.5% _write$NOCANCEL$UNIX2003
      11   1.4%  97.1%      764  96.7% SliceStep::DoStep
       9   1.1%  98.2%        9   1.1% 0x00027253
       6   0.8%  99.0%        6   0.8% 0x000274a6

Esto se parece a lo que esperaba, excepto que no veo un aumento visible en el rendimiento (0,1 segundo en un cálculo de 10 segundos).El código es esencialmente:

ofstream outfile("out.txt");
for loop:
  SliceStep::DoStep()
  outfile << 'result'
outfile.close()

Actualizar:Realizo el tiempo usando boost::timer, comenzando donde comienza el generador de perfiles y terminando donde termina.No uso hilos ni nada sofisticado.

Answer 1

De mis comentarios:

Los números que obtiene de su generador de perfiles dicen que el programa debería ser alrededor de un 40% más rápido sin las declaraciones impresas.

El tiempo de ejecución, sin embargo, se mantiene casi igual.

Obviamente, una de las medidas debe estar equivocada. Eso significa que tiene que hacer más y mejores mediciones.

Primero sugiero comenzar con otra herramienta fácil: el comando de tiempo. Esto debería darle una idea aproximada de dónde pasa su tiempo.

Si los resultados aún no son concluyentes, necesita un mejor caso de prueba:

• Usa un problema mayor
• Haga un calentamiento antes de medir. Haga algunos bucles e inicie cualquier medición después (en el mismo proceso).

---

  

Tiristan: Todo está en el usuario. Creo que lo que estoy haciendo es bastante simple ... ¿Significa algo el hecho de que el archivo esté abierto todo el tiempo?

Eso significa que el perfilador está equivocado.

Imprimir 100000 líneas en la consola usando python resulta en algo como:

for i in xrange(100000):
    print i

A la consola:

time python print.py
[...]
real    0m2.370s
user    0m0.156s
sys     0m0.232s

Versus:

time python test.py > /dev/null

real    0m0.133s
user    0m0.116s
sys     0m0.008s

Mi punto es: Sus mediciones internas y muestran que no obtiene nada al deshabilitar la salida. Google Perf Tools dice que deberías. ¿Quién está equivocado?

Answer 2

_write $ UNIX2003 probablemente se refiera a la llamada al sistema write POSIX, que se envía al terminal. La E / S es muy lenta en comparación con casi cualquier otra cosa, por lo que tiene sentido que su programa pase mucho tiempo allí si está escribiendo un poco de producción.

No estoy seguro de por qué su programa no se aceleraría cuando elimine la salida, pero realmente no puedo adivinar solo la información que ha proporcionado. Sería bueno ver parte del código, o incluso la salida de perftools cuando se elimina la declaración cout.

Answer 3

Google perftools recopila muestras de la pila de llamadas, por lo que lo que necesita es tener algo de visibilidad sobre ellas.

Según el documento, puede mostrar el gráfico de llamada en la declaración o la granularidad de la dirección. Eso debería decirle lo que necesita saber.