search

thubbo / jmeter-plugins-for-apache-dubbo

Dubbo Plugin for Apache JMeter, It is a plug-in developed for testing Dubbo in Jmeter.
Apache License 2.0
565 stars 290 forks source link

jmeter场景停止时jmeter.log会被清零。 #144

Closed x-dongzi closed 2 years ago

x-dongzi commented 3 years ago

问题如题所示，尝试了最新的2.7.4.1和更老的jar包，也试过Ctrl+C和shutdown命令来停止，不管哪种方式，只要jmeter进程一结束，jmeter.log就会清空，这个在哪里取消清空？因为我们需要查看log来确定报错情况，谢谢！

ningyu1 commented 3 years ago

@x-dongzi 没遇到过这种问题，理论上日志不会自动清空的，你检查一下你的jmeter配置或者sample中是否有类似的操作

x-dongzi commented 3 years ago

现在是从官网上下载下来的jmeter5.4.1解压后直接用就会这样，清空操作是发生在关闭jmeter窗口或者jmeter -n 命令退出的时候。在jmeter进程关闭之前log里面内容是一直有的。 很奇怪，那我再好好检查下看是哪里有干扰。

x-dongzi commented 3 years ago

这两天又验证了下，我用的是jmeter-plugins-dubbo-2.7.4.1-jar-with-dependencies.jar，所有的环境都是新的，应该就是jar包里面的某个地方触发导致的。 先说下复现的方法 1、把with-dependencies.jar放到lib/ext下 2、打开jmeter，我在linux和win下都试过，再开jmeter的时候，控制台会出现如下slf4j的警告信息

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/log4j-slf4j-i
mpl-2.13.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/ext/jmeter-pl
ugins-dubbo-2.7.4.1-jar-with-dependencies.jar!/org/slf4j/impl/StaticLoggerBinder
.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.

SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]

3、新建一个threadgroup，添加dubbo sampler，随便写的东西 4、保持jmeter窗口打开状态，别关闭，查看下jmeter.log，此时是有日志的，日志的例子如下：

2021-03-10 11:18:28,810 INFO o.a.j.u.JMeterUtils: Setting Locale to en_EN
2021-03-10 11:18:28,830 INFO o.a.j.JMeter: Loading user properties from: user.properties
2021-03-10 11:18:28,831 INFO o.a.j.JMeter: Loading system properties from: system.properties
2021-03-10 11:18:28,844 INFO o.a.j.JMeter: Copyright (c) 1998-2021 The Apache Software Foundation
2021-03-10 11:18:28,844 INFO o.a.j.JMeter: Version 5.4.1
2021-03-10 11:18:28,844 INFO o.a.j.JMeter: java.version=1.8.0_201
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: java.vm.name=Java HotSpot(TM) 64-Bit Server VM
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: os.name=Windows 7
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: os.arch=amd64
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: os.version=6.1
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: file.encoding=GBK
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: java.awt.headless=null
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: Max memory     =1073741824
2021-03-10 11:18:28,845 INFO o.a.j.JMeter: Available Processors =4
2021-03-10 11:18:28,851 INFO o.a.j.JMeter: Default Locale=English (EN)
2021-03-10 11:18:28,851 INFO o.a.j.JMeter: JMeter  Locale=English (EN)
2021-03-10 11:18:28,852 INFO o.a.j.JMeter: JMeterHome=D:\Data\apache-jmeter-5.4.1
2021-03-10 11:18:28,852 INFO o.a.j.JMeter: user.dir  =D:\Data\apache-jmeter-5.4.1\bin
2021-03-10 11:18:28,852 INFO o.a.j.JMeter: PWD       =D:\Data\apache-jmeter-5.4.1\bin
2021-03-10 11:18:28,853 INFO o.a.j.JMeter: IP: 192.168.8.103 Name: dong-PC FullName: windows10.microdone.cn
2021-03-10 11:18:28,971 INFO o.a.j.JMeter: Setting LAF to: com.github.weisj.darklaf.DarkLaf:com.github.weisj.darklaf.theme.DarculaTheme
2021-03-10 11:18:30,091 INFO o.a.j.JMeter: Loaded icon properties from org/apache/jmeter/images/icon.properties
2021-03-10 11:18:46,376 INFO o.a.d.c.l.LoggerFactory: using logger: org.apache.dubbo.common.logger.log4j.Log4jLoggerAdapter
2021-03-10 11:18:57,258 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times
2021-03-10 11:18:57,258 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to ISO-8859-1
2021-03-10 11:18:57,258 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true
2021-03-10 11:18:57,258 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000
2021-03-10 11:19:08,690 INFO o.a.j.s.FileServer: Default base='D:\Data\apache-jmeter-5.4.1\bin'
2021-03-10 11:19:08,692 INFO o.a.j.s.FileServer: Set new base='D:\Data\apache-jmeter-5.4.1\bin'
2021-03-10 11:19:08,932 INFO o.a.j.s.SaveService: Testplan (JMX) version: 2.2. Testlog (JTL) version: 2.2
2021-03-10 11:19:08,965 INFO o.a.j.s.SaveService: Using SaveService properties file encoding UTF-8
2021-03-10 11:19:08,967 INFO o.a.j.s.SaveService: Using SaveService properties version 5.0

5、关闭jmeter的窗口，这个时候再看jmeter.log，文件已经是清空状态了。

启动的时候，看到控制体有警告，所以就想查一下看是不是这个地方解决了就日志不会清空了，结果发现不是，解决掉这个警告后，日志还是会在jmeter退出的时候清空。 我解决的方法如下，看控制台报错的时候提示“See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.” 就去看了下这个页面，根据页面上的方法，在pom.xml上的4个地方（apollo、zookeeper、slf4j）加了4处排除

<!-- apollo -->
        <dependency>
            <groupId>org.apache.dubbo</groupId>
            <artifactId>dubbo-configcenter-apollo</artifactId>

            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-log4j12</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>log4j</groupId>
                    <artifactId>log4j</artifactId>
                </exclusion>
            </exclusions>

        </dependency>
        <!-- zookeeper -->
        <dependency>
            <groupId>org.apache.dubbo</groupId>
            <artifactId>dubbo-configcenter-zookeeper</artifactId>

            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-log4j12</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>log4j</groupId>
                    <artifactId>log4j</artifactId>
                </exclusion>
            </exclusions>

        </dependency>
<!-- slf4j -->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>

            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-log4j12</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>log4j</groupId>
                    <artifactId>log4j</artifactId>
                </exclusion>
            </exclusions>

        </dependency>
        <dependency>
            <groupId>org.slf4j</groupId>
<!--            <artifactId>log4j-over-slf4j</artifactId>-->
            <artifactId>log4j-over-slf4j</artifactId>
            <version>${slf4j.version}</version>

            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-log4j12</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>log4j</groupId>
                    <artifactId>log4j</artifactId>
                </exclusion>
            </exclusions>

        </dependency>

重新编译jar包，放到lib/ext下后，启动jmeter时控制台就不会再报warning了，但是一关闭jmeter，jmeter.log还是会被清空。 不知道具体是什么情况导致的了

x-dongzi commented 3 years ago

更新一下新的进展 全新试验了下2.7.4.1和2.7.8这两个jar包，2.7.4.1会清log，2.7.8不会清。 在控制台启动，打开dubbo sampler，并关闭jmeter，2.7.4.1输出如下

D:\Data\apache-jmeter-5.4.1\bin>jmeter.bat
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/log4j-slf4j-i
mpl-2.13.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/ext/jmeter-pl
ugins-dubbo-2.7.4.1-jar-with-dependencies.jar!/org/slf4j/impl/StaticLoggerBinder
.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.

SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
================================================================================

Don't use GUI mode for load testing !, only for Test creation and Test debugging
.
For load testing, use CLI Mode (was NON GUI):
   jmeter -n -t [jmx file] -l [results file] -e -o [Path to web report folder]
& increase Java Heap to meet your test requirements:
   Modify current env variable HEAP="-Xms1g -Xmx1g -XX:MaxMetaspaceSize=256m" in
 the jmeter batch file
Check : https://jmeter.apache.org/usermanual/best-practices.html
================================================================================

2021-03-10 16:20:04,787 DubboShutdownHook WARN Unable to register Log4j shutdown
 hook because JVM is shutting down. Using SimpleLogger

D:\Data\apache-jmeter-5.4.1\bin>

而2.7.8的输出如下：

D:\Data\apache-jmeter-5.4.1\bin>jmeter.bat
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/log4j-slf4j-i
mpl-2.13.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/D:/Data/apache-jmeter-5.4.1/lib/ext/jmeter-pl
ugins-dubbo-2.7.8-jar-with-dependencies.jar!/org/slf4j/impl/StaticLoggerBinder.c
lass]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.

SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
================================================================================

Don't use GUI mode for load testing !, only for Test creation and Test debugging
.
For load testing, use CLI Mode (was NON GUI):
   jmeter -n -t [jmx file] -l [results file] -e -o [Path to web report folder]
& increase Java Heap to meet your test requirements:
   Modify current env variable HEAP="-Xms1g -Xmx1g -XX:MaxMetaspaceSize=256m" in
 the jmeter batch file
Check : https://jmeter.apache.org/usermanual/best-practices.html
================================================================================

D:\Data\apache-jmeter-5.4.1\bin>

2.7.4.1比2.7.8多了一句

DubboShutdownHook WARN Unable to register Log4j shutdown hook because JVM is shutting down. Using SimpleLogger

我推测应该是这个地方导致的2.7.4.1退出jmeter的时候会清理log 查了一下，发现如果把jmeter/bin/下的log4j2.xml配置中加上shutdownHook="disable"，那2.7.4.1就也不会清空log文件了。

<Configuration status="WARN" packages="org.apache.jmeter.gui.logging" shutdownHook="disable">