Created attachment 202 [details]
patch against udp-echo.cc to reproduce

This patch, if applied to udp-echo.cc, reproduces the problem.

If no one beats me to this, I will provide a patch fix by Friday.  

- add an integer attribute to ArpCache called "MaxRetries"
- add a m_retries member variable to ArpCache::Entry that counts up to m_maxRetries
- add some timer logic that is invoked when the cache entry enters WaitReply state.  The timer will fire every m_waitReplyTimeout interval.  If m_retries <= m_maxRetries, resend the arp request and increment m_retries and restart timer; otherwise, move to dead state

Created attachment 204 [details]
proposed patch

I tested this against the test case, and did some bounds checking on the maxRetries value.  It basically adds a timer to protect the ArpRequest, and a counter to control how many requests are sent before giving up.

(In reply to comment #3)
> Created an attachment (id=204) [details]
> proposed patch
> 
> I tested this against the test case, and did some bounds checking on the
> maxRetries value.  It basically adds a timer to protect the ArpRequest, and a
> counter to control how many requests are sent before giving up.

The idea sounds ok modulo the expected question: how do real systems deal with that ? Why was it not enough for you to make the 'dead' timer value smaller ?

As to the patch, adding a Timer * instance _per entry_ seems horrendous from a memory perspective. I would much rather do one of:
1) do not use a Timer object and Simulator::Schedule without storing the resulting EventId. 
2) If you really must include the timer, do not use a "Timer *" But use a "Timer".
3) use a per-cache timer shared by all entries which scans through all entries to find waiting entries whenever it expires and uses the Entry::m_lastSeen field together with the  m_waitReplyTimeout value to guess how many retries were done for each entry and whether or not it should resend a request (i.e., if now - m_lastSeen / m_waitReplyTimeout is bigger than m_retries + 1, you should send a new request and increment m_retries and potentially re-schedule the wait reply timeout.

I really prefer 3 above.

Another comment is that your current patch as well as any of the proposed modifications make the following code uneeded in ArpL3Protocol::Lookup. It should be replaced at least by an ASSERT : if (IsWaitReply) {NS_ASSERT ()} or, better, be removed after some serious testing.

         else if (entry->IsWaitReply ())
            {
              NS_LOG_LOGIC ("node="<<m_node->GetId ()<<
                        ", wait reply for " << destination << " expired -- drop");
              entry->MarkDead ();
              Ptr<Packet> pending = entry->DequeuePending();
              while (pending != 0)
                {
                  m_dropTrace (pending);
                  pending = entry->DequeuePending();
                }
              m_dropTrace (packet);
            }

(In reply to comment #4)
> (In reply to comment #3)
> > Created an attachment (id=204) [details] [details]
> > proposed patch
> > 
> > I tested this against the test case, and did some bounds checking on the
> > maxRetries value.  It basically adds a timer to protect the ArpRequest, and a
> > counter to control how many requests are sent before giving up.
> 
> The idea sounds ok modulo the expected question: how do real systems deal with
> that ? Why was it not enough for you to make the 'dead' timer value smaller ?

can you point me to the use of the dead timer?  I didn't see any evidence in the code of a timer or events being scheduled to handle this.  ArpL3Protocol::Lookup() seems to be data-driven only.

> 
> As to the patch, adding a Timer * instance _per entry_ seems horrendous from a
> memory perspective. I would much rather do one of:
> 1) do not use a Timer object and Simulator::Schedule without storing the
> resulting EventId. 
> 2) If you really must include the timer, do not use a "Timer *" But use a
> "Timer".

I considered this but the problem seemed to be:
- Timer is in src/simulator and is not a Ptr or Object; Timer access seems to need to be by reference
- the code that schedules this per-entry timer is outside of the cache entry itself
- there seemed to be other instances of exporting pointers to cache entries, so I followed along

If we go away from storing the timer in the entry, this problem may go away.

> 3) use a per-cache timer shared by all entries which scans through all entries
> to find waiting entries whenever it expires and uses the Entry::m_lastSeen
> field together with the  m_waitReplyTimeout value to guess how many retries
> were done for each entry and whether or not it should resend a request (i.e.,
> if now - m_lastSeen / m_waitReplyTimeout is bigger than m_retries + 1, you
> should send a new request and increment m_retries and potentially re-schedule
> the wait reply timeout.
> 
> I really prefer 3 above.

I would be fine with this, thanks.

> 
> Another comment is that your current patch as well as any of the proposed
> modifications make the following code uneeded in ArpL3Protocol::Lookup. It
> should be replaced at least by an ASSERT : if (IsWaitReply) {NS_ASSERT ()} or,
> better, be removed after some serious testing.
> 
>          else if (entry->IsWaitReply ())
>             {
>               NS_LOG_LOGIC ("node="<<m_node->GetId ()<<
>                         ", wait reply for " << destination << " expired --
> drop");
>               entry->MarkDead ();
>               Ptr<Packet> pending = entry->DequeuePending();
>               while (pending != 0)
>                 {
>                   m_dropTrace (pending);
>                   pending = entry->DequeuePending();
>                 }
>               m_dropTrace (packet);
>             }
> 

OK, will put an assert in for now.

(In reply to comment #5)

> > The idea sounds ok modulo the expected question: how do real systems deal with
> > that ? Why was it not enough for you to make the 'dead' timer value smaller ?
> 
> can you point me to the use of the dead timer?  I didn't see any evidence in
> the code of a timer or events being scheduled to handle this. 
> ArpL3Protocol::Lookup() seems to be data-driven only.

Yes. I wrote that comment before reviewing your patch completely. Sorry for the noise.
>
> If we go away from storing the timer in the entry, this problem may go away.

Yes. So, let's ignore the issue.

> > 3) use a per-cache timer 
[ ... ]
 
> > I really prefer 3 above.

> I would be fine with this, thanks.

When I initially thought about the problem I came to the conclusion that a per-cache timer would be best; but when I looked at Linux I found per-entry timers.

I believe the primary reason you would swallow this overhead is to avoid a "thundering herd" of retries which you could get if you scanned the entire cache on a single timer expiration; especially if we were to someday start aging the entries in the cache.

Since our default position is to do it like Linux, I thought multiple timers were were expensive but justifiable.

(In reply to comment #7)
> > > 3) use a per-cache timer 
> [ ... ]
> 
> > > I really prefer 3 above.
> 
> > I would be fine with this, thanks.
> 
> When I initially thought about the problem I came to the conclusion that a
> per-cache timer would be best; but when I looked at Linux I found per-entry
> timers.

ok. that's a good data point.

> I believe the primary reason you would swallow this overhead is to avoid a
> "thundering herd" of retries which you could get if you scanned the entire
> cache on a single timer expiration; especially if we were to someday start
> aging the entries in the cache.

It should not be too hard to just fire an update for the first one and defer the next update to some later time.

> It should not be too hard to just fire an update for the 
> first one and defer the next update to some later time.

Not hard -- we just need to consider possible broadcast storms and avoid them.  Linux folks do it with multiple timers -- we could do it with multiple timer expirations just as well.

(In reply to comment #8)
> > I believe the primary reason you would swallow this overhead is to avoid a
> > "thundering herd" of retries which you could get if you scanned the entire
> > cache on a single timer expiration; especially if we were to someday start
> > aging the entries in the cache.
> 
> It should not be too hard to just fire an update for the first one and defer
> the next update to some later time.
> 

Along these links, a way to avoid the herd is to schedule transmissions at a small random interval later, such as:

while (iterating over cache entries)
{
  if (found entry that has timed out)
  {
    // Do not call SendArpRequest just yet-- schedule it for small time later
    Schedule (UniformVariable::GetSingleValue(0, Seconds(ArpTimerTickInterval/2)), &SendArpRequest);
  }
}

This type of idiom might be nice to establish to deal with Craig's other recently filed bug about too much determinism in our packet emissions. 

Created attachment 206 [details]
revised workaround patch

small bugfix to previous patch:

void
ArpCache::Entry::IncrementRetries (void)
{
  NS_LOG_FUNCTION_NOARGS ();
  m_retries++;
+  UpdateSeen ();
}

I will next look at the per-cache timer implementation

Created attachment 212 [details]
revised patch

This patch responds to tracker suggestions to implement a per-cache rather than per-entry timer, and to avoid use of ns3::Timer and use EventId directly.

(In reply to comment #12)
> Created an attachment (id=212) [details]
> revised patch
> 
> This patch responds to tracker suggestions to implement a per-cache rather than
> per-entry timer, and to avoid use of ns3::Timer and use EventId directly. 

I would have expected that you need to check that the cache entry has been in the wait replay state for long enough to increment the counter. Otherwise you risk retransmitting arp requests for entries which have just been moved to the wait reply state.

Created attachment 216 [details]
small fix based on Mathieu's comment

Mathieu, I agree with your comment; I think the below should avoid retransmitting entries that have just moved to waitreply state.  In general, entries will be first retransmitted after they have waited between 1 and 2 waitreply timeout intervals.

  for (CacheI i = m_arpCache.begin (); i != m_arpCache.end (); i++) 
     {
       entry = (*i).second;
-      if (entry != 0 && entry->IsWaitReply ())
+      if (entry != 0 && entry->IsWaitReply () && entry->IsExpired ())

(In reply to comment #14)
> Created an attachment (id=216) [details]
> small fix based on Mathieu's comment
> 
> Mathieu, I agree with your comment; I think the below should avoid
> retransmitting entries that have just moved to waitreply state.  In general,
> entries will be first retransmitted after they have waited between 1 and 2
> waitreply timeout intervals.
> 
>   for (CacheI i = m_arpCache.begin (); i != m_arpCache.end (); i++) 
>      {
>        entry = (*i).second;
> -      if (entry != 0 && entry->IsWaitReply ())
> +      if (entry != 0 && entry->IsWaitReply () && entry->IsExpired ())

Yes, I had something similar in mind.

A small nit: you have a method ClearRetries and you don't use it from within the ArpCache::Entry code. It might make debugging easier to use it rather than access m_retries directly.

This has incorrect indentation:
+    /**
+     * This function is an event handler for the event that the
+     * ArpCache wants to check whether it must retry any Arp requests.
+     * If there are no Arp requests pending, this event is not scheduled.
+     */
+    void HandleWaitReplyTimeout (void);

Let's make this ASSERT a NS_FATAL_ERROR which asks for a bug report if it is ever hit and remove the code in the else block.

@@ -218,6 +220,7 @@ ArpL3Protocol::Lookup (Ptr<Packet> packe
             } 
           else if (entry->IsWaitReply ()) 
             {
+              NS_ASSERT (false); // Test for unreachable code, remove later

Why do you have ArpL3Protocol::GetDropTrace ?

ArpCache::SetDropTrace is not needed because ArpCache derives from Object and is accessible under the /NodeList/xx/$ArpL3Protocol/CacheList/xx/ so, you can make m_dropTrace a simple member of ArpCache which is never accessed by ArpL3Protocol.

(In reply to comment #15)
> (In reply to comment #14)
> > Created an attachment (id=216) [details] [details]
> > small fix based on Mathieu's comment
> > 
> > Mathieu, I agree with your comment; I think the below should avoid
> > retransmitting entries that have just moved to waitreply state.  In general,
> > entries will be first retransmitted after they have waited between 1 and 2
> > waitreply timeout intervals.
> > 
> >   for (CacheI i = m_arpCache.begin (); i != m_arpCache.end (); i++) 
> >      {
> >        entry = (*i).second;
> > -      if (entry != 0 && entry->IsWaitReply ())
> > +      if (entry != 0 && entry->IsWaitReply () && entry->IsExpired ())
> 
> Yes, I had something similar in mind.
> 
> A small nit: you have a method ClearRetries and you don't use it from within
> the ArpCache::Entry code. It might make debugging easier to use it rather than
> access m_retries directly.

OK
> 
> This has incorrect indentation:
> +    /**
> +     * This function is an event handler for the event that the
> +     * ArpCache wants to check whether it must retry any Arp requests.
> +     * If there are no Arp requests pending, this event is not scheduled.
> +     */
> +    void HandleWaitReplyTimeout (void);
> 
> Let's make this ASSERT a NS_FATAL_ERROR which asks for a bug report if it is
> ever hit and remove the code in the else block.

OK

> 
> @@ -218,6 +220,7 @@ ArpL3Protocol::Lookup (Ptr<Packet> packe
>              } 
>            else if (entry->IsWaitReply ()) 
>              {
> +              NS_ASSERT (false); // Test for unreachable code, remove later
> 
> Why do you have ArpL3Protocol::GetDropTrace ?

Trying to reuse the ArpL3Protocol in ArpCache without introducing a dependency in ArpCache on ArpL3Protocol.  
> 
> ArpCache::SetDropTrace is not needed because ArpCache derives from Object and
> is accessible under the /NodeList/xx/$ArpL3Protocol/CacheList/xx/ so, you can
> make m_dropTrace a simple member of ArpCache which is never accessed by
> ArpL3Protocol.
> 

OK, I will add this separate drop trace instead.

Created attachment 217 [details]
latest iteration

any further comments?

changeset a18520551cdf