Echoing out build log file results in output truncation

[yueework]

Jenkins and plugins versions report

Environment

Jenkins: 2.464
OS: Linux - 5.15.0-101-generic
Java: 17.0.12 - Ubuntu (OpenJDK 64-Bit Server VM)
---
analysis-model-api:12.3.3
ant:497.v94e7d9fffa_b_9
antisamy-markup-formatter:162.v0e6ec0fcfcf6
apache-httpcomponents-client-4-api:4.5.14-208.v438351942757
apache-httpcomponents-client-5-api:5.3.1-1.0
asm-api:9.7-33.v4d23ef79fcc8
audit-trail:361.v82cde86c784e
authentication-tokens:1.113.v81215a_241826
backgroundbuildrotator:0.9
badge:1.13
blueocean:1.27.13
blueocean-autofavorite:1.2.5
blueocean-bitbucket-pipeline:1.27.13
blueocean-commons:1.27.13
blueocean-config:1.27.13
blueocean-core-js:1.27.13
blueocean-dashboard:1.27.13
blueocean-display-url:2.4.2
blueocean-events:1.27.13
blueocean-git-pipeline:1.27.13
blueocean-github-pipeline:1.27.13
blueocean-i18n:1.27.13
blueocean-jira:1.27.13
blueocean-jwt:1.27.13
blueocean-personalization:1.27.13
blueocean-pipeline-api-impl:1.27.13
blueocean-pipeline-editor:1.27.13
blueocean-pipeline-scm-api:1.27.13
blueocean-rest:1.27.13
blueocean-rest-impl:1.27.13
blueocean-web:1.27.13
bootstrap5-api:5.3.3-1
bouncycastle-api:2.30.1.78.1-248.ve27176eb_46cb_
branch-api:2.1169.va_f810c56e895
build-environment:1.7
build-history-manager:1.9.1
build-monitor-plugin:1.14-883.vf620a_44eb_ec1
build-name-setter:2.4.2
build-timeout:1.33
build-user-vars-plugin:166.v52976843b_435
buildrotator:1.2
built-on-column:1.4
caffeine-api:3.1.8-133.v17b_1ff2e0599
checks-api:2.2.0
cloudbees-bitbucket-branch-source:887.va_d359b_3d2d8d
cloudbees-disk-usage-simple:203.v3f46a_7462b_1a_
cloudbees-folder:6.942.vb_43318a_156b_2
command-launcher:107.v773860566e2e
commons-compress-api:1.26.1-2
commons-lang3-api:3.14.0-76.vda_5591261cfe
commons-text-api:1.12.0-129.v99a_50df237f7
conditional-buildstep:1.4.3
configuration-as-code:1850.va_a_8c31d3158b_
copyartifact:746.vd2a_674fb_4f6f
credentials:1371.vfee6b_095f0a_3
credentials-binding:681.vf91669a_32e45
dashboard-view:2.508.va_74654f026d1
data-tables-api:2.0.8-1
display-url-api:2.204.vf6fddd8a_8b_e9
docker-commons:439.va_3cb_0a_6a_fb_29
docker-workflow:580.vc0c340686b_54
downstream-ext:73.vdda_16e6eb_0da
durable-task:555.v6802fe0f0b_82
echarts-api:5.5.0-1
eddsa-api:0.3.0-4.v84c6f0f4969e
email-ext:1814.v404722f34263
enhanced-old-build-discarder:1.4
envinject:2.908.v66a_774b_31d93
envinject-api:1.199.v3ce31253ed13
extended-read-permission:53.v6499940139e5
external-monitor-job:215.v2e88e894db_f8
favorite:2.218.vd60382506538
flexible-publish:0.16.1
font-awesome-api:6.5.2-1
forensics-api:2.4.0
gerrit-trigger:2.41.1
git:5.4.1
git-changelog:3.38
git-client:5.0.0
git-server:126.v0d945d8d2b_39
github:1.40.0
github-api:1.321-468.v6a_9f5f2d5a_7e
github-branch-source:1797.v86fdb_4d57d43
gitlab-plugin:1.8.1
global-build-stats:293.vd7b_d6e361475
gradle:2.12
greenballs:1.15.1
groovy:457.v99900cb_85593
groovy-postbuild:228.vcdb_cf7265066
gson-api:2.11.0-41.v019fcf6125dc
handy-uri-templates-2-api:2.1.8-30.v7e777411b_148
hashicorp-vault-pipeline:1.4
hashicorp-vault-plugin:368.v48134f694db_f
htmlpublisher:1.35
http_request:1.18
influxdb:3.6.1
instance-identity:185.v303dc7c645f9
ionicons-api:74.v93d5eb_813d5f
jackson2-api:2.17.0-379.v02de8ec9f64c
jacoco:3.3.6
jakarta-activation-api:2.1.3-1
jakarta-mail-api:2.1.3-1
javadoc:243.vb_b_503b_b_45537
javax-activation-api:1.2.0-7
javax-mail-api:1.6.2-10
jaxb:2.3.9-1
jdk-tool:73.vddf737284550
jenkins-design-language:1.27.13
jenkins-multijob-plugin:627.v7c23cef20a_6a
jersey2-api:2.42-147.va_28a_44603b_d5
jira:3.13
jjwt-api:0.11.5-112.ve82dfb_224b_a_d
job-dsl:1.87
job-import-plugin:3.6
jobrequeue:1.1
joda-time-api:2.12.7-29.v5a_b_e3a_82269a_
jquery:1.12.4-1
jquery3-api:3.7.1-2
jsch:0.2.16-86.v42e010d9484b_
json-api:20240303-41.v94e11e6de726
json-path-api:2.9.0-58.v62e3e85b_a_655
junit:1265.v65b_14fa_f12f0
ldap:725.v3cb_b_711b_1a_ef
lenientshutdown:1.1.1
lockable-resources:1255.vf48745da_35d0
logging:1.0.0
mailer:472.vf7c289a_4b_420
mapdb-api:1.0.9-40.v58107308b_7a_7
matrix-auth:3.2.2
matrix-project:832.va_66e270d2946
maven-plugin:3.23
mercurial:1260.vdfb_723cdcc81
metrics:4.2.21-451.vd51df8df52ec
mina-sshd-api-common:2.12.1-113.v4d3ea_5eb_7f72
mina-sshd-api-core:2.12.1-113.v4d3ea_5eb_7f72
mock-slave:153.v9768799a_2294
monitoring:1.99.0
multi-slave-config-plugin:1.2.0
nodelabelparameter:1.12.0
oic-auth:4.303.v84089a_708ea_7
okhttp-api:4.11.0-172.vda_da_1feeb_c6e
opentelemetry:3.1391.vcb_a_a_b_9779d75
opentelemetry-api:1.40.0-36.v1e02b_b_4db_8f4
pam-auth:1.11
parameterized-trigger:806.vf6fff3e28c3e
performance:962.v95a_4913d332e
permissive-script-security:0.7
pipeline-build-step:540.vb_e8849e1a_b_d8
pipeline-github-lib:61.v629f2cc41d83
pipeline-graph-analysis:216.vfd8b_ece330ca_
pipeline-groovy-lib:727.ve832a_9244dfa_
pipeline-input-step:495.ve9c153f6067b_
pipeline-milestone-step:119.vdfdc43fc3b_9a_
pipeline-model-api:2.2214.vb_b_34b_2ea_9b_83
pipeline-model-definition:2.2214.vb_b_34b_2ea_9b_83
pipeline-model-extensions:2.2214.vb_b_34b_2ea_9b_83
pipeline-rest-api:2.34
pipeline-stage-step:312.v8cd10304c27a_
pipeline-stage-tags-metadata:2.2214.vb_b_34b_2ea_9b_83
pipeline-stage-view:2.34
pipeline-utility-steps:2.17.0
plain-credentials:183.va_de8f1dd5a_2b_
plugin-util-api:4.1.0
postbuild-task:1.9
postbuildscript:3.2.0-550.v88192b_d3e922
preSCMbuildstep:71.v1f2990a_37e27
prism-api:1.29.0-17
publish-over:0.22
publish-over-ssh:1.25
pubsub-light:1.18
purge-build-queue-plugin:88.v23b_97b_f2c7a_d
pyenv-pipeline:2.1.2
rebuild:332.va_1ee476d8f6d
resource-disposer:0.23
reverse-proxy-auth-plugin:1.7.7
role-strategy:727.vd344b_eec783d
run-condition:1.7
saferestart:0.7
saltstack:3.2.2
saml:4.464.vea_cb_75d7f5e0
scm-api:696.v778d637b_a_762
script-security:1361.v913100720139
shared-workspace:1.0.2
sidebar-link:2.4.1
simple-theme-plugin:176.v39740c03a_a_f5
slack:722.vd07f1ea_7ff40
sloccount:1.27
snakeyaml-api:2.3-123.v13484c65210a_
sse-gateway:1.27
ssh-agent:367.vf9076cd4ee21
ssh-credentials:343.v884f71d78167
ssh-slaves:2.973.v0fa_8c0dea_f9f
ssh-steps:2.0.68.va_d21a_12a_6476
sshd:3.330.vc866a_8389b_58
structs:338.v848422169819
subversion:1269.v53185011cd9f
test-results-analyzer:0.4.1
thinBackup:2.0
throttle-concurrents:2.14
timestamper:1.27
token-macro:400.v35420b_922dcb_
trilead-api:2.147.vb_73cc728a_32e
update-sites-manager:2.0.0
variant:60.v7290fc0eb_b_cd
versioncolumn:243.vda_c20eea_a_8a_f
warnings-ng:11.3.0
windows-slaves:1.8.1
workflow-aggregator:596.v8c21c963d92d
workflow-api:1316.v33eb_726c50b_a_
workflow-basic-steps:1058.vcb_fc1e3a_21a_9
workflow-cps:3961.ve48ee2c44a_b_3
workflow-durable-task-step:1371.vb_7cec8f3b_95e
workflow-job:1426.v2ecb_a_a_42fd46
workflow-multibranch:791.v28fb_f74dfca_e
workflow-scm-step:427.v4ca_6512e7df1
workflow-step-api:678.v3ee58b_469476
workflow-support:920.v59f71ce16f04
ws-cleanup:0.46
xcode-plugin:2.0.17-565.v1c48051d46ef

What Operating System are you using (both controller, and any agents involved in the problem)?

Controller on VM: Ubuntu 22.04.4 LTS
Observed behaviour on agents as well and reproduced on above Ubuntu linux controller.

OTel plugin sends data to APM running in K8s:

$ ./apm-server version
apm-server version 8.15.2 (linux/amd64) [1f0cd7772b3718cc1e5e57e6fec76abd53bc4ce9 2024-09-19 08:15:14 +0000 UTC (modified)]

Reproduction steps

1. Configured the following to avoid any possible config limits.

otel.logs.mirror_to_disk=trueotel.instrumentation.jenkins.web.enabled=false
otel.instrumentation.jenkins.job.dsl.collapse.job.name=false
otel.exporter.otlp.timeout=60
otel.exporter.otlp.protocol=grpc
otel.span.event.count.limit=3840
otel.attribute.count.limit=3840
otel.span.link.count.limit=3840
otel.span.attribute.value.length.limit=9999999
elastic.apm.transaction_max_spans=1000000

2. Run in pipeline:
   echo sh(script: 'cat bigfile.txt', returnStdout: true )

3. Contents of bigfile.txt:

$ head bigfile.txt
This is line 1 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum
This is line 2 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum
This is line 3 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum
This is line 4 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

$ tail -n 3 bigfile.txt
This is line 8498 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum
This is line 8499 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum
This is line 8500 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

4. Output collected in ElasticSearch:

This is line 2553 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

This is line 2554 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

This is line 2555 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

This is line 2556 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum

+ ls -lrt

[Pipeline] echo

total 10

Output of subsequent shell commands function collected successfully, such as the ls -lrt command that was run after the cat command, seen above.

Expected Results

Expected the entire output of the cat to be collected in ES.

Actual Results

In 4. above, only around ~2550 lines was collected from the output of cat

Anything else?

Question, is there a config that limits the number of lines collected in a single span?
This is with the understanding that each line of output of the cat is a document that has a span.id
For eg:

          "span.id": [
            "44bc2188539ae87d"
          ],
          "message": [
            "This is line 1 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum"
          ],

          "span.id": [
            "44bc2188539ae87d"
          ],
          "message": [
            "This is line 1876 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum"
          ],

Are you interested in contributing a fix?

No response

[yueework]

Updated to APM 8.17.2 and verified with debug logs turned on.

Data received in APM also stops at line 2551 indicating the emission from OTel plugin is truncating output

{\"timeUnixNano\":\"1739322951513827896\",\"observedTimeUnixNano\":\"1739322951513827965\",\"severityNumber\":9,\"body\":{\"stringValue\":\"This is line 2549 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum\"},\"attributes\":[{\"key\":\"ci.pipeline.id\",\"value\":{\"stringValue\":\"Testing/childjob\"}},{\"key\":\"ci.pipeline.run.number\",\"value\":{\"intValue\":\"1799\"}},{\"key\":\"jenkins.pipeline.step.id\",\"value\":{\"stringValue\":\"64\"}}],\"flags\":1,\"traceId\":\"e5b8e0fe30b9e739ac65cee6d6812288\",\"spanId\":\"e1af12df4d591307\"},
{\"timeUnixNano\":\"1739322951513833595\",\"observedTimeUnixNano\":\"1739322951513833673\",\"severityNumber\":9,\"body\":{\"stringValue\":\"This is line 2550 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum\"},\"attributes\":[{\"key\":\"ci.pipeline.id\",\"value\":{\"stringValue\":\"Testing/childjob\"}},{\"key\":\"ci.pipeline.run.number\",\"value\":{\"intValue\":\"1799\"}},{\"key\":\"jenkins.pipeline.step.id\",\"value\":{\"stringValue\":\"64\"}}],\"flags\":1,\"traceId\":\"e5b8e0fe30b9e739ac65cee6d6812288\",\"spanId\":\"e1af12df4d591307\"},
{\"timeUnixNano\":\"1739322951513839254\",\"observedTimeUnixNano\":\"1739322951513839320\",\"severityNumber\":9,\"body\":{\"stringValue\":\"This is line 2551 - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum\"},\"attributes\":[{\"key\":\"ci.pipeline.id\",\"value\":{\"stringValue\":\"Testing/childjob\"}},{\"key\":\"ci.pipeline.run.number\",\"value\":{\"intValue\":\"1799\"}},{\"key\":\"jenkins.pipeline.step.id\",\"value\":{\"stringValue\":\"64\"}}],\"flags\":1,\"traceId\":\"e5b8e0fe30b9e739ac65cee6d6812288\",\"spanId\":\"e1af12df4d591307\"}
]}]}]}","ecs.version":"1.6.0"}

[kuisathaverat]

In APM, there is a limit on the event size, IIRC it should appear as an error/warning in the logs of the APM server. For most of those cases, the first place to check is the logs of the APM server, which usually gives some clues.

https://www.elastic.co/guide/en/apm/server/current/common-problems.html#event-too-large
https://www.elastic.co/guide/en/observability/current/apm-configuration-process.html#apm-max_event_size

[kuisathaverat]

I can replicate it with the default configuration on EDOT, it shows about 500 lines in this case

pipeline {
    agent any

    stages {
        stage('Hello') {
            steps {
                sh '''
                I=0
                while [ "$I" -lt 5000 ];
                do
                    echo "This is line ${I} - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum" >> test.txt
                    I=$(($I+1))
                done
                '''
                sh "cat test.txt"
            }
        }
    }
}

[sandeepbarnwal]

I can replicate it with the default configuration on EDOT, it shows about 500 lines in this case

pipeline {
agent any

stages {
    stage('Hello') {
        steps {
            sh '''
            I=0
            while [ "$I" -lt 5000 ];
            do
                echo "This is line ${I} - Lorem ipsum adipiscing elit, , sunt in culpa qui officia deserunt mollit anim id est laborum" >> test.txt
                I=$(($I+1))
            done
            '''
            sh "cat test.txt"
        }
    }
}

}

I also attempted to reproduce the issue using your pipeline script with the default configuration on EDOT and observed that the number of log lines varied with each build. Upon further debugging, I discovered that log records were being dropped during batch processing.

One of the metrics indicating this behavior is shown below:

2025-07-04 17:12:15 StartTimestamp: 2025-07-04 11:08:45.514 +0000 UTC
2025-07-04 17:12:15 Timestamp: 2025-07-04 11:42:15.124 +0000 UTC
2025-07-04 17:12:15 Value: 150
2025-07-04 17:12:15 ScopeMetrics #1
2025-07-04 17:12:15 ScopeMetrics SchemaURL: 
2025-07-04 17:12:15 InstrumentationScope io.opentelemetry.sdk.logs 
2025-07-04 17:12:15 Metric #0
2025-07-04 17:12:15 Descriptor:
2025-07-04 17:12:15      -> Name: processedLogs
2025-07-04 17:12:15      -> Description: The number of logs processed by the BatchLogRecordProcessor. [dropped=true if they were dropped due to high throughput]
2025-07-04 17:12:15      -> Unit: 1
2025-07-04 17:12:15      -> DataType: Sum
2025-07-04 17:12:15      -> IsMonotonic: true
2025-07-04 17:12:15      -> AggregationTemporality: Cumulative
2025-07-04 17:12:15 NumberDataPoints #0
2025-07-04 17:12:15 Data point attributes:
2025-07-04 17:12:15      -> dropped: Bool(true)
2025-07-04 17:12:15      -> processorType: Str(BatchLogRecordProcessor)

This behavior is caused by the queue size in BatchLogRecordProcessor being insufficient (default is 2049) for our use case, where a large number of logs are generated in a short period.

After tuning the queue size using otel.blrp.max.queue.size to approximately 75% of the total number of log lines in the file, the issue was resolved.

While there are other related configuration options, they do not fully address this scenario where log generation is both rapid and high in volume, frequently overwhelming the queue:

• otel.blrp.max.export.batch.size: Defines the maximum number of log records sent in a single export batch.

• otel.blrp.schedule.delay: Specifies the interval between export operations when the batch has not yet reached the maximum size. Please see -BatchLogRecordProcessor.java#L237

Please note that the configuration of the OTel Collector or the backend observability system also plays a key role here and must be tuned accordingly to handle the throughput.

What happens if some log lines exceed typical length limits?

The LogLimits class defines the maximum allowable length for a Log Record and the number of attributes it can have. By default, there is effectively no limit on the record length. I tested this by creating a log entry with 1,106,885 characters, and it was exported successfully without any problems. It's worth noting that this log entry is treated as a single item in the queue.