View Issue Details

IDProjectCategoryView StatusLast Update
0003448GNUnettransport servicepublic2018-06-07 00:25
ReporterBart PolotAssigned ToChristian Grothoff 
PriorityimmediateSeveritymajorReproducibilityalways
Status closedResolutionfixed 
Product VersionSVN HEAD 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0003448: Core-level (transport? ats?) connectivity problems
DescriptionScenario: working from my laptop at home, running peer ZGV0, and the pc at the office via ssh, running peer WX7E. Both same svn version (HEAD).

Problem 1: gnunet-core shows no connections on either computer, same with gnunet-transport -i, although gnunet-peerinfo shows 9 peers with apparently valid addresses. Is gnunet.org's peer running? What about fulcrum?

Problem 2: I connect both peers via peerinfo -g on the office and peerinfo -s on my nat-ed laptop. They connect. Then this happens:

[bart@saturn ~]$ gnunet-core
 Mi Jun 18 02:42:26 2014: connection established ZGV0 (timeout in 276 s)
[bart@saturn ~]$ gnunet-core
 Mi Jun 18 02:42:28 2014: connection established ZGV0 (timeout in 274 s)
[bart@saturn ~]$ Jun 18 02:42:31-233905 cadet-p2p-14693 DEBUG DISCONNECTED WX7E <= ZGV0
 (core_disconnect callback in cadet)
[bart@saturn ~]$ gnunet-core
[bart@saturn ~]$

See timestamps: 3 seconds after last gnunet-core call, the connection goes down. All this was logged in the ssh terminal, so no TCP/IP connectivity issues.

Trying to re-establish the connection from the laptop did not work either.

Some interesting events (clocks are in sync to the second). Disconnection:
Jun 18 02:42:31-204758 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E

Debug information from cadet service, does not know any paths towards the pc.
Jun 18 02:42:43-568329 cadet-loc-28849 ERROR Peer WX7E
Jun 18 02:42:43-568348 cadet-loc-28849 ERROR 0 paths

Trying to trigger a DHT GET, which will call transport_try_connect on the hello.
[bart@voyager ~]$ gnunet-cadet -e WX7E[...] 42
Jun 18 02:43:00-757996 gnunet-cadet-32648 DEBUG Creating channel to WX7E[.,.]
Jun 18 02:43:00-759361 cadet-p2p-28849 DEBUG Starting DHT GET for peer WX7E
Jun 18 02:43:00-760232 cadet-dht-28849 INFO Got path from DHT: ZGV0 WX7E
Jun 18 02:43:00-760244 cadet-dht-28849 DEBUG Got HELLO for WX7E
Jun 18 02:43:03-883021 cadet-hll-28849 DEBUG hello for WX7E (214 bytes), expires on Wed Jun 18 14:43:03 2014

Nothing happens, giving up:
Jun 18 02:43:19-734790 cadet-loc-28849 DEBUG Channel WX7E:42 [...] destroy, due to client 16 shutdown.

And after a while:
Jun 18 02:45:54-937865 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E

And then, doing nothing:
Jun 18 02:48:13-866576 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:49:45-266041 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 02:50:08-885054 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:50:37-512949 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 02:52:08-903343 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:53:25-293517 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 02:54:24-206163 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:55:40-596059 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 02:56:08-886468 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:56:32-359062 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 02:58:08-880949 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 02:59:25-268735 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 03:03:24-189939 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 03:04:40-577326 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 03:07:06-538477 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 03:08:24-233635 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 03:08:58-184410 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 03:09:45-461662 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E
Jun 18 03:10:38-185800 cadet-p2p-28849 DEBUG DISCONNECTED ZGV0 <= WX7E
Jun 18 03:11:54-575097 cadet-p2p-28849 INFO CONNECTED ZGV0 <= WX7E

Both laptop and pc only ever have the one connection to each other, never connect to other peers. If I keep the connection busy (one ping message per second) the problem does *STILL* happen. At least CADET nicely resumes traffic delivery after the connection is back up :)


With such unstable connections it's really annoying to run tests :(

In case it's relevant, I'm behind three NATs (my AP, my home router and mnet's IPv4 tunnel NAT), but it doesn't seem to affect any other programs (web, ssh (even idle)).
TagsNo tags attached.

Relationships

parent of 0003669 closedChristian Grothoff GNUnet Assertion failed at ats_api_scheduling.c:716. 
parent of 0003672 closedChristian Grothoff GNUnet ATS testcases FTBFS 
parent of 0003666 closedChristian Grothoff GNUnet Revision 35208, transport-11501 ERROR Assertion failed at gnunet-service-transport_ats.c:580. 
parent of 0003658 closedChristian Grothoff GNUnet ATS testcases should be reviewed 
parent of 0003683 closedChristian Grothoff GNUnet peers fail to respond to PING 
parent of 0003692 closedChristian Grothoff GNUnet UDP connections do not last 
related to 0003424 closedMatthias Wachs gnunet-gtk Revision 33497: All connections to my peer 10.0.2.2 are gone. 

Activities

Christian Grothoff

2014-06-18 10:21

manager   ~0008451

As far as I know & see (and I am experiencing the same issue), this all goes back to transport being really bad right now.

Matthias Wachs

2014-06-30 09:07

manager   ~0008482

Connected for the whole weekend:

mwachs@fulcrum:~/coding/gnunet$ gnunet-core
Mon Jun 30 08:59:38 2014: connection established 8RW1 (timeout in 299 s)
Mon Jun 30 08:59:38 2014: connection established 668D (timeout in 299 s)
Mon Jun 30 08:59:38 2014: connection established 4YCN (timeout in 298 s)
mwachs@fulcrum:~/coding/gnunet$

4CYN is a nat'ed peer ...

Matthias Wachs

2014-06-30 09:20

manager   ~0008483

Can you provide more information:

- Syste
- Transport plugins
- NAT configuration

Bart Polot

2014-06-30 11:11

manager   ~0008485

WX7E is my workstation, so it has an up to date linux setup with a public IP and no NAT.

As I reported, ZGV0 is behind a triple NAT, but that doesn't bother ssh, for example. It also has the latest linux kernel and system libs.

I haven't changed the transport plugins, so both tcp and udp are active. Both are used, according to gnunet-transport -i. I haven't noticed if only one of them has this unstable behavior or it's both of them.

BTW, I see the same problem inside a LAN, too. Peers stay in "key sent" core starte for long periods of time and/or connect and disconnect randomly.

Bart Polot

2014-07-07 18:35

manager   ~0008509

Seems to be back with r33938.

Jul 07 18:21:15-066631 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:21:17-757620 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN
Jul 07 18:23:21-673741 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:23:24-858240 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN
Jul 07 18:25:28-781872 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:25:30-469789 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN
Jul 07 18:27:34-384823 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:27:36-568357 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN
Jul 07 18:29:40-499832 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:29:41-929261 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN
Jul 07 18:31:47-658370 cadet-p2p-18435 INFO DISCONNECTED VYGR <= STRN
Jul 07 18:31:49-599949 cadet-p2p-18435 INFO CONNECTED VYGR <= STRN

Bart Polot

2014-07-07 18:36

manager   ~0008510

Last edited: 2014-07-07 18:38

View 2 revisions

Btw, note that now it reconnects after 2 seconds, not ~ 2 minutes like before.

Bart Polot

2014-07-25 04:34

manager   ~0008534

Still happens as of r34044:

Jul 24 21:16:12-489369 cadet-p2p-920 INFO DISCONNECTED VYGR <= H3X4
Jul 24 21:16:21-792436 cadet-p2p-920 INFO CONNECTED VYGR <= H3X4

Jul 25 04:19:49-582580 cadet-p2p-920 INFO DISCONNECTED VYGR <= STRN
Jul 25 04:21:14-796986 cadet-p2p-920 INFO CONNECTED VYGR <= STRN

Seems to be less frequent, although yesterday I observed regular disconnections between two machines on my own LAN for a couple hours every few minutes.

Bart Polot

2014-07-25 12:49

manager   ~0008535

Might be related:
Jul 25 13:42:28-221593 transport-22907 WARNING External protocol violation detected at gnunet-service-transport.c:455.

Christian Grothoff

2015-02-28 18:33

manager   ~0008948

By and large this seems fixed (with related ATS, transport and CORE issues).

Issue History

Date Modified Username Field Change
2014-06-18 03:41 Bart Polot New Issue
2014-06-18 03:41 Bart Polot Status new => assigned
2014-06-18 03:41 Bart Polot Assigned To => Christian Grothoff
2014-06-18 10:21 Christian Grothoff Assigned To Christian Grothoff => Matthias Wachs
2014-06-18 10:21 Christian Grothoff Note Added: 0008451
2014-06-18 10:22 Christian Grothoff Priority high => immediate
2014-06-18 10:22 Christian Grothoff Category core service => transport service
2014-06-18 10:22 Christian Grothoff Relationship added related to 0003424
2014-06-30 09:07 Matthias Wachs Note Added: 0008482
2014-06-30 09:20 Matthias Wachs Note Added: 0008483
2014-06-30 11:11 Bart Polot Note Added: 0008485
2014-07-07 18:35 Bart Polot Note Added: 0008509
2014-07-07 18:36 Bart Polot Note Added: 0008510
2014-07-07 18:38 Bart Polot Note Edited: 0008510 View Revisions
2014-07-25 04:34 Bart Polot Note Added: 0008534
2014-07-25 12:49 Bart Polot Note Added: 0008535
2015-02-10 12:39 Christian Grothoff Assigned To Matthias Wachs => Christian Grothoff
2015-02-11 00:31 Christian Grothoff Relationship added parent of 0003669
2015-02-11 00:31 Christian Grothoff Relationship added parent of 0003672
2015-02-11 00:32 Christian Grothoff Relationship added parent of 0003666
2015-02-11 00:32 Christian Grothoff Relationship added parent of 0003651
2015-02-11 00:32 Christian Grothoff Relationship added parent of 0003658
2015-02-12 20:58 Christian Grothoff Relationship added parent of 0003683
2015-02-28 15:43 Christian Grothoff Relationship added parent of 0003652
2015-02-28 15:45 Christian Grothoff Relationship added parent of 0003692
2015-02-28 18:32 Christian Grothoff Relationship deleted parent of 0003652
2015-02-28 18:32 Christian Grothoff Relationship deleted parent of 0003651
2015-02-28 18:33 Christian Grothoff Note Added: 0008948
2015-02-28 18:33 Christian Grothoff Status assigned => resolved
2015-02-28 18:33 Christian Grothoff Fixed in Version => 0.11.0pre66
2015-02-28 18:33 Christian Grothoff Resolution open => fixed
2018-06-07 00:25 Christian Grothoff Status resolved => closed