You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@sling.apache.org by ie...@apache.org on 2013/02/27 09:37:12 UTC
svn commit: r1450676 - in /sling/whiteboard/ieb/log/src:
main/java/org/apache/sling/commons/log/internal/monitor/
main/java/org/apache/sling/commons/log/internal/slf4j/
test/java/org/apache/sling/commons/log/internal/monitor/
Author: ieb
Date: Wed Feb 27 08:37:11 2013
New Revision: 1450676
URL: http://svn.apache.org/r1450676
Log:
Possible counter implementation with test.
The SIngle threaded counter test shows the count operation takes just under 200ns.
Multi threaded 1 2 cores, 240ns and then adjusting for the number of processors up to 250ns upto 32 threads, indicating
no blocking on the counters.
These tests try and warm up hotspot by running 100k operations before starting the test, but they wont be fully representative
of a real environment.
The impl uses AtomicLongs and ConcurrentHashMaps with no synchronisation to ensure all the memory operations are performed within
the atomic instances.
The servlet needs to be registered as a service.
Added:
sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/
sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java (with props)
sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java (with props)
sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/
sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java (with props)
Modified:
sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/slf4j/SlingLogger.java
Added: sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java
URL: http://svn.apache.org/viewvc/sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java?rev=1450676&view=auto
==============================================================================
--- sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java (added)
+++ sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java Wed Feb 27 08:37:11 2013
@@ -0,0 +1,124 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The SF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations under the License.
+ */
+package org.apache.sling.commons.log.internal.monitor;
+
+import java.util.Map;
+import java.util.Map.Entry;
+import java.util.Set;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.atomic.AtomicLong;
+
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
+public class Counter {
+
+ /**
+ * Name of the marker.
+ * might want to move these to a class where they can be exported (probably not this one).
+ */
+ public static final String MAKER_NAME = "count";
+ /**
+ * The marker itself. same as above.
+ */
+ public static final Marker COUNT = MarkerFactory.getMarker(MAKER_NAME);
+ // there might be as many as 100 counters, adjust if more becomes the norm.
+ private static final int NCOUNTERS = 100;
+ // not likely to meet a machine with > 32 cores and see all trying to
+ // update a counter within the same few ms.
+ private static final int CONCURRENCY = 32;
+ // not expecting much map growth, so up the occupancy factor a bit.
+ private float LOAD_FACTOR = 0.80F;
+
+ /**
+ * Singleton instance.
+ */
+ private static Counter instance = new Counter();
+ private Map<String, AtomicLong> counters = new ConcurrentHashMap<String, AtomicLong>(
+ NCOUNTERS, LOAD_FACTOR, CONCURRENCY);
+ // size of the last output buffer.
+ private int last_size = 100;
+
+ /**
+ * @return the counter singleton.
+ */
+ public static Counter getInstance() {
+ return instance;
+ }
+
+ /**
+ * @param marker
+ * the marker that was used to log the message.
+ * @param message
+ * the message which if a counter should be the name of the
+ * message.
+ * @return true if the marker is a counter.
+ */
+ public boolean increment(Marker marker, String message) {
+ if (COUNT.equals(marker) && message != null) {
+ get(message).incrementAndGet();
+ return true;
+ }
+ return false;
+ }
+
+ /**
+ *
+ * @return a json string of the counters with a timestamp of when the
+ * counters were dumped. Not all counters might have been dumped
+ * precisely at the time recorded in the json response.
+ */
+ public String toJson() {
+ // create a string buffer every time a bit larger than the last time
+ // Each response is new as _timenanos must be updated.
+ StringBuilder sb = new StringBuilder(last_size + 10);
+ sb.append("{");
+ Set<Entry<String, AtomicLong>> es = counters.entrySet();
+ sb.append("\"_timenanos\":").append(System.nanoTime());
+ for (Entry<String, AtomicLong> e : es) {
+ sb.append(",\"");
+ sb.append(e.getKey().replace('"', '_'));
+ sb.append("\":");
+ sb.append(e.getValue().get());
+ }
+ sb.append("}");
+ // save the last size so next time we can make the StringBuffer about
+ // the right size.
+ last_size = sb.length();
+ return sb.toString();
+ }
+
+ /**
+ * @param name name of the counter.
+ * @return the atomic long associated with the name.
+ */
+ private AtomicLong get(String name) {
+ AtomicLong l = counters.get(name);
+ // this might create multiples at the same time but the last will be returned.
+ // one and the counter will only be a few out.
+ // but even so the ConcurrentHashMap get may also miss the put on
+ // another thread, see the ConcurrentHashMap API description.
+ // for more details.
+ if (l == null) {
+ l = new AtomicLong();
+ counters.put(name, l);
+ }
+ return l;
+ }
+
+}
Propchange: sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/Counter.java
------------------------------------------------------------------------------
svn:eol-style = native
Added: sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java
URL: http://svn.apache.org/viewvc/sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java?rev=1450676&view=auto
==============================================================================
--- sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java (added)
+++ sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java Wed Feb 27 08:37:11 2013
@@ -0,0 +1,56 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The SF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations under the License.
+ */
+package org.apache.sling.commons.log.internal.monitor;
+
+import java.io.IOException;
+
+import javax.servlet.ServletException;
+import javax.servlet.http.HttpServlet;
+import javax.servlet.http.HttpServletRequest;
+import javax.servlet.http.HttpServletResponse;
+
+
+public class CounterServlet extends HttpServlet {
+
+ /**
+ *
+ */
+ private static final long serialVersionUID = 4824982332082956436L;
+
+ @Override
+ protected void doGet(HttpServletRequest req, HttpServletResponse resp)
+ throws ServletException, IOException {
+
+ String response = Counter.getInstance().toJson();
+ resp.setContentType("application/json; charset=utf-8");
+ resp.setHeader("Cache-control", "no-cache");
+ resp.setContentLength(response.length());
+ resp.getWriter().write(response);
+ }
+
+ @Override
+ protected void service(HttpServletRequest req, HttpServletResponse resp)
+ throws ServletException, IOException {
+ if ("GET".equals(req.getMethod()) ) {
+ doGet(req, resp);
+ } else {
+ resp.sendError(HttpServletResponse.SC_METHOD_NOT_ALLOWED);
+ }
+ }
+
+}
Propchange: sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/monitor/CounterServlet.java
------------------------------------------------------------------------------
svn:eol-style = native
Modified: sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/slf4j/SlingLogger.java
URL: http://svn.apache.org/viewvc/sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/slf4j/SlingLogger.java?rev=1450676&r1=1450675&r2=1450676&view=diff
==============================================================================
--- sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/slf4j/SlingLogger.java (original)
+++ sling/whiteboard/ieb/log/src/main/java/org/apache/sling/commons/log/internal/slf4j/SlingLogger.java Wed Feb 27 08:37:11 2013
@@ -21,6 +21,7 @@ package org.apache.sling.commons.log.int
import java.io.PrintWriter;
import java.io.StringWriter;
+import org.apache.sling.commons.log.internal.monitor.Counter;
import org.slf4j.Marker;
import org.slf4j.helpers.FormattingTuple;
import org.slf4j.helpers.MessageFormatter;
@@ -32,8 +33,11 @@ class SlingLogger implements LocationAwa
private SlingLoggerConfig config;
+ private Counter counter;
+
SlingLogger(String name) {
this.name = name;
+ this.counter = Counter.getInstance();
}
void setLoggerConfig(SlingLoggerConfig config) {
@@ -58,6 +62,9 @@ class SlingLogger implements LocationAwa
private void log(Marker marker, String fqcn, SlingLoggerLevel level,
String msg, Throwable t) {
+ if ( counter.increment(marker, msg) ) {
+ return;
+ }
StringWriter writer = new StringWriter();
// create the formatted log line; use a local copy because the field
Added: sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java
URL: http://svn.apache.org/viewvc/sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java?rev=1450676&view=auto
==============================================================================
--- sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java (added)
+++ sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java Wed Feb 27 08:37:11 2013
@@ -0,0 +1,115 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The SF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations under the License.
+ */
+package org.apache.sling.commons.log.internal.monitor;
+
+import java.util.concurrent.atomic.AtomicLong;
+
+import junit.framework.Assert;
+
+import org.junit.Test;
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
+public class CounterTest {
+ /**
+ * Give a very rough idea of performance single threaded.
+ * NB: This is a totally unscientific benchmark.
+ */
+ @Test
+ public void testCounter() {
+ Marker m = MarkerFactory.getMarker("count");
+ Counter counter = Counter.getInstance();
+ int loops = 100000;
+ int counters = 100;
+ long ncounts = loops*counters;
+ // attemt to warm up hotspot by causing the code to be executed > 10k times.
+ for ( int j = 0; j < loops+1; j++ ) {
+ for ( int i = 0; i < counters+1; i++) {
+ counter.increment(m, "cou\"nter"+i);
+ }
+ }
+
+ long l = System.nanoTime();
+ for ( int j = 0; j < loops; j++ ) {
+ for ( int i = 0; i < counters; i++) {
+ counter.increment(m, "cou\"nter"+i);
+ }
+ }
+ l = System.nanoTime() - l;
+ System.err.println("Time Taken for 1 count operation is "+(l/ncounts)+" nanoseconds");
+ String json = counter.toJson();
+ Assert.assertNotNull(json);
+ }
+
+ @Test
+ public void testCounterMultiThreaded() throws InterruptedException {
+ for (int i = 1; i < 32; i++ ) {
+ doMulti(i, 10000, 100, Runtime.getRuntime().availableProcessors());
+ }
+ }
+
+ public long doMulti(int threads, final int loops, final int counters, int cores) throws InterruptedException {
+ final Marker m = MarkerFactory.getMarker("count");
+ final Counter counter = Counter.getInstance();
+ // attemt to warm up hotspot by causing the code to be executed > 10k times.
+ for ( int j = 0; j < loops+1; j++ ) {
+ for ( int i = 0; i < counters+1; i++) {
+ counter.increment(m, "cou\"nter"+i);
+ }
+ }
+ final int ncounts = loops*counters;
+ final int tcounts = ncounts*threads;
+ Thread[] t = new Thread[threads];
+ final long[] l = new long[threads];
+ for ( int i = 0; i < threads; i++ ) {
+ final int threadn = i;
+ t[i] = new Thread() {
+ public void run() {
+ l[threadn] = System.nanoTime();
+ for ( int j = 0; j < loops; j++ ) {
+ for ( int i = 0; i < counters; i++) {
+ counter.increment(m, "cou\"nter"+i);
+ }
+ }
+ l[threadn] = System.nanoTime() - l[threadn];
+ };
+ };
+ }
+ for ( int i = 0; i < t.length; i++) {
+ t[i].start();
+ }
+ for ( int i = 0; i < t.length; i++) {
+ t[i].join();
+ }
+ // work out the total time over all threads.
+ long overall = 0L;
+ for ( int i = 0; i < t.length; i++) {
+ overall += l[i];
+ }
+ // work out how long it should have taken if we had as many cores as threads.
+ // this number should remain constant if no threads block other threads and both cores on the box are
+ // fully utilized.
+ long adjusted = overall/tcounts;
+ if ( threads > cores ) {
+ adjusted = (cores*100*(adjusted))/(100*threads);
+ }
+ System.err.println("Time Taken for 1 count operation over "+t.length+" threads is "+(overall/tcounts)+" ns "+adjusted+" ns adjusted for CPUs");
+ return adjusted;
+
+ }
+}
Propchange: sling/whiteboard/ieb/log/src/test/java/org/apache/sling/commons/log/internal/monitor/CounterTest.java
------------------------------------------------------------------------------
svn:eol-style = native