Duplicated fibers in fiber dump

[TimWSpence]

Running the following code:

package io.github.timwspence.cats.stm

import cats.effect._

object Test extends IOApp.Simple {
  override def run: IO[Unit] =
    for {
      d <- IO.deferred[Int]
      f <- d.get.start
      _ <- f.join
      _ <- d.complete(1)
    } yield ()
}

on JDK 17 and pressing Crtl-T for a fiber dump yields the following:

cats.effect.IOFiber@707af0cd WAITING

cats.effect.IOFiber@539c7a54 WAITING
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ╰ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

cats.effect.IOFiber@539c7a54 ACTIVE
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ├ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 ╰ main @ jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

Thread[io-compute-5,5,run-main-group-1] (#5): 0 enqueued
Thread[io-compute-11,5,run-main-group-1] (#11): 0 enqueued
Thread[io-compute-2,5,run-main-group-1] (#2): 0 enqueued
Thread[io-compute-4,5,run-main-group-1] (#4): 0 enqueued
Thread[io-compute-9,5,run-main-group-1] (#9): 0 enqueued
Thread[io-compute-1,5,run-main-group-1] (#1): 0 enqueued
Thread[io-compute-6,5,run-main-group-1] (#6): 0 enqueued
Thread[io-compute-3,5,run-main-group-1] (#3): 0 enqueued
Thread[io-compute-7,5,run-main-group-1] (#7): 0 enqueued
Thread[io-compute-0,5,run-main-group-1] (#0): 0 enqueued
Thread[io-compute-8,5,run-main-group-1] (#8): 0 enqueued
Thread[io-compute-10,5,run-main-group-1] (#10): 0 enqueued

Global: enqueued 0, foreign 1, waiting 2

Note that fiber 539c7a54 is duplicated as both active and waiting. I've re-run it a bunch of times and the output appears to be deterministic

[armanbilge]

Thanks for writing this up!

We discussed this on Discord so I think I have some idea what's going on here:

1. The duplication is of the main fiber, due to this change: 9a212ed. I assumed it would get de-duplicated, but there might be a bug in that code.
2. The traces themselves are not quite right. We need to add jdk.* classes to our filters.

[djspiewak]

Out of curiosity, why is jdk.internal.reflect even part of the stack trace to begin with?

[armanbilge]

I would guess that's how main is invoked on the newer JDKs. But IDK.

[TimWSpence]

Is there a reason why in IOFiber we don't use the fiber itself as the monitor key in IOFiber but instead instantiate a new AnyRef() and use that? I assume the problem here is that we've used different keys for the same fiber in IOApp and IOFiber

[vasilmkd]

@TimWSpence might be exactly right here.

This registration is coming from the main thread which is a foreign thread w.r.t. our runtime.

cats-effect/core/jvm/src/main/scala/cats/effect/IOApp.scala

Lines 283 to 284 in 854dc9e

	if (isStackTracing)
	runtime.fiberMonitor.monitorSuspended(fiber, fiber)

So we do have a situation of the same fiber being shown twice, because it is indeed registered with two different keys.

@armanbilge What does the IOApp registration aim to achieve exactly?

[vasilmkd]

I still am pretty sure that fixing the subtraction of foreign and suspended fibers in FiberMonitor will fix this though.

[armanbilge]

So we do have a situation of the same fiber being shown twice, because it is indeed registered with two different keys.

Yes, this is a general problem. I'm pretty sure that evalOning a fiber which then suspends will lead to the exact same outcome, since it will be registered with both the async callback and the opaque object used for evalOn registration.

What does the IOApp registration aim to achieve exactly?

See #2587 (comment):

By explicitly monitoring the main fiber, we are guaranteed that it appears in the fiber dump even if a foreign runtime is being used.

[TimWSpence]

I still am pretty sure that fixing the subtraction of foreign and suspended fibers in FiberMonitor will fix this though.

Yeah, I just opened #2607 with a suggested fix. Thanks @armanbilge for demonstrating that it does fix a more general problem as well

[TimWSpence]

Confirmed with

package io.timwspence

import cats.effect._
import scala.concurrent.ExecutionContext
import java.util.concurrent.Executors

object Test extends IOApp.Simple {
  val ec = ExecutionContext.fromExecutorService(Executors.newSingleThreadExecutor())
  override def run: IO[Unit] =
    for {
      d <- IO.deferred[Int]
      f <- d.get.evalOn(ec).start
      _ <- f.join
      _ <- d.complete(1)
    } yield ()
}

that evalOn introduces the same problem and that the same fix works! 🎉