TinyOS/nesC Receive.receive event is signalled periodically but processed only once

Question

I'm currently working with implementation of AODV protocol for TinyOS and I'm seeing weird behaviour when network layer is signalling application about received message.

Below are relevant pieces of application and AODV library code + some debug output to show what is going on.

Test application

Configuration

configuration BasicTestAppC{
}
implementation{
    components MainC, BasicTestC, AODV, LedsC;

    BasicTestC.Boot->MainC.Boot;
    BasicTestC.SplitControl->AODV.SplitControl;

    BasicTestC.AMSend->AODV.AMSend[1];
    BasicTestC.Receive->AODV.Receive[1];

    ...
}

Implementation

#include "BasicTest.h"

module BasicTestC {
    uses {
        interface Boot;
        interface SplitControl;
        interface Timer<TMilli> as MilliTimer;
        interface AMSend;
        interface Receive;
        interface Leds;
        interface Packet;
    }
}

implementation {
    message_t pkt;
    message_t * p_pkt;

    uint16_t src = 0x0007;
    uint16_t dest = 0x000A;

    uint16_t ctr = 0;
    test_msg* test_pkt; 
    test_msg* rcv_pkt;

    ...

    //Send counter value to node 10 on every timer tick
    event void MilliTimer.fired() {
        call Leds.led0Toggle();

            ctr = ctr + 1;

        test_pkt = (test_msg*)(call Packet.getPayload(p_pkt, sizeof (test_msg)));
        test_pkt->counter = ctr;
        call AMSend.send(dest, p_pkt, sizeof(test_msg));
    }

    event void AMSend.sendDone(message_t * bufPtr, error_t error) {
        test_pkt = (test_msg*)(call Packet.getPayload(p_pkt, sizeof (test_msg)));
        dbg("APPS", "%s\t APPS: sendDone!! (error=%d) ctr=%u\n", sim_time_string(), error, test_pkt->counter);
    }

    event message_t* Receive.receive(message_t * bufPtr, void * payload, uint8_t len) {
        rcv_pkt = (test_msg * ) payload;
        dbg("APPS", "%s\t APPS: receive!! %u\n", sim_time_string(), rcv_pkt->counter);
        return bufPtr;
    }

}

AODV module

Processing receive event from AMReceiverC component:

event message_t* SubReceive.receive( message_t* p_msg, void* payload, uint8_t len ) {

    uint8_t i;
    aodv_msg_hdr* aodv_hdr = (aodv_msg_hdr*)(p_msg->data);

    test_msg_y* tmp;
    uint16_t ctr;

    dbg("AODV", "%s\t AODV: SubReceive.receive() dest: %d src:%d\n", sim_time_string(), aodv_hdr->dest, aodv_hdr->src);

    if( aodv_hdr->dest == call AMPacket.address() ) {

        for( i=0;i<len;i++ ) {
            p_app_msg_->data[i] = aodv_hdr->data[i];
        }

        tmp = (test_msg_y*) p_app_msg_->data;
        ctr = tmp->counter;

        //Send signal to application layer
        p_msg = signal Receive.receive[aodv_hdr->app]( p_app_msg_, p_app_msg_->data, len - AODV_MSG_HEADER_LEN );

        dbg("AODV", "%s\t AODV: SubReceive.receive() delivered to upper layer - %u\n", sim_time_string(), ctr);

    } else {

        am_addr_t nexthop = get_next_hop( aodv_hdr->dest );

        dbg("AODV", "%s\t AODV: SubReceive.receive() deliver to next hop:%x\n", sim_time_string(), nexthop);

        /* If there is a next-hop for the destination of the message, 
           the message will be forwarded to the next-hop.            */
        if (nexthop != INVALID_NODE_ID) {
                forwardMSG( p_msg, nexthop, len );
        }
    }
    return p_msg;
}

Debug output

DEBUG (7): 0:0:2.006653503   APPS: sendDone!! (error=0) ctr=2
DEBUG (10): 0:0:2.019577622  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:2.019577622  AODV: SubReceive.receive() delivered to upper layer - 2
DEBUG (10): 0:0:2.019577622  APPS: receive!! 2
DEBUG (7): 0:0:3.010407143   APPS: sendDone!! (error=0) ctr=3
DEBUG (10): 0:0:3.021820651  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:3.021820651  AODV: SubReceive.receive() delivered to upper layer - 3
DEBUG (7): 0:0:4.005264961   APPS: sendDone!! (error=0) ctr=4
DEBUG (10): 0:0:4.023239710  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:4.023239710  AODV: SubReceive.receive() delivered to upper layer - 4
DEBUG (7): 0:0:5.010010417   APPS: sendDone!! (error=0) ctr=5
DEBUG (10): 0:0:5.024780838  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:5.024780838  AODV: SubReceive.receive() delivered to upper layer - 5
DEBUG (7): 0:0:6.003983230   APPS: sendDone!! (error=0) ctr=6
DEBUG (10): 0:0:6.010147745  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:6.010147745  AODV: SubReceive.receive() delivered to upper layer - 6
DEBUG (7): 0:0:7.008331960   APPS: sendDone!! (error=0) ctr=7
DEBUG (10): 0:0:7.020187970  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:7.020187970  AODV: SubReceive.receive() delivered to upper layer - 7
DEBUG (7): 0:0:8.004013748   APPS: sendDone!! (error=0) ctr=8
DEBUG (10): 0:0:8.013474142  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:8.013474142  AODV: SubReceive.receive() delivered to upper layer - 8
DEBUG (7): 0:0:9.009140671   APPS: sendDone!! (error=0) ctr=9
DEBUG (10): 0:0:9.020233746  AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:9.020233746  AODV: SubReceive.receive() delivered to upper layer - 9
DEBUG (7): 0:0:10.010391884  APPS: sendDone!! (error=0) ctr=10
DEBUG (10): 0:0:10.018341667 AODV: SubReceive.receive() dest: 10 src:7
DEBUG (10): 0:0:10.018341667 AODV: SubReceive.receive() delivered to upper layer - 10

As you can see - receive event at the application layer is triggered/executed only once. All following messages reach destination node but don't get above network layer.

Any thoughts as to what might be going on here?

Answer 1

Problem was in following line:

p_msg = signal Receive.receive[aodv_hdr->app]( p_app_msg_, p_app_msg_->data, len - AODV_MSG_HEADER_LEN );

Documentation on Receive.receive suggests that it should not reuse receive message buffer and most common thing to do is to return same pointer that was passed to it as a first argument.

The problem with it is - if user application follows guidelines when implementing Receive.receive event handler, it will return pointer to the message buffer (the first argument). However first argument that is passed to Receive.receive in the line above is p_app_msg_, which means that after first message was received, p_msg is not pointing to the original message buffer any more.

Still considering what the best way to fix this is, but at the moment I just don't assign result of Receive.receive back to p_msg and avoid reusing receive message buffer in application code.