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.

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

Feature/add time sync logs #205

Merged
merged 9 commits into from
Mar 21, 2024

Conversation

MishkaMN
Copy link
Contributor

@MishkaMN MishkaMN commented Mar 19, 2024

PR Details

Description

Adds logs to support usdot-fhwa-stol/carma-analytics-fotda#43

Related GitHub Issue

Related Jira Key

CDAR-774

Motivation and Context

Data Analysis

How Has This Been Tested?

Types of changes

  • Defect fix (non-breaking change that fixes an issue)
  • New feature (non-breaking change that adds functionality)
  • Breaking change (fix or feature that cause existing functionality to change)

Checklist:

  • I have added any new packages to the sonar-scanner.properties file
  • My change requires a change to the documentation.
  • I have updated the documentation accordingly.
  • I have read the CONTRIBUTING document.
  • I have added tests to cover my changes.
  • All new and existing tests passed.

@MishkaMN MishkaMN changed the base branch from develop to release/lavida March 19, 2024 19:03
@@ -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.

@@ -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

Copy link
Contributor

@paulbourelly999 paulbourelly999 left a comment

Choose a reason for hiding this comment

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

See comments.

@paulbourelly999
Copy link
Contributor

Address code smells.

@MishkaMN
Copy link
Contributor Author

Confirmed that this works. I enabled DEBUG in logback.xml to get this:

2024-03-21 16:00:54,428 INFO  CarmaV2xMessageReceiver:78 - CarmaV2xMessageReceiver started listening on UDP port: 1517.
2024-03-21 16:00:54,429 INFO  CarmaV2xMessageReceiver:78 - CarmaV2xMessageReceiver started listening on UDP port: 1516.
2024-03-21 16:00:54,446 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036854446 and requested from id: mapping
2024-03-21 16:00:54,447 INFO  AbstractTimeManagement:231 - Simulating: 0ns (0.0s / 600.0s) - 0.0% (RTF:0.00, ETC:unknown)                        
2024-03-21 16:00:54,447 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036854447 and requested from id: sumo
2024-03-21 16:01:11,883 INFO  AbstractTimeManagement:231 - Simulating: 0ns (0.0s / 600.0s) - 0.0% (RTF:0.00, ETC:unknown)                        
2024-03-21 16:01:11,891 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036871891 and requested from id: ns3
2024-03-21 16:01:11,901 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036871901 and requested from id: carla
2024-03-21 16:01:12,383 INFO  AbstractTimeManagement:231 - Simulating: 0ns (0.0s / 600.0s) - 0.0% (RTF:0.00, ETC:unknown)                        
2024-03-21 16:01:12,883 INFO  AbstractTimeManagement:231 - Simulating: 0ns (0.0s / 600.0s) - 0.0% (RTF:0.00, ETC:unknown)                        
2024-03-21 16:01:13,383 INFO  AbstractTimeManagement:231 - Simulating: 0ns (0.0s / 600.0s) - 0.0% (RTF:0.00, ETC:unknown)                        
2024-03-21 16:01:13,666 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036873666 and requested from id: carma
2024-03-21 16:01:13,722 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036873722 and requested from id: infrastructure
2024-03-21 16:01:13,722 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036873722 and requested from id: application
2024-03-21 16:01:13,723 DEBUG SequentialTimeManagement:103 - Simulation Time: 0 where current system time is: 1711036873723 and requested from id: ns3
2024-03-21 16:01:13,723 DEBUG SequentialTimeManagement:103 - Simulation Time: 1 where current system time is: 1711036873723 and requested from id: ns3
2024-03-21 16:01:13,724 DEBUG SequentialTimeManagement:103 - Simulation Time: 1 where current system time is: 1711036873724 and requested from id: ns3
2024-03-21 16:01:13,724 DEBUG SequentialTimeManagement:103 - Simulation Time: 2 where current system time is: 1711036873724 and requested from id: ns3
2024-03-21 16:01:13,724 DEBUG SequentialTimeManagement:103 - Simulation Time: 2 where current system time is: 1711036873724 and requested from id: ns3
2024-03-21 16:01:13,724 DEBUG SequentialTimeManagement:103 - Simulation Time: 3 where current system time is: 1711036873724 and requested from id: ns3
2024-03-21 16:01:13,725 DEBUG SequentialTimeManagement:103 - Simulation Time: 3 where current system time is: 1711036873725 and requested from id: ns3
2024-03-21 16:01:13,725 DEBUG SequentialTimeManagement:103 - Simulation Time: 4 where current system time is: 1711036873725 and requested from id: ns3
2024-03-21 16:01:13,725 DEBUG SequentialTimeManagement:103 - Simulation Time: 4 where current system time is: 1711036873725 and requested from id: ns3

Copy link

sonarcloud bot commented Mar 21, 2024

Quality Gate Failed Quality Gate failed

Failed conditions
78.57% Line Coverage on New Code (required ≥ 80%)

See analysis details on SonarCloud

@paulbourelly999 paulbourelly999 merged commit 233aaa8 into release/lavida Mar 21, 2024
2 of 3 checks passed
@paulbourelly999 paulbourelly999 deleted the feature/add-time-sync-logs branch March 21, 2024 17:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants