View Issue Details

IDProjectCategoryView StatusLast Update
0003705GNUnetset servicepublic2018-06-07 00:39
ReporterChristian GrothoffAssigned ToFlorian Dold 
PriorityhighSeveritymajorReproducibilityrandom
Status closedResolutionfixed 
Platformi7OSDebian GNU/LinuxOS Versionsqueeze
Product VersionSVN HEAD 
Target Version0.11.0Fixed in Version0.11.0pre66 
Summary0003705: set union fails with "other peer disconnected prematurely"
DescriptionI get this error when normal peers are running as part of their typical revocation set union calculation:

Mar 07 19:58:58-516571 revocation-15465 DEBUG Peer `AZ7G' connected to us
Mar 07 19:58:58-516647 revocation-15465 DEBUG Starting SET operation with peer `AZ7G'
Mar 07 19:58:59-517691 revocation-15465 DEBUG Starting set exchange with peer `AZ7G'
Mar 07 19:58:59-517820 set-15470 DEBUG Initiating union operation evaluation
Mar 07 19:58:59-517851 set-15470 DEBUG sent op request without context message
Mar 07 19:59:17-331942 revocation-15465 DEBUG Peer `CW42' connected to us
Mar 07 19:59:17-331978 revocation-15465 DEBUG Starting SET operation with peer `CW42'
Mar 07 19:59:17-700085 revocation-15465 DEBUG Peer `APHW' connected to us
Mar 07 19:59:18-332643 revocation-15465 DEBUG Starting set exchange with peer `CW42'
Mar 07 19:59:18-332771 set-15470 DEBUG Initiating union operation evaluation
Mar 07 19:59:18-332798 set-15470 DEBUG sent op request without context message
Mar 07 19:59:30-772084 set-15470 DEBUG channel_end_cb called
Mar 07 19:59:30-772113 set-15470 DEBUG calling peer disconnect due to channel end
Mar 07 19:59:30-772135 set-15470 WARNING other peer disconnected prematurely
Mar 07 19:59:30-772145 set-15470 DEBUG destroying union op
Mar 07 19:59:30-772195 set-15470 DEBUG destroying union op done
Mar 07 19:59:30-772211 set-15470 DEBUG channel_end_cb finished
Mar 07 19:59:30-772233 set-15470 DEBUG channel_end_cb called
Mar 07 19:59:30-772241 set-15470 DEBUG calling peer disconnect due to channel end
Mar 07 19:59:30-772248 set-15470 WARNING other peer disconnected prematurely
Mar 07 19:59:30-772255 set-15470 DEBUG destroying union op
Mar 07 19:59:30-772301 set-15470 DEBUG destroying union op done
Mar 07 19:59:30-772309 set-15470 DEBUG channel_end_cb finished
Mar 07 19:59:30-772438 set-api-15465 DEBUG Got result message with status 1
Mar 07 19:59:30-772486 revocation-15465 WARNING Error computing revocation set union with CW42
Mar 07 19:59:30-772517 set-api-15465 DEBUG Got result message with status 1
Mar 07 19:59:30-772529 revocation-15465 WARNING Error computing revocation set union with AZ7G
Steps To ReproduceRun a peer for a while. Note that it seems only the 'initiating' peer sees this error. OTOH, no set unions ever officially succeed as far as revocation's statistics are concerned.
Additional InformationThis involves two empty sets.
TagsNo tags attached.

Activities

Florian Dold

2015-03-07 23:30

developer   ~0008990

It's really difficult to see what's going on without the other peer's logs.

It seems like the CADET channel is closed right after the initiating peer sends the first message (the request for a set operation). The REVOCATION service doesn't call reject on any set operation request, and the time between the request and channel end call is too short to be the timeout for unanswered incoming requests. Thus I'm unsure where the disconnect actually happens.

There are a lot of places where we disconnect a peer because of protocol violations, but that only happens further along in the protocol.

Is this a new bug / does it only happen sometimes? I'm not sure what you mean by "no set unions ever officially succeed as far as revocation's statistics are concerned". Shouldn't the corresponding test case for revocation fail then?

Christian Grothoff

2015-03-07 23:51

manager   ~0008994

That's the strange thing: the test has passed for a long time, but I don't have evidence this ever worked "in the real world". The bug is certainly not new, I just used to be able to blame it on other things...

Florian Dold

2015-03-07 23:58

developer   ~0008995

Any ideas what we can do to investigate this? From a look at the code and the logs there doesn't seem to be anything too obvious, I especially don't get why the test case passes.

Did I understand you correctly that we *never* see a set reconciliation succeeding from revocation when running as a normal peer (and not in a testbed).

Christian Grothoff

2015-03-07 23:59

manager   ~0008996

Well, at least I have never seen the 'success' stat for revocation > 0.

Florian Dold

2015-03-08 00:04

developer   ~0008997

Alright, maybe this will get clearer after adding statistics to the set service (0003706).

Christian Grothoff

2015-03-08 12:45

manager   ~0008998

Oh, I was wrong, it does work sometimes:

gnunet9@sam:~$ gnunet-statistics -s revocation
   revocation # peers connected: 15
   revocation # revocation set unions completed: 36
   revocation # revocation set unions failed: 9

Christian Grothoff

2018-06-07 00:39

manager   ~0012989

Closing as recent fixes to CADET explain a _lot_ of these issues.

Issue History

Date Modified Username Field Change
2015-03-07 20:09 Christian Grothoff New Issue
2015-03-07 20:09 Christian Grothoff Status new => assigned
2015-03-07 20:09 Christian Grothoff Assigned To => Florian Dold
2015-03-07 20:38 Christian Grothoff Target Version => 0.11.0
2015-03-07 23:30 Florian Dold Note Added: 0008990
2015-03-07 23:51 Christian Grothoff Note Added: 0008994
2015-03-07 23:58 Florian Dold Note Added: 0008995
2015-03-07 23:59 Christian Grothoff Note Added: 0008996
2015-03-08 00:04 Florian Dold Note Added: 0008997
2015-03-08 12:45 Christian Grothoff Note Added: 0008998
2018-06-07 00:39 Christian Grothoff Status assigned => closed
2018-06-07 00:39 Christian Grothoff Resolution open => fixed
2018-06-07 00:39 Christian Grothoff Fixed in Version => 0.11.0pre66
2018-06-07 00:39 Christian Grothoff Note Added: 0012989