What's the difference between the following code blocks

Question

I am new to reactive programming and want to understand some of the basics.

 @Test
    public void testMonoThen() {
        Mono<Void> fromRunnable = Mono.fromRunnable(() -> log.info("message from main"));
        fromRunnable.then(getMono1()).then(getMono2()).subscribe();

        //vs

        Mono<Void> fromRunnable2 = Mono.fromRunnable(() -> log.info("message from main2"));
        fromRunnable2.then(getMono3()).then(getMono4()).subscribe();
        
    }

    public Mono<Void> getMono1() {

        return Mono.fromRunnable(
                () -> log.info("Message from thread: {} and method mono1", Thread.currentThread().getId()));
    }

    public Mono<Void> getMono2() {

        return Mono.fromRunnable(
                () -> log.info("Message from thread: {} and method mono2", Thread.currentThread().getId()));
    }

    public Mono<Void> getMono3() {

        log.info("Message from thread: {} and method mono3", Thread.currentThread().getId());
        return Mono.empty();
    }

    public Mono<Void> getMono4() {
        log.info("Message from thread: {} and method mono4", Thread.currentThread().getId());
        return Mono.empty();
    }

Is there any difference between getMono3 and getMono1 functions from the execution perspective. Why the order of log message is not the same i.e. message from main is not printed in the same order.

output:

19:07:10.971 [main] DEBUG reactor.util.Loggers - Using Slf4j logging framework
19:07:10.977 [main] INFO com.reactivetests.SampleTest - message from main
19:07:10.977 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono1
19:07:10.979 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono2
19:07:10.980 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono3
19:07:10.981 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono4
19:07:10.981 [main] INFO com.reactivetests.SampleTest - message from main2

Answer 1

Regardless of using reactive programming via Mono or not, when a method it called, the code it contains will be executed. So when your method

public Mono<Void> getMono3() {

    log.info("Message from thread: {} and method mono3", Thread.currentThread().getId());
    return Mono.empty();
}

is called, it will generate the log entry.

When you have the following line

fromRunnable2.then(getMono3()).then(getMono4()).subscribe();

the methods getMono3() and getMono4() have to be called to evaluate this statement. But they have to be called. This means you get the log entries

19:07:10.980 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono3
19:07:10.981 [main] INFO com.reactivetests.SampleTest - Message from thread: 1 and method mono4

because java will evaluate your expression to finally something like

fromRunnable2.then(Mono.empty()).then(Mono.empty()).subscribe();

After that, when the log entries are already generated, your subscription will run and you get the message from main2 message from the

Mono<Void> fromRunnable2 = Mono.fromRunnable(() -> log.info("message from main2");

runnable. That's why you get the log entries from mono3 and mono4 "first", and then the log entry "message from main2".

Basically, your log.info() calls are not "in the chain" of the Mono subscription (like in getMono1() and getMono2()).