* issue #826 resolution

* version changed to 2.5.3
emc-mongoose · Oct 19, 2016 · 6b38b8e · 6b38b8e
1 parent aa1a39e
commit 6b38b8e
Show file tree

Hide file tree

Showing 8 changed files with 39 additions and 5 deletions.
diff --git a/conf/defaults.json b/conf/defaults.json
@@ -169,7 +169,7 @@
 			"resume" : {
 				"enabled" : false
 			},
-			"version" : "2.5.2"
+			"version" : "2.5.3"
 		},
 		"storage" : {
 			"type" : "http",
@@ -182,7 +182,7 @@
 				"fsAccess" : false,
 				"headers" : {
 					"Connection" : "keep-alive",
-					"User-Agent" : "mongoose/2.5.2"
+					"User-Agent" : "mongoose/2.5.3"
 				},
 				"namespace" : null,
 				"versioning" : false

diff --git a/conf/logging.json b/conf/logging.json
@@ -303,7 +303,7 @@
 					"PatternLayout": {
 						"header": "<result>\n",
 						"footer": "</result>\n",
-						"pattern": "<result id=\"%X{run.id}\" filesize=\"%X{item.data.size}\" %replace{%m}{\"([\\d]+)\\-([A-Za-z0-9]+)\\-([CreatRdUpDl]+)[\\d]*\\-([\\d]*)x?([\\d]*)x?([\\d]*)\"[\\s]+summary:[\\s]+n=\\((\\d+)/\\\u001B*\\[*\\d*m*(\\d+)\\\u001B*\\[*\\d*m*\\);[\\s]+size=\\(([\\.\\d]+[KMGTPE]?B?)\\);[\\s]+t\\[s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+TP\\[op/s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+BW\\[MB/s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+dur\\[us\\]=\\((\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)\\);[\\s]+lat\\[us\\]=\\((\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)\\)}{bw=\"$14\" bw_unit=\"MBps\" clients=\"$6\" error=\"$8\" latency=\"$22\" latency_unit=\"us\" operation=\"$3\" runtime=\"$10\" threads=\"$4\" tps=\"$12\" tps_unit=\"Fileps\" duration=\"$16\" duration_unit=\"us\" latency_min=\"$23\" latency_loq=\"$24\" latency_med=\"$25\" latency_hiq=\"$26\" latency_max=\"$27\" duration_min=\"$17\" duration_loq=\"$18\" duration_med=\"$19\" duration_hiq=\"$20\" duration_max=\"$21\"\/>}%n",
+						"pattern": "<result id=\"%X{run.id}\" StartDate=\"%X{start.date}\" StartTimestamp=\"%X{start.time}\" EndDate=\"%X{end.date}\" EndTimestamp=\"%X{end.time}\" filesize=\"%X{item.data.size}\" %replace{%m}{\"([\\d]+)\\-([A-Za-z0-9]+)\\-([CreatRdUpDl]+)[\\d]*\\-([\\d]*)x?([\\d]*)x?([\\d]*)\"[\\s]+summary:[\\s]+n=\\((\\d+)/\\\u001B*\\[*\\d*m*(\\d+)\\\u001B*\\[*\\d*m*\\);[\\s]+size=\\(([\\.\\d]+[KMGTPE]?B?)\\);[\\s]+t\\[s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+TP\\[op/s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+BW\\[MB/s\\]=\\(([\\.\\d]+)/([\\.\\d]+)\\);[\\s]+dur\\[us\\]=\\((\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)\\);[\\s]+lat\\[us\\]=\\((\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)/(\\d+)\\)}{bw=\"$14\" bw_unit=\"MBps\" clients=\"$6\" error=\"$8\" latency=\"$22\" latency_unit=\"us\" operation=\"$3\" runtime=\"$10\" threads=\"$4\" tps=\"$12\" tps_unit=\"Fileps\" duration=\"$16\" duration_unit=\"us\" latency_min=\"$23\" latency_loq=\"$24\" latency_med=\"$25\" latency_hiq=\"$26\" latency_max=\"$27\" duration_min=\"$17\" duration_loq=\"$18\" duration_med=\"$19\" duration_hiq=\"$20\" duration_max=\"$21\"\/>}%n",
 						"noConsoleNoAnsi": true
 					},
 					"Filters": {

diff --git a/src/main/java/com/emc/mongoose/client/impl/load/model/metrics/DistributedIoStats.java b/src/main/java/com/emc/mongoose/client/impl/load/model/metrics/DistributedIoStats.java
@@ -327,6 +327,7 @@ public final Snapshot getSnapshot() {
 		final long currElapsedTime = tsStartMicroSec > 0 ?
 			TimeUnit.NANOSECONDS.toMicros(System.nanoTime()) - tsStartMicroSec : 0;
 		return new BasicIoStats.BasicSnapshot(
+			tsStartMilliSec,
 			countSucc, succRateLast, countFail, failRateLast, countByte, byteRateLast,
 			prevElapsedTimeMicroSec + currElapsedTime, sumDurMicroSec, sumLatMicroSec,
 			reqDuration.getSnapshot(), respLatency.getSnapshot()

diff --git a/src/main/java/com/emc/mongoose/core/api/load/model/metrics/IoStats.java b/src/main/java/com/emc/mongoose/core/api/load/model/metrics/IoStats.java
@@ -50,6 +50,8 @@ void markSucc(
 	//
 	interface Snapshot
 	extends Serializable {
+		//
+		long getStartTimeMilliSec();
 		//
 		long getSuccCount();
 		double getSuccRateMean();

diff --git a/src/main/java/com/emc/mongoose/core/impl/load/executor/LoadExecutorBase.java b/src/main/java/com/emc/mongoose/core/impl/load/executor/LoadExecutorBase.java
@@ -35,14 +35,19 @@
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.Marker;
+import org.apache.logging.log4j.ThreadContext;
 
 import java.io.IOException;
 import java.io.InterruptedIOException;
 import java.rmi.RemoteException;
+import java.text.DateFormat;
+import java.text.SimpleDateFormat;
 import java.util.ArrayList;
 import java.util.Collections;
+import java.util.Date;
 import java.util.LinkedList;
 import java.util.List;
+import java.util.TimeZone;
 import java.util.concurrent.ArrayBlockingQueue;
 import java.util.concurrent.RejectedExecutionException;
 import java.util.concurrent.ThreadPoolExecutor;
@@ -63,6 +68,11 @@ public abstract class LoadExecutorBase<T extends Item>
 implements LoadExecutor<T> {
 	//
 	private final static Logger LOG = LogManager.getLogger();
+	private final static DateFormat FMT_DATE_RESULTS = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss") {
+		{
+			setTimeZone(TimeZone.getTimeZone("UTC"));
+		}
+	};
 	//
 	protected final int instanceNum, storageNodeCount;
 	protected final String storageNodeAddrs[];
@@ -314,6 +324,16 @@ public void logMetrics(final Marker logMarker) {
 					medIoStats == null ? null : medIoStats.getSnapshot().toSummaryString()
 				);
 			} else if(Markers.PERF_SUM.equals(logMarker)) {
+				final long startTimeMillis = lastStats.getStartTimeMilliSec();
+				ThreadContext.put("start.date", FMT_DATE_RESULTS.format(new Date(startTimeMillis)));
+				ThreadContext.put(
+					"start.time", Long.toString(TimeUnit.MILLISECONDS.toSeconds(startTimeMillis))
+				);
+				final long endTimeMillis = System.currentTimeMillis();
+				ThreadContext.put("end.date", FMT_DATE_RESULTS.format(new Date(endTimeMillis)));
+				ThreadContext.put(
+					"end.time", Long.toString(TimeUnit.MILLISECONDS.toSeconds(endTimeMillis))
+				);
 				LOG.info(
 					logMarker, "\"{}\" summary: {}", getName(),
 					lastStats == null ? null : lastStats.toSummaryString()

diff --git a/src/main/java/com/emc/mongoose/core/impl/load/model/metrics/BasicIoStats.java b/src/main/java/com/emc/mongoose/core/impl/load/model/metrics/BasicIoStats.java
@@ -78,6 +78,7 @@ public Snapshot getSnapshot() {
 		final com.codahale.metrics.Snapshot respLatSnapshot = respLatency.getSnapshot();
 		LockSupport.parkNanos(1_000);
 		return new BasicSnapshot(
+			tsStartMilliSec,
 			throughPutSucc == null ? 0 : throughPutSucc.getCount(),
 			throughPutSucc == null ? 0 : throughPutSucc.getLastRate(),
 			throughPutFail == null ? 0 : throughPutFail.getCount(),

diff --git a/src/main/java/com/emc/mongoose/core/impl/load/model/metrics/IoStatsBase.java b/src/main/java/com/emc/mongoose/core/impl/load/model/metrics/IoStatsBase.java
@@ -31,6 +31,7 @@ public abstract class IoStatsBase
 	protected final MBeanServer mBeanServer;
 	protected final CustomJmxReporter jmxReporter;
 	protected final Histogram reqDuration, respLatency;
+	protected volatile long tsStartMilliSec = -1;
 	protected volatile long tsStartMicroSec = -1, prevElapsedTimeMicroSec = 0;
 	//
 	protected IoStatsBase(final String name, final boolean serveJmxFlag) {
@@ -52,6 +53,7 @@ public void start() {
 			jmxReporter.start();
 		}
 		tsStartMicroSec = TimeUnit.NANOSECONDS.toMicros(System.nanoTime());
+		tsStartMilliSec = System.currentTimeMillis();
 	}
 	//
 	@Override
@@ -106,6 +108,7 @@ public static String formatNumber(final double number) {
 	protected final static class BasicSnapshot
 	implements Snapshot {
 		//
+		private final long tsStartMilliSec;
 		private final long countSucc;
 		private final double succRateLast;
 		private final long countFail;
@@ -121,13 +124,15 @@ protected final static class BasicSnapshot
 		private final long elapsedTime;
 		//
 		public BasicSnapshot(
+			final long tsStartMilliSec,
 			final long countSucc, final double succRateLast,
 			final long countFail, final double failRate,
 			final long countByte, final double byteRate,
 			final long elapsedTime, final long sumDur, final long sumLat,
 			final com.codahale.metrics.Snapshot durSnapshot,
 			final com.codahale.metrics.Snapshot latSnapshot
 		) {
+			this.tsStartMilliSec = tsStartMilliSec;
 			this.countSucc = countSucc;
 			this.succRateLast = succRateLast;
 			this.countFail = countFail;
@@ -144,6 +149,11 @@ public BasicSnapshot(
 		}
 		//
 		@Override
+		public final long getStartTimeMilliSec() {
+			return tsStartMilliSec;
+		}
+		//
+		@Override
 		public final long getSuccCount() {
 			return countSucc;
 		}

diff --git a/src/main/resources/defaults.json b/src/main/resources/defaults.json
@@ -169,7 +169,7 @@
 			"resume" : {
 				"enabled" : false
 			},
-			"version" : "2.5.2"
+			"version" : "2.5.3"
 		},
 		"storage" : {
 			"type" : "http",
@@ -182,7 +182,7 @@
 				"fsAccess" : false,
 				"headers" : {
 					"Connection" : "keep-alive",
-					"User-Agent" : "mongoose/2.5.2"
+					"User-Agent" : "mongoose/2.5.3"
 				},
 				"namespace" : null,
 				"versioning" : false