MicroModem receive statistics reports incorrect number of frames

[Josh Leighton]

When the MicroModem driver is configured to fetch receive statistics for receptions, one extra frame is reported in the receive statistics protobuf up to the maximum number of frames for that rate. For example in a rate 2 PSK packet:

Received 1 frame -> receive statistics reports 2 frames
Received 2 frames -> receive statistics reports 3 frames
Received 3 frames -> receive statistics reports 3 frames

All of these are for good receptions. Number of bad frames seems to be reported correctly. The problem appears to be the same for all rates which can handle multiple frames.

[toby schneider (tes)]

Can you please post the actual NMEA message ($CACST, .... ) along with the micromodem::protobuf::ReceiveStatistics message? If you set glog to "DEBUG2" verbosity, the Micro-Modem NMEA messages are posted. Also, please post the Micro-Modem firmware version ($CAREV,AUV, ... message).

I suspect this is a bug in the Micro-Modem firmware, not the Goby MMDriver.

[Josh Leighton (leighton-josh)]

One example is posted inline. Looks like it it is coming from the modem.
 Checked the transmitting end and the ModemTransmission protobuf being
passed contains just the one frame.

src: 2
dest: 0
time: 1344008758000000
time_source: MODEM_TIME
type: DATA
ack_requested: false
frame:
"asdasdasdasdasdasdadasdasdasdasdasdadasdasdadasdsadadasdasdasd\377\377"
[micromodem.protobuf.receive_stat] {
  mode: RECEIVE_GOOD
  time: 1344008758000000
  clock_mode: NO_SYNC_TO_PPS_AND_CCCLK_GOOD
  mfd_peak: 1696
  mfd_power: 26
  mfd_ratio: 129
  spl: 201
  shf_agn: 0
  shf_ainpshift: 0
  shf_ainshift: 0
  shf_mfdshift: 1
  shf_p2bshift: 1
  rate: 2
  source: 2
  dest: 0
  psk_error_code: NO_ERROR
  packet_type: PSK
  number_frames: 2
  number_bad_frames: 0
  snr_rss: 165
  snr_in: 6
  snr_out: 4
  snr_symbols: 8
  mse_equalizer: -1
  data_quality_factor: 0
  doppler: 0
  stddev_noise: 62
  carrier_freq: 25000
  bandwidth: 5000
  version: 0
}

[ 2012-Aug-03 15:45:59.019519 ]
{goby::acomms::modemdriver::in::1}: D2: $CARXP,1*45
[ 2012-Aug-03 15:45:59.021320 ]
{goby::acomms::modemdriver::in::1}: ^ Incoming packet detected, modem to
host
[ 2012-Aug-03 15:46:01.627915 ]
{goby::acomms::modemdriver::in::1}: D2: $CACYC,1,2,0,2,0,2*58
[ 2012-Aug-03 15:46:01.629563 ]
{goby::acomms::modemdriver::in::1}: ^ Echo of Network Cycle Initialization
command
[ 2012-Aug-03 15:46:01.646928 ]
{goby::acomms::modemdriver::in::1}: D2: $CAMFD,1696,26,0129,0201*48
[ 2012-Aug-03 15:46:01.652544 ]
{goby::acomms::modemdriver::in::1}: ^ Comms matched filter information,
modem to host
[ 2012-Aug-03 15:46:01.684040 ]
{goby::acomms::modemdriver::in::1}: D2: $CASHF,00,00,00,01,01*73
[ 2012-Aug-03 15:46:01.690815 ]
{goby::acomms::modemdriver::in::1}: ^ Shift information, modem to host
[ 2012-Aug-03 15:46:01.707020 ]
{goby::acomms::modemdriver::in::1}: D2: $CADOP,0.0*5B
[ 2012-Aug-03 15:46:01.717702 ]
{goby::acomms::modemdriver::in::1}: ^ Doppler speed message, modem to host
[ 2012-Aug-03 15:46:02.229597 ]
{goby::acomms::modemdriver::in::1}: D2:
$CARXD,2,0,0,1,6173646173646173646173646173646173646164617364617364617364617364617364616461736461736461646173647361646164617364617364617364ffff*63
[ 2012-Aug-03 15:46:02.231214 ]
{goby::acomms::modemdriver::in::1}: ^ Received binary message, modem to host
[ 2012-Aug-03 15:46:02.243849 ]
{goby::acomms::modemdriver::in::1}: D: Received 64 byte DATA frame 0 from 2
[ 2012-Aug-03 15:46:02.247359 ]
{goby::acomms::modemdriver::in::1}: D2: $CARXD,2,0,0,2,*60
[ 2012-Aug-03 15:46:02.252333 ]
{goby::acomms::modemdriver::in::1}: ^ Received binary message, modem to host
[ 2012-Aug-03 15:46:02.259719 ]
{goby::acomms::modemdriver::in::1}: D2:
$CACST,0,154558.0000,1,1696,26,0129,0201,00,00,00,01,01,2,002,000,0,3,2,0,165,06,04,08,-1,000,0.0,62,25000,5000*75
[ 2012-Aug-03 15:46:02.262252 ]
{goby::acomms::modemdriver::in::1}: ^ Communication cycle receive statistics

[ 2012-Aug-03 15:46:02.432151 ]
{goby::acomms::modemdriver::in::1}: D2: $CAREV,154602,AUV,0.93.7.51*0E
[ 2012-Aug-03 15:46:02.438194 ]
{goby::acomms::modemdriver::in::1}: ^ Software revision message, modem to
host
[ 2012-Aug-03 15:46:02.441429 ]
{goby::acomms::modemdriver::in::1}: D2: $CAREV,154602,COPROC,0.10.0...

[toby schneider (tes)]

This makes sense - the CCCYC must have the number of frames desired to send, and currently the Goby MMDriver sets this to the maximum for that packet type, then terminates the transmission early by sending a blank frame (which stops the Micro--Modem from requesting more). This blank frame counts as a frame however, so you see one more frame received than expected.

I can and will fix this for the case where a given node initiates its own cycle ($CCCYC address 1 == $CCTXD source), but not for the case of third-party cycle inits ("polling") since the master doesn't know how much data a given node will send.

Thanks-
-t

[toby schneider (tes)]

Fix committed to lp:goby/2.0