Sunday, July 19, 2020

LBARD over Codan HF modem and debugging LBARD sync problems

This week I am finally getting to working on the remaining work for supporting the Codan 3012 HF data modem in LBARD.  This was started a long time ago, but has stalled at various points along the way.

The purpose of using this data modem is that it comes as a software option in the Codan Envoy 2210 HF radios, and can in theory transfer close to 100x more data than the horrible ALE text message method that we had demonstrated a few years ago.  That said, we are still talking about a data link that in theory can do 2,400bits per second. I say in theory, because that relies on good atmospheric conditions for the HF communications, and because the link is actually half-duplex with quite a noticeable turn-around time.  That is, the modem at one end sends a blob of data, stops transmitting, and begins listening. The modem at the other end receives the blob of data, switches to transmit, transmits its blob of data, stops transmitting and begins listening. This is a good thing, but not so helpful for our data throughput. Thus it takes perhaps a tenth of a second or more to do the turn-around.  Because this is all happening with radios that can transmit at 125W, it involves relays and various safe-guards in the TX to RX turn-around.

The modems seem to send a data blob lasting 2 seconds. So in every ~(2 + 0.1 + 2 + 0.1) seconds we get to send one blob of data.  Thus while the channel can carry 2,400 bits per second, we are limited to something below 1,200 bits per second from each end. We'll estimate this to be about 1,000 bits per second for ease of calculation.  This should give us an effective data rate of a bout 125 bytes per second in each direction.

This is pretty modest by modern internet standards, but it does correlate to about one text message per second. Of course, by the time we have overhead for routing, authentication and other house-keeping elements, a text message might be closer to 1KB, which would require about 8 seconds to send under ideal conditions.  This means that a link that is active 24/7 could send and receive about 86,400 seconds/day / 8 seconds = ~10,000 messages per day.  Even with just an hour a day this means that we should be able to send and receive about 400 messages. Given our goal is to connect small isolated island communities in the Pacific, and to provide backup text messaging capability during disasters, this sounds like a pretty reasonable capacity -- and certainly better than the 10 to 15 minutes it was taking to send an authenticated text message via the ALE text messaging channel!

The radio setup I have here is a pair of Codan 2210s kindly loaned to us by Codan themselves.  I have these hooked up to a laptop here via USB serial adapters.

The first step is to enable the data modems on the Envoy radios. If you have obtained these radios without enabling this feature, you will need to give Codan a call to purchase an unlock code.  You shouldn't need any hardware changes, which is handy, if you are already in the middle of nowhere, needing to setup communications.

Next, use the handset to select "Menu", "User data", "Peripherals" and "RFU GP port", and select "2.4kbps data modem". It is important to NOT select "3012 mode", unless you really are using an external modem, rather than the built-in one.  The menus are shown in the following figures:





The modems themselves have an interesting feature, where they report themselves when you connect to them via the USB serial port.  However, if you power the Envoy on with the USB already connected, this doesn't always occur, and sometimes I had problems getting anything out of the modem in that context. The solution is to disconnect the USB port from the computer and reconnect it. 

I'll have to think about a robust solution for that,  as it can cause LBARD's auto-detection of the modem to fail, which would be unfortunate for automatic operation, which is what we want to achieve. It might be possible to do a software USB disconnect and reconnect, for example. Or there might be some magic option I need to setup on the radio.  Anyway, we'll come back to that later.

The modems need only a few simple commands to control them -- assuming the HF radios are sitting on the same channel. I haven't yet used the commands that the modems offer for selecting channels, although it should be quite possible.

The first thing to do is to give the modem a station ID. This is a bit like a phone number. It can have upto 6 digits, but for reasons I don't immediately recall, the last two digits cannot be 00.  This is set using the AT&I=number command, e.g.:

AT&I=2

would set the station ID to 2.  Once that has been setup, you can tell a modem to try to dial it using the good old ATD command, e.g.,

ATD2

would call a modem that had been configured as previously described. This will cause the standard RING, NO ANSWER, NO CARRIER, and CONNECTED messages to be displayed based on whether the remote end answers with ATA or not, or later disconnects with ATH0.  In short, Codan have done a great job of making this modem masquerade as an old-fashion 2400 bps data modem.  This helps it be compatible with various existing software, and helps me, because I have previously had many adventures programming such modems.

The modems default to having compression enabled, although I don't know what kind of compression they have, nor how effective it is.  For now, I am just ignoring it, and leaving it in the default setting of enabled. 

Armed with the information on how to control the modem, I set about creating an LBARD driver for it. This consists mostly of an auto-detection routine, the state machine for managing the call states, and routines for sending and receiving packets.  This is all in the src/drivers/drv_codan3012.c file.

Initialisation just consists of sending a few AT commands to set the modem's HF station ID, and enable hardware flow-control:

int hfcodan3012_initialise(int serialfd)
{
  char cmd[1024];
  fprintf(stderr,"Initialising Codan HF 3012 modem with id '%s'...\n",hfselfid?hfselfid:"<not set>");
  snprintf(cmd,1024,"at&i=%s\r\n",hfselfid?hfselfid:"1");
  write_all(serialfd,cmd,strlen(cmd));
  fprintf(stderr,"Set HF station ID in modem to '%s'\n",hfselfid?hfselfid:"1");

  snprintf(cmd,1024,"at&k=3\r\n");
  write_all(serialfd,cmd,strlen(cmd));
  fprintf(stderr,"Enabling hardware flow control.\n");

  // Slow message rate, so that we don't have overruns all the time,
  // and so that we don't end up with lots of missed packets which messes with the
  // sync algorithm
  message_update_interval = 1000;
 
}


Flow control is a bit interesting to manage. The big problem is that we don't want the buffer of the modem to get too full, as this makes the round-trip time for control messages too long, which slows things down. For example, if the far end doesn't quickly confirm that a given bundle has been received, the sender will keep sending pieces of it. Thus we need to keep well away from hitting the flow control-imposed limit. The packet sending and receiving routines keep track of this by having sequence numbers that are then returned to the sender, so that the sender can get an idea of the number of packets in flight.

LBARD modulates packet flow, not by the number of packets in flight, but by the average interval between packets.  As a first-cut approach, I set the packet interval dynamically based on the number of outstanding packets in flight.  Basically I set the packet interval to some multiple of the number of outstanding packets.  250ms per outstanding packet seems to work ok, with reasonable throughput balanced against not having too many unacknolwedged packets to waste outgoing bandwidth with needless retransmissions.  I can refine that a bit more later.

The state machine for the modem is also fairly simple:
 
  switch(hf_state) {
  case HF_DISCONNECTED:
    if (hfcallplan) {
      int n;
      char remoteid[1024];
      int f=sscanf(&hfcallplan[hfcallplan_pos],
                   "call %[^,]%n",
                   remoteid,&n);
      if (f==1) {
        hfcallplan_pos+=n;
        fprintf(stderr,"Calling station '%s'\n",remoteid);
        char cmd[1024];
        snprintf(cmd,1024,"atd%s\r\n",remoteid);
        write_all(serialfd,cmd,strlen(cmd));
        call_timeout=time(0)+300;
        hf_state=HF_CALLREQUESTED;
     } else {
        fprintf(stderr," remoteid='%s', n=%d, f=%d\n",remoteid,n,f);
      }
     
      while (hfcallplan[hfcallplan_pos]==',') hfcallplan_pos++;
      if (!hfcallplan[hfcallplan_pos]) hfcallplan_pos=0;
    }   
    break;
  case HF_CALLREQUESTED:
    if (time(0)>=call_timeout) hf_state=HF_DISCONNECTED;
    break;
  case HF_ANSWERCALL:
    write_all(serialfd,"ata\r\n",5);
    hf_state=HF_CONNECTING;
    call_timeout=300;
    break;
  case HF_CONNECTING:
    // wait for CONNECT or NO CARRIER message
    break;
  case HF_DATALINK:
    // Modem is connected
    write_all(serialfd,"ato\r\n",5);
    hf_state=HF_DATAONLINE;
    call_timeout=time(0)+120;
    break;
  case HF_DATAONLINE:
    // Mode is online.  Do nothing but indicate that the modem is
    // ready to process packets
    if (time(0)>call_timeout) {
      // Nothing for too long, so hang up
      sleep(2);
      write_all(serialfd,"+++",3);
      sleep(2);
      write_all(serialfd,"ath0\r\n",5);
      hf_state=HF_DISCONNECTED;
    }
    break;
  case HF_DISCONNECTING:
    break;
  default:
    break;
  }
 
In short, we make a call if we have been instructed to, and am not currently on a call.  Otherwise stay on the call unless we get no data for too long, in which case, hang up, and repeat the process.

With the above and the necessary glue, I was able to get packets flowing between the two modems fairly easily.  But when I started trying to transfer bundles, I started seeing the protocol get confused with both sides trying to send each other the same bundle endlessly.  This should never happen, as when one end realises that the other has a given bundle, it should stop trying to send it, because it has pretty clear evidence that the other end has it already. 

I'd seen this problem before in the field with UHF radios in the Mesh Extenders, but it had stubbornly refused to be reproduced reliably in the lab.  So while it is on the one hand annoying, its actually a great relief to have found the problem, and to be able to progressively work on solving it.

It turns out to be caused by a number of things:

First, the TreeSync algorithm seems to not realise when the other end receives a bundle, even though it should.  That module is quite fancy and efficient at doing its job, and I don't understand it well enough to figure out what subtle problem it is suffering from.  The mechanism by which this causes the lockup took a little while to realise, but it made a lot of sense once realised it:  Once both sides have as their highest priority bundle for the other a bundle that the other side actually has, and that trips this TreeSync problem, then they will continue to try to send it forever.

It self-corrects eventually, but only briefly, because when it produces a new generation ID, the tree is re-built, which allows it to send the next few bundles before locking again.  To work around this, I now maintain a list of bundles that we have seen the other end try to send.  If they try to send a bundle, then they must by definition have it.  Therefore we should never try to send that bundle to them again.  This works to stop the TreeSync algorithm from re-scheduling the same bundle over and over.

That fixed the protocol lock-up.  Then I was seeing that the scheduling of which data blocks to send was being completely random.  Now, it is supposed to be rather random, so that if multiple senders are available for a given bundle, a single receiver can receive pieces from all of them, and thus receive the bundle as a whole sooner. 

The problem was that the system for keeping track of which blocks we think the recipient might already have was not being activated, because it was getting confused about which bundle we thought we were sending them, or should be sending them.  As a result very small bundles consisting of only a few blocks would send in reasonable time, as the probability of all their blocks being sent would approach 1 very quickly. But larger bundles consisting of more than a dozen or so blocks would be extremely slow to send, because it was basically pot luck waiting for the last few holes to get filled in.

This required a bit of fiddling about in a few different places to pick up all the corner cases of when we should reset it, and making sure that we clear the bitmap of sent blocks and other minor details. I also fixed the situation where we see another party sending a bundle to someone, and we haven't yet worked out what to send to them.  In that case, we now join in sending the same bundle, so that the receiver can hopefully receive the whole bundle that bit quicker. 

These multi-way transfer optimisations are not really applicable to the HF radios, as the modems are designed for point-to-point, but it made sense to implement them, anyway. Also, down the track, it would be possible for us to look at ways to make a radio listen to multiple HF radio channels in parallel, and receive all the content being delivered on them.  This promiscuous mode of listening could greatly increase the effective capacity of the system, and basically is just a sensible use of the true broadcast nature of radio.

Back to the bitmap sending, even after I got it working, it was still not particularly efficient, as even when there were a relatively few pieces left to send, it would still chose them at random, potentially resending the same block many times until the next bitmap update came through.  As the round-trip latency is typically 10 - 20 seconds, by the time all the modem buffering is done, this can add significant delays through redundant sending. Also, it can get stuck sending manifest pieces for a long time, which again can be quite wasteful, as the manifest is typically less than 300 bytes, and will keep getting resent until the bitmap update comes through indicating that the manifest has been fully received. 

What would be better, would be to keep track of the set of pieces that are outstanding at any point in time, and just randomise their order, and then send them in that randomised order, and then start over.  That way we will avoid redundant sending.  The order can be randomised afresh each time we get a bitmap update.

First implementation of this, seems to work fairly well: It sends the blocks in random order. It's still not as fast as I would like, averaging only about 20 bytes per second in each direction.  This will be partly because I am sending 64 byte blocks at random, but the packets can hold 128 or sometimes even 192 bytes. But if there are no contiguous outstanding blocks, then it will end up being very inefficient.  I'll likely fix that by allowing a message type that can contain more than one piece of the same bundle.  Actually, I figured out an easier quick fix: Consider all odd-numbered blocked to have been send once already, so that we try to send all the even-numbered ones at least once.


The bigger problem, though, is that the indication of when the other end has received a bundle is not working properly, and so we are back to our protocol lock-up situation.

So looking at a particular run when this is occurring, we have LBARD2 and LBARD8 talking to each other.

The begin by exchanging two small bundles with each other, before moving on to transfer bundles of several KB. 

LBARD2 receives bundle 4B47* (4870 bytes long) from LBARD8. LBARD8 receives C884* (4850 bytes long) from LBARD2. 

So both now have C884*.  The problem is that both think that the other doesn't have it. As C884* is smaller than 4B47*, it has a higher TX priority, and thus both sides keep trying to send it to the other.

LBARD8 received C884* at 11:42.38.   By 11:42:47, LBARD8 has received confirmation that the bundle was inserted into the Rhizome database, and thus knows definitively that it has the bundle.

Even though it knows that it has this bundle, it continues to accept receiving the bundle afresh from LBARD2.

Part of the problem is that LBARD8 doesn't immediately note that LBARD2 has the bundle.  It should do this, whenever it sees LBARD2 sending a piece of the bundle. 

In fact, there is no indication whatever that LBARD8 is receiving the pieces of the bundle after it has received it the first time.  I'll need to re-run with more debugging enabled.  Perhaps part of LBARD is noticing that it already has the bundle, thus is ignoring the messages, but without scheduling the indication to the other end that it already has the bundle.  But even if that is not the case, the receiver shouldn't be willing to again start reception of the same bundle, after it knows that it has it itself. 

Each run has randomised bundle IDs, which is a bit annoying.  So I have to trawl through the logs again to see what is going on.

So this time, LBARD2 receives bundle D386* from LBARD8 at 12:18.26.

Interestingly, the "recent senders" information is correctly noting that LBARD8 has sent a piece of this bundle.  So I can make use of that to update the other structures, if necessary.

At the point where LBARD2 receives D386*, it is sending bundle 3A7C* to LBARD8.
Ah, I have just spotted at the point where we realise that the other party has the bundle, instead of dequeuing the bundle to them, we are actually queueing it to them.  That should be fixed. This is also the point at which we should mark that we know that that peer has the bundle already.  So we will try that in the next run.  Simultaneously I have added some instrumentation for the "prioritise even over odd" optimisation, as it doesn't seem to be doing exactly what it should.

Fixed that, and some other related bugs. It now does a fairly reasonable job of scheduling, although there is still room for improvement. The big problem is that it is still sitting at around 20 bytes per second of effective throughput. 

Now, this isn't as bad as it sounds, as that includes the overhead of negotiating what needs to be sent, and packetising it all, so that if the modems do lose packets, we don't lose anything. It also reflects the reality that we are only sending one packet in each direction every 3 seconds or so.  With an effective MTU of 220 bytes, we only end up fitting one or two 64 byte blocks of data in each.  Thus our potential throughput is limited to about 64 or 128 bytes every 3 seconds = ~20 -- 40 bytes per second. 

So at the current state of affairs, we have something that is at least 10x faster than the old ALE messaging based transport -- and its is bidirectional throughput. We are seeing message delivery latencies for short messages that are about 30 to 50 seconds.  This compares very favourably to the ~3 minutes that sending a bundle was taking with the ALE transport.  But it still isn't as good as we would like or, I think, we can achieve.  We know that we should have something like 125 bytes per second of bandwidth in each direction.  Even with the suboptimal scheduling of pieces to send, we should be able to achieve at least half of that figure.

The first port of call is to try to optimise the packet sending rate, as it seems that one packet of ~260 bytes in each direction every ~3 seconds or so is probably not quite filling the 2,400bps channel, even allowing for the change-over.  Well, that sounded like a great theory. Looking closer, the packet rate is closer to one every 2 seconds, not every 3 seconds.  2400bps / 2 = 1200bps = 150 bytes per second raw rate in each direction, before subtracting a bit for turn-around.  Thus sending a 255 byte packet every 2 seconds = ~128 bytes per second, which is pretty much spot on the channel capacity.

This means we will have to look at other options.  The most obvious is to send large slabs of bundles, without all the other protocol fluff.  This is only really possible in this context, because the modem link is point-to-point, so we don't have to worry about any trade-offs. In fact, the whole packet format and message types are really a bit of an over-kill for this configuration.  But short of re-writing the whole thing, we can instead get some substantial gain by just sending a slab of useful bundle data after every normal LBARD packet.  This will get us half of the channel use at close to 100% goodput, and thus bring the average up to >50%.   If we send large contiguous slabs, then that will also reduce the opportunity for the block scheduling to get too much wrong, so it may well be even more effective. 

The modem has no natural packet size limit, so we can even send more than 256 bytes at a time -- if we trust ourselves to the modem's error correction to get the data to the other end intact. If errors creep in, and we don't have a means of detecting them, it will be really bad. The current error correcting code works on blocks of 232 bytes. We don't want to send huge amounts, though, as we want to maintain the agility to respond to changing bundle mixes. 

The largest number of 64 byte blocks we can thus fit would be 192 bytes.  256 would have been nicer, so that it would be an even number of blocks. That's a bit annoying, so I'll have to make a different type of packet that can carry upto 256 bytes of raw data. It will assume that the data is for the currently selected bundle, and thus only have a 4 byte offset and 2 byte length indicator, plus the escaping of the packet termination character. Thus it should have an average overhead of less than 10 bytes, and thus be better than 90% efficient.

Well, the next challenge was that some bytes were getting lost, as though buffer overflow was occurring.  However, as I have hardware flow-control enabled, I'm not sure of the cause here.  My work around is to send only 192 bytes, after all, and to make sure I throttle back the packet sending rate,  to try to keep the data flowing at a reasonable rate, without overwhelming the buffers.  This is a bit worrying, as in real life it is quite likely that we will get data rates below 2,400bps on the HF links quite often. 

Reducing the data packet size to 192 bytes has seemed to fix the buffer overflow problem. Also, I am now seeing the larger bundles go through more quickly.  However, I am still seeing the problem where the same bundle is received more than once.  Presumably it starts being received a 2nd time before we get confirmation from the Rhizome data base that it has been inserted. 

The solution would be to filter the receive list whenever we notice a bundle has been added to the rhizome database.  That way such duplicate transmission of the same bundle should get suppressed. Examining the log file of when this happened, it turns out that the problem was actually that the bundle was corrupted during reception.  This is possible if the bundle being transferred changes part way through, as our pure data packets lack bundle identifying information to save space. However, it looks like we will will need it after, to avoid problems with inferring which bundle is being sent by the remote end.

There is also a pattern where some pieces of a bundle are failing to get sent in the data packets. I'm suspecting that this is due to escaping of characters causing the encoded size of the data packet to become too large.  So I might need to trim the packet size again.  (This is all part of why I don't like it when systems try to hide packetisation behind a pretend stream interface.  You end up having to put framing back in the stream, which adds overhead, and there is no way to make sure your packets actually end on the underlying packet boundaries which increases latency. But I understand why people implement them.)

So I guess I'll have to drop back to 128 bytes per data packet, as well as including the bundle information.

Ok, that has helped quite a lot.  It is now delivering the packets more reliably.  But the throughput is still pretty horrible, with good-put rates still somewhere around 25 bytes per second.  I suspect the modems are really not designed for this kind of two-way sustained communications, but rather are optimised for mostly uni-directional transfers. 

If I can get hardware flow-control working, I should be able to improve things by using larger packet sizes.  But I think its also about time I actually wrote a simple test programme that measures the actual bidirectional throughput that these modems can deliver.  That way I know whether it is my protocol side of things that is the problem, or whether I really am hitting the limit of what these modems can achieve. 

But that will all have to wait for the next blog post.