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 (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                    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.EOFException | java.io.InterruptedIOException e) {
188                    // posted from idle port when enableReceiveTimeout used
189                    // Normal condition, go around the loop again
190                    continue;
191                } catch (java.io.IOException e) {
192                    // fired when write-end of HexFile reaches end
193                    log.debug("IOException, should only happen with HexFile", e); // NOI18N
194                    log.info("End of file"); // NOI18N
195                    disconnectPort(controller);
196                    return;
197                } catch (RuntimeException e) {
198                    // normally, we don't catch RuntimeException, but in this
199                    // permanently running loop it seems wise.
200                    log.warn("run: unexpected Exception", e); // NOI18N
201                    continue;
202                }
203            } // end of permanent loop
204        }
205    }
206
207    /**
208     * Captive class to notify of one message
209     */
210    private static class RcvMemo implements jmri.util.ThreadingUtil.ThreadAction {
211
212        public RcvMemo(LocoNetMessage msg, LnTrafficController trafficController) {
213            thisMsg = msg;
214            thisTc = trafficController;
215        }
216        LocoNetMessage thisMsg;
217        LnTrafficController thisTc;
218
219        /**
220         * {@inheritDoc}
221         */
222        @Override
223        public void run() {
224            thisTc.notify(thisMsg);
225        }
226    }
227
228    /**
229     * Captive class to handle transmission
230     */
231    class XmtHandlerStrict implements Runnable {
232
233        /**
234         * {@inheritDoc}
235         */
236        @Override
237        public void run() {
238            int waitCount;
239            while (true) { // loop permanently
240                // any input?
241                try {
242                    // get content; blocks until present
243                    log.trace("check for input"); // NOI18N
244
245                    byte msg[] = xmtList.take();
246
247                    // input - now send
248                    try {
249                        if (ostream != null) {
250                            if (!controller.okToSend()) {
251                                log.debug("LocoNet port not ready to receive"); // NOI18N
252                            }
253                            log.debug("start write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
254                            // get it started
255                            reTryRequired = true;
256                            int reTryCount = 0;
257                            while (reTryRequired) {
258                                // assert its going to work
259                                reTryRequired = false;
260                                waitForMsg = new LocoNetMessage(msg);
261                                if ((msg[0] & 0x08) != 0) {
262                                    waitingOnLack = true;
263                                }
264                                while (waitBusy != 0) {
265                                    // we do it this way as during our sleep the waitBusy time can be reset
266                                    int waitTime = waitBusy;
267                                    waitBusy = 0;
268                                    //    log.debug("waitBusy");
269                                    // for now so we know how prevalent this is over a long time span
270                                    log.warn("Waitbusy");
271                                    try {
272                                        Thread.sleep(waitTime);
273                                    } catch (InterruptedException ee) {
274                                        log.warn("waitBusy sleep Interrupted", ee); // NOI18N
275                                    }
276                                }
277                                ostream.write(msg);
278                                ostream.flush();
279                                log.trace("end write to stream: {}", jmri.util.StringUtil.hexStringFromBytes(msg)); // NOI18N
280                                // loop waiting for echo message and or LACK
281                                // minimal sleeps so as to exit fast
282                                waitCount = 0;
283                                // echo as really fast
284                                while ((waitForMsg != null) && waitCount < maxWaitCount) {
285                                    try {
286                                        Thread.sleep(1);
287                                    } catch (InterruptedException ee) {
288                                        log.error("waitForMsg sleep Interrupted", ee); // NOI18N
289                                    }
290                                    waitCount++;
291                                }
292                                // Oh my lost the echo...
293                                if (waitCount >= maxWaitCount) {
294                                    log.warn("Retry Send for Lost Packet [{}] Count[{}]", waitForMsg,
295                                                reTryCount); // NOI18N
296                                    if (reTryCount < 5) {
297                                        reTryRequired = true;
298                                        reTryCount++;
299                                    } else {
300                                        reTryRequired = false;
301                                        reTryCount = 0;
302                                        log.warn("Give up on lost packet");
303                                    }
304                                } else {
305                                    // LACKs / a response can be slow
306                                    while (waitingOnLack && waitCount < 3*maxWaitCount) {
307                                        try {
308                                            Thread.sleep(1);
309                                        } catch (InterruptedException ee) {
310                                            log.error("waitingOnLack sleep Interrupted", ee); // NOI18N
311                                        }
312                                        waitCount++;
313                                    }
314                                    // Oh my lost the LACK / response...
315                                    if (waitCount >= 3*maxWaitCount) {
316                                        try {
317                                            log.warn("Retry Send for Lost Response Count[{}]", reTryCount); // NOI18N
318                                        } catch (NullPointerException npe) {
319                                            log.warn("Retry Send for waitingOnLack null?  Count[{}]", reTryCount); // NOI18N
320                                        }
321                                        if (reTryCount < 5) {
322                                            reTryRequired = true;
323                                            reTryCount++;
324                                        } else {
325                                            log.warn("Give up on Lost Response."); // NOI18N
326                                            reTryRequired = false;
327                                            reTryCount = 0;
328                                        }
329                                    }
330                                }
331                            }
332                            messageTransmitted(msg);
333                        } else {
334                            // no stream connected
335                            log.warn("sendLocoNetMessage: no connection established"); // NOI18N
336                        }
337                    } catch (java.io.IOException e) {
338                        log.warn("sendLocoNetMessage: IOException: {}", e.toString()); // NOI18N
339                    }
340                } catch (InterruptedException ie) {
341                    return; // ending the thread
342                }
343            }
344        }
345    }
346
347
348    /**
349     * Invoked at startup to start the threads needed here.
350     */
351    @Override
352    public void startThreads() {
353        int priority = Thread.currentThread().getPriority();
354        log.debug("startThreads current priority = {} max available = {} default = {} min available = {}", // NOI18N
355                priority, Thread.MAX_PRIORITY, Thread.NORM_PRIORITY, Thread.MIN_PRIORITY);
356
357        // make sure that the xmt priority is no lower than the current priority
358        int xmtpriority = (Thread.MAX_PRIORITY - 1 > priority ? Thread.MAX_PRIORITY - 1 : Thread.MAX_PRIORITY);
359        // start the XmtHandler in a thread of its own
360        if (xmtHandler == null) {
361            xmtHandler = new XmtHandlerStrict();
362        }
363        xmtThread = jmri.util.ThreadingUtil.newThread(xmtHandler, "LocoNet transmit handler"); // NOI18N
364        log.debug("Xmt thread starts at priority {}", xmtpriority); // NOI18N
365        xmtThread.setDaemon(true);
366        xmtThread.setPriority(Thread.MAX_PRIORITY - 1);
367        xmtThread.start();
368
369        // start the RcvHandler in a thread of its own
370        if (rcvHandler == null) {
371            rcvHandler = new RcvHandlerStrict(this);
372        }
373        rcvThread = jmri.util.ThreadingUtil.newThread(rcvHandler, "LocoNet receive handler"); // NOI18N
374        rcvThread.setDaemon(true);
375        rcvThread.setPriority(Thread.MAX_PRIORITY);
376        rcvThread.start();
377
378        log.info("Strict Packetizer in use");
379
380    }
381
382    private static final Logger log = LoggerFactory.getLogger(LnPacketizerStrict.class);
383
384}