after adding an ssp I observe a strange slowdow: after round 98 (i.e. 980000 requests) it becomes 5 time slower
for i in `seq 1000`; do echo round $i; ab -n 10000 -H "Accept: application/xhtml+xml" -c 100 -A admin:admin http://localhost:8080/greeting/list; done Round 1: Time per request: 520.207 [ms] (mean) Round 2: Time per request: 395.147 [ms] (mean) ... Round 96: Time per request: 394.507 [ms] (mean) Round 97: Time per request: 567.768 [ms] (mean) Round 98: Time per request: 558.511 [ms] (mean) Round 99: Time per request: 2662.950 [ms] (mean) Round 100: Time per request: 2839.969 [ms] (mean) Round 101: Time per request: 2928.085 [ms] (mean) Round 102: Time per request: 2934.582 [ms] (mean) Round 103: Time per request: 3008.430 [ms] (mean) Round 104: Time per request: 2957.012 [ms] (mean) Round 105: Time per request: 3012.764 [ms] (mean) Round 106: Time per request: 3569.310 [ms] (mean) Round 107: Time per request: 3915.529 [ms] (mean) On the console I see aroung 1000 logs like this [qtp476205266-19 - Acceptor0 [email protected]:8080] WARN org.eclipse.jetty.util.log - EXCEPTION java.io.IOException: Too many open files at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:163) at org.eclipse.jetty.server.nio.SelectChannelConnector$1.acceptChannel(SelectChannelConnector.java:74) at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:650) at org.eclipse.jetty.io.nio.SelectorManager.doSelect(SelectorManager.java:195) at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:134) at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:793) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436) at java.lang.Thread.run(Thread.java:636) There are two open sockets, and 256 open files in the tdb-data directory Repeating the experiment, the speed is quite constant till round 97 and then starts to decrease massively. 95 Time per request: 533.913 [ms] (mean) 96 Time per request: 377.717 [ms] (mean) 97 Time per request: 541.047 [ms] (mean) 98 Time per request: 1429.697 [ms] (mean) 99 Time per request: 2693.674 [ms] (mean) 100 Time per request: 2763.258 [ms] (mean) 101 Time per request: 2857.210 [ms] (mean) 102 Time per request: 2898.990 [ms] (mean) 103 Time per request: 2932.736 [ms] (mean) 104 Time per request: 3014.051 [ms] (mean) 105 Time per request: 3325.968 [ms] (mean) 106 Time per request: 4154.931 [ms] (mean) 107 Time per request: 3938.169 [ms] (mean) 108 Time per request: 4004.883 [ms] (mean) 109 Time per request: 4181.464 [ms] (mean) 110 Time per request: 4317.757 [ms] (mean) 111 Time per request: 4535.995 [ms] (mean) 112 Time per request: 4695.218 [ms] (mean) 113 Time per request: 4900.455 [ms] (mean) 114 Time per request: 5161.572 [ms] (mean) 115 Time per request: 5372.835 [ms] (mean) 116 Time per request: 5680.455 [ms] (mean) 117 Time per request: 5965.081 [ms] (mean) 118 Time per request: 6291.290 [ms] (mean) 119 Time per request: 6668.914 [ms] (mean) 120 Time per request: 7074.508 [ms] (mean) 121 Time per request: 7546.811 [ms] (mean) 122 Time per request: 8095.533 [ms] (mean) 123 Time per request: 8619.783 [ms] (mean) 124 Time per request: 9317.463 [ms] (mean) 125 Time per request: 10131.045 [ms] (mean) 126 Time per request: 11079.445 [ms] (mean) 127 Time per request: 12146.688 [ms] (mean) 128 Time per request: 13516.644 [ms] (mean) 129 Time per request: 15219.902 [ms] (mean) 130 Time per request: 17367.628 [ms] (mean) 131 Time per request: 20243.487 [ms] (mean) 132 Time per request: 24319.549 [ms] (mean) 133 Time per request: 30387.020 [ms] (mean) No "Too many open files" logs this time, instead two logs about exceptions caused by "java.io.IOException: Broken pipe". Reto On Thu, Oct 28, 2010 at 7:58 PM, Reto Bachmann-Gmuer < [email protected]> wrote: > Still investigating on the situation where Clerezza doesn'tswllo stress > test. Today it passed the following 10 millions triples challenge: > > Setting: > - 100 concurrent threads > - 1000 * 10000 requests > - requested media-type: application/rdf+xml > > generating resource method: > @GET > public GraphNode list() { > TripleCollection resultGraph = new SimpleMGraph(); > GraphNode result = new GraphNode(new BNode(), resultGraph); > RdfList list = new RdfList(result); > LockableMGraph contentGraph = cgProvider.getContentGraph(); > Lock l = contentGraph.getLock().readLock(); > l.lock(); > try { > Iterator<Triple> greetings = contentGraph.filter(null, > RDF.type, GREETINGS.Greeting); > while (greetings.hasNext()) { > list.add(greetings.next().getSubject()); > } > } finally { > l.unlock(); > } > return result; > } > > Data: > - 2 resources of type GREETINGS.Greeting > > Result: > For every block of 10000 requests the following is true: > - 90% of the requests where answered in less than 161 ms > - 50% of all requests where answered in less than 58 ms > - the longest request took between 15687 and 3105 ms > - mean time between 109 and 221 ms > - No requests failed > > No rocket science statistics, but it gives an idea. > > A next step is to add an ssp. > > Reto > >
