Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Feature/add time sync logs #205

Merged
merged 9 commits into from
Mar 21, 2024
Merged

Feature/add time sync logs #205

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
ddd71e2
add time sync logs
MishkaMN Mar 19, 2024
fd21afb
reduce logs
MishkaMN Mar 20, 2024
10e9329
add log and enable debugging
MishkaMN Mar 21, 2024
27a485b
code smells
MishkaMN Mar 21, 2024
f8ef74e
refactor
MishkaMN Mar 21, 2024
21cb0dc
make sumo to debug
MishkaMN Mar 21, 2024
e6c9bfe
add explanation
MishkaMN Mar 21, 2024
f8cc7b1
code smell
MishkaMN Mar 21, 2024
8264517
rename variable and comments
MishkaMN Mar 21, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 14 additions & 0 deletions ...aic-sumo/src/main/java/org/eclipse/mosaic/fed/sumo/ambassador/AbstractSumoAmbassador.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -206,6 +206,12 @@ public abstract class AbstractSumoAmbassador extends AbstractFederateAmbassador
*/
protected boolean receivedSimulationStep = false;

/**
* received simulation step from carla
*
*/
protected boolean firstTimePrintingTime = true;

/**
* CARLA federate is enabled
*/
Expand Down Expand Up @@ -1193,6 +1199,13 @@ public synchronized void processTimeAdvanceGrant(long time) throws InternalFeder
return;
}

if (!receivedSimulationStep && firstTimePrintingTime)
{
long millis = System.currentTimeMillis();
log.info("Simulation Time: {} where current system time is: {} and nextTimeStep: {} and ambasador id: {}", (int) (time/1e6), millis, nextTimeStep, getId());
firstTimePrintingTime = false;
}

if (time > lastAdvanceTime) {
// actually add vehicles in sumo, before we reach the next advance time
flushNotYetAddedVehicles(lastAdvanceTime);
Expand Down Expand Up @@ -1229,6 +1242,7 @@ public synchronized void processTimeAdvanceGrant(long time) throws InternalFeder
rti.triggerInteraction(simulationStepResult.getTrafficDetectorUpdates());
this.rti.triggerInteraction(simulationStepResult.getTrafficLightUpdates());
receivedSimulationStep = false;
firstTimePrintingTime = true;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you need both of these variables. receivedSimulationStep should be !firstTimePrintingTime

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because they are meant for different cases.
receivedSimulationStep is flagged when carla returns with some handshake to sumoAmbassador. However, sumoAmbassador is called many times before that by MOSAIC.
firstTimePrintingTime is meant to track the first time ever sumoAmbassador is called to progressTime. And that is by design.
In other words, we can't reuse the same variable, because if we pick !receivedSimulationStep, the log will still end up printing many times in almost like 1ms apart. This firstTimePrintingTime is meant to avoid such excessive logging.

}

// System.out.println("Sumo request time advance at time: " + nextTimeStep);
Expand Down
18 changes: 18 additions & 0 deletions ...i/mosaic-rti-core/src/main/java/org/eclipse/mosaic/rti/time/SequentialTimeManagement.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,9 @@

package org.eclipse.mosaic.rti.time;

import java.util.HashMap;
import java.util.Map;

import org.eclipse.mosaic.rti.MosaicComponentParameters;
import org.eclipse.mosaic.rti.api.ComponentProvider;
import org.eclipse.mosaic.rti.api.FederateAmbassador;
Expand All @@ -31,6 +34,9 @@ public class SequentialTimeManagement extends AbstractTimeManagement {

private final int realtimeBrake;

// Debugging & Logging
HashMap<String, Long> logging_map = new HashMap<String, Long>();

/**
* Creates a new instance of the sequential time management.
*
Expand Down Expand Up @@ -87,6 +93,18 @@ public void runSimulation() throws InternalFederateException, IllegalValueExcept
if (ambassador != null) {
federation.getMonitor().onBeginActivity(event);
long startTime = System.currentTimeMillis();

if (!logging_map.containsKey(event.getFederateId())) // first time printing, then directly save the last simulation time requested and print
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should all be avoidable by setting log level to info. All this should be inside an if for log level debug or trace and we may want to leave a comment to consider reworking this. What you really want is just data about when each federate progresses in time. This is probably not a long term solution.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You could even just make this whole block a method that takes in event and start time.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Addressed

{
logging_map.put(event.getFederateId(), event.getRequestedTime());
this.logger.info("Simulation Time: {} where current system time is: {} and requested from id: {}", (int) (event.getRequestedTime()/1e6), startTime, event.getFederateId());
} // only print if last simulation time printed is different than new one
else if (logging_map.containsKey(event.getFederateId()) && logging_map.get(event.getFederateId()) != event.getRequestedTime())
{
logging_map.put(event.getFederateId(), event.getRequestedTime());
this.logger.info("Simulation Time: {} where current system time is: {} and requested from id: {}", (int) (event.getRequestedTime()/1e6), startTime, event.getFederateId());
}

ambassador.advanceTime(event.getRequestedTime());
federation.getMonitor().onEndActivity(event, System.currentTimeMillis() - startTime);

Expand Down
Loading