[JENKINS-75081] Avoid heap allocation when rendering large logs

[jglick]

See JENKINS-75081. Integrating jenkinsci/stapler#657. Alternative to #10236.

Closes #10236

Testing done

Tested interactively, in bom, and via jenkinsci/workflow-job-plugin#528.

Proposed changelog entries

• Reduce heap usage of various HTTP endpoints serving large build logs.

Proposed changelog category

/label bug

Proposed upgrade guidelines

N/A

Desired reviewers

@Dohbedoh

Before the changes are marked as ready-for-merge:

Maintainer checklist

• There are at least two (2) approvals for the pull request and no outstanding requests for change.
• Conversations in the pull request are over, or it is explicit that a reviewer is not blocking the change.
• Changelog entries in the pull request title and/or Proposed changelog entries are accurate, human-readable, and in the imperative mood.
• Proper changelog labels are set so that the changelog can be generated automatically.
• If the change needs additional upgrade steps from users, the upgrade-guide-needed label is set and there is a Proposed upgrade guidelines section in the pull request title (see example).
• If it would make sense to backport the change to LTS, a Jira issue must exist, be a Bug or Improvement, and be labeled as lts-candidate to be considered (see query).

[Dohbedoh]

Trying to reproduce the problem with the scenario in the ticket:

node {
    for(int i=0; i<10; i++) {
        sh "head -c 1073741824 /dev/urandom | base64 --break=1000"
    }
}

Before this change

Hitting /logText/progressiveText/ shows a rapid spike to near 10GB heap and then OOM:

Going to the console output shows the same behavior and fails with:

Caused by: java.lang.OutOfMemoryError: Required array length 2147483639 + 9 is too large
	at java.base/jdk.internal.util.ArraysSupport.hugeLength(ArraysSupport.java:752)
	at java.base/jdk.internal.util.ArraysSupport.newLength(ArraysSupport.java:745)
	at java.base/java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:100)
	at java.base/java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:132)
	at org.apache.commons.io.output.ProxyOutputStream.write(ProxyOutputStream.java:147)
	at org.kohsuke.stapler.framework.io.LargeText.writeLogTo(LargeText.java:244)
	at hudson.console.AnnotatedLargeText.writeRawLogTo(AnnotatedLargeText.java:226)
	at PluginClassLoader for workflow-job//org.jenkinsci.plugins.workflow.job.WorkflowRun.writeLogTo(WorkflowRun.java:1173)
	at PluginClassLoader for workflow-job//org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogInputStream(WorkflowRun.java:1141)
	at hudson.model.Run.writeLogTo(Run.java:1471)

After this change

Hitting /logText/progressiveText/ shows a slow memory consumption pattern on /logText/progressiveText/:

(so the fix proposed here seem to address the problem of heap usage on that endpoint).

Going to the console output shows a rapid spike to 10gb and fails (like before the fix):

Caused by: java.lang.OutOfMemoryError: Required array length 2147483639 + 9 is too large
	at java.base/jdk.internal.util.ArraysSupport.hugeLength(ArraysSupport.java:752)
	at java.base/jdk.internal.util.ArraysSupport.newLength(ArraysSupport.java:745)
	at java.base/java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:100)
	at java.base/java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:132)
	at org.apache.commons.io.output.ProxyOutputStream.write(ProxyOutputStream.java:147)
	at org.kohsuke.stapler.framework.io.LargeText.writeLogUncounted(LargeText.java:250)
	at org.kohsuke.stapler.framework.io.LargeText.writeLogTo(LargeText.java:235)
	at hudson.console.AnnotatedLargeText.writeRawLogTo(AnnotatedLargeText.java:226)
	at PluginClassLoader for workflow-job//org.jenkinsci.plugins.workflow.job.WorkflowRun.writeLogTo(WorkflowRun.java:1173)
	at PluginClassLoader for workflow-job//org.jenkinsci.plugins.workflow.job.WorkflowRun.getLogInputStream(WorkflowRun.java:1141)

Note that in both cases, chrome is failing with Aw snap message. But that is kind of expected with 10gb log to load and display..

[jglick]

Hmm the OOME from WorkflowRun.getLogInputStream is definitely unexpected. That appears to be from a completed build, where the bug report was about an in-progress build. At any rate, significant heap usage for any log writing method should be treated as a bug. I will have to dig deeper into this because it sounds like they are multiple longstanding flaws. First, the automated test failures here need to be fixed. Then we also need automated tests for all the known scenarios of gigantic log files, though they will probably need to be @Ignored.

[jglick]

Running into a problem with AnnotatedLargeText: while in the upstream I managed to set a correct X-Text-Size before streaming text, here X-ConsoleAnnotator must be set after processing output (since its value is computed based on the text) yet before sending any of it (since it is an HTTP header), which is impossible to make efficient. Fortunately this misconceived design only affects the classic console, so I just need to figure out how to disable the optimized behavior from doProgressiveHtml.

[jglick]

The WorkflowRun.getLogInputStream problem is because this method was never (as of JEP-210) intended to be called in production scenarios, and is thus not optimized. It seems this regressed in #4905. 👀

[jglick]

@Dohbedoh

base64 --break=1000

given an error on Linux. Seems to be a Mac option according to docs

-b count, --break=count
Insert line breaks every count characters. Default is 0, which generates an unbroken stream.

The Linux equivalent seems to be

-w, --wrap=COLS
wrap encoded lines after COLS character (default 76). Use 0 to disable line wrapping

[github-actions]

Please take a moment and address the merge conflicts of your pull request. Thanks!

[timja]

Thanks!

[basil]

LGTM; the only question I have is whether we need to make any changes to Pipeline Graph View to adapt to this, or if that will automatically benefit from this fix. Since Workflow: Job didn't need any changes, my impression is that Pipline Graph View won't need any, either?

[jglick]

I am not aware of any changes required to Pipeline Graph View, nor whether it is currently calling a Java API or using an HTTP endpoint which would benefit from this change. I will take a look.

[timja]

I am not aware of any changes required to Pipeline Graph View, nor whether it is currently calling a Java API or using an HTTP endpoint which would benefit from this change. I will take a look.

endpoint is here:
https://github.com/jenkinsci/pipeline-graph-view-plugin/blob/3f933d339c4a065aa1e8987fc9422994de1ff16e/src/main/java/io/jenkins/plugins/pipelinegraphview/consoleview/PipelineConsoleViewAction.java#L123-L156

[jglick]

/pipeline-console/consoleOutput does still seem to fail with an OOME. From code inspection, the implementation of getConsoleText would throw an OOME as well. Not much that core can do about this—the limitation is in that plugin.

[timja]

/pipeline-console/consoleOutput does still seem to fail with an OOME. From code inspection, the implementation of getConsoleText would throw an OOME as well. Not much that core can do about this—the limitation is in that plugin.

What is it doing wrong?

[jglick]

Well, it seems to be buffering an unbounded amount of text in a memory buffer rather than streaming it to the response as this PR accomplishes for some endpoints.

For comparison, I checked CloudBees Pipeline Explorer, which is able to handle the gigantic logs smoothly. It is using an independent HTTP endpoint that explicitly batches up text up to some limit.

[basil]

Sure, my concern was only whether or not Pipeline Graph View needed changes to adapt to this PR, not fixing any preëxisting issues there.

---

This PR is now ready for merge. We will merge it after approximately 24 hours if there is no negative feedback. Please see the merge process documentation for more information about the merge process. Thanks!