Scripts not running with JMeter 5.2.1 with Java 1.8.0_221-b11 that work with JMeter 5.2.1 with Java 1.8.0_181-b13

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Scripts not running with JMeter 5.2.1 with Java 1.8.0_221-b11 that work with JMeter 5.2.1 with Java 1.8.0_181-b13

ljmwaugh
This has driven us nuts.

We have a script that works fine in JMeter 5.2.1 with Java 1.8.0_181-b13.  It produces data in the tree view and summary view and runs clean.

We try the same script with JMeter 5.2.1 with Java 1.8.0_221-b11 and the tree view doesn’t display at all.  An error message about:

 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:1106) [ApacheJMeter_core.jar:5.2.1]

And the start time in the output from the file writer shows a start time of 0.

Here is the entire log:

2019-12-12 09:37:54,639 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2019-12-12 09:37:54,639 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2019-12-12 09:37:54,640 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, *local*)
2019-12-12 09:37:54,878 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Transaction Services
2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Transaction Services.
2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2019-12-12 09:37:54,879 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=0 delayedStart=false
2019-12-12 09:37:54,879 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2019-12-12 09:37:54,880 INFO o.a.j.t.JMeterThread: Thread started: Transaction Services 1-1
2019-12-12 09:37:54,880 INFO o.a.j.s.FileServer: Stored: /Users/perftest/ibm/QuoteHub/Credentials.csv
2019-12-12 09:37:54,880 INFO o.a.j.s.FileServer: Stored: /Users/perftest/github/quote-hub-test-automation/Jmeter/Non_Json.csv
2019-12-12 09:37:54,881 INFO o.a.j.s.FileServer: Stored: /Users/perftest/github/quote-hub-test-automation/Jmeter/Json.csv
2019-12-12 09:37:54,882 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:1106) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
2019-12-12 09:37:54,887 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:1106) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
2019-12-12 09:37:54,891 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:1106) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
2019-12-12 09:37:54,894 INFO o.a.j.t.JMeterThread: Thread is done: Transaction Services 1-1
2019-12-12 09:37:54,894 INFO o.a.j.t.JMeterThread: Thread finished: Transaction Services 1-1
2019-12-12 09:37:54,894 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2019-12-12 09:37:54,894 INFO o.a.j.s.FileServer: Close: /Users/perftest/github/quote-hub-test-automation/Jmeter/Json.csv
2019-12-12 09:37:54,894 INFO o.a.j.s.FileServer: Close: /Users/perftest/github/quote-hub-test-automation/Jmeter/Non_Json.csv
2019-12-12 09:37:54,895 INFO o.a.j.s.FileServer: Close: /Users/perftest/ibm/QuoteHub/Credentials.csv
2019-12-12 09:37:54,895 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, *local*)

Any ideas why?

Regards,

Lisa JM Waugh
Performance Test Engineer
Pricing@IBM
Phone: 1-720-342-5373 | Mobile: 1-704-907-7008
E-mail: [hidden email]<mailto:[hidden email]>

3039 E Cornwallis Rd
Research Triangle Park, NC 27709-2195
United States

Reply | Threaded
Open this post in threaded view
|

Re: Scripts not running with JMeter 5.2.1 with Java 1.8.0_221-b11 that work with JMeter 5.2.1 with Java 1.8.0_181-b13

Felix Schumacher

Am 12.12.19 um 15:48 schrieb Lisa Waugh - [hidden email]:

> This has driven us nuts.
>
> We have a script that works fine in JMeter 5.2.1 with Java 1.8.0_181-b13.  It produces data in the tree view and summary view and runs clean.
>
> We try the same script with JMeter 5.2.1 with Java 1.8.0_221-b11 and the tree view doesn’t display at all.  An error message about:
>
>  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:1106) [ApacheJMeter_core.jar:5.2.1]
>
> And the start time in the output from the file writer shows a start time of 0.
>
> Here is the entire log:
>
> 2019-12-12 09:37:54,639 INFO o.a.j.e.StandardJMeterEngine: Running the test!
> 2019-12-12 09:37:54,639 INFO o.a.j.s.SampleEvent: List of sample_variables: []
> 2019-12-12 09:37:54,640 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, *local*)
> 2019-12-12 09:37:54,878 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Transaction Services
> 2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Transaction Services.
> 2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
> 2019-12-12 09:37:54,879 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=0 delayedStart=false
> 2019-12-12 09:37:54,879 INFO o.a.j.t.ThreadGroup: Started thread group number 1
> 2019-12-12 09:37:54,879 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
> 2019-12-12 09:37:54,880 INFO o.a.j.t.JMeterThread: Thread started: Transaction Services 1-1
> 2019-12-12 09:37:54,880 INFO o.a.j.s.FileServer: Stored: /Users/perftest/ibm/QuoteHub/Credentials.csv
> 2019-12-12 09:37:54,880 INFO o.a.j.s.FileServer: Stored: /Users/perftest/github/quote-hub-test-automation/Jmeter/Non_Json.csv
> 2019-12-12 09:37:54,881 INFO o.a.j.s.FileServer: Stored: /Users/perftest/github/quote-hub-test-automation/Jmeter/Json.csv
> 2019-12-12 09:37:54,882 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:1106) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
> 2019-12-12 09:37:54,887 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:1106) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
> 2019-12-12 09:37:54,891 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:1106) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:654) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.samplers.SampleResult.addSubResult(SampleResult.java:623) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.extractor.DebugPostProcessor.process(DebugPostProcessor.java:92) [ApacheJMeter_components.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.runPostProcessors(JMeterThread.java:931) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:569) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:490) [ApacheJMeter_core.jar:5.2.1]
> at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:257) [ApacheJMeter_core.jar:5.2.1]
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]
> 2019-12-12 09:37:54,894 INFO o.a.j.t.JMeterThread: Thread is done: Transaction Services 1-1
> 2019-12-12 09:37:54,894 INFO o.a.j.t.JMeterThread: Thread finished: Transaction Services 1-1
> 2019-12-12 09:37:54,894 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
> 2019-12-12 09:37:54,894 INFO o.a.j.s.FileServer: Close: /Users/perftest/github/quote-hub-test-automation/Jmeter/Json.csv
> 2019-12-12 09:37:54,894 INFO o.a.j.s.FileServer: Close: /Users/perftest/github/quote-hub-test-automation/Jmeter/Non_Json.csv
> 2019-12-12 09:37:54,895 INFO o.a.j.s.FileServer: Close: /Users/perftest/ibm/QuoteHub/Credentials.csv
> 2019-12-12 09:37:54,895 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, *local*)
>
> Any ideas why?

Can you give a simple test plan, that we can use to reproduce the issue?

If I use a simple test plan with a JSR223 Sampler and one Debug Post
Processor with Java 8 U232 and get no such error. So we are probably
looking for a sampler that doesn't call setStartTime early enough.

(On the tomcat project we had a report of errors after changing minor
versions of Java 8 where a class had done too much overwriting over a
parent class (jsp tags), maybe we have something similar here)

Felix

>
> Regards,
>
> Lisa JM Waugh
> Performance Test Engineer
> Pricing@IBM
> Phone: 1-720-342-5373 | Mobile: 1-704-907-7008
> E-mail: [hidden email]<mailto:[hidden email]>
>
> 3039 E Cornwallis Rd
> Research Triangle Park, NC 27709-2195
> United States
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]