From 470c71dd93633d484525835de5bb438baa48f17e Mon Sep 17 00:00:00 2001 From: torque Date: Mon, 31 Jul 2023 23:27:56 -0700 Subject: [PATCH] spid: handle a control stream containing log packets I have an MD-01 controller running firmware 2.0.237 that is connected to the computer via the COM0 DB9 port. When it receives a control command to move the rotator, it prints debug logs to the serial output that look like this: input: W3600\x0A4500\x0A\x2F\x20 output: W\x03\x06\x00\x00\x0A\x04\x05\x01\x00\x0A\x20 287925671: in motion\r\n 287925673: Change motion state M0 to mcsStart\r\n 287925678: GO A 0.000000 0.000000 t ---\r\n 287925680: in motion\r\n 287925683: Change motion state M1 to mcsStart\r\n 287925686: GO E 90.000000 91.000000 t ---\r\n 287925690: distance to go M0 too small. End.\r\n 287925694: Change motion state M0 to mcsStopped\r\n 287925698: Stop on motor 0 on angle 0.000000\r\n 287925703: Change motion state M1 to mcsRunning\r\n 287926610: distance to go M1 too small. End.\r\n 287926613: Change motion state M1 to mcsStopped\r\n 287926617: Stop on motor 1 on angle 90.000000\r\n Note that the response frame is not necessarily present in an specific order relative to the log messages: I have seen it come after the logs as well. Because the current implementation just slurps up response bytes without checking the framing or anything, as soon as any of this log data enters the command stream, all subsequent commands will read completely bogus responses. Regardless of whether it's due to a misconfiguration, a weird artifact of the firmware, or something more sinister, the MD-01 is awkwardly interspersing its normal fixed-size-frame response with these line-based log messages. As shown above, the log messages appear to be consistently of the format : \r\n, where is some kind of integer timestamp (possibly relative to unit boot) and is an ASCII string. Due to poor(?) design decisions by the protocol designers, the frame start and end bytes are both printable ASCII characters ('W' and ' ' respectively) and the MD-01 response frame contains no other validation information (such as a CRC), which means that a valid log line could fairly easily contain a character sequence that is indistinguishable from a valid response frame, without actually being a valid response frame. However, since the log messages appear to be reasonably strictly structured, we can make a small number of assumptions that will allow us to reliably separate response frames from log lines without having to fall back on a heuristic-based parsing strategy. These assumptions are as follows: 1. A log line will always begin with an ASCII character in the range [0-9], none of which are the frame start byte. 2. A log line will never contain \r\n in the middle of the line (i.e. multi-line log messages do not exist). This means a log "frame" will always be of the form [0-9]\r\n. 3. The controller will not emit a response frame in the middle of a log line. 4. The operating system's serial port read buffer is large enough that we won't lose data while accumulating log messages between commands. Provided the above assumptions are true, a simple state machine can be used to parse the response by treating the log lines as a different type of frame. This could be made much more robust by applying additional heuristics for specific packets (e.g. get_position has some reasonably strict numerical bounds that could be used to sanity check the contents of the reply frame). --- rotators/spid/spid.c | 149 +++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 143 insertions(+), 6 deletions(-) diff --git a/rotators/spid/spid.c b/rotators/spid/spid.c index 072d019ca..fe46b5af1 100644 --- a/rotators/spid/spid.c +++ b/rotators/spid/spid.c @@ -39,6 +39,143 @@ struct spid_rot2prog_priv_data int el_resolution; }; +enum spid_rot2prog_framemagic { + ROT2PROG_FRAME_START_BYTE = 'W', + ROT2PROG_FRAME_END_BYTE = ' ', +}; + +enum r2p_frame_parser_state { + ROT2PROG_PARSER_EXPECT_FRAME_START, + ROT2PROG_PARSER_EXPECT_CR, + ROT2PROG_PARSER_EXPECT_LF, + ROT2PROG_PARSER_EXPECT_FRAME_END, +}; + +static int read_r2p_frame(hamlib_port_t *port, unsigned char *rxbuffer, + size_t count) +{ + // Some MD-01 firmware can apparently print debug messages to the same + // serial port that is used for the control protocol. This awkwardly + // intersperses the normal fixed-size frame response with a line-based + // logs. Theoretically, a valid response frame will not actually be emitted + // in the middle of a log message. + // + // Log messages are of the format : \r\n, where + // is a unix-ish timestamp (inasmuch as it is an integer) and + // is an ASCII string. + + // Due to poor(?) design decisions by the protocol designers, the frame + // start and end bytes are both printable ASCII characters ('W' and ' ' + // respectively) and the MD-01 response frame contains no other validation + // information (such as a CRC), which means that a valid log line can + // contain a character sequence that is indistinguishable from a valid + // response frame, without actually being a valid response frame. + + // However, since the log messages appear to be reasonably strictly + // structured, we can make a small number of assumptions that will allow us + // to reliably separate response frames from log lines without having to + // fall back on a heuristic-based parsing strategy. These assumptions are + // as follows: + + // 1. A log line will always begin with an ASCII character in the range + // [0-9], none of which are the frame start byte. + // 2. A log line will never contain \r\n in the middle of the line (i.e. + // multi-line log messages do not exist). This means a log "frame" will + // always be of the form [0-9]\r\n. + // 3. The controller will not emit a response frame in the middle of a log + // line. + // 4. The operating system's serial port read buffer is large enough that we + // won't lose data while accumulating log messages between commands. + + // Provided the above assumptions are true, a simple state machine can be + // used to parse the response by treating the log lines as a different type + // of frame. This could be made much more robust by applying additional + // heuristics for specific packets (e.g. get_position has some reasonably + // strict numerical bounds that could be used to sanity check the contents + // of the reply frame). + + + int res = 0; + unsigned char peek = 0; + enum r2p_frame_parser_state pstate = ROT2PROG_PARSER_EXPECT_FRAME_START; + + while (1) { + switch (pstate) + { + case ROT2PROG_PARSER_EXPECT_FRAME_START: + res = read_block(port, &peek, 1); + if (res < 0) return res; + + switch (peek) + { + case '0': + case '1': + case '2': + case '3': + case '4': + case '5': + case '6': + case '7': + case '8': + case '9': { + pstate = ROT2PROG_PARSER_EXPECT_CR; + break; + } + + case ROT2PROG_FRAME_START_BYTE: { + rxbuffer[0] = peek; + pstate = ROT2PROG_PARSER_EXPECT_FRAME_END; + break; + } + + default: return -RIG_EPROTO; + } + break; + + case ROT2PROG_PARSER_EXPECT_CR: + res = read_block(port, &peek, 1); + if (res < 0) return res; + + if (peek == '\r') pstate = ROT2PROG_PARSER_EXPECT_LF; + break; + + case ROT2PROG_PARSER_EXPECT_LF: + res = read_block(port, &peek, 1); + if (res < 0) return res; + + if (peek == '\n') + { + pstate = ROT2PROG_PARSER_EXPECT_FRAME_START; + } + else + { + // we have stumbled across a \r that is not immediately + // followed by \n. We could assume this is a weirdly formed + // log message, but I think it makes more sense to be + // defensive here and assume it is invalid for this to + // happen. + return -RIG_EPROTO; + } + break; + + case ROT2PROG_PARSER_EXPECT_FRAME_END: + // we already read the frame start byte + res = read_block(port, rxbuffer + 1, count - 1); + if (res < 0) return res; + + if (rxbuffer[count - 1] != ROT2PROG_FRAME_END_BYTE) + { + return -RIG_EPROTO; + } + + // lie about the number of bytes read + return res + 1; + + default: return -RIG_EINTERNAL; + } + } +} + static int spid_rot_init(ROT *rot) { rig_debug(RIG_DEBUG_TRACE, "%s called\n", __func__); @@ -217,7 +354,7 @@ static int spid_rot2prog_rot_set_position(ROT *rot, azimuth_t az, } memset(cmdstr, 0, 12); - retval = read_block(&rs->rotport, (unsigned char *) cmdstr, 12); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) cmdstr, 12); } while (retval < 0 && retry_read++ < rot->state.rotport.retry); @@ -264,7 +401,7 @@ static int spid_rot2prog_rot_set_position(ROT *rot, azimuth_t az, do { - retval = read_block(&rs->rotport, (unsigned char *) cmdstr, 12); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) cmdstr, 12); } while ((retval < 0) && (retry_read++ < rot->state.rotport.retry)); } @@ -295,12 +432,12 @@ static int spid_rot_get_position(ROT *rot, azimuth_t *az, elevation_t *el) if (rot->caps->rot_model == ROT_MODEL_SPID_ROT1PROG) { - retval = read_block(&rs->rotport, (unsigned char *) posbuf, 5); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) posbuf, 5); } else if (rot->caps->rot_model == ROT_MODEL_SPID_ROT2PROG || rot->caps->rot_model == ROT_MODEL_SPID_MD01_ROT2PROG) { - retval = read_block(&rs->rotport, (unsigned char *) posbuf, 12); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) posbuf, 12); } else { @@ -367,12 +504,12 @@ static int spid_rot_stop(ROT *rot) if (rot->caps->rot_model == ROT_MODEL_SPID_ROT1PROG) { - retval = read_block(&rs->rotport, (unsigned char *) posbuf, 5); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) posbuf, 5); } else if (rot->caps->rot_model == ROT_MODEL_SPID_ROT2PROG || rot->caps->rot_model == ROT_MODEL_SPID_MD01_ROT2PROG) { - retval = read_block(&rs->rotport, (unsigned char *) posbuf, 12); + retval = read_r2p_frame(&rs->rotport, (unsigned char *) posbuf, 12); } } while (retval < 0 && retry_read++ < rot->state.rotport.retry);