apache / apache/jmeter

Use plugin "Selenium/WebDriver Support" and get error "setEndTime must be called after setStartTime"

Open
#6,230 1 comment 0 reactions 0 assignees View on GitHub
defect to-triage
Dominant language
Java
Stars
9.5k
Forks
2.3k
Avg merge
1d 22h
Merged PRs (30d)
5

Description

### Expected behavior

Error log:
2024-01-23 20:20:01,069 INFO o.j.r.JARSourceHTTP: Requesting https://jmeter-plugins.org/repo/?installID=windows_11-ce830d5eda2ae34b1182059c8f21596d-gui
2024-01-23 20:20:11,322 INFO o.a.j.s.FileServer: Default base='C:\Programs\JMeter56\bin'
2024-01-23 20:20:11,324 INFO o.a.j.g.a.Load: Loading file: C:\Temp\JMeter\SeleniumWebDriver.jmx
2024-01-23 20:20:11,324 INFO o.a.j.s.FileServer: Set new base='C:\Temp\JMeter'
2024-01-23 20:20:11,432 INFO o.a.j.s.SaveService: Testplan (JMX) version: 2.2. Testlog (JTL) version: 2.2
2024-01-23 20:20:11,440 INFO o.a.j.s.SaveService: Using SaveService properties file encoding UTF-8
2024-01-23 20:20:11,441 INFO o.a.j.s.SaveService: Using SaveService properties version 5.0
2024-01-23 20:20:11,443 INFO o.a.j.s.SaveService: Loading file: C:\Temp\JMeter\SeleniumWebDriver.jmx
2024-01-23 20:20:11,546 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times
2024-01-23 20:20:11,546 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to UTF-8
2024-01-23 20:20:11,546 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true
2024-01-23 20:20:11,546 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000
2024-01-23 20:20:11,647 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-manager-1.10.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.ResultRenderer], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:11,650 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-webdriver-4.13.0.0.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.ResultRenderer], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:11,672 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-manager-1.10.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.RequestView], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:11,675 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-webdriver-4.13.0.0.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.RequestView], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:11,716 INFO o.a.j.s.FileServer: Set new base='C:\Temp\JMeter'
2024-01-23 20:20:16,035 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2024-01-23 20:20:16,035 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2024-01-23 20:20:16,035 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2024-01-23 20:20:16,036 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must contain the string: '.functions.'
2024-01-23 20:20:16,036 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must not contain the string: '.gui.'
2024-01-23 20:20:16,218 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-manager-1.10.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.functions.Function], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:16,220 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-webdriver-4.13.0.0.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.functions.Function], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:20:16,231 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, *local*)
2024-01-23 20:20:16,316 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2024-01-23 20:20:16,316 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group.
2024-01-23 20:20:16,316 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2024-01-23 20:20:16,316 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false
2024-01-23 20:20:16,320 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2024-01-23 20:20:16,320 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2024-01-23 20:20:16,322 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1
2024-01-23 20:20:22,901 INFO c.g.j.p.w.c.WebDriverConfig: Created browser object: ChromeDriver: chrome on windows (null)
2024-01-23 20:20:23,655 INFO o.a.h.i.c.DefaultHttpClient: I/O exception (java.net.SocketException) caught when connecting to {s}->https://jmeter-plugins.org:443: Connection reset
2024-01-23 20:20:23,655 INFO o.a.h.i.c.DefaultHttpClient: Retrying connect to {s}->https://jmeter-plugins.org:443
2024-01-23 20:20:27,179 ERROR o.a.j.s.SampleResult: setEndTime must be called after setStartTime
java.lang.Throwable: Invalid call sequence
at org.apache.jmeter.samplers.SampleResult.setEndTime(SampleResult.java:1158) [ApacheJMeter_core.jar:5.6.3]
at org.apache.jmeter.samplers.SampleResult.sampleEnd(SampleResult.java:1196) [ApacheJMeter_core.jar:5.6.3]
at jdk.nashorn.internal.scripts.Script$3$\^eval\_.:program(:1) [?:?]
at jdk.nashorn.internal.runtime.ScriptFunctionData.invoke(ScriptFunctionData.java:637) [nashorn.jar:?]
at jdk.nashorn.internal.runtime.ScriptFunction.invoke(ScriptFunction.java:494) [nashorn.jar:?]
at jdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:393) [nashorn.jar:?]
at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:449) [nashorn.jar:?]
at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:406) [nashorn.jar:?]
at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:402) [nashorn.jar:?]
at jdk.nashorn.api.scripting.NashornScriptEngine.eval(NashornScriptEngine.java:155) [nashorn.jar:?]
at javax.script.AbstractScriptEngine.eval(Unknown Source) [?:1.8.0_341]
at com.googlecode.jmeter.plugins.webdriver.sampler.WebDriverSampler.sample(WebDriverSampler.java:101) [jmeter-plugins-webdriver-4.13.0.0.jar:?]
at org.apache.jmeter.threads.JMeterThread.doSampling(JMeterThread.java:651) [ApacheJMeter_core.jar:5.6.3]
at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:570) [ApacheJMeter_core.jar:5.6.3]
at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:501) [ApacheJMeter_core.jar:5.6.3]
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:268) [ApacheJMeter_core.jar:5.6.3]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_341]
2024-01-23 20:20:27,209 INFO o.a.j.t.JMeterThread: Thread is done: Thread Group 1-1
2024-01-23 20:20:27,209 INFO o.a.j.t.JMeterThread: Thread finished: Thread Group 1-1
2024-01-23 20:20:28,493 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2024-01-23 20:20:28,494 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, *local*)
2024-01-23 20:20:42,992 WARN o.j.r.PluginManagerMenuItem: Failed to load plugin updates info
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(Unknown Source) ~[?:1.8.0_341]
at java.net.SocketInputStream.read(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketInputRecord.read(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketInputRecord.readHeader(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketInputRecord.decode(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLTransport.decode(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketImpl.decode(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source) ~[?:1.8.0_341]
at sun.security.ssl.SSLSocketImpl.startHandshake(Unknown Source) ~[?:1.8.0_341]
at org.apache.http.conn.ssl.SSLSocketFactory.createLayeredSocket(SSLSocketFactory.java:570) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.conn.ssl.SSLSocketFactory.connectSocket(SSLSocketFactory.java:554) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.conn.ssl.SSLSocketFactory.connectSocket(SSLSocketFactory.java:415) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:326) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:605) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:440) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:835) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.14.jar:4.5.14]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.14.jar:4.5.14]
at org.jmeterplugins.repository.JARSourceHTTP.execute(JARSourceHTTP.java:499) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.JARSourceHTTP.execute(JARSourceHTTP.java:494) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.JARSourceHTTP.getJSON(JARSourceHTTP.java:152) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.JARSourceHTTP.getRepositories(JARSourceHTTP.java:276) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.JARSourceHTTP.getRepo(JARSourceHTTP.java:304) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.PluginManager.load(PluginManager.java:71) ~[jmeter-plugins-manager-1.10.jar:?]
at org.jmeterplugins.repository.PluginManagerMenuItem$1.run(PluginManagerMenuItem.java:38) [jmeter-plugins-manager-1.10.jar:?]
2024-01-23 20:21:07,219 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-manager-1.10.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.RequestView], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning
2024-01-23 20:21:07,224 INFO o.a.j.r.ClassFinder: Will scan jar C:\Programs\JMeter56\lib\ext\jmeter-plugins-webdriver-4.13.0.0.jar with filter ExtendsClassFilter [parents=[interface org.apache.jmeter.visualizers.RequestView], inner=false, contains=null, notContains=null]. Consider exposing JMeter plugins via META-INF/services, and add JMeter-Skip-Class-Scanning=true manifest attribute so JMeter can skip classfile scanning

### Actual behavior

![image](https://github.com/apache/jmeter/assets/23305875/c56ab947-738a-493f-a21a-7362580d17e6)

### Steps to reproduce the problem

jmx file:




false
true
false







1
1
true
continue

1
false




false
true
C:\Programs\Python38\chromedriver.exe
false
true
false


SYSTEM


8080
true

8080

8080

8080
localhost




WDS.sampleResult.sampleStart()
WDS.browser.get('https://www.selenium.dev/')


javascript



0
500



var pkg = JavaImporter(org.openqa.selenium, org.openqa.selenium.support.ui)
var tabDocumentation = WDS.browser.findElement(pkg.By.cssSelector('#main_navbar > ul > li:nth-child(3) > a'))
tabDocumentation.click()


javascript



0
100.0



var pkg = JavaImporter(org.openqa.selenium, org.openqa.selenium.support.ui)
var tabBlog = WDS.browser.findElement(pkg.By.cssSelector('#main_navbar > ul > li:nth-child(6) > a'))
tabBlog.click()

javascript



300



WDS.sampleResult.sampleEnd()


javascript



false

saveConfig


true
true
true
true
true
true
true
true
false
true
true
false
false
false
true
false
false
false
true
0
true
true
true
true
true
true






false

saveConfig


true
true
true
true
true
true
true
true
false
true
true
false
false
false
true
false
false
false
true
0
true
true
true
true
true
true







### JMeter Version

5.6

### Java Version

1.8.0_341-b10

### OS Version

Windows 11

Contributor guide

Open the contributing guide

Research direction

Start at WebDriverSampler.java:101 and inspect the SampleResult.setEndTime stack trace in the JMeter 5.6.3 run. Reproduce with the SeleniumWebDriver.jmx file and determine the conditions around the reported call sequence; done means the sampler no longer logs “setEndTime must be called after setStartTime” for this case.

Written by the indexing model from the issue text.

Assessment

Tech stack
java
Domain
testing-qa
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.