View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001795GNUnetDV service or transportpublic2011-09-19 11:552024-03-07 20:24
ReporterChristian Grothoff Assigned Toschanzen  
PrioritynormalSeverityfeatureReproducibilityalways
Status closedResolutionfixed 
Product VersionGit master 
Target Version0.21.0Fixed in Version0.21.0 
Summary0001795: DV is not implemented
DescriptionTests crash reliabily right now. DV was removed from buildbots and marked as experimental in the build. DV should be fixed to not crash... (did we change that much in the plugin API!?).
Tagstng

Relationships

related to 0001936 confirmed need performance test for DV 
related to 0003131 closedBart Polot mesh crash causes consensus to fail 
related to 0005710 confirmed TNG meta issue 
parent of 0002836 closedFlorian Dold consensus creation fails in DV testcase 
parent of 0002837 closedMatthias Wachs need a way to get current (DV) distance information to a peer from ATS 
parent of 0002838 closedMatthias Wachs need ability to blacklist a particular plugin for a particular connection between peers in configuration 
parent of 0002850 closedChristian Grothoff consensus service segfaults during dv test 
parent of 0002846 closedMatthias Wachs ATS 'assemble_ats_information' has hard-coded ATS types/costs 
parent of 0002956 closedChristian Grothoff Jul 22 10:26:45-523995 mesh-27110 ERROR Assertion failed at gnunet-service-mesh.c:1252. 
parent of 0002955 closedFlorian Dold GNUNET_set_listen calls listen CB with NULL request 
parent of 0002963 closedFlorian Dold Jul 22 20:22:45-582528 dv-28437 ERROR Assertion failed at set_api.c:545. 
parent of 0003152 closedChristian Grothoff Dynamic growing consensus set causes segfault 
parent of 0003155 closedChristian Grothoff Crash in shutdown 
parent of 0003170 closedChristian Grothoff segfault in mesh 
parent of 0003169 closedBart Polot segfault in mesh 
parent of 0003168 closedChristian Grothoff use-after-free in mesh 
parent of 0003167 closedBart Polot segfault in mesh 
parent of 0003166 closedBart Polot segfault in mesh 
parent of 0003193 closedBart Polot Dec 11 00:42:53-176860 mesh-11331 ERROR Assertion failed at gnunet-service-mesh_channel.c:2030. 
parent of 0003177 closedMatthias Wachs transport crash in dv testcase 
related to 0002960 closedChristian Grothoff Set, DV, are not resistant to mesh crashes. 

Activities

Christian Grothoff

2013-03-18 12:56

manager   ~0006987

Code is mostly there; what is missing:
1) get proper distances to other peers from ATS/transport/core API
2) need ability to blacklist individual TCP-connection between some
   peers to force DV in the testcase
3) consensus service has problems (needs to be fixed first)

Christian Grothoff

2013-06-03 13:10

manager   ~0007146

DV implementation is now finished (using SET API instead of consensus); however, the code is untested and SET still needs to migrate to mesh (as it currently uses stream which then causes assertion failures).

Christian Grothoff

2013-07-10 14:44

manager   ~0007222

Set is now ready. Time to test DV...

Christian Grothoff

2013-10-20 20:27

manager   ~0007544

Matthias: did you and Sree make any progress on the testing issue for DV?

Christian Grothoff

2013-10-20 20:28

manager   ~0007545

Reminder sent to: Matthias Wachs, Sree Harsha Totakura

Did you make any progress on this yet?

Sree Harsha Totakura

2013-10-20 22:04

developer   ~0007549

I remember testing DV testcases with Matthias sometime ago. AFAIR, the failing DV testcase due to testbed timing out is fixed by reducing the per-operation timeout and observing the number of failed overlay connections. The overlay topology is again retried after sometime and this time it succeeds due to DV propagation.

Christian Grothoff

2013-10-21 11:56

manager   ~0007550

Well, right now the tests fail. With SVN HEAD, "CACHE_SIZE = 0" in template_dv.conf results in testbed crashing on assertion failure (because cache is NULL as the hash map is not initialized with a size of zero).

If I set CACHE_SIZE to 1 instead, I get (instantly):
$ ./test_transport_blacklist
Oct 21 11:54:03-356461 test-transport-blacklist-2067 ERROR Testbed connect peers despite blacklist!
grothoff@pixel:~/svn/gnunet/src/dv$ ./test_transport_dv
Testbed connected peers, should not happen...
Oct 21 11:54:12-698630 mesh-2168 ERROR Assertion failed at gnunet-service-mesh.c:3498.
Oct 21 11:54:12-698705 mesh-2168 ERROR type GNUNET_MESSAGE_TYPE_MESH_CONNECTION_ACK unknown!
Oct 21 11:54:12-698741 mesh-2168 ERROR Assertion failed at gnunet-service-mesh.c:3090.
Oct 21 11:54:12-700561 set-2166 ERROR Assertion failed at gnunet-service-set.c:369.

Sree Harsha Totakura

2013-10-29 10:46

developer   ~0007578

I fixed the bug in testbed which causes it to crash when CACHE_SIZE is set to 0. The DV testcases however do not pass.

Matthias Wachs

2013-11-12 14:20

manager   ~0007624

Last edited: 2013-11-12 14:55

 Blacklist IDs updated -> ./test_transport_blacklist passes
-> transport blacklisting for tcp connections works

Analyzing dv service:
- Peers connect on CORE level
- SET transmission is done
- SETs are exchanged correctly

- The SETs seem to be empty?

Matthias Wachs

2013-11-12 15:44

manager   ~0007625

My analysis:

The consensus sets exchanged between peers are empty, because direct connected peers are never added to the consensus set.


Routes for direct neigbours are added for a neighbour:

- Direct neighbour is created in core_connect
- handle_ats_update sets distance to 1 and tries to refresh routes...

But routes are never added:

In handle_ats_update -> refresh_routes:
  if (NULL != neighbor->neighbor_table)
  {

    GNUNET_CONTAINER_multipeermap_iterate (neighbor->neighbor_table,
                                           &check_possible_route,
                                           neighbor);
  }


neighbor->neighbor_table is never created and never populated!

Matthias Wachs

2013-11-25 15:34

manager   ~0007680

Added direct connections to consensus set ...
ATM SETs are not exchanged ... SET tests fail seems to be a set problem...

Matthias Wachs

2013-11-26 10:46

manager   ~0007689

Analysis peers do not exchange sets:

6DER initiate with G3FJ
6DER initiate with 6ULB
6DER initiate with DJ5S

G3FJ listens to 6DER
G3FJ listens to 6ULB

6ULB initiate with G3FJ
6ULB initiate with DJ5S
6ULB listens to 6DER

DJ5S listens to 6DER
DJ5S listens to 6ULB

Not established
# DJ5S - G3FJ


-- Nov 26 10:31:42-661563 dv-2431 DEBUG I am peer: 6DER
Nov 26 10:31:42-908563 dv-2431 DEBUG Initiating SET union with peer `G3FJ'
Nov 26 10:31:42-920771 dv-2431 DEBUG Finished building my SET for peer `G3FJ' with 0 elements, committing

Nov 26 10:31:42-933992 dv-2431 DEBUG Adding direct route to 6ULB

Nov 26 10:31:42-946805 dv-2431 DEBUG Initiating SET union with peer `6ULB'
Nov 26 10:31:42-948181 dv-2431 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:31:42-950916 dv-2431 DEBUG Finished building my SET for peer `6ULB' with 1 elements, committing

Nov 26 10:31:42-951765 dv-2431 DEBUG Adding direct route to DJ5S

Nov 26 10:31:42-963605 dv-2431 DEBUG Initiating SET union with peer `DJ5S'
Nov 26 10:31:42-964156 dv-2431 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:31:42-964706 dv-2431 DEBUG Adding peer `6ULB' with distance 1 to SET
Nov 26 10:31:42-965152 dv-2431 DEBUG Finished building my SET for peer `DJ5S' with 2 elements, committing

-- Nov 26 10:31:42-691340 dv-2441 DEBUG I am peer: DJ5S

Nov 26 10:31:43-021856 dv-2441 DEBUG Starting SET listen operation with peer `6DER'
Nov 26 10:31:43-069040 dv-2441 DEBUG Starting SET listen operation with peer `6ULB'

-- Nov 26 10:31:42-721183 dv-2437 DEBUG I am peer: 6ULB

Nov 26 10:31:42-971826 dv-2437 DEBUG Initiating SET union with peer `G3FJ'
Nov 26 10:31:42-984021 dv-2437 DEBUG Finished building my SET for peer `G3FJ' with 0 elements, committing

Nov 26 10:31:43-032581 dv-2437 DEBUG Initiating SET union with peer `DJ5S'
Nov 26 10:31:43-033904 dv-2437 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:31:43-036799 dv-2437 DEBUG Adding peer `6DER' with distance 1 to SET
Nov 26 10:31:43-037532 dv-2437 DEBUG Finished building my SET for peer `DJ5S' with 2 elements, committing

Nov 26 10:31:43-011622 dv-2437 DEBUG Starting SET listen operation with peer `6DER'

-- Nov 26 10:31:42-735928 dv-2427 DEBUG I am peer: G3FJ
Nov 26 10:31:43-076361 dv-2427 DEBUG Starting SET listen operation with peer `6DER'
Nov 26 10:31:43-114702 dv-2427 DEBUG Starting SET listen operation with peer `6ULB'

Matthias Wachs

2013-11-26 10:50

manager   ~0007690

Last edited: 2013-11-26 10:50

 Output with DV and SET on debug:

mwachs@fulcrum:~/coding/gnunet/src/dv$ ./test_transport_dv
Nov 26 10:48:57-307802 test-transport-dv-4387 DEBUG Starting HELPER process `/home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-helper-testbed'
Nov 26 10:48:57-308625 test-transport-dv-4387 DEBUG Transmitted 3552 bytes to /home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-helper-testbed
Nov 26 10:48:57-314904 test-transport-dv-4387 DEBUG Got 3647 bytes from helper `/home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-helper-testbed'
Nov 26 10:48:57-386462 dv-api-4413 DEBUG Connecting to DV service
Nov 26 10:48:57-386462 dv-api-4411 DEBUG Connecting to DV service
Nov 26 10:48:57-386724 dv-api-4412 DEBUG Connecting to DV service
Nov 26 10:48:57-394499 dv-api-4417 DEBUG Connecting to DV service
==4423== Memcheck, a memory error detector
==4423== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==4423== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==4423== Command: /home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-service-dv -c /tmp/testbed7LspHu/2/config
==4423==
==4422== Memcheck, a memory error detector
==4422== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==4422== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==4422== Command: /home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-service-dv -c /tmp/testbed7LspHu/0/config
==4422==
==4421== Memcheck, a memory error detector
==4421== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==4421== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==4421== Command: /home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-service-dv -c /tmp/testbed7LspHu/1/config
==4421==
==4435== Memcheck, a memory error detector
==4435== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==4435== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==4435== Command: /home/mwachs/coding/gnb/lib/gnunet/libexec/gnunet-service-dv -c /tmp/testbed7LspHu/3/config
==4435==
Nov 26 10:48:58-776848 dv-4421 DEBUG I am peer: 6ULB
Nov 26 10:48:58-852755 dv-4421 DEBUG Core connected to G3FJ (distance unknown)
Nov 26 10:48:58-855182 dv-4421 DEBUG Core connected to DJ5S (distance unknown)
Nov 26 10:48:58-858854 dv-4421 DEBUG Direct connection to G3FJ established, routing table exchange begins.
Nov 26 10:48:58-870211 dv-4421 DEBUG Adding direct route to G3FJ
Nov 26 10:48:58-850489 dv-4435 DEBUG I am peer: G3FJ
Nov 26 10:48:58-853510 dv-4423 DEBUG I am peer: DJ5S
Nov 26 10:48:58-927197 dv-4435 DEBUG Core connected to 6ULB (distance unknown)
Nov 26 10:48:58-929891 dv-4435 DEBUG Core connected to 6DER (distance unknown)
Nov 26 10:48:58-931190 dv-4423 DEBUG Core connected to 6ULB (distance unknown)
Nov 26 10:48:58-933679 dv-4435 DEBUG Direct connection to 6DER established, routing table exchange begins.
Nov 26 10:48:58-934599 dv-4423 DEBUG Core connected to 6DER (distance unknown)
Nov 26 10:48:58-939355 dv-4423 DEBUG Direct connection to 6DER established, routing table exchange begins.
Nov 26 10:48:58-944680 dv-4435 DEBUG Adding direct route to 6DER
Nov 26 10:48:58-950385 dv-4423 DEBUG Adding direct route to 6DER
Nov 26 10:48:58-949586 dv-4422 DEBUG I am peer: 6DER
Nov 26 10:48:59-023968 dv-4421 DEBUG Initiating SET union with peer `G3FJ'
Nov 26 10:48:59-026331 dv-4422 DEBUG Core connected to G3FJ (distance unknown)
Nov 26 10:48:59-028926 set-api-4421 DEBUG set client created
Nov 26 10:48:59-029731 dv-4422 DEBUG Core connected to 6ULB (distance unknown)
Nov 26 10:48:59-030789 dv-4422 DEBUG Core connected to DJ5S (distance unknown)
Nov 26 10:48:59-032974 set-4440 INFO started
Nov 26 10:48:59-034588 dv-4422 DEBUG Direct connection to G3FJ established, routing table exchange begins.
Nov 26 10:48:59-040989 dv-4421 DEBUG Finished building my SET for peer `G3FJ' with 0 elements, committing
Nov 26 10:48:59-047848 dv-4422 DEBUG Adding direct route to G3FJ
Nov 26 10:48:59-052586 set-4440 DEBUG client created new set (operation 2)
Nov 26 10:48:59-052634 set-4440 DEBUG union set created
Nov 26 10:48:59-052863 dv-4421 DEBUG Core connected to 6DER (distance unknown)
Nov 26 10:48:59-056242 set-4440 DEBUG evaluating union operation
Nov 26 10:48:59-056294 set-4440 DEBUG sent op request without context message
Nov 26 10:48:59-056858 dv-4421 DEBUG Direct connection to 6DER established, routing table exchange begins.
Nov 26 10:48:59-057465 dv-4421 DEBUG Adding direct route to 6DER
Nov 26 10:48:59-070346 dv-4421 DEBUG Starting SET listen operation with peer `6DER'
Nov 26 10:48:59-074112 set-4440 DEBUG new listener created (op 2, app 4IUT9PIE)
Nov 26 10:48:59-074150 set-4440 DEBUG considered all incoming requests
Nov 26 10:48:59-074403 dv-4421 DEBUG Direct connection to DJ5S established, routing table exchange begins.
Nov 26 10:48:59-074627 dv-4421 DEBUG Adding direct route to DJ5S
Nov 26 10:48:59-092883 dv-4421 DEBUG Initiating SET union with peer `DJ5S'
Nov 26 10:48:59-093660 set-api-4421 DEBUG set client created
Nov 26 10:48:59-094886 dv-4421 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:48:59-097015 set-4440 DEBUG client created new set (operation 2)
Nov 26 10:48:59-097056 set-4440 DEBUG union set created
Nov 26 10:48:59-097254 set-4440 DEBUG client ins/rem element of size 36
Nov 26 10:48:59-096526 dv-4435 DEBUG Starting SET listen operation with peer `6DER'
Nov 26 10:48:59-097641 dv-4421 DEBUG Adding peer `6DER' with distance 1 to SET
Nov 26 10:48:59-097883 set-4440 DEBUG client ins/rem element of size 36
Nov 26 10:48:59-098118 dv-4421 DEBUG Finished building my SET for peer `DJ5S' with 2 elements, committing
Nov 26 10:48:59-098471 set-4440 DEBUG evaluating union operation
Nov 26 10:48:59-098505 set-4440 DEBUG sent op request without context message
Nov 26 10:48:59-106663 set-4444 INFO started
Nov 26 10:48:59-107176 dv-4423 DEBUG Starting SET listen operation with peer `6DER'
Nov 26 10:48:59-115811 set-4446 INFO started
Nov 26 10:48:59-116599 set-4444 DEBUG new listener created (op 2, app A35H9N4K)
Nov 26 10:48:59-116632 set-4444 DEBUG considered all incoming requests
Nov 26 10:48:59-118205 dv-4435 DEBUG Direct connection to 6ULB established, routing table exchange begins.
Nov 26 10:48:59-119602 dv-4435 DEBUG Adding direct route to 6ULB
Nov 26 10:48:59-128571 set-4446 DEBUG new listener created (op 2, app 46Q0EAUB)
Nov 26 10:48:59-128617 set-4446 DEBUG considered all incoming requests
Nov 26 10:48:59-130344 dv-4423 DEBUG Direct connection to 6ULB established, routing table exchange begins.
Nov 26 10:48:59-131721 dv-4423 DEBUG Adding direct route to 6ULB
Nov 26 10:48:59-135212 dv-4435 DEBUG Starting SET listen operation with peer `6ULB'
Nov 26 10:48:59-136495 set-4444 DEBUG new listener created (op 2, app 3EHDSDB7)
Nov 26 10:48:59-136528 set-4444 DEBUG considered all incoming requests
Nov 26 10:48:59-147625 dv-4423 DEBUG Starting SET listen operation with peer `6ULB'
Nov 26 10:48:59-148502 set-4446 DEBUG new listener created (op 2, app 9VP5P4I2)
Nov 26 10:48:59-148596 set-4446 DEBUG considered all incoming requests
Nov 26 10:48:59-228971 dv-4422 DEBUG Initiating SET union with peer `G3FJ'
Nov 26 10:48:59-232234 set-api-4422 DEBUG set client created
Nov 26 10:48:59-234479 set-4454 INFO started
Nov 26 10:48:59-243288 dv-4422 DEBUG Finished building my SET for peer `G3FJ' with 0 elements, committing
Nov 26 10:48:59-255213 set-4454 DEBUG client created new set (operation 2)
Nov 26 10:48:59-255264 set-4454 DEBUG union set created
Nov 26 10:48:59-257499 set-4454 DEBUG evaluating union operation
Nov 26 10:48:59-257535 set-4454 DEBUG sent op request without context message
Nov 26 10:48:59-257988 dv-4422 DEBUG Direct connection to 6ULB established, routing table exchange begins.
Nov 26 10:48:59-258628 dv-4422 DEBUG Adding direct route to 6ULB
Nov 26 10:48:59-270711 dv-4422 DEBUG Initiating SET union with peer `6ULB'
Nov 26 10:48:59-271242 set-api-4422 DEBUG set client created
Nov 26 10:48:59-272230 dv-4422 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:48:59-274335 set-4454 DEBUG client created new set (operation 2)
Nov 26 10:48:59-274374 set-4454 DEBUG union set created
Nov 26 10:48:59-274565 set-4454 DEBUG client ins/rem element of size 36
Nov 26 10:48:59-275012 dv-4422 DEBUG Finished building my SET for peer `6ULB' with 1 elements, committing
Nov 26 10:48:59-275332 set-4454 DEBUG evaluating union operation
Nov 26 10:48:59-275363 set-4454 DEBUG sent op request without context message
Nov 26 10:48:59-275506 dv-4422 DEBUG Direct connection to DJ5S established, routing table exchange begins.
Nov 26 10:48:59-275880 dv-4422 DEBUG Adding direct route to DJ5S
Nov 26 10:48:59-287648 dv-4422 DEBUG Initiating SET union with peer `DJ5S'
Nov 26 10:48:59-288067 set-api-4422 DEBUG set client created
Nov 26 10:48:59-288372 dv-4422 DEBUG Adding peer `G3FJ' with distance 1 to SET
Nov 26 10:48:59-288609 set-4454 DEBUG client created new set (operation 2)
Nov 26 10:48:59-288643 set-4454 DEBUG union set created
Nov 26 10:48:59-289021 set-4454 DEBUG client ins/rem element of size 36
Nov 26 10:48:59-289127 dv-4422 DEBUG Adding peer `6ULB' with distance 1 to SET
Nov 26 10:48:59-289673 set-4454 DEBUG client ins/rem element of size 36
Nov 26 10:48:59-289873 dv-4422 DEBUG Finished building my SET for peer `DJ5S' with 2 elements, committing
Nov 26 10:48:59-290195 set-4454 DEBUG evaluating union operation
Nov 26 10:48:59-290225 set-4454 DEBUG sent op request without context message
Nov 26 10:49:02-913768 testbed-api-topology-4387 WARNING Error while establishing a link: 0x10: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:03-100675 testbed-api-topology-4387 WARNING Error while establishing a link: 0x13: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Nov 26 10:49:08-101927 testbed-api-topology-4387 WARNING Error while establishing a link: 0x15: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Nov 26 10:49:08-101958 testbed-api-topology-4387 WARNING Error while establishing a link: 0x14: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:13-103372 testbed-api-topology-4387 WARNING Error while establishing a link: 0x17: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:13-103407 testbed-api-topology-4387 WARNING Error while establishing a link: 0x16: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Testbed failed to connect peers,
Nov 26 10:49:23-110327 testbed-api-topology-4387 WARNING Error while establishing a link: 0x22: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:23-111899 testbed-api-topology-4387 WARNING Error while establishing a link: 0x25: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Nov 26 10:49:28-113248 testbed-api-topology-4387 WARNING Error while establishing a link: 0x27: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Nov 26 10:49:28-113280 testbed-api-topology-4387 WARNING Error while establishing a link: 0x26: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:33-114558 testbed-api-topology-4387 WARNING Error while establishing a link: 0x29: Timeout during TRANSPORT_try_connect() at peer G3FJ -- Retrying
Nov 26 10:49:33-114595 testbed-api-topology-4387 WARNING Error while establishing a link: 0x28: Timeout during TRANSPORT_try_connect() at peer DJ5S -- Retrying
Nov 26 10:49:38-115932 test-transport-dv-4387 INFO Links successful 10 / 8 fai

Florian Dold

2013-11-26 15:00

developer   ~0007700

I can confirm that gnunet-consensus-profiler also stopped working ...

At the moment it looks to me like there's just no data going through the mesh channel, so maybe mesh is broken, but I'll have to investigate further ...

Florian Dold

2013-11-26 15:13

developer   ~0007701

Last edited: 2013-11-26 15:13

 Confirmed, if the service would actually get data, something like
Nov 26 15:03:56-017111 set-3675 DEBUG dispatching mesh message (type: 581)
would be in the logs.

Florian Dold

2013-11-26 15:18

developer   ~0007702

Ah! Mesh crashes ...
Nov 26 15:17:31-190177 mesh-api-5069 DEBUG Mesh service disconnected, reconnecting

Matthias Wachs

2013-11-27 10:28

manager   ~0007728

Peers exchange sets, routes are discovered:

Nov 27 10:15:09-003955 dv-321 DEBUG I am peer: DJ5S
Nov 27 10:15:09-622887 dv-321 DEBUG Discovered new route to G3FJ using 2 hops
Nov 27 10:15:09-624684 dv-321 DEBUG Delivering CONNECT about peer `G3FJ'

Nov 27 10:15:08-891056 dv-317 DEBUG I am peer: 6DER
Nov 27 10:15:09-423679 dv-317 DEBUG Discovered new route to DJ5S using 2 hops
Nov 27 10:15:09-426123 dv-317 DEBUG Delivering CONNECT about peer `DJ5S'

Matthias Wachs

2013-12-05 14:25

manager   ~0007761

Current state (location of crash):

==2224== Invalid read of size 8
==2224== at 0x403EB5: cull_routes (gnunet-service-dv.c:1165)
==2224== by 0x56836BB: GNUNET_CONTAINER_multipeermap_iterate (container_multipeermap.c:361)
==2224== by 0x403FD7: handle_direct_disconnect (gnunet-service-dv.c:1187)
==2224== by 0x405D68: cleanup_neighbor (gnunet-service-dv.c:1816)
==2224== by 0x406087: handle_core_disconnect (gnunet-service-dv.c:1858)
==2224== by 0x5450C46: disconnect_and_free_peer_entry (core_api.c:389)
==2224== by 0x56836BB: GNUNET_CONTAINER_multipeermap_iterate (container_multipeermap.c:361)
==2224== by 0x545624B: GNUNET_CORE_disconnect (core_api.c:1221)
==2224== by 0x406332: shutdown_task (gnunet-service-dv.c:1924)
==2224== by 0x56A6DD0: run_ready (scheduler.c:593)
==2224== by 0x56A7657: GNUNET_SCHEDULER_run (scheduler.c:808)
==2224== by 0x56B56DA: GNUNET_SERVICE_run (service.c:1478)
==2224== Address 0x6f07920 is 0 bytes inside a block of size 48 free'd
==2224== at 0x4C2BA6C: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==2224== by 0x566FE1E: GNUNET_xfree_ (common_allocation.c:236)
==2224== by 0x4032B4: handle_direct_connect (gnunet-service-dv.c:878)
==2224== by 0x4042E5: handle_ats_update (gnunet-service-dv.c:1303)
==2224== by 0x4E3BE4D: process_pi_message (ats_api_performance.c:382)
==2224== by 0x4E3CB6A: process_ats_message (ats_api_performance.c:554)
==2224== by 0x566D130: receive_task (client.c:589)
==2224== by 0x56A6DD0: run_ready (scheduler.c:593)
==2224== by 0x56A7657: GNUNET_SCHEDULER_run (scheduler.c:808)
==2224== by 0x56B56DA: GNUNET_SERVICE_run (service.c:1478)
==2224== by 0x4067D3: main (gnunet-service-dv.c:2085)
==2224==

Christian Grothoff

2013-12-08 21:51

manager   ~0007782

Last edited: 2013-12-08 21:53

 I don't see the above anymore right now. But I get:

Dec 08 21:49:56-819037 dv-32086 ERROR Assertion failed at gnunet-service-dv.c:757.
Dec 08 21:50:04-694219 transport-32063 ERROR Assertion failed at plugin_transport_dv.c:313.

..Dec 08 21:50:07-176106 dv-32081 WARNING External protocol violation detected at gnunet-service-dv.c:1515.
Dec 08 21:52:29-184547 dv-32147 ERROR Assertion failed at gnunet-service-dv.c:660.

Christian Grothoff

2013-12-08 21:51

manager   ~0007783

I _also_ get:
==32091== Invalid read of size 1
==32091== at 0x4C2E819: bcmp (mc_replace_strmem.c:935)
==32091== by 0x10B55F: build_set (gnunet-service-dv.c:844)
==32091== by 0x569C1B9: impl_send_continue (mq.c:289)
==32091== by 0x56ABEC0: run_ready (scheduler.c:595)
==32091== by 0x56AC812: GNUNET_SCHEDULER_run (scheduler.c:817)
==32091== by 0x56BB60F: GNUNET_SERVICE_run (service.c:1478)
==32091== by 0x10F3C8: main (gnunet-service-dv.c:2101)
==32091== Address 0x8 is not stack'd, malloc'd or (recently) free'd
==32091==

Christian Grothoff

2013-12-11 00:39

manager   ~0007834

DV now stopped crashing and seems to be exchanging routes, but I don't see it actually establishing connections (core/transport-level).

Christian Grothoff

2013-12-19 00:09

manager   ~0007901

DV now connects at the ATS and transport layers, but not at CORE. This is very strange, as CORE does get the 'connect' and does respond with a KX initiation. It seemed that then ATS (!) may decide to switch to TCP (which is blacklisted), which then causes the KX to fail (as gnunet-service-transport_neighbours takes the ATS opinion into account while it checks for the blacklist). It is possible that the (blacklisted) TCP connection is then removed from ATS, but that does not help: core somehow got a disconnect (from transport), but transport continues to be connected, and DV has no timeout implemented so the situation is also never rectified by DV disconnect/reconnect. I'm not sure how exactly CORE gets the disconnect while transport remains connected, but it is late...

Christian Grothoff

2013-12-22 01:43

manager   ~0007928

I'm re-scheduling this one for 0.10.1, as we clearly won't have time to finish it, and 0003229 is much more pressing.

Christian Grothoff

2019-05-02 14:45

manager   ~0014373

Note that DV *is* now implemented (but not tested) as part of TNG.

schanzen

2024-03-07 20:24

administrator   ~0021780

0.21 released

Issue History

Date Modified Username Field Change
2011-09-19 11:55 Christian Grothoff New Issue
2011-09-19 11:55 Christian Grothoff Status new => assigned
2011-09-19 11:55 Christian Grothoff Assigned To => mrwiggles
2011-11-15 13:44 Christian Grothoff Assigned To mrwiggles =>
2011-11-15 13:44 Christian Grothoff Status assigned => confirmed
2012-02-21 22:03 Christian Grothoff Target Version => 0.9.5
2012-03-16 23:51 Christian Grothoff Priority normal => low
2012-06-22 10:58 Christian Grothoff Target Version 0.9.5 => 0.10.0
2012-10-07 14:06 Christian Grothoff Target Version 0.10.0 =>
2012-12-06 19:16 Christian Grothoff Severity crash => feature
2012-12-06 19:16 Christian Grothoff Summary DV tests crash => DV is not implemented
2012-12-22 16:15 Christian Grothoff Priority low => normal
2012-12-22 16:15 Christian Grothoff Target Version => 0.10.1
2013-03-13 23:46 Christian Grothoff Assigned To => Christian Grothoff
2013-03-13 23:46 Christian Grothoff Status confirmed => assigned
2013-03-15 21:07 Christian Grothoff Priority normal => high
2013-03-15 21:07 Christian Grothoff Target Version 0.10.1 => 0.10.0
2013-03-18 12:53 Christian Grothoff Relationship added parent of 0002836
2013-03-18 12:56 Christian Grothoff Note Added: 0006987
2013-03-18 12:59 Christian Grothoff Relationship added parent of 0002837
2013-03-18 13:01 Christian Grothoff Relationship added parent of 0002838
2013-03-18 14:59 Christian Grothoff Target Version 0.10.0 => 0.10.1
2013-03-30 17:31 Christian Grothoff Relationship added parent of 0002850
2013-03-30 17:31 Christian Grothoff Relationship added parent of 0002846
2013-06-03 13:10 Christian Grothoff Note Added: 0007146
2013-06-03 13:11 Christian Grothoff Relationship added related to 0001936
2013-07-10 14:44 Christian Grothoff Note Added: 0007222
2013-07-11 00:08 Christian Grothoff Priority high => urgent
2013-07-11 00:08 Christian Grothoff Target Version 0.10.1 => 0.10.0
2013-07-22 20:53 Christian Grothoff Relationship added parent of 0002956
2013-07-22 20:53 Christian Grothoff Relationship added parent of 0002955
2013-07-22 20:54 Christian Grothoff Relationship added parent of 0002963
2013-08-31 21:45 Christian Grothoff Assigned To Christian Grothoff => Matthias Wachs
2013-10-20 20:27 Christian Grothoff Note Added: 0007544
2013-10-20 20:28 Christian Grothoff Note Added: 0007545
2013-10-20 22:04 Sree Harsha Totakura Note Added: 0007549
2013-10-21 11:56 Christian Grothoff Note Added: 0007550
2013-10-29 10:46 Sree Harsha Totakura Note Added: 0007578
2013-11-12 14:20 Matthias Wachs Note Added: 0007624
2013-11-12 14:55 Matthias Wachs Note Edited: 0007624
2013-11-12 15:44 Matthias Wachs Note Added: 0007625
2013-11-12 15:45 Matthias Wachs Status assigned => feedback
2013-11-25 15:34 Matthias Wachs Note Added: 0007680
2013-11-25 15:34 Matthias Wachs Status feedback => confirmed
2013-11-26 10:46 Matthias Wachs Note Added: 0007689
2013-11-26 10:50 Matthias Wachs Note Added: 0007690
2013-11-26 10:50 Matthias Wachs Note Edited: 0007690
2013-11-26 15:00 Florian Dold Note Added: 0007700
2013-11-26 15:13 Florian Dold Note Added: 0007701
2013-11-26 15:13 Florian Dold Note Edited: 0007701
2013-11-26 15:18 Florian Dold Note Added: 0007702
2013-11-26 15:33 Florian Dold Relationship added related to 0003131
2013-11-27 10:28 Matthias Wachs Note Added: 0007728
2013-11-29 20:09 Christian Grothoff Relationship added related to 0002960
2013-12-05 14:25 Matthias Wachs Note Added: 0007761
2013-12-07 22:20 Christian Grothoff Relationship added parent of 0003152
2013-12-07 22:20 Christian Grothoff Relationship added parent of 0003155
2013-12-08 21:51 Christian Grothoff Note Added: 0007782
2013-12-08 21:51 Christian Grothoff Note Added: 0007783
2013-12-08 21:52 Christian Grothoff Note Edited: 0007782
2013-12-08 21:53 Christian Grothoff Note Edited: 0007782
2013-12-08 22:25 Christian Grothoff Relationship added parent of 0003170
2013-12-08 22:25 Christian Grothoff Relationship added parent of 0003169
2013-12-08 22:25 Christian Grothoff Relationship added parent of 0003168
2013-12-08 22:25 Christian Grothoff Relationship added parent of 0003167
2013-12-08 22:25 Christian Grothoff Relationship added parent of 0003166
2013-12-11 00:39 Christian Grothoff Note Added: 0007834
2013-12-11 20:12 Christian Grothoff Relationship added parent of 0003193
2013-12-11 20:12 Christian Grothoff Relationship added parent of 0003177
2013-12-19 00:09 Christian Grothoff Note Added: 0007901
2013-12-22 01:42 Christian Grothoff Target Version 0.10.0 => 0.10.1
2013-12-22 01:43 Christian Grothoff Note Added: 0007928
2013-12-23 19:07 Christian Grothoff Status confirmed => assigned
2014-01-30 15:54 Christian Grothoff Target Version 0.10.1 =>
2014-04-11 15:06 Christian Grothoff Target Version => 0.11.0pre66
2014-06-04 15:30 Christian Grothoff Priority urgent => normal
2014-06-04 15:30 Christian Grothoff Target Version 0.11.0pre66 =>
2014-12-08 15:29 Christian Grothoff Assigned To Matthias Wachs => Christian Grothoff
2015-01-18 18:27 Christian Grothoff Assigned To Christian Grothoff =>
2015-01-18 18:27 Christian Grothoff Status assigned => confirmed
2019-05-02 14:45 Christian Grothoff Relationship added related to 0005710
2019-05-02 14:45 Christian Grothoff Note Added: 0014373
2020-08-14 12:01 schanzen Tag Attached: tng
2020-10-29 10:09 schanzen Target Version => 0.15.0
2021-06-10 19:36 schanzen Target Version 0.15.0 => 0.16.0
2021-12-31 09:29 schanzen Target Version 0.16.0 => 0.17.0
2021-12-31 09:32 schanzen Target Version 0.17.0 => 1.0.0
2024-03-05 15:51 schanzen Assigned To => schanzen
2024-03-05 15:51 schanzen Status confirmed => resolved
2024-03-05 15:51 schanzen Resolution open => fixed
2024-03-05 15:51 schanzen Fixed in Version => 0.21.0
2024-03-05 15:52 schanzen Target Version 1.0.0 => 0.21.0
2024-03-07 20:24 schanzen Note Added: 0021780
2024-03-07 20:24 schanzen Status resolved => closed