Skip to main content
summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorAndrew M. Finkbeiner2017-05-21 10:18:17 -0400
committerAndrew M. Finkbeiner2017-06-01 17:09:00 -0400
commitd3ffba84542110ce3f193f19470d24c05ad580c7 (patch)
tree9d731968674e5d3c92dc8af622490a5d5eddb649
parent4fb9ea85f786d747ba8344a84e5437f2b64872a5 (diff)
downloadorg.eclipse.osee-ote_0.23.2.tar.gz
org.eclipse.osee-ote_0.23.2.tar.xz
org.eclipse.osee-ote_0.23.2.zip
feature[ats_ATS377052]: Add message send/receive timing infrastructureote_0.23.2
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/Message.java13
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageListenerTrace.java214
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendPeriodTrace.java165
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendTrace.java161
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeEvent.java20
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeTrace.java60
-rw-r--r--plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/listener/MessageSystemListener.java62
7 files changed, 661 insertions, 34 deletions
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/Message.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/Message.java
index 82249a11ef..ed68c72e53 100644
--- a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/Message.java
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/Message.java
@@ -697,6 +697,19 @@ public abstract class Message<S extends ITestEnvironmentMessageSystemAccessor, T
public MessageSystemListener getRemoveableListener() {
return removableListenerHandler;
}
+
+ public void setListenerTrace(MessageListenerTrace listener) {
+ if(listenerHandler != null){
+ listenerHandler.setMessageListenerTrace(this, listener);
+ }
+ }
+
+ public MessageListenerTrace clearListenerTrace() {
+ if(listenerHandler != null){
+ return listenerHandler.clearListenerTrace(this);
+ }
+ return null;
+ }
public void addListener(IOSEEMessageListener listener) {
listenerHandler.addListener(listener);
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageListenerTrace.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageListenerTrace.java
new file mode 100644
index 0000000000..e426b63c40
--- /dev/null
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageListenerTrace.java
@@ -0,0 +1,214 @@
+package org.eclipse.osee.ote.message;
+
+import java.util.List;
+import java.util.concurrent.TimeUnit;
+
+import org.eclipse.osee.ote.core.environment.interfaces.ITestLogger;
+import org.eclipse.osee.ote.core.log.TestLevel;
+import org.eclipse.osee.ote.message.listener.IOSEEMessageListener;
+
+/**
+ * This class will time the listeners of a message. Only one can be set on a message at a time.
+ *
+ * <pre>
+ * {@code
+ * MessageListenerTrace trace = new MessageListenerTrace(TimeUnit.NANOSECONDS, testMessage, logger);
+ * trace.start();
+ * //wait or do stuff
+ * trace.stop();
+ * trace.printResults();
+ * }
+ * </pre>
+ * @author Andrew M. Finkbeiner
+ *
+ */
+public class MessageListenerTrace extends TimeTrace {
+
+ @SuppressWarnings("rawtypes")
+ private Message message;
+ private TimeUnit timeUnit;
+ private ITestLogger logger = null;
+ private int maxAllListenerTime = Integer.MAX_VALUE;
+ private int maxListenerTime = Integer.MAX_VALUE;
+
+ /**
+ *
+ * @param timeUnit - determines the resolution of the timing that is measured.
+ * @param message - the message to measure
+ */
+ @SuppressWarnings("rawtypes")
+ public MessageListenerTrace(TimeUnit timeUnit, Message message) {
+ super(String.format("MessageListenerTrace[%s]", message.getName()));
+ this.message = message;
+ this.timeUnit = timeUnit;
+ }
+
+ /**
+ *
+ * @param timeUnit - determines the resolution of the timing that is measured.
+ * @param message - the message to measure
+ * @param logger - output will be written to a logger if the value is not null
+ */
+ @SuppressWarnings("rawtypes")
+ public MessageListenerTrace(TimeUnit timeUnit, Message message, ITestLogger logger) {
+ this(timeUnit, message);
+ this.logger = logger;
+ }
+
+ public void setMaxAllListeners(int time){
+ maxAllListenerTime = time;
+ }
+
+ public void setMaxListeners(int time){
+ maxListenerTime = time;
+ }
+
+ @Override
+ public void start(){
+ super.start();
+ message.setListenerTrace(this);
+ }
+
+ @Override
+ public void stop(){
+ super.stop();
+ message.clearListenerTrace();
+ }
+
+ public void printResults(){
+ List<TimeEvent> events = get();
+ int allCount = 0;
+ int allexceedanceCount = 0;
+ double allaverage = 0.0;
+ double allmax = -1.0;
+ double allmin = -1.0;
+
+ int count = 0;
+ int exceedanceCount = 0;
+ double average = 0.0;
+ double max = -1.0;
+ double min = -1.0;
+
+ ListenerEvent preNotify = null;
+ ListenerEvent postNotify = null;
+ ListenerEvent preListener = null;
+ ListenerEvent postListener = null;
+
+ for(TimeEvent event:events){
+ if(event instanceof ListenerEvent){
+ ListenerEvent sendEvent = (ListenerEvent)event;
+ if(sendEvent.type == ListenerEventType.startNotify){
+ preNotify = sendEvent;
+ } else if (sendEvent.type == ListenerEventType.endNotify) {
+ postNotify = sendEvent;
+ } else if (sendEvent.type == ListenerEventType.startListener){
+ preListener = sendEvent;
+ } else if (sendEvent.type == ListenerEventType.endListener){
+ postListener = sendEvent;
+ }
+ }
+ if(preNotify != null && postNotify != null){
+ long nanoDiff = postNotify.getNanoTime() - preNotify.getNanoTime();
+ preNotify = null;
+ postNotify = null;
+ allCount++;
+ long currentTime = timeUnit.convert(nanoDiff, TimeUnit.NANOSECONDS);
+
+ if(currentTime >= 0){
+ if(allmax < 0 || currentTime > allmax){
+ allmax = currentTime;
+ }
+ if(allmin < 0 || currentTime < allmin){
+ allmin = currentTime;
+ }
+ if(currentTime > maxAllListenerTime){
+ allexceedanceCount++;
+ String maxMessage = String.format("%s: count[%d] %d [%d (count)] [%s]", getName(), allCount, currentTime, allexceedanceCount, timeUnit.name());
+ System.out.println(maxMessage);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, maxMessage, null);
+ }
+ }
+ allaverage = (((allCount-1) * allaverage) + currentTime)/allCount;
+ }
+ }
+
+ if(preListener != null && postListener != null && preListener.listener == postListener.listener){
+ long nanoDiff = postListener.getNanoTime() - preListener.getNanoTime();
+ String listenerLabel = preListener.listener.getClass().getName();
+ preListener = null;
+ postListener = null;
+ count++;
+ long currentTime = timeUnit.convert(nanoDiff, TimeUnit.NANOSECONDS);
+
+ if(currentTime >= 0){
+ if(max < 0 || currentTime > max){
+ max = currentTime;
+ }
+ if(min < 0 || currentTime < min){
+ min = currentTime;
+ }
+ if(currentTime > maxListenerTime){
+ exceedanceCount++;
+ String maxMessage = String.format("%s: %s: count[%d] %d [%d (count)] [%s]", getName(), listenerLabel, count, currentTime, exceedanceCount, timeUnit.name());
+ System.out.println(maxMessage);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, maxMessage, null);
+ }
+ }
+ average = (((count-1) * average) + currentTime)/count;
+ }
+ }
+ }
+ String summaryMessage = String.format("%s: ALL count[%d] avg[%f] min[%f] max[%f] units[%s] { exceedanceCount [%d] (%d) }", getName(), allCount, allaverage, allmin, allmax, timeUnit.name(), allexceedanceCount, maxAllListenerTime);
+ String summaryMessage2 = String.format("%s: Listeners count[%d] avg[%f] min[%f] max[%f] units[%s] { exceedanceCount [%d] (%d) }", getName(), count, average, min, max, timeUnit.name(), exceedanceCount, maxListenerTime);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, summaryMessage, null);
+ logger.log(TestLevel.ATTENTION, summaryMessage2, null);
+ }
+ System.out.println(summaryMessage);
+ System.out.println(summaryMessage2);
+ }
+
+ public void addStartNotify() {
+ add(new ListenerEvent(ListenerEventType.startNotify));
+ }
+
+ public void addEndNotify() {
+ add(new ListenerEvent(ListenerEventType.endNotify));
+ }
+
+ public void addStartListener(IOSEEMessageListener listener) {
+ add(new ListenerEvent(ListenerEventType.startListener, listener));
+ }
+
+ public void addEndListener(IOSEEMessageListener listener) {
+ add(new ListenerEvent(ListenerEventType.endListener, listener));
+ }
+
+ private static class ListenerEvent extends TimeEvent {
+
+ public final ListenerEventType type;
+ public IOSEEMessageListener listener;
+
+ public ListenerEvent(ListenerEventType type) {
+ super(type.name());
+ this.type = type;
+ }
+
+ public ListenerEvent(ListenerEventType type, IOSEEMessageListener listener) {
+ this(type);
+ this.listener = listener;
+ }
+
+ }
+
+ private enum ListenerEventType {
+ startNotify,
+ endNotify,
+ startListener,
+ endListener
+ }
+
+
+}
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendPeriodTrace.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendPeriodTrace.java
new file mode 100644
index 0000000000..953e7f1aed
--- /dev/null
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendPeriodTrace.java
@@ -0,0 +1,165 @@
+package org.eclipse.osee.ote.message;
+
+import java.util.List;
+import java.util.concurrent.TimeUnit;
+
+import org.eclipse.osee.ote.core.environment.interfaces.ITestLogger;
+import org.eclipse.osee.ote.core.log.TestLevel;
+import org.eclipse.osee.ote.message.data.MessageData;
+
+/**
+ * This class will measure the time between sends.
+ * <pre>
+ * {@code
+ * MessageSendPeriodTrace trace = new MessageSendPeriodTrace(TimeUnit.NANOSECONDS, testMessage, logger);
+ * trace.start();
+ * //wait or do stuff
+ * trace.stop();
+ * trace.printResults();
+ * }
+ * </pre>
+ * @author Andrew M. Finkbeiner
+ *
+ */
+public class MessageSendPeriodTrace extends TimeTrace {
+
+ private SendTimer sendTimer;
+ @SuppressWarnings("rawtypes")
+ private Message message;
+ private int maxFlag = Integer.MAX_VALUE;
+ private ITestLogger logger = null;
+ private TimeUnit timeUnit;
+ private int minError = Integer.MIN_VALUE;
+ private int maxError = Integer.MAX_VALUE;
+
+ /**
+ * This version of the constructor will log results to the outfile.
+ *
+ * @param message
+ * @param logger
+ */
+ @SuppressWarnings("rawtypes")
+ public MessageSendPeriodTrace(TimeUnit timeUnit, Message message, ITestLogger logger) {
+ this(timeUnit, message);
+ this.logger = logger;
+ }
+
+ @SuppressWarnings("rawtypes")
+ public MessageSendPeriodTrace(TimeUnit timeUnit, Message message) {
+ super(String.format("MessageSendPeriodTrace[%s]", message.getMessageName()));
+ this.timeUnit = timeUnit;
+ this.message = message;
+ sendTimer = new SendTimer(this);
+ }
+
+ /**
+ *
+ * @param expected the expected period in the constructed TimeUnit
+ * @param maxError the max variance off of the period in the constructed TimeUnit
+ */
+ public void setMaxVariance(int expected, int maxError){
+ this.minError = expected - maxError;
+ this.maxError = expected + maxError;
+ }
+
+ public void addStartEvent(String message){
+ add(new TimeEvent(message));
+ }
+
+
+ @Override
+ public void start(){
+ super.start();
+ message.getDefaultMessageData().addSendListener(sendTimer);
+ }
+
+ @Override
+ public void stop(){
+ super.stop();
+ message.getDefaultMessageData().removeSendListener(sendTimer);
+ }
+
+ public void printResults(){
+ List<TimeEvent> events = get();
+ int count = 0;
+ int exceedanceCount = 0;
+ double average = 0.0;
+ double max = -1.0;
+ double min = -1.0;
+
+ SendEvent pre1 = null;
+ SendEvent pre2 = null;
+ for(TimeEvent event:events){
+ if(event instanceof SendEvent){
+ SendEvent sendEvent = (SendEvent)event;
+ if(sendEvent.type == SendEventType.pre){
+ pre1 = pre2;
+ pre2 = sendEvent;
+ }
+ }
+ if(pre1 != null && pre2 != null){
+ long nanoDiff = pre2.getNanoTime() - pre1.getNanoTime();
+ count++;
+ long currentTime = timeUnit.convert(nanoDiff, TimeUnit.NANOSECONDS);
+
+ if(currentTime >= 0){
+ if(max < 0 || currentTime > max){
+ max = currentTime;
+ }
+ if(min < 0 || currentTime < min){
+ min = currentTime;
+ }
+ if(currentTime > maxError || currentTime < minError){
+ exceedanceCount++;
+ String maxMessage = String.format("%s: count[%d] %d [%d (count)] [%s]", getName(), count, currentTime, exceedanceCount, timeUnit.name());
+ System.out.println(maxMessage);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, maxMessage, null);
+ }
+ }
+ average = (((count-1) * average) + currentTime)/count;
+ }
+ }
+ }
+ String summaryMessage = String.format("%s: count[%d] avg[%f] min[%f] max[%f] units[%s] { exceedanceCount [%d] (%d) }", getName(), count, average, min, max, timeUnit.name(), exceedanceCount, maxFlag);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, summaryMessage, null);
+ }
+ System.out.println(summaryMessage);
+ }
+
+ private static class SendTimer implements IMessageSendListener {
+
+ private MessageSendPeriodTrace messageSendOperator;
+
+ public SendTimer(MessageSendPeriodTrace messageSendOperator) {
+ this.messageSendOperator = messageSendOperator;
+ }
+
+ @Override
+ public void onPreSend(MessageData messageData) {
+ messageSendOperator.add(new SendEvent(SendEventType.pre));
+ }
+
+ @Override
+ public void onPostSend(MessageData messageData) {
+ }
+
+ }
+
+ private static class SendEvent extends TimeEvent {
+
+ public final SendEventType type;
+
+ public SendEvent(SendEventType type) {
+ super(type.name());
+ this.type = type;
+ }
+
+ }
+
+ private enum SendEventType {
+ pre
+ }
+
+}
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendTrace.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendTrace.java
new file mode 100644
index 0000000000..aaff766511
--- /dev/null
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/MessageSendTrace.java
@@ -0,0 +1,161 @@
+package org.eclipse.osee.ote.message;
+
+import java.util.List;
+import java.util.concurrent.TimeUnit;
+
+import org.eclipse.osee.ote.core.environment.interfaces.ITestLogger;
+import org.eclipse.osee.ote.core.log.TestLevel;
+import org.eclipse.osee.ote.message.data.MessageData;
+
+/**
+ * This class will time the send call of a message. From just after you call send to after socket.send() has been called.
+ *
+ * The results will be written to System.out or System.out and the Outfile, depending on which constructor you use.
+ *
+ * @author Andrew M. Finkbeiner
+ *
+ */
+public class MessageSendTrace extends TimeTrace {
+
+ private SendTimer sendTimer;
+ @SuppressWarnings("rawtypes")
+ private Message message;
+ private int maxFlag = Integer.MAX_VALUE;
+ private ITestLogger logger = null;
+ private TimeUnit timeUnit;
+
+ /**
+ * This version of the constructor will log results to the outfile.
+ *
+ * @param message
+ * @param logger
+ */
+ @SuppressWarnings("rawtypes")
+ public MessageSendTrace(TimeUnit timeUnit, Message message, ITestLogger logger) {
+ this(timeUnit, message);
+ this.logger = logger;
+ }
+
+ @SuppressWarnings("rawtypes")
+ public MessageSendTrace(TimeUnit timeUnit, Message message) {
+ super(String.format("MessageSendTrace[%s]", message.getMessageName()));
+ this.timeUnit = timeUnit;
+ this.message = message;
+ sendTimer = new SendTimer(this);
+ }
+
+ /**
+ * Set the time that you want to flag for exceeding the expected time. It is in the scale of the passed in TimeUnit.
+ *
+ * @param maxFlagNS
+ */
+ public void setMaxFlag(int maxFlag){
+ this.maxFlag = maxFlag;
+ }
+
+ public void addStartEvent(String message){
+ add(new TimeEvent(message));
+ }
+
+
+ @Override
+ public void start(){
+ super.start();
+ message.getDefaultMessageData().addSendListener(sendTimer);
+ }
+
+ @Override
+ public void stop(){
+ super.stop();
+ message.getDefaultMessageData().removeSendListener(sendTimer);
+ }
+
+ public void printResults(){
+ List<TimeEvent> events = get();
+ int count = 0;
+ int exceedanceCount = 0;
+ double average = 0.0;
+ double max = -1.0;
+ double min = -1.0;
+
+ SendEvent pre = null;
+ SendEvent post = null;
+ for(TimeEvent event:events){
+ if(event instanceof SendEvent){
+ SendEvent sendEvent = (SendEvent)event;
+ if(sendEvent.type == SendEventType.pre){
+ pre = sendEvent;
+ } else {
+ post = sendEvent;
+ }
+ }
+ if(pre != null && post != null){
+ long nanoDiff = post.getNanoTime() - pre.getNanoTime();
+ pre = null;
+ post = null;
+ count++;
+ long currentTime = timeUnit.convert(nanoDiff, TimeUnit.NANOSECONDS);
+
+ if(currentTime >= 0){
+ if(max < 0 || currentTime > max){
+ max = currentTime;
+ }
+ if(min < 0 || currentTime < min){
+ min = currentTime;
+ }
+ if(currentTime > maxFlag){
+ exceedanceCount++;
+ String maxMessage = String.format("%s: count[%d] %d [%d (count)] [%s]", getName(), count, currentTime, exceedanceCount, timeUnit.name());
+ System.out.println(maxMessage);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, maxMessage, null);
+ }
+ }
+ average = (((count-1) * average) + currentTime)/count;
+ }
+ }
+ }
+ String summaryMessage = String.format("%s: count[%d] avg[%f] min[%f] max[%f] units[%s] { exceedanceCount [%d] (%d) }", getName(), count, average, min, max, timeUnit.name(), exceedanceCount, maxFlag);
+ if(logger != null){
+ logger.log(TestLevel.ATTENTION, summaryMessage, null);
+ }
+ System.out.println(summaryMessage);
+ }
+
+ private static class SendTimer implements IMessageSendListener {
+
+ private MessageSendTrace messageSendOperator;
+
+ public SendTimer(MessageSendTrace messageSendOperator) {
+ this.messageSendOperator = messageSendOperator;
+ }
+
+ @Override
+ public void onPreSend(MessageData messageData) {
+ messageSendOperator.add(new SendEvent(SendEventType.pre));
+ }
+
+ @Override
+ public void onPostSend(MessageData messageData) {
+ messageSendOperator.add(new SendEvent(SendEventType.post));
+ }
+
+ }
+
+ private static class SendEvent extends TimeEvent {
+
+ public final SendEventType type;
+
+ public SendEvent(SendEventType type) {
+ super(type.name());
+ this.type = type;
+ }
+
+ }
+
+ private enum SendEventType {
+ pre,
+ post
+ }
+
+}
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeEvent.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeEvent.java
new file mode 100644
index 0000000000..1a7c12131b
--- /dev/null
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeEvent.java
@@ -0,0 +1,20 @@
+package org.eclipse.osee.ote.message;
+
+public class TimeEvent {
+
+ private long nanoTime;
+ private String lable;
+
+ public TimeEvent(String label) {
+ this.lable = label;
+ nanoTime = System.nanoTime();
+ }
+
+ public long getNanoTime(){
+ return nanoTime;
+ }
+
+ public void print() {
+ System.out.printf("%s %d", lable, nanoTime);
+ }
+}
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeTrace.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeTrace.java
new file mode 100644
index 0000000000..3678918aa8
--- /dev/null
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/TimeTrace.java
@@ -0,0 +1,60 @@
+package org.eclipse.osee.ote.message;
+
+import java.util.ArrayList;
+import java.util.List;
+
+/**
+ * This is a class that has the base functionality to keep a list of {@link TimeEvent} objects. This way
+ * we can post process the events to determine timing of a trace of functionality.
+ *
+ * @author Andrew M. Finkbeiner
+ *
+ */
+public class TimeTrace {
+
+ private String name;
+ private List<TimeEvent> events;
+ private volatile boolean isRunning;
+
+ public TimeTrace(String name){
+ this.name = name;
+ events = new ArrayList<>();
+ }
+
+ public void stop() {
+ isRunning = false;
+ }
+
+ public void start(){
+ isRunning = true;
+ }
+
+ public synchronized void add(TimeEvent event){
+ if(isRunning){
+ events.add(event);
+ }
+ }
+
+ public List<TimeEvent> get(){
+ return events;
+ }
+
+ public synchronized void printResults(){
+ System.out.println(">>>>>>>>>>>>>>>>>>>>-----------------");
+ System.out.println(name);
+ System.out.println("-----------------");
+ for(int i = 0; i < events.size(); i++){
+ events.get(i).print();
+ System.out.println();
+ }
+ System.out.println("<<<<<<<<<<<<<<<<<<<<-----------------");
+ }
+
+ public synchronized void clear(){
+ events.clear();
+ }
+
+ public String getName(){
+ return name;
+ }
+}
diff --git a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/listener/MessageSystemListener.java b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/listener/MessageSystemListener.java
index de3cb97620..9a23b5fbe9 100644
--- a/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/listener/MessageSystemListener.java
+++ b/plugins/org.eclipse.osee.ote.core/src/org/eclipse/osee/ote/message/listener/MessageSystemListener.java
@@ -24,7 +24,9 @@ import org.eclipse.osee.ote.core.environment.interfaces.ICancelTimer;
import org.eclipse.osee.ote.core.environment.interfaces.ITestEnvironmentAccessor;
import org.eclipse.osee.ote.core.environment.interfaces.ITimeout;
import org.eclipse.osee.ote.message.Message;
+import org.eclipse.osee.ote.message.MessageListenerTrace;
import org.eclipse.osee.ote.message.MessageSystemException;
+import org.eclipse.osee.ote.message.TimeTrace;
import org.eclipse.osee.ote.message.condition.ICondition;
import org.eclipse.osee.ote.message.data.MessageData;
import org.eclipse.osee.ote.message.elements.MsgWaitResult;
@@ -39,24 +41,12 @@ import org.eclipse.osee.ote.properties.OtePropertiesCore;
*/
public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEMessageWriterListener, ITimeout {
- private static long debugTimeout = OtePropertiesCore.timeDebugTimeout.getLongValue();
- private static boolean debugTime = OtePropertiesCore.timeDebug.getBooleanValue();
-
-
private volatile boolean isTimedOut = false;
private int masterMessageCount = 0;
- // private final Message message;
private final WeakReference<Message> message;
- private static final Benchmark tbm = new Benchmark("Total Message System Listener", 2500);
-
-
private int messageCount = 0;
- // public static enum SPEED {
- //// FAST, SLOW
- // };
-
/**
* A thread pool for handling slow listeners. We start the pool with 5 threads, which should in most cases be more
* than enough threads to handle the listeners. Because the queue is static, it will be shared by all
@@ -75,6 +65,7 @@ public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEM
private final CopyOnWriteNoIteratorList<IOSEEMessageListener> fastListeners = new CopyOnWriteNoIteratorList<>(IOSEEMessageListener.class);
private final CopyOnWriteNoIteratorList<IOSEEMessageListener> slowListeners = new CopyOnWriteNoIteratorList<>(IOSEEMessageListener.class);
private volatile boolean disposed = false;
+ private MessageListenerTrace timeTrace;
/**
* This class takes in a message in the constructor so that it can tell the message to update when it recieves new
@@ -219,7 +210,10 @@ public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEM
@Override
public synchronized void onDataAvailable(final MessageData data, DataType type) throws MessageSystemException {
if(disposed) return;
- tbm.startSample();
+ boolean isTimeTrace = timeTrace != null;
+ if(isTimeTrace){
+ timeTrace.addStartNotify();
+ }
if (message.get().getMemType() == type) {
messageCount++;
masterMessageCount++;
@@ -230,37 +224,29 @@ public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEM
IOSEEMessageListener[] ref = fastListeners.get();
for (int i = 0; i < ref.length; i++) {
IOSEEMessageListener listener = ref[i];
-// for (IOSEEMessageListener listener : fastListeners) {
- if(debugTime){
- start = System.nanoTime();
+ if(isTimeTrace){
+ timeTrace.addStartListener(listener);
}
listener.onDataAvailable(data, type);
- if(debugTime){
- elapsed = System.nanoTime() - start;
- if(elapsed > debugTimeout){
- Locale.setDefault(Locale.US);
- System.out.printf("%s %s SLOW %,d\n", message.get().getName(), listener.getClass().getName(), elapsed);
- }
+ if(isTimeTrace){
+ timeTrace.addEndListener(listener);
}
}
ref = slowListeners.get();
for (int i = 0; i < ref.length; i++){
IOSEEMessageListener listener = ref[i];
-// for (IOSEEMessageListener listener : slowListeners) {
- if(debugTime){
- start = System.nanoTime();
+ if(isTimeTrace){
+ timeTrace.addStartListener(listener);
}
threadPool.execute(new SlowListenerNotifier(listener, data, type, false));
- if(debugTime){
- elapsed = System.nanoTime() - start;
- if(elapsed > debugTimeout){
- Locale.setDefault(Locale.US);
- System.out.printf("%s %s SLOW TO SUBMIT SLOW %,d\n", message.get().getName(), listener.getClass().getName(), elapsed);
- }
+ if(isTimeTrace){
+ timeTrace.addEndListener(listener);
}
}
- tbm.endSample();
+ if(isTimeTrace){
+ timeTrace.addEndNotify();
+ }
}
@Override
@@ -269,14 +255,12 @@ public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEM
IOSEEMessageListener[] ref = fastListeners.get();
for (int i = 0; i < ref.length; i++) {
IOSEEMessageListener listener = ref[i];
-// for (IOSEEMessageListener listener : fastListeners) {
listener.onInitListener();
}
ref = slowListeners.get();
for (int i = 0; i < ref.length; i++){
IOSEEMessageListener listener = ref[i];
-// for (IOSEEMessageListener listener : slowListeners) {
threadPool.execute(new SlowListenerNotifier(listener, null, null, true));
}
}
@@ -336,4 +320,14 @@ public class MessageSystemListener implements IOSEEMessageReaderListener, IOSEEM
this.fastListeners.clear();
this.slowListeners.clear();
}
+
+ public synchronized void setMessageListenerTrace(Message message, MessageListenerTrace timeTrace) {
+ this.timeTrace = timeTrace;
+ }
+
+ public synchronized MessageListenerTrace clearListenerTrace(Message message) {
+ MessageListenerTrace trace = this.timeTrace;
+ this.timeTrace = null;
+ return trace;
+ }
}

Back to the top