View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0003448 | GNUnet | transport service | public | 2014-06-18 03:41 | 2018-06-07 00:25 |
| Reporter | Bart Polot | Assigned To | Christian Grothoff | ||
| Priority | immediate | Severity | major | Reproducibility | always |
| Status | closed | Resolution | fixed | ||
| Product Version | Git master | ||||
| Target Version | 0.11.0pre66 | Fixed in Version | 0.11.0pre66 | ||
| Summary | 0003448: Core-level (transport? ats?) connectivity problems | ||||
| Description | Scenario: 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)). | ||||
| Tags | No tags attached. | ||||
| parent of | 0003669 | closed | Christian Grothoff | GNUnet | Assertion failed at ats_api_scheduling.c:716. |
| parent of | 0003672 | closed | Christian Grothoff | GNUnet | ATS testcases FTBFS |
| parent of | 0003666 | closed | Christian Grothoff | GNUnet | Revision 35208, transport-11501 ERROR Assertion failed at gnunet-service-transport_ats.c:580. |
| parent of | 0003658 | closed | Christian Grothoff | GNUnet | ATS testcases should be reviewed |
| parent of | 0003683 | closed | Christian Grothoff | GNUnet | peers fail to respond to PING |
| parent of | 0003692 | closed | Christian Grothoff | GNUnet | UDP connections do not last |
| related to | 0003424 | closed | Matthias Wachs | gnunet-gtk | Revision 33497: All connections to my peer 10.0.2.2 are gone. |
|
|
As far as I know & see (and I am experiencing the same issue), this all goes back to transport being really bad right now. |
|
|
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 ... |
|
|
Can you provide more information: - Syste - Transport plugins - NAT configuration |
|
|
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. |
|
|
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 |
|
|
Btw, note that now it reconnects after 2 seconds, not ~ 2 minutes like before. |
|
|
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. |
|
|
Might be related: Jul 25 13:42:28-221593 transport-22907 WARNING External protocol violation detected at gnunet-service-transport.c:455. |
|
|
By and large this seems fixed (with related ATS, transport and CORE issues). |
| 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 | |
| 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 |
