Skip to content

Commit d8b9b55

Browse files
bedaHovorkaclaude
bedaHovorka
and
claude
committed
Add comprehensive structured logging for railway simulation events
This commit implements enhanced logging across the simulation engine to improve observability and debugging of railway interlocking operations. Changes: - RailSwitch: Add INFO-level logging for switch position changes and path setup - SimpleTrack: Add INFO-level logging for block state transitions (RESERVE, ENTRY, EXIT, RELEASE) - SimpleTrack: Add WARN/ERROR logging for state conflicts and violations - InOutWorker: Add INFO-level logging for approval decisions (GRANTED/DENIED) - AbstractPath: Add INFO-level logging for path availability checks (PATH_NOT_FREE reasons) - Train: Add INFO-level logging for semaphore sensor detection events - Train: Add DEBUG-level logging for front/tail position tracking - logback.xml: Configure INFO-level logging for new loggers with file output The new logging provides structured events with consistent timestamp formatting and critical simulation state information, enabling better analysis of interlocking behavior and conflict detection. 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com>
1 parent 8b6567b commit d8b9b55

6 files changed

Lines changed: 109 additions & 13 deletions

File tree

‎src/main/java/cz/vutbr/fit/interlockSim/objects/cells/RailSwitch.java‎

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,9 @@
1515
import java.util.Set;
1616
import java.util.Map.Entry;
1717

18+
import org.slf4j.Logger;
19+
import org.slf4j.LoggerFactory;
20+
1821
import cz.vutbr.fit.interlockSim.sim.PathSeparatorChangeException;
1922
import cz.vutbr.fit.interlockSim.util.EnumUnorientedGraph;
2023

@@ -23,6 +26,8 @@
2326
* CZ: "výhybka"
2427
*/
2528
public class RailSwitch extends NodeCell {
29+
private static final Logger logger = LoggerFactory.getLogger(RailSwitch.class);
30+
2631
private enum Kind {
2732
/**
2833
* switch with one branch
@@ -223,7 +228,12 @@ protected void setConf(Conf conf) {
223228
*/
224229
public void changeConf() {
225230
assert conf != null;
231+
final Conf oldConf = conf;
226232
conf = conf==Conf.MAIN ? Conf.BRANCH : Conf.MAIN;
233+
if (logger.isInfoEnabled()) {
234+
logger.info("{} Switch {} position change: {} -> {}",
235+
jDisco.Process.time(), this.hashCode(), oldConf, conf);
236+
}
227237
}
228238

229239
public void cancelPathSetup(Segment from, Segment to) throws PathSeparatorChangeException {
@@ -264,7 +274,12 @@ public Set<Segment> getBranchSegments() {
264274
}
265275

266276
public void setUpPath(Segment from, Segment to, double allowedSpeed) throws PathSeparatorChangeException {
267-
setConf(getPathConfWithException(from, to));
277+
final Conf newConf = getPathConfWithException(from, to);
278+
if (logger.isInfoEnabled()) {
279+
logger.info("{} Switch {} path setup: from={} to={}, conf={}, allowedSpeed={}",
280+
jDisco.Process.time(), this.hashCode(), from, to, newConf, allowedSpeed);
281+
}
282+
setConf(newConf);
268283
}
269284

270285
private Conf getPathConfWithException(Segment from, Segment to) throws PathSeparatorChangeException {

‎src/main/java/cz/vutbr/fit/interlockSim/objects/paths/AbstractPath.java‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@
2727
import cz.vutbr.fit.interlockSim.objects.cells.RailSwitch;
2828
import cz.vutbr.fit.interlockSim.objects.cells.Cell.Segment;
2929
import cz.vutbr.fit.interlockSim.objects.tracks.AbstractTrack;
30+
import cz.vutbr.fit.interlockSim.objects.tracks.SimpleTrack;
3031
import cz.vutbr.fit.interlockSim.objects.tracks.Track;
3132
import cz.vutbr.fit.interlockSim.sim.PathSeparatorChangeException;
3233
import cz.vutbr.fit.interlockSim.sim.TrackOperationException;
@@ -170,6 +171,10 @@ private boolean pathIterating(PathSeparator sep) throws TrackOperationException
170171
final Track nextTrack = Util.assertInstanceOf(Track.class, iterator.next());
171172

172173
if (!separatorSetting(methodName, separator, previous, nextTrack)) {
174+
if (logger.isInfoEnabled() && IS_FREE_FROM.equals(methodName)) {
175+
logger.info("{} PATH_NOT_FREE: Separator {} prevents path - config cannot be set",
176+
jDisco.Process.time(), separator);
177+
}
173178
if (logger.isDebugEnabled()) {
174179
logger.debug("Separator setting failed for method: {}", methodName);
175180
}
@@ -178,6 +183,11 @@ private boolean pathIterating(PathSeparator sep) throws TrackOperationException
178183

179184
final Object invoke = method.invoke(nextTrack, new Object[]{separator});
180185
if (Boolean.FALSE.equals(invoke)) {
186+
if (logger.isInfoEnabled() && IS_FREE_FROM.equals(methodName)) {
187+
logger.info("{} PATH_NOT_FREE: Track {} prevents path - state={}",
188+
jDisco.Process.time(), nextTrack,
189+
nextTrack instanceof SimpleTrack ? ((SimpleTrack)nextTrack).getState() : "unknown");
190+
}
181191
if (logger.isDebugEnabled()) {
182192
logger.debug("Method invocation returned false for method: {}", methodName);
183193
}

‎src/main/java/cz/vutbr/fit/interlockSim/objects/tracks/SimpleTrack.java‎

Lines changed: 28 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -51,17 +51,25 @@ public SimpleTrack(PathSeparator end1, PathSeparator end2, double length, double
5151
}
5252

5353
public void enter(TrackOccupant occupant) {
54-
logger.debug("Track {} ENTER: occupant={}, state transition RESERVED->OCCUPIED at t={}",
55-
this, occupant, Process.time());
54+
if (logger.isInfoEnabled()) {
55+
logger.info("{} Block {} ENTRY: occupant={}, state={}->OCCUPIED",
56+
Process.time(), this, occupant, state);
57+
}
58+
if (in != null) {
59+
logger.error("{} CONFLICT: Block {} collision! Existing occupant={}, new occupant={}",
60+
Process.time(), this, in, occupant);
61+
}
5662
assert in == null; //tak to zavani srazkou (posuny neimplementovany)
5763
assertGoodStateChange(State.RESERVED, State.OCCUPIED);
5864
in = occupant;
5965
from = null;
6066
}
6167

6268
public void leave(TrackOccupant occupant) {
63-
logger.debug("Track {} LEAVE: occupant={}, state transition OCCUPIED->FREE at t={}",
64-
this, occupant, Process.time());
69+
if (logger.isInfoEnabled()) {
70+
logger.info("{} Block {} EXIT: occupant={}, state=OCCUPIED->FREE",
71+
Process.time(), this, occupant);
72+
}
6573
assert in == occupant;
6674
assertGoodStateChange(State.OCCUPIED, State.FREE);
6775
in = null;
@@ -76,8 +84,14 @@ public boolean isFreeFrom(PathSeparator seg) {
7684
}
7785

7886
public void setUpPath(PathSeparator sep) throws TrackOperationException {
79-
logger.debug("Track {} RESERVE: from={}, state transition FREE->RESERVED at t={}",
80-
this, sep, Process.time());
87+
if (logger.isInfoEnabled()) {
88+
logger.info("{} Block {} RESERVE: from={}, state=FREE->RESERVED",
89+
Process.time(), this, sep);
90+
}
91+
if (state != State.FREE) {
92+
logger.warn("{} CONFLICT: Block {} reservation rejected - state={}, occupant={}, requested by={}",
93+
Process.time(), this, state, in, sep);
94+
}
8195
exeptionStateChange(State.FREE, State.RESERVED);
8296
from = sep;
8397
}
@@ -98,8 +112,10 @@ public boolean isSetUpPath(PathSeparator sep) {
98112
}
99113

100114
public void cancelPathSetup(PathSeparator sep) throws TrackOperationException {
101-
logger.debug("Track {} CANCEL: from={}, state transition RESERVED->FREE at t={}",
102-
this, sep, Process.time());
115+
if (logger.isInfoEnabled()) {
116+
logger.info("{} Block {} RELEASE: from={}, state=RESERVED->FREE",
117+
Process.time(), this, sep);
118+
}
103119
exeptionStateChange(State.RESERVED, State.FREE);
104120
if (sep != from) throw new TrackOperationException("wrong end on cancel", this);
105121
from = null;
@@ -112,8 +128,11 @@ private boolean stateChange(State from, State to) {
112128
}
113129

114130
private void exeptionStateChange(State from, State to) throws TrackOperationException {
115-
if (!stateChange(from, to))
131+
if (!stateChange(from, to)) {
132+
logger.error("{} CONFLICT: Block {} state violation - expected={}, actual={}, attempted={}",
133+
Process.time(), this, from, state, to);
116134
throw new TrackOperationException(errorStateMessage(from), this);
135+
}
117136
}
118137

119138
private String errorStateMessage(State from) {

‎src/main/java/cz/vutbr/fit/interlockSim/sim/InOutWorker.java‎

Lines changed: 23 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -56,8 +56,22 @@ public boolean test() {
5656
//EXTENSION az bude Interlocking: co kdyz cesta vubec neexistuje
5757
path = context.pathToNextSemaphore(inOut, next);//EXTENSION lepe
5858
try {
59-
return path != null && path.isFreeFrom(inOut);
59+
final boolean pathExists = path != null;
60+
final boolean isFree = pathExists && path.isFreeFrom(inOut);
61+
62+
if (logger.isDebugEnabled()) {
63+
if (!pathExists) {
64+
logger.debug("{} APPROVAL_CHECK: InOut {} - path does not exist",
65+
jDisco.Process.time(), inOut.getName());
66+
} else if (!isFree) {
67+
logger.debug("{} APPROVAL_CHECK: InOut {} - path not free, length={}",
68+
jDisco.Process.time(), inOut.getName(), path.length());
69+
}
70+
}
71+
return isFree;
6072
} catch (TrackOperationException e) {
73+
logger.error("{} APPROVAL_ERROR: InOut {} - path check failed: {}",
74+
jDisco.Process.time(), inOut.getName(), e.getMessage());
6175
context.errorStop(e);
6276
return false;
6377
}
@@ -77,7 +91,15 @@ protected void iteration() {
7791
try {
7892
//zarezervovat koleje
7993
path.setUpPath(inOut);
94+
if (logger.isInfoEnabled()) {
95+
logger.info("{} APPROVAL_GRANTED: InOut {} - path reserved for {}, length={}",
96+
jDisco.Process.time(), inOut.getName(), first, path.length());
97+
}
8098
} catch (Exception e) {
99+
if (logger.isWarnEnabled()) {
100+
logger.warn("{} APPROVAL_DENIED: InOut {} - path setup failed for {}: {}",
101+
jDisco.Process.time(), inOut.getName(), first, e.getMessage());
102+
}
81103
logger.debug("InOutWorker {} path setup failed: {}", inOut.getName(), e.getMessage());
82104
context.errorStop(e);
83105
return;

‎src/main/java/cz/vutbr/fit/interlockSim/sim/Train.java‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -169,6 +169,12 @@ private class Front extends Site {
169169
private void semaphoreAction(final RailSemaphore semaphore, final PathSeparator separator, final TrackSection current, final TrackSection next) {
170170
assert context.isSeparatorInDirection((OrientedPathSeparator)separator, next, current) : semaphore;
171171
assert semaphore.getSignal() != null;
172+
if (logger.isInfoEnabled()) {
173+
logger.info("{} SENSOR: Train {} detected at semaphore {}, signal={}, velocity={} m/s",
174+
jDisco.Process.time(), number,
175+
semaphore.getName() != null ? semaphore.getName() : semaphore.hashCode(),
176+
semaphore.getSignal(), getVelocity());
177+
}
172178
final Path path = context.pathToNextSemaphore(separator, next);
173179

174180
// EXTENSION stanice
@@ -273,6 +279,10 @@ private void accelerateToSignal(final RailSemaphore semaphore, final Path path)
273279

274280
@Override
275281
public void separatorAction(PathSeparator where, TrackSection current, TrackSection next) {
282+
if (logger.isDebugEnabled()) {
283+
logger.debug("{} POSITION: Train {} front at separator {}, entering block {}, leaving block {}",
284+
jDisco.Process.time(), number, where, next, current);
285+
}
276286

277287
if (where instanceof RailSemaphore && context.isSeparatorInDirection((RailSemaphore) where, next, current)) {
278288
RailSemaphore semaphore = (RailSemaphore) where;
@@ -295,6 +305,10 @@ private class Tail extends Site {
295305
private boolean fromHome = false;
296306
@Override
297307
public void separatorAction(PathSeparator where, TrackSection current, TrackSection next) {
308+
if (logger.isDebugEnabled()) {
309+
logger.debug("{} POSITION: Train {} tail at separator {}, clearing block {}",
310+
jDisco.Process.time(), number, where, current);
311+
}
298312
if (where == timetable.getIn()) {
299313
fromHome = true;
300314
start();

‎src/main/resources/logback.xml‎

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,8 +30,24 @@
3030
<!-- Debug logging for train simulation -->
3131
<logger name="cz.vutbr.fit.interlockSim.sim.Train" level="DEBUG"/>
3232
<logger name="cz.vutbr.fit.interlockSim.sim.ShuntingLoop" level="DEBUG"/>
33-
<logger name="cz.vutbr.fit.interlockSim.objects.paths.AbstractPath" level="DEBUG"/>
34-
<logger name="cz.vutbr.fit.interlockSim.objects.tracks.SimpleTrack" level="DEBUG"/>
33+
34+
<!-- Enhanced logging for Priority 1: Switch State Logging -->
35+
<logger name="cz.vutbr.fit.interlockSim.objects.cells.RailSwitch" level="INFO">
36+
<appender-ref ref="FILE"/>
37+
</logger>
38+
39+
<!-- Enhanced logging for Priority 2: Block Transition Logging -->
40+
<logger name="cz.vutbr.fit.interlockSim.objects.tracks.SimpleTrack" level="INFO">
41+
<appender-ref ref="FILE"/>
42+
</logger>
43+
44+
<!-- Enhanced logging for Priority 5: Approval Decision Logging -->
45+
<logger name="cz.vutbr.fit.interlockSim.sim.InOutWorker" level="INFO">
46+
<appender-ref ref="FILE"/>
47+
</logger>
48+
<logger name="cz.vutbr.fit.interlockSim.objects.paths.AbstractPath" level="INFO">
49+
<appender-ref ref="FILE"/>
50+
</logger>
3551

3652
<!-- Root logger -->
3753
<root level="INFO">

0 commit comments

Comments
 (0)