Error log of tcp 802.11s, applciation suddenly stop to work

[ahmad r]

Hi.
I am using TCP to send a bulk of data, code borrowed from tcp-bulk-send.cc. I wan to send data from node A to node B, and after that from node A to node C. B and C are reachable using some hops. the nodes are not moving.  I am using 802.11s, and nodes are multi hop far away, and they are located in the same line.

about application:
I send data from node A to B, and then A to C, and then B to C. and then after few seconds, I start this procedure again. to do so, I have override the PacketSink::HandleRead, and within it, after a node(say B) received a certain amount of data from A, it will build and trigger another source(B) and sink(C) and start sending the data (all in the PacketSink::HandleRead). 


Question:
Sometimes this procedure runs for multiple times(say 50 times) and then suddenly stop(before the simulation stop time), and by changing some parameters(like the number of nodes, or the size of data), the number of runs without error will change.
I know that you might need some more logs, but I dont know which log you need. Thanks for all your help.
 
 [node 8] TcpL4Protocol:PacketReceived(0x8581198, 0x86b2630, 0 > 0 Seq=0 Ack=0 Win=65535, 05-04-0a:01:01:03, 05-04-0a:01:01:09)
 [node 8] TcpL4Protocol 0x8581198 receiving seq 1 ack 1 flags FIN|ACK data size 224
 [node 8] TcpL4Protocol 0x8581198 received a packet and now forwarding it up to endpoint/socket
 [node 8] TcpL4Protocol:SendPacket(0x8581198, 0x86aeeb8, 9 > 49182 [ACK] Seq=1 Ack=194 Win=39023 ns3::TcpOptionTS(543677;543672), 05-04-0a:01:01:09, 05-04-0a:01:01:03, 0)
 [node 8] TcpL4Protocol:SendPacketV4(0x8581198, 0x86aeeb8, 10.1.1.9, 10.1.1.3, 0)
 [node 8] TcpL4Protocol 0x8581198 sending seq 1 ack 194 flags ACK data size 0

PacketSink:HandlePeerClose(0x859d348, 0x86b28c8)

 [node 8] TcpL4Protocol:SendPacket(0x8581198, 0x86b2d90, 9 > 49182 [RST] Seq=1 Ack=194 Win=39023 ns3::TcpOptionTS(543677;543672), 05-04-0a:01:01:09, 05-04-0a:01:01:03, 0)
 [node 8] TcpL4Protocol:SendPacketV4(0x8581198, 0x86b2d90, 10.1.1.9, 10.1.1.3, 0)
 [node 8] TcpL4Protocol 0x8581198 sending seq 1 ack 194 flags RST data size 0

PacketSink:HandlePeerError(0x859d348, 0x86b28c8)

 [node 8] TcpL4Protocol:DeAllocate(0x8581198, 0x86b1950)
 [node 8] TcpL4Protocol:RemoveSocket(0x8581198, 0x86b28c8)
 [node 2] TcpL4Protocol:Receive(0x857a808, 0x86afa18, tos 0x0 DSCP Default ECN Not-ECT ttl 64 id 13 protocol 6 offset (bytes) 0 flags [none] length: 52 10.1.1.9 > 10.1.1.3, 0x857a750)
 [node 2] TcpL4Protocol:PacketReceived(0x857a808, 0x86afa18, 0 > 0 Seq=0 Ack=0 Win=65535, 05-04-0a:01:01:09, 05-04-0a:01:01:03)
 [node 2] TcpL4Protocol 0x857a808 receiving seq 1 ack 194 flags ACK data size 32
 [node 2] TcpL4Protocol 0x857a808 received a packet and now forwarding it up to endpoint/socket
 [node 2] TcpL4Protocol:Receive(0x857a808, 0x86b2790, tos 0x0 DSCP Default ECN Not-ECT ttl 64 id 14 protocol 6 offset (bytes) 0 flags [none] length: 52 10.1.1.9 > 10.1.1.3, 0x857a750)


I have this log in my flow monitor, which is related to this error(the last flows):

    <Flow flowId="329" timeFirstTxPacket="+543668772968.0ns" timeFirstRxPacket="+543670879628.0ns" timeLastTxPacket="+543672827823.0ns" timeLastRxPacket="+543677145610.0ns" delaySum="+6424447.0ns" jitterSum="+2211127.0ns" lastDelay="+4317787.0ns" txBytes="352" rxBytes="300" txPackets="3" rxPackets="2" lostPackets="1" timesForwarded="0">
      <delayHistogram nBins="5" >
        <bin index="2" start="0.002" width="0.001" count="1" />
        <bin index="4" start="0.004" width="0.001" count="1" />
      </delayHistogram>
      <jitterHistogram nBins="3" >
        <bin index="2" start="0.002" width="0.001" count="1" />
      </jitterHistogram>
      <packetSizeHistogram nBins="13" >
        <bin index="2" start="40" width="20" count="1" />
        <bin index="12" start="240" width="20" count="1" />
      </packetSizeHistogram>
      <flowInterruptionsHistogram nBins="0" >
      </flowInterruptionsHistogram>
    </Flow>
    <Flow flowId="330" timeFirstTxPacket="+543670879628.0ns" timeFirstRxPacket="+543672827822.0ns" timeLastTxPacket="+543677145610.0ns" timeLastRxPacket="+543680781533.0ns" delaySum="+7436311.0ns" jitterSum="+1879729.0ns" lastDelay="+3635923.0ns" txBytes="160" rxBytes="160" txPackets="3" rxPackets="3" lostPackets="0" timesForwarded="0">
      <delayHistogram nBins="4" >
        <bin index="1" start="0.001" width="0.001" count="2" />
        <bin index="3" start="0.003" width="0.001" count="1" />
      </delayHistogram>
      <jitterHistogram nBins="2" >
        <bin index="0" start="0" width="0.001" count="1" />
        <bin index="1" start="0.001" width="0.001" count="1" />
      </jitterHistogram>
      <packetSizeHistogram nBins="3" >
        <bin index="2" start="40" width="20" count="3" />
      </packetSizeHistogram>
      <flowInterruptionsHistogram nBins="0" >
      </flowInterruptionsHistogram>
    </Flow>
  </FlowStats>

    <Flow flowId="329" sourceAddress="10.1.1.3" destinationAddress="10.1.1.9" protocol="6" sourcePort="49182" destinationPort="9" />
    <Flow flowId="330" sourceAddress="10.1.1.9" destinationAddress="10.1.1.3" protocol="6" sourcePort="9" destinationPort="49182" />

Thanks

[Tommaso Pecorella]

Hi,

it seems like a very unlucky drop in the connection establishment phase.

To further investigate it, we'll need a non-working minimal script, i.e., with a minimal number of nodes and the "event" happening as soon as possible.

Mind that it is always possible that two nodes will fail to open a connection. Unlikely, but possible.

Cheers,

T.

[ahmad r]

I have attached the code.
I tried to clean the code. I know that it is not as clean as possible.(and even what you called clean).


Thank you so much