gradle-helm-plugin icon indicating copy to clipboard operation
gradle-helm-plugin copied to clipboard

Redirect helm output stream into default logger

Open vgalloy opened this issue 2 years ago • 10 comments

Motivation:

Let helm print with the default output is not a good idea. It's hard to catch. Most of the time, we don't need to see these messages.

Modification:

  • Redirect ExecSpec#standardOutput to info logger

vgalloy avatar Nov 05 '21 13:11 vgalloy

Hi, and thanks for the PR!

I think in general it's a nice idea, but I would suggest some improvements:

  1. This behavior should be in sync with Task.getLoggingManager(), which already has a way to configure how stdout / stderr is redirected to Gradle's log levels. We would need to transport this information to the worker task somehow. Maybe there are some Gradle APIs that we can reuse on the worker side, but I assume they will be internal.

  2. Add some more overloads to the InfoLoggerOutputStream so it doesn't write byte-by-byte. This should also be smart enough to interpret a multi-line output as a single log statement (e.g. with helm template or helm status you might potentially get a lot of lines in the output, but they will usually be printed all at once.

  3. Consider using StringBuilder instead of StringBuffer

  4. Can we use val instead of var for the StringBuffer/StringBuilder, and just clear it after each line? Or is creating a new StringBuffer for each line meant to be an optimization?

tkrullmann avatar Nov 08 '21 09:11 tkrullmann

Thank for you quick reply !

  1. As far as I understand, Task#getLoggingManager allows user to redirect standardOutput to a log level. But in paralllel execution, the ExecSpec may run in different thread and the standardOutput will be not capture. For that, you need to find a way to bind the standardOutput to your task. I guess using the task System.out should works.
  2. I understand you point. But I don't know how the java.lang.Process will use the output stream. So I can't do this kind of optimisation.

Maybe it will be clearer with an example. Imagine the Helm process produce the following output "Line one\nLine two". This ouput may be recevied by the outputStream as ["Line one\nLine two"] or ["Line one\n", "Line two"] or ["Line one\n", "Line ", "two"] depending on how the process is internally optimised. In this condition how can the InfoLoggerOutputStream has a consistent printing ability ?

  1. Done (I've updated the PR)
  2. Done (I've updated the PR)

vgalloy avatar Nov 08 '21 12:11 vgalloy

I tried it out, and the mechanisms built into Gradle (LoggingManager) will already do what you are suggesting. A task calling exec is already capturing the subprocess's stdout and stderr and redirects them to Gradle's outputs. Using task.getLogging().captureStandardOutput(level) will work even if the exec is done in a worker.

i.e. if I put the following in the project:

tasks.withType<org.unbrokendome.gradle.plugins.helm.command.tasks.AbstractHelmCommandTask> {
    logging.captureStandardOutput(LogLevel.INFO)
    logging.captureStandardError(LogLevel.ERROR)  // this is probably already the default
}

then I will see the output of Helm invocations only when running Gradle with --info.

tkrullmann avatar Nov 09 '21 09:11 tkrullmann

My suggestion would be to make this available as a project property for convenience, so the HelmCommandsPlugin could check for a project property like helm.exec.logLevel and run the above code accordingly.

tkrullmann avatar Nov 09 '21 09:11 tkrullmann

I don't face the same behaviour. There is probably something I don't understand.

  1. By default INFO log should not be display during build
  2. When you capture standardOutput (like you do) you are redirecting it to INFO level

1 + 2 => I should not see any helm message in the console when I run a task.

I created a project https://github.com/vgalloy/unbroken-dome-test

When I'm running helmAddRepoRepository (check readme.md) I always get the following message "repo" has been added to your repositories

Did I miss something ?

vgalloy avatar Nov 09 '21 15:11 vgalloy

Did you try adding this to your Gradle script?

tasks.withType<org.unbrokendome.gradle.plugins.helm.command.tasks.AbstractHelmCommandTask> {
    logging.captureStandardOutput(LogLevel.INFO)
    logging.captureStandardError(LogLevel.ERROR)
}

tkrullmann avatar Nov 09 '21 16:11 tkrullmann

Yes : https://github.com/vgalloy/unbroken-dome-test/blob/master/buildSrc/src/main/kotlin/vgalloy.unbroken-dome-conventions.gradle.kts#L14

vgalloy avatar Nov 10 '21 07:11 vgalloy

Strange, I tried running exactly your build script and I didn't get anything on stdout. Running with --info I got the message "repo" has been added to your repositories on INFO level, as expected.

Which Gradle version are you using? I think this loggingManager has been around for a while, but just to make sure this behavior hasn't changed recently

tkrullmann avatar Nov 10 '21 12:11 tkrullmann

I'm using Gradle 7.2

With gradle wrapper you can see this information here: https://github.com/vgalloy/unbroken-dome-test/blob/master/gradle/wrapper/gradle-wrapper.properties#L3

I have the same output with Gradle 6.3, 7.0, 7.1 and 7.3.

I'm using Java 16

$ java -version
openjdk 16.0.1 2021-04-20
OpenJDK Runtime Environment (build 16.0.1+9-24)
OpenJDK 64-Bit Server VM (build 16.0.1+9-24, mixed mode, sharing)

vgalloy avatar Nov 10 '21 14:11 vgalloy

I opened a bug for Gradle team: https://github.com/gradle/gradle/issues/18991

vgalloy avatar Nov 15 '21 18:11 vgalloy