print timestamp for CPU starvation warning in System.err

[mr-git]

Please print timestamp for CPU starvation warning in System.err in addition to warning.

With current implementation we can observe few such warnings, but it is impossible to correlate the warning with application's log.

[armanbilge]

Thanks! In addition, maybe we should make the log action for the warning configurable, so that users can send it to their logger. We do something similar for unhandled exceptions.

[mr-git]

We do something similar for unhandled exceptions

Where I can find some sample on this?

[armanbilge]

Take a look at this PR:

• https://github.com/typelevel/cats-effect/pull/2869

[mr-git]

Looks promising! Thank you!

P.S. is there some ETA for next release?

[armanbilge]

We generally do patch releases in 3.4.x as-needed when fixes come in.

Minor releases i.e. 3.5.0 will probably be early-ish next year.

[armanbilge]

@mtomko just made a similar feature request on Discord, would be great if someone can pick this up! :)

[mtomko]

I'm looking at it, but I don't think I've worked in this codebase before so it'll take a little bit to look through it and make a proposal.

[mtomko]

I have some changes that would let you configure it this way:

import java.time.format.DateTimeFormatter
import java.time.Instant

import scala.concurrent.duration.FiniteDuration

import cats.effect.IOApp
import cats.effect.unsafe

object HopefullyNotStarvingApp extends IOApp {

  def asInstant(fd: FiniteDuration): String = {
    DateTimeFormatter.ISO_INSTANT.format(Instant.ofEpochMilli(fd.toMillis))
  }

  override val runtimeConfig = unsafe.IORuntimeConfig().copy(cpuStarvationTimestampFormat = asInstant)

  def run(args: List[String]): IO[ExitCode] = ???
}

The reason I did it this way is that it leaves the implementation in the shared source tree rather than having to separate out JVM, JS, and Native implementations; then the caller can provide a function that makes sense for whatever platform they're targeting.

I can see a few key ergonomic problems with this approach, however. The first is the obvious one, which is that overriding the format function requires you to explicitly instantiate something that's in the unsafe package and whose docs directly imply that "you generally don't want to do this".

The second flaw is that there's a way to configure the other starvation properties without directly overriding the IORuntimeConfig using system properties. Until now, that's worked beautifully because all the other properties are scalar values that have a direct and natural String (well, Properties) representation. Passing a function like this is much less clear. In my implementation of the above, I punted on that problem - you simply cannot override the format via system properties. I'm not thrilled with that lack of parity, however.

If you would be interested in seeing a draft PR, I can go ahead and commit the code as-is. If people have alternative suggestions for how to go about this, I'd be happy to workshop this a bit more before making a real PR. I'm only able to put a tiny bit of normal work time into this, but I have a longish flight home on Friday evening and was hoping to spend that time putting lipstick on this pig so I could make a proper PR.

[armanbilge]

Thanks for all your work on this! Yes, putting up a draft PR is the best way to get feedback :)

I'm not sure if we need this function to be configurable. Because of the platform-specific differences, we just need to implement it different on JVM/Native and JS by using platform-specific code in Cats Effect. On JVM/Native we can use Instant, on JS we can use js.Date.

[mtomko]

I will try to adapt my approach a bit and then make a draft PR. I think I still want the bulk of the code to live in the shared area, so maybe I can just put the implementation of the formatter in the various source trees and leave the rest of the code where it is in the shared area.

[armanbilge]

so maybe I can just put the implementation of the formatter in the various source trees

That's exactly the way to do it! :) we have various examples of this in the codebase, you can check the platform-specific source folders to see (look for things named SomethingPlatform).

[mtomko]

Oh, the other question I had was sort of one of aesthetics. For the sake of argument, I changed the message so it read like this:

  private[this] def mkWarning(threshold: Duration, format: FiniteDuration => String)(
      when: FiniteDuration) =
    s"""|[WARNING] ${format(when)} 
        |Your app's responsiveness to a new asynchronous event (such as a
        |new connection, an upstream response, or a timer) was in excess of $threshold.
        |Your CPU is probably starving. Consider increasing the granularity
        |of your delays or adding more cedes. This may also be a sign that you are
        |unintentionally running blocking I/O operations (such as File or InetAddress)
        |without the blocking combinator.""".stripMargin

I wasn't super worried about readability or aesthetics, I just needed to put a timestamp in there so I could see when the problem was. I don't think this solution is tragic, but since @armanbilge was the original author (I think?) of the CPU starvation check, perhaps you have opinions on where/how you'd like the timestamp to be displayed! It could easily go right where it is, or on a separate line, or at the beginning... or something else?

[armanbilge]

That seems fine :) it is originally @TimWSpence's work actually.

[mtomko]

Created a draft PR for this. I will run existing tests in the morning, because I left my power adapter at work and my battery will not withstand the full test suite, I don't think. Also, I will look around and see what tests are possible for this code - it's sort of at the edge of the program, which always makes the testing story awkward, but perhaps I'll find some inspiration in the existing test suites.

[mr-git]

my ~2~ 3 cents:

• timestamp as very first "token" is better - most of logging frameworks tend to put timestamp there
• ISO8601 could be very good as default format - both Java and JS have functions to work with it
• would it be possible to provide timestamp format pattern in config instead of function on unsafe?

[mtomko]

Thanks for your feedback. I think the timestamp as the first token may make testing a tiny bit easier, too. @armanbilge has already suggested a better place for the format functions to go, which I'll be working on today or tomorrow.