On Thu, Nov 22, 2018 at 10:54 AM Oleg Kalnichevski <[email protected]> wrote:

> On Thu, 2018-11-22 at 09:23 -0700, Gary Gregory wrote:
> > [I can't seem to change the Subject of this email in GMail, sorry for
> > the
> > "(no subject)"]
> >
> > In my latest test I ran:
> > - the async file server example from the command line
> > - the async reverse proxy example from Eclipse with output redirected
> > to a
> > file
> > - JMeter form the command line.
> >
> > After about 40 minutes, the async file server not only disappeared
> > but
> > crashed the command line window it was running in.
> >
> > I am attributing this for now to Oracle Java 7 lameness. I am going
> > to
> > switch to running all tests under Java 8 and see if that helps.
> >
> > Another round of tests I need to do is to use HTTPS everywhere in
> > stress
> > tests which is what my customer will want to do in the end.
> >
> > Gary
> >
>
> If you can reproduce the issue with Java 1.8 or later, I'll look into
> it. Heap dump would also help.
>

Hi Oleg,

I was able to reproduce the problem using Oracle Java 8 on Windows 10:
Again a SocketTimeoutException in the IO reactor. I am using:

Java version: 1.8.0_191, vendor: Oracle Corporation, runtime: C:\Program
Files\Java\jdk1.8.0_191\jre
Default locale: en_US, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

I have HttpCore gt master checked out in
C:\vcs\git\apache\httpcomponents\httpcomponents-core and built to classes
with Eclipse.

Run our AsyncFileServerExample from the command line:
"%JAVA_8_HOME%\bin\java.exe" -Dfile.encoding=UTF-8 -classpath
C:\vcs\git\apache\httpcomponents\httpcomponents-core\httpcore5\target\classes
org.apache.hc.core5.http.examples.AsyncFileServerExample C:\temp

Run our  AsyncReverseProxyExample from the command line:
"%JAVA_8_HOME%\bin\java.exe" -Dfile.encoding=UTF-8 -classpath
C:\vcs\git\apache\httpcomponents\httpcomponents-core\httpcore5\target\classes
org.apache.hc.core5.http.examples.AsyncReverseProxyExample localhost:8080
9094 >C:\test\AsyncReverseProxyExample.log

Then run JMeter from C:\Java\apache-jmeter-5.0\bin:

rmdir /q/s c:\test\jmeter-OneByteHttpCore & del /F
c:\test\OneByteHttpCore.csv & jmeter -n -t
C:\Users\ggregory\Downloads\OneByteHttpCore.jmx -l
c:\test\OneByteHttpCore.csv -e -o c:\test\jmeter-OneByteHttpCore

OneByteHttpCore.jmx is here: https://pastebin.com/N6uK4Q3d

After 16 minutes, JMeter stops when it encounters the first error. The
JMeter console output: https://pastebin.com/PX4kdy2Q

The console for AsyncFileServerExample shows:
...
2018-11-22 10:29:03.903 -0700 | 127.0.0.1:8080<->127.0.0.1:17407 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.908 -0700 | 127.0.0.1:8080<->127.0.0.1:17413 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.912 -0700 | 127.0.0.1:8080<->127.0.0.1:17420 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.918 -0700 | 127.0.0.1:8080<->127.0.0.1:17426 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.922 -0700 | 127.0.0.1:8080<->127.0.0.1:17433 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.927 -0700 | 127.0.0.1:8080<->127.0.0.1:17442 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.932 -0700 | 127.0.0.1:8080<->127.0.0.1:17449 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.937 -0700 | 127.0.0.1:8080<->127.0.0.1:17457 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.941 -0700 | 127.0.0.1:8080<->127.0.0.1:17465 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.948 -0700 | 127.0.0.1:8080<->127.0.0.1:17470 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.954 -0700 | 127.0.0.1:8080<->127.0.0.1:17476 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.960 -0700 | 127.0.0.1:8080<->127.0.0.1:17483 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:03.965 -0700 | 127.0.0.1:8080<->127.0.0.1:17491 | serving
file C:\temp\one-byte.txt
2018-11-22 10:29:*03*.970 -0700 | 127.0.0.1:8080<->127.0.0.1:17495 |
serving file C:\temp\one-byte.txt
2018-11-22 10:29:*16*.126 -0700 | 127.0.0.1:8080<->127.0.0.1:17503 |
serving file C:\temp\one-byte.txt

Notice the large elapsed time between the last two entries.

After I came back to my PC, I did a Ctrl-Break on the console for
AsyncFileServerExample and got: https://pastebin.com/q1z4rSVP

An after the fact dump AsyncReverseProxyExample is here:
https://pastebin.com/wC2KMyYN

I capture console output from AsyncReverseProxyExample to a file but that
is 155 MB unzipped and 8 MB zipped so I am not sure where to put that. I
put the max paste size of 512Kn from the file tail that pastbin allows
here: https://pastebin.com/xCGFnQ2r

Notice the usual suspect timeout:

[proxy->origin] connection released http://localhost:8080; total kept
alive: 0; total allocated: 0 of 100
[client<-proxy] connection /127.0.0.1:9094->/127.0.0.1:17493 kept alive
[client->proxy] 0002815E GET /one-byte.txt
[proxy->origin] 0002815E request connection to http://localhost:8080
[proxy->origin] connection leased http://localhost:8080
[client<-proxy] 0002815E 10 SECONDS
java.net.SocketTimeoutException: 10 SECONDS
at
org.apache.hc.core5.io.SocketTimeoutExceptionFactory.create(SocketTimeoutExceptionFactory.java:50)
at
org.apache.hc.core5.http.impl.nio.AbstractHttp1StreamDuplexer.onTimeout(AbstractHttp1StreamDuplexer.java:404)
at
org.apache.hc.core5.http.impl.nio.AbstractHttp1IOEventHandler.timeout(AbstractHttp1IOEventHandler.java:81)
at
org.apache.hc.core5.http.impl.nio.ServerHttp1IOEventHandler.timeout(ServerHttp1IOEventHandler.java:1)
at
org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalDataChannel.java:185)
at
org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalChannel.java:67)
at
org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(SingleCoreIOReactor.java:232)
at
org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChannels(SingleCoreIOReactor.java:165)
at
org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:127)
at
org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:81)
at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
at java.lang.Thread.run(Thread.java:748)
[proxy->origin] 0002815E connection leased
[proxy->origin] 0002815E GET /one-byte.txt
[proxy<-origin] 0002815E status 200
[client<-proxy] 0002815E status 200
[proxy<-origin] 0002815E 1 bytes received
[proxy->origin] 0002815E input capacity: 4095
[proxy<-origin] 0002815E end of input
[proxy<-origin] connection /127.0.0.1:17503->localhost/127.0.0.1:8080 kept
alive
[proxy->origin] connection released http://localhost:8080; total kept
alive: 0; total allocated: 0 of 100

Thank you again for your help,
Gary

>
> Oleg
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
>

Reply via email to