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