[roeter]

There is nothing in the log-file which immediately and clearly points to this problem.
There are, however, some items which I would suggest to have a look at : for instance, the simple typing error in the sigscr.dat file (SSIGASP) can cause some signals to show incorrect aspects.

Regards,
Rob Roeterdink

[disc]

That's fixed already.

[disc]

The random KeyNotFoundExceptions usually happen when i just start to accelerate after a station stop, and happens only if i drive the train. With AI trains only the "fixed" KeyNotFoundExceptions happen.
These random exceptions happen more frequently with the old signal system, and less frequent with the new signal system under development.

[disc]

Any new possibilities to find what is causing these errors?

[roeter]

A major problem here is that I still have not been able to reproduce this error. And without that, there is no way of finding out what is going wrong. All that suggests that it must some something very particular - and not very obvious - in the train or path definitions which is causing the problem.

I read in a bug report - on a different subject, actually - that someone running a timetable on Surfliner2 did have this problem. I don't remember which bug this was, though.
I have that route, so if that someone can contact me than perhaps I can finally create a situation where I can reproduce this error and find out what is going on.

Regards,
Rob Roeterdink

[gpz]

I can also reliably reproduce this error on our Alföld 6.5 route. The relevant part of the log is

Error: System.Collections.Generic.KeyNotFoundException: A megadott kulcs nem szerepel a szótárban.
   a következő helyen: System.ThrowHelper.ThrowKeyNotFoundException()
   a következő helyen: System.Collections.Generic.Dictionary`2.get_Item(TKey key)
   a következő helyen: ORTS.DeadlockInfo.GetEndSection(Train thisTrain) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 12227
   a következő helyen: ORTS.DeadlockInfo.CheckDeadlockPathAvailability(TrackCircuitSection startSection, Train thisTrain) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 11740
   a következő helyen: ORTS.SignalObject.getBlockState_locationBased(TCSubpathRoute thisRoute, TrainRouted thisTrain) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 9737
   a következő helyen: ORTS.SignalObject.getBlockState(TCSubpathRoute thisRoute, TrainRouted thisTrain) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 9477
   a következő helyen: ORTS.SignalObject.checkRouteState(Boolean isPropagated, TCSubpathRoute thisRoute, TrainRouted thisTrain) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 9140
   a következő helyen: ORTS.SignalObject.requestClearSignal(TCSubpathRoute RoutePart, TrainRouted thisTrain, Int32 clearNextSignals, Boolean requestIsPropagated, SignalObject lastSignal) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 9070
   a következő helyen: ORTS.SignalObject.propagateRequest() hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 9348
   a következő helyen: ORTS.SignalObject.Update() hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 8515
   a következő helyen: ORTS.Signals.Update(Boolean preUpdate) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Signals\Signals.cs, sor: 546
   a következő helyen: ORTS.Simulator.Update(Single elapsedClockSeconds) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Simulator\Simulator.cs, sor: 500
   a következő helyen: ORTS.Viewer3D.Viewer.Update(RenderFrame frame, Single elapsedRealTime) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Viewer3D\Viewer.cs, sor: 538
   a következő helyen: ORTS.Processes.GameStateViewer3D.Update(RenderFrame frame, Double totalRealSeconds) hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Processes\GameStateViewer3D.cs, sor: 122
   a következő helyen: ORTS.Processes.UpdaterProcess.Update() hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Processes\UpdaterProcess.cs, sor: 129
   a következő helyen: ORTS.Processes.UpdaterProcess.DoUpdate() hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Processes\UpdaterProcess.cs, sor: 108
   a következő helyen: ORTS.Processes.UpdaterProcess.UpdaterThread() hely: d:\Sim_Devel\git\OpenRails\Source\RunActivity\Processes\UpdaterProcess.cs, sor: 74
   a következő helyen: System.Threading.ThreadHelper.ThreadStart_Context(Object state)
   a következő helyen: System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   a következő helyen: System.Threading.ThreadHelper.ThreadStart()

It is this code:

public int GetEndSection(Train thisTrain)
{
    int thisTrainAndSubpathIndex = GetTrainAndSubpathIndex(thisTrain.Number, thisTrain.TCRoute.activeSubpath);
    int pathIndex = TrainReferences[thisTrainAndSubpathIndex][0];
    DeadlockPathInfo pathInfo = AvailablePathList[pathIndex];
    return (pathInfo.EndSectionIndex);
}

The problem is that the actual DeadlockInfo object's TrainReferences doesn't contain the thisTrainAndSubpathIndex queried. In my case the TrainReferences is filled up from index 1 to 40, but the queried index is 41. I see that TrainReferences is compiled at loading time, and then is read only during the runtime. But whether maybe the train's route is getting changed during runtime, or the initial data collecting couldn't find a particular route, I don't know...

Rob, if you would like me to make a debug run, I may do that. The crash happens in 10 minutes (maybe just 5, don't remember exactly) after startup. But I also have a saved game, where the crash happens within some seconds, however in debugging that might not be so much of a help, since the DeadLockInfo is collected at initial startup.

Disc, just FYI, for me it happens with train 2177, that starts from Szob, and crashes after leaving Zebegény, and before arriving to Nagymaros station. But I think it happens with most trains using this path. The crash happens at the moment a signal was passed.

[roeter]

That the error occurs on passing a signal is no surprise, as that is when the next bit of the route is checked. How it can occur is the mystery here, as that field "thisTrainAndSubpathIndex" is only set when a path for that train is inserted in the related list. Checking through the code visually, it should not be possible for a train to have that index set, and yet not have a path allocated.

Peter, if you want to have a go at it, I have send you a PM with some suggestions.

Regards,
Rob Roeterdink

[disc]

gpz, on 08 January 2015 - 11:09 PM, said:

Disc, just FYI, for me it happens with train 2177, that starts from Szob, and crashes after leaving Zebegény, and before arriving to Nagymaros station. But I think it happens with most trains using this path. The crash happens at the moment a signal was passed.

It happens with train 2117 too(and probably with others), but if you try you will see this only happens if the player drives the train, but does not if it's driven by AI. The main problem isn't this, but the same error happens at totally different parts of the route, with totally different paths. It happens a certain point of route with the InterCity trains, and triggered by other passenger services that are never reach that point(as these trains have end their services about 50km before that point, so does not interfere with the Intercities), and that's the biggest mystery.
(A szegedi vonatokkal ezért nem tudok mit csinálni, mert ha hozzáadom a szegedi IC-ket, minden jó, de ha hozzáadom a Szeged-Kiskunfélegyháza közti személyeket, akkor a napi első IC már elhasal a fenti hibával, méghozzá ceglédbercelnél (ami elég érthetetlen, mert ugye a hibát kiváltó személyvonatok kiskunfélegyházánál megállnak, és nem mennek tovább).

[gpz]

Thank you Rob, I will take a look.
Disc, I think if the crash could be tracked back at the easier case, the more complicated one might be gone too, at least hopefully. :) I also noticed, that this crash only happens at player train. The trains can run around a whole day alone without errors.

[gpz]

After first evening's tracking (for me it is very difficult to track the various indices and object in deadlock processing, and I am far from understanding all of them) it turned out to me that the crash happens because:

1. The given index (41) is generated as a new index in
TCRoutePath--ProcessAlternativePath_LocationDef--InsertPassingPath--GetTrainAndSubpathIndex(int trainNumber, int subpathIndex)
Thus TrainSubpathIndex will contain the new index just generated.


2. However, the startSection.DeadlockReference and endSection.DeadlockReference is not set to the DeadlockInfo object previously in
TCRoutePath--ProcessAlternativePath_LocationDef--InsertPassingPath--FindDeadlockInfo(ref passPath, mainPath, startSectionIndex, endSectionIndex)


3. After this calling
TCRoutePath--SearchPassingPaths--SetTrainDetails--TrainReferences.Add(GetTrainAndSubpathIndex(int trainNumber, int subpathIndex))
is avoided, because SetTrainDetails will not be called because of the missing DeadLockReference. Thus TrainReferences will not contain the relevant TrainSubpathIndex object. And when the program wants to pair these (TrainReferences and TrainSubpathIndex) together later in runtime GetEndSection, it will crash.

So I think the bug must be somewhere in point 2, at setting the deadlock reference in FindDeadlockInfo, specifically in this code part:

            if (newDeadlockInfo == null)
            {
                // if both references are equal, use existing information
                if (startSectionDLReference > 0 && startSectionDLReference == endSectionDLReference)
                {
                    newDeadlockInfo = signalRef.DeadlockInfoList[startSectionDLReference];
                }

                // if both references are null, check for existing references along route
                else if (startSectionDLReference < 0 && endSectionDLReference < 0)
                {
                    if (CheckNoOverlapDeadlockPaths(partPath, signalRef))
                    {
                        newDeadlockInfo = new DeadlockInfo(signalRef, startSection, endSection);
                        signalRef.DeadlockReference.Add(startSectionIndex, newDeadlockInfo.DeadlockIndex);
                        signalRef.DeadlockReference.Add(endSectionIndex, newDeadlockInfo.DeadlockIndex);

                        startSection.DeadlockReference = newDeadlockInfo.DeadlockIndex;
                        endSection.DeadlockReference = newDeadlockInfo.DeadlockIndex;
                    }
                    // else : overlaps existing deadlocks - will sort that out later //TODO DEADLOCK
                }
            }

I have checked, this case has nothing to do with the comment about unimplemented deadlock overlapping. After this I went to sleep :D, so currently I am just wondering, what happens if exclusively startSectionDLReference < 0 or endSectionDLReference < 0 ? These are the missing cases that are not covered there. What could cause such a situation? I have to test it this evening.

Rob, does it make sense for you, or I am on a totally wrong way?