You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@jmeter.apache.org by Ivan Rancati <iv...@sharpmind.de> on 2006/02/06 18:14:12 UTC
JMeter sends the same request twice ?
I have been investigating an issue where, when running tests for long
periods of time (between 4 and 12 hours), some http requests (normally
0.5% or less of the total) fail with this exception
java.io.IOException: Stream closed
at java.io.BufferedInputStream.getInIfOpen(BufferedInputStream.java:134)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:254)
at java.io.BufferedInputStream.read(BufferedInputStream.java:313)
at java.io.FilterInputStream.read(FilterInputStream.java:90)
at
org.apache.jmeter.protocol.http.sampler.HTTPSampler.readResponse(HTTPSampler.java:235)
at
org.apache.jmeter.protocol.http.sampler.HTTPSampler.sample(HTTPSampler.java:449)
at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:514)
at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:503)
at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:247)
at java.lang.Thread.run(Thread.java:595)
To trace better the failing requests, I added a counter and a timestamp
parameter to each http request
The values for the parameters are defined in the HTTP request defaults
for the thread group as
${__counter(false, count)}
${__javaScript(new Date().getTime(),timestamp)}
and are ignored, but logged, by the Tomcat servlet that I am testing
In the application logs, I would therefore expect to see only unique
requests, but I have seen that when a request fails in JMeter with the
"Stream closed" exception, is present twice in the application logs.
In both instances, the application logs indicate that the request has
been correctly processed (although the first one took over 5 minutes)
To understand whether the problem was on the load balancer/application
side or JMeter, I ran this tcpdump command on the client side while
running the test:
tcpdump -w jmeter-tcpdump-log -C 2 -Aq -s 1520 dst host tc-chromium
so I would record all the requests sent from the test computer to the
application.
If I reopen the log with tcpdump -r, I see the request twice, with a
delta of almost exactly 5 minutes.
22:40:43.720789 IP iridium.sharpmind.de.60899 >
tc-chromium-ext.sharpmind.de.http-alt: P 0:406(406) ack 1 win 1460
E....G@.@..V
..j
..
......He....P....N..GET
/?gps_history=1337300;5251640;20;30;$&way_points=1342157;5238465;$&destination=784964;4799853;&cmd=navigate&version=1&counter=34176×tamp=1137966043712
HTTP/1.1^M
Connection: close^M
Cookie: JSESSIONID=3404FCE146B94BA510AA5A10CAE18D9F^M
22:45:43.699368 IP iridium.sharpmind.de.43856 >
tc-chromium-ext.sharpmind.de.http-alt: P 0:406(406) ack 1 win 1460
E.....@.@.9.
..j
..
.P.......6].P....N..GET
/?gps_history=1337300;5251640;20;30;$&way_points=1342157;5238465;$&destination=784964;4799853;&cmd=navigate&version=1&counter=34176×tamp=1137966043712
HTTP/1.1^M
Connection: close^M
Cookie: JSESSIONID=3404FCE146B94BA510AA5A10CAE18D9F^M
So, it looks like JMeter, for some reason, is sending the request again.
Is there some circumstance when JMeter would send again a request
(perhaps after an internal timeout of 5 minutes has been reached?)
Also, what additional troubleshooting/investigation could I do?
JMeter.log does not indicate anything strange and the .jtl file used in
"Write All data to a File" in the Aggregate report writes the HTTP
request name but not the URL.
My environment is
JMeter 2.1.1
JDK 1.5.0
SuSE 9.3 client
Debian server
thanks
--
Ivan Rancati
SharpMind QA
---------------------------------------------------------------------
To unsubscribe, e-mail: jmeter-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: jmeter-user-help@jakarta.apache.org
Re: JMeter sends the same request twice ?
Posted by sebb <se...@gmail.com>.
Sounds rather odd.
What does your testplan look like?
S.
On 06/02/06, Ivan Rancati <iv...@sharpmind.de> wrote:
>
>
> I have been investigating an issue where, when running tests for long
> periods of time (between 4 and 12 hours), some http requests (normally
> 0.5% or less of the total) fail with this exception
>
> java.io.IOException: Stream closed
> at java.io.BufferedInputStream.getInIfOpen(BufferedInputStream.java:134)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:254)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:313)
> at java.io.FilterInputStream.read(FilterInputStream.java:90)
> at
> org.apache.jmeter.protocol.http.sampler.HTTPSampler.readResponse(HTTPSampler.java:235)
> at
> org.apache.jmeter.protocol.http.sampler.HTTPSampler.sample(HTTPSampler.java:449)
> at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:514)
> at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:503)
> at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:247)
> at java.lang.Thread.run(Thread.java:595)
>
> To trace better the failing requests, I added a counter and a timestamp
> parameter to each http request
> The values for the parameters are defined in the HTTP request defaults
> for the thread group as
> ${__counter(false, count)}
> ${__javaScript(new Date().getTime(),timestamp)}
> and are ignored, but logged, by the Tomcat servlet that I am testing
>
> In the application logs, I would therefore expect to see only unique
> requests, but I have seen that when a request fails in JMeter with the
> "Stream closed" exception, is present twice in the application logs.
> In both instances, the application logs indicate that the request has
> been correctly processed (although the first one took over 5 minutes)
> To understand whether the problem was on the load balancer/application
> side or JMeter, I ran this tcpdump command on the client side while
> running the test:
>
> tcpdump -w jmeter-tcpdump-log -C 2 -Aq -s 1520 dst host tc-chromium
>
> so I would record all the requests sent from the test computer to the
> application.
> If I reopen the log with tcpdump -r, I see the request twice, with a
> delta of almost exactly 5 minutes.
>
> 22:40:43.720789 IP iridium.sharpmind.de.60899 >
> tc-chromium-ext.sharpmind.de.http-alt: P 0:406(406) ack 1 win 1460
> E....G@.@..V
> ..j
> ..
> ......He....P....N..GET
> /?gps_history=1337300;5251640;20;30;$&way_points=1342157;5238465;$&destination=784964;4799853;&cmd=navigate&version=1&counter=34176×tamp=1137966043712
> HTTP/1.1^M
> Connection: close^M
> Cookie: JSESSIONID=3404FCE146B94BA510AA5A10CAE18D9F^M
>
> 22:45:43.699368 IP iridium.sharpmind.de.43856 >
> tc-chromium-ext.sharpmind.de.http-alt: P 0:406(406) ack 1 win 1460
> E.....@.@.9.
> ..j
> ..
> .P.......6].P....N..GET
> /?gps_history=1337300;5251640;20;30;$&way_points=1342157;5238465;$&destination=784964;4799853;&cmd=navigate&version=1&counter=34176×tamp=1137966043712
> HTTP/1.1^M
> Connection: close^M
> Cookie: JSESSIONID=3404FCE146B94BA510AA5A10CAE18D9F^M
>
> So, it looks like JMeter, for some reason, is sending the request again.
> Is there some circumstance when JMeter would send again a request
> (perhaps after an internal timeout of 5 minutes has been reached?)
> Also, what additional troubleshooting/investigation could I do?
> JMeter.log does not indicate anything strange and the .jtl file used in
> "Write All data to a File" in the Aggregate report writes the HTTP
> request name but not the URL.
>
>
> My environment is
> JMeter 2.1.1
> JDK 1.5.0
> SuSE 9.3 client
> Debian server
>
> thanks
>
> --
> Ivan Rancati
> SharpMind QA
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: jmeter-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: jmeter-user-help@jakarta.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: jmeter-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: jmeter-user-help@jakarta.apache.org