Heavy loop does not allow to reach code next to the "lauch()" method

[armansimonyan13]

The following code from an example does not reach to the "delay(1300L)" on my machine.
But when I uncomment "delay(1L)" it works as expected.

fun main(args: Array<String>) = runBlocking {
    val startTime = System.currentTimeMillis()
    val job = launch(Dispatchers.Default) {
        var nextPrintTime = startTime
        var i = 0
        while (isActive) { // cancellable computation loop
            // print a message twice a second
            if (System.currentTimeMillis() >= nextPrintTime) {
                println("I'm sleeping ${i++} ...")
                nextPrintTime += 500L
                // delay(1L)
            }
        }
    }
    delay(1300L) // delay a bit
    println("main: I'm tired of waiting!")
    job.cancelAndJoin() // cancels the job and waits for its completion
    println("main: Now I can quit.")
}

[elizarov]

What version of kotlinx.coroutines are you using? Please, try on the latest one (0.30.2)

[armansimonyan13]

I am using 0.30.2-eap13. Will try "0.30.2".

[elizarov]

0.30.2-eap13 should be fine, too. What environment (OS, CPU, JDK version) you are running it on?

[armansimonyan13]

OS: macOS High Sierra v10.13.6
CPU: 2.9 GHz Intel Core i7
JDK:
java version "1.8.0_60"
Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)

[elizarov]

Can you let it run for a few second, do a thread-dump and post it here, please (it is kill -3 <pid> from the console) or a "Thread Dump" button in the console window if you run it from IDEA.

[armansimonyan13]

2018-10-10 19:48:00
Full thread dump OpenJDK 64-Bit Server VM (25.152-b06 mixed mode):

"Monitor Ctrl-Break" #10 daemon prio=5 os_prio=31 tid=0x00007ff8870a4000 nid=0xa903 runnable [0x000070000f140000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
- locked <0x000000076ad9ec50> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(InputStreamReader.java:184)
at java.io.BufferedReader.fill(BufferedReader.java:161)
at java.io.BufferedReader.readLine(BufferedReader.java:324)
- locked <0x000000076ad9ec50> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(BufferedReader.java:389)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)

"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007ff88881c000 nid=0x3b03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007ff888010800 nid=0x3e03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007ff889801000 nid=0x3903 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007ff88704e800 nid=0x4103 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007ff88a801800 nid=0x3803 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007ff88a800800 nid=0x430b waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007ff888817800 nid=0x3203 in Object.wait() [0x000070000e928000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000076ab08ec8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x000000076ab08ec8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007ff888814800 nid=0x4d03 in Object.wait() [0x000070000e825000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000076ab06b68> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x000000076ab06b68> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=31 tid=0x00007ff88700a800 nid=0x1703 runnable [0x000070000de06000]
java.lang.Thread.State: RUNNABLE
at com.example.armansimonyan.coroutines.MainKt$main$1$job$1.invokeSuspend(Main.kt:11)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)
at kotlinx.coroutines.DispatchedTask$DefaultImpls.run(Dispatched.kt:165)
at kotlinx.coroutines.DispatchedContinuation.run(Dispatched.kt:13)
at kotlinx.coroutines.EventLoopBase.processNextEvent(EventLoop.kt:166)
at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:69)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:45)
at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:35)
at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
at com.example.armansimonyan.coroutines.MainKt.main(Main.kt:6)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intellij.rt.execution.application.AppMainV2.main(AppMainV2.java:131)

"VM Thread" os_prio=31 tid=0x00007ff88706a000 nid=0x4f03 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007ff887003800 nid=0x1f07 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007ff887026000 nid=0x1e03 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007ff887026800 nid=0x2b03 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007ff887027800 nid=0x2c03 runnable

"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007ff887028000 nid=0x2d03 runnable

"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007ff887028800 nid=0x2f03 runnable

"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007ff887029000 nid=0x5103 runnable

"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007ff88702a000 nid=0x3103 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007ff88a007000 nid=0x3c03 waiting on condition

JNI global references: 14

Heap
PSYoungGen total 76288K, used 13107K [0x000000076ab00000, 0x0000000770000000, 0x00000007c0000000)
eden space 65536K, 20% used [0x000000076ab00000,0x000000076b7ccfa8,0x000000076eb00000)
from space 10752K, 0% used [0x000000076f580000,0x000000076f580000,0x0000000770000000)
to space 10752K, 0% used [0x000000076eb00000,0x000000076eb00000,0x000000076f580000)
ParOldGen total 175104K, used 0K [0x00000006c0000000, 0x00000006cab00000, 0x000000076ab00000)
object space 175104K, 0% used [0x00000006c0000000,0x00000006c0000000,0x00000006cab00000)
Metaspace used 4162K, capacity 5176K, committed 5376K, reserved 1056768K
class space used 451K, capacity 488K, committed 512K, reserved 1048576K

[elizarov]

This is very strange. Are you sure you run the code you've posted? In particular do you have launch(Dispatchers.Default) { .. } (check the dispatcher, please)?

[armansimonyan13]

Sorry, my mistake. I missed the "Dispatchers.Default"

[armansimonyan13]

Do I need to remove the issue?

[elizarov]

I've closed it.