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    static public 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 (true) {  // loop permanently, program close will exit
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                    if (log.isTraceEnabled()) {
079                        log.trace(" (RcvHandler) Start message with opcode: {}", Integer.toHexString(opCode)); // NOI18N
080                    }
081                    LocoNetMessage msg = null;
082                    while (msg == null) {
083                        try {
084                            // Capture 2nd byte, always present
085                            int byte2 = readByteProtected(istream) & 0xFF;
086                            if (log.isTraceEnabled()) {
087                                log.trace("Byte2: {}", Integer.toHexString(byte2)); // NOI18N
088                            }   // Decide length
089                            int len = 2;
090                            switch ((opCode & 0x60) >> 5) {
091                                case 0:
092                                    /* 2 byte message */
093                                    len = 2;
094                                    break;
095                                case 1:
096                                    /* 4 byte message */
097                                    len = 4;
098                                    break;
099                                case 2:
100                                    /* 6 byte message */
101                                    len = 6;
102                                    break;
103                                case 3:
104                                    /* N byte message */
105                                    if (byte2 < 2) {
106                                        log.error("LocoNet message length invalid: {} opcode: {}",
107                                                byte2, Integer.toHexString(opCode)); // NOI18N
108                                    }
109                                    len = byte2;
110                                    break;
111                                default:
112                                    log.warn("Unhandled code: {}", (opCode & 0x60) >> 5);
113                                    break;
114                            }
115                            msg = new LocoNetMessage(len);
116                            // message exists, now fill it
117                            msg.setOpCode(opCode);
118                            msg.setElement(1, byte2);
119                            log.trace("len: {}", len); // NOI18N
120                            for (int i = 2; i < len; i++) {
121                                // check for message-blocking error
122                                int b = readByteProtected(istream) & 0xFF;
123                                if (log.isTraceEnabled()) {
124                                    log.trace("char {} is: {}", i, Integer.toHexString(b)); // NOI18N
125                                }
126                                if ((b & 0x80) != 0) {
127                                    log.warn("LocoNet message with opCode: {} ended early. Expected length: {} seen length: {} unexpected byte: {}", Integer.toHexString(opCode), len, i, Integer.toHexString(b)); // NOI18N
128                                    opCode = b;
129                                    throw new LocoNetMessageException();
130                                }
131                                msg.setElement(i, b);
132                            }
133                        } catch (LocoNetMessageException e) {
134                            // retry by destroying the existing message
135                            // opCode is set for the newly-started packet
136                            msg = null;
137                        }
138                    }
139                    // check parity
140                    if (!msg.checkParity()) {
141                        log.warn("Ignore LocoNet packet with bad checksum: [{}]", msg.toString());  // NOI18N
142                        throw new LocoNetMessageException();
143                    }
144                    // message is complete, dispatch it !!
145                    {
146                        if (log.isDebugEnabled()) { // avoid String building if not needed
147                            log.debug("queue message for notification: {}", msg.toString());  // NOI18N
148                        }
149                        // check for XmtHandler waiting on return values
150                        if (waitForMsg != null) {
151                            if (waitForMsg.equals(msg)) {
152                                waitForMsg = null;
153                            }
154                        }
155                        if (waitingOnLack) {
156                            if (msg.getOpCode() == LnConstants.OPC_LONG_ACK) {
157                                waitingOnLack = false;
158                                // check bad IMM
159                                if ((msg.getElement(1) & 0xff) == 0x6d && (msg.getElement(2) & 0xff) == 0) {
160                                    reTryRequired = true;
161                                    waitBusy = 100;
162                                    log.warn("IMM Back off");  // NOI18N
163                                } else {
164                                    reTryRequired = false;
165                                }
166                            } else if (msg.getOpCode() == LnConstants.OPC_SL_RD_DATA) {
167                                waitingOnLack = false;
168                            } else if ( msg.getOpCode() == LnConstants.OPC_ALM_READ ) { // Extended slot status
169                                waitingOnLack = false;
170                            }
171                            // check for CS busy
172                        } else if (msg.getOpCode() == LnConstants.OPC_GPBUSY) {
173                            waitBusy = 100;
174                            log.warn("CS Busy Back off");  // NOI18N
175                            reTryRequired = true;
176                            // check for waiting on echo
177                        }
178                        jmri.util.ThreadingUtil.runOnLayoutEventually(new RcvMemo(msg, trafficController));
179                    }
180                    // done with this one
181                } catch (LocoNetMessageException e) {
182                    // just let it ride for now
183                    log.warn("run: unexpected LocoNetMessageException", e); // NOI18N
184                } catch (java.io.EOFException e) {
185                    // posted from idle port when enableReceiveTimeout used
186                    log.trace("EOFException, is LocoNet serial I/O using timeouts?"); // NOI18N
187                } catch (java.io.IOException e) {
188                    // fired when write-end of HexFile reaches end
189                    log.debug("IOException, should only happen with HexFile", e); // NOI18N
190                    log.info("End of file"); // NOI18N
191                    disconnectPort(controller);
192                    return;
193                } // normally, we don't catch RuntimeException, but in this
194                // permanently running loop it seems wise.
195                catch (RuntimeException e) {
196                    log.warn("run: unexpected Exception", e); // NOI18N
197                }
198            } // end of permanent loop
199        }
200    }
201
202    /**
203     * Captive class to notify of one message
204     */
205    private static class RcvMemo implements jmri.util.ThreadingUtil.ThreadAction {
206
207        public RcvMemo(LocoNetMessage msg, LnTrafficController trafficController) {
208            thisMsg = msg;
209            thisTc = trafficController;
210        }
211        LocoNetMessage thisMsg;
212        LnTrafficController thisTc;
213
214        /**
215         * {@inheritDoc}
216         */
217        @Override
218        public void run() {
219            thisTc.notify(thisMsg);
220        }
221    }
222
223    /**
224     * Captive class to handle transmission
225     */
226    class XmtHandlerStrict implements Runnable {
227
228        /**
229         * {@inheritDoc}
230         */
231        @Override
232        public void run() {
233            int waitCount;
234            while (true) { // loop permanently
235                // any input?
236                try {
237                    // get content; blocks until present
238                    log.trace("check for input"); // NOI18N
239
240                    byte msg[] = xmtList.take();
241
242                    // input - now send
243                    try {
244                        if (ostream != null) {
245                            if (!controller.okToSend()) {
246                                log.debug("LocoNet port not ready to receive"); // NOI18N
247                            }
248                            if (log.isDebugEnabled()) { // avoid String building if not needed
249                                log.debug("start write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
250                            }
251                            // get it started
252                            reTryRequired = true;
253                            int reTryCount = 0;
254                            while (reTryRequired) {
255                                // assert its going to work
256                                reTryRequired = false;
257                                waitForMsg = new LocoNetMessage(msg);
258                                if ((msg[0] & 0x08) != 0) {
259                                    waitingOnLack = true;
260                                }
261                                while (waitBusy != 0) {
262                                    // we do it this way as during our sleep the waitBusy time can be reset
263                                    int waitTime = waitBusy;
264                                    waitBusy = 0;
265                                    //if (log.isDebugEnabled()) {
266                                    //    log.debug("waitBusy");
267                                    //}
268                                    // for now so we know how prevalent this is over a long time span
269                                    log.warn("Waitbusy");
270                                    try {
271                                        Thread.sleep(waitTime);
272                                    } catch (InterruptedException ee) {
273                                        log.warn("waitBusy sleep Interrupted", ee); // NOI18N
274                                    }
275                                }
276                                ostream.write(msg);
277                                ostream.flush();
278                                if (log.isTraceEnabled()) {
279                                    log.trace("end write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
280                                }
281                                // loop waiting for echo message and or LACK
282                                // minimal sleeps so as to exit fast
283                                waitCount = 0;
284                                // echo as really fast
285                                while ((waitForMsg != null) && waitCount < maxWaitCount) {
286                                    try {
287                                        Thread.sleep(1);
288                                    } catch (InterruptedException ee) {
289                                        log.error("waitForMsg sleep Interrupted", ee); // NOI18N
290                                    }
291                                    waitCount++;
292                                }
293                                // Oh my lost the echo...
294                                if (waitCount >= maxWaitCount) {
295                                    log.warn("Retry Send for Lost Packet [{}] Count[{}]", waitForMsg,
296                                                reTryCount); // NOI18N
297                                    if (reTryCount < 5) {
298                                        reTryRequired = true;
299                                        reTryCount++;
300                                    } else {
301                                        reTryRequired = false;
302                                        reTryCount = 0;
303                                        log.warn("Give up on lost packet");
304                                    }
305                                } else {
306                                    // LACKs / a response can be slow
307                                    while (waitingOnLack && waitCount < 3*maxWaitCount) {
308                                        try {
309                                            Thread.sleep(1);
310                                        } catch (InterruptedException ee) {
311                                            log.error("waitingOnLack sleep Interrupted", ee); // NOI18N
312                                        }
313                                        waitCount++;
314                                    }
315                                    // Oh my lost the LACK / response...
316                                    if (waitCount >= 3*maxWaitCount) {
317                                        try {
318                                            log.warn("Retry Send for Lost Response Count[{}]", reTryCount); // NOI18N
319                                        } catch (NullPointerException npe) {
320                                            log.warn("Retry Send for waitingOnLack null?  Count[{}]", reTryCount); // NOI18N
321                                        }
322                                        if (reTryCount < 5) {
323                                            reTryRequired = true;
324                                            reTryCount++;
325                                        } else {
326                                            log.warn("Give up on Lost Response."); // NOI18N
327                                            reTryRequired = false;
328                                            reTryCount = 0;
329                                        }
330                                    }
331                                }
332                            }
333                            messageTransmitted(msg);
334                        } else {
335                            // no stream connected
336                            log.warn("sendLocoNetMessage: no connection established"); // NOI18N
337                        }
338                    } catch (java.io.IOException e) {
339                        log.warn("sendLocoNetMessage: IOException: {}", e.toString()); // NOI18N
340                    }
341                } catch (InterruptedException ie) {
342                    return; // ending the thread
343                }
344            }
345        }
346    }
347
348
349    /**
350     * Invoked at startup to start the threads needed here.
351     */
352    @Override
353    public void startThreads() {
354        int priority = Thread.currentThread().getPriority();
355        log.debug("startThreads current priority = {} max available = {} default = {} min available = {}", // NOI18N
356                priority, Thread.MAX_PRIORITY, Thread.NORM_PRIORITY, Thread.MIN_PRIORITY);
357
358        // make sure that the xmt priority is no lower than the current priority
359        int xmtpriority = (Thread.MAX_PRIORITY - 1 > priority ? Thread.MAX_PRIORITY - 1 : Thread.MAX_PRIORITY);
360        // start the XmtHandler in a thread of its own
361        if (xmtHandler == null) {
362            xmtHandler = new XmtHandlerStrict();
363        }
364        xmtThread = new Thread(xmtHandler, "LocoNet transmit handler"); // NOI18N
365        log.debug("Xmt thread starts at priority {}", xmtpriority); // NOI18N
366        xmtThread.setDaemon(true);
367        xmtThread.setPriority(Thread.MAX_PRIORITY - 1);
368        xmtThread.start();
369
370        // start the RcvHandler in a thread of its own
371        if (rcvHandler == null) {
372            rcvHandler = new RcvHandlerStrict(this);
373        }
374        rcvThread = new Thread(rcvHandler, "LocoNet receive handler"); // NOI18N
375        rcvThread.setDaemon(true);
376        rcvThread.setPriority(Thread.MAX_PRIORITY);
377        rcvThread.start();
378
379        log.info("Strict Packetizer in use");
380
381    }
382
383    private final static Logger log = LoggerFactory.getLogger(LnPacketizerStrict.class);
384
385}