espressif/openthread
1
0
Fork 0
mirror of https://github.com/espressif/openthread.git synced 2026-09-13 12:40:05 +00:00
Code Issues Packages Projects Releases Wiki Activity

spi-hdlc-adapter: Reliability and Performance Improvements (#1441)

Browse Source 
This change includes many improvements which reduce latency, increase
throughput, and improve reliability.

The most significant change from this commit is addressing a frame
corruption bug which would occasionally corrupt frames received from
the slave during periods of congestion. This was occurring because
`push_pull_spi()` was allowed to be called when `sSpiTxIsReady` was
set, even if `sSpiRxPayloadSize` was not equal to zero. Under such
circumstances the previously received frame would be corrupted. This
change makes sure that `push_pull_spi()` does not get called until
`sSpiRxPayloadSize` is zero.

`push_pull_spi()` now only performs a single SPI transaction (instead
of two), which eliminates a significant amount of duplicated code. The
call to `usleep()` has been removed entirely, along with the
associated static `sSpiTransactionDelay`.

Statistics are now gathered and reported at exit. You can also induce
`spi-hdlc-adapter` to dump its statistics while it is running by
sending it a `SIGUSR1` signal.

This change also includes miscellaneous smaller changes.
This commit is contained in:
Robert Quattlebaum
2017-03-13 12:15:55 -07:00
committed by Jonathan Hui
parent 5298a515c3
commit 0449c2bed4
2 changed files with 241 additions and 195 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tools/spi-hdlc-adapter/README.md
+23 -5
View File
@@ -31,16 +31,19 @@ protocol document.
inefficient.
* `--gpio-reset[=gpio-path]`: Specify a path to the Linux
sysfs-exported GPIO directory for the `R̅E̅S̅` pin.
* `--spi-mode[=mode]`: Specify the SPI mode to use (0-3).
* `--spi-speed[=hertz]`: Specify the SPI speed in hertz.
* `--spi-mode[=mode]`: Specify the SPI mode to use (0-3). Default
value is `0`.
* `--spi-speed[=hertz]`: Specify the SPI speed in hertz. Default
value is `1000000` (1MHz).
* `--spi-cs-delay[=usec]`: Specify the delay after C̅S̅ assertion,
in microseconds.
in microseconds. Default is 20µs. Note that this may need to be
set to zero for spi-hdlc-adapter to work with some SPI drivers.
* `--spi-align-allowance[=n]`: Specify the the maximum number of 0xFF
bytes to clip from start of MISO frame. This makes this tool usable
with SPI slaves which have buggy SPI blocks that prepend up to
three 0xFF bytes to the start of MISO frame. Default value is `0`.
Maximum value is `3`. *This must be set to `2` for chips in the
SiLabs EM35x family.*
Maximum value is `3`. *This must be set to at least `2` for chips
in the SiLabs EM35x family.*
* `--verbose`: Increase debug verbosity.
* `--help`: Print out usage information to `stdout` and exit.
@@ -70,3 +73,18 @@ procedure:
1. Set `R̅E̅S̅/direction` to `low`.
2. Sleep for 30ms.
3. Set `R̅E̅S̅/direction` to `high`.
## Statistics ##
Some simple usage statistics are printed out to syslog at exit and
whenever the `SIGUSR1` signal is received. The easiest way to send
that signal to `spi-hdlc-adapter` is like this:
# killall -sigusr1 spi-hdlc-adapter
At which point you will see something like this in the syslogs:
spi-hdlc-adapter[5215]: INFO: sSpiFrameCount=45660
spi-hdlc-adapter[5215]: INFO: sSpiValidFrameCount=45643
spi-hdlc-adapter[5215]: INFO: sSpiGarbageFrameCount=17
spi-hdlc-adapter[5215]: INFO: sSpiDuplexFrameCount=20931
tools/spi-hdlc-adapter/spi-hdlc-adapter.c
+218 -190
View File
@@ -67,7 +67,7 @@
/* ------------------------------------------------------------------------- */
/* MARK: Macros and Constants */
#define SPI_HDLC_VERSION "0.04"
#define SPI_HDLC_VERSION "0.05"
#define MAX_FRAME_SIZE 2048
#define HEADER_LEN 5
@@ -90,7 +90,7 @@
#define USEC_PER_SEC (USEC_PER_MSEC * MSEC_PER_SEC)
#endif
#define SPI_POLL_PERIOD_MSEC (MSEC_PER_SEC/30)
#define SPI_POLL_PERIOD_MSEC (MSEC_PER_SEC/100)
#define GPIO_INT_ASSERT_STATE 0 // I̅N̅T̅ is asserted low
#define GPIO_RES_ASSERT_STATE 0 // R̅E̅S̅ is asserted low
@@ -100,7 +100,7 @@
#define SOCKET_DEBUG_BYTES_PER_LINE 16
#ifndef AUTO_PRINT_BACKTRACE
#define AUTO_PRINT_BACKTRACE (HAVE_EXECINFO_H || __APPLE__)
#define AUTO_PRINT_BACKTRACE (HAVE_EXECINFO_H)
#endif
#define AUTO_PRINT_BACKTRACE_STACK_DEPTH 20
@@ -142,7 +142,6 @@ static int sHdlcOutputFd = -1;
static int sSpiSpeed = 1000000; // in Hz (default: 1MHz)
static uint8_t sSpiMode = 0;
static int sSpiCsDelay = 20; // in microseconds
static int sSpiTransactionDelay = 200; // in microseconds
static uint16_t sSpiRxPayloadSize;
static uint8_t sSpiRxFrameBuffer[MAX_FRAME_SIZE + SPI_RX_ALIGN_ALLOWANCE_MAX];
@@ -154,9 +153,6 @@ static uint8_t sSpiTxFrameBuffer[MAX_FRAME_SIZE + SPI_RX_ALIGN_ALLOWANCE_MAX];
static int sSpiRxAlignAllowance = 0;
static uint32_t sSpiFrameCount = 0;
static uint32_t sSpiValidFrameCount = 0;
static bool sSlaveDidReset = false;
// If sUseRawFrames is set to true, HDLC encoding/encoding
@@ -168,9 +164,22 @@ static int sMTU = MAX_FRAME_SIZE - HEADER_LEN;
static int sRet = 0;
static bool sDumpInfo = false;
static sig_t sPreviousHandlerForSIGINT;
static sig_t sPreviousHandlerForSIGTERM;
/* ------------------------------------------------------------------------- */
/* MARK: Statistics */
static uint64_t sSpiFrameCount = 0;
static uint64_t sSpiValidFrameCount = 0;
static uint64_t sSpiGarbageFrameCount = 0;
static uint64_t sSpiDuplexFrameCount = 0;
static uint64_t sHdlcRxFrameCount = 0;
static uint64_t sHdlcTxFrameCount = 0;
static uint64_t sHdlcRxBadCrcCount = 0;
/* ------------------------------------------------------------------------- */
/* MARK: Signal Handlers */
@@ -206,7 +215,8 @@ static void signal_SIGTERM(int sig)
// this signal again we perform the system default action.
signal(SIGTERM, sPreviousHandlerForSIGTERM);
sPreviousHandlerForSIGTERM = NULL;
(void) sig;
(void)sig;
}
static void signal_SIGHUP(int sig)
@@ -223,7 +233,20 @@ static void signal_SIGHUP(int sig)
// because we always want to let the main
// loop decide what to do for hangups.
(void) sig;
(void)sig;
}
static void signal_SIGUSR1(int sig)
{
static const char message[] = "\nCaught SIGUSR1!\n";
sDumpInfo = true;
// Can't use syslog() because it isn't async signal safe.
// So we write to stderr
IGNORE_RETURN_VALUE(write(STDERR_FILENO, message, sizeof(message)-1));
(void)sig;
}
#if AUTO_PRINT_BACKTRACE
@@ -390,6 +413,8 @@ static int do_spi_xfer(int len)
}
};
if (sSpiCsDelay > 0)
{
// A C̅S̅ delay has been specified. Start transactions
@@ -408,14 +433,6 @@ static int do_spi_xfer(int len)
log_debug_buffer("SPI-TX", sSpiTxFrameBuffer, (int)xfer[1].len);
log_debug_buffer("SPI-RX", sSpiRxFrameBuffer, (int)xfer[1].len);
if (spi_header_get_flag_byte(sSpiRxFrameBuffer) != 0xFF)
{
if (spi_header_get_flag_byte(sSpiRxFrameBuffer) & SPI_HEADER_RESET_FLAG)
{
sSlaveDidReset = true;
}
}
sSpiFrameCount++;
}
@@ -446,23 +463,29 @@ static void debug_spi_header(const char* hint)
static int push_pull_spi(void)
{
static const uint16_t SMALL_PACKET_SIZE = 5;
int ret;
uint16_t spi_xfer_bytes = 0;
const uint8_t* spiRxFrameBuffer = NULL;
uint8_t slave_header;
uint16_t slave_max_rx;
uint16_t slave_data_len;
uint16_t spi_xfer_bytes = 5;
const uint8_t* spiRxFrameBuffer = NULL;
int successful_exchanges = 0;
static uint16_t slave_data_len;
sSpiTxFlowControl = false;
/// -- FIRST TRANSACTION --------------------------------------------------
// The purpose of the first transaction is to attempt to
// send any transactions we have queued and fetch the slave's
// buffer sizes.
// For now, sSpiRxPayloadSize must be zero
// when entering this function. This may change
// at some point, for now this makes things
// much easier.
assert(sSpiRxPayloadSize == 0);
if (sSpiValidFrameCount == 0)
{
// Set the reset flag to indicate to our slave that we
// are coming up from scratch.
spi_header_set_flag_byte(sSpiTxFrameBuffer, SPI_HEADER_RESET_FLAG|SPI_HEADER_PATTERN_VALUE);
}
else
@@ -470,13 +493,16 @@ static int push_pull_spi(void)
spi_header_set_flag_byte(sSpiTxFrameBuffer, SPI_HEADER_PATTERN_VALUE);
}
// Zero out our max rx and data len
// so that the slave doesn't think
// we are actually trying to transfer
// data.
// Zero out our rx_accept and our data_len for now.
spi_header_set_accept_len(sSpiTxFrameBuffer, 0);
spi_header_set_data_len(sSpiTxFrameBuffer, 0);
// Sanity check.
if (slave_data_len > MAX_FRAME_SIZE)
{
slave_data_len = 0;
}
if (sSpiTxIsReady)
{
// Go ahead and try to immediately send a frame if we have it queued up.
@@ -488,16 +514,35 @@ static int push_pull_spi(void)
}
}
// If we aren't already processing a received frame, we
// can also handle receiving the next frame if its length
// is equal to or less than the size of what we are
// trying to transmit above.
if (sSpiRxPayloadSize == 0) {
if (sSpiRxPayloadSize == 0)
{
if (slave_data_len != 0)
{
// In a previous transaction the slave indicated
// it had something to send us. Make sure our
// transaction is large enough to handle it.
if (slave_data_len > spi_xfer_bytes)
{
spi_xfer_bytes = slave_data_len;
}
}
else
{
// Set up a minimum transfer size to allow small
// frames the slave wants to send us to be handled
// in a single transaction.
if (SMALL_PACKET_SIZE > spi_xfer_bytes)
{
spi_xfer_bytes = SMALL_PACKET_SIZE;
}
}
spi_header_set_accept_len(sSpiTxFrameBuffer, spi_xfer_bytes);
}
// Perform the first SPI transaction.
// Perform the SPI transaction.
ret = do_spi_xfer(spi_xfer_bytes);
if (ret < 0)
{
perror("do_spi_xfer");
@@ -515,16 +560,36 @@ static int push_pull_spi(void)
// Account for misalignment (0xFF bytes at the start)
spiRxFrameBuffer = get_real_rx_frame_start();
debug_spi_header("push_pull_1");
debug_spi_header("push_pull");
slave_header = spi_header_get_flag_byte(spiRxFrameBuffer);
if ((slave_header == 0xFF) || (slave_header == 0x00))
{
// Device is off or in a bad state.
if ( (slave_header == spiRxFrameBuffer[1])
&& (slave_header == spiRxFrameBuffer[2])
&& (slave_header == spiRxFrameBuffer[3])
&& (slave_header == spiRxFrameBuffer[4])
) {
// Device is off or in a bad state.
// In some cases may be induced by flow control.
syslog(slave_data_len == 0 ? LOG_DEBUG : LOG_WARNING, "Discarded frame.");
}
else
{
// Header is full of garbage
syslog(
LOG_WARNING,
"Gibberish in header : %02X %02X %02X %02X %02X",
spiRxFrameBuffer[0],
spiRxFrameBuffer[1],
spiRxFrameBuffer[2],
spiRxFrameBuffer[3],
spiRxFrameBuffer[4]
);
}
sSpiGarbageFrameCount++;
sSpiTxFlowControl = true;
syslog(LOG_DEBUG, "Discarded frame. (1)");
goto bail;
}
@@ -536,9 +601,11 @@ static int push_pull_spi(void)
|| (slave_data_len > MAX_FRAME_SIZE)
)
{
sSpiGarbageFrameCount++;
sSpiTxFlowControl = true;
slave_data_len = 0;
syslog(
LOG_INFO,
LOG_WARNING,
"Gibberish in header (h:0x%02X, max_rx:0x%04X, data_len:0x%04X)",
slave_header,
slave_max_rx,
@@ -549,6 +616,12 @@ static int push_pull_spi(void)
sSpiValidFrameCount++;
if ( (slave_header & SPI_HEADER_RESET_FLAG) == SPI_HEADER_RESET_FLAG)
{
syslog(LOG_NOTICE, "Slave did reset");
sSlaveDidReset = true;
}
// Handle received packet, if any.
if ( (sSpiRxPayloadSize == 0)
&& (slave_data_len != 0)
@@ -559,20 +632,25 @@ static int push_pull_spi(void)
sSpiRxPayloadSize = slave_data_len;
slave_data_len = 0;
successful_exchanges++;
}
if (sSpiTxIsReady)
// Handle transmitted packet, if any.
if (sSpiTxPayloadSize == spi_header_get_data_len(sSpiTxFrameBuffer))
{
// Handle transmitted packet.
if (spi_header_get_data_len(sSpiTxFrameBuffer) <= slave_max_rx)
{
// Outbound packet has been successfully transmitted. Clear
// Our outbound packet has been successfully transmitted. Clear
// sSpiTxPayloadSize and sSpiTxIsReady so that pull_hdlc() can
// pull another packet for us to send.
sSpiTxIsReady = false;
sSpiTxPayloadSize = 0;
spi_header_set_data_len(sSpiTxFrameBuffer, 0);
} else {
sSpiTxFlowControl = false;
successful_exchanges++;
}
else
{
// The slave Wasn't ready for what we had to
// send them. Turn on rate limiting so that we
// don't waste a ton of CPU bombarding them
@@ -581,138 +659,36 @@ static int push_pull_spi(void)
}
}
if (slave_data_len == 0)
if (successful_exchanges == 2)
{
// Nothing else to do.
goto bail;
sSpiDuplexFrameCount++;
}
/// -- SECOND TRANSACTION ------------------------------------------------
// The purpose of the second transaction is to attempt to
// fetch any packets that the slave has for us that didn't
// fit in the first transaction.
spi_header_set_flag_byte(sSpiTxFrameBuffer, SPI_HEADER_PATTERN_VALUE);
spi_header_set_accept_len(sSpiTxFrameBuffer, 0);
if (sSpiTxIsReady)
{
spi_xfer_bytes = sSpiTxPayloadSize;
spi_header_set_data_len(sSpiTxFrameBuffer, sSpiTxPayloadSize);
} else {
spi_xfer_bytes = 0;
}
if ( (slave_data_len != 0)
&& (sSpiRxPayloadSize == 0)
)
{
spi_header_set_accept_len(sSpiTxFrameBuffer, slave_data_len);
if (slave_data_len > spi_xfer_bytes)
{
spi_xfer_bytes = slave_data_len;
}
}
// Optionally delay a short period to give
// the slave time to get its affairs in order.
usleep((unsigned int)sSpiTransactionDelay);
// Perform the second SPI transaction.
ret = do_spi_xfer(spi_xfer_bytes);
if (ret < 0)
{
perror("do_spi_xfer");
// Print out a helpful error message for
// a common error.
if ( (sSpiCsDelay != 0)
&& (errno == EINVAL)
) {
syslog(LOG_ERR, "SPI ioctl failed with EINVAL. Try adding `--spi-cs-delay=0` to command line arguments.");
}
goto bail;
}
// Account for misalignment (0xFF bytes at the start)
spiRxFrameBuffer = get_real_rx_frame_start();
debug_spi_header("push_pull_2");
slave_header = spi_header_get_flag_byte(spiRxFrameBuffer);
if ((slave_header == 0xFF) || (slave_header == 0x00))
{
// Device is off or in a bad state.
sSpiTxFlowControl = true;
syslog(LOG_DEBUG, "Discarded frame. (2)");
goto bail;
}
slave_max_rx = spi_header_get_accept_len(spiRxFrameBuffer);
slave_data_len = spi_header_get_data_len(spiRxFrameBuffer);
if ( (slave_header != SPI_HEADER_PATTERN_VALUE)
|| (slave_max_rx > MAX_FRAME_SIZE)
|| (slave_data_len > MAX_FRAME_SIZE)
)
{
sSpiTxFlowControl = true;
syslog(
LOG_INFO,
"Gibberish in header (h:0x%02X, max_rx:0x%04X, data_len:0x%04X) (2)",
slave_header,
slave_max_rx,
slave_data_len
);
goto bail;
}
sSpiValidFrameCount++;
if ( (sSpiRxPayloadSize == 0)
&& (slave_data_len <= spi_header_get_accept_len(sSpiTxFrameBuffer))
) {
// We have received a packet. Set sSpiRxPayloadSize so that
// the packet will eventually get queued up by push_hdlc().
sSpiRxPayloadSize = slave_data_len;
}
if ( (sSpiTxPayloadSize == spi_header_get_data_len(sSpiTxFrameBuffer))
&& (spi_header_get_data_len(sSpiTxFrameBuffer) <= slave_max_rx)
) {
// Out outbound packet has been successfully transmitted. Clear
// sSpiTxPayloadSize and sSpiTxIsReady so that pull_hdlc() can
// pull another packet for us to send.
sSpiTxIsReady = false;
sSpiTxPayloadSize = 0;
sSpiTxFlowControl = false;
}
bail:
return ret;
}
static bool check_and_clear_interrupt(void)
{
char value[5] = "";
ssize_t len;
lseek(sIntGpioValueFd, 0, SEEK_SET);
len = read(sIntGpioValueFd, value, sizeof(value)-1);
if (len < 0)
if (sIntGpioValueFd >= 0)
{
perror("check_and_clear_interrupt");
sRet = EXIT_FAILURE;
char value[5] = "";
ssize_t len;
lseek(sIntGpioValueFd, 0, SEEK_SET);
len = read(sIntGpioValueFd, value, sizeof(value)-1);
if (len < 0)
{
perror("check_and_clear_interrupt");
sRet = EXIT_FAILURE;
}
// The interrupt pin is active low.
return GPIO_INT_ASSERT_STATE == atoi(value);
}
// The interrupt pin is active low.
return GPIO_INT_ASSERT_STATE == atoi(value);
return true;
}
/* ------------------------------------------------------------------------- */
@@ -897,6 +873,9 @@ static int push_hdlc(void)
if (escaped_frame_len == escaped_frame_sent)
{
escaped_frame_len = escaped_frame_sent = 0;
// Increment counter for statistics
sHdlcTxFrameCount++;
}
ret = 0;
@@ -937,6 +916,7 @@ static int pull_hdlc(void)
else if (fcs != kHdlcCrcCheckValue)
{
syslog(LOG_WARNING, "HDLC frame with bad CRC (LEN:%d, FCS:0x%04X)", sSpiTxPayloadSize, fcs);
sHdlcRxBadCrcCount++;
unescape_next_byte = false;
sSpiTxPayloadSize = 0;
fcs = kHdlcCrcResetValue;
@@ -949,6 +929,9 @@ static int pull_hdlc(void)
// Indicate that a frame is ready to go out
sSpiTxIsReady = true;
// Increment counter for statistics
sHdlcRxFrameCount++;
// Clean up for the next frame
unescape_next_byte = false;
fcs = kHdlcCrcResetValue;
@@ -1060,6 +1043,9 @@ static int push_raw(void)
if (raw_frame_len == raw_frame_sent)
{
raw_frame_len = raw_frame_sent = 0;
// Increment counter for statistics
sHdlcTxFrameCount++;
}
ret = 0;
@@ -1093,6 +1079,9 @@ static int pull_raw(void)
{
sSpiTxPayloadSize = (uint16_t)ret;
sSpiTxIsReady = true;
// Increment counter for statistics
sHdlcRxFrameCount++;
}
}
@@ -1417,9 +1406,9 @@ static void print_help(void)
" GPIO directory for the `R̅E̅S̅` pin.\n"
" --spi-mode[=mode] ............ Specify the SPI mode to use (0-3).\n"
" --spi-speed[=hertz] .......... Specify the SPI speed in hertz.\n"
" --spi-cs-delay[=usec] ........ Specify the delay after C̅S̅ assertion, in usec\n"
" --spi-cs-delay[=usec] ........ Specify the delay after C̅S̅ assertion, in µsec\n"
" --spi-align-allowance[=n] .... Specify the the maximum number of FF bytes to\n"
" clip from start of MISO frame.\n"
" clip from start of MISO frame. Max value is 3.\n"
" -v/--verbose ................. Increase debug verbosity. (Repeatable)\n"
" -h/-?/--help ................. Print out usage information and exit.\n"
"\n";
@@ -1489,6 +1478,7 @@ int main(int argc, char *argv[])
sPreviousHandlerForSIGINT = signal(SIGINT, &signal_SIGINT);
sPreviousHandlerForSIGTERM = signal(SIGTERM, &signal_SIGTERM);
signal(SIGHUP, &signal_SIGHUP);
signal(SIGUSR1, &signal_SIGUSR1);
#if AUTO_PRINT_BACKTRACE
sigact.sa_sigaction = &signal_critical;
@@ -1505,7 +1495,7 @@ int main(int argc, char *argv[])
openlog(basename(prog), LOG_PERROR | LOG_PID | LOG_CONS, LOG_DAEMON);
setlogmask(setlogmask(0) & LOG_UPTO(sVerbose));
setlogmask(LOG_UPTO(sVerbose));
while (1)
{
@@ -1534,6 +1524,7 @@ int main(int argc, char *argv[])
syslog(LOG_ERR, "Invalid SPI RX Align Allowance \"%s\" (MAX: %d)", optarg, SPI_RX_ALIGN_ALLOWANCE_MAX);
exit(EXIT_FAILURE);
}
break;
case ARG_SPI_MODE:
@@ -1554,6 +1545,11 @@ int main(int argc, char *argv[])
case ARG_SPI_CS_DELAY:
sSpiCsDelay = atoi(optarg);
if (sSpiCsDelay < 0)
{
syslog(LOG_ERR, "Negative values (%d) for --spi-cs-delay are invalid.", sSpiCsDelay);
exit(EXIT_FAILURE);
}
syslog(LOG_NOTICE, "SPI CS Delay set to %d usec", sSpiCsDelay);
break;
@@ -1564,11 +1560,13 @@ int main(int argc, char *argv[])
case ARG_MTU:
sMTU = atoi(optarg);
if (sMTU > MAX_FRAME_SIZE - HEADER_LEN) {
if (sMTU > MAX_FRAME_SIZE - HEADER_LEN)
{
syslog(LOG_ERR, "Specified MTU of %d is too large, maximum is %d bytes.", sMTU, MAX_FRAME_SIZE - HEADER_LEN);
exit(EXIT_FAILURE);
}
if (sMTU < 1) {
if (sMTU < 1)
{
syslog(LOG_ERR, "Specified MTU of %d is too small, minimum is 1 byte.", sMTU);
exit(EXIT_FAILURE);
}
@@ -1739,26 +1737,10 @@ int main(int argc, char *argv[])
FD_SET(sHdlcInputFd, &read_set);
}
else if (sSpiTxFlowControl)
{
// We are being rate-limited by the NCP. This is
// fairly normal behavior. We poll because we
// won't get an interrupt unless the NCP happens
// to be trying to send us something.
timeout_ms = SPI_POLL_PERIOD_MSEC;
if (!did_print_rate_limit_log) {
// Avoid printing out this message over and over.
syslog(LOG_INFO, "NCP is rate limiting transactions");
did_print_rate_limit_log = true;
}
}
else
{
// We have data to send to the slave. Since we
// are not being rate-limited, proceed immediately.
// We have data to send to the slave.
timeout_ms = 0;
did_print_rate_limit_log = false;
}
if (sSpiRxPayloadSize != 0)
@@ -1797,6 +1779,34 @@ int main(int argc, char *argv[])
timeout_ms = SPI_POLL_PERIOD_MSEC;
}
if (sDumpInfo)
{
timeout_ms = 0;
}
if (sSpiTxFlowControl)
{
// We are being rate-limited by the NCP. This is
// fairly normal behavior. We poll because we
// won't get an interrupt unless the NCP happens
// to be trying to send us something.
if (timeout_ms < SPI_POLL_PERIOD_MSEC)
{
timeout_ms = SPI_POLL_PERIOD_MSEC;
if (!did_print_rate_limit_log)
{
// Avoid printing out this message over and over.
syslog(LOG_INFO, "NCP is rate limiting transactions");
did_print_rate_limit_log = true;
}
}
}
else
{
did_print_rate_limit_log = false;
}
// Calculate the timeout value.
timeout.tv_sec = timeout_ms / MSEC_PER_SEC;
timeout.tv_usec = (timeout_ms % MSEC_PER_SEC) * USEC_PER_MSEC;
@@ -1804,6 +1814,18 @@ int main(int argc, char *argv[])
// Wait for something to happen.
IGNORE_RETURN_VALUE(select(max_fd + 1, &read_set, &write_set, &error_set, &timeout));
if (sDumpInfo || sRet != 0)
{
sDumpInfo = false;
syslog(LOG_NOTICE, "INFO: sSpiFrameCount=%llu", (unsigned long long)sSpiFrameCount);
syslog(LOG_NOTICE, "INFO: sSpiValidFrameCount=%llu", (unsigned long long)sSpiValidFrameCount);
syslog(LOG_NOTICE, "INFO: sSpiGarbageFrameCount=%llu", (unsigned long long)sSpiGarbageFrameCount);
syslog(LOG_NOTICE, "INFO: sSpiDuplexFrameCount=%llu", (unsigned long long)sSpiDuplexFrameCount);
syslog(LOG_NOTICE, "INFO: sHdlcTxFrameCount=%llu", (unsigned long long)sHdlcTxFrameCount);
syslog(LOG_NOTICE, "INFO: sHdlcRxFrameCount=%llu", (unsigned long long)sHdlcRxFrameCount);
syslog(LOG_NOTICE, "INFO: sHdlcRxBadCrcCount=%llu", (unsigned long long)sHdlcRxBadCrcCount);
}
// Handle serial input.
if (FD_ISSET(sHdlcInputFd, &read_set))
{
@@ -1824,12 +1846,18 @@ int main(int argc, char *argv[])
sRet = EXIT_FAILURE;
break;
}
continue;
}
// Service the SPI port if we can receive
// a packet or we have a packet to be sent.
if ((sSpiRxPayloadSize == 0) || sSpiTxIsReady)
{
if ( (sSpiRxPayloadSize == 0)
&& (sSpiTxIsReady || check_and_clear_interrupt())
) {
// We guard this with the above check because we don't
// want to overwrite any previously received (but not
// yet pushed out) frames.
if (push_pull_spi() < 0)
{
sRet = EXIT_FAILURE;