001package jmri.jmrit.logix;
002
003import java.util.List;
004import java.util.concurrent.LinkedBlockingQueue;
005
006import jmri.*;
007import jmri.implementation.SignalSpeedMap;
008import org.slf4j.Logger;
009import org.slf4j.LoggerFactory;
010
011/**
012 * An SCWarrant is a warrant that is controlled by the signals on a layout.
013 * It will not run unless you have your layout fully covered with sensors and
014 * signals.
015 *
016 * @author  Karl Johan Lisby Copyright (C) 2016
017 */
018public class SCWarrant extends Warrant {
019
020    private static final String WAIT_UNEXPECTED_EXCEPTION = "{} wait unexpected exception {}";
021    private NamedBean _nextSignal = null; // The signal that we are currently looking at to determine speed.
022    public static final float SPEED_STOP = 0.0f;
023    public static final float SPEED_TO_PLATFORM = 0.2f;
024    public static final float SPEED_UNSIGNALLED = 0.4f;
025    private long timeToPlatform = 500;
026    private float speedFactor = 0.8f;
027    private boolean forward = true;
028    private final boolean _allowShallowAllocation = false;
029    private DccThrottle _throttle = null;
030
031    /**
032     * Create an object with no route defined.
033     * <p>
034     * The list of BlockOrders is the route from an Origin to a Destination.
035     * @param sName system name.
036     * @param uName username.
037     * @param TTP time to platform.
038     */
039    public SCWarrant(String sName, String uName, long TTP) {
040        super(sName, uName);
041        log.debug("new SCWarrant {} TTP={}",uName,TTP);
042        timeToPlatform = TTP;
043        setNoRamp(true);
044    }
045
046    public long getTimeToPlatform() {
047        return timeToPlatform;
048    }
049
050    public void setTimeToPlatform(long TTP) {
051        timeToPlatform = TTP;
052    }
053
054    public void setForward(boolean set) {
055        forward = set;
056    }
057
058    public boolean getForward() {
059        return forward;
060    }
061
062    public void setSpeedFactor(float factor) {
063        if (factor > 1.0) {
064            speedFactor = 1.0f;
065        } else if (factor < 0.1) {
066            speedFactor = 0.1f;
067        } else {
068            speedFactor = factor;
069        }
070    }
071
072    public float getSpeedFactor() {
073        return speedFactor;
074    }
075
076    float _maxBlockLength = 0;
077    float getMaxBlockLength() {
078        return _maxBlockLength;
079    }
080    void setMaxBlockLength() {
081        float blockLength;
082        for (int i=0; i <= getBlockOrders().size()-1; i++) {
083            blockLength = getBlockOrderAt(i).getBlock().getLengthCm();
084            if (blockLength > _maxBlockLength) {
085                _maxBlockLength = blockLength;
086            }
087        }
088    }
089
090    private String allocateStartBlock() {
091        BlockOrder bo = getBlockOrderAt(0);
092        OBlock block = bo.getBlock();
093        String message = block.allocate(this);
094        if (message != null) {
095           log.info("{} START-block allocation failed {} ",_trainName,message);
096           return message;
097        }
098        message = bo.setPath(this);
099        if (message != null) {
100           log.info("{} setting path in START-block failed {}",_trainName,message);
101           return message;
102        }
103        return null;
104    }
105
106    /**
107     * This method has been overridden in order to avoid allocation of occupied blocks.
108     */
109    @Override
110     public String setRoute(boolean delay, List<BlockOrder> orders) {
111        return allocateStartBlock();
112    }
113
114    boolean allTurnoutsSet() {
115        for (int i=0; i<getBlockOrders().size(); i++) {
116            OBlock block_i = getBlockOrderAt(i).getBlock();
117            OPath  path_i  = getBlockOrderAt(i).getPath();
118            if (!path_i.checkPathSet()) {
119                log.debug("{}: turnouts at block {} are not set yet (in allTurnoutsSet).",_trainName,block_i.getDisplayName());
120                return false;
121            }
122        }
123        return true;
124    }
125
126    public boolean isRouteFree() {
127        for (int i=0; i<getBlockOrders().size(); i++) {
128            OBlock block_i = getBlockOrderAt(i).getBlock();
129            if ((block_i.getState() & OBlock.ALLOCATED) == OBlock.ALLOCATED) {
130                log.debug("{}: block {} is allocated to {} (in isRouteFree).",_trainName,block_i.getDisplayName(),block_i.getAllocatingWarrantName());
131                if (!block_i.isAllocatedTo(this)) {
132                    return false;
133                }
134            }
135            if ( ((block_i.getState() & Block.OCCUPIED) == Block.OCCUPIED) && (i>0) ) {
136                log.debug("{}: block {} is not free (in isRouteFree).",_trainName,block_i.getDisplayName());
137                return false;
138            }
139        }
140        return true;
141    }
142
143    boolean isRouteAllocated() {
144        for (int i=0; i<getBlockOrders().size(); i++) {
145            OBlock block_i = getBlockOrderAt(i).getBlock();
146            if (!block_i.isAllocatedTo(this)) {
147                log.debug("{}: block {} is not allocated to this warrant (in isRouteAllocated).",_trainName,block_i.getDisplayName());
148                return false;
149            }
150        }
151        return true;
152    }
153
154    /**
155     * Callback from acquireThrottle() when the throttle has become available.sync
156     */
157    @Override
158    public void notifyThrottleFound(DccThrottle throttle) {
159        _throttle = throttle;
160        if (throttle == null) {
161            abortWarrant("notifyThrottleFound: null throttle(?)!");
162            firePropertyChange("throttleFail", null, Bundle.getMessage("noThrottle"));
163            return;
164        }
165        if (_runMode == MODE_LEARN) {
166            abortWarrant("notifyThrottleFound: No LEARN mode for SCWarrant");
167            InstanceManager.throttleManagerInstance().releaseThrottle(throttle, this);
168            firePropertyChange("throttleFail", null, Bundle.getMessage("noThrottle"));
169            return;
170        }
171        log.debug("{} notifyThrottleFound address= {} _runMode= {}",_trainName,throttle.getLocoAddress(),_runMode);
172
173        startupWarrant();
174
175        firePropertyChange("WarrantStart", Integer.valueOf(MODE_NONE), Integer.valueOf(_runMode));
176        runSignalControlledTrain();
177    }
178
179    /**
180     * Generate status message to show in warrant table.
181     * {@inheritDoc}
182     **/
183    @Override
184    protected synchronized String getRunningMessage() {
185        if (_throttle == null) {
186            // The warrant is not active
187            return super.getRunningMessage();
188        } else if (_runMode != MODE_RUN) {
189            return ("Idle");
190        } else {
191            if (getBlockOrderAt(getCurrentOrderIndex()) == null) {
192                return ("Uninitialized");
193            }
194            String block = getBlockOrderAt(getCurrentOrderIndex()).getBlock().getDisplayName();
195            String signal = "no signal";
196            String aspect = "none";
197            if (_nextSignal != null) {
198                signal = _nextSignal.getDisplayName();
199                if (_nextSignal instanceof SignalHead) {
200                    int appearance = ((SignalHead) _nextSignal).getAppearance();
201                    aspect = "appearance "+appearance;
202                } else {
203                    aspect = ((SignalMast) _nextSignal).getAspect();
204                }
205            }
206            return Bundle.getMessage("SCWStatus", block, getCurrentOrderIndex(), _throttle.getSpeedSetting(),signal,aspect);
207        }
208    }
209
210    /******************************************************************************************************
211     * Use _throttle to control the train.
212     *
213     * Get notified of signals, block occupancy and take care of block allocation status to determine speed.
214     *
215     * We have three speeds: Stop == SPEED_STOP
216     *                       Normal == SPEED_NORMAL
217     *                       Anything else == SPEED_MID (Limited, Medium, Slow, Restricted)
218     *
219     * If you have blocks large enough to ramp speed nicely up and down and to have further control
220     * of speed settings: Use a normal warrant and not a signal controlled one.
221     *
222     * This is "the main loop" for running a Signal Controlled Warrant
223     ******************************************************************************************************/
224    protected void runSignalControlledTrain () {
225        allocateBlocksAndSetTurnouts(0);
226        setTrainDirection();
227        SCTrainRunner thread = new SCTrainRunner(this);
228        Thread t = jmri.util.ThreadingUtil.newThread(thread);
229        t.setName("SCTrainRunner");
230        t.start();
231    }
232
233    /**
234     * Wait until there is a train in the start block.
235     * @return true if block not UNOCCUPIED
236     */
237    protected boolean isStartBlockOccupied() {
238        int blockState = getBlockOrderAt(0).getBlock().getState();
239        return (blockState & Block.UNOCCUPIED) != Block.UNOCCUPIED;
240    }
241
242    protected synchronized void waitForStartblockToGetOccupied() {
243        while (!isStartBlockOccupied()) {
244            log.debug("{} waiting for start block {} to become occupied",_trainName,getBlockOrderAt(0).getBlock().getDisplayName());
245            try {
246                // We will not be woken up by goingActive, since we have not allocated the start block yet.
247                // So do a timed wait.
248                wait(2500);
249            } catch (InterruptedException ie) {
250                log.debug("{} waitForStartblockToGetOccupied InterruptedException {}",_trainName,ie,ie);
251            }
252            catch(Exception e){
253                log.debug("{} waitForStartblockToGetOccupied unexpected exception {}",_trainName,e,e);
254            }
255        }
256    }
257
258    /**
259     * Set this train to run backwards or forwards as specified in the command list.
260     */
261    public void setTrainDirection () {
262        _throttle.setIsForward(forward);
263    }
264
265    /**
266     * Is the next block free or occupied, i.e do we risk to crash into an other train, if we proceed?
267     * And is it allocated to us?
268     * @return true if allocated to us and unoccupied, else false.
269     */
270    public boolean isNextBlockFreeAndAllocated() {
271        BlockOrder bo = getBlockOrderAt(getCurrentOrderIndex()+1);
272        if (bo == null) return false;
273        int blockState = bo.getBlock().getState();
274        if (blockState == (Block.UNOCCUPIED | OBlock.ALLOCATED)) {
275            return getBlockOrderAt(getCurrentOrderIndex()+1).getBlock().isAllocatedTo(this);
276        } else {
277            return false;
278        }
279    }
280
281    /**
282     * Find the next signal along our route and setup subscription for status changes on that signal.
283     */
284    public void getAndGetNotifiedFromNextSignal() {
285        if (_nextSignal != null) {
286            log.debug("{} getAndGetNotifiedFromNextSignal removing property listener for signal {}",_trainName,_nextSignal.getDisplayName());
287            _nextSignal.removePropertyChangeListener(this);
288            _nextSignal = null;
289        }
290        for (int i = getCurrentOrderIndex()+1; i <= getBlockOrders().size()-1; i++) {
291            BlockOrder bo = getBlockOrderAt(i);
292            if (bo == null) {
293                log.debug("{} getAndGetNotifiedFromNextSignal could not find a BlockOrder for index {}",_trainName,i);
294            } else if (bo.getEntryName().equals("")) {
295                log.debug("{} getAndGetNotifiedFromNextSignal could not find an entry to Block for index {}",_trainName,i);
296            } else {
297                log.debug("{} getAndGetNotifiedFromNextSignal examines block {} with entryname = {}",_trainName,bo.getBlock().getDisplayName(),bo.getEntryName());
298                _nextSignal = bo.getSignal();
299                if (_nextSignal != null) {
300                    log.debug("{} getAndGetNotifiedFromNextSignal found a new signal to listen to: {}",_trainName,_nextSignal.getDisplayName());
301                    break;
302                }
303            }
304        }
305        if (_nextSignal != null) {
306            _nextSignal.addPropertyChangeListener(this);
307        }
308    }
309
310    /**
311     * Are we still in the start block?
312     * @return true if still in start block
313     */
314    boolean inStartBlock() {
315        return (getCurrentOrderIndex() == 0);
316    }
317
318    /**
319     * Are we close to the destination block?
320     * @return true if close
321     */
322    boolean approchingDestination() {
323        float distance = 0;
324        float blockLength;
325        if (getCurrentOrderIndex() == getBlockOrders().size()-2) {
326            // We are in the block just before destination
327            return true;
328        }
329        // Calculate the distance to destination
330        for (int i = getCurrentOrderIndex(); i <= getBlockOrders().size()-2; i++) {
331            blockLength = getBlockOrderAt(i).getBlock().getLengthCm();
332            if (blockLength < 1) {
333                // block length not set for at least one block
334                return false;
335            }
336            distance += blockLength;
337        }
338        return (distance < 1.5*getMaxBlockLength());
339    }
340
341    /**
342     * Move the train if _nextSignal permits. If there is no next signal, we will move forward with half speed.
343     */
344    SignalSpeedMap _speedMap = InstanceManager.getDefault(SignalSpeedMap.class);
345    public void setSpeedFromNextSignal () {
346        String speed = null;
347        if (_nextSignal == null) {
348            _throttle.setSpeedSetting(speedFactor*SPEED_UNSIGNALLED);
349        } else {
350            if (_nextSignal instanceof SignalHead) {
351                int appearance = ((SignalHead) _nextSignal).getAppearance();
352                speed = _speedMap.getAppearanceSpeed(((SignalHead) _nextSignal).getAppearanceName(appearance));
353                log.debug("{} SignalHead {} shows appearance {} which maps to speed {}",_trainName,((SignalHead) _nextSignal).getDisplayName(),appearance,speed);
354            } else {
355                String aspect = ((SignalMast) _nextSignal).getAspect();
356                speed = _speedMap.getAspectSpeed((aspect == null ? "" : aspect), 
357                    ((SignalMast) _nextSignal).getSignalSystem());
358                log.debug("{} SignalMast {} shows aspect {} which maps to speed {}",_trainName,((SignalMast) _nextSignal).getDisplayName(),aspect,speed);
359            }
360            float speed_f = (float) (_speedMap.getSpeed(speed) / 125.);
361            // Ease the speed, if we are approaching the destination block
362            if ((approchingDestination() || inStartBlock()) && (speed_f > SPEED_UNSIGNALLED)) {
363                speed_f = SPEED_UNSIGNALLED;
364            }
365            _throttle.setSpeedSetting(speedFactor*speed_f);
366        }
367    }
368
369     /**
370     * Do what the title says. But make sure not to set the turnouts if already done, since that
371     * would just cause all signals to go to Stop aspects and thus cause a jerky train movement.
372     * @param startIndex Allocate starting with this index
373     */
374    protected void allocateBlocksAndSetTurnouts(int startIndex) {
375        log.debug("{} allocateBlocksAndSetTurnouts startIndex={} _orders.size()={}",_trainName,startIndex,getBlockOrders().size());
376        for (int i = startIndex; i < getBlockOrders().size(); i++) {
377            log.debug("{} allocateBlocksAndSetTurnouts for loop #{}",_trainName,i);
378            BlockOrder bo = getBlockOrderAt(i);
379            OBlock block = bo.getBlock();
380            String pathAlreadySet = block.isPathSet(bo.getPathName());
381            if (pathAlreadySet == null) {
382                String message = null;
383                if ((block.getState() & Block.OCCUPIED) != 0) {
384                    log.info("{} block allocation failed {} not allocated, but Occupied.",_trainName,block.getDisplayName());
385                    message = " block allocation failed ";
386                }
387                if (message == null) {
388                    message = block.allocate(this);
389                    if (message != null) {
390                        log.info("{} block allocation failed {}",_trainName,message);
391                    }
392                }
393                if (message == null) {
394                    message = bo.setPath(this);
395                }
396                if (message != null) {
397                    log.debug("{} path setting failed for {} at block {} {}",_trainName,getDisplayName(),block.getDisplayName(),message);
398                    if (_stoppingBlock != null) {
399                        _stoppingBlock.removePropertyChangeListener(this);
400                    }
401                    _stoppingBlock = block;
402                    _stoppingBlock.addPropertyChangeListener(this);
403                    // This allocation failed. Do not attempt to allocate the rest of the route.allocation
404                    // That would potentially lead to deadlock situations where two warrants are competing
405                    // and each getting every second block along the same route.
406                    return;
407                }
408            } else if (pathAlreadySet.equals(this.getDisplayName())) {
409                log.debug("{} Path {} already set (and thereby block allocated) for {}",_trainName,bo.getPathName(),pathAlreadySet);
410            } else {
411                log.info("{} Block allocation failed: Path {} already set (and thereby block allocated) for {}",_trainName,bo.getPathName(),pathAlreadySet);
412                return;
413            }
414        }
415    }
416
417    @Override
418    public String setRunMode(int mode, DccLocoAddress address,
419            LearnThrottleFrame student,
420            List<ThrottleSetting> commands, boolean runBlind) {
421        if (log.isDebugEnabled()) {
422            log.debug("{}: SCWarrant::setRunMode({}) ({}) called with _runMode= {}.",
423                  getDisplayName(), mode, MODES[mode], MODES[_runMode]);
424        }
425        _message = null;
426        if (_runMode != MODE_NONE) {
427            _message = getRunModeMessage();
428            log.debug("setRunMode called, but SCWarrant is already running");
429            return _message;
430        }
431        if (mode == MODE_RUN) {
432            // set mode before setStoppingBlock and callback to notifyThrottleFound are called
433            _runMode = mode;
434        } else {
435            deAllocate();
436            return _message;
437        }
438        getBlockAt(0)._entryTime = System.currentTimeMillis();
439        _message = acquireThrottle();
440        return _message;
441    } // end setRunMode
442
443    /**
444     * Block in the route going active.
445     * Make sure to allocate the rest of the route, update our present location and then tell
446     * the main loop to find a new throttle setting.
447     */
448    @Override
449    @edu.umd.cs.findbugs.annotations.SuppressFBWarnings(value = "NN_NAKED_NOTIFY", justification="NotifyAll call triggers recomputation")
450    protected void goingActive(OBlock block) {
451        log.debug("{} **Block \"{}\" goingActive. "
452                    + " - warrant= {} _runMode = {} _throttle==null: {}",_trainName,block.getDisplayName(),getDisplayName(),_runMode,(_throttle==null));
453        if (_runMode != MODE_RUN) {
454            // if we are not running, we must not think that we are going to the next block - it must be another train
455            log.debug("_runMode != MODE_RUN - ignored");
456            return;
457        }
458        if (_throttle == null || _throttle.getSpeedSetting() == SPEED_STOP) {
459            // if we are not running, we must not think that we are going to the next block - it must be another train
460            log.debug("Train is not running - ignored");
461            return;
462        }
463        int activeIdx = getIndexOfBlockAfter(block, getCurrentOrderIndex());
464        log.debug("{} **Block \"{}\" goingActive. activeIdx= {}"
465                    + ", getCurrentOrderIndex()= {}"
466                    + " - warrant= {} _runMode = {} _throttle==null: {}",_trainName,block.getDisplayName(),activeIdx,getCurrentOrderIndex(),getDisplayName(),_runMode,(_throttle==null));
467        if (activeIdx <= 0) {
468            // The block going active is not part of our route ahead
469            log.debug("{} Block going active is not part of this trains route forward",_trainName);
470        } else if (activeIdx == getCurrentOrderIndex()) {
471            // Unusual case of current block losing detection, then regaining it.  i.e. dirty track, derail etc.
472            log.debug("{} Current block becoming active - ignored",_trainName);
473        } else if (activeIdx == getCurrentOrderIndex() + 1) {
474            // not necessary: It is done in the main loop in SCTrainRunner.run:  allocateBlocksAndSetTurnouts(getCurrentOrderIndex()+1)
475            // update our present location
476            incrementCurrentOrderIndex();
477            block.setValue(_trainName);
478            block.setState(block.getState() | OBlock.RUNNING);
479            // fire property change (entered new block)
480            firePropertyChange("blockChange", getBlockAt(getCurrentOrderIndex() - 1), getBlockAt(getCurrentOrderIndex()));
481            // now let the main loop adjust speed.
482            synchronized(this) {
483                notifyAll();
484            }
485        } else {
486            log.debug("{} Rogue occupation of block.",_trainName);
487            // now let the main loop stop for a train that is coming in our immediate way.
488            synchronized(this) {
489                notifyAll();
490            }
491        }
492    }
493
494    /**
495     * Block in the route is going Inactive.
496     * Release the blocks that we have left.
497     * Check if current block has been left (i.e. we have left our route) and stop the train in that case.
498     */
499    @Override
500    @edu.umd.cs.findbugs.annotations.SuppressFBWarnings(value = "NN_NAKED_NOTIFY", justification="See comment above notify call")
501    protected void goingInactive(OBlock block) {
502        int idx = getIndexOfBlockAfter(block, 0);  // if idx >= 0, it is in this warrant
503        log.debug("{} Block \"{}\" goingInactive. idx= {}"
504                    + ", getCurrentOrderIndex()= {}"
505                    + " - warrant= {}",_trainName,block.getDisplayName(),idx,getCurrentOrderIndex(),getDisplayName());
506        if (_runMode != MODE_RUN) {
507            return;
508        }
509        if (idx < getCurrentOrderIndex()) {
510            if (_allowShallowAllocation) {
511                deallocateUpToBlock(idx);
512            }
513        } else if (idx == getCurrentOrderIndex()) {
514            // train is lost
515            log.debug("{} LOST TRAIN firePropertyChange(\"blockChange\", {}"
516                                + ", null) - warrant= {}",_trainName,block.getDisplayName(),getDisplayName());
517        }
518        // now let the main loop stop our train if this means that the train is now entirely within the last block.
519        // Or let the train continue if an other train that was in its way has now moved.
520        synchronized(this) {
521            notifyAll();
522        }
523    }
524
525    /**
526     * Deallocate all blocks up to and including idx, but only on these conditions in order to ensure that only a consecutive list of blocks are allocated at any time:
527     *     1. Only if our train has left not only this block, but also all previous blocks.
528     *     2. Only if the block shall not be re-used ahead and all block up until the block are allocated.
529     * @param idx Index of final block
530     */
531    protected void deallocateUpToBlock(int idx) {
532        for (int i=0; i<=idx; i++) {
533            OBlock block_i = getBlockOrderAt(i).getBlock();
534            if (block_i.isAllocatedTo(this)) {
535                if ((block_i.getState() & Block.UNOCCUPIED) != Block.UNOCCUPIED) {
536                    //Do not deallocate further blocks, since this one is still allocated to us and not free.
537                    log.debug("{} Block {} occupied. Not de-allocating any further",_trainName,block_i.getDisplayName());
538                    return;
539                }
540                boolean deAllocate = true;
541                // look ahead to see if block_i is reused in the remaining part of the route.
542                for (int j= getCurrentOrderIndex(); j<getBlockOrders().size(); j++) {
543                    OBlock block_j = getBlockOrderAt(j).getBlock();
544                    if (!block_j.isAllocatedTo(this)) {
545                        // There is an unallocated block ahead before we have found block_i is re-used. So deallocate block_i
546                        break;
547                    }
548                    if (block_i == block_j) {
549                        // clock_i is re-used, and we have no "holes" in the string of allocated blocks before it. So do not deallocate.
550                        deAllocate = false;
551                        break;
552                    }
553                }
554                if (deAllocate) {
555                    log.debug("{} De-allocating block {}",_trainName,block_i.getDisplayName());
556                    block_i.deAllocate(this);
557                }
558            }
559        }
560    }
561
562    /**
563     * Something has fired a property change event.
564     * React if:
565     *     - it is a warrant that we need to synchronize with. And then again: Why?
566     *     - it is _nextSignal
567     * Do not worry about sensors and blocks. They are handled by goingActive and goingInactive.
568     */
569    @edu.umd.cs.findbugs.annotations.SuppressFBWarnings(value = {"UW_UNCOND_WAIT", "NN_NAKED_NOTIFY"},
570            justification = "Unconditional wait is give the warrant that now has _stoppingBlock allocated a little time to deallocate it.  This occurs after this method sets _stoppingBlock to null. NotifyAll passing event, not state.")
571    @Override
572    public void propertyChange(java.beans.PropertyChangeEvent evt) {
573        if (!(evt.getSource() instanceof NamedBean)) {
574            log.debug("{} propertyChange \"{}\" old= {} new= {}",_trainName,evt.getPropertyName(),evt.getOldValue(),evt.getNewValue());
575            return;
576        }
577        String property = evt.getPropertyName();
578        log.debug("{} propertyChange \"{}\" new= {} source= {} - warrant= {}",_trainName,property,evt.getNewValue(),((NamedBean) evt.getSource()).getDisplayName(),getDisplayName());
579        if (_nextSignal != null && _nextSignal == evt.getSource()) {
580            if (property.equals("Aspect") || property.equals("Appearance")) {
581                // The signal controlling this warrant has changed. Adjust the speed (in runSignalControlledTrain)
582                synchronized(this) {
583                    notifyAll();
584                }
585                return;
586            }
587        }
588        synchronized(this) {
589            if (_stoppingBlock != null) {
590                log.debug("{} CHECKING STOPPINGBLOCKEVENT ((NamedBean) evt.getSource()).getDisplayName() = '{}' evt.getPropertyName() = '{}' evt.getNewValue() = {} _throttle==null: {}",_trainName,((NamedBean) evt.getSource()).getDisplayName(),evt.getPropertyName(),evt.getNewValue(),(_throttle==null));
591                if (((NamedBean) evt.getSource()).getDisplayName().equals(_stoppingBlock.getDisplayName()) &&
592                        evt.getPropertyName().equals("state") &&
593                        (((Number) evt.getNewValue()).intValue() & Block.UNOCCUPIED) == Block.UNOCCUPIED) {
594                    log.debug("{} being aware that Block {} has become free",_trainName,((NamedBean) evt.getSource()).getDisplayName());
595                    _stoppingBlock.removePropertyChangeListener(this);
596                    _stoppingBlock = null;
597                    // we might be waiting for this block to become free
598                    // Give the warrant that now has _stoppingBlock allocated a little time to deallocate it
599                    try {
600                        wait(100);
601                    } catch (InterruptedException e) {
602                        // ignoring interrupted exceptions
603                    } catch(Exception e){
604                        log.debug(WAIT_UNEXPECTED_EXCEPTION,_trainName,e,e);
605                    }
606                    // And then let our main loop continue
607                    notifyAll();
608                    return;
609                }
610                if (((NamedBean) evt.getSource()).getDisplayName().equals(getBlockOrderAt(0).getBlock().getDisplayName()) &&
611                        evt.getPropertyName().equals("state") &&
612                        (((Number) evt.getOldValue()).intValue() & Block.UNOCCUPIED) == Block.UNOCCUPIED &&
613                        (((Number) evt.getNewValue()).intValue() & Block.UNOCCUPIED) != Block.UNOCCUPIED &&
614                        _throttle==null && _runMode==MODE_RUN) {
615                    // We are waiting for the train to arrive at the starting block, and that has just happened now.
616                    log.debug("{} has arrived at starting block",_trainName);
617                    String msg = null;
618                    msg = acquireThrottle();
619                    if (msg != null) {
620                        log.warn("propertyChange of \"{}\" has message: {}", property, msg);
621                        _message = msg;
622                        abortWarrant(msg);
623                    }
624                }
625            }
626        }
627    }
628
629
630    /**
631     * Make sure to free up additional resources for a running SCWarrant.
632     */
633    @Override
634    public synchronized void stopWarrant(boolean abort, boolean turnOffFunctions) {
635        if (_nextSignal != null) {
636            _nextSignal.removePropertyChangeListener(this);
637            _nextSignal = null;
638        }
639        super.stopWarrant(abort, false);
640        _message = null;
641    }
642
643    /*******************************************************************************************************************************
644     * The waiting for event must happen in a separate thread.
645     * Therefore the main code of runSignalControlledTrain is put in this class.
646     *******************************************************************************************************************************/
647    static LinkedBlockingQueue<SCWarrant> waitToRunQ = new LinkedBlockingQueue<>();
648    private class SCTrainRunner implements Runnable {
649        private static final String INTERRUPTED_EXCEPTION = "{} InterruptedException {}";
650        SCWarrant _warrant = null;
651        SCTrainRunner(SCWarrant warrant) {
652            _warrant = warrant;
653        }
654
655        /**
656         * When not using shallow allocation, warrants will have to wait until the entire route
657         * is free and allocated to that particular warrant, before strting to run the train.
658         * This method uses the waitToRunQ to ensure that warrants do not just compete about
659         * resources, but waits in line until their route is free and unallocated.
660         */
661        boolean isItOurTurn() {
662            for (SCWarrant e : waitToRunQ) {
663                try { // using another SCWarrant might be dangerous - it might no longer exist
664                    log.debug("{} isItOurTurn is checking {}",_trainName,e.getDisplayName());
665                    if (e.isRouteFree()) {
666                        if (e == _warrant) {
667                            log.debug("{} isItOurTurn: We are first in line",_trainName);
668                            return true;
669                        } else {
670                            log.debug("{} isItOurTurn: An other warrant is before us",_trainName);
671                            return false;
672                        }
673                    } else {
674                        if (e == _warrant) {
675                            log.debug("{} isItOurTurn: our route is not free - keep waiting",_trainName);
676                            return false;
677                        }
678                    }
679                } catch (Exception ex) {
680                    log.debug("{} isItOurTurn exception ignored: {}",_trainName,ex,ex);
681                }
682            }
683            // we should not reach this point, but if we do, we should try to run
684            log.debug("{} isItOurTurn: No warrant with a free route is waiting. Let us try our luck, so that we are not all waiting for each other.",_trainName);
685            return true;
686        }
687
688        @Override
689        public void run() {
690            synchronized(_warrant) {
691
692                waitForStartblockToGetOccupied();
693
694                // Make sure the entire route is allocated before attemting to start the train
695                if (!_allowShallowAllocation) {
696                    boolean AllocationDone = false;
697                    log.debug("{} ENTERING QUEUE ",_trainName);
698                    try {
699                        waitToRunQ.put(_warrant);
700                    } catch (InterruptedException ie) {
701                        log.debug("{} waitToRunQ.put InterruptedException {}",_trainName,ie,ie);
702                    }
703
704                    while (!AllocationDone) {
705                        log.debug("{} Route is not allocated yet..... ",_trainName);
706                        while (!isItOurTurn()) {
707                            deAllocate();
708                            log.debug("{} Waiting for route to become free ....",_trainName);
709                            try {
710                                _warrant.wait(2500 + Math.round(1000*Math.random()));
711                            } catch (InterruptedException ie) {
712                                log.debug("{} _warrant.wait InterruptedException {}",_trainName,ie,ie);
713                            }
714                            catch(Exception e){
715                                log.debug("{} _warrant.wait unexpected exception {}",_trainName,e,e);
716                            }
717                        }
718                        allocateStartBlock();
719                        allocateBlocksAndSetTurnouts(1);
720                        AllocationDone = isRouteAllocated();
721                        if (!AllocationDone) {
722                            deAllocate();
723                            try {
724                                _warrant.wait(10000 + Math.round(1000*Math.random()));
725                            } catch (InterruptedException ie) {
726                                log.debug("{} _warrant.wait !AllocationDone InterruptedException {}",_trainName,ie,ie);
727                            }
728                            catch(Exception e){
729                                log.debug("{} _warrant.wait !AllocationDone unexpected exception {}",_trainName,e,e);
730                            }
731                        }
732                    }
733
734                    log.debug("{} LEAVING QUEUE ",_trainName);
735                    waitToRunQ.remove(_warrant);
736
737                    while (!allTurnoutsSet()) {
738                        log.debug("{} Waiting for turnouts to settle ....",_trainName);
739                        try {
740                            _warrant.wait(2500);
741                        } catch (InterruptedException ie) {
742                            log.debug("{} _warrant.wait InterruptedException {}",_trainName,ie,ie);
743                        }
744                        catch(Exception e){
745                            log.debug("{} _warrant.wait unexpected exception {}",_trainName,e,e);
746                        }
747                    }
748                    // And then wait another 3 seconds to make the last turnout settle - just in case the command station is not giving correct feedback
749                    try {
750                        _warrant.wait(3000);
751                    } catch (InterruptedException ie) {
752                        log.debug(INTERRUPTED_EXCEPTION,_trainName,ie,ie);
753                    }
754                    catch(Exception e){
755                        log.debug(WAIT_UNEXPECTED_EXCEPTION,_trainName,e,e);
756                    }
757                }
758
759                // Do not include the stopping block in this while loop. It will be handled after the loop.
760                List<BlockOrder> orders = getBlockOrders();
761                while (_warrant.getCurrentOrderIndex() < orders.size()-1 && _runMode == MODE_RUN) {
762                    log.debug("{} runSignalControlledTrain entering while loop. getCurrentOrderIndex()={} _orders.size()={}",_warrant._trainName,getCurrentOrderIndex(),orders.size());
763                    if (_throttle == null) {
764                        // We lost our throttle, so we might have a runaway train
765                        emergencyStop();
766                    }
767                    if (_allowShallowAllocation) {
768                        allocateBlocksAndSetTurnouts(_warrant.getCurrentOrderIndex());
769                    }
770                    if (isNextBlockFreeAndAllocated()) {
771                        getAndGetNotifiedFromNextSignal();
772                        setSpeedFromNextSignal();
773                    } else {
774                        try {
775                            _throttle.setSpeedSetting(SPEED_STOP);
776                            getBlockOrderAt(getCurrentOrderIndex()+1).getBlock().addPropertyChangeListener(_warrant);
777                            log.debug("{} runSignalControlledTrain stops train due to block not free: {}",_warrant._trainName,getBlockOrderAt(getCurrentOrderIndex()+1).getBlock().getDisplayName());
778                        } catch (Exception e) {
779                            emergencyStop();
780                            log.debug("{} exception trying to stop train due to block not free: {}",_warrant._trainName,e,e);
781                        }
782                    }
783                    log.debug("{} {} before wait {} getCurrentOrderIndex(): {} orders.size(): {}",_warrant._trainName,_warrant.getDisplayName(),_warrant.getRunningMessage(),_warrant.getCurrentOrderIndex(),orders.size());
784                    try {
785                        // We do a timed wait for the sake of robustness, even though we will be woken up by all relevant events.
786                        _warrant.wait(2000);
787                    } catch (InterruptedException ie) {
788                        log.debug(INTERRUPTED_EXCEPTION,_warrant._trainName,ie,ie);
789                    }
790                    catch(Exception e){
791                        log.debug(WAIT_UNEXPECTED_EXCEPTION,_trainName,e,e);
792                    }
793                    log.debug("{} {} after wait {} getCurrentOrderIndex(): {} orders.size(): {}",_warrant._trainName,_warrant.getDisplayName(),_warrant.getRunningMessage(),_warrant.getCurrentOrderIndex(),orders.size());
794                }
795                // We are now in the stop block. Move forward for half a second with half speed until the block before the stop block is free.
796                log.debug("{} runSignalControlledTrain out of while loop, i.e. train entered stop block getCurrentOrderIndex()={}"
797                          + " orders.size()={} waiting for train to clear block {}",
798                          _warrant._trainName,getCurrentOrderIndex(),orders.size(),getBlockAt(orders.size()-2).getDisplayName());
799                if (_throttle==null) {
800                    emergencyStop();
801                    log.debug("Throttle lost at stop block");
802                } else {
803                    _throttle.setSpeedSetting(speedFactor*SPEED_TO_PLATFORM);
804                }
805                while ((getBlockAt(orders.size()-2).getState()&Block.OCCUPIED)==Block.OCCUPIED && getBlockAt(orders.size()-2).isAllocatedTo(_warrant)) {
806                    log.debug(" runSignalControlledTrain {} entering wait. Block {}   free: {}   allocated to this warrant: {}",
807                              _warrant._trainName,
808                              getBlockAt(orders.size()-2).getDisplayName(),
809                              getBlockAt(orders.size()-2).isFree(),
810                              getBlockAt(orders.size()-2).isAllocatedTo(_warrant));
811                    try {
812                        // This does not need to be a timed wait, since we will get interrupted once the block is free
813                        // However, the functionality is more robust with a timed wait.
814                        _warrant.wait(500);
815                    } catch (InterruptedException ie) {
816                        log.debug(INTERRUPTED_EXCEPTION,_warrant._trainName,ie,ie);
817                    }
818                    catch(Exception e){
819                        log.debug(WAIT_UNEXPECTED_EXCEPTION,_trainName,e,e);
820                    }
821                    log.debug("{} runSignalControlledTrain woken after last wait.... _orders.size()={}",_warrant._trainName,orders.size());
822                }
823                if (timeToPlatform > 100) {
824                    log.debug("{} runSignalControlledTrain is now fully into the stopping block. Proceeding for {} miliseconds",_warrant._trainName,timeToPlatform);
825                    long timeWhenDone = System.currentTimeMillis() + timeToPlatform;
826                    long remaining;
827                    while ((remaining = timeWhenDone - System.currentTimeMillis()) > 0) {
828                        try {
829                            log.debug("{} running slowly to platform for {} miliseconds",_warrant._trainName,remaining);
830                            _warrant.wait(remaining);
831                        } catch (InterruptedException e) {
832                            log.debug(INTERRUPTED_EXCEPTION,_warrant._trainName,e,e);
833                        }
834                    }
835                }
836                log.debug("{} runSignalControlledTrain STOPPING TRAIN IN STOP BLOCK",_warrant._trainName);
837                if (_throttle==null) {
838                    emergencyStop();
839                    log.debug("Throttle lost after stop block");
840                } else {
841                    _throttle.setSpeedSetting(SPEED_STOP);
842                }
843                stopWarrant(false, false);
844            }
845        }
846
847        /**
848         * If we think we might have a runaway train - take the power of the entire layout.
849         */
850        private void emergencyStop() {
851            PowerManager manager = InstanceManager.getNullableDefault(PowerManager.class);
852            if (manager == null) {
853                log.debug("{} EMERGENCY STOP IMPOSSIBLE: NO POWER MANAGER",_trainName);
854                return;
855            }
856            try {
857                manager.setPower(PowerManager.OFF);
858            } catch (Exception e) {
859                log.debug("{} EMERGENCY STOP FAILED WITH EXCEPTION: {}",_trainName,e,e);
860            }
861            log.debug("{} EMERGENCY STOP",_trainName);
862        }
863
864    }
865
866    /* What super does currently is fine. But FindBug reports EQ_DOESNT_OVERRIDE_EQUALS
867     * FindBug wants us to duplicate and override anyway
868     */
869    @Override
870    public boolean equals(Object obj) {
871        return super.equals(obj);
872    }
873
874    /* What super does currently is fine. But FindBug reports HE_EQUALS_NO_HASHCODE
875     * FindBug wants us to duplicate and override anyway
876     */
877    @Override
878    public int hashCode() {
879        return super.hashCode();
880    }
881
882    /**
883     *
884     */
885    private static final Logger log = LoggerFactory.getLogger(SCWarrant.class);
886}