spinel over RS-485… anyone tried it?

[Stuart Longland]

Hi all,

I'm in the process of trying to bring up the NCP code on our hardware…
basically the intent is to enable one of our devices to act as NCP by
flashing it with appropriate firmware.

Now, a quirk: the device actually has two RS-485 ports attached to the
one UART… so we can do half-duplex RS-485 serial comms with one port, or
combine both to do full-duplex RS-485 or RS-422 comms with both. I
found out yesterday morning that the industrial PC we had intended to
run the OpenThread border router on, only has half-duplex RS-485
available, so we either need to look around for a RS-422 USB serial
dongle, or try and make the NCP work half-duplex.

The alternative to this is to try and use the USB device port on the
CC2538 to do USB-CDC ACM. TI's usblib doesn't compile under gcc without
a lot of hacking… and porting something like LUFA over to the CC2538 is
a lot of work too. (I've got a half-started branch.)

I've managed to port the NCP example app over to our HAL, and while the
HAL works fine for doing Modbus communications and for a serial console,
it seems I get problems using this with the NCP:

> wpantund[691]: Starting wpantund 0.08.00d (Aug 21 2017 05:44:28) . . .
> wpantund[691]: BUILD_VERSION = a5d2c20
> wpantund[691]: Configuration file "/etc/wpantund.conf" read.
> wpantund[691]: Ready. Using DBUS bus ":1.3"
> wpantund[691]: Running as root without dropping privileges!
> wpantund[691]: State change: "uninitialized" -> "offline"
> wpantund[691]: NCP is running "OPENTHREAD/0.01.00; CC2538; Aug 22 2017 12:07:50"
> wpantund[691]: Driver is running "0.08.00d (/a5d2c20; Aug 21 2017 05:44:28)"
> wpantund[691]: HARDWARE ADDRESS IS INVALID, MULTICAST BIT IS SET!
> wpantund[691]: Network is not joinable
> wpantund[691]: Resetting interface(s). . .
> wpantund[691]: Finished initializing NCP
> wpantund[691]: Scan -> Name:WideSky , PanId:0x0000, Ch:11, Joinable:NO , XPanId:0xDEAD00BEEF00CAFE, HwAddr:0x8ACB5F22091366FE, RSSI:4 , LQI:106, ProtoId:3 , Version: 0, ShortAddr:0xFFFF
> wpantund[691]: State change: "offline" -> "associating"
> wpantund[691]: State change: "associating" -> "associated"
> wpantund[691]: Node type change: "unknown" -> "end-device"
> wpantund[691]: Adding address "fdde:ad00:beef:0:aa81:8bfb:90ee:b514/64" to NCP
> wpantund[691]: SpinelNCPTaskSendCommand.cpp:305: Requirement Failed ((mRetVal == kWPANTUNDStatus_Ok) || (mRetVal == kWPANTUNDStatus_Busy))
> wpantund[691]: SendCommand task encountered an error: 16 (0x00000010)
> wpantund[691]: SpinelNCPTaskSendCommand.cpp:363: Check Failed (error 16)
> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]
> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]
> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]
> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]
> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]

I'm not sure if this is a buffering issue in my code, or whether the NCP
requires special settings for its serial communications.

Has anyone seen this when debugging the NCP code and have some ideas
where I should look next?
--
_ ___ Stuart Longland - Systems Engineer
\ /|_) | T: +61 7 3535 9619
\/ | \ | 38b Douglas Street F: +61 7 3535 9699
SYSTEMS Milton QLD 4064 http://www.vrt.com.au

[Stuart Longland]

On 22/08/17 12:23, Stuart Longland wrote:
> Has anyone seen this when debugging the NCP code and have some ideas
> where I should look next?

On a related note, it seems the spinel docs scripts are broken too:
> stuartl@vk4msl-ws:~/vrt/projects/widesky/hub/hal/third_party/openthread/doc/spinel-protocol-src$ make
> sed 's/@SOURCE_VERSION@/3572d5bb-dirty/g;s/@SOURCE_DATE@/2017-08-18T04:35:19Z/g' < draft-rquattle-spinel-unified.md.in > draft-rquattle-spinel-unified.md
> docker run --rm --user=`id -u`:`id -g` -v `pwd`:/rfc -v /home/stuartl/.cache/xml2rfc:/var/cache/xml2rfc paulej/rfctools mmark -xml2 -page draft-rquattle-spinel-unified.md draft-rquattle-spinel-unified.xml
> Unable to find image 'paulej/rfctools:latest' locally
> latest: Pulling from paulej/rfctools
> 0fc456f626d7: Pull complete
> 213530f0c1eb: Pull complete
> 770dd8781918: Pull complete
> 93981b797e92: Pull complete
> 7d91b56b4b3b: Pull complete
> f675941445c7: Pull complete
> Digest: sha256:a8e02193919386a42680a08d3ac284c7acc9a0b8d3146b9fb696e663990081ec
> Status: Downloaded newer image for paulej/rfctools:latest
> sed -i "" -e 's/fullname="James Woodyatt"/fullname="James Woodyatt" role="editor"/' draft-rquattle-spinel-unified.xml
> sed: can't read : No such file or directory
> make: *** [Makefile:64: draft-rquattle-spinel-unified.xml] Error 2
> stuartl@vk4msl-ws:~/vrt/projects/widesky/hub/hal/third_party/openthread/doc/spinel-protocol-src$-

[Stuart Longland]

On 22/08/17 12:23, Stuart Longland wrote:

> I've managed to port the NCP example app over to our HAL, and while the
> HAL works fine for doing Modbus communications and for a serial console,
> it seems I get problems using this with the NCP:
>

>> wpantund[691]: NCP => Framing error 6: [80 03 72 68 00 60 00 00 00 00 40 3A 01 FD DE AD 00 BE EF 00 00 AA 81 8B FB 90 EE B5 14 FF FF 02 00 00 00 00 00 00 00 00 00]

Okay, so just realised that earlier, I had incorporated POSIX-style byte
stuffing to indicate error conditions such as parity errors and frame
errors. This was handy with my Modbus code, as it allowed the Modbus
client to handle a parity error efficiently without needing it to have
hooks into the driver to detect such conditions.

I never saw problems with the console because… well… who types 0xff
characters into a serial console?

POSIX has a termios feature called PARMRK which marks when such errors
occur:

> PARMRK If this bit is set, input bytes with parity or framing
> errors are marked when passed to the program. This bit
> is meaningful only when INPCK is set and IGNPAR is not
> set. The way erroneous bytes are marked is with two
> preceding bytes, \377 and \0. Thus, the program actu‐
> ally reads three bytes for one erroneous byte received
> from the terminal. If a valid byte has the value \377,
> and ISTRIP (see below) is not set, the program might
> confuse it with the prefix that marks a parity error.
> Therefore, a valid byte \377 is passed to the program
> as two bytes, \377 \377, in this case.
>
> If neither IGNPAR nor PARMRK is set, read a character
> with a parity error or framing error as \0.

… and I've more or less borrowed that idea to represent general error
flags from the UART driver:

> WH-308: uart: Use POSIX-style "marking" for errors.
>
> Rather than handing off to a separate handler, we instead take a leaf
> out of the book of POSIX which marks parity errors this way:
>
> Literal 0xff: 0xff 0xff
> Byte with error: 0xff 0x00 {byte}
>
> We'll do something a little different:
> Byte with error: 0xff {error} {byte}
>
> where {error} is a bit mask of error bits:
>
> /*! Frame error has occurred */
> #define CC2538_UART_ERR_FRAME (0)
> /*! Parity error has occurred */
> #define CC2538_UART_ERR_PARITY (1)
> /*! A BREAK has been received */
> #define CC2538_UART_ERR_BREAK (2)
> /*! Bytes missed while FIFO full */
> #define CC2538_UART_ERR_OVERRUN (3)
>
> Applications receiving data, on receipt of 0xff should check the very
> next byte. If the most significant nibble is non-zero, then the byte is
> a literal 0xff, otherwise the least significant nibble carries the error
> flags, and the byte *following that*, has the actual byte received.

I think I am seeing that with the 0xff in the IPv6 address, which is why
it is complaining about a multicast bit being set, and various framing
errors. Question is though, okay we can safely ignore parity errors,
but how do we handle overruns, breaks or frame errors?

I also read in the spinel docs that while hardware control is
recommended, it can also use software flow control. However, I see
`wpantund` doesn't seem to have an option to enable it. I suspect my
UART code will need to handle the XON/XOFF itself as I haven't spotted
anything in OpenThread that implements it. spinel itself looks to be
designed to avoid the use of XON/XOFF characters, so I suspect it should
work okay. Has anyone tried using this or have any advice on software
flow control?

[Stuart Longland]

On 22/08/17 14:52, Stuart Longland wrote:
> I think I am seeing that with the 0xff in the IPv6 address, which is why
> it is complaining about a multicast bit being set, and various framing
> errors. Question is though, okay we can safely ignore parity errors,
> but how do we handle overruns, breaks or frame errors?

Okay, fixed that problem… mostly… I still get the odd frame error I
notice, but I am able to actually send traffic through the NCP this time:

> wpantund[3773]: Starting wpantund 0.08.00d (Aug 1 2017 14:30:16) . . .
> wpantund[3773]: SOURCE_VERSION = 0.07.01-116-gf26ee8f
> wpantund[3773]: BUILD_VERSION = 0.07.01-116-gf26ee8f
> wpantund[3773]: Configuration file "/usr/local/etc/wpantund.conf" read.
> wpantund[3773]: Ready. Using DBUS bus ":1.0"
> wpantund[3773]: Running as root without dropping privileges!
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:412: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: Resetting and trying again... (retry 1)
> wpantund[3773]: [-NCP-]: NCP was reset (STATUS_RESET_POWER_ON, 112)
> wpantund[3773]: [NCP->]: Frame CRC Mismatch: Calc:0xD82D != Frame:0xD97E, Garbage on line?
> wpantund[3773]: [NCP->]: Garbage is not ASCII ([0]=128)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:412: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: Resetting and trying again... (retry 2)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:402: Requirement Failed (event == EVENT_NCP_RESET)
> wpantund[3773]: Resetting and trying again... (retry 3)
> wpantund[3773]: [-NCP-]: NCP was reset (STATUS_RESET_POWER_ON, 112)
> wpantund[3773]: [NCP->]: Frame CRC Mismatch: Calc:0xEAC4 != Frame:0xF1C2, Garbage on line?
> wpantund[3773]: [NCP->]: Garbage is not ASCII ([0]=128)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:412: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: The NCP is misbehaving: Repeatedly unable to initialize NCP. Entering fault state.
> wpantund[3773]: State change: "uninitialized" -> "uninitialized:fault"
> wpantund[3773]: State change: "uninitialized:fault" -> "uninitialized"
> wpantund[3773]: SpinelNCPTask.cpp:70: Requirement Failed (Failure while trying to send command)
> wpantund[3773]: SpinelNCPTaskSendCommand.cpp:322: Requirement Failed ((mRetVal) == 0)
> wpantund[3773]: SendCommand task encountered an error: 7 (0x00000007)
> wpantund[3773]: [-NCP-]: NCP was reset (STATUS_RESET_POWER_ON, 112)
> wpantund[3773]: State change: "uninitialized" -> "offline"
> wpantund[3773]: NCP is running "OPENTHREAD/0.01.00; CC2538; Aug 22 2017 12:07:50"
> wpantund[3773]: Driver is running "0.08.00d (0.07.01-116-gf26ee8f; Aug 1 2017 14:30:16)"
> wpantund[3773]: HARDWARE ADDRESS IS INVALID, MULTICAST BIT IS SET!
> wpantund[3773]: Network is not joinable
> wpantund[3773]: Resetting interface(s). . .
> wpantund[3773]: Finished initializing NCP
> wpantund[3773]: [-NCP-]: NCP was reset (STATUS_RESET_POWER_ON, 112)
> wpantund[3773]: State change: "offline" -> "uninitialized"
> wpantund[3773]: State change: "uninitialized" -> "offline"
> wpantund[3773]: NCP is running "OPENTHREAD/0.01.00; CC2538; Aug 22 2017 12:07:50"
> wpantund[3773]: Driver is running "0.08.00d (0.07.01-116-gf26ee8f; Aug 1 2017 14:30:16)"
> wpantund[3773]: Network is not joinable
> wpantund[3773]: Resetting interface(s). . .
> wpantund[3773]: Finished initializing NCP
> wpantund[3773]: Scan -> Name:WideSky , PanId:0x0000, Ch:11, Joinable:NO , XPanId:0xDEAD00BEEF00CAFE, HwAddr:0x8ACB5F22091366FE, RSSI:4 , LQI:107, ProtoId:3 , Version: 0, ShortAddr:0xFFFF
> wpantund[3773]: State change: "offline" -> "associating"
> wpantund[3773]: State change: "associating" -> "associated"
> wpantund[3773]: Node type change: "unknown" -> "end-device"
> wpantund[3773]: [NCP->]: Frame CRC Mismatch: Calc:0xC11D != Frame:0x082A, Garbage on line?
> wpantund[3773]: [NCP->]: Garbage is not ASCII ([0]=128)
> wpantund[3773]: SpinelNCPTask.cpp:85: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: SpinelNCPTaskSendCommand.cpp:322: Requirement Failed ((mRetVal) == 0)
> wpantund[3773]: SendCommand task encountered an error: 7 (0x00000007)
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: NCP => Framing error 6: [80 03 72 68 00 60 02 6B 7E 00 40 3A 01 FE 80 00 00 00 00 00 00 1C 66 DD DA 3A 0C 73 D8 FF 02 00 00 00 00 00 00 00 00 00 00]
> wpantund[3773]: SpinelNCPTask.cpp:85: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: SpinelNCPTaskSendCommand.cpp:322: Requirement Failed ((mRetVal) == 0)
> wpantund[3773]: SendCommand task encountered an error: 7 (0x00000007)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:232: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: NCP is misbehaving or unresponsive
> wpantund[3773]: State change: "associated" -> "uninitialized"
> wpantund[3773]: Taking interface(s) down. . .
> wpantund[3773]: "fdde:ad00:beef:0:e855:820b:4347:d7fa" was removed from "wpan0"
> wpantund[3773]: "fe80::1c66:ddda:3a0c:73d8" was removed from "wpan0"
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:412: Requirement Failed (IS_EVENT_FROM_NCP(event) && GetInstance(this)->mInboundHeader == mLastHeader)
> wpantund[3773]: Resetting and trying again... (retry 1)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:402: Requirement Failed (event == EVENT_NCP_RESET)
> wpantund[3773]: Resetting and trying again... (retry 2)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:402: Requirement Failed (event == EVENT_NCP_RESET)
> wpantund[3773]: Resetting and trying again... (retry 3)
> wpantund[3773]: SpinelNCPInstance-Protothreads.cpp:402: Requirement Failed (event == EVENT_NCP_RESET)
> wpantund[3773]: The NCP is misbehaving: Repeatedly unable to initialize NCP. Entering fault state.
> wpantund[3773]: State change: "uninitialized" -> "uninitialized:fault"

It seems though that the NCP works for a little while, then stops. So
more work it seems. That might be the buffering bug I initially suspected.

At the moment, it ignores bytes that have frame errors, breaks or
overrun status bits flagged. Not sure if that is the best approach, it
would be nice to signal to OpenThread that there's some garbage here and
let it handle the situation (probably by pre-emptively throwing out the
buffer content and waiting for the next frame).

Also, while I'm doing software flow control on my end, I'm still not
sure if `wpantund` implements it, which might be what's happening too,
the buffer gets overrun and that's when it hiccups. Thoughts?

Regards,

[Stuart Longland]

On 22/08/17 17:49, Stuart Longland wrote:
> It seems though that the NCP works for a little while, then stops. So
> more work it seems. That might be the buffering bug I initially suspected.
>
> At the moment, it ignores bytes that have frame errors, breaks or
> overrun status bits flagged. Not sure if that is the best approach, it
> would be nice to signal to OpenThread that there's some garbage here and
> let it handle the situation (probably by pre-emptively throwing out the
> buffer content and waiting for the next frame).
>
> Also, while I'm doing software flow control on my end, I'm still not
> sure if `wpantund` implements it, which might be what's happening too,
> the buffer gets overrun and that's when it hiccups. Thoughts?

Also wpantund related… this is a quote from the manual page:

> OPTIONS
> -h, --help
> Print help.
>
> -v, --version
> Print version.
>
> -d, --debug LEVEL
> Enable debugging mode (see DEBUGGING below).
…
> -- NCPSocketBaud
>
> DEBUGGING
> EXAMPLES
> $ sudo wpantund -o NCPSocketName /dev/ttyUSB0 -o WPANInterfaceName wpan0
> Starts wpantund on /dev/ttyUSB0 and create network intarfeca called wpan0.
>
> FILES
> /etc/wpantund.conf
> The default wpantund configuration file.

I think some text is missing.

[Stuart Longland]

On 22/08/17 17:49, Stuart Longland wrote:

> Also, while I'm doing software flow control on my end, I'm still not
> sure if `wpantund` implements it, which might be what's happening too,
> the buffer gets overrun and that's when it hiccups. Thoughts?

Turns out you can… but the interface is not obvious, I had to dig
through the code to find it. You use a socket path of the form:

serial:/dev/ttySx,default,ixon=1,crtscts=0,b9600

where ttySx is your serial device. (it's ttyS1 on the Advantech box
we're planning to use.)

Note that the bXXXX is needed to set the baud rate as the -b option to
wpanctl breaks when the options are specified directly like this.

[Stuart Longland]

On 23/08/17 12:18, Stuart Longland wrote:
>> Also, while I'm doing software flow control on my end, I'm still not
>> sure if `wpantund` implements it, which might be what's happening too,
>> the buffer gets overrun and that's when it hiccups. Thoughts?
> Turns out you can… but the interface is not obvious, I had to dig
> through the code to find it. You use a socket path of the form:
>
> serial:/dev/ttySx,default,ixon=1,crtscts=0,b9600
>
> where ttySx is your serial device. (it's ttyS1 on the Advantech box
> we're planning to use.)

So the above may be useful for those who want to try software flow
control, but I've just realised while it will work with full-duplex
RS-485, RS-232 or RS-422, it will never work with half-duplex RS-485
because you cannot send the XOFF byte whilst receiving data from the
host as you're sharing the same pair of wires for transmit and receive.

That should have been obvious to me, but it's amazing how one can forget
little details like that when you're focused on one problem.

There's generally no such animal as hardware flow control on these sorts
of control links, so I guess the answer is to enlarge the buffers and
hope they never fill up. Still, that does beg the question, what do we
do at the MCU end when they do?

[Stuart Longland]

On 23/08/17 10:50, Stuart Longland wrote:
> On 22/08/17 17:49, Stuart Longland wrote:
>> It seems though that the NCP works for a little while, then stops. So
>> more work it seems. That might be the buffering bug I initially suspected.
>>
>> At the moment, it ignores bytes that have frame errors, breaks or
>> overrun status bits flagged. Not sure if that is the best approach, it
>> would be nice to signal to OpenThread that there's some garbage here and
>> let it handle the situation (probably by pre-emptively throwing out the
>> buffer content and waiting for the next frame).
>>
>> Also, while I'm doing software flow control on my end, I'm still not
>> sure if `wpantund` implements it, which might be what's happening too,
>> the buffer gets overrun and that's when it hiccups. Thoughts?
>
> Also wpantund related… this is a quote from the manual page:
>

> I think some text is missing.

Still battling this. I haven't got flow control available to me as I
have to work half-duplex. I've turned off the PARMRK-inspired byte
stuffing for reporting errors, and I've re-worked my buffering code.

It works better now, but:
- when first starting `wpantund`, it sometimes fails to reset the NCP.
I need this to work unattended, so having it try 3 times then give up is
not helpful.
- it will sometimes drop out, requiring a reset to keep the link up.
Again, sometimes reset works automatically, sometimes it needs a manual
poke.
- I get the odd CRC errors with frames from data being sent from the NCP
(as far as I can tell), e.g.:

wpantund[22717]: [NCP->]: Frame CRC Mismatch: Calc:0x1DE3 !=
Frame:0x72A6, Garbage on line?
wpantund[22717]: [NCP->]: Garbage is not ASCII ([0]=128)

I have no idea where this corruption is being introduced, and my job of
finding this is made neigh on impossible due to my lack of understanding
in how the NCP generates the spinel frames, and not having visibility of
those said frames as they're consumed on the host. A hexdump of the
incoming frame would be a real nice feature here as it would at least
let me figure out which part of the frame is possibly in error. Does
anyone know how to extract such a beast out of wpantund logs?

In my case, I'm just transmitting what OpenThread tells me to transmit.
It works fine elsewhere, so I'm a bit miffed as to why this should be
generating CRC errors. The code literally is:

> otError otPlatUartSend(const uint8_t *aBuf, uint16_t aBufLength) {
> console_out_buf = aBuf;
> console_out_sz = aBufLength;
> return OT_ERROR_NONE;
> }

…in a function called from the `main()` loop:
> if (console_out_buf) {
> /* Write via the newlib stub */
> write(FD_CONSOLE_OUT, console_out_buf, console_out_sz);
>
> console_out_buf = NULL;
> console_out_sz = 0;
>
> otPlatUartSendDone();
> }

and in my `_write_r` stub:
> /* Wait for clear-to-send */
> while (!serial_is_cts());
>
> /* Put the device into write mode */
> serial_mode_dir(serial_port, 1);
>
> /* Wait a bit so we don't chop the frame off! */
> delay_us(1000000 / (serial_config[serial_port] & SERIAL_BAUD_bm));
>
> /* Write the data */
> cc2538_uart_tx(CC2538_UART_PORT0_ADDR, (uint8_t*)buf, cnt, true);
>
> /* Wait a bit so we don't chop the frame off! */
> delay_us(1000000 / (serial_config[serial_port] & SERIAL_BAUD_bm));
>
> /* Put the device back into receive */
> serial_mode_dir(serial_port, 0);
>
> /* Reset clear-to-send */
> serial_cts_reset();
> return cnt;

The `serial_is_cts` here has no effect as that's only used when in
Modbus timeout mode. I'm not sure if the Modbus/RTU timeout handling
would help or hinder here.

The flow control is handled transparently from OpenThread's perspective.
Looking at oscilloscope traces on the UART transmit and RS-485 driver
enable lines, it appears this code is doing what's expected of it:

http://www.longlandclan.id.au/~stuartl/openthread/2017/08/24-spinel-rs485/qc000001.png
http://www.longlandclan.id.au/~stuartl/openthread/2017/08/24-spinel-rs485/qc000002.png
http://www.longlandclan.id.au/~stuartl/openthread/2017/08/24-spinel-rs485/qc000003.png
http://www.longlandclan.id.au/~stuartl/openthread/2017/08/24-spinel-rs485/qc000004.png

Not sure if that's one spinel frame or two in that capture, I suspect
one but I'm not sure how they're constructed and sent from the
OpenThread end. I presume that I am safe in assuming the buffer passed
to `otPlatUartSend` does not change before `otPlatUartSendDone` is called?

Another problem I'm noticing that even though the NCP is associated,
`wpantund` doesn't pass on IPv6 addresses to the `wpan0` device:

> stuartl@vk4msl-ws ~ $ sudo wpanctl
> Password:
> wpanctl:wpan0> status
> wpan0 => [
> "NCP:State" => "associated"
> "Daemon:Enabled" => true
> "NCP:Version" => "OPENTHREAD/0.01.00; CC2538; Aug 23 2017 13:48:56"
> "Daemon:Version" => "0.08.00d (0.07.01-122-ga5d2c20; Aug 24 2017 15:24:03)"
> "Config:NCP:DriverName" => "spinel"
> "NCP:HardwareAddress" => [11F47B8000124B00]
> "NCP:Channel" => 11
> "Network:NodeType" => "router"
> "Network:Name" => "WideSky"
> "Network:XPANID" => 0xDEAD00BEEF00CAFE
> "Network:PANID" => 0x0000
> "IPv6:LinkLocalAddress" => "fe80::a8a1:61bd:2439:ec05"
> "IPv6:MeshLocalAddress" => "fdde:ad00:beef:0:6e3d:3c4c:77c8:3fcc"
> "IPv6:MeshLocalPrefix" => "fdde:ad00:beef::/64"
> "com.nestlabs.internal:Network:AllowingJoin" => false
> ]
> wpanctl:wpan0>
> stuartl@vk4msl-ws ~ $ ip -6 addr show dev wpan0
> 74: wpan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1280 state UNKNOWN qlen 500
> inet6 fe80::5fce:78e8:cc71:d9c2/64 scope link flags 800
> valid_lft forever preferred_lft forever
I have to kill `wpantund` and re-start it. Again, this is going to be
problematic with non-interactive use, such as with the OpenThread Border
Router.

http://www.longlandclan.id.au/~stuartl/openthread/2017/08/24-spinel-rs485/debug.log
is the logs from wpantund… they're a bit big to post here in full. If
anyone can shed some light on what could be tripping this up, I'm all ears.

Thanks in advance.
Regards,

[Ellis, Duane]

Stuart> Still battling this. I haven't got flow control available to me as I have to work half-duplex. I've turned off the PARMRK-inspired byte stuffing for reporting errors, and I've re-worked my buffering code.

Hmm - the central problem I think you are going to have both ends need to send spontaneous messages asynchronously.
You never know when a packet will arrive on either side of the NCP & WPANTUND

In a half-duplex situation, that's non-trivial - and the only viable way I know of is a polling packet.

The well known examples that I know are:

USB 1.1 & USB2 - is a half duplex solution, the host (your PC) periodically sends an "IN" packet to the FUNCTION (aka: the device, example: keyboard, mouse, thumbdrive) and that device must send either (a) NAK - indicating no data or (b) DATA which of course means data.

(widely used, but not widely known) is actually harder, in that it is a multidrop half duplex system. This is found in older IBM point of sale cash registers to talk to barcode scanners, printers, weight scales, and other devices. The point of sale (POS) machine periodically polls devices on the bus, and they have a window to respond, with data, or no data

The point here is I think you are going to have to "wrap" the SPINEL protocol in something that is more agreeable with your half duplex transport.

[Stuart Longland]

Hi Duane,

Many thanks for your insights here. Indeed I think raw SPINEL/UART
isn't going to work as-is, and the requirement is an unusual one in the
context of SPINEL.

I did try using Modbus/RTU style framing… that is, all frames have a 3.5
character pause, and existing frames discarded if there's a break of
more than 1.5 characters, but as the PC wasn't aware of this, I don't
think it helped much.
--
Stuart Longland
Systems Engineer
_ ___

[rqua...@google.com]

Yes, we really need to document that mechanism. Glad you found it. :)

[rqua...@google.com]

On Wednesday, August 23, 2017 at 11:00:39 PM UTC-7, Stuart Longland wrote:

Still battling this.  I haven't got flow control available to me as I
have to work half-duplex.  I've turned off the PARMRK-inspired byte
stuffing for reporting errors, and I've re-worked my buffering code.

 As Duane Ellis pointed out, the recommended Spinel UART frame transport is really only designed to be used with real full-duplex UART connections. If you are running half-duplex, you will need to design your own frame transport protocol and write a tool like spi-hdlc-adapter as an adapter (wpantund can talk to programs as if they were the NCP using the system: prefix).

This hypothetical protocol will be significantly more complex due to the fact that you will need to have explicit retransmission and reliability support. We get away without that with UART because a correctly implemented UART tends to be fairly reliable when the signal is transmitted just a centimeter or so.

Another alternative may be to write up a native USB transport and write up an adapter program (usb-hdlc-adapter perhaps?) to allow you to communicate with it using wpantund. Or you could do as you described, using USB-CDC-ACM.

I was in the process of writing up a reliability and fragmentation layer that would then allow an unreliable frame transport to be used as a reliable frame transport, but other work has taken priority and prevented me from coming back to it. I did write up a protocol document for it, but I'm far from a working implementation. The protocol was also designed to be able to do multiplexing (although it is technically optional) and MTU negotiation.

[Stuart Longland]

On 25/08/17 09:57, rquattle via openthread-users wrote:
>
> As Duane Ellis pointed out, the recommended Spinel UART frame transport

> <https://tools.ietf.org/html/draft-rquattle-spinel-unified-00#appendix-A.1> is

> really only designed to be used with real full-duplex UART connections.
> If you are running half-duplex, you will need to design your own frame
> transport protocol and write a tool like spi-hdlc-adapter

> <https://github.com/openthread/openthread/tree/master/tools/spi-hdlc-adapter#spihdlc-adaptor>

> as an adapter (wpantund can talk to programs as if they were the NCP
> using the system: prefix).

Ahh okay, so in theory that program could be something like `nc` talking
to a serial-Ethernet gateway or is something more capable needed?

> This hypothetical protocol will be significantly more complex due to the
> fact that you will need to have explicit retransmission and reliability
> support. We get away without that with UART because a correctly
> implemented UART tends to be fairly reliable when the signal is
> transmitted just a centimeter or so.

Yeah, the ideal from my point of view would have been a USB-serial
interface on the board. We've burned more than the cost of one of these
in engineering time with me debugging this already.

The design actually does have the USB controller on the CC2538 broken
out to a micro-USB connector, but then interfacing to that needs a USB
stack on the CC2538 where resources are tight.

Right now, it looks like the way forward is to use the two RS-485
transceivers together, one permanently in receive, the other in
transmit, which will give us a full-duplex RS-485, or RS-422 compatible
serial link.

It turns out there is an add-on board for the industrial computers we're
using that gives us RS-422, and using that, I should be able to do
full-duplex serial with software flow control.