java - ¿Por qué dos bucles separados son más rápidos que uno?

performance optimization

Question

Quiero entender qué tipo de optimizaciones hace Java para los bucles consecutivos. Más precisamente, estoy tratando de comprobar si se realiza la fusión de bucle. Teóricamente, esperaba que esta optimización no se hiciera automáticamente y esperaba confirmar que la versión fusionada era más rápida que la versión con dos bucles.

Sin embargo, después de ejecutar los puntos de referencia, los resultados muestran que dos bucles separados (y consecutivos) son más rápidos que un solo bucle haciendo todo el trabajo.

Ya intenté usar JMH para crear los puntos de referencia y obtuve los mismos resultados.

Utilicé el comando javap y muestra que el bytecode generado para el archivo de origen con dos bucles corresponde en realidad a dos bucles que se están ejecutando (no se realizó el desenrollado del bucle ni se realizó otra optimización).

Código que se mide para BenchmarkMultipleLoops.java :

private void work() {
        List<Capsule> intermediate = new ArrayList<>();
        List<String> res = new ArrayList<>();
        int totalLength = 0;

        for (Capsule c : caps) {
            if(c.getNumber() > 100000000){
                intermediate.add(c);
            }
        }

        for (Capsule c : intermediate) {
            String s = "new_word" + c.getNumber();
            res.add(s);
        }

        //Loop to assure the end result (res) is used for something
        for(String s : res){
            totalLength += s.length();
        }

        System.out.println(totalLength);
    }

Código que se mide para BenchmarkSingleLoop.java :

private void work(){
        List<String> res = new ArrayList<>();
        int totalLength = 0;

        for (Capsule c : caps) {
            if(c.getNumber() > 100000000){
                String s = "new_word" + c.getNumber();
                res.add(s);
            }
        }

        //Loop to assure the end result (res) is used for something
        for(String s : res){
            totalLength += s.length();
        }

        System.out.println(totalLength);
    }

Y aquí está el código para Capsule.java :

public class Capsule {
    private int number;
    private String word;

    public Capsule(int number, String word) {
        this.number = number;
        this.word = word;
    }

    public int getNumber() {
        return number;
    }

    @Override
    public String toString() {
        return "{" + number +
                ", " + word + ''}'';
    }
}

caps es una ArrayList<Capsule> con 20 millones de elementos rellenados como este al principio:

private void populate() {
        Random r = new Random(3);

        for(int n = 0; n < POPSIZE; n++){
            int randomN = r.nextInt();
            Capsule c = new Capsule(randomN, "word" + randomN);
            caps.add(c);
        }
    }

Antes de medir, se ejecuta una fase de calentamiento.

Ejecuté cada uno de los puntos de referencia 10 veces o, en otras palabras, el método work() se ejecuta 10 veces para cada punto de referencia y los tiempos promedio para completar se presentan a continuación (en segundos). Después de cada iteración, el GC se ejecutó junto con algunos tiempos de espera:

• MultipleLoops: 4.9661 segundos
• SingleLoop: 7.2725 segundos

OpenJDK 1.8.0_144 se ejecuta en un Intel i7-7500U (Kaby Lake).

¿Por qué la versión de MultipleLoops es más rápida que la versión de SingleLoop, aunque tiene que atravesar dos estructuras de datos diferentes?

ACTUALIZACIÓN 1:

Como se sugiere en los comentarios, si cambio la implementación para calcular la totalLength mientras se generan las cadenas, evitando la creación de la lista de res , la versión de bucle único se vuelve más rápida.

Sin embargo, esa variable solo se introdujo de manera que se realizó algún trabajo después de crear la lista de resultados, para evitar descartar los elementos si no se hizo nada con ellos.

En otras palabras, el resultado previsto es producir la lista final . Pero esta sugerencia ayuda a comprender mejor lo que está sucediendo.

Resultados:

• MultipleLoops: 0.9339 segundos
• SingleLoop: 0.66590005 segundos

ACTUALIZACIÓN 2:

Aquí hay un enlace para el código que usé para el punto de referencia JMH: https://gist.github.com/FranciscoRibeiro/2d3928761f76e4f7cecfcfcdf7fc96d5

Resultados:

• MultipleLoops: 7.397 segundos
• SingleLoop: 8,092 segundos

Answer 1

Investigué este "fenómeno" y parece que obtuve algo así como una respuesta.
.jvmArgs("-verbose:gc") a OptionsMuilder de OptionsBuilder . Resultados para 1 Iteración:

Single Loop: [Full GC (Ergonomics) [PSYoungGen: 2097664K-> 0K (2446848K)] [ParOldGen: 3899819K-> 4574771K (5592576K) space_pinsk , 5.0438301 secs] [Tiempos: usuario = 37.92 sys = 0.10, real = 5.05 secs] 4.954 s / op

Múltiples Bucles: [Full GC (Ergonomics) [PSYoungGen: 2097664K-> 0K (2446848K)] [ParOldGen: 3899819K-> 4490913K (5592576K)] 5997483K-> 4490913K (8039424K), [Metas) , 3.7991573 segundos] [Tiempos: usuario = 26.84 sys = 0.08, real = 3.80 segundos] 4.187 s / op

JVM gastó gran cantidad de tiempo de CPU para GC. Una vez por 2 ejecuciones de prueba, JVM tiene que hacer Full GC (mover 600Mb a OldGen y recolectar 1.5Gb de basura de los ciclos anteriores). Ambos recolectores de basura realizaron el mismo trabajo, pero pasaron ~ 25% menos de tiempo de aplicación para el caso de prueba de múltiples bucles. Si disminuimos el POPSIZE a 10_000_000 o lo agregamos antes de bh.consume() Thread.sleep(3000) , o agregamos -XX:+UseG1GC a los -XX:+UseG1GC de JVM, luego desaparece el efecto de aumento de bucle múltiple. Lo ejecuto una vez más con .addProfiler(GCProfiler.class) . La principal diferencia:

Varios bucles: gc.churn.PS_Eden_Space 374.417 ± 23 MB / seg.

Bucle único: gc.churn.PS_Eden_Space 336.037 MB / seg ± 19 MB / seg

Creo que vemos la velocidad en tales circunstancias específicas, porque el algoritmo Compare y Swap GC antiguo-bueno tiene un cuello de botella en la CPU para múltiples ejecuciones de prueba y utiliza un ciclo extra "sin sentido" para recolectar basura de las ejecuciones anteriores. Es aún más fácil de reproducir con @Threads(2) , si tiene suficiente RAM. Se ve así, si intentas hacer un perfil de la prueba Single_Loop:

Answer 2

Para comprender lo que sucede debajo del capó, puede agregar el comportamiento de JMX para analizar la ejecución de la aplicación en jvisualvm , ubicada en JAVA_HOME / bin. Con un tamaño de 20M de una lista de cápsulas en la memoria, se quedó sin memoria y visualvm no respondió. . Había reducido el tamaño de la lista de cápsulas a 200k y 100M a 1M en condición de prueba. Después de observar el comportamiento en visualvm, la ejecución de un solo bucle se completó antes de varios bucles. Tal vez este no sea el enfoque correcto, pero podrías experimentar con él.

LoopBean.java

import java.util.List;
public interface LoopMBean {
    void multipleLoops();
    void singleLoop();
    void printResourcesStats();
}

Loop.java

import java.util.ArrayList;
import java.util.List;
import java.util.Random;

public class Loop implements LoopMBean {

    private final List<Capsule> capsules = new ArrayList<>();

    {
        Random r = new Random(3);
        for (int n = 0; n < 20000000; n++) {
            int randomN = r.nextInt();
            capsules.add(new Capsule(randomN, "word" + randomN));
        }
    }

    @Override
    public void multipleLoops() {

        System.out.println("----------------------Before multiple loops execution---------------------------");
        printResourcesStats();

        final List<Capsule> intermediate = new ArrayList<>();
        final List<String> res = new ArrayList<>();
        int totalLength = 0;

        final long start = System.currentTimeMillis();

        for (Capsule c : capsules)
            if (c.getNumber() > 100000000) {
                intermediate.add(c);
            }

        for (Capsule c : intermediate) {
            String s = "new_word" + c.getNumber();
            res.add(s);
        }

        for (String s : res)
            totalLength += s.length();

        System.out.println("multiple loops=" + totalLength + " | time taken=" + (System.currentTimeMillis() - start) + " milliseconds");

        System.out.println("----------------------After multiple loops execution---------------------------");
        printResourcesStats();

        res.clear();
    }

    @Override
    public void singleLoop() {

        System.out.println("----------------------Before single loop execution---------------------------");
        printResourcesStats();

        final List<String> res = new ArrayList<>();
        int totalLength = 0;

        final long start = System.currentTimeMillis();

        for (Capsule c : capsules)
            if (c.getNumber() > 100000000) {
                String s = "new_word" + c.getNumber();
                res.add(s);
            }

        for (String s : res)
            totalLength += s.length();

        System.out.println("Single loop=" + totalLength + " | time taken=" + (System.currentTimeMillis() - start) + " milliseconds");
        System.out.println("----------------------After single loop execution---------------------------");
        printResourcesStats();

        res.clear();
    }

    @Override
    public void printResourcesStats() {
        System.out.println("Max Memory= " + Runtime.getRuntime().maxMemory());
        System.out.println("Available Processors= " + Runtime.getRuntime().availableProcessors());
        System.out.println("Total Memory= " + Runtime.getRuntime().totalMemory());
        System.out.println("Free Memory= " + Runtime.getRuntime().freeMemory());
    }
}

LoopClient.java

import javax.management.MBeanServer;
import javax.management.ObjectName;
import java.lang.management.ManagementFactory;

public class LoopClient {

    void init() {

        final MBeanServer mBeanServer = ManagementFactory.getPlatformMBeanServer();
        try {
            mBeanServer.registerMBean(new Loop(), new ObjectName("LOOP:name=LoopBean"));
        } catch (Exception e) {
            e.printStackTrace();
        }

    }

    public static void main(String[] args) {

        final LoopClient client = new LoopClient();
        client.init();
        System.out.println("Loop client is running...");
        waitForEnterPressed();
    }

    private static void waitForEnterPressed() {
        try {
            System.out.println("Press  to continue...");
            System.in.read();
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

Ejecutar con el siguiente comando:

java -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false LoopClient

Podría agregar la opción adicional -Xmx3072M para un rápido aumento de la memoria para evitar OutOfMemoryError