通过TestNg自定义结果报告快速定位失败用例

最近在写自动化时对困扰很久的一个问题进行了优化,问题主要是在线上使用自动化用例回归时无法快速定位到失败用例的信息,当然主要是无法精确看到case运行时的日志信息,导致分析失败原因比较困难。

问题分析

当前所在的项目组主要以服务端测试为主,所有模块基本全部实现自动化,自动化主要有以下几个特点:

  • 自动化代码以java为主,测试代码均使用TestNG
  • 所测模块接口较多,服务端逻辑复杂,导致测试用例多,且测试方法逻辑复杂
  • 每个自动化测试方法都使用dataProvider形式为测试用例提供测试数据,接口参数多会导致每个dataProvider数据数量多

上述的特点决定了在运行一个测试方法时,根据dataProvider提供数据的条数会运行多次,假如其中一条数据导致用例失败,testng日志中展示的结果仅会打印出失败的测试方法及断言错误信息,根据测试方法去日志中搜索日志会发现较多正常通过用例执行日志会被过滤出来。

一般来说如果有用例失败,testng最终的reporter会打印类似如下的信息:

 PASSED: testCaseOne
FAILED: testCaseTwo
java.lang.AssertionError: expected:<true> but was:<false>
    at org.testng.Assert.fail(Assert.java:89)
    at org.testng.Assert.failNotEquals(Assert.java:489)
    ....
    at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:152)
    at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:57)


===============================================
    Default test
    Tests run: 2, Failures: 1, Skips: 0
===============================================


===============================================
Default suite
Total tests run: 2, Failures: 1, Skips: 0
===============================================

如果你是通过mvn test方式执行测试,那么结果信息类似如下:

 Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 10.35 sec <<< FAILURE! - in TestSuite
testCaseTwo(com.netease.nos.test.utils.ExampleTest)  Time elapsed: 0.003 sec  <<< FAILURE!
java.lang.AssertionError: expected:<true> but was:<false>
    at org.testng.Assert.fail(Assert.java:89)
    at org.testng.Assert.failNotEquals(Assert.java:489)
    at org.testng.Assert.assertTrue(Assert.java:37)
    at org.testng.Assert.assertTrue(Assert.java:47)
    at com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:25)


Results :

Failed tests:
  ExampleTest.testCaseTwo:25 expected:<true> but was:<false>

Tests run: 2, Failures: 1, Errors: 0, Skipped: 0

从上面两种执行方法得到的测试结果来看,对于失败的用例我们仅能获取到失败用例的测试方法名称,但由于同一个用例方法有多组数据,即有多个用例,仅仅靠方法名称去反查日志信息便比较困难,且当前线上回归本地不通无法通过开发工具来进行调试验证失败的测试用例,只能在跳板机上通过mvn test方式执行测试集,最终根据日志的打印信息来看用例失败的初步原因。

问题解决

从上面分析看,如果希望能够快速定位到失败用例的执行日志信息,首先每一个case的运行,日志中需要包含其独有的标签信息,其次在最终结果输出中,不仅仅需要知道失败的测试方法,且需要知道失败用例对应的标签信息。

首先第一个问题的解决较为简单,通常的做法便是生成唯一的Id信息,比如通常说的RequestId。在用例方法中所有日志信息打印时将生成的id信息带入即可。

第二个问题,如何把上述标签信息带入到最终结果报告中,或者如何能够通过必要的标签信息快速定位到测试用例执行情况是解决整个问题的关键。

熟悉TestNg的人都会注意到,TestNg本身提供了一些自定义报告及自定义日志的方法,为此我们可以以此为基础传入必要的标签信息,并最终输出即可。按照此思路,可以有两种选择,一种是通过自定义日志记录的方式,一种是通过自定义report的形式。

自定义日志记录的方法:

  • 创建名称为CustomListener.java的类,内容如下(其中失败的用例日志可以添加特殊标签便于过滤):

import org.testng.ITestResult;
import org.testng.TestListenerAdapter;

public class CustomListener extends TestListenerAdapter {
    private int m_count = 0;

    @Override
    public void onTestFailure(ITestResult tr) {
        log("\n==================failed case==================\n");
        log(tr.getName() + "--Test method failed,  requestId: " + tr.getAttribute(TestHelper.reuestId) + "\n");
        log("===============================================\n");
    }

    @Override
    public void onTestSkipped(ITestResult tr) {
        log(tr.getName() + "--Test method skipped\n");
    }

    @Override
    public void onTestSuccess(ITestResult tr) {
        log(tr.getName() + "--Test method success\n");
    }

    private void log(String string) {
        System.out.print(string);
        if (++m_count % 40 == 0) {
            System.out.println("");
        }
    }

}
  • 在测试方法中传入标签信息到当前测试用例结果中,如下finally中两行代码:
@Test
public void testCaseTwo() {
    String requestId = CommonUtils.generateRequestId();
    logger.debug(String.format("requestId: %s ========== Start testCaseTwo =========", requestId));
    try {
        logger.debug(String.format("requestId: %s , Err testcase", requestId));
        Assert.assertTrue(false);
    } finally {
        ITestResult tr = Reporter.getCurrentTestResult();
        tr.setAttribute("requestId", requestId);
    }
}

上述准备完成之后,如何才能让自定义的listenner生效呢,有以下几种方法:

  • 方法一:

通过注解的方式,在测试类上方添加注解,如下所示:

 @Listeners(CustomListener.class)
public class ExampleTest {
    private static final Logger logger = Logger.getLogger(ExampleTest.class);
  • 方法二:

在创建的用例集,即xml文件中添加listener信息,如下:

<suite name="sdk test suite all">
    <listeners>
        <listener class-name="com.netease.nos.test.utils.CustomListener" />
    </listeners>
    <test name="sdkTest">
    <classes>
        <class name="com.netease.nos.test.utils.ExampleTest">
        <methods>
            <include name="testCaseOne" />
            <include name="testCaseTwo" />
        </methods>
        </class>
    </classes>
    </test>
</suite>
  • 方法三:

当使用mvn test执行用例集运行时,可以在pom文件中添加响应的listener信息,如下:

<plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-surefire-plugin</artifactId>
    <version>2.16</version>
    <configuration>
        <argLine>-Dfile.encoding=UTF-8</argLine>
        <suiteXmlFiles>
            <suiteXmlFile>src/main/resources/xml/TestNg2.xml</suiteXmlFile>
        </suiteXmlFiles>
        <properties>
                <property>
                    <name>usedefaultlisteners</name>
                    <value>false</value>
                </property>
                <property>
                    <name>listener</name>
                    <value>com.netease.nos.test.utils.CustomListener</value>
                </property>
        </properties>
    </configuration>
</plugin>
  • 上述准备完成后,运行测试,会看到测试结果如下:

[DEBUG] 2017-09-23 23:28:04,551 - POSITION:com.netease.nos.test.utils.ExampleTest.testCaseOne(ExampleTest.java:17) - MESSAGE:<< Success testcase
testCaseOne--Test method success
[DEBUG] 2017-09-23 23:28:04,577 - POSITION:com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:24) - MESSAGE:<< requestId: d329e90c0ab40000015eaf5a4dd2c002 ========== Start testCaseTwo =========
[DEBUG] 2017-09-23 23:28:04,578 - POSITION:com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:26) - MESSAGE:<< requestId: d329e90c0ab40000015eaf5a4dd2c002 , Err testcase

==================failed case==================
testCaseTwo--Test method failed,  requestId: d329e90c0ab40000015eaf5a4dd2c002
===============================================
Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.326 sec <<< FAILURE! - in TestSuite
testCaseTwo(com.netease.nos.test.utils.ExampleTest)  Time elapsed: 0.028 sec  <<< FAILURE!
java.lang.AssertionError: expected:<true> but was:<false>
    at org.testng.Assert.fail(Assert.java:89)
    at org.testng.Assert.failNotEquals(Assert.java:489)
    at org.testng.Assert.assertTrue(Assert.java:37)
    at org.testng.Assert.assertTrue(Assert.java:47)
    at com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:27)


Results :

Failed tests:
  ExampleTest.testCaseTwo:27 expected:<true> but was:<false>

由于我们在自定义失败用例日志时,添加了相关标签信息,故我们在最终看到失败用例方法后通

过过滤执行失败的此方法便可以找到用例requestId信息,根据requestId信息即可查到所有此用例相关的日志信息。

自定义报告的方法

  • 创建名称为CustomReporter的类,实现report输出形式,t添加必要的输出信息,内容如下:

import java.util.List;
import java.util.Map;
import java.util.Set;

import org.testng.IReporter;
import org.testng.ISuite;
import org.testng.ISuiteResult;
import org.testng.ITestContext;
import org.testng.ITestResult;

public class CustomReporter implements IReporter{

    @Override
    public void generateReport(List xmlSuites, List suites,
        String outputDirectory) {
        //Iterating over each suite included in the test
        for (ISuite suite : (List<ISuite>)suites) {
            //Following code gets the suite name
            String suiteName = suite.getName();
        //Getting the results for the said suite
        Map <String, ISuiteResult> suiteResults = suite.getResults();
        for (ISuiteResult sr : suiteResults.values()) {
            ITestContext tc = sr.getTestContext();
            Set<ITestResult> set = tc.getFailedTests().getAllResults();
            System.out.println("\n******************Failed Case******************\n");
            for (ITestResult rs : set) {  
                System.out.println(rs.getClass().getName() + "." + rs.getName() + ", requseId:" + rs.getAttribute("requestId") + "\n");
            } 
            System.out.println("***********************************************\n");
          }
        }
    }
}
  • 同前面提到的方法一致,将RequestId信息传入到用例执行结果中
  • 如何将重写的Listener生效,和前面提到的三种方法一致,将listener名称替换为CustomReporter即可。
  • 运行后测试结果如下:
[DEBUG] 2017-09-23 23:45:06,734 - POSITION:com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:25) - MESSAGE:<< requestId: 3713c8da0ab40000015eaf69e6a1c002 ========== Start testCaseTwo =========
[DEBUG] 2017-09-23 23:45:06,734 - POSITION:com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:27) - MESSAGE:<< requestId: 3713c8da0ab40000015eaf69e6a1c002 , Err testcase

******************Failed Case******************

org.testng.internal.TestResult.testCaseTwo, requseId:3713c8da0ab40000015eaf69e6a1c002

***********************************************

Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.323 sec <<< FAILURE! - in TestSuite
testCaseTwo(com.netease.nos.test.utils.ExampleTest)  Time elapsed: 0.025 sec  <<< FAILURE!
java.lang.AssertionError: expected:<true> but was:<false>
    at org.testng.Assert.fail(Assert.java:89)
    at org.testng.Assert.failNotEquals(Assert.java:489)
    at org.testng.Assert.assertTrue(Assert.java:37)
    at org.testng.Assert.assertTrue(Assert.java:47)
    at com.netease.nos.test.utils.ExampleTest.testCaseTwo(ExampleTest.java:28)


Results :

Failed tests:
  ExampleTest.testCaseTwo:28 expected:<true> but was:<false>

Tests run: 2, Failures: 1, Errors: 0, Skipped: 0

如上显示,此种方法会将所有失败的用例方法以及用例执行时对应的Requestid信息打印出来,我们以此可以快速定位到用例执行的所有具体信息,此种方法更高效的方便我们解决本文的问题。

总结

上面介绍的两种方法,很好的解决了一直以来的困扰,不当之处还请谅解。有兴趣的同学可以试验一下,过程中有问题随时交流,当然如果你有好的方法烦请不吝赐教。

本文来自网易实践者社区,经作者刘成 授权发布。