move metric naming to metricFilter isntead of metric emitter, add

average complete request time metric.

[#151023794] https://www.pivotaltracker.com/story/show/151023794
[#151023792] https://www.pivotaltracker.com/story/show/151023792

Signed-off-by: Shash Reddy <sreddy@pivotal.io>

server/src/main/java/org/cloudfoundry/identity/uaa/metrics/IdleTimer.java

@@ -21,14 +21,18 @@
  */
 public class IdleTimer {
 
-    private int inflightRequests = 0;
+    private long inflightRequests = 0;
     private long idleTime = 0;
+
+    private double averageTime = 0;
     private long lastIdleStart = System.currentTimeMillis();
     private final long startTime = System.currentTimeMillis();
     private long requestCount = 0;
 
+    private int averageCount = 0;
+
     public synchronized void endRequest() {
-        switch (--inflightRequests) {
+        switch ((int) --inflightRequests) {
             case 0:
                 lastIdleStart = System.currentTimeMillis();
                 break;
@@ -41,17 +45,37 @@ public synchronized void endRequest() {
     }
 
     public synchronized void startRequest() {
-        switch (++inflightRequests) {
+        switch ((int) ++inflightRequests) {
             case 1:
                 idleTime += (System.currentTimeMillis() - lastIdleStart);
                 break;
             default:
                 break;
         }
 
+
+
+    }
+
+    public void updateAverageTime(long duration) {
+        if(duration < 0) {
+            throw new IllegalArgumentException("Duration cannot be negative.");
+        }
+        averageCount++;
+        double newAverage = averageTime + (1.0 / (averageCount) * (duration - averageTime)); //iterative mean
+        averageTime = (newAverage);
+    }
+
+    public long getAverageTime() {
+        return (long) averageTime;
     }
 
-    public int getInflightRequests() {
+    public void setAverageTime(long averageTime) {
+        this.averageTime = averageTime;
+    }
+
+
+    public long getInflightRequests() {
         return inflightRequests;
     }
 

server/src/main/java/org/cloudfoundry/identity/uaa/metrics/UaaMetricsFilter.java

@@ -58,6 +58,7 @@ protected void doFilterInternal(HttpServletRequest request, HttpServletResponse
                 MetricsAccessor.clear();
                 inflight.endRequest();
                 metric.stop(response.getStatus(), timeService.getCurrentTimeMillis());
+                inflight.updateAverageTime(metric.getRequestCompleteTime() - metric.getRequestStartTime());
                 MetricsQueue queue = getMetricsQueue(uriGroup);
                 queue.offer(metric);
             }
@@ -117,8 +118,9 @@ protected String getUriGroup(HttpServletRequest request) {
     }
 
 
+
     @ManagedMetric(category = "performance", displayName = "Inflight Requests")
-    public int getInflightRequests() {
+    public long getOutstandingCount() {
         return inflight.getInflightRequests();
     }
 
@@ -128,17 +130,17 @@ public long getIdleTime() {
     }
 
     @ManagedMetric(category = "performance", displayName = "Processing request time (ms)")
-    public long getProcessingTime() {
-        return inflight.getRunTime() - inflight.getIdleTime();
+    public long getCompletedTime() {
+        return inflight.getAverageTime();
     }
 
     @ManagedMetric(category = "performance", displayName = "Total server run time (ms)")
-    public long getRunTime() {
+    public long getUpTime() {
         return inflight.getRunTime();
     }
 
-    @ManagedMetric(category = "performance", displayName = "Number of completed requests")
-    public long getCompletedRequests() {
+    @ManagedMetric(category = "performance", displayName="CompletedRequests", description = "Number of completed requests")
+    public long getCompletedCount() {
         return inflight.getRequestCount();
     }
 

server/src/test/java/org/cloudfoundry/identity/uaa/metrics/IdleTimerTests.java

@@ -15,6 +15,7 @@
 
 package org.cloudfoundry.identity.uaa.metrics;
 
+import org.junit.Assert;
 import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
@@ -72,6 +73,21 @@ public void while_inflight() throws Exception {
         assertThat("Idle time should have changed.", timer.getIdleTime(), greaterThan(idleTime));
     }
 
+    @Test
+    public void average_time_test() throws Exception {
+        for(int i = 1; i < 101; i++) {
+            timer.updateAverageTime(i);
+        }
+        assertEquals(50, timer.getAverageTime());
+
+        try{
+            timer.updateAverageTime(-5);
+            Assert.fail("updateAverageTime didn't throw an error for negative duration");
+        }catch (IllegalArgumentException e) {
+            assertEquals("Duration cannot be negative.", e.getMessage());
+        }
+    }
+
     @Test
     public void concurrency_test() throws Exception {
         final CountDownLatch latch = new CountDownLatch(THREAD_COUNT);

server/src/test/java/org/cloudfoundry/identity/uaa/metrics/UaaMetricsFilterTests.java

@@ -111,10 +111,10 @@ public void idle_counter() throws Exception {
         Thread invoker = new Thread(invocation);
         invoker.start();
         Thread.sleep(10);
-        assertEquals(1, filter.getInflightRequests());
+        assertEquals(1, filter.getOutstandingCount());
         lock.unlock();
         Thread.sleep(25);
-        assertEquals(0, filter.getInflightRequests());
+        assertEquals(0, filter.getOutstandingCount());
         long idleTime = filter.getIdleTime();
         assertThat(idleTime, greaterThan(20l));
         System.out.println("Total idle time was:"+idleTime);

statsd/src/main/java/org/cloudfoundry/identity/statsd/MBeanMap.java

@@ -86,7 +86,7 @@ public Set<java.util.Map.Entry<String, Object>> entrySet() {
 			for (MBeanOperationInfo operation : operations) {
 				String key = operation.getName();
 				if (key.startsWith("get") && operation.getSignature().length == 0) {
-					String attribute = StringUtils.camelToUnderscore(key.substring(3));
+					String attribute = StringUtils.camelToPeriod(key.substring(3));
 					if (map.containsKey(attribute)) {
 						continue;
 					}
@@ -168,7 +168,7 @@ private void verySafePut(Map<? extends Object, Object> map, Object key, Object v
 	private void safePut(Map<Object, Object> map, Object key, Object value, boolean prettifyKeys) {
 		Object property = key;
 		if (key instanceof String && prettifyKeys) {
-			property = StringUtils.camelToUnderscore((String) key);
+			property = StringUtils.camelToPeriod((String) key);
 		}
 		// Don't prettify system property keys in case user has added upper case properties
 		map.put(property, getCompositeWrapper(value, prettifyKeys && !key.equals("SystemProperties")));

statsd/src/main/java/org/cloudfoundry/identity/statsd/StringUtils.java

@@ -33,4 +33,12 @@ public static String camelToUnderscore(String value) {
 		result = result.toLowerCase();
 		return result;
 	}
+
+	public static String camelToPeriod(String key) {
+		String result = key.replace(" ", ".");
+		result = result.replaceAll("([a-z])([A-Z])", "$1.$2");
+		result = result.replace("_", ".");
+		result = result.toLowerCase();
+		return result;
+	}
 }

statsd/src/main/java/org/cloudfoundry/identity/statsd/UaaMetricsEmitter.java

@@ -53,12 +53,13 @@ public void emitMetrics() throws Exception {
     }
 
     @Scheduled(fixedRate = 5000)
-    public void emitRequestCount() throws Exception {
+    public void emitGlobalRequestMetrics() throws Exception {
         Map<String, ?> spring = metricsUtils.pullUpMap("cloudfoundry.identity", "*", server);
         if (spring != null) {
             MBeanMap uaaMetricsMap = (MBeanMap) getValueFromMap(spring, "#this['ServerRequests']");
             if (uaaMetricsMap != null){
-                statsDClient.gauge("requests.global.completed.count", (Long) uaaMetricsMap.get("completed_requests"));
+                String prefix = "requests.global.";
+                uaaMetricsMap.entrySet().stream().filter(e -> e.getValue() != null && e.getValue() instanceof Long).forEach(e -> statsDClient.gauge(prefix+e.getKey(), (long) e.getValue()));
             }
         }
     }

statsd/src/test/java/org/cloudfoundry/identity/statsd/UaaMetricsEmitterTests.java

@@ -84,7 +84,7 @@ public void requestCount_metrics_emitted() throws Exception {
         uaaMetricsEmitter.setMetricsUtils(metricsUtils);
         Mockito.when(metricsUtils.pullUpMap("cloudfoundry.identity", "*", server)).thenReturn((Map)mBeanMap3);
 
-        uaaMetricsEmitter.emitRequestCount();
+        uaaMetricsEmitter.emitGlobalRequestMetrics();
         Mockito.verify(statsDClient).gauge("requests.global.completed.count", 53L);
     }
 

statsd/src/test/java/org/cloudfoundry/identity/statsd/integration/UaaMetricsEmitterIT.java

@@ -96,6 +96,26 @@ public void testGlobalCompletedCountMetrics() throws IOException {
         assertTrue("Expected " + nextValue + " to be greater than " + previousValue, nextValue > previousValue);
     }
 
+    @Test
+    public void testGlobalCompletedTimeMetrics() throws IOException {
+        String message = getMessage("uaa.requests.global.completed.time", 5000);
+
+        RestTemplate template = new RestTemplate();
+
+        HttpHeaders headers = new HttpHeaders();
+        headers.set(headers.ACCEPT, MediaType.TEXT_HTML_VALUE);
+        ResponseEntity<String> loginResponse = template.exchange(UAA_BASE_URL + "/login",
+                HttpMethod.GET,
+                new HttpEntity<>(null, headers),
+                String.class);
+
+        message = getMessage("uaa.requests.global.completed.time", 5000);
+        Long nextValue = IntegrationTestUtils.getGaugeValueFromMessage(message);
+
+        assertTrue("Expected " + nextValue + " to be greater than0", nextValue > 0);
+    }
+
+
     protected String getMessage(String fragment, int timeout) throws IOException {
         long startTime = System.currentTimeMillis();
         String found = null;