View Issue Details

IDProjectCategoryView StatusLast Update
0003405GNUnetcadet servicepublic2018-06-07 00:25
ReporterellAssigned ToBart Polot 
PrioritynormalSeverityminorReproducibilityhave not tried
Status closedResolutionfixed 
Platformnat vboxOSXubuntu-14.04-64amdOS Version
Product VersionSVN HEAD 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0003405: Revision 33231: cadet susceptible to dynamic IP-change
DescriptionRevision 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.
TagsNo tags attached.

Relationships

has duplicate 0003422 closedBart Polot many mesh/cadet assertions when running conversation link 
has duplicate 0003459 closedBart Polot Errors after restarting peer 

Activities

ell

2014-05-16 11:47

reporter   ~0008350

Last edited: 2014-05-16 11:48

View 2 revisions

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.
...

Bart Polot

2014-05-16 12:31

manager   ~0008351

I think I found the cause: CADET fails to create new connections under some circumstances. I'll look into it, thanks!

Bart Polot

2014-06-17 14:21

manager   ~0008435

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.

ell

2014-06-17 19:35

reporter   ~0008442

Last edited: 2014-06-20 16:44

View 7 revisions

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.

ell

2014-06-23 21:26

reporter   ~0008461

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

ell

2014-06-23 21:36

reporter   ~0008462

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

Bart Polot

2014-06-24 04:46

manager   ~0008463

Can you please check if the tunnel.c:1217 assertion has been solved in versions > r33819?

ell

2014-06-24 16:28

reporter   ~0008465

"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

Bart Polot

2014-06-24 16:59

manager   ~0008466

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.

Issue History

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 View Revisions
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 View Revisions
2014-06-20 16:06 ell Note Edited: 0008442 View Revisions
2014-06-20 16:13 ell Note Edited: 0008442 View Revisions
2014-06-20 16:14 ell Note Edited: 0008442 View Revisions
2014-06-20 16:19 ell Note Edited: 0008442 View Revisions
2014-06-20 16:44 ell Note Edited: 0008442 View Revisions
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 => SVN HEAD
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 SVN HEAD => 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