jenkinsci / build-history-manager-plugin

Jenkins plugin that allows to define which builds should be removed and which preserved. Several decision factors such as date, number or result can be taken into account
https://plugins.jenkins.io/build-history-manager/
MIT License
4 stars 11 forks source link

Plugin spews MANY, MANY log messages. #49

Closed nightskyguy closed 2 years ago

nightskyguy commented 3 years ago

Version report

Jenkins and plugins versions report:

Jenkins: 2.277.4.3
OS: Linux - 4.15.0-47-generic
---
Parameterized-Remote-Trigger: "3.1.5.1"
ace-editor: "1.1"
analysis-collector: "2.0.0"
analysis-core: "1.96"
analysis-model-api: "10.0.0"
ansicolor: "1.0.0"
ant: "1.11"
antisamy-markup-formatter: "2.1"
any-buildstep: "0.1"
apache-httpcomponents-client-4-api: "4.5.13-1.0"
artifactdeployer: "0.33"
async-http-client: "1.7.24.3"
audit-trail: "3.8"
authentication-tokens: "1.4"
authorize-project: "1.4.0"
aws-credentials: "1.28.1"
aws-java-sdk: "1.11.995"
blame-upstream-commiters: "1.2"
blueocean: "DISABLED:1.24.6"
blueocean-autofavorite: "DISABLED:1.2.4"
blueocean-bitbucket-pipeline: "DISABLED:1.24.6"
blueocean-commons: "DISABLED:1.24.6"
blueocean-config: "DISABLED:1.24.6"
blueocean-core-js: "DISABLED:1.24.6"
blueocean-dashboard: "DISABLED:1.24.6"
blueocean-display-url: "DISABLED:2.4.1"
blueocean-events: "DISABLED:1.24.6"
blueocean-git-pipeline: "DISABLED:1.24.6"
blueocean-github-pipeline: "DISABLED:1.24.6"
blueocean-i18n: "DISABLED:1.24.6"
blueocean-jira: "DISABLED:1.24.6"
blueocean-jwt: "DISABLED:1.24.6"
blueocean-personalization: "DISABLED:1.24.6"
blueocean-pipeline-api-impl: "DISABLED:1.24.6"
blueocean-pipeline-editor: "DISABLED:1.24.6"
blueocean-pipeline-scm-api: "DISABLED:1.24.6"
blueocean-rest: "DISABLED:1.24.6"
blueocean-rest-impl: "DISABLED:1.24.6"
blueocean-web: "DISABLED:1.24.6"
bootstrap4-api: "4.6.0-3"
bouncycastle-api: "2.20"
branch-api: "2.6.3"
>> build-history-manager: "1.3.0"  <<
build-name-setter: "2.2.0"
build-timeout: "1.20"
build-token-root: "1.7"
build-user-vars-plugin: "1.7"
build-view-column: "0.3"
build-with-parameters: "1.5.1"
built-on-column: "1.1"
checks-api: "1.7.0"
checkstyle: "4.0.0"
claim: "2.18.2"
clang-scanbuild-plugin: "1.7"
cloudbees-aborted-builds: "1.14"
cloudbees-administrative-monitors: "1.0.1"
cloudbees-analytics: "1.28"
cloudbees-assurance: "2.276.0.3"
cloudbees-aws-cli: "1.5.15"
cloudbees-aws-deployer: "1.18"
cloudbees-bitbucket-branch-source: "2.9.7"
cloudbees-blueocean-default-theme: "DISABLED:0.8"
cloudbees-consolidated-build-view: "1.6.1"
cloudbees-credentials: "3.3"
cloudbees-even-scheduler: "3.10"
cloudbees-folder: "6.15"
cloudbees-folders-plus: "3.12"
cloudbees-groovy-view: "1.13"
cloudbees-ha: "DISABLED:4.27"
cloudbees-jsync-archiver: "5.15"
cloudbees-label-throttling-plugin: "3.8"
cloudbees-license: "9.53"
cloudbees-long-running-build: "1.16"
cloudbees-monitoring: "2.11"
cloudbees-nodes-plus: "1.22"
cloudbees-platform-common: "1.7"
cloudbees-plugin-usage: "2.7"
cloudbees-quiet-start: "1.7"
cloudbees-request-filter: "1.7"
cloudbees-ssh-slaves: "2.9"
cloudbees-support: "3.26"
cloudbees-template: "4.49"
cloudbees-uc-data-api: "4.43"
cloudbees-unified-ui: "1.6"
cloudbees-update-center-plugin: "4.59"
cloudbees-view-creation-filter: "1.6"
cloudbees-workflow-template: "3.12"
cloudbees-workflow-ui: "2.6"
clover: "4.12.0"
cobertura: "1.16"
code-coverage-api: "1.3.2"
command-launcher: "1.5"
concurrent-step: "1.0.0"
conditional-buildstep: "1.4.1"
config-file-provider: "3.7.2"
configuration-as-code: "1.47"
configuration-as-code-support: "DISABLED:1.18"
copyartifact: "1.46"
cors-filter: "1.1"
coverity: "1.11.4"
create-fingerprint: "1.2"
credentials: "2.3.15.1"
credentials-binding: "1.24"
cucumber-testresult-plugin: "0.10.1"
dashboard-view: "2.16"
data-tables-api: "1.10.23-3"
depgraph-view: "1.0.5"
deployed-on-column: "1.8"
deployer-framework: "1.3"
description-setter: "1.10"
display-url-api: "2.3.4"
docker-build-publish: "1.3.3"
docker-commons: "1.17"
docker-java-api: "3.1.5.2"
docker-plugin: "1.2.2"
docker-traceability: "1.2"
docker-workflow: "1.26"
dockerhub-notification: "2.5.2"
downstream-build-cache: "1.6"
downstream-buildview: "1.9"
dropdown-viewstabbar-plugin: "1.7"
dtkit-api: "3.0.0"
durable-task: "1.35"
echarts-api: "5.0.1-1"
email-ext: "2.82"
embeddable-build-status: "2.0.3"
emma: "1.31"
envinject: "2.4.0"
envinject-api: "1.7"
external-monitor-job: "1.7"
fail-the-build-plugin: "1.0"
favorite: "DISABLED:2.3.3"
file-leak-detector: "1.6"
findbugs: "5.0.0"
flexible-publish: "0.16.1"
font-awesome-api: "5.15.2-2"
forensics-api: "1.0.0"
git: "4.7.1"
git-client: "3.7.1"
git-parameter: "0.9.13"
git-server: "1.9"
git-validated-merge: "3.30"
github: "1.33.1"
github-api: "1.123"
github-branch-source: "2.10.2"
github-pull-request-build: "1.13"
gradle: "1.36"
greenballs: "1.15.1"
groovy: "2.4"
groovy-events-listener-plugin: "1.014"
handlebars: "1.1.1"
handy-uri-templates-2-api: "2.1.8-1.0"
hsts-filter-plugin: "1.0"
htmlpublisher: "1.25"
http_request: "1.9.0"
hue-light: "1.2.0"
icon-shim: "3.0.0"
icon-shim-plugin: "1.0.0"
ignore-committer-strategy: "1.0.4"
infradna-backup: "3.38.34"
jackson2-api: "2.12.1"
jacoco: "3.1.1"
javadoc: "1.6"
jaxb: "2.3.0.1"
jdk-tool: "1.5"
jenkins-design-language: "DISABLED:1.24.6"
jenkins-multijob-plugin: "1.36"
jira: "3.2.1"
jjwt-api: "0.11.2-5.143e44951c52"
job-dsl: "1.77"
join: "1.21"
jquery: "1.12.4-1"
jquery-detached: "1.2.1"
jquery-ui: "1.0.2"
jquery3-api: "3.6.0-1"
jsch: "0.1.55.2"
junit: "1.49"
kubernetes: "1.29.2"
kubernetes-client-api: "4.13.2-1"
kubernetes-credentials: "0.8.0"
label-linked-jobs: "6.0.1"
ldap: "2.4"
lenientshutdown: "1.1.1"
lockable-resources: "2.10"
log-parser: "DISABLED:2.1"
login-theme: "1.1"
mail-watcher-plugin: "1.16"
mailer: "1.34"
managed-scripts: "1.5.4"
mapdb-api: "1.0.9.0"
matrix-auth: "2.6.6"
matrix-project: "1.18"
matrixtieparent: "1.2"
maven-plugin: "3.10"
mercurial: "2.14"
metrics: "4.0.2.7"
mission-control-view: "0.9.16"
momentjs: "1.1.1"
monitoring: "1.87.0"
msbuild: "1.30"
mstest: "1.0.0"
mstestrunner: "1.3.0"
multibranch-action-triggers: "1.8.6"
multiple-scms: "0.8"
nectar-license: "8.31"
nectar-rbac: "5.57"
next-build-number: "1.6"
node-iterator-api: "1.5"
nodelabelparameter: "1.8.1"
notification: "1.14"
okhttp-api: "3.14.9"
operations-center-agent: "2.277.0.2"
operations-center-analytics-config: "2.222.0.1"
operations-center-analytics-reporter: "2.222.0.1"
operations-center-client: "2.277.0.4"
operations-center-cloud: "2.277.0.1"
operations-center-context: "2.277.0.5"
operations-center-openid-cse: "1.8.110"
pagerduty: "0.7.0"
pam-auth: "1.6"
parameterized-trigger: "2.40"
pipeline-build-step: "2.13"
pipeline-github: "2.7"
pipeline-github-lib: "1.0"
pipeline-graph-analysis: "1.10"
pipeline-input-step: "2.12"
pipeline-milestone-step: "1.3.2"
pipeline-model-api: "1.8.4"
pipeline-model-declarative-agent: "1.1.1"
pipeline-model-definition: "1.8.4"
pipeline-model-extensions: "1.8.4"
pipeline-rest-api: "2.19"
pipeline-stage-step: "2.5"
pipeline-stage-tags-metadata: "1.8.4"
pipeline-stage-view: "2.19"
pipeline-utility-steps: "2.8.0"
plain-credentials: "1.7"
plugin-util-api: "2.1.0"
pmd: "4.0.0"
popper-api: "1.16.1-2"
postbuildscript: "2.11.0"
preSCMbuildstep: "0.3"
promoted-builds: "3.9.1"
pubsub-light: "DISABLED:1.13"
python: "1.3"
rake: "1.8.0"
rebuild: "1.32"
resource-disposer: "0.15"
run-condition: "1.5"
saml: "2.0.3"
scm-api: "2.6.4"
script-security: "1.76"
scriptler: "3.1"
secure-requester-whitelist: "1.6"
skip-plugin: "4.10"
snakeyaml-api: "1.27.0"
sse-gateway: "DISABLED:1.24"
ssh-agent: "1.22"
ssh-credentials: "1.18.1"
ssh-slaves: "1.31.5"
structs: "1.22"
subversion: "2.14.2"
support-core: "2.72.1"
suppress-stack-trace: "1.6"
testdroid-run-in-cloud: "2.114.0"
testng-plugin: "1.15"
text-file-operations: "1.3.2"
throttle-concurrents: "2.2"
timestamper: "1.12"
token-macro: "2.15"
translation: "1.15"
trigger-restrictions: "1.6"
trilead-api: "1.0.13"
unique-id: "2.2.0"
uno-choice: "2.5.6"
variant: "1.4"
view-job-filters: "2.3"
violations: "0.7.11"
warnings: "DISABLED:5.0.1"
warnings-ng: "9.0.1"
wikitext: "3.13"
windows-slaves: "1.7"
workflow-aggregator: "2.6"
workflow-api: "2.42"
workflow-basic-steps: "2.23"
workflow-cps: "2.90"
workflow-cps-checkpoint: "2.10"
workflow-cps-global-lib: "2.18"
workflow-cps-global-lib-http: "1.13.0"
workflow-durable-task-step: "2.38"
workflow-job: "2.40"
workflow-multibranch: "2.23"
workflow-remote-loader: "1.5"
workflow-scm-step: "2.12"
workflow-step-api: "2.23"
workflow-support: "3.8"
ws-cleanup: "0.39"
xcode-plugin: "2.0.15"
xunit: "3.0.2"
yet-another-build-visualizer: "1.14"
Ubuntu: OS: Linux - 4.15.0-47-generic

Reproduction steps

#!groovy
  properties([[$class: 'JiraProjectProperty'], 
    buildDiscarder(BuildHistoryManager([[actions: [], conditions: [], continueAfterMatch: false, matchAtMost: 3],  // SKIP latest 3 builds 
        [actions: [], conditions: [BuildResult(matchSuccess: true)], continueAfterMatch: false, matchAtMost: 1],   // SKIP to and OVER the most recent SUCCESSful build.
        // to test, may want to delete the log file [$class: 'DeleteLogFileAction'] rather than the whole build.
        [actions: [DeleteBuild()], conditions: [MatchEveryBuild(), BuildResult(matchSuccess: true)], continueAfterMatch: false], // Delete all remaining successful builds.
        [actions: [], conditions: [MatchEveryBuild()], continueAfterMatch: false, matchAtMost: 4],  // keep 4 more builds (total of 8)
        [actions: [DeleteBuild()], conditions: [], continueAfterMatch: false]])), // delete all the remaining builds regardless of status
        disableConcurrentBuilds(), disableResume(), [$class: 'RebuildSettings', autoRebuild: false, rebuildDisabled: false], 
        parameters([booleanParam(defaultValue: false, description: '', name: 'FAILME')]), 
        throttleJobProperty(categories: [], limitOneJobWithMatchingParams: false, maxConcurrentPerNode: 0, maxConcurrentTotal: 0, paramsToUseForLimit: '', throttleEnabled: false, throttleOption: 'project')]
        )
    if (params.FAILME)
    {
        currentBuild.description = 'FAIL'
        sleep 5
        error "Forced to fail"
    } else {
        currentBuild.description = 'SUCCESS'
    }

Results

Expected result:

I expect perhaps one or two log messages per build - independent of the number of builds in the job or the number of rules.

Something like

Processing BuildHistory for Job X build number N with 200 builds. Applying 4 rules. ... Done process BuildHistory for Job X build number N: 23 builds deleted, 2 logs removed, 0 artifacts removed.

I also expect that a DEBUG level log could be set to determine what rule(s) are being applied. But this level of detail should only be enabled if DEBUG level logging is enabled.

Actual result:

Info Level logging swamps the Jenkins log (this example is from kibana in reverse order). Here are 138 messages from ONE build with only 8 retained builds. Note that this came from Kibana and was resorted to restore proper order, so may not match the actual log order (since it will sort two records with the same time alphabetically). However these are all the log messages that were received.

2021-06-10 22:38:27.730+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Start evaluating build history
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 2
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #135
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #136
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #137
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #138
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #139
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.731+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.732+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 3
2021-06-10 22:38:27.732+0000 [id=52]    INFO    p.d.j.b.model.Rule#performActions: platform/slave/slc_monitor_TEST: Processing action 'Delete build' for build #135
2021-06-10 22:38:27.732+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.732+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.742+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #134
2021-06-10 22:38:27.742+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.742+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.742+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.742+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #132
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.743+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #130
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #131
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.744+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #136
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #137
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #138
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #139
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Start evaluating build history
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.745+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.745+0000 [id=52]    INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.745+0000 [id=52]    INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 2
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #132
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #134
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.746+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #131
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.747+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing build #130
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 1
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 2
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 3
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 1 times
2021-06-10 22:38:27.754+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Skipping rule because matched 3 times
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing actions for rule no 4
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.BuildHistoryManager#perform: platform/slave/slc_monitor_TEST: Processing rule no 4
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Condition 'Build result' does not match
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Build result'
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'
2021-06-10 22:38:27.755+0000 [id=15922] INFO    p.d.j.b.model.Rule#validateConditions: platform/slave/slc_monitor_TEST: Processing condition 'Match every build'

image

damianszczepanik commented 3 years ago

This is not a bug. This is a feature.

Imagine the situation when you are designing rules and conditions for new job. This helps you to prove that configuration is correct. This also helps me to fix the problem in case user reports bug.

nightskyguy commented 2 years ago

This makes your plugin incompatible with our use of Jenkins. We can't afford thousands and thousands of lines of INFO level debugging that swamps all other logs. If someone DID need to debug, they could always add logging via the log manager.

Checking if Cloudbees supports SUPPRESSING logs using the log manager... but this is the first (and only) plugin we've used that exhibits this overabundance of logs.

https://support.cloudbees.com/hc/en-us/articles/204880580/comments/4408473755675

a-wildman commented 2 years ago

I disagree that this is a 'feature' -- such logging should occur at level DEBUG or TRACE. One can always set a custom logging level for a specific package if one wants to inspect how new rules are being evaluated.

On my Jenkins instance, INFO logging for this plugin is 844K lines per minute.

INFO is clearly not the right level for this kind of output.

damianszczepanik commented 2 years ago

The goal is to show those log at job level not Jenkins level because access to the first is generally allowed for everyone while Jenkins logs is available only for admins

a-wildman commented 2 years ago

This is a fair goal, but the problem is that these are not being logged at the job level, they are going to the Jenkins log itself.

On Feb 21, 2022, at 4:09 AM, Damian Szczepanik @.***> wrote:

 The goal is to show those log at job level not Jenkins level because access to the first is generally allowed for everyone while Jenkins logs is available only for admins

— Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android. You are receiving this because you commented.

damianszczepanik commented 2 years ago

That's true and this is because code that clears old jobs has no access to job context

phillipjohnston commented 2 years ago

This is definitely a problem that the default is DEBUG and not INFO, it is a ton of output. Why is it a feature to use up file system space and clutter a log with undesired information?

damianszczepanik commented 2 years ago

@phillipjohnston @nightskyguy @a-wildman can you review https://github.com/jenkinsci/build-history-manager-plugin/pull/59 - does it solve this problem ?

damianszczepanik commented 2 years ago

Published