001package jmri.jmrix.dcc4pc; 002 003import java.beans.PropertyChangeListener; 004import java.util.List; 005import javax.annotation.CheckForNull; 006import javax.annotation.Nonnull; 007import jmri.RailCom; 008import jmri.AddressedProgrammer; 009import jmri.AddressedProgrammerManager; 010import jmri.CommandStation; 011import jmri.NmraPacket; 012import jmri.ProgListener; 013import jmri.Programmer; 014import jmri.ProgrammerException; 015import jmri.ProgrammingMode; 016 017/** 018 * Provides an Ops mode proxy programming interface for a RailCom Reader. This 019 * forwards the read request to the command station to forward on and handles 020 * sending back the CV reading results from the RailCom message 021 * <p> 022 * A read sends the POM read packet through the other connection's command 023 * station, and waits only for the decoder's RailCom reply, decoded by the 024 * reader. It doesn't use that connection's own ops-mode read: a command 025 * station that can't read RailCom keeps its programmer busy for seconds after 026 * each read, waiting for a value it will never get. 027 * <p> 028 * Packets are paced: each is handed to the command station only once it has 029 * had time to send the last one with its repeats, because a LocoNet command 030 * station drops a packet it's given while still busy, without telling 031 * sendPacket. A packet with no reply is sent again every RETRY_AFTER, up to 032 * MAX_SENDS times in all. 033 * Resending every second instead (2026-10-13) built a backlog the command 034 * station was still working through 20 s later. 035 * <p> 036 * Without a command station, the read goes through the other connection's 037 * programmer instead, and finishes with the first value that arrives: the 038 * RailCom reply, or the value that programmer reads back. 039 * <p> 040 * A write is sent the same way. The decoder answers a POM write with the 041 * value it then holds, so the write is done when that matches; if it never 042 * does, the write ends with ConfirmFailed. Without a command station, the 043 * other connection's programmer does the write and reports the result. 044 * 045 * @see jmri.Programmer 046 * @author Kevin Dickerson Copyright (C) 2012 047 */ 048public class Dcc4PcOpsModeProgrammer extends jmri.jmrix.AbstractProgrammer implements PropertyChangeListener, AddressedProgrammer { 049 050 int pAddress = 0; 051 boolean pLongAddress; 052 RailCom rcTag; 053 int cv; 054 jmri.ProgListener progListener = null; 055 056 /** True while a read or confirm is waiting for its value. */ 057 boolean awaitingValue = false; 058 059 /** 060 * Longest a read waits when it goes through the other connection's 061 * programmer (no command station to send the packets ourselves). 062 */ 063 static final int READ_TIMEOUT = 5000; 064 065 /** 066 * Longest a read or write waits when we send the POM packets: time for 067 * the last of the {@link #MAX_SENDS} sends to be answered (answers come 068 * 160-270 ms after a send). With 5 s, the few CVs that got no answer at 069 * all took 40% of a Read All (2026-10-16). 070 */ 071 static final int RAILCOM_TIMEOUT = 2600; 072 073 /** 074 * How many times the command station sends a POM read packet. A decoder 075 * may need a moment to fetch the value, and then sends it in later 076 * cutouts; only one that follows the read packet itself can be matched to 077 * the CV, so it helps if the packet is still being repeated by then. 078 */ 079 static final int READ_REPEATS = 4; 080 081 /** 082 * How many times the command station sends a POM write packet. A decoder 083 * only writes after two identical write packets in a row. 084 */ 085 static final int WRITE_REPEATS = 4; 086 087 /** 088 * Time to leave per repeat before handing the command station another 089 * packet. A LocoNet command station drops a packet it's given while still 090 * sending the last one (it answers "busy", which sendPacket doesn't 091 * report), so on 2026-10-13 every write sent straight after another was 092 * lost. This is an estimate: about one DCC packet per repeat, with room 093 * for the command station's own refresh traffic. 094 * <p> 095 * 2026-10-15: 150 ms made no difference to how many sends went 096 * unanswered, so the losses aren't the command station being busy. 097 */ 098 static final long GAP_PER_REPEAT = 60; 099 100 /** 101 * If no reply has come after this long, the packet is sent once more, in 102 * case it or its answer was lost. Answers normally come 160-270 ms after 103 * the send (2026-10-15); 1500 ms made each lost one cost far more than 104 * the answer itself. 105 */ 106 static final int RETRY_AFTER = 600; 107 108 /** How many times a packet is sent in all while no answer comes, RETRY_AFTER apart. */ 109 static final int MAX_SENDS = 4; 110 111 /** Earliest time any DCC4PC programmer may hand the command station its next packet. */ 112 private static long nextSendAllowed = 0; 113 114 /** Counts operations, so a delayed send or retry from an earlier one is dropped. */ 115 private int operation = 0; 116 117 AddressedProgrammerManager defaultManager; 118 Programmer defaultProgrammer; 119 /** Sends the POM packets; null to go through defaultProgrammer instead. */ 120 final CommandStation commandStation; 121 122 public Dcc4PcOpsModeProgrammer(boolean pLongAddress, int pAddress, AddressedProgrammerManager dp) { 123 this(pLongAddress, pAddress, dp, null); 124 } 125 126 /** 127 * @param pLongAddress true for a long address 128 * @param pAddress the loco's address 129 * @param dp the other connection's programmer manager, for writes 130 * @param cs the other connection's command station, which sends 131 * the POM read packets; null to read through the 132 * programmer instead 133 */ 134 public Dcc4PcOpsModeProgrammer(boolean pLongAddress, int pAddress, AddressedProgrammerManager dp, 135 @CheckForNull CommandStation cs) { 136 defaultManager = dp; 137 defaultProgrammer = defaultManager.getAddressedProgrammer(pLongAddress, pAddress); 138 commandStation = cs; 139 this.pAddress = pAddress; 140 this.pLongAddress = pLongAddress; 141 LONG_TIMEOUT = cs != null ? RAILCOM_TIMEOUT : READ_TIMEOUT; 142 rcTag = (RailCom) jmri.InstanceManager.getDefault(jmri.RailComManager.class).provideIdTag("" + pAddress); 143 } 144 145 /** 146 * The NMRA ops-mode "verify byte" packet (S-9.2.1 long-form CV access, 147 * instruction 1110 01VV), which a RailCom decoder answers with the CV's 148 * value on channel 2. The data byte doesn't matter for a read. 149 * 150 * @param address the loco's address 151 * @param longAddr true for a long address 152 * @param cvNum the CV, 1 to 1024 153 * @return the packet, as {@link NmraPacket} builds it for 154 * {@link CommandStation#sendPacket}, or empty if the address or CV is invalid 155 */ 156 @Nonnull 157 static byte[] pomReadPacket(int address, boolean longAddr, int cvNum) { 158 if (cvNum < 1 || cvNum > 1024) { 159 return new byte[0]; 160 } 161 int instruction = 0xE4 | (((cvNum - 1) >> 8) & 0x03); 162 byte[] packet = NmraPacket.threeBytePacket(address, longAddr, (byte) instruction, (byte) ((cvNum - 1) & 0xFF), (byte) 0); 163 return packet == null ? new byte[0] : packet; 164 } 165 166 /** 167 * The value being written, or -1 for a read. A decoder answers a POM 168 * write with the value it then holds, so the write is done when that 169 * matches. 170 */ 171 int writeValue = -1; 172 173 /** The last value a write was answered with, or -1 for none yet. */ 174 int lastWriteReply = -1; 175 176 /** 177 * {@inheritDoc} 178 * 179 * The POM write packet goes out through the command station, and the 180 * write is done when the decoder's RailCom reply shows the new value. 181 * Without a command station, the other connection's programmer does the 182 * write and reports the result. 183 */ 184 @Override 185 synchronized public void writeCV(String CVname, int val, ProgListener p) throws ProgrammerException { 186 if (commandStation == null) { 187 progListener = p; 188 defaultProgrammer.setMode(getMode()); 189 defaultProgrammer.writeCV(CVname, val, (value, status) -> finishWrite(value, status)); 190 return; 191 } 192 byte[] packet = NmraPacket.opsCvWriteByte(pAddress, pLongAddress, Integer.parseInt(CVname), val); 193 if (packet == null) { 194 throw new ProgrammerException("Can't write CV " + CVname + " of " + getAddress()); 195 } 196 start(CVname, p, val); 197 send(packet, WRITE_REPEATS); 198 } 199 200 private synchronized void finishWrite(int value, int status) { 201 ProgListener l = progListener; 202 progListener = null; 203 notifyProgListenerEnd(l, value, status); 204 } 205 206 /** 207 * {@inheritDoc} 208 */ 209 @Override 210 synchronized public void readCV(String CVname, ProgListener p) throws ProgrammerException { 211 if (commandStation == null) { 212 start(CVname, p, -1); 213 defaultProgrammer.readCV(CVname, (value, status) -> commandStationReplied(value, status)); 214 return; 215 } 216 byte[] packet = pomReadPacket(pAddress, pLongAddress, Integer.parseInt(CVname)); 217 if (packet.length == 0) { 218 throw new ProgrammerException("Can't read CV " + CVname + " of " + getAddress()); 219 } 220 start(CVname, p, -1); 221 send(packet, READ_REPEATS); 222 } 223 224 /** 225 * Hand the packet to the command station once it has had time to finish 226 * the last one, and again every RETRY_AFTER while no reply has come, up 227 * to MAX_SENDS sends in all. Must be called while the operation is 228 * waiting for its reply. 229 */ 230 private void send(byte[] packet, int repeats) { 231 int op = operation; 232 sendPaced(packet, repeats, op); 233 scheduleResend(packet, repeats, op, 2); 234 } 235 236 private void scheduleResend(byte[] packet, int repeats, int op, int sendNumber) { 237 if (sendNumber > MAX_SENDS) { 238 return; 239 } 240 jmri.util.TimerUtil.scheduleOnLayoutThread(new java.util.TimerTask() { 241 @Override 242 public void run() { 243 if (isWaiting(op)) { 244 log.debug("No reply yet for CV {} of {}; sending again ({} of {})", cv, pAddress, sendNumber, MAX_SENDS); 245 sendPaced(packet, repeats, op); 246 scheduleResend(packet, repeats, op, sendNumber + 1); 247 } 248 } 249 }, RETRY_AFTER); 250 } 251 252 /** For tests: forget the pacing left by earlier sends. */ 253 static synchronized void resetPacing() { 254 nextSendAllowed = 0; 255 } 256 257 private synchronized boolean isWaiting(int op) { 258 return awaitingValue && operation == op; 259 } 260 261 private void sendPaced(byte[] packet, int repeats, int op) { 262 long delay; 263 synchronized (Dcc4PcOpsModeProgrammer.class) { 264 long now = System.currentTimeMillis(); 265 long sendAt = Math.max(now, nextSendAllowed); 266 nextSendAllowed = sendAt + repeats * GAP_PER_REPEAT; 267 delay = sendAt - now; 268 } 269 if (delay == 0) { 270 log.debug("Sent CV {} of {} x{}", cv, pAddress, repeats); 271 commandStation.sendPacket(packet, repeats); 272 return; 273 } 274 jmri.util.TimerUtil.scheduleOnLayoutThread(new java.util.TimerTask() { 275 @Override 276 public void run() { 277 if (isWaiting(op)) { 278 log.debug("Sent CV {} of {} x{} after {} ms pacing", cv, pAddress, repeats, delay); 279 commandStation.sendPacket(packet, repeats); 280 } 281 } 282 }, delay); 283 } 284 285 /** 286 * {@inheritDoc} 287 * 288 * Reads the CV and lets the listener know whether it matches. The command 289 * station's own confirm can't be used: it may only report that it sent 290 * the packets. 291 */ 292 @Override 293 public synchronized void confirmCV(String cvName, int val, ProgListener p) throws ProgrammerException { 294 readCV(cvName, (value, status) -> { 295 if (status == ProgListener.OK && value != val) { 296 status = ProgListener.ConfirmFailed; 297 } 298 if (p != null) { 299 p.programmingOpReply(value, status); 300 } 301 }); 302 } 303 304 /** 305 * Start waiting for the decoder's RailCom reply for a CV. 306 * 307 * @param CVname the CV 308 * @param p told the result 309 * @param value the value being written, or -1 for a read 310 */ 311 private void start(String CVname, ProgListener p, int value) { 312 cv = Integer.parseInt(CVname); 313 progListener = p; 314 writeValue = value; 315 lastWriteReply = -1; 316 operation++; 317 awaitingValue = true; 318 rcTag.addPropertyChangeListener(this); 319 rcTag.setExpectedCv(cv); 320 startLongTimer(); 321 defaultProgrammer.setMode(getMode()); 322 log.debug("{} CV {} of {}", value < 0 ? "Read" : "Write " + value + " to", cv, pAddress); 323 } 324 325 /** The command station's connection has answered the read. */ 326 private void commandStationReplied(int value, int status) { 327 if (status == ProgListener.OK) { 328 log.debug("CV {} = {}, read by the command station", cv, value); 329 finishRead(value, ProgListener.OK); 330 } else { 331 // keep waiting: the RailCom reply comes through the reader, not the command station 332 log.debug("Command station could not read CV {} (status {}); waiting for RailCom", cv, status); 333 } 334 } 335 336 /** End the operation, once, whichever of the RailCom reply, the command station and the timer comes first. */ 337 private synchronized void finishRead(int value, int status) { 338 if (!awaitingValue) { 339 return; 340 } 341 awaitingValue = false; 342 log.debug("CV {} of {} finished: value {} status {}", cv, pAddress, value, status); 343 stopTimer(); 344 rcTag.removePropertyChangeListener(this); 345 rcTag.setExpectedCv(-1); 346 ProgListener l = progListener; 347 progListener = null; 348 notifyProgListenerEnd(l, value, status); 349 } 350 351 /** 352 * {@inheritDoc} 353 * 354 * Types implemented here. 355 */ 356 @Override 357 @Nonnull 358 public List<ProgrammingMode> getSupportedModes() { 359 return defaultProgrammer.getSupportedModes(); 360 } 361 362 /** 363 * {@inheritDoc} 364 */ 365 @Override 366 synchronized protected void timeout() { 367 if (writeValue >= 0 && lastWriteReply >= 0) { 368 log.warn("CV {} of {} still reads {} after writing {}", cv, pAddress, lastWriteReply, writeValue); 369 finishRead(lastWriteReply, ProgListener.ConfirmFailed); 370 } else { 371 log.debug("No RailCom reply for CV {} within {} ms", cv, LONG_TIMEOUT); 372 finishRead(0, ProgListener.FailedTimeout); 373 } 374 } 375 376 /** 377 * {@inheritDoc} 378 * 379 * The loco's RailCom tag has a POM reply for the CV being read or 380 * written. 381 */ 382 @Override 383 public synchronized void propertyChange(java.beans.PropertyChangeEvent e) { 384 if (!"cvvalue".equals(e.getPropertyName()) || !awaitingValue) { 385 return; 386 } 387 int repliedCv = (Integer) e.getOldValue(); 388 int newValue = (Integer) e.getNewValue(); 389 if (repliedCv != cv) { 390 // normal: the command station keeps repeating earlier POM packets 391 log.debug("RailCom reply for CV {} while waiting for CV {}; ignored", repliedCv, cv); 392 } else if (writeValue < 0 || newValue == writeValue) { 393 log.debug("CV {} = {}, from RailCom", repliedCv, newValue); 394 finishRead(newValue, ProgListener.OK); 395 } else { 396 // the reply may have come before the write took effect: wait for the next one 397 log.debug("CV {} reads {} while writing {}; waiting", cv, newValue, writeValue); 398 lastWriteReply = newValue; 399 rcTag.setExpectedCv(cv); // the tag only delivers one value per expected CV 400 } 401 } 402 403 /** 404 * {@inheritDoc} 405 */ 406 @Override 407 public boolean getLongAddress() { 408 return pLongAddress; 409 } 410 411 /** 412 * {@inheritDoc} 413 */ 414 @Override 415 public int getAddressNumber() { 416 return pAddress; 417 } 418 419 /** 420 * {@inheritDoc} 421 */ 422 @Override 423 public String getAddress() { 424 return "" + getAddressNumber() + " " + getLongAddress(); 425 } 426 427 // initialize logging 428 private static final org.slf4j.Logger log = org.slf4j.LoggerFactory.getLogger(Dcc4PcOpsModeProgrammer.class); 429 430}