View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0003405 | GNUnet | cadet service | public | 2014-05-10 16:08 | 2018-06-07 00:25 |
| Reporter | ell | Assigned To | Bart Polot | ||
| Priority | normal | Severity | minor | Reproducibility | have not tried |
| Status | closed | Resolution | fixed | ||
| Platform | nat vbox | OS | Xubuntu-14.04-64amd | ||
| Product Version | Git master | ||||
| Target Version | 0.11.0pre66 | Fixed in Version | 0.11.0pre66 | ||
| Summary | 0003405: Revision 33231: cadet susceptible to dynamic IP-change | ||||
| Description | Revision 33231: When T-COM changes my IP-address this triggers a lot of ... May 10 15:23:21-465993 cadet-9003 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:990. May 10 15:23:21-467118 cadet-9003 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:990. May 10 15:23:26-467729 cadet-9003 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:990. May 10 15:23:26-468328 cadet-9003 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:990. ... and seems not to stop. Only a gnunet-arm -e and gnunet-arm -c /etc/gnunet-conf -s helps. | ||||
| Tags | No tags attached. | ||||
| has duplicate | 0003422 | closed | Bart Polot | many mesh/cadet assertions when running conversation link |
| has duplicate | 0003459 | closed | Bart Polot | Errors after restarting peer |
|
|
Revision 33304: when dynamic IP changes, "ats-8059 ERROR" starts and seems to mark the beginning of a loop. ... May 16 11:32:24-878288 cadet-tun-2655 WARNING malformed PING on SAJL May 16 11:32:25-011363 cadet-tun-2655 WARNING malformed PING on KNGC May 16 11:33:13-126084 ats-8059 WARNING Trying to set unknown address `1J0Q' `udp' `6' to NO May 16 11:33:13-126339 ats-8059 ERROR Assertion failed at gnunet-service-ats_addresses.c:1190. May 16 11:33:13-126371 ats-8059 ERROR Assertion failed at gnunet-service-ats_scheduling.c:411. May 16 11:33:29-967457 cadet-2655 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1136. May 16 11:33:29-967860 cadet-2655 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1136. May 16 11:33:34-973205 cadet-2655 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1136. May 16 11:33:34-974172 cadet-2655 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1136. ... |
|
|
I think I found the cause: CADET fails to create new connections under some circumstances. I'll look into it, thanks! |
|
|
If this happens again (now it's on line 1217) please include the debug information that will follow the Assertion notice. Can't reproduce on my system, but I don't have any reason to believe it has been fixed by other changes. |
|
|
I will look for that. But needs some time, because normally my dynamic IP only changes one-time a day. Well, I got something, hope that helps: un 20 15:55:51-705185 cadet-20356 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1217. Jun 20 15:55:51-705267 cadet-tun-20356 WARNING TTT DEBUG TUNNEL TOWARDS MJTE Jun 20 15:55:51-705311 cadet-tun-20356 WARNING TTT cstate CADET_TUNNEL_WAITING, estate CADET_TUNNEL_KEY_PING Jun 20 15:55:51-705355 cadet-tun-20356 WARNING TTT kx_ctx 0x7ff3db268850, rekey_task 0 Jun 20 15:55:51-705397 cadet-tun-20356 WARNING TTT tq_head 0x7ff3db2685c0, tq_tail 0x7ff3db268420 Jun 20 15:55:51-705439 cadet-tun-20356 WARNING TTT destroy 0 Jun 20 15:55:51-705480 cadet-tun-20356 WARNING TTT channels: Jun 20 15:55:51-705522 cadet-tun-20356 WARNING TTT connections: Jun 20 15:55:51-705563 cadet-tun-20356 WARNING TTT DEBUG TUNNEL END Jun 20 15:55:51-706176 cadet-20356 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1217. Jun 20 15:55:51-706228 cadet-tun-20356 WARNING TTT DEBUG TUNNEL TOWARDS MJTE Jun 20 15:55:51-706270 cadet-tun-20356 WARNING TTT cstate CADET_TUNNEL_WAITING, estate CADET_TUNNEL_KEY_PING Jun 20 15:55:51-706311 cadet-tun-20356 WARNING TTT kx_ctx 0x7ff3db268850, rekey_task 0 Jun 20 15:55:51-706352 cadet-tun-20356 WARNING TTT tq_head 0x7ff3db2685c0, tq_tail 0x7ff3db268420 Jun 20 15:55:51-706393 cadet-tun-20356 WARNING TTT destroy 0 Jun 20 15:55:51-706477 cadet-tun-20356 WARNING TTT channels: Jun 20 15:55:51-706540 cadet-tun-20356 WARNING TTT connections: Jun 20 15:55:51-706595 cadet-tun-20356 WARNING TTT DEBUG TUNNEL END .... Seems to be looping, every 5 sec. ... Restarting with gnunet-arm -e gnunet-arm -c /etc/gnunet.conf -s makes disappear the loop. (Only the well-known Jun 20 16:42:17-819380 cadet-tun-22479 WARNING malformed PING on MJTE message loops) Revision 33738. |
|
|
Revision 33795: Jun 23 21:23:39-481446 cadet-tun-22358 WARNING TTT DEBUG TUNNEL TOWARDS EK26 Jun 23 21:23:39-481475 cadet-tun-22358 WARNING TTT cstate CADET_TUNNEL_WAITING, estate CADET_TUNNEL_KEY_PING Jun 23 21:23:39-481504 cadet-tun-22358 WARNING TTT kx_ctx 0x7fbce8ff5620, rekey_task 0 Jun 23 21:23:39-481533 cadet-tun-22358 WARNING TTT tq_head 0x7fbce8ff4f60, tq_tail 0x7fbce8fdc410 Jun 23 21:23:39-481562 cadet-tun-22358 WARNING TTT destroy 0 Jun 23 21:23:39-481591 cadet-tun-22358 WARNING TTT channels: Jun 23 21:23:39-481621 cadet-tun-22358 WARNING TTT - EK26:19 gid:40000001 (80000001 / 0) Jun 23 21:23:39-481650 cadet-tun-22358 WARNING TTT connections: Jun 23 21:23:39-481678 cadet-tun-22358 WARNING TTT DEBUG TUNNEL END |
|
|
Revision 33798: Jun 23 21:34:35-618814 cadet-885 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:1217. Jun 23 21:34:35-618966 cadet-tun-885 WARNING TTT DEBUG TUNNEL TOWARDS 4YCN Jun 23 21:34:35-618999 cadet-tun-885 WARNING TTT cstate CADET_TUNNEL_WAITING, estate CADET_TUNNEL_KEY_SENT Jun 23 21:34:35-619029 cadet-tun-885 WARNING TTT kx_ctx 0x7f840bb45c00, rekey_task 0 Jun 23 21:34:35-619059 cadet-tun-885 WARNING TTT tq_head (nil), tq_tail (nil) Jun 23 21:34:35-619088 cadet-tun-885 WARNING TTT destroy 0 Jun 23 21:34:35-619117 cadet-tun-885 WARNING TTT channels: Jun 23 21:34:35-619146 cadet-tun-885 WARNING TTT connections: Jun 23 21:34:35-619179 cadet-tun-885 WARNING TTT DEBUG TUNNEL END Jun 23 21:34:35-970947 cadet-tun-885 WARNING malformed PING on 7WSQ Jun |
|
|
Can you please check if the tunnel.c:1217 assertion has been solved in versions > r33819? |
|
|
"tunnel.c:1217 assertion" not seen anymore in Revision 33829. A dynamical change of IP did not trigger this error again. Some warnings pop up during IP-change: un 24 15:58:51-561671 cadet-p2p-28715 WARNING PPP DEBUG PEER VMTV Jun 24 15:58:51-561783 cadet-p2p-28715 WARNING PPP last contact Tue Jun 24 15:57:53 2014 Jun 24 15:58:51-561866 cadet-p2p-28715 WARNING PPP core transmit handle (nil) Jun 24 15:58:51-561952 cadet-p2p-28715 WARNING PPP DHT GET handle 0x7f124f6dff60 Jun 24 15:58:51-562040 cadet-p2p-28715 WARNING PPP # connections over link to peer: 0 Jun 24 15:58:51-562126 cadet-p2p-28715 WARNING QQQ Message queue towards VMTV Jun 24 15:58:51-562216 cadet-p2p-28715 WARNING QQQ queue length: 0 Jun 24 15:58:51-562303 cadet-p2p-28715 WARNING QQQ core tmt rdy: (nil) Jun 24 15:58:51-562390 cadet-p2p-28715 WARNING QQQ End queue towards VMTV Jun 24 15:58:51-562620 cadet-p2p-28715 WARNING PPP DEBUG END Jun 24 15:58:51-563637 cadet-tun-28715 WARNING sending { KX_PING} Jun 24 15:58:51-563734 cadet-tun-28715 WARNING TTT DEBUG TUNNEL TOWARDS VMTV Jun 24 15:58:51-563874 cadet-tun-28715 WARNING TTT cstate CADET_TUNNEL_SEARCHING, estate CADET_TUNNEL_KEY_PING Jun 24 15:58:51-563963 cadet-tun-28715 WARNING TTT kx_ctx 0x7f124f6eb1b0, rekey_task 0 Jun 24 15:58:51-564048 cadet-tun-28715 WARNING TTT tq_head 0x7f124f6dee60, tq_tail 0x7f124f6dc440 Jun 24 15:58:51-564133 cadet-tun-28715 WARNING TTT destroy 46452 Jun 24 15:58:51-564221 cadet-tun-28715 WARNING TTT channels: Jun 24 15:58:51-564306 cadet-tun-28715 WARNING TTT connections: Jun 24 15:58:51-564385 cadet-tun-28715 WARNING TTT DEBUG TUNNEL END Jun 24 15:58:51-564471 cadet-p2p-28715 WARNING PPP DEBUG PEER VMTV Jun 24 15:58:51-564578 cadet-p2p-28715 WARNING PPP last contact Tue Jun 24 15:57:53 2014 Jun 24 15:58:51-564661 cadet-p2p-28715 WARNING PPP core transmit handle (nil) Jun 24 15:58:51-564743 cadet-p2p-28715 WARNING PPP DHT GET handle 0x7f124f6dff60 Jun 24 15:58:51-564830 cadet-p2p-28715 WARNING PPP # connections over link to peer: 0 Jun 24 15:58:51-564919 cadet-p2p-28715 WARNING QQQ Message queue towards VMTV Jun 24 15:58:51-564997 cadet-p2p-28715 WARNING QQQ queue length: 0 Jun 24 15:58:51-565078 cadet-p2p-28715 WARNING QQQ core tmt rdy: (nil) Jun 24 15:58:51-565159 cadet-p2p-28715 WARNING QQQ End queue towards VMTV Jun 24 15:58:51-565243 cadet-p2p-28715 WARNING PPP DEBUG END Jun 24 16:20:49-316973 cadet-chn-28715 WARNING MID 0 not expected (1 - 64), dropping! Jun 24 16:20:53-595815 cadet-chn-28715 WARNING MID 0 not expected (1 - 64), dropping! Jun 24 16:21:00-864576 cadet-chn-28715 WARNING MID 1 not expected (2 - 65), dropping! Jun 24 16:21:05-989414 cadet-chn-28715 WARNING MID 1 not expected (2 - 65), dropping! Jun 24 16:21:11-057722 cadet-chn-28715 WARNING MID 1 not expected (2 - 65), dropping! Jun 24 16:21:16-312500 cadet-chn-28715 WARNING MID 1 not expected (2 - 65), dropping! Jun 24 16:21:21-428839 cadet-chn-28715 WARNING MID 1 not expected (2 - 65), dropping! J |
|
|
The WARNING PPP, QQQ and TTT messages are leftovers debug messages, they have been re-classified as DEBUG level in r33832. The situation is that an existing connection is broken when your IP changes and it cannot be build again, probably due to 0003448. The MID warnings are unrelated, they are just duplicated traffic, might also be related to 0003448 (could cause ACKs to get lost). I have included more verbose messages in r33833. Feel free to file a new bug if you see many of those. |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2014-05-10 16:08 | ell | New Issue | |
| 2014-05-10 16:08 | ell | Status | new => assigned |
| 2014-05-10 16:08 | ell | Assigned To | => Bart Polot |
| 2014-05-16 11:47 | ell | Note Added: 0008350 | |
| 2014-05-16 11:48 | ell | Note Edited: 0008350 | |
| 2014-05-16 12:31 | Bart Polot | Note Added: 0008351 | |
| 2014-05-16 12:32 | Bart Polot | Status | assigned => acknowledged |
| 2014-06-08 14:11 | Christian Grothoff | Target Version | => 0.11.0pre66 |
| 2014-06-17 14:21 | Bart Polot | Note Added: 0008435 | |
| 2014-06-17 14:21 | Bart Polot | Status | acknowledged => feedback |
| 2014-06-17 14:31 | Bart Polot | Relationship added | has duplicate 0003422 |
| 2014-06-17 19:35 | ell | Note Added: 0008442 | |
| 2014-06-17 19:35 | ell | Status | feedback => assigned |
| 2014-06-20 15:58 | ell | Note Edited: 0008442 | |
| 2014-06-20 16:06 | ell | Note Edited: 0008442 | |
| 2014-06-20 16:13 | ell | Note Edited: 0008442 | |
| 2014-06-20 16:14 | ell | Note Edited: 0008442 | |
| 2014-06-20 16:19 | ell | Note Edited: 0008442 | |
| 2014-06-20 16:44 | ell | Note Edited: 0008442 | |
| 2014-06-23 21:26 | ell | Note Added: 0008461 | |
| 2014-06-23 21:36 | ell | Note Added: 0008462 | |
| 2014-06-24 04:46 | Bart Polot | Note Added: 0008463 | |
| 2014-06-24 04:46 | Bart Polot | Status | assigned => resolved |
| 2014-06-24 04:46 | Bart Polot | Fixed in Version | => Git master |
| 2014-06-24 04:46 | Bart Polot | Resolution | open => fixed |
| 2014-06-24 16:28 | ell | Note Added: 0008465 | |
| 2014-06-24 16:28 | ell | Status | resolved => feedback |
| 2014-06-24 16:28 | ell | Resolution | fixed => reopened |
| 2014-06-24 16:59 | Bart Polot | Note Added: 0008466 | |
| 2014-06-24 16:59 | Bart Polot | Status | feedback => resolved |
| 2014-06-24 16:59 | Bart Polot | Resolution | reopened => fixed |
| 2014-06-27 21:57 | Christian Grothoff | Fixed in Version | Git master => 0.11.0pre66 |
| 2014-06-30 16:20 | Bart Polot | Relationship added | has duplicate 0003459 |
| 2018-06-07 00:25 | Christian Grothoff | Status | resolved => closed |
