Hi Oleg,
I was able to reproduce the problem, the results are in the branch
ggregory-async-reverse-proxy-problem, folder
httpcore5/AsyncReverseProxyExample-run1.
I edited the stock example AsyncReverseProxyExample and ran it from Eclipse
and redirected output to a file which I then copied
to httpcore5/AsyncReverseProxyExample-run1/AsyncReverseProxyExample.log.
The edit is:
final IOReactorConfig config = IOReactorConfig.custom()
.setSoTimeout(10, TimeUnit.SECONDS)
.setIoThreadCount(1)
.setSelectInterval(TimeValue.ofMilliseconds(10))
.build();
I ran the test using JMeter like this:
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
The JMX test plan is in
httpcore5/AsyncReverseProxyExample-run1\OneByteHttpCore.jmx.
The last line of the output csv file describes the problem:
1542476047205,21871,One Byte HttpCore,Non HTTP response code:
org.apache.http.ConnectionClosedException,Non HTTP response message: *Premature
end of Content-Length delimited message body (expected: 1; received: 0*,Thread
Group 1-1,text,false,,1330,0,1,1,http://localhost:9094/one-byte.txt,0,0,11
With the side effect of the timeout as previously observed:
[client<-proxy] 0000C836 output available: 1
[client<-proxy] 0000C836 produce output
[client<-proxy] 0000C836 1 bytes sent
[client<-proxy] 0000C836 end of output
[client<-proxy] 0000C836 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:416)
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:184)
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:80)
at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44)
at java.lang.Thread.run(Thread.java:745)
Any help you can provide is greatly appreciated. Please let me know what I
can do to help.
Thank you,
Gary
On Sat, Nov 17, 2018 at 8:25 AM Gary Gregory <[email protected]> wrote:
>
>
> On Fri, Nov 16, 2018 at 1:49 AM Oleg Kalnichevski <[email protected]>
> wrote:
>
>> On Thu, 2018-11-15 at 13:19 -0700, Gary Gregory wrote:
>> > Hi Oleg,
>> >
>> > I was able to reproduce the problem with the git master code and my
>> > results
>> > are saved in the branch *ggregory-async-reverse-proxy-problem*:
>> >
>> > - The test stack is the same as my original email.
>> > - In this current version of *AsyncReverseProxyExampleNoLogging*, the
>> > IO
>> > Reactor configurations no longer has the "silly" settings.
>> > - The last line in the JMeter output file
>> > *AsyncReverseProxyExampleNoLogging-run0/OneByteHttpCore.csv* shows
>> > the same
>> > problem:
>> > 1542311760223,10016,One Byte HttpCore,Non HTTP response code:
>> > org.apache.http.ConnectionClosedException,Non HTTP response message:
>> > *Premature
>> > end of Content-Length delimited message body (expected: 1; received:
>> > 0*,Thread
>> > Group 1-1,text,false,,1330,0,1,1,
>> > http://localhost:9094/one-byte.txt,0,0,1
>> > - The proxy's console is captured
>> > in AsyncReverseProxyExampleNoLogging-run0/console-out.txt and shows
>> > the
>> > usual side-effect: java.net.SocketTimeoutException: 10 SECONDS.
>> > - The results of running the plain old *AsyncReverseProxyExample *is
>> > stored
>> > in the *AsyncReverseProxyExample-run0* folder and does not show a
>> > "*Premature
>> > end of Content-Length"* error but a different unhelpful error BUT it
>> > does
>> > show the socket timeout in the proxy's console output.
>> >
>> > Please advise,
>> > Gary
>> >
>>
>> Hi Gary
>>
>> I am sorry but I am unable to reproduce the problem locally. I ran
>> several tests with 1 Mio requests and all message exchanges completed
>> correctly.
>> ---
>>
>> oleg@ok2c:~/temp$ ab -c 1 -n 1000000 -k
>> http://localhost:9094/one-byte.txt
>> This is ApacheBench, Version 2.3 <$Revision: 1807734 $>
>> Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
>> Licensed to The Apache Software Foundation, http://www.apache.org/
>>
>> Server Software: ecstatic-3.3.0
>> Server Hostname: localhost
>> Server Port: 9094
>>
>> Document Path: /one-byte.txt
>> Document Length: 1 bytes
>>
>> Concurrency Level: 1
>> Time taken for tests: 667.319 seconds
>> Complete requests: 1000000
>> Failed requests: 0
>> Keep-Alive requests: 1000000
>> Total transferred: 286000000 bytes
>> HTML transferred: 1000000 bytes
>> Requests per second: 1498.53 [#/sec] (mean)
>> Time per request: 0.667 [ms] (mean)
>> Time per request: 0.667 [ms] (mean, across all concurrent requests)
>> Transfer rate: 418.54 [Kbytes/sec] received
>>
>
> Thank you Oleg,
>
> I will try to reproduce my failure again but with something that fails
> faster, or at least I will attempt to do so...
>
> Gary
>
>
>>
>> >
>> > On Thu, Nov 15, 2018 at 10:31 AM Gary Gregory <[email protected]
>> > >
>> > wrote:
>> >
>> > > On Thu, Nov 15, 2018 at 8:59 AM Gary Gregory <
>> > > [email protected]>
>> > > wrote:
>> > >
>> > > > On Thu, Nov 15, 2018 at 8:45 AM Oleg Kalnichevski <
>> > > > [email protected]>
>> > > > wrote:
>> > > >
>> > > > > On Sun, 2018-11-11 at 18:30 -0700, Gary Gregory wrote:
>> > > > > > Hi All:
>> > > > > >
>> > > > >
>> > > > > ...
>> > > > >
>> > > > > > I am looking for guidance here. I suppose this could be a bug
>> > > > > > in the
>> > > > > > example, or in the core, or that the example could/should be
>> > > > > > adjusted
>> > > > > > to
>> > > > > > avoid this unfortunate sequence. Again, the IO rector
>> > > > > > parameters I
>> > > > > > used are
>> > > > > > only to demonstrate the problem. In my set up, I use the
>> > > > > > default
>> > > > > > select
>> > > > > > timeout of 1 second and reactor IO thread counts of 2.
>> > > > > >
>> > > > > > Thank you,
>> > > > > > Gary
>> > > > >
>> > > > >
>> > > > > Oh, it was a nasty one. It is just sheer luck that the problem
>> > > > > was much
>> > > > > easier to reproduce with non-persistent connections and out of
>> > > > > laziness
>> > > > > I opted for AB (which uses non-persistent HTTP/1.0 by default)
>> > > > > instead
>> > > > > of JMeter.
>> > > > >
>> > > > > I believe the culprit was this race condition:
>> > > > >
>> > > > >
>> > > > >
>>
>> https://github.com/apache/httpcomponents-core/commit/f5590e471f46892787df01fca2a6e8faf26fd454
>> > > > >
>> > > > > I also fixed incorrect handling of incoming HTTP/1.0 requests
>> > > > > by the
>> > > > > reverse proxy example.
>> > > > >
>> > > > > Please test the latest snapshot with your application and let
>> > > > > me know
>> > > > > the outcome.
>> > > > >
>> > > >
>> > > > Thank you Oleg, I am testing... My initial app test failed (I
>> > > > made the
>> > > > same change to my app as you made to the sample to use a distinct
>> > > > HttpContext for outgoing message exchanges) so I will review and
>> > > > try to
>> > > > reproduce with the example...
>> > > >
>> > >
>> > > Hi Oleg,
>> > >
>> > > Using the previous example I posted called
>> > > "AsyncReverseProxyExampleNoLogging" which I updated to use a
>> > > distinct
>> > > HttpContext for outgoing message exchanges (just like the updated
>> > > example),
>> > > and JMeter, I can send over 285K requests but it fails on the
>> > > 285,032th
>> > > request with a different error. The last line in the resulting
>> > > JMeter
>> > > output file OneByteHttpCore.csv is:
>> > >
>> > > 1542298828472,10053,One Byte HttpCore,Non HTTP response code:
>> > > org.apache.http.NoHttpResponseException,Non HTTP response message:
>> > > localhost:9094 failed to respond,Thread Group 1-
>> > > 1,text,false,,2090,0,1,1,
>> > > http://localhost:9094/one-byte.txt,0,0,1
>> > >
>> > > Which does not tell us much sadly. BUT, perhaps more tellingly, the
>> > > console for the proxy (running from Eclipse), shows:
>> > >
>> > > Reverse proxy to http://localhost:8080
>> > > Listening on port 9094
>> > > java.net.SocketTimeoutException: 10 SECONDS
>> > > at
>> > > org.apache.hc.core5.io.SocketTimeoutExceptionFactory.create(SocketT
>> > > imeoutExceptionFactory.java:50)
>> > > at
>> > > org.apache.hc.core5.http.impl.nio.AbstractHttp1StreamDuplexer.onTim
>> > > eout(AbstractHttp1StreamDuplexer.java:416)
>> > > at
>> > > org.apache.hc.core5.http.impl.nio.AbstractHttp1IOEventHandler.timeo
>> > > ut(AbstractHttp1IOEventHandler.java:81)
>> > > at
>> > > org.apache.hc.core5.http.impl.nio.ServerHttp1IOEventHandler.timeout
>> > > (ServerHttp1IOEventHandler.java:40)
>> > > at
>> > > org.apache.hc.core5.reactor.InternalDataChannel.onTimeout(InternalD
>> > > ataChannel.java:184)
>> > > at
>> > > org.apache.hc.core5.reactor.InternalChannel.checkTimeout(InternalCh
>> > > annel.java:67)
>> > > at
>> > > org.apache.hc.core5.reactor.SingleCoreIOReactor.checkTimeout(Single
>> > > CoreIOReactor.java:232)
>> > > at
>> > > org.apache.hc.core5.reactor.SingleCoreIOReactor.validateActiveChann
>> > > els(SingleCoreIOReactor.java:165)
>> > > at
>> > > org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCor
>> > > eIOReactor.java:127)
>> > > at
>> > > org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(Abs
>> > > tractSingleCoreIOReactor.java:80)
>> > > at
>> > > org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.jav
>> > > a:44)
>> > > at java.lang.Thread.run(Thread.java:745)
>> > >
>> > > Which would indicate that the problem is the same as before.
>> > >
>> > > I will try with different parameters to see if I can make it fail
>> > > faster.
>> > >
>> > > FTR, the JMeter output is:
>> > >
>> > > 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
>> > > Creating summariser <summary>
>> > > Created the tree successfully using
>> > > C:\Users\ggregory\Downloads\OneByteHttpCore.jmx
>> > > Starting the test @ Thu Nov 15 08:50:25 MST 2018 (1542297025377)
>> > > Waiting for possible Shutdown/StopTestNow/Heapdump message on port
>> > > 4445
>> > > summary + 424 in 00:00:04 = 100.4/s Avg: 8 Min: 4
>> > > Max: 228
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary + 4903 in 00:00:30 = 163.5/s Avg: 5 Min: 4
>> > > Max: 56
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 5327 in 00:00:34 = 155.7/s Avg: 6 Min: 4
>> > > Max: 228
>> > > Err: 0 (0.00%)
>> > > summary + 5257 in 00:00:30 = 175.2/s Avg: 5 Min: 3
>> > > Max: 110
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 10584 in 00:01:04 = 164.8/s Avg: 5 Min: 3
>> > > Max: 228
>> > > Err: 0 (0.00%)
>> > > summary + 5646 in 00:00:30 = 188.2/s Avg: 5 Min: 3
>> > > Max: 45
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 16230 in 00:01:34 = 172.2/s Avg: 5 Min: 3
>> > > Max: 228
>> > > Err: 0 (0.00%)
>> > > summary + 5776 in 00:00:30 = 192.6/s Avg: 4 Min: 3
>> > > Max: 51
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 22006 in 00:02:04 = 177.1/s Avg: 5 Min: 3
>> > > Max: 228
>> > > Err: 0 (0.00%)
>> > > summary + 3738 in 00:00:30 = 124.6/s Avg: 7 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 25744 in 00:02:34 = 166.9/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5633 in 00:00:30 = 187.7/s Avg: 5 Min: 3
>> > > Max: 64
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 31377 in 00:03:04 = 170.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5631 in 00:00:30 = 187.8/s Avg: 5 Min: 3
>> > > Max: 61
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 37008 in 00:03:34 = 172.8/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5736 in 00:00:30 = 191.2/s Avg: 5 Min: 3
>> > > Max: 19
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 42744 in 00:04:04 = 175.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5240 in 00:00:30 = 174.7/s Avg: 5 Min: 3
>> > > Max: 474
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 47984 in 00:04:34 = 175.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4498 in 00:00:30 = 149.9/s Avg: 6 Min: 3
>> > > Max: 387
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 52482 in 00:05:04 = 172.5/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5099 in 00:00:30 = 169.8/s Avg: 5 Min: 3
>> > > Max: 340
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 57581 in 00:05:34 = 172.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3838 in 00:00:30 = 128.0/s Avg: 7 Min: 3
>> > > Max: 1403
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 61419 in 00:06:04 = 168.6/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4413 in 00:00:30 = 147.1/s Avg: 6 Min: 3
>> > > Max: 4468
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 65832 in 00:06:34 = 167.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4901 in 00:00:30 = 163.3/s Avg: 5 Min: 3
>> > > Max: 95
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 70733 in 00:07:04 = 166.7/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5136 in 00:00:30 = 171.2/s Avg: 5 Min: 3
>> > > Max: 60
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 75869 in 00:07:34 = 167.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5126 in 00:00:30 = 170.9/s Avg: 5 Min: 3
>> > > Max: 81
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 80995 in 00:08:04 = 167.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4996 in 00:00:30 = 166.5/s Avg: 5 Min: 3
>> > > Max: 82
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 85991 in 00:08:34 = 167.2/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4781 in 00:00:30 = 159.4/s Avg: 6 Min: 3
>> > > Max: 81
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 90772 in 00:09:04 = 166.8/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5136 in 00:00:30 = 171.2/s Avg: 5 Min: 3
>> > > Max: 53
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 95908 in 00:09:34 = 167.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5342 in 00:00:30 = 178.1/s Avg: 5 Min: 3
>> > > Max: 189
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 101250 in 00:10:04 = 167.6/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4895 in 00:00:30 = 163.1/s Avg: 5 Min: 3
>> > > Max: 235
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 106145 in 00:10:34 = 167.4/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5124 in 00:00:30 = 170.8/s Avg: 5 Min: 3
>> > > Max: 68
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 111269 in 00:11:04 = 167.5/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5587 in 00:00:30 = 186.2/s Avg: 5 Min: 3
>> > > Max: 51
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 116856 in 00:11:34 = 168.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4987 in 00:00:30 = 166.2/s Avg: 5 Min: 3
>> > > Max: 221
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 121843 in 00:12:04 = 168.2/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3699 in 00:00:30 = 123.3/s Avg: 7 Min: 3
>> > > Max: 147
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 125542 in 00:12:34 = 166.5/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5499 in 00:00:30 = 183.3/s Avg: 5 Min: 3
>> > > Max: 102
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 131041 in 00:13:04 = 167.1/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5684 in 00:00:30 = 189.5/s Avg: 5 Min: 3
>> > > Max: 29
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 136725 in 00:13:34 = 167.9/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4898 in 00:00:30 = 163.3/s Avg: 5 Min: 3
>> > > Max: 66
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 141623 in 00:14:04 = 167.8/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5506 in 00:00:30 = 183.5/s Avg: 5 Min: 3
>> > > Max: 37
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 147129 in 00:14:34 = 168.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5388 in 00:00:30 = 179.6/s Avg: 5 Min: 3
>> > > Max: 60
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 152517 in 00:15:04 = 168.7/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4588 in 00:00:32 = 143.9/s Avg: 6 Min: 3
>> > > Max: 5522
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 157105 in 00:15:36 = 167.8/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5083 in 00:00:28 = 180.7/s Avg: 5 Min: 3
>> > > Max: 64
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 162188 in 00:16:04 = 168.2/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5208 in 00:00:30 = 173.6/s Avg: 5 Min: 3
>> > > Max: 62
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 167396 in 00:16:34 = 168.4/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 5420 in 00:00:30 = 180.7/s Avg: 5 Min: 3
>> > > Max: 35
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 172816 in 00:17:04 = 168.7/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4802 in 00:00:30 = 160.1/s Avg: 6 Min: 3
>> > > Max: 88
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 177618 in 00:17:34 = 168.5/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3879 in 00:00:30 = 129.3/s Avg: 7 Min: 3
>> > > Max: 128
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 181497 in 00:18:04 = 167.4/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3410 in 00:00:30 = 113.7/s Avg: 8 Min: 4
>> > > Max: 99
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 184907 in 00:18:34 = 166.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3960 in 00:00:30 = 132.0/s Avg: 7 Min: 3
>> > > Max: 106
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 188867 in 00:19:04 = 165.1/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3977 in 00:00:30 = 132.6/s Avg: 7 Min: 4
>> > > Max: 74
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 192844 in 00:19:34 = 164.2/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4564 in 00:00:30 = 152.1/s Avg: 6 Min: 3
>> > > Max: 35
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 197408 in 00:20:04 = 163.9/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4576 in 00:00:30 = 152.5/s Avg: 6 Min: 3
>> > > Max: 43
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 201984 in 00:20:34 = 163.7/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4216 in 00:00:30 = 140.5/s Avg: 6 Min: 3
>> > > Max: 113
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 206200 in 00:21:04 = 163.1/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4485 in 00:00:30 = 149.5/s Avg: 6 Min: 3
>> > > Max: 68
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 210685 in 00:21:34 = 162.8/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4698 in 00:00:30 = 156.6/s Avg: 6 Min: 3
>> > > Max: 52
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 215383 in 00:22:04 = 162.6/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4463 in 00:00:30 = 148.7/s Avg: 6 Min: 3
>> > > Max: 62
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 219846 in 00:22:34 = 162.3/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4353 in 00:00:30 = 145.2/s Avg: 6 Min: 3
>> > > Max: 598
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 224199 in 00:23:04 = 162.0/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4333 in 00:00:30 = 144.4/s Avg: 6 Min: 3
>> > > Max: 827
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 228532 in 00:23:34 = 161.6/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4983 in 00:00:30 = 166.1/s Avg: 5 Min: 3
>> > > Max: 26
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 233515 in 00:24:04 = 161.7/s Avg: 5 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4066 in 00:00:30 = 135.5/s Avg: 7 Min: 4
>> > > Max: 81
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 237581 in 00:24:34 = 161.2/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4282 in 00:00:30 = 142.8/s Avg: 6 Min: 3
>> > > Max: 73
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 241863 in 00:25:04 = 160.8/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4486 in 00:00:30 = 149.5/s Avg: 6 Min: 4
>> > > Max: 66
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 246349 in 00:25:34 = 160.6/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4244 in 00:00:30 = 141.5/s Avg: 6 Min: 4
>> > > Max: 48
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 250593 in 00:26:04 = 160.2/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 3691 in 00:00:30 = 123.1/s Avg: 7 Min: 3
>> > > Max: 118
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 254284 in 00:26:34 = 159.5/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4155 in 00:00:30 = 138.5/s Avg: 7 Min: 3
>> > > Max: 69
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 258439 in 00:27:04 = 159.1/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4305 in 00:00:30 = 143.5/s Avg: 6 Min: 3
>> > > Max: 55
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 262744 in 00:27:34 = 158.8/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4218 in 00:00:30 = 140.6/s Avg: 6 Min: 3
>> > > Max: 60
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 266962 in 00:28:04 = 158.5/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4255 in 00:00:30 = 141.8/s Avg: 6 Min: 3
>> > > Max: 85
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 271217 in 00:28:34 = 158.2/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4452 in 00:00:30 = 148.4/s Avg: 6 Min: 3
>> > > Max: 39
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 275669 in 00:29:04 = 158.0/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4803 in 00:00:30 = 160.0/s Avg: 6 Min: 3
>> > > Max: 78
>> > > Err: 0 (0.00%) Active: 1 Started: 1 Finished: 0
>> > > summary = 280472 in 00:29:34 = 158.1/s Avg: 6 Min: 3
>> > > Max: 9818
>> > > Err: 0 (0.00%)
>> > > summary + 4559 in 00:00:39 = 118.3/s Avg: 8 Min: 3 Max:
>> > > 10053
>> > > Err: 1 (0.02%) Active: 0 Started: 1 Finished: 1
>> > > summary = 285031 in 00:30:13 = 157.2/s Avg: 6 Min: 3 Max:
>> > > 10053
>> > > Err: 1 (0.00%)
>> > > Tidying up ... @ Thu Nov 15 09:20:38 MST 2018 (1542298838562)
>> > > ... end of run
>> > >
>> > > Gary
>> > >
>> > >
>> > >
>> > >
>> > >
>> > > > Gary
>> > > >
>> > > >
>> > > > >
>> > > > > Cheers
>> > > > >
>> > > > > Oleg
>> > > > >
>> > > > >
>> > > > > -------------------------------------------------------------
>> > > > > --------
>> > > > > To unsubscribe, e-mail: [email protected]
>> > > > > For additional commands, e-mail: [email protected]
>> > > > >
>> > > > >
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [email protected]
>> For additional commands, e-mail: [email protected]
>>
>>
