put timer into qnetsimengine and print the results to csv

matsim/pom.xml

@@ -307,6 +307,11 @@
 			<version>3.3.3</version>
 			<scope>test</scope>
 		</dependency>
+		<dependency>
+			<groupId>it.unimi.dsi</groupId>
+			<artifactId>fastutil</artifactId>
+			<version>8.5.8</version>
+		</dependency>
 	</dependencies>
 
 	<profiles>

matsim/src/main/java/org/matsim/core/mobsim/qsim/qnetsimengine/AbstractQNetsimEngine.java

@@ -174,7 +174,7 @@ public final void onPrepareSim() {
 
 
 	@Override
-	public final void afterSim() {
+	public void afterSim() {
 
 		/*
 		 * Calling the afterSim Method of the QSimEngineThreads

matsim/src/main/java/org/matsim/core/mobsim/qsim/qnetsimengine/AbstractQNetsimEngineRunner.java

@@ -38,6 +38,8 @@
  */
 abstract class AbstractQNetsimEngineRunner extends NetElementActivationRegistry {
 
+
+
 	private double time = 0.0;
 
 	/*
@@ -70,6 +72,17 @@ abstract class AbstractQNetsimEngineRunner extends NetElementActivationRegistry
 	private boolean lockNodes = false;
 	private boolean lockLinks = false;
 
+	private int nodeCounter = 0;
+	private int linkCounter = 0;
+
+	public int getNodeCounter() {
+		return nodeCounter;
+	}
+
+	public int getLinkCounter() {
+		return linkCounter;
+	}
+
 	/*package*/ long[] runTimes;
 	private long startTime = 0;
 	{	
@@ -80,16 +93,19 @@ abstract class AbstractQNetsimEngineRunner extends NetElementActivationRegistry
 	/*package*/ final void setTime(final double t) {
 		time = t;
 	}
+	final double getTime() { return time; }
 
 	public abstract void afterSim() ;
 
 	protected void moveNodes() {
 		boolean remainsActive;
 		this.lockNodes = true;
+		nodeCounter = 0;
 		QNodeI node;
 		Iterator<QNodeI> simNodes = this.nodesQueue.iterator();
 		while (simNodes.hasNext()) {
 			node = simNodes.next();
+			nodeCounter++;
 			remainsActive = node.doSimStep(time);
 			if (!remainsActive) simNodes.remove();
 		}
@@ -99,11 +115,12 @@ protected void moveNodes() {
 	protected final void moveLinks() {
 		boolean remainsActive;
 		lockLinks = true;
+		linkCounter = 0;
 		QLinkI link;
 		ListIterator<QLinkI> simLinks = this.linksList.listIterator();
 		while (simLinks.hasNext()) {
 			link = simLinks.next();
-
+			linkCounter++;
 			remainsActive = link.doSimStep();
 
 			if (!remainsActive) simLinks.remove();

matsim/src/main/java/org/matsim/core/mobsim/qsim/qnetsimengine/QNetsimEngineRunnerForThreadpool.java

@@ -34,8 +34,20 @@ final class QNetsimEngineRunnerForThreadpool extends AbstractQNetsimEngineRunner
 
 	private volatile boolean simulationRunning = true;
 	private boolean movingNodes;
+	private final Timing nodesTiming;
+	private final Timing linksTiming;
 
-	QNetsimEngineRunnerForThreadpool() {
+	public Timing getNodesTiming() {
+		return nodesTiming;
+	}
+
+	public Timing getLinksTiming() {
+		return linksTiming;
+	}
+
+	QNetsimEngineRunnerForThreadpool(String timingName) {
+		nodesTiming = new Timing(timingName + "_nodes");
+		linksTiming = new Timing(timingName + "_links");
 	}
 
 	@Override
@@ -46,9 +58,15 @@ public Boolean call() {
 		}
 
 		if (this.movingNodes) {
+			var startTime = System.nanoTime();
 			moveNodes();
+			var duration = System.nanoTime() - startTime;
+			nodesTiming.addDuration(duration / Math.max(1, getNodeCounter()));
 		} else {
+			var startTime = System.nanoTime();
 			moveLinks();
+			var duration = System.nanoTime() - startTime;
+			linksTiming.addDuration(duration / Math.max(1, getLinkCounter()));
 		}
 		return true ;
 	}

matsim/src/main/java/org/matsim/core/mobsim/qsim/qnetsimengine/QNetsimEngineWithThreadpool.java

@@ -20,16 +20,24 @@
 
 package org.matsim.core.mobsim.qsim.qnetsimengine;
 
+import java.io.IOException;
+import java.nio.file.Files;
+import java.nio.file.Paths;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 import java.util.concurrent.ThreadFactory;
+import java.util.stream.Collectors;
+import java.util.stream.Stream;
 
 import javax.inject.Inject;
 
+import it.unimi.dsi.fastutil.doubles.DoubleArrayList;
+import it.unimi.dsi.fastutil.doubles.DoubleList;
+import org.apache.commons.csv.CSVFormat;
 import org.matsim.core.mobsim.qsim.QSim;
 
 /**
@@ -46,6 +54,12 @@
 final class QNetsimEngineWithThreadpool extends AbstractQNetsimEngine<QNetsimEngineRunnerForThreadpool> {
 
 	private final int numOfRunners;
+	private final Timing overallTiming = new Timing( "NetsimeEngine_overall");
+	private final Timing nodesTiming = new Timing("NetsimeEngine_nodes");
+	private final Timing linksTiming = new Timing("NetsimeEngine_links");
+	private final DoubleList times = new DoubleArrayList();
+	private final String timingOutuputPath;
+	private final String runId;
 	private ExecutorService pool;
 
 	public QNetsimEngineWithThreadpool(final QSim sim) {
@@ -55,9 +69,51 @@ public QNetsimEngineWithThreadpool(final QSim sim) {
 	@Inject
 	public QNetsimEngineWithThreadpool(final QSim sim, QNetworkFactory netsimNetworkFactory) {
 		super(sim, netsimNetworkFactory);
+		timingOutuputPath = sim.getScenario().getConfig().controler().getOutputDirectory();
+		runId = sim.getScenario().getConfig().controler().getRunId();
 		this.numOfRunners = this.numOfThreads;
 	}
 
+	@Override
+	public void afterSim() {
+
+		var timings = this.getQnetsimEngineRunner().stream()
+				.flatMap(runner -> Stream.of(runner.getLinksTiming(), runner.getNodesTiming()))
+				.collect(Collectors.toList());
+
+		var ownTimings = List.of(overallTiming, nodesTiming, linksTiming);
+		timings.addAll(ownTimings);
+		var outputPath = Paths.get(timingOutuputPath).resolve(runId + "_timings.csv");
+
+		try (var writer = Files.newBufferedWriter(outputPath); var printer = CSVFormat.Builder.create().build().print(writer)) {
+
+			// print the header
+			printer.print("time");
+			for(var timing : timings) {
+				printer.print(timing.getName());
+			}
+			printer.println();
+
+			// now all the values
+			// assuming that all the timings have the same number of values
+			var firstTimingSize = timings.get(0).getDurations().size();
+			for(int i = 0; i < firstTimingSize; i++) {
+				// first the time step
+				printer.print(times.getDouble(i));
+				for (var timing : timings) {
+					var duration = timing.getDurations().getLong(i);
+					printer.print(duration);
+				}
+				printer.println();
+			}
+
+		} catch (IOException e) {
+			e.printStackTrace();
+		}
+
+		super.afterSim();
+	}
+
 	@Override
 	public void finishMultiThreading() {
 		this.pool.shutdown();
@@ -89,23 +145,45 @@ protected void run(double time) {
 		// as input for the domain decomposition under (b).
 
 		// set current Time
+		times.add(time);
 		for (AbstractQNetsimEngineRunner engine : this.getQnetsimEngineRunner()) {
 			engine.setTime(time);
 		}
 
 		try {
+			var overallStartTime = System.nanoTime();
 			for (AbstractQNetsimEngineRunner engine : this.getQnetsimEngineRunner()) {
 				((QNetsimEngineRunnerForThreadpool) engine).setMovingNodes(true);
 			}
+
+			var nodesStartTime = System.nanoTime();
 			for (Future<Boolean> future : pool.invokeAll(this.getQnetsimEngineRunner())) {
 				future.get();
+
 			}
+			var nodesDuration = System.nanoTime() - nodesStartTime;
+			int nodeCount = this.getQnetsimEngineRunner().stream()
+					.mapToInt(AbstractQNetsimEngineRunner::getNodeCounter)
+					.sum();
+			nodesTiming.addDuration(nodesDuration / Math.max(1, nodeCount));
+
 			for (AbstractQNetsimEngineRunner engine : this.getQnetsimEngineRunner()) {
 				((QNetsimEngineRunnerForThreadpool) engine).setMovingNodes(false);
 			}
+
+			var linksStartTime = System.nanoTime();
 			for (Future<Boolean> future : pool.invokeAll(this.getQnetsimEngineRunner())) {
 				future.get();
 			}
+			var afterLinksTime = System.nanoTime();
+			var linksDuration = afterLinksTime - linksStartTime;
+			var linkCount = this.getQnetsimEngineRunner().stream()
+					.mapToInt(AbstractQNetsimEngineRunner::getLinkCounter)
+					.sum();
+			linksTiming.addDuration(linksDuration / Math.max(1, linkCount));
+
+			var overallDuration = afterLinksTime - overallStartTime;
+			overallTiming.addDuration(overallDuration);
 		} catch (InterruptedException e) {
 			throw new RuntimeException(e) ;
 		} catch (ExecutionException e) {
@@ -126,7 +204,7 @@ public Thread newThread(Runnable r) {
 	protected List<QNetsimEngineRunnerForThreadpool> initQSimEngineRunners() {
 		List<QNetsimEngineRunnerForThreadpool> engines = new ArrayList<>();
 		for (int i = 0; i < numOfRunners; i++) {
-			QNetsimEngineRunnerForThreadpool engine = new QNetsimEngineRunnerForThreadpool();
+			QNetsimEngineRunnerForThreadpool engine = new QNetsimEngineRunnerForThreadpool("Runner_" + i);
 			engines.add(engine);
 		}
 		return engines;

matsim/src/main/java/org/matsim/core/mobsim/qsim/qnetsimengine/Timing.java

@@ -0,0 +1,30 @@
+package org.matsim.core.mobsim.qsim.qnetsimengine;
+
+import it.unimi.dsi.fastutil.doubles.DoubleList;
+import it.unimi.dsi.fastutil.longs.LongArrayList;
+import it.unimi.dsi.fastutil.longs.LongList;
+
+import java.util.ArrayList;
+import java.util.List;
+
+public class Timing {
+
+	private final String name;
+	private final LongList durations = new LongArrayList();
+
+	public Timing(String name) {
+		this.name = name;
+	}
+
+	void addDuration(long duration) {
+		durations.add(duration);
+	}
+
+	public String getName() {
+		return name;
+	}
+
+	public LongList getDurations() {
+		return this.durations;
+	}
+}