[Tinyos-help] Strange Memory Overwrite Problem

wasif masood rwmasood at gmail.com
Thu Nov 11 01:02:35 PST 2010


look at this TOSSIM trace:

DEBUG (3): Sending...
DEBUG (3): ForwardingEngineP$0$Forward$send: Forwarding:2
DEBUG (3): 9
DEBUG (3): ForwardingEngineP$0$Forward$send: sending packet via CTP:17
DEBUG (3): ForwardingEngineP$0$Forward$send: queue entry is 0 deep
DEBUG (3): QueueC$0$Queue$enqueue: size is 0, 0xb7374878
DEBUG (3): head <-[782e11b7] <- tail
DEBUG (3):  AppC: Sent err:0
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: Trying to send a packet.
Queue size is 1.
DEBUG (3): ForwardingEngineP$0$sendTask$runTask:payloadLen:11
DEBUG (3): Sending, src:0 dest:2
DEBUG (3): Sending, origin:3 seq_no:17 thl:0
DEBUG (3): PacketSendReceiveP$AMSend$send with genlen: 12,len:11, addr;2,
err:0
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: subsend succeeded
DEBUG (3): PacketSendReceiveP$SubSend$sendDone len:12 Error: 0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: payloadLenght:11
DEBUG (3): SendDone, src:3 dest:2 ERR:0
DEBUG (3): SendDone, origin:3 seq_no:17 thl:0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: not acked, retrying
attempt:29,0
DEBUG (3): Rexmit timer will fire in 26 ms
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: Trying to send a packet.
Queue size is 1.
DEBUG (3): ForwardingEngineP$0$sendTask$runTask:payloadLen:11
DEBUG (3): Sending, src:0 dest:2
DEBUG (3): Sending, origin:3 seq_no:17 thl:0
DEBUG (3): PacketSendReceiveP$AMSend$send with genlen: 12,len:11, addr;2,
err:0
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: subsend succeeded
DEBUG (3): PacketSendReceiveP$SubReceive$receive received,SubType:3,len:12
DEBUG (3): packet received of size(11)
DEBUG (3): Rexmit timer will fire in 26 ms
DEBUG (3): Received, src:2 dest:3
DEBUG (3): Received, origin:5 seq_no:13 thl:3
DEBUG (3): SendQueue.size():1
DEBUG (3): matching origin:3 seq_no:17 thl:4
DEBUG (3): Forwarding packet from 5.
DEBUG (3): PoolP$0$Pool$empty size is 12
DEBUG (3): PoolP$1$Pool$empty size is 12
DEBUG (3): packet received of size:m(11)
DEBUG (3): BEFORE: Queue Entries, Origin3, seq_no:17, thl:0
DEBUG (3): PoolP$1$Pool$get size is 11, 0xb708efc4
DEBUG (3): PoolP$0$Pool$get size is 11, 0xb7106f84
DEBUG (3): forwardCTP: Queue Entries, Origin5, seq_no:13, thl:4
DEBUG (3): packet received of size:qe->msg(11)
DEBUG (3): QueueC$0$Queue$enqueue: size is 1, 0xb7112e78
DEBUG (3): head <-[782e11b7] [782e11b7] <- tail
DEBUG (3): AFTER: Queue Entries, Origin5, seq_no:13, thl:4
DEBUG (3): AFTER: Queue Entries, Origin5, seq_no:13, thl:4
DEBUG (3): Rexmit timer will fire in 114 ms
DEBUG (3): PacketSendReceiveP$SubSend$sendDone len:12 Error: 0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: payloadLenght:11
DEBUG (3): SendDone, src:3 dest:2 ERR:0
DEBUG (3): SendDone, origin:3 seq_no:17 thl:0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: not acked, retrying
attempt:29,0
DEBUG (3): Rexmit timer will fire in 24 ms
DEBUG (3): PacketSendReceiveP$SubReceive$receive received,SubType:3,len:12
DEBUG (3): packet received of size(11)
DEBUG (3): Rexmit timer will fire in 21 ms
DEBUG (3): Received, src:4 dest:3
DEBUG (3): Received, origin:4 seq_no:12 thl:0
DEBUG (3): SendQueue.size():2
DEBUG (3): matching origin:4 seq_no:12 thl:1
DEBUG (3): CTP duplicate received
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: Trying to send a packet.
Queue size is 2.
DEBUG (3): ForwardingEngineP$0$sendTask$runTask:payloadLen:11
DEBUG (3): Sending, src:4 dest:2
DEBUG (3): Sending, origin:4 seq_no:12 thl:1
DEBUG (3): PacketSendReceiveP$AMSend$send with genlen: 12,len:11, addr;2,
err:0
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: subsend succeeded
DEBUG (3): PacketSendReceiveP$SubSend$sendDone len:12 Error: 0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: payloadLenght:11
DEBUG (3): SendDone, src:3 dest:2 ERR:0
DEBUG (3): SendDone, origin:4 seq_no:12 thl:1
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: not acked, retrying
attempt:28,0
DEBUG (3): Rexmit timer will fire in 18 ms
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: Trying to send a packet.
Queue size is 2.
DEBUG (3): ForwardingEngineP$0$sendTask$runTask:payloadLen:11
DEBUG (3): Sending, src:4 dest:2
DEBUG (3): Sending, origin:4 seq_no:12 thl:1
DEBUG (3): PacketSendReceiveP$AMSend$send with genlen: 12,len:11, addr;2,
err:0
DEBUG (3): ForwardingEngineP$0$sendTask$runTask: subsend succeeded
DEBUG (3): PacketSendReceiveP$SubSend$sendDone len:12 Error: 0
DEBUG (3): ForwardingEngineP$0$SubSend$sendDone: payloadLenght:11
DEBUG (3): SendDone, src:3 dest:2 ERR:0
DEBUG (3): SendDone, origin:4 seq_no:12 thl:1



the entry in the SendQueue before the pushing the received Packet was :

DEBUG (3): BEFORE: Queue Entries, Origin3, seq_no:17, thl:0

but after pushing one qe entry, the entire Queue becomes:

DEBUG (3): AFTER: Queue Entries, Origin5, seq_no:13, thl:4
DEBUG (3): AFTER: Queue Entries, Origin5, seq_no:13, thl:4


but, in the start, things went well this is what happens after some has been
passed.

problem should be with this forwardCTP function:

  message_t* ONE forwardCTP(message_t* ONE m) {
        int i;

    if (call MessagePool.empty()) {
      dbg("Forwarder", "%s cannot forward, message pool empty.\n",
__FUNCTION__);
    }
    else if (call QEntryPool.empty()) {
      dbg("Forwarder", "%s cannot forward, queue entry pool empty.\n",
          __FUNCTION__);
    }
    else {
      message_t* newMsg;
      fe_queue_entry_t *qe;
      fe_queue_entry_t *qe_temp;
      uint16_t gradient;

        dbg("Forwarder", "packet received of size:m(%d)\n",call
Packet.payloadLength(m));

            if (call SendQueue.size() > 0) {
              for (i = 0 ; i< (call SendQueue.size()); i++) {
                    qe_temp = call SendQueue.element(i);
                    dbg("Forwarder", "BEFORE: Queue Entries, Origin%u,
seq_no:%u, thl:%u\n",call CtpDataPacketInfo.getOrigin(qe_temp->msg),
                                                    call
CtpDataPacketInfo.getSequenceNumber(qe_temp->msg),call
CtpDataPacketInfo.getThl(qe_temp->msg));
                }
          }

      qe = call QEntryPool.get();
      if (qe == NULL) {
        return m;
      }

      newMsg = call MessagePool.get();
      if (newMsg == NULL) {
        return m;
      }

      memset(newMsg, 0, sizeof(message_t));
      memset(m->metadata, 0, sizeof(message_metadata_t));

      qe->msg = m;
      qe->client = 0xff;        // this field is now used to distinguish b/t
forwarded and self packets
      qe->retries = MAX_RETRIES;

            dbg("Forwarder", "forwardCTP: Queue Entries, Origin%u,
seq_no:%u, thl:%u\n",call CtpDataPacketInfo.getOrigin(m),
                                        call
CtpDataPacketInfo.getSequenceNumber(m),call CtpDataPacketInfo.getThl(m));

        dbg("Forwarder", "packet received of size:qe->msg(%d)\n",call
Packet.payloadLength(qe->msg));

                if (call SendQueue.size() > 0) {
                  for (i = 0 ; i< (call SendQueue.size()); i++) {
                        qe_temp = call SendQueue.element(i);
                        dbg("Forwarder", "AFTER: Queue Entries, Origin%u,
seq_no:%u, thl:%u\n",call CtpDataPacketInfo.getOrigin(qe_temp->msg),
                                                    call
CtpDataPacketInfo.getSequenceNumber(qe_temp->msg),call
CtpDataPacketInfo.getThl(qe_temp->msg));
                    }
              }



      if (call SendQueue.enqueue(qe) == SUCCESS) {
        dbg("Forwarder", "%s forwarding packet %p with queue size %hhu\n",
__FUNCTION__, m, call SendQueue.size());
                if (call SendQueue.size() > 0) {
                  for (i = 0 ; i< (call SendQueue.size()); i++) {
                        qe_temp = call SendQueue.element(i);
                        dbg("Forwarder", "AFTER: Queue Entries, Origin%u,
seq_no:%u, thl:%u\n",call CtpDataPacketInfo.getOrigin(qe_temp->msg),
                                                    call
CtpDataPacketInfo.getSequenceNumber(qe_temp->msg),call
CtpDataPacketInfo.getThl(qe_temp->msg));
                    }
              }


                    dbg("Forwarder", "Received: Queue Entries, Origin%u,
seq_no:%u, thl:%u\n",call CtpDataPacketInfo.getOrigin(m),
                                                    call
CtpDataPacketInfo.getSequenceNumber(m),call CtpDataPacketInfo.getThl(m));


        //printf("FE:Forward: forwarding packet %p with queue size %hhu\n",
m, call SendQueue.size());printfflush();
        // Loop-detection code:
        if (call CtpInfo.getEtx(&gradient) == SUCCESS) {
          // We only check for loops if we know our own metric
          if (call CtpDataPacketInfo.getEtx(m) <= gradient) {
            // If our etx metric is less than or equal to the etx value
                        // on the packet (etx of the previous hop node),
then we believe
                        // we are in a loop.
                        // Trigger a route update and backoff.
            call CtpInfo.triggerImmediateRouteUpdate();
            startRetxmitTimer(LOOPY_WINDOW, LOOPY_OFFSET);
          }
        }

        if (!call RetxmitTimer.isRunning()) {
          // sendTask is only immediately posted if we don't detect a
          // loop.
          post sendTask();
        }

        // Successful function exit point:
        return newMsg;
      } else {
        // There was a problem enqueuing to the send queue.
        dbg("Forwarder", "%s forwarding packet with queue\n",__FUNCTION__);
        if (call MessagePool.put(newMsg) != SUCCESS){}
          //call CollectionDebug.logEvent(NET_C_FE_PUT_MSGPOOL_ERR);
        if (call QEntryPool.put(qe) != SUCCESS){}
          //call CollectionDebug.logEvent(NET_C_FE_PUT_QEPOOL_ERR);
      }
    }

    // NB: at this point, we have a resource acquistion problem.
    // Log the event, and drop the
    // packet on the floor.

    return m;
  }

its also worth noting that even if you drop a packet due to duplicate
receive, it somehow got copied in SendQueue(see the end lines of this
trace).





On Thu, Nov 11, 2010 at 7:04 AM, Omprakash Gnawali
<gnawali at cs.stanford.edu>wrote:

> On Wed, Nov 10, 2010 at 1:49 PM, wasif masood <rwmasood at gmail.com> wrote:
> >
> > Hi All,
> >
> > I am testing CTP and I am stucked in a very pathetic problem, my Declared
> > PoolC is overwriting SendQueue after some time is spent in TOSSIM.
> > did anyone ever had such problem?
>
> How do you know PoolC is overwriting SendQueue?
>
> - om_p
>



-- 
Wasif Masood
-------------- next part --------------
An HTML attachment was scrubbed...
URL: https://www.millennium.berkeley.edu/pipermail/tinyos-help/attachments/20101111/5670f7c1/attachment-0001.htm 


More information about the Tinyos-help mailing list