Jenkins 控制台输出充斥着 [DEBUG] http-outgoing 日志条目
Jenkins console output flooded with [DEBUG] http-outgoing log entries
我们有一个构建作业,其中控制台输出显示许多如下所示的奇怪消息,因此我们无法加载完整的日志并且必须删除构建配置中的 -X
选项以摆脱它们。我想是我升级Jenkins版本后发生的。
知道是什么原因造成的吗?
[DEBUG] http-outgoing-0 >> "j[0x5]q4/J[0x18]^di[0x86][0xbf]C_[0xd6]G[0x1d]
[0xd4][0x7][0xf3][0xc7][0x14][0xdf][0x8d][0xe1][0x13][0xd8]$y|#[0x1e][0xbf]
[0xe6][0x81]<[0xca][0x6][0xa1]~j[0x81]3[0xbc][0x98][0xd1][0x83][0xa7]
[0xc5]8[0xfa]>[0xd9]edZ[0xb2][0xc][0xe0][0x5][0xab][0xf3][0x1a]M[0xb3][0xe7]
[0x1][0xf4][\n]"
[DEBUG] http-outgoing-0 >> "[0xcd][0x9d][0x86]Zjp[0xb4][0x8d][0x87]
[0x8f]cn[0xe7][0xab]oL.[0xb2]}[0x86][0xf8]D[0x87][0xba][0x9d][0xcc]j[0x15]
[0xa4][0xe6]![0x9f]_BBC[0xbf]j[0xab]Rl[0x10][0x92][0xc5])[0xb2][0xc5]i[0xc2]
我大约在同一时间(2018 年 4 月)遇到了这个问题,发现它是由 Artifactory 插件 2.15.0(及更高版本)触发的。一年多来,我一直将该插件降级,以避免在我的构建日志中记录 DEBUG。尽管这对我有用(直到上周由于与新版本的 Artifactory 不兼容而被迫升级),您的类路径中的其他插件或 jar 文件可能会导致您的问题。
在花了整个周末解决这个问题后,我终于在我的构建环境中找到了根本原因。
重点是:
- 这是构建过程(例如 Ant)的类路径的问题。
- 这不是 Jenkins 的配置问题。
- 这无法通过项目配置解决。
- 触发器(Jenkins 或插件更新)不一定是 DEBUG 日志的根本原因。
- 触发此问题时,可能有多种原因,导致此问题很难排查。
休眠问题
就我而言,DEBUG 日志记录的根本原因是我的测试依赖项中有 cobertura-2.1.1.jar,其中包含 logback.xml 文件并且还带来了 logback-classic.jar 作为依赖项(被广泛认为是一个错误,参见 Issue 2, Issue 14, Issue 36 ). logback.xml 文件在类路径中找到时,会覆盖 Jenkins(以及正在构建的项目)中的任何其他 logback 设置。但是,由于 logback 不是由 Apache Commons Logging (JCL) 编辑的日志框架 select,因此从未触发过此日志设置。
触发器
将 Artifactory 插件从 2.14.0 升级到 2.15.0 将其日志记录从:commons-logging-1.1.1.jar (log4j-1.2.17.jar) 到:jcl-over-slf4j-1.7.25.jar (slf4j -api-1.7.25.jar)。仅供参考,log4j 1.x uses a default root logging level of DEBUG, while log4j 2.x 使用 ERROR 的全局日志记录级别,可能 是完全不同的 DEBUG 日志记录来源(但在我的情况下不是)。我的构建环境 (ant) 在类路径上提供了 log4j 2.10.0 和 logback,这只会根据构建过程中 运行 的插件产生不一致的结果来混淆我的测试。
当使用 Artifactory 插件 v2.15.0+ 时,日志框架切换到 logback,这会在 cobertura-2.1 中提供 logback.xml 文件。 1.jar 将根日志级别设置为 DEBUG 的权限,强制构建过程的所有后续部分以 DEBUG 级别记录。这包括 Apache Commons HttpClient 的 wire-logging,它生成 http-outgoing-0(序列化的十六进制 和 每条 HTTP/S 消息中的交错 Base64 编码内容 - 如您在问题中所示)。即使对于一个小项目,以这种方式记录 JAR 文件的单个 PUT 也会将构建时间和构建日志的大小增加几个数量级(这是我在构建环境中遇到的情况),这可以轻松削弱整个 Jenkins 服务器。这是一个巨大的问题,正如您从上面的 Cobertura GitHub 问题中看到的那样,即使它很容易修复,也没有采取措施在四年内生成修复版本。
修复
要解决此问题,我必须在我的 Jenkins 服务器上进行几项更改:
将logback-classic.jar和logback-core.jar替换为slf4j-simple-1.7.26.jar 在我的 .ant/lib 文件夹中(这是 Ant 在构建和测试我的时使用的类路径项目)。此更改完全阻止在 Ant 中使用 logback(因此类路径中的任何 logback.xml 文件变得无关紧要),同时仍然允许您的构建通过 SLF4J API(通过slf4j-simple)。
删除对冗余日志记录版本的任何依赖(例如,不要同时包含 commons-logging-1.1.1 和 commons-logging-1.2 在类路径中)。如果使用 log4j,这一点尤其重要,其中 1.1 版默认为 DEBUG,而 1.2 版默认为 ERROR。你永远不知道 JCL 会选择哪个底层框架,所以你想给它尽可能少的选择。
最后为了测试环境和Ant环境匹配,我把自己项目全部的依赖调整为 exclude logback-classic (我使用 Ivy 进行依赖解析,所以 maven 或 gradle 会有不同的语法):
<dependency org="net.sourceforge.cobertura" name="cobertura" rev="latest.release" conf="test->default">
<exclude org="org.apache.ant" />
<exclude name="jaxen" />
<exclude name="jetty" />
<exclude name="jetty-util" />
<exclude name="servlet-api-2.5" />
<exclude name="logback-classic" /> <!-- IMPORTANT -->
</dependency>
作为参考,我的 broken .ant/lib 文件夹包含这些 logging-related jar 文件(2 个可能的来源调试日志):
- commons-logging-1.1.1.jar (redundat JCL 版本,不确定使用的是哪个)
- commons-logging-1.2.jar
- slf4j-api-1.7.21.jar (新神器插件使用的日志框架)
- logback-classic-1.0.13.jar (cobertura-2.1.1 中包含的日志框架)
- logback-core-1.0.13.jar
而我的 fixed .ant/lib 文件夹包含以下日志记录 jar:
- commons-logging-1.2.jar (现在唯一可用的JCL版本)
- slf4j-api-1.7.26.jar (现在唯一可用的日志框架)
- slf4j-simple-1.7.26.jar (现在唯一的SLF4J实现)
在我固定的Ant类路径中,commons-logging-1.2只能select SLF4J API(或JUL),并且只能单个 SLF4J 实现可用(slf4j-simple)。
TL;DR
三年来,Cobertura 2.1.1 告诉 logback 到 "DEBUG All the Things!",但直到新版本的 Artifactory 插件更改了 JCL 版本并且没有人在听带来了一个 SLF4J 实现,允许将 logback selected 作为 "best available" 日志框架。当 JCL 被引入到 logback 时,logback 采纳了 Cobertura 的建议并在我的构建日志中举办了一场派对。这可以通过从环境中删除 logback 并为 JCL 和 SLF4J API(例如 slf4j-simple)提供 well-behaved 日志框架来防止。
我们有一个构建作业,其中控制台输出显示许多如下所示的奇怪消息,因此我们无法加载完整的日志并且必须删除构建配置中的 -X
选项以摆脱它们。我想是我升级Jenkins版本后发生的。
知道是什么原因造成的吗?
[DEBUG] http-outgoing-0 >> "j[0x5]q4/J[0x18]^di[0x86][0xbf]C_[0xd6]G[0x1d]
[0xd4][0x7][0xf3][0xc7][0x14][0xdf][0x8d][0xe1][0x13][0xd8]$y|#[0x1e][0xbf]
[0xe6][0x81]<[0xca][0x6][0xa1]~j[0x81]3[0xbc][0x98][0xd1][0x83][0xa7]
[0xc5]8[0xfa]>[0xd9]edZ[0xb2][0xc][0xe0][0x5][0xab][0xf3][0x1a]M[0xb3][0xe7]
[0x1][0xf4][\n]"
[DEBUG] http-outgoing-0 >> "[0xcd][0x9d][0x86]Zjp[0xb4][0x8d][0x87]
[0x8f]cn[0xe7][0xab]oL.[0xb2]}[0x86][0xf8]D[0x87][0xba][0x9d][0xcc]j[0x15]
[0xa4][0xe6]![0x9f]_BBC[0xbf]j[0xab]Rl[0x10][0x92][0xc5])[0xb2][0xc5]i[0xc2]
我大约在同一时间(2018 年 4 月)遇到了这个问题,发现它是由 Artifactory 插件 2.15.0(及更高版本)触发的。一年多来,我一直将该插件降级,以避免在我的构建日志中记录 DEBUG。尽管这对我有用(直到上周由于与新版本的 Artifactory 不兼容而被迫升级),您的类路径中的其他插件或 jar 文件可能会导致您的问题。
在花了整个周末解决这个问题后,我终于在我的构建环境中找到了根本原因。
重点是:
- 这是构建过程(例如 Ant)的类路径的问题。
- 这不是 Jenkins 的配置问题。
- 这无法通过项目配置解决。
- 触发器(Jenkins 或插件更新)不一定是 DEBUG 日志的根本原因。
- 触发此问题时,可能有多种原因,导致此问题很难排查。
休眠问题
就我而言,DEBUG 日志记录的根本原因是我的测试依赖项中有 cobertura-2.1.1.jar,其中包含 logback.xml 文件并且还带来了 logback-classic.jar 作为依赖项(被广泛认为是一个错误,参见 Issue 2, Issue 14, Issue 36 ). logback.xml 文件在类路径中找到时,会覆盖 Jenkins(以及正在构建的项目)中的任何其他 logback 设置。但是,由于 logback 不是由 Apache Commons Logging (JCL) 编辑的日志框架 select,因此从未触发过此日志设置。
触发器
将 Artifactory 插件从 2.14.0 升级到 2.15.0 将其日志记录从:commons-logging-1.1.1.jar (log4j-1.2.17.jar) 到:jcl-over-slf4j-1.7.25.jar (slf4j -api-1.7.25.jar)。仅供参考,log4j 1.x uses a default root logging level of DEBUG, while log4j 2.x 使用 ERROR 的全局日志记录级别,可能 是完全不同的 DEBUG 日志记录来源(但在我的情况下不是)。我的构建环境 (ant) 在类路径上提供了 log4j 2.10.0 和 logback,这只会根据构建过程中 运行 的插件产生不一致的结果来混淆我的测试。
当使用 Artifactory 插件 v2.15.0+ 时,日志框架切换到 logback,这会在 cobertura-2.1 中提供 logback.xml 文件。 1.jar 将根日志级别设置为 DEBUG 的权限,强制构建过程的所有后续部分以 DEBUG 级别记录。这包括 Apache Commons HttpClient 的 wire-logging,它生成 http-outgoing-0(序列化的十六进制 和 每条 HTTP/S 消息中的交错 Base64 编码内容 - 如您在问题中所示)。即使对于一个小项目,以这种方式记录 JAR 文件的单个 PUT 也会将构建时间和构建日志的大小增加几个数量级(这是我在构建环境中遇到的情况),这可以轻松削弱整个 Jenkins 服务器。这是一个巨大的问题,正如您从上面的 Cobertura GitHub 问题中看到的那样,即使它很容易修复,也没有采取措施在四年内生成修复版本。
修复
要解决此问题,我必须在我的 Jenkins 服务器上进行几项更改:
将logback-classic.jar和logback-core.jar替换为slf4j-simple-1.7.26.jar 在我的 .ant/lib 文件夹中(这是 Ant 在构建和测试我的时使用的类路径项目)。此更改完全阻止在 Ant 中使用 logback(因此类路径中的任何 logback.xml 文件变得无关紧要),同时仍然允许您的构建通过 SLF4J API(通过slf4j-simple)。
删除对冗余日志记录版本的任何依赖(例如,不要同时包含 commons-logging-1.1.1 和 commons-logging-1.2 在类路径中)。如果使用 log4j,这一点尤其重要,其中 1.1 版默认为 DEBUG,而 1.2 版默认为 ERROR。你永远不知道 JCL 会选择哪个底层框架,所以你想给它尽可能少的选择。
最后为了测试环境和Ant环境匹配,我把自己项目全部的依赖调整为 exclude logback-classic (我使用 Ivy 进行依赖解析,所以 maven 或 gradle 会有不同的语法):
<dependency org="net.sourceforge.cobertura" name="cobertura" rev="latest.release" conf="test->default"> <exclude org="org.apache.ant" /> <exclude name="jaxen" /> <exclude name="jetty" /> <exclude name="jetty-util" /> <exclude name="servlet-api-2.5" /> <exclude name="logback-classic" /> <!-- IMPORTANT --> </dependency>
作为参考,我的 broken .ant/lib 文件夹包含这些 logging-related jar 文件(2 个可能的来源调试日志):
- commons-logging-1.1.1.jar (redundat JCL 版本,不确定使用的是哪个)
- commons-logging-1.2.jar
- slf4j-api-1.7.21.jar (新神器插件使用的日志框架)
- logback-classic-1.0.13.jar (cobertura-2.1.1 中包含的日志框架)
- logback-core-1.0.13.jar
而我的 fixed .ant/lib 文件夹包含以下日志记录 jar:
- commons-logging-1.2.jar (现在唯一可用的JCL版本)
- slf4j-api-1.7.26.jar (现在唯一可用的日志框架)
- slf4j-simple-1.7.26.jar (现在唯一的SLF4J实现)
在我固定的Ant类路径中,commons-logging-1.2只能select SLF4J API(或JUL),并且只能单个 SLF4J 实现可用(slf4j-simple)。
TL;DR
三年来,Cobertura 2.1.1 告诉 logback 到 "DEBUG All the Things!",但直到新版本的 Artifactory 插件更改了 JCL 版本并且没有人在听带来了一个 SLF4J 实现,允许将 logback selected 作为 "best available" 日志框架。当 JCL 被引入到 logback 时,logback 采纳了 Cobertura 的建议并在我的构建日志中举办了一场派对。这可以通过从环境中删除 logback 并为 JCL 和 SLF4J API(例如 slf4j-simple)提供 well-behaved 日志框架来防止。