sending a link characterization request results in peer being brought down

[louberger]

test using configs in #8
on modem:

dest up 0:0:0:0:0:1 Latency_Range 1;2

on router:

linkchar request 0:0:0:0:0:1 Latency 4 Current_Data_Rate_Receive 0 Current_Data_Rate_Transmit 1

with logging turned on on modem see:
11:35:30.024 INFO: .../LL-DLEP/Peer.cpp:1492:handle_destination_up_response(): status=Success 11:35:30.024 DEBUG: .../LL-DLEP/Peer.cpp:1016:handle_session_receive(): signal buffer has 0 extra bytes after the signal just handled 11:35:40.731 INFO: .../LL-DLEP/Peer.cpp:950:handle_session_receive(): from peer=127.0.0.1:58860 error=system:0 bytes_recvd=50 11:35:40.731 DEBUG: .../LL-DLEP/Peer.cpp:987:handle_session_receive(): signal buffer now holds 50 bytes from the peer 11:35:40.731 INFO: .../LL-DLEP/Peer.cpp:1873:handle_peer_signal(): from=127.0.0.1:58860 size=50 : 11:35:40.731 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:552:parse(): handle_peer_signal message length=50 bytes=00 0e 00 2e 00 07 00 06 00 00 00 00 00 01 00 10 00 08 00 00 00 00 00 00 00 04 00 0e 00 08 00 00 00 00 00 00 00 00 00 0f 00 08 00 00 00 00 00 00 00 01 11:35:40.731 INFO: .../LL-DLEP/ProtocolMessage.cpp:603:parse(): handle_peer_signal signal id=14(Link_Characteristics_Request) length=46 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=4 data item id=7 length=6 MAC_Address 00:00:00:00:00:01 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=14 data item id=16 length=8 Latency 4 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=26 data item id=14 length=8 Current_Data_Rate_Receive 0 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=38 data item id=15 length=8 Current_Data_Rate_Transmit 1 11:35:40.732 INFO: .../LL-DLEP/Peer.cpp:1739:handle_link_characteristics_request(): from peer=127.0.0.1:58860 destination=00:00:00:00:00:01 11:35:40.732 DEBUG: .../LL-DLEP/Peer.cpp:1774:handle_link_characteristics_request(): calling client linkchar_request handler 11:35:40.732 INFO: .../LL-DLEP/Peer.cpp:718:link_characteristics_response(): to peer=127.0.0.1:58860 mac=00:00:00:00:00:01 11:35:40.732 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:80:add_data_item(): added data item MAC_Address to Link_Characteristics_Response, now length=14 11:35:40.732 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:80:add_data_item(): added data item Latency to Link_Characteristics_Response, now length=26 11:35:40.732 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:80:add_data_item(): added data item Current_Data_Rate_Receive to Link_Characteristics_Response, now length=38 11:35:40.732 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:80:add_data_item(): added data item Current_Data_Rate_Transmit to Link_Characteristics_Response, now length=50 11:35:40.732 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:552:parse(): link_characteristics_response message length=50 bytes=00 0f 00 2e 00 07 00 06 00 00 00 00 00 01 00 10 00 08 00 00 00 00 00 00 00 04 00 0e 00 08 00 00 00 00 00 00 00 00 00 0f 00 08 00 00 00 00 00 00 00 01 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:603:parse(): link_characteristics_response signal id=15(Link_Characteristics_Response) length=46 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=4 data item id=7 length=6 MAC_Address 00:00:00:00:00:01 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=14 data item id=16 length=8 Latency 4 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=26 data item id=14 length=8 Current_Data_Rate_Receive 0 11:35:40.732 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=38 data item id=15 length=8 Current_Data_Rate_Transmit 1 11:35:40.732 ERROR: .../LL-DLEP/ProtocolMessage.cpp:712:validate(): Link_Characteristics_Response exactly one of Status required, but got 0 11:35:40.732 INFO: .../LL-DLEP/Peer.cpp:71:send_session_message(): to peer=127.0.0.1:58860 size=50 11:35:40.732 DEBUG: .../LL-DLEP/Peer.cpp:1016:handle_session_receive(): signal buffer has 0 extra bytes after the signal just handled 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:62:handle_send(): peer=127.0.0.1:58860 error=system:0 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:950:handle_session_receive(): from peer=127.0.0.1:58860 error=system:0 bytes_recvd=80 11:35:40.733 DEBUG: .../LL-DLEP/Peer.cpp:987:handle_session_receive(): signal buffer now holds 80 bytes from the peer 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:1873:handle_peer_signal(): from=127.0.0.1:58860 size=80 : 11:35:40.733 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:552:parse(): handle_peer_signal message length=80 bytes=00 05 00 4c 00 01 00 48 82 4c 69 6e 6b 5f 43 68 61 72 61 63 74 65 72 69 73 74 69 63 73 5f 52 65 73 70 6f 6e 73 65 20 65 78 61 63 74 6c 79 20 6f 6e 65 20 6f 66 20 53 74 61 74 75 73 20 72 65 71 75 69 72 65 64 2c 20 62 75 74 20 67 6f 74 20 30 11:35:40.733 INFO: .../LL-DLEP/ProtocolMessage.cpp:603:parse(): handle_peer_signal signal id=5(Session_Termination) length=76 11:35:40.733 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=4 data item id=1 length=72 Status 130;Link_Characteristics_Response exactly one of Status required, but got 0 11:35:40.733 DEBUG: .../LL-DLEP/ProtocolMessage.cpp:552:parse(): send_simple_response message length=4 bytes=00 06 00 00 11:35:40.733 INFO: .../LL-DLEP/ProtocolMessage.cpp:603:parse(): send_simple_response signal id=6(Session_Termination_Response) length=0 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:71:send_session_message(): to peer=127.0.0.1:58860 size=4 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:821:stop_peer(): peer=127.0.0.1:58860 11:35:40.733 DEBUG: .../LL-DLEP/Peer.cpp:932:stop_timers(): stopping heartbeats to peer=127.0.0.1:58860 11:35:40.733 DEBUG: .../LL-DLEP/Peer.cpp:936:stop_timers(): stopping acktivity timer for peer=127.0.0.1:58860 11:35:40.733 INFO: .../LL-DLEP/Peer.cpp:1999:set_state(): peer=127.0.0.1:58860 old state=in session new state=terminating 11:35:40.733 DEBUG: .../LL-DLEP/Peer.cpp:1016:handle_session_receive(): signal buffer has 0 extra bytes after the signal just handled 11:35:40.734 INFO: .../LL-DLEP/Peer.cpp:62:handle_send(): peer=127.0.0.1:58860 error=system:0 11:35:40.734 ERROR: .../LL-DLEP/Peer.cpp:906:handle_heartbeat_timeout(): boost timer error system:125 11:35:40.734 ERROR: .../LL-DLEP/Peer.cpp:467:handle_acktivity_timeout(): boost timer error system:125 11:35:41.721 INFO: .../LL-DLEP/Dlep.cpp:541:cleanup_ex_peers(): deleting peer=127.0.0.1:58860 11:35:41.732 DEBUG: .../LL-DLEP/Peer.cpp:871:cancel_session(): peer=127.0.0.1:58860 11:35:41.732 INFO: .../LL-DLEP/Peer.cpp:950:handle_session_receive(): from peer=127.0.0.1:58860 error=system:125 bytes_recvd=0 11:35:41.774 ERROR: .../LL-DLEP/Peer.cpp:955:handle_session_receive(): bailing out because error=system:125 11:35:41.774 DEBUG: .../LL-DLEP/Peer.cpp:50:~Peer(): peer=127.0.0.1:58860

[davidpwiggins]

This line is the key:

11:35:40.733 INFO: .../LL-DLEP/ProtocolMessage.cpp:629:parse(): at index=4 data item id=1 length=72 Status 130;Link_Characteristics_Response exactly one of Status required, but got 0

This is using the example client. By default, the "linkchar-autoreply" configuration parameter is set to 1 (enabled). This tells the example client to automatically reply to any linkchar request with exactly the same data items that it received in the request, giving the appearance that the request was honored. The problem is that the Link Characteristics Response message requires a Status data item (just like the error message above says), but the example client doesn't add one when it sends the reply. It just echos the same data items it got. The fix is to add the Status data item before sending the reply.