2010-09-07 11 views
10

Tengo un programa que copié de un libro de texto, y que mide la diferencia en el tiempo de ejecución de la ejecución del programa al calcular lo mismo con una matriz iniciada sin inicializar y vectores.Ejecución del programa de temporización en MATLAB; resultados extraños

Sin embargo, aunque el programa se ejecuta en cierta forma como se esperaba, si se ejecuta varias veces de vez en cuando dará un resultado loco loco. Vea a continuación el programa y un ejemplo de loco resultado.

clear all; clc; 

% Purpose: 
% This program calculates the time required to calculate the squares of 
% all integers from 1 to 10000 in three different ways: 
% 1. using a for loop with an uninitialized output array 
% 2. Using a for loop with a pre-allocated output array 
% 3. Using vectors 

% PERFORM CALCULATION WITH AN UNINITIALIZED ARRAY 
% (done only once because it is so slow) 

maxcount = 1; 
tic; 
for jj = 1:maxcount 
    clear square 
    for ii = 1:10000 
     square(ii) = ii^2; 
    end 
end 
average1 = (toc)/maxcount; 

% PERFORM CALCULATION WITH A PRE-ALLOCATED ARRAY 
% (averaged over 10 loops) 

maxcount = 10; 
tic; 
for jj = 1:maxcount 
    clear square 
    square = zeros(1,10000); 
    for ii = 1:10000 
     square(ii) = ii^2; 
    end 
end 
average2 = (toc)/maxcount; 

% PERFORM CALCULATION WITH VECTORS 
% (averaged over 100 executions) 

maxcount = 100; 
tic; 
for jj = 1:maxcount 
    clear square 
    ii = 1:10000; 
    square = ii.^2; 
end 
average3 = (toc)/maxcount; 

% Display results 
fprintf('Loop/uninitialized array = %8.6f\n', average1) 
fprintf('Loop/initialized array = %8.6f\n', average2) 
fprintf('Vectorized =     %8.6f\n', average3) 

Resultado - medio:

Loop/uninitialized array = 0.195286 
Loop/initialized array = 0.000339 
Vectorized =     0.000079 

Resultado - loca:

Loop/uninitialized array = 0.203350 
Loop/initialized array = 973258065.680879 
Vectorized =     0.000102 

Por qué sucede esto? (a veces el número loco está en vectorizado, a veces en bucle inicializado)

¿Dónde MATLAB "encontrar" ese número?

+0

¿Podría ser cuando el valor del reloj, almacenado en toc, se da la vuelta? – gary

+0

¿Qué versión de MATLAB estás usando? – gnovice

+0

@gnovice - 7.10.0.499 (2010a) – Rook

Respuesta

1

Existen al menos dos posibles fuentes de error. ¿Puedes tratar de diferenciar entre 'tic/toc' y 'fprintf' simplemente mirando los valores calculados sin formatearlos?

No entiendo las llaves alrededor de 'toc' pero no deberían hacer ningún daño.

+0

Sí, el promedio X realmente obtiene el valor grande. Entonces, el problema no está en las funciones fprintf. Los frenos son solo restos de algo que probé yo mismo, después de lo cual olvidé eliminarlos. No hacen daño. – Rook

+0

Qué sucede si aumenta el número de iteraciones (maxcount). ¿En qué plataforma estás trabajando? – zellus

+0

@Rook: También puede echar un vistazo a la siguiente publicación. Entonces, el final de la publicación y los comentarios son interesantes. http://undocumentedmatlab.com/blog/tic-toc-undocumented-option/ – zellus

3

Eso es realmente una locura. No sé qué podría causarlo y no pude reproducir en mi propia copia Matlab R2010a durante varias ejecuciones, invocadas por nombre o vía F5.

Aquí hay una idea para depurarlo.

Al usar tic/toc dentro de un script o función, use el formulario "tstart = tic" que captura el resultado. Esto hace que sea seguro usar llamadas anidadas de tic/toc (por ejemplo, dentro de las funciones llamadas), y le permite atenerse a múltiples tiempos de inicio y transcurridos y examinarlos mediante programación.

t0 = tic; 
% ... do some work ... 
te = toc(t0); % "te" for "time elapsed" 

Se pueden utilizar diferentes sufijos "t0_label" para cada una de las tic y toc devoluciones, o almacenarlos en un vector, por lo que ellos conservar hasta el final de su script.

t0_uninit = tic; 
% ... do the uninitialized-array test ... 
te_uninit = toc(t0_uninit); 

t0_prealloc = tic; 
% ... test the preallocated array ... 
te_prealloc = toc(t0_prealloc); 

Haga que la secuencia de comandos entre en el depurador cuando encuentre uno de los valores grandes.

if any([te_uninit te_prealloc te_vector] > 5) 
    keyboard 
end 

Luego puede examinar el espacio de trabajo y los valores de retorno de tic, lo que podría proporcionar algunas pistas.


EDIT: También podría intentar probar tic() por sí solo para ver si hay algo extraño con el reloj del sistema, o lo que sea TIC/TOC está llamando. El valor de retorno de tic() parece una marca de tiempo nativa de algún tipo. Intente llamarlo muchas veces seguidas y comparando los valores subsiguientes. Si alguna vez retrocede, eso sería sorprendente.

function test_tic 

t0 = tic; 
for i = 1:1000000 
    t1 = tic; 
    if t1 <= t0 
     fprintf('tic went backwards: %s to %s\n', num2str(t0), num2str(t1)); 
    end 
    t0 = t1; 
end 

En Matlab R2010b (preliminar), que tiene matemáticas Int64, puede reproducir un resultado similar por parte toc ridícula jiggering la referencia tic valor para que sea "en el futuro". Parece un efecto de rollover int, como lo sugiere gary comtois.

>> t0 = tic; toc(t0+999999) 
Elapsed time is 6148914691.236258 seconds. 

Esto sugiere que si había alguna fluctuación en el temporizador que toc estaban usando, es posible obtener antivuelco si ocurre mientras estás sincronización operaciones muy cortos. (Supongo que toc() internamente hace algo así como tic() para obtener un valor para comparar la entrada.) Aumentar el número de iteraciones podría hacer que el efecto desaparezca porque una pequeña cantidad de fluctuación del reloj sería menos significativa como parte de un período más largo. períodos tic/toc. También explicaría por qué no ve esto en su prueba no preasignada, que lleva más tiempo.


ACTUALIZACIÓN: Pude reproducir este comportamiento. Estaba trabajando en un código no relacionado y descubrí que en una computadora de escritorio en particular con un modelo de CPU que no habíamos utilizado anteriormente, un quad core Core 2 Q8400 2.66 GHz, tic estaba dando resultados inexactos. Parece un error dependiente del sistema en tic/toc.

En esta máquina en particular, tic/toc regularmente informará valores extrañamente altos como el suyo.

>> for i = 1:50000; t0 = tic; te = toc(t0); if te > 1; fprintf('elapsed: %.9f\n', te); end; end 
elapsed: 6934787980.471930500 
elapsed: 6934787980.471931500 
elapsed: 6934787980.471899000 
>> for i = 1:50000; t0 = tic; te = toc(t0); if te > 1; fprintf('elapsed: %.9f\n', te); end; end 
>> for i = 1:50000; t0 = tic; te = toc(t0); if te > 1; fprintf('elapsed: %.9f\n', te); end; end 
elapsed: 6934787980.471928600 
elapsed: 6934787980.471913300 
>> 

Va más allá de eso. En esta máquina, tic/toc informará regularmente el tiempo transcurrido para las operaciones, especialmente para tareas de bajo uso de la CPU.

>> t0 = tic; c0 = clock; pause(4); toc(t0); fprintf('Wall time is %.6f seconds.\n', etime(clock, c0)); 
Elapsed time is 0.183467 seconds. 
Wall time is 4.000000 seconds. 

lo que parece que este es un error en TIC/TOC que se relaciona con determinados modelos de CPU (o algo más específico para la configuración del sistema). He informado el error a MathWorks.

Esto significa que tic/toc probablemente le da resultados inexactos, incluso cuando no produce esos números increíblemente grandes. Como solución alternativa, en esta máquina, use etime() y solo dedique tiempo a trozos de trabajo más largos para compensar la menor resolución de etime. Podría envolverlo en sus propias funciones tic/toc que usan la prueba i = 1: 50000 para detectar cuándo se rompe el tic en la máquina actual, usar tic/toc normalmente y hacer que lo adviertan y vuelvan a utilizar etime() en sistemas rotos-tic.

ACTUALIZACIÓN 2012-03-28: He visto esto en la naturaleza por un tiempo, y es muy probable debido a una interacción con el temporizador de alta resolución y escalado de velocidad de la CPU, y (en Windows) QueryPerformanceCounter, como se describe aquí: http://support.microsoft.com/kb/895980/. No es un error en tic/toc, el problema está en las características del sistema operativo que tic/toc está llamando. Establecer un parámetro de arranque puede solucionarlo.

+0

Aunque todavía no estoy seguro de la causa, parece que aumentar ... uhmm; si pudieras leer mi comentario a zellus para no repetirlo aquí. Me voy a probar esto también ahora. – Rook

+0

buena explicación, me ayuda a resolver mi problema. – Yasin

2

aquí está mi teoría acerca de lo que podría estar sucediendo, sobre la base de estos dos datos que he encontrado:

  • Hay una función maxNumCompThreads que controla el número máximo de subprocesos de cálculo utilizados por MATLAB para realizar tareas. Citando la documentación:

    Por defecto, MATLAB hace uso de las capacidades de multithreading del equipo sobre el que se está ejecutando.

    Lo que me lleva a pensar que tal vez se ejecutan varias copias de su script al mismo tiempo.

  • This newsgroup thread se describe un error en una versión anterior de MATLAB (R14) "en la forma en que MATLAB acelera M-código con variables de estructura mundial", que parece que el TIC/TOC funciones pueden utilizar. La solución que había que desactivar el acelerador con el indocumentado FEATURE función:

    feature accel off 
    

Poner estas dos cosas juntas, me pregunto si las múltiples versiones de la secuencia de comandos que se ejecutan en el espacio de trabajo pueden ser simultáneamente restablecer las variables globales utilizadas por las funciones TIC/TOC y atornillar entre sí. Quizás esto no sea un problema al convertir su script a una función como lo hizo Amro, ya que esto separaría los espacios de trabajo en los que se ejecutan los dos programas (es decir, no se ejecutarían en el área de trabajo principal).

Esto también podría explicar los números excesivamente grandes que obtiene. Como han señalado Gary y Andrew, estos números parecen ser debidos a un efecto de vuelco entero (es decir, un integer overflow) por el cual el tiempo de inicio (desde TIC) es mayor que el tiempo de finalización (desde TOC). Esto daría como resultado un gran número que sigue siendo positivo porque TIC/TOC están usando internamente sin signo enteros de 64 bits como medidas de tiempo. Consideremos el siguiente escenario posible con dos secuencias de comandos se ejecuta al mismo tiempo en diferentes hilos:

  1. El primer subproceso llama TIC, la inicialización de una variable global a una medida de tiempo de inicio (es decir, la hora actual).
  2. El primer subproceso llama a TOC y la acción inmediata que probablemente realice la función TOC es obtener la medida de tiempo actual.
  3. El segundo hilo llama a TIC, reiniciando la medida del tiempo de inicio global a la hora actual, que es posterior a el tiempo que acaba de medir la función TOC para el primer hilo.
  4. La función TOC para el primer subproceso tiene acceso a la medida del tiempo de inicio global para obtener la diferencia entre él y la medida que tomó previamente. Esta diferencia daría como resultado un número negativo, excepto que las medidas de tiempo son enteros sin signo. Esto da como resultado un desbordamiento de enteros, dando un gran número positivo para la diferencia de tiempo.

Entonces, ¿cómo podría evitar este problema? Cambiar las secuencias de comandos a funciones como Amro lo hizo es probablemente la mejor opción, ya que eso parece eludir el problema y evita que el espacio de trabajo se llene. Una solución alternativa alternativa que podría intentar es establecer el número máximo de hilos computacionales para uno:

maxNumCompThreads(1); 

Esto debe mantener múltiples copias de la secuencia de comandos se ejecute al mismo tiempo, en el espacio de trabajo principal.

+0

Consideré el efecto de la secuencia de comandos frente a la función, y también el efecto de JIT cuando se ejecutan cosas en vivo en la línea de comandos frente a ejecutar un archivo m guardado. Todavía no pude reproducir el problema (estoy ejecutando la misma versión de MATLAB y el sistema operativo como OP). Esto podría ser un error de condición de carrera – Amro

+0

@Amro: Desafortunadamente, no tengo la misma versión de MATLAB que el OP, así que no puedo intentar reproducirlo. * Puedo * decir que no he podido reproducirlo en R2009a. Sin R2010a, lo anterior es mi mejor estimación. ;) – gnovice

1

Aquí hay una hipótesis que es comprobable. Los tic()/toc() de Matlab tienen que estar usando un temporizador de alta resolución. En Windows, debido a que su valor de retorno parece ciclos de reloj, creo que están usando la llamada Win32 QueryPerformanceCounter(), o tal vez algo más golpeando el contador de marca de tiempo RDTSC de la CPU. Estos aparentemente tienen fallas en algunos sistemas multiprocesador, mencionados en los artículos vinculados. Tal vez su máquina sea una de ellas, obteniendo resultados diferentes si el proceso de Matlab se mueve desde el núcleo al núcleo mediante el programador del proceso.

http://msdn.microsoft.com/en-us/library/ms644904(VS.85).aspx

http://www.virtualdub.org/blog/pivot/entry.php?id=106

Esta configuración de hardware y el sistema sería dependiente, lo que explicaría por qué los otros críticos no han sido capaces de reproducirlo.

Intente utilizar el Administrador de tareas de Windows para establecer la afinidad en su proceso de matlab.exe a una sola CPU. (En la pestaña Procesos, haga clic con el botón derecho en MATLAB.exe, "Establecer afinidad ...", desmarque todo menos CPU 0.) Si el tiempo loco desaparece mientras se establece la afinidad, parece que encontró la causa.

En cualquier caso, la solución parece simplemente aumentar la cuenta máxima, por lo que está temporizando trabajos más largos, y el ruido que aparentemente obtiene en tic()/toc() es pequeño en comparación con el valor medido. (No querrá tener que perder el tiempo con la afinidad de la CPU; se supone que Matlab es fácil de ejecutar.) Si hay un problema que está causando un desbordamiento interno, los otros pequeños números positivos también son un poco sospechosos. Además, el tiempo de alta resolución en un lenguaje de alto nivel como Matlab es un poco problemático. Las cargas de trabajo de sincronización hasta un par de cientos de microsegundos las somete al ruido de otras condiciones transitorias en el estado de su máquina.

Cuestiones relacionadas