001package jmri.jmrix.loconet;
002
003import org.slf4j.Logger;
004import org.slf4j.LoggerFactory;
005
006/**
007 * Converts Stream-based I/O to/from LocoNet messages. The "LocoNetInterface"
008 * side sends/receives LocoNetMessage objects. The connection to a
009 * LnPortController is via a pair of *Streams, which then carry sequences of
010 * characters for transmission.
011 * <p>
012 * Messages come to this via the main GUI thread, and are forwarded back to
013 * listeners in that same thread. Reception and transmission are handled in
014 * dedicated threads by RcvHandler and XmtHandler objects. Those are internal
015 * classes defined here. The thread priorities are:
016 * <ul>
017 * <li> RcvHandler - at highest available priority
018 * <li> XmtHandler - down one, which is assumed to be above the GUI
019 * <li> (everything else)
020 * </ul>
021 * Some of the message formats used in this class are Copyright Digitrax, Inc.
022 * and used with permission as part of the JMRI project. That permission does
023 * not extend to uses in other software products. If you wish to use this code,
024 * algorithm or these message formats outside of JMRI, please contact Digitrax
025 * Inc for separate permission.
026 *
027 * @author Bob Jacobsen Copyright (C) 2001, 2018
028 */
029public class LnPacketizerStrict extends LnPacketizer {
030
031    // waiting for this echo
032    private LocoNetMessage waitForMsg;
033    // waiting on LACK
034    private boolean waitingOnLack;
035    // wait this, CS gone busy
036    private int waitBusy;
037    // retry required, lost echo, bad IMM, general busy
038    private boolean reTryRequired;
039
040    public static int maxWaitCount = 150; // public for script access
041
042    public LnPacketizerStrict(LocoNetSystemConnectionMemo m) {
043        super(m);
044    }
045
046    /**
047     * Captive class to handle incoming characters. This is a permanent loop,
048     * looking for input messages in character form on the stream connected to
049     * the LnPortController via <code>connectPort</code>.
050     */
051    protected class RcvHandlerStrict implements Runnable {
052
053        /**
054         * Remember the LnPacketizer object.
055         */
056        LnTrafficController trafficController;
057
058        public RcvHandlerStrict(LnTrafficController lt) {
059            trafficController = lt;
060        }
061
062        /**
063         * Handle incoming characters. This is a permanent loop, looking for
064         * input messages in character form on the stream connected to the
065         * LnPortController via <code>connectPort</code>. Terminates with the
066         * input stream breaking out of the try block.
067         */
068        @Override
069        public void run() {
070            int opCode;
071            while (!threadStopRequest && ! Thread.interrupted() ) {  // loop until asked to stop
072                try {
073                    // start by looking for command -  skip if bit not set
074                    while (((opCode = (readByteProtected(istream) & 0xFF)) & 0x80) == 0) {
075                        log.trace("Skipping: {}", Integer.toHexString(opCode)); // NOI18N
076                    }
077                    // here opCode is OK. Create output message
078                    log.trace(" (RcvHandler) Start message with opcode: {}", Integer.toHexString(opCode)); // NOI18N
079                    LocoNetMessage msg = null;
080                    while (msg == null) {
081                        try {
082                            // Capture 2nd byte, always present
083                            int byte2 = readByteProtected(istream) & 0xFF;
084                            log.trace("Byte2: {}", Integer.toHexString(byte2)); // NOI18N
085                            int len = 2;
086                            switch ((opCode & 0x60) >> 5) {
087                                case 0:
088                                    /* 2 byte message */
089                                    len = 2;
090                                    break;
091                                case 1:
092                                    /* 4 byte message */
093                                    len = 4;
094                                    break;
095                                case 2:
096                                    /* 6 byte message */
097                                    len = 6;
098                                    break;
099                                case 3:
100                                    /* N byte message */
101                                    if (byte2 < 2) {
102                                        log.error("LocoNet message length invalid: {} opcode: {}",
103                                                byte2, Integer.toHexString(opCode)); // NOI18N
104                                    }
105                                    len = byte2;
106                                    break;
107                                default:
108                                    log.warn("Unhandled code: {}", (opCode & 0x60) >> 5);
109                                    break;
110                            }
111                            msg = new LocoNetMessage(len);
112                            // message exists, now fill it
113                            msg.setOpCode(opCode);
114                            msg.setElement(1, byte2);
115                            log.trace("len: {}", len); // NOI18N
116                            for (int i = 2; i < len; i++) {
117                                // check for message-blocking error
118                                int b = readByteProtected(istream) & 0xFF;
119                                log.trace("char {} is: {}", i, Integer.toHexString(b)); // NOI18N
120                                if ((b & 0x80) != 0) {
121                                    log.warn("LocoNet message with opCode: {} ended early. Expected length: {} seen length: {} unexpected byte: {}", Integer.toHexString(opCode), len, i, Integer.toHexString(b)); // NOI18N
122                                    opCode = b;
123                                    throw new LocoNetMessageException();
124                                }
125                                msg.setElement(i, b);
126                            }
127                        } catch (LocoNetMessageException e) {
128                            // retry by destroying the existing message
129                            // opCode is set for the newly-started packet
130                            msg = null;
131                        }
132                    }
133                    // check parity
134                    if (!msg.checkParity()) {
135                        log.warn("Ignore LocoNet packet with bad checksum: [{}]", msg.toString());  // NOI18N
136                        throw new LocoNetMessageException();
137                    }
138                    // message is complete, dispatch it !!
139                    {
140                        log.trace("message complete: {}", msg);
141
142                        // check for XmtHandler waiting on return values
143                        if (waitForMsg != null) {
144                            if (waitForMsg.equals(msg)) {
145                                waitForMsg = null;
146                            }
147                        }
148                        if (waitingOnLack) {
149                            if (msg.getOpCode() == LnConstants.OPC_LONG_ACK) {
150                                waitingOnLack = false;
151                                // check bad IMM
152                                if ((msg.getElement(1) & 0xff) == 0x6d && (msg.getElement(2) & 0xff) == 0) {
153                                    reTryRequired = true;
154                                    waitBusy = 100;
155                                    log.warn("IMM Back off");  // NOI18N
156                                } else {
157                                    reTryRequired = false;
158                                }
159                            } else if (msg.getOpCode() == LnConstants.OPC_SL_RD_DATA) {
160                                waitingOnLack = false;
161                            } else if ( msg.getOpCode() == LnConstants.OPC_ALM_READ ) { // Extended slot status
162                                waitingOnLack = false;
163                            }
164                            // check for CS busy
165                        } else if (msg.getOpCode() == LnConstants.OPC_GPBUSY) {
166                            waitBusy = 100;
167                            log.warn("CS Busy Back off");  // NOI18N
168                            reTryRequired = true;
169                            // check for waiting on echo
170                        }
171                        // check if this message was supposed to be ignored
172                        // sentList will be empty if preference "LoconetUpdateSlotOnMessageCreation" is not activated
173                        if(trafficController.getSentList().contains(msg)) {
174                            trafficController.getSentList().remove(msg);
175                            log.trace("found packet {} in sentList, ignoring. {} packets in sentList remaining.", msg, trafficController.getSentList().size());
176                        }
177                        else {
178                            log.trace("queue message for notification: {}", msg);
179                            jmri.util.ThreadingUtil.runOnLayoutEventually(new RcvMemo(msg, trafficController));
180                        }
181                    }
182                    // done with this one
183                } catch (LocoNetMessageException e) {
184                    // just let it ride for now
185                    log.warn("run: unexpected LocoNetMessageException", e); // NOI18N
186                    continue;
187                } catch (java.io.InterruptedIOException e) {
188                    // being requested to stop
189                    // will be process in while clause
190                } catch (java.io.IOException e) {
191                    if (controller.getAllowConnectionRecovery()) {
192                        log.info("run: server closed connection, attempting recovery");
193                        controller.closePort();
194                        controller.recover();
195                    } else {
196                        // fired when read detects end-of-file
197                        log.info("End of file", e); // NOI18N
198                        dispose();
199                        disconnectPort(controller);
200                    }
201                    return;
202                } catch (RuntimeException e) {
203                    // normally, we don't catch RuntimeException, but in this
204                    // permanently running loop it seems wise.
205                    log.warn("run: unexpected Exception", e); // NOI18N
206                    continue;
207                }
208            } // end of permanent loop
209        }
210    }
211
212    /**
213     * Captive class to notify of one message
214     */
215    private static class RcvMemo implements jmri.util.ThreadingUtil.ThreadAction {
216
217        public RcvMemo(LocoNetMessage msg, LnTrafficController trafficController) {
218            thisMsg = msg;
219            thisTc = trafficController;
220        }
221        LocoNetMessage thisMsg;
222        LnTrafficController thisTc;
223
224        /**
225         * {@inheritDoc}
226         */
227        @Override
228        public void run() {
229            thisTc.notify(thisMsg);
230        }
231    }
232
233    /**
234     * Captive class to handle transmission
235     */
236    class XmtHandlerStrict implements Runnable {
237
238        /**
239         * {@inheritDoc}
240         */
241        @Override
242        public void run() {
243            int waitCount;
244            while (!threadStopRequest) {   // loop until asked to stop)
245                // any input?
246                try {
247                    // get content; blocks until present
248                    log.trace("check for input"); // NOI18N
249
250                    byte msg[] = xmtList.take();
251
252                    // input - now send
253                    try {
254                        if (ostream != null) {
255                            if (!controller.okToSend()) {
256                                log.debug("LocoNet port not ready to receive"); // NOI18N
257                            }
258                            log.debug("start write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
259                            // get it started
260                            reTryRequired = true;
261                            int reTryCount = 0;
262                            while (reTryRequired) {
263                                // assert its going to work
264                                reTryRequired = false;
265                                waitForMsg = new LocoNetMessage(msg);
266                                if ((msg[0] & 0x08) != 0) {
267                                    waitingOnLack = true;
268                                }
269                                while (waitBusy != 0) {
270                                    // we do it this way as during our sleep the waitBusy time can be reset
271                                    int waitTime = waitBusy;
272                                    waitBusy = 0;
273                                    //    log.debug("waitBusy");
274                                    // for now so we know how prevalent this is over a long time span
275                                    log.warn("Waitbusy");
276                                    try {
277                                        Thread.sleep(waitTime);
278                                    } catch (InterruptedException ee) {
279                                        log.warn("waitBusy sleep Interrupted", ee); // NOI18N
280                                    }
281                                }
282                                ostream.write(msg);
283                                ostream.flush();
284                                log.trace("end write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
285                                // loop waiting for echo message and or LACK
286                                // minimal sleeps so as to exit fast
287                                waitCount = 0;
288                                // echo as really fast
289                                while ((waitForMsg != null) && waitCount < maxWaitCount) {
290                                    try {
291                                        Thread.sleep(1);
292                                    } catch (InterruptedException ee) {
293                                        log.error("waitForMsg sleep Interrupted", ee); // NOI18N
294                                    }
295                                    waitCount++;
296                                }
297                                // Oh my lost the echo...
298                                if (waitCount >= maxWaitCount) {
299                                    log.warn("Retry Send for Lost Packet [{}] Count[{}]", waitForMsg,
300                                                reTryCount); // NOI18N
301                                    if (reTryCount < 5) {
302                                        reTryRequired = true;
303                                        reTryCount++;
304                                    } else {
305                                        reTryRequired = false;
306                                        reTryCount = 0;
307                                        log.warn("Give up on lost packet");
308                                    }
309                                } else {
310                                    // LACKs / a response can be slow
311                                    while (waitingOnLack && waitCount < 3*maxWaitCount) {
312                                        try {
313                                            Thread.sleep(1);
314                                        } catch (InterruptedException ee) {
315                                            log.error("waitingOnLack sleep Interrupted", ee); // NOI18N
316                                        }
317                                        waitCount++;
318                                    }
319                                    // Oh my lost the LACK / response...
320                                    if (waitCount >= 3*maxWaitCount) {
321                                        try {
322                                            log.warn("Retry Send for Lost Response Count[{}]", reTryCount); // NOI18N
323                                        } catch (NullPointerException npe) {
324                                            log.warn("Retry Send for waitingOnLack null?  Count[{}]", reTryCount); // NOI18N
325                                        }
326                                        if (reTryCount < 5) {
327                                            reTryRequired = true;
328                                            reTryCount++;
329                                        } else {
330                                            log.warn("Give up on Lost Response."); // NOI18N
331                                            reTryRequired = false;
332                                            reTryCount = 0;
333                                        }
334                                    }
335                                }
336                            }
337                            messageTransmitted(msg);
338                        } else {
339                            // no stream connected
340                            log.warn("sendLocoNetMessage: no connection established"); // NOI18N
341                        }
342                    } catch (java.io.IOException e) {
343                        log.warn("sendLocoNetMessage: IOException: {}", e.toString()); // NOI18N
344                        if (controller.getAllowConnectionRecovery()) {
345                            log.info("run: server closed connection, attempting recovery");
346                            controller.closePort();
347                            controller.recover();
348                        }
349                    }
350                } catch (InterruptedException ie) {
351                    return; // ending the thread
352                } catch (RuntimeException rt) {
353                    log.error("Exception on take() call", rt);
354                }
355            }
356        }
357    }
358
359
360    /**
361     * Invoked at startup to start the threads needed here.
362     */
363    @Override
364    public void startThreads() {
365        int priority = Thread.currentThread().getPriority();
366        log.debug("startThreads current priority = {} max available = {} default = {} min available = {}", // NOI18N
367                priority, Thread.MAX_PRIORITY, Thread.NORM_PRIORITY, Thread.MIN_PRIORITY);
368
369        // make sure that the xmt priority is no lower than the current priority
370        int xmtpriority = (Thread.MAX_PRIORITY - 1 > priority ? Thread.MAX_PRIORITY - 1 : Thread.MAX_PRIORITY);
371        // start the XmtHandler in a thread of its own
372        if (xmtHandler == null) {
373            xmtHandler = new XmtHandlerStrict();
374        }
375        xmtThread = jmri.util.ThreadingUtil.newThread(xmtHandler, "LocoNet transmit handler"); // NOI18N
376        log.debug("Xmt thread starts at priority {}", xmtpriority); // NOI18N
377        xmtThread.setDaemon(true);
378        xmtThread.setPriority(Thread.MAX_PRIORITY - 1);
379        xmtThread.start();
380
381        // start the RcvHandler in a thread of its own
382        if (rcvHandler == null) {
383            rcvHandler = new RcvHandlerStrict(this);
384        }
385        rcvThread = jmri.util.ThreadingUtil.newThread(rcvHandler, "LocoNet receive handler"); // NOI18N
386        rcvThread.setDaemon(true);
387        rcvThread.setPriority(Thread.MAX_PRIORITY);
388        rcvThread.start();
389
390        log.info("Strict Packetizer in use");
391
392    }
393
394    private static final Logger log = LoggerFactory.getLogger(LnPacketizerStrict.class);
395
396}