ReaderProxy history reloaded incorrectly missing GAP message [4962] by guillaumeautran · Pull Request #453 · eProsima/Fast-DDS

guillaumeautran · 2019-03-18T20:50:13Z

The problem is invalid changes at the end of the stateful writer history don't get added to a newly connected reader proxy cache causing the reader proxy to miss a lot of invalid changed and not generate the proper GAP message.

The fix is to make sure the missing changes are loaded into the reader proxy history so that the GAP message is properly generated.

should fix #452

richiware · 2019-03-18T22:30:42Z

Build status:

Linux
Mac
Windows

guillaumeautran · 2019-03-18T22:43:17Z

Looks like the build failure on Linux is due to a infrastructure problem

Cloning repository https://github.com/eProsima/Fast-RTPS.git
 > git init /workspace/FastRTPS Manual Linux # timeout=10
ERROR: Error cloning remote repo 'origin'
hudson.plugins.git.GitException: Could not init /workspace/FastRTPS Manual Linux

Not really sure why the MAC build failed though. The test results is unclear to me...

richiware · 2019-03-19T07:41:18Z

Build status:

Linux
Mac
Windows

richiware · 2019-03-29T14:07:27Z

Build status:

Linux
Mac
Windows

MiguelCompany · 2019-04-01T05:38:43Z

src/cpp/rtps/writer/ReaderProxy.cpp

These lines were removed on PR #425, as the error message could incorrectly be shown on correct situations after the changes on PR #411. There could be a situation were we receive an acknack message requesting a single change that is not considered unacknowledged (may be underway), in which case the logError will be incorrectly stated.

Yes, I noticed this after the fact. Is there a easy way to differentiate those two cases? (when the missing change is legitimate vs. when it is not?).

The only non-legitimate situation I can think of is if the acknack requests a change that has been already acknowledged, in which case its sequence number would be lower or equal to the low_mark. We could add some code before line 172. Something like:

if(*sit <= changesFromRLowMark_) { logError(RTPS_WRITER,"Requested already acknowledged change: " << *sit << " (low mark: " << changesFromRLowMark_ << ")"); } else if(chit != m_changesForReader.end() && UNACKNOWLEDGED == chit->getStatus())

We could even just perform an assert(*sit > changesFromRLowMark_ ) before line 170.

I'm not going to perform the assert because I know there are cases where the requested change is above the low_mark. But I will most definitely silence the log is the requested changes are below the low_mark.

[2019-04-01 15:23:48.632 UTC] [ERROR] [/bridge]: [fastrtps.RTPS_WRITER] Requested Changes: 14 15 16 17 18 30 31 32 33 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 not found (low mark: 13)

The trace shown may just mean those changes are either already marked as requested (i.e. the same acknack was received twice), or considered underway (i.e. recently sent). Both are legal situations. That is the reason the message was originally silenced.

Ok, so I've modified the code to record those sequence numbers greater than the low mark but not found in the reader history. These are most definitely an error that should not happen. Let me know if that's good now.

but not found in the reader history

I guess you mean writer history, as the ReaderProxy is part of the writer.

Even though, this will still log errors in legal situations. The changes may have been removed from the writer's history (due to history limits, removed by the user, ...). In that case, after receiving the acknack, a gap message will be sent informing the reader of the missing changes.

Right, the reader proxy (aka the writer history).

I am still sceptical wrt the GAP message being sent in the cases where there is a GAP in the writer history without a corresponding irrelevant change recorded in the reader proxy.
At least in 1.7.2 release, I do not see this happening. Can you please point me to the code where this is taken care of (ie: a ACKNACK message received generating a GAP message for missing change seqnum > low mark)? IMHO, if that was the case, this whole fix would be mute since the whole problem this fix addresses is the fact that a new reader proxy being created did not get initialized with the missing (irrelevant) change records indicating the gap at the tail end of the Writer History.

I've taken a deeper look at this and I've got to the conclusion that you're right. The changes may not be on the writer's history but should be on the ReaderProxy collection. We may refactor that in the future, but right now we're good to go with your changes.

richiware · 2019-04-02T15:43:49Z

Build status:

Linux
Mac
Windows

richiware · 2019-04-02T20:30:59Z

Build status:

Linux
Mac
Windows

guillaumeautran · 2019-04-11T16:23:24Z

@MiguelCompany : Just rebased against latest develop. Feel free to merge anytime.

richiware · 2019-04-11T18:15:35Z

Build status:

Linux
Mac
Windows

The problem is invalid changes at the end of the stateful writer history don't get added to a newly connected reader proxy cache causing the reader proxy to miss a lot of invalid changed and not generate the proper GAP message. The fix is to make sure the missing changes are loaded into the reader proxy history so that the GAP message is properly generated. Reworked the error message on missing changes to eliminate legitimate cases (UNACK'ed changed or duplicated ACK request). The ERROR will only show if the change was not found and the change was not ACK'ed previously. Remove meaningless assert statement. issue eProsima#452

richiware · 2019-04-15T18:45:10Z

Build status:

Linux
Mac
Windows

richiware · 2019-04-16T08:27:21Z

Build status:

Linux
Mac
Windows

guillaumeautran · 2019-04-16T14:09:07Z

@MiguelCompany Any help in understanding why the MAC tests are not passing?

MiguelCompany · 2019-04-23T14:32:17Z

Hi @guillaumeautran

ReaderProxy was refactored and changes are now removed from ReaderProxy when they are removed from writer's history.

I've found that irrelevant changes are added to the collection of the ReaderProxy and they shouldn't.

GAP messages are sent taking into consideration history's next_sequence_number() (see here and here )

So to take already removed changes into account when a new reader matches, and based on your changes, I propose the following patch:

diff --git a/src/cpp/rtps/writer/ReaderProxy.cpp b/src/cpp/rtps/writer/ReaderProxy.cpp
index 442a7abc..cb331fdf 100644
--- a/src/cpp/rtps/writer/ReaderProxy.cpp
+++ b/src/cpp/rtps/writer/ReaderProxy.cpp
@@ -142,6 +142,12 @@ void ReaderProxy::add_change(
         return;
     }
 
+    // Irrelevant changes are not added to the collection
+    if (!change.isRelevant())
+    {
+        return;
+    }
+
     if (changes_for_reader_.push_back(change) == nullptr)
     {
         // This should never happen
diff --git a/src/cpp/rtps/writer/StatefulWriter.cpp b/src/cpp/rtps/writer/StatefulWriter.cpp
index 00f4e2b0..73b0c20f 100644
--- a/src/cpp/rtps/writer/StatefulWriter.cpp
+++ b/src/cpp/rtps/writer/StatefulWriter.cpp
@@ -610,6 +610,13 @@ bool StatefulWriter::matched_reader_add(const ReaderProxyData& rdata)
         for(std::vector<CacheChange_t*>::iterator cit = mp_history->changesBegin();
                 cit != mp_history->changesEnd(); ++cit)
         {
+            // This is to cover the case when there are holes in the history
+            while (current_seq != (*cit)->sequenceNumber)
+            {
+                not_relevant_changes.insert(current_seq);
+                ++current_seq;
+            }
+
             ChangeForReader_t changeForReader(*cit);
 
             if(rp->durability_kind() >= TRANSIENT_LOCAL && this->getAttributes().durabilityKind >= TRANSIENT_LOCAL)
@@ -632,7 +639,12 @@ bool StatefulWriter::matched_reader_add(const ReaderProxyData& rdata)
             ++current_seq;
         }
 
-        assert(last_seq + 1 == current_seq);
+        // This is to cover the case where the last changes have been removed from the history
+        while (current_seq < next_sequence_number())
+        {
+            not_relevant_changes.insert(current_seq);
+            ++current_seq;
+        }
 
         try
         {

guillaumeautran · 2019-04-23T16:30:52Z

Sounds good @MiguelCompany
Are you taking care of the new updated changes then or do you want me to make a new PR (I will not be able to test it anytime soon as we are stuck on 1.7.2 until late May).

MiguelCompany · 2019-04-24T05:31:31Z

Closing in favor of #502

raquelalvarezbanos changed the title ~~ReaderProxy history reloaded incorrectly missing GAP message~~ ReaderProxy history reloaded incorrectly missing GAP message [4962] Mar 19, 2019

MiguelCompany mentioned this pull request Mar 29, 2019

Release 1.8.0 #468

Closed

31 tasks

MiguelCompany requested changes Apr 1, 2019

View reviewed changes

guillaumeautran force-pushed the issue_452 branch from 3954090 to e7ce157 Compare April 2, 2019 17:41

MiguelCompany previously approved these changes Apr 8, 2019

View reviewed changes

guillaumeautran dismissed MiguelCompany’s stale review via abdb99f April 11, 2019 16:20

guillaumeautran force-pushed the issue_452 branch 2 times, most recently from abdb99f to f552a76 Compare April 11, 2019 16:22

guillaumeautran force-pushed the issue_452 branch from f552a76 to a19016e Compare April 15, 2019 17:01

MiguelCompany mentioned this pull request Apr 24, 2019

ReaderProxy history reloaded incorrectly missing GAP message [4962] #502

Merged

MiguelCompany closed this Apr 24, 2019

Conversation

guillaumeautran commented Mar 18, 2019 • edited by MiguelCompany Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

richiware commented Mar 18, 2019

Uh oh!

guillaumeautran commented Mar 18, 2019

Uh oh!

richiware commented Mar 19, 2019

Uh oh!

richiware commented Mar 29, 2019

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

richiware commented Apr 2, 2019

Uh oh!

richiware commented Apr 2, 2019

Uh oh!

guillaumeautran commented Apr 11, 2019

Uh oh!

richiware commented Apr 11, 2019

Uh oh!

richiware commented Apr 15, 2019

Uh oh!

richiware commented Apr 16, 2019

Uh oh!

guillaumeautran commented Apr 16, 2019

Uh oh!

MiguelCompany commented Apr 23, 2019

Uh oh!

guillaumeautran commented Apr 23, 2019

Uh oh!

MiguelCompany commented Apr 24, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

guillaumeautran commented Mar 18, 2019 •

edited by MiguelCompany

Loading