使用 JMeter 的 HTTP/2 请求因“nullSession”而失败 (jetty-alpn)

Posted 2023-02-16

技术标签:

【中文标题】使用 JMeter 的 HTTP/2 请求因“nullSession”而失败 (jetty-alpn)【英文标题】：HTTP/2 Request with JMeter fails with "nullSession" (jetty-alpn) 【发布时间】：2020-10-24 02:40:41 【问题描述】：

我已经为 JMeter 安装了 Blazemeter HTTP/2 Plugin，但无法让 HTTP/2 请求正常工作。

我的最小测试如下所示：

线程组 HTTP2 请求服务器：***.com 协议：https 查看结果树 Http2

运行测试会在视图结果树中显示以下采样器结果：

Thread Name:Thread Group 1-1
Sample Start:1970-01-01 01:00:00 CET
Load time:0
Connect Time:0
Latency:0
Size in bytes:2700
Sent bytes:0
Headers size in bytes:0
Body size in bytes:2700
Sample Count:1
Error Count:1
Data type ("text"|"bin"|""):text
Response code:Non HTTP response code: java.util.concurrent.ExecutionException
Response message:Non HTTP response message: org.eclipse.jetty.io.RuntimeIOException: javax.net.ssl.SSLHandshakeException: nullSession


HTTP2SampleResult fields:
ContentType: 
DataEncoding: null

还有日志：

2020-07-03 12:58:13,457 WARN o.a.j.v.ViewResultsFullVisualizer: Error loading result renderer: org.apache.jmeter.visualizers.RenderInBrowser
java.lang.NoClassDefFoundError: javafx/embed/swing/JFXPanel
    at java.lang.Class.forName0(Native Method) ~[?:1.8.0_252]
    at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_252]
    at com.blazemeter.jmeter.http2.visualizers.ViewResultsFullVisualizer.createComboRender(ViewResultsFullVisualizer.java:396) ~[jmeter-bzm-http2-1.5.jar:?]
    at com.blazemeter.jmeter.http2.visualizers.ViewResultsFullVisualizer.createLeftPanel(ViewResultsFullVisualizer.java:322) ~[jmeter-bzm-http2-1.5.jar:?]
    at com.blazemeter.jmeter.http2.visualizers.ViewResultsFullVisualizer.init(ViewResultsFullVisualizer.java:283) ~[jmeter-bzm-http2-1.5.jar:?]
    at com.blazemeter.jmeter.http2.visualizers.ViewResultsFullVisualizer.<init>(ViewResultsFullVisualizer.java:118) ~[jmeter-bzm-http2-1.5.jar:?]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.8.0_252]
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:1.8.0_252]
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.8.0_252]
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[?:1.8.0_252]
    at org.apache.jmeter.gui.GuiPackage.getGuiFromCache(GuiPackage.java:405) ~[ApacheJMeter_core.jar:5.2.1]
    at org.apache.jmeter.gui.GuiPackage.createTestElement(GuiPackage.java:352) ~[ApacheJMeter_core.jar:5.2.1]
    at org.apache.jmeter.gui.action.AddToTree.doAction(AddToTree.java:68) ~[ApacheJMeter_core.jar:5.2.1]
    at org.apache.jmeter.gui.action.ActionRouter.performAction(ActionRouter.java:88) ~[ApacheJMeter_core.jar:5.2.1]
    at org.apache.jmeter.gui.action.ActionRouter.lambda$actionPerformed$0(ActionRouter.java:70) ~[ApacheJMeter_core.jar:5.2.1]
    at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:311) [?:1.8.0_252]
    at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:758) [?:1.8.0_252]
    at java.awt.EventQueue.access$500(EventQueue.java:97) [?:1.8.0_252]
    at java.awt.EventQueue$3.run(EventQueue.java:709) [?:1.8.0_252]
    at java.awt.EventQueue$3.run(EventQueue.java:703) [?:1.8.0_252]
    at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_252]
    at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:74) [?:1.8.0_252]
    at java.awt.EventQueue.dispatchEvent(EventQueue.java:728) [?:1.8.0_252]
    at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:205) [?:1.8.0_252]
    at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116) [?:1.8.0_252]
    at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105) [?:1.8.0_252]
    at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101) [?:1.8.0_252]
    at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93) [?:1.8.0_252]
    at java.awt.EventDispatchThread.run(EventDispatchThread.java:82) [?:1.8.0_252]
Caused by: java.lang.ClassNotFoundException: javafx.embed.swing.JFXPanel
    at java.net.URLClassLoader.findClass(URLClassLoader.java:382) ~[?:1.8.0_252]
    at java.lang.ClassLoader.loadClass(ClassLoader.java:418) ~[?:1.8.0_252]
    at java.lang.ClassLoader.loadClass(ClassLoader.java:351) ~[?:1.8.0_252]
    ... 29 more
2020-07-03 12:58:19,743 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2020-07-03 12:58:19,745 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2020-07-03 12:58:19,751 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, *local*)
2020-07-03 12:58:20,368 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2020-07-03 12:58:20,371 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group.
2020-07-03 12:58:20,372 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2020-07-03 12:58:20,373 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false
2020-07-03 12:58:20,376 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2020-07-03 12:58:20,376 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2020-07-03 12:58:20,381 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1
2020-07-03 12:58:20,489 WARN o.e.j.i.SelectorManager: Exception while notifying connection SslConnection@694fa68a::SocketChannelEndPoint@65c6505a***.com/151.101.129.69:443<->/192.168.0.178:34818,CLOSED,fill=-,flush=-,to=2/30000io=1/1,kio=-1,kro=-1->SslConnection@694fa68aNEED_UNWRAP,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE~>DecryptedEndPoint@58ec6f77***.com/151.101.129.69:443<->/192.168.0.178:34818,CLOSED,fill=-,flush=-,to=10/30000=>ALPNClientConnection@1d8fc708
org.eclipse.jetty.io.RuntimeIOException: javax.net.ssl.SSLHandshakeException: nullSession
    at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:72) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ssl.SslConnection.onOpen(SslConnection.java:360) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.SelectorManager.connectionOpened(SelectorManager.java:324) [jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ManagedSelector.createEndPoint(ManagedSelector.java:276) [jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ManagedSelector.access$1800(ManagedSelector.java:62) [jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ManagedSelector$CreateEndPoint.run(ManagedSelector.java:933) [jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) [jetty-util-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) [jetty-util-9.4.26.v20200117.jar:9.4.26.v20200117]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
Caused by: javax.net.ssl.SSLHandshakeException: nullSession
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.handshakeFailed(SslConnection.java:933) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1142) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:63) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    ... 8 more
Caused by: java.lang.NoSuchFieldError: nullSession
    at sun.security.ssl.ClientHandshaker.getKickstartMessage(ClientHandshaker.java:1350) ~[?:1.8.0_252]
    at sun.security.ssl.Handshaker.kickstart(Handshaker.java:1117) ~[?:1.8.0_252]
    at sun.security.ssl.SSLEngineImpl.kickstartHandshake(SSLEngineImpl.java:736) ~[?:1.8.0_252]
    at sun.security.ssl.SSLEngineImpl.writeAppRecord(SSLEngineImpl.java:1232) ~[?:1.8.0_252]
    at sun.security.ssl.SSLEngineImpl.wrap(SSLEngineImpl.java:1185) ~[?:1.8.0_252]
    at javax.net.ssl.SSLEngine.wrap(SSLEngine.java:511) ~[?:1.8.0_252]
    at org.eclipse.jetty.io.ssl.SslConnection.wrap(SslConnection.java:412) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1052) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    at org.eclipse.jetty.io.NegotiatingClientConnection.onOpen(NegotiatingClientConnection.java:63) ~[jetty-io-9.4.26.v20200117.jar:9.4.26.v20200117]
    ... 8 more
2020-07-03 12:58:20,494 WARN o.e.j.i.ManagedSelector: org.eclipse.jetty.io.RuntimeIOException: javax.net.ssl.SSLHandshakeException: nullSession
2020-07-03 12:58:20,498 INFO o.a.j.t.JMeterThread: Thread is done: Thread Group 1-1
2020-07-03 12:58:20,498 INFO o.a.j.t.JMeterThread: Thread finished: Thread Group 1-1
2020-07-03 12:58:20,499 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2020-07-03 12:58:20,500 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, *local*)

将协议更改为 HTTP

如果我将协议更改为 HTTP，我会得到以下采样器结果：

Thread Name:Thread Group 1-1
Sample Start:2020-07-03 13:11:59 CEST
Load time:0
Connect Time:354
Latency:0
Size in bytes:1072
Sent bytes:0
Headers size in bytes:0
Body size in bytes:1072
Sample Count:1
Error Count:1
Data type ("text"|"bin"|""):text
Response code:java.util.concurrent.TimeoutException
Response message:null

这是日志：

2020-07-03 13:11:58,817 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2020-07-03 13:11:58,819 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2020-07-03 13:11:58,824 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, *local*)
2020-07-03 13:11:59,307 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2020-07-03 13:11:59,307 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group.
2020-07-03 13:11:59,307 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2020-07-03 13:11:59,308 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false
2020-07-03 13:11:59,309 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2020-07-03 13:11:59,310 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2020-07-03 13:11:59,312 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1
2020-07-03 13:11:59,690 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-07-03 13:11:59,691 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-07-03 13:11:59,692 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-07-03 13:11:59,692 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-07-03 13:11:59,693 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser
2020-07-03 13:11:59,693 INFO c.b.j.h.s.HTTP2StreamHandler: Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser
2020-07-03 13:11:59,736 INFO o.a.j.t.JMeterThread: Thread is done: Thread Group 1-1
2020-07-03 13:11:59,737 INFO o.a.j.t.JMeterThread: Thread finished: Thread Group 1-1
2020-07-03 13:12:19,741 ERROR c.b.j.h.s.HTTP2SampleResult: Error while await for response
java.util.concurrent.TimeoutException: null
    at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1784) ~[?:1.8.0_252]
    at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1928) ~[?:1.8.0_252]
    at com.blazemeter.jmeter.http2.sampler.HTTP2Connection.awaitResponses(HTTP2Connection.java:171) ~[jmeter-bzm-http2-1.5.jar:?]
    at com.blazemeter.jmeter.http2.sampler.HTTP2Request.lambda$waitAllResponses$1(HTTP2Request.java:587) ~[jmeter-bzm-http2-1.5.jar:?]
    at java.util.HashMap$Values.forEach(HashMap.java:981) [?:1.8.0_252]
    at com.blazemeter.jmeter.http2.sampler.HTTP2Request.waitAllResponses(HTTP2Request.java:585) [jmeter-bzm-http2-1.5.jar:?]
    at com.blazemeter.jmeter.http2.sampler.HTTP2Request.threadFinished(HTTP2Request.java:548) [jmeter-bzm-http2-1.5.jar:?]
    at org.apache.jmeter.threads.JMeterThread$ThreadListenerTraverser.addNode(JMeterThread.java:774) [ApacheJMeter_core.jar:5.2.1]
    at org.apache.jorphan.collections.HashTree.traverseInto(HashTree.java:994) [jorphan.jar:5.2.1]
    at org.apache.jorphan.collections.HashTree.traverse(HashTree.java:977) [jorphan.jar:5.2.1]
    at org.apache.jmeter.threads.JMeterThread.threadFinished(JMeterThread.java:741) [ApacheJMeter_core.jar:5.2.1]
    at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:329) [ApacheJMeter_core.jar:5.2.1]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2020-07-03 13:12:19,756 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2020-07-03 13:12:19,758 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, *local*)

我的设置：

我在 Linux (version 5.6.15-arch1-1) 上使用 JMeter 5.2.1 和 OpenJDK 8 (openjdk version "1.8.0_252")

（在 Ubuntu 20.04 上使用 JMeter 5.3 得到相同的结果，在 CLI 模式下运行）

根据 HTTP/2 插件的要求，我在 jmeter 启动脚本的顶部添加了以下行：

JVM_ARGS="-Xbootclasspath/p:/opt/jmeter/lib/alpn-boot-8.1.13.v20181017.jar"

如何解决或调试此问题？

更新：

我发现一旦我使用上面提到的alpn-boot，我对常规 HTTP 请求就有相同的行为，所以这似乎是该库的问题。 https://github.com/jetty-project/jetty-alpn/blob/master/docs/version_mapping.properties 有一个 jetty-alpn 版本与 Java 版本的映射表，目前不包含我的 Java 版本。

docs 说

该表仅显示了到 OpenJDK 8u242 的映射，这是需要 ALPN 引导 jar 的最后一个版本。

但是如果我在没有 alpn 参数的情况下启动 JMeter，我会看到这样的结果（HTTP/2 和 HTTPS）：

Response code:Non HTTP response code: java.util.concurrent.ExecutionException
Response message:Non HTTP response message: java.lang.IllegalStateException: No Client ALPNProcessors!

【问题讨论】：

我想我发现了这个问题：“您需要 Jetty 9.4.28 才能使用 8u252。” webtide.com/jetty-alpn-java-8u252 - 成功后将作为答案发布 【参考方案1】：

我发现，OpenJDK 8u252 和 Jetty 9.4.26（JMeter 附带）的组合不兼容。

ALPN API 已向后移植到 Java 8u252 和 Jetty 9.4.28，不再需要 alpn-boot。

更多信息：https://webtide.com/jetty-alpn-java-8u252/

将 Jetty 库更新到 9.4.28 有帮助：

从https://repo1.maven.org/maven2/org/eclipse/jetty/jetty-distribution/9.4.28.v20200408/ 和https://repo1.maven.org/maven2/org/eclipse/jetty/jetty-client/9.4.28.v20200408/ 下载文件将 jmeter/lib 中的 jetty*-9.4.26* 文件替换为下载存档中对应的 9.4.28 文件

更新：文件列表

lib/jetty-alpn-client-9.4.28.v20200408.jar
lib/jetty-alpn-openjdk8-client-9.4.28.v20200408.jar
lib/jetty-client-9.4.28.v20200408.jar
lib/jetty-http-9.4.28.v20200408.jar
lib/jetty-io-9.4.28.v20200408.jar
lib/jetty-util-9.4.28.v20200408.jar

【讨论】：

jetty 9.4.28+ 中没有 jetty-alpn-client jar。你对他们做了什么？删除？还是保留？在这两种情况下，它对我 ALPN 相关问题仍然失败。 JDK 1.8.0_265、JMeter 5.3.0、JMeter HTTP2 插件 1、Jetty 9.4.31。 @martin-g 我用文件列表和第二个下载链接更新了答案。我记得我是先从不同的位置下载的，然后在jetty-distribution找到其余的文件... 谢谢你，费边！ ALPN 客户端 jars（jetty-alpn-client-9.4.31.v20200723.jar 和 jetty-alpn-openjdk8-client-9.4.31.v20200723.jar）不是 jetty-distribution 的一部分，我认为它们不再发布.我已经从 Maven Central 下载了它们，现在一切正常！

以上是关于使用 JMeter 的 HTTP/2 请求因“nullSession”而失败 (jetty-alpn)的主要内容，如果未能解决你的问题，请参考以下文章

请求超时 - JMeter HTTP2 插件

HTTP2 请求不遵循 JMeter 5.0 中的重定向

Java 12 JMeter 5 HTTP/2 请求 java.lang.NoClassDefFoundError: org/eclipse/jetty/alpn/client/ALPNClientC

JMeter学习-042-JMeter BeanShell 脚本应用实例之正则应用：正则提取，批量获取测试数据

Jmeter仪表板因管道分隔符jtl失败

JMeter学习-004-WEB脚本入门实战