Merge pull request #715 from mikaelnousiainen/fix-icom-transceive-and-spectrum-data-conflicts

Attempt to handle asynchronous rig output data in Icom backend

rigs/icom/frame.c

@@ -23,9 +23,7 @@
 #include "config.h"
 #endif
 
-#include <stdlib.h>
 #include <string.h>  /* String function definitions */
-#include <unistd.h>  /* UNIX standard function definitions */
 
 #include "hamlib/rig.h"
 #include "serial.h"
@@ -90,6 +88,26 @@ int make_cmd_frame(char frame[], char re_id, char ctrl_id, char cmd, int subcmd,
     RETURNFUNC(i);
 }
 
+int icom_frame_fix_preamble(int frame_len, unsigned char *frame)
+{
+    if (frame[0] == PR)
+    {
+        // Sometimes the second preamble byte is missing -> TODO: Find out why!
+        if (frame[1] != PR)
+        {
+            memmove(frame + 1, frame, frame_len);
+            frame_len++;
+        }
+    }
+    else
+    {
+        rig_debug(RIG_DEBUG_WARN, "%s: invalid Icom CI-V frame, no preamble found\n", __func__);
+        RETURNFUNC(-RIG_EPROTO);
+    }
+
+    return frame_len;
+}
+
 /*
  * icom_one_transaction
  *
@@ -109,11 +127,12 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
     struct icom_priv_data *priv;
     const struct icom_priv_caps *priv_caps;
     struct rig_state *rs;
+    struct timeval start_time, current_time, elapsed_time;
     // this buf needs to be large enough for 0xfe strings for power up
     // at 115,200 this is now at least 150
     unsigned char buf[200];
     unsigned char sendbuf[MAXFRAMELEN];
-    int frm_len, retval;
+    int frm_len, frm_data_len, retval;
     int ctrl_id;
 
     ENTERFUNC;
@@ -168,12 +187,14 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
 
         if (retval < 0)
         {
+            Unhold_Decode(rig);
             /* Other error, return it */
             RETURNFUNC(retval);
         }
 
         if (retval < 1)
         {
+            Unhold_Decode(rig);
             RETURNFUNC(-RIG_EPROTO);
         }
 
@@ -223,6 +244,9 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
         RETURNFUNC(RIG_OK);
     }
 
+    gettimeofday(&start_time, NULL);
+
+read_another_frame:
     /*
      * wait for ACK ...
      * FIXME: handle padding/collisions
@@ -245,10 +269,9 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
 
 #endif
 
-    Unhold_Decode(rig);
-
     if (frm_len < 0)
     {
+        Unhold_Decode(rig);
         /* RIG_TIMEOUT: timeout getting response, return timeout */
         /* other error: return it */
         RETURNFUNC(frm_len);
@@ -256,12 +279,23 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
 
     if (frm_len < 1)
     {
+        Unhold_Decode(rig);
         RETURNFUNC(-RIG_EPROTO);
     }
 
+    retval = icom_frame_fix_preamble(frm_len, buf);
+    if (retval < 0)
+    {
+        Unhold_Decode(rig);
+        RETURNFUNC(retval);
+    }
+
+    frm_len = retval;
+
     switch (buf[frm_len - 1])
     {
     case COL:
+        Unhold_Decode(rig);
         /* Collision */
         RETURNFUNC(-RIG_BUSBUSY);
 
@@ -270,30 +304,71 @@ int icom_one_transaction(RIG *rig, int cmd, int subcmd,
         break;
 
     case NAK:
+        Unhold_Decode(rig);
         RETURNFUNC(-RIG_ERJCTED);
 
     default:
+        Unhold_Decode(rig);
         /* Timeout after reading at least one character */
         /* Problem on ci-v bus? */
         RETURNFUNC(-RIG_EPROTO);
     }
 
-    if (frm_len < ACKFRMLEN) { RETURNFUNC(-RIG_EPROTO); }
+    if (frm_len < ACKFRMLEN)
+    {
+        Unhold_Decode(rig);
+        RETURNFUNC(-RIG_EPROTO);
+    }
 
     // if we send a bad command we will get back a NAK packet
     // e.g. fe fe e0 50 fa fd
-    if (frm_len == 6 && NAK == buf[frm_len - 2]) { RETURNFUNC(-RIG_ERJCTED); }
+    if (frm_len == 6 && NAK == buf[frm_len - 2])
+    {
+        Unhold_Decode(rig);
+        RETURNFUNC(-RIG_ERJCTED);
+    }
 
     rig_debug(RIG_DEBUG_TRACE, "%s: frm_len=%d, frm_len-1=%02x, frm_len-2=%02x\n",
               __func__, frm_len, buf[frm_len - 1], buf[frm_len - 2]);
 
     // has to be one of these two now or frame is corrupt
-    if (FI != buf[frm_len - 1] && ACK != buf[frm_len - 1]) { RETURNFUNC(-RIG_BUSBUSY); }
+    if (FI != buf[frm_len - 1] && ACK != buf[frm_len - 1])
+    {
+        Unhold_Decode(rig);
+        RETURNFUNC(-RIG_BUSBUSY);
+    }
 
-    *data_len = frm_len - (ACKFRMLEN - 1);
+    frm_data_len = frm_len - (ACKFRMLEN - 1);
 
-    if (*data_len <= 0) { RETURNFUNC(-RIG_EPROTO); }
+    if (frm_data_len <= 0)
+    {
+        Unhold_Decode(rig);
+        RETURNFUNC(-RIG_EPROTO);
+    }
 
+    // TODO: Does ctrlid (detected by icom_is_async_frame) vary (seeing some code above using 0x80 for non-full-duplex)?
+    if (icom_is_async_frame(rig, frm_len, buf))
+    {
+        int elapsed_ms;
+        icom_process_async_frame(rig, frm_len, buf);
+
+        gettimeofday(&current_time, NULL);
+        timersub(&current_time, &start_time, &elapsed_time);
+
+        elapsed_ms = (int) (elapsed_time.tv_sec * 1000 + elapsed_time.tv_usec / 1000);
+
+        if (elapsed_ms > rs->rigport.timeout)
+        {
+            Unhold_Decode(rig);
+            RETURNFUNC(-RIG_ETIMEOUT);
+        }
+
+        goto read_another_frame;
+    }
+
+    Unhold_Decode(rig);
+
+    *data_len = frm_data_len;
     memcpy(data, buf + 4, *data_len);
 
     /*

rigs/icom/frame.h

@@ -28,6 +28,7 @@
  * helper functions
  */
 int make_cmd_frame(char frame[], char re_id, char ctrl_id, char cmd, int subcmd, const unsigned char *data, int data_len);
+int icom_frame_fix_preamble(int frame_len, unsigned char *frame);
 
 int icom_transaction (RIG *rig, int cmd, int subcmd, const unsigned char *payload, int payload_len, unsigned char *data, int *data_len);
 int read_icom_frame(hamlib_port_t *p, unsigned char rxbuffer[], int rxbuffer_len);

rigs/icom/icom.c

@@ -7933,7 +7933,7 @@ int icom_mW2power(RIG *rig, float *power, unsigned int mwpower, freq_t freq,
     RETURNFUNC(RIG_OK);
 }
 
-static int icom_parse_spectrum_frame(RIG *rig, int length, unsigned char *frame_data)
+static int icom_parse_spectrum_frame(RIG *rig, int length, const unsigned char *frame_data)
 {
     struct rig_caps *caps = rig->caps;
     struct icom_priv_caps *priv_caps = (struct icom_priv_caps *) caps->priv;
@@ -8059,6 +8059,85 @@ static int icom_parse_spectrum_frame(RIG *rig, int length, unsigned char *frame_
     RETURNFUNC(RIG_OK);
 }
 
+int icom_is_async_frame(RIG *rig, int frame_len, const unsigned char *frame)
+{
+    if (frame_len < ACKFRMLEN)
+    {
+        return 0;
+    }
+
+    /* Spectrum scope data is not CI-V transceive data, but handled the same way as it is pushed by the rig */
+    return frame[2] == BCASTID || (frame[2] == CTRLID && frame[4] == C_CTL_SCP && frame[5] == S_SCP_DAT);
+}
+
+int icom_process_async_frame(RIG *rig, int frame_len, const unsigned char *frame)
+{
+    struct rig_state *rs = &rig->state;
+    struct icom_priv_data *priv = (struct icom_priv_data *) rs->priv;
+    rmode_t mode;
+    pbwidth_t width;
+
+    rig_debug(RIG_DEBUG_VERBOSE, "%s called\n", __func__);
+
+    /*
+     * the first 2 bytes must be 0xfe
+     * the 3rd one 0x00 since this is transceive mode
+     * the 4rd one the emitter
+     * then the command number
+     * the rest is data
+     * and don't forget one byte at the end for the EOM
+     */
+    switch (frame[4])
+    {
+        case C_SND_FREQ:
+            /*
+             * TODO: the freq length might be less than 4 or 5 bytes
+             *          on older rigs!
+             */
+            if (rig->callbacks.freq_event)
+            {
+                freq_t freq;
+                freq = from_bcd(frame + 5, (priv->civ_731_mode ? 4 : 5) * 2);
+                RETURNFUNC(rig->callbacks.freq_event(rig, RIG_VFO_CURR, freq,
+                        rig->callbacks.freq_arg));
+            }
+            else
+            {
+                RETURNFUNC(-RIG_ENAVAIL);
+            }
+
+            break;
+
+        case C_SND_MODE:
+            if (rig->callbacks.mode_event)
+            {
+                icom2rig_mode(rig, frame[5], frame[6], &mode, &width);
+                RETURNFUNC(rig->callbacks.mode_event(rig, RIG_VFO_CURR,
+                        mode, width, rig->callbacks.mode_arg));
+            }
+            else
+            {
+                RETURNFUNC(-RIG_ENAVAIL);
+            }
+
+            break;
+
+        case C_CTL_SCP:
+            if (frame[5] == S_SCP_DAT)
+            {
+                icom_parse_spectrum_frame(rig, frame_len - (6 + 1), frame + 6);
+            }
+            break;
+
+        default:
+            rig_debug(RIG_DEBUG_VERBOSE, "%s: transceive cmd unsupported %#2.2x\n",
+                    __func__, frame[4]);
+            RETURNFUNC(-RIG_ENIMPL);
+    }
+
+    RETURNFUNC(RIG_OK);
+}
+
 /*
  * icom_decode is called by sa_sigio, when some asynchronous
  * data has been received from the rig
@@ -8068,9 +8147,7 @@ int icom_decode_event(RIG *rig)
     struct icom_priv_data *priv;
     struct rig_state *rs;
     unsigned char buf[MAXFRAMELEN];
-    int frm_len;
+    int retval, frm_len;
-    rmode_t mode;
-    pbwidth_t width;
 
     rig_debug(RIG_DEBUG_VERBOSE, "%s called\n", __func__);
 
@@ -8087,24 +8164,17 @@ int icom_decode_event(RIG *rig)
 
     if (frm_len < 1)
     {
-        RETURNFUNC(0);
+        RETURNFUNC(RIG_OK);
     }
 
-    if (buf[0] == PR)
+    retval = icom_frame_fix_preamble(frm_len, buf);
+    if (retval < 0)
     {
-        // Sometimes the second preamble byte is missing -> TODO: Find out why!
+        RETURNFUNC(retval);
-        if (buf[1] != PR)
-        {
-            memmove(buf + 1, buf, frm_len);
-            frm_len++;
-        }
-    }
-    else
-    {
-        rig_debug(RIG_DEBUG_WARN, "%s: invalid Icom CI-V frame, no preamble found\n", __func__);
-        RETURNFUNC(-RIG_EPROTO);
     }
 
+    frm_len = retval;
+
     switch (buf[frm_len - 1])
     {
     case COL:
@@ -8122,72 +8192,13 @@ int icom_decode_event(RIG *rig)
         RETURNFUNC(-RIG_EPROTO);
     }
 
-    /* Spectrum scope data is not CI-V transceive data, but handled the same way as it is pushed by the rig */
+    if (!icom_is_async_frame(rig, frm_len, buf))
-    if (buf[3] != BCASTID && buf[3] != priv->re_civ_addr && buf[4] != C_CTL_SCP)
     {
         rig_debug(RIG_DEBUG_WARN, "%s: CI-V %#x called for %#x!\n", __func__,
-                  priv->re_civ_addr, buf[3]);
+                  priv->re_civ_addr, buf[2]);
     }
 
-    /*
+    RETURNFUNC(icom_process_async_frame(rig, frm_len, buf));
-     * the first 2 bytes must be 0xfe
-     * the 3rd one the emitter
-     * the 4rd one 0x00 since this is transceive mode
-     * then the command number
-     * the rest is data
-     * and don't forget one byte at the end for the EOM
-     */
-    switch (buf[4])
-    {
-    case C_SND_FREQ:
-
-        /*
-         * TODO: the freq length might be less than 4 or 5 bytes
-         *          on older rigs!
-         */
-        if (rig->callbacks.freq_event)
-        {
-            freq_t freq;
-            freq = from_bcd(buf + 5, (priv->civ_731_mode ? 4 : 5) * 2);
-            RETURNFUNC(rig->callbacks.freq_event(rig, RIG_VFO_CURR, freq,
-                                                 rig->callbacks.freq_arg));
-        }
-        else
-        {
-            RETURNFUNC(-RIG_ENAVAIL);
-        }
-
-        break;
-
-    case C_SND_MODE:
-        if (rig->callbacks.mode_event)
-        {
-            icom2rig_mode(rig, buf[5], buf[6], &mode, &width);
-            RETURNFUNC(rig->callbacks.mode_event(rig, RIG_VFO_CURR,
-                                                 mode, width,
-                                                 rig->callbacks.mode_arg));
-        }
-        else
-        {
-            RETURNFUNC(-RIG_ENAVAIL);
-        }
-
-        break;
-
-    case C_CTL_SCP:
-        if (buf[5] == S_SCP_DAT)
-        {
-            icom_parse_spectrum_frame(rig, frm_len - (6 + 1), buf + 6);
-        }
-        break;
-
-    default:
-        rig_debug(RIG_DEBUG_VERBOSE, "%s: transceive cmd unsupported %#2.2x\n",
-                  __func__, buf[4]);
-        RETURNFUNC(-RIG_ENIMPL);
-    }
-
-    RETURNFUNC(RIG_OK);
 }
 
 int icom_set_raw(RIG *rig, int cmd, int subcmd, int subcmdbuflen,

rigs/icom/icom.h

@@ -387,6 +387,8 @@ int icom_set_custom_parm_time(RIG *rig, int parmbuflen, unsigned char *parmbuf,
 int icom_get_custom_parm_time(RIG *rig, int parmbuflen, unsigned char *parmbuf,
                               int *seconds);
 int icom_get_freq_range(RIG *rig);
+int icom_is_async_frame(RIG *rig, int frame_len, const unsigned char *frame);
+int icom_process_async_frame(RIG *rig, int frame_len, const unsigned char *frame);
 
 extern const struct confparams icom_cfg_params[];
 extern const struct confparams icom_ext_levels[];

src/event.c

@@ -56,9 +56,9 @@
 #include <signal.h>
 #include <errno.h>
 
-
 #include <hamlib/rig.h>
 #include "event.h"
+#include "misc.h"
 
 #if defined(WIN32) && !defined(HAVE_TERMIOS_H)
 #  include "win32termios.h"
@@ -300,6 +300,8 @@ static int search_rig_and_decode(RIG *rig, rig_ptr_t data)
     struct timeval tv;
     int retval;
 
+    ENTERFUNC;
+
     /*
      * so far, only file oriented ports have event reporting support
      */
@@ -309,6 +311,22 @@ static int search_rig_and_decode(RIG *rig, rig_ptr_t data)
         return -1;
     }
 
+    /*
+     * TODO: FIXME: We may end up calling decode_event right before or after the hold_decode lock is released
+     *   by backend transaction routine. With the Icom backend this will end up waiting for the next CI-V frame
+     *   to be read and this will interfere with reading of the next response to any command.
+     *   => It is difficult to find a way to avoid this routine picking up regular responses.
+     */
+
+    /*
+     * Do not disturb, the backend is currently receiving data
+     */
+    if (rig->state.hold_decode)
+    {
+        rig_debug(RIG_DEBUG_TRACE, "%s: hold decode, backend is receiving data\n", __func__);
+        RETURNFUNC(-1);
+    }
+
     /* FIXME: siginfo is not portable, however use it where available */
 #if 0&&defined(HAVE_SIGINFO_T)
     siginfo_t *si = (siginfo_t *)data;
@@ -334,10 +352,10 @@ static int search_rig_and_decode(RIG *rig, rig_ptr_t data)
     if (retval < 0)
     {
         rig_debug(RIG_DEBUG_ERR,
-                  "%s: select: %s\n",
+                  "%s: select() failed: %s\n",
                   __func__,
                   strerror(errno));
-        return -1;
+        RETURNFUNC(-1);
     }
 
 #endif
@@ -347,7 +365,8 @@ static int search_rig_and_decode(RIG *rig, rig_ptr_t data)
      */
     if (rig->state.hold_decode)
     {
-        return -1;
+        rig_debug(RIG_DEBUG_TRACE, "%s: hold decode, backend is receiving data\n", __func__);
+        RETURNFUNC(-1);
     }
 
     if (rig->caps->decode_event)
@@ -355,7 +374,7 @@ static int search_rig_and_decode(RIG *rig, rig_ptr_t data)
         rig->caps->decode_event(rig);
     }
 
-    return 1;   /* process each opened rig */
+    RETURNFUNC(1);   /* process each opened rig */
 }
 
 

src/misc.c

@@ -1904,7 +1904,7 @@ int HAMLIB_API parse_hoststr(char *hoststr, char host[256], char port[6])
     return -1;
 }
 
-#undef RIG_FLUSH_REMOVE
+#define RIG_FLUSH_REMOVE
 int HAMLIB_API rig_flush(hamlib_port_t *port)
 {
 #ifndef RIG_FLUSH_REMOVE

tests/rigctld.c

@@ -910,11 +910,19 @@ int main(int argc, char *argv[])
         timeout.tv_usec = 0;
         retcode = select(sock_listen + 1, &set, NULL, NULL, &timeout);
 
-        if (-1 == retcode)
+        if (retcode == -1)
         {
-            rig_debug(RIG_DEBUG_ERR, "%s: select\n", __func__);
+            int errno_stored = errno;
+            rig_debug(RIG_DEBUG_ERR, "%s: select() failed: %s\n", __func__, strerror(errno_stored));
+
+            // TODO: FIXME: Why does this select() return EINTR after any command when set_trn RIG is enabled?
+            if (errno == EINTR)
+            {
+                rig_debug(RIG_DEBUG_VERBOSE, "%s: ignoring interrupted system call\n", __func__);
+                retcode = 0;
             }
-        else if (!retcode)
+        }
+        else if (retcode == 0)
         {
             if (ctrl_c)
             {
@@ -1039,11 +1047,13 @@ void *handle_socket(void *arg)
     int ext_resp = 0;
     char resp_sep = '\n';
 
+    ENTERFUNC;
+
     fsockin = get_fsockin(handle_data_arg);
 
     if (!fsockin)
     {
-        rig_debug(RIG_DEBUG_ERR, "fdopen(0x%d) in: %s\n", handle_data_arg->sock,
+        rig_debug(RIG_DEBUG_ERR, "%s: fdopen(0x%d) in: %s\n", __func__, handle_data_arg->sock,
                   strerror(errno));
         goto handle_exit;
     }
@@ -1052,7 +1062,7 @@ void *handle_socket(void *arg)
 
     if (!fsockout)
     {
-        rig_debug(RIG_DEBUG_ERR, "fdopen out: %s\n", strerror(errno));
+        rig_debug(RIG_DEBUG_ERR, "%s: fdopen out: %s\n", __func__, strerror(errno));
         fclose(fsockin);
 
         goto handle_exit;