View Issue Details

IDProjectCategoryView StatusLast Update
0003393GNUnetcadet servicepublic2018-06-07 00:25
ReporterellAssigned ToBart Polot 
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
Platformnat vbox on dynamic IPOSXubuntu-14.04-64amdOS Version
Product VersionSVN HEAD 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0003393: performing PING-loop until killed..
DescriptionObserved in svn-Revision-33159 and previous, starting
gnunet-arm -c /etc/gnunet.conf -s
as user gnunet
and then wait some hours, in my case 0000009:0000004 hours.
Steps To Reproducegnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 03 09:02:25-516641 mesh-chn-2474 WARNING MID 0 not expected (1 - 64), dropping!
May 03 09:02:25-539078 mesh-chn-2474 WARNING MID 0 not expected (1 -64), dropping!
May 03 09:02:41-661442 mesh-chn-2474 WARNING MID 0 not expected (1 -64), dropping!
May 03 09:03:25-243114 transport-2479 ERROR Trying to transmit ACK to peer `100.43.116.216:2086' but not session found!
May 03 09:03:55-187351 transport-2479 ERROR Trying to transmit ACK to peer `100.43.116.216:2086' but not session found!
May 03 09:05:25-369363 transport-2479 ERROR Trying to transmit ACK to peer `100.43.116.216:2086' but not session found!
May 03 09:06:58-471828 mesh-2474 ERROR Assertion failed at gnunet-service-mesh_connection.c:2820.
May 03 09:06:59-580177 mesh-2474 ERROR Assertion failed at gnunet-service-mesh_connection.c:2820.
May 03 09:06:59-580520 mesh-2474 ERROR Assertion failed at gnunet-service-mesh_connection.c:614.
May 03 09:06:59-580801 mesh-con-2474 ERROR Message { ENCRYPTED} sent on NULL connection!
May 03 09:34:25-350701 transport-2479 ERROR Trying to transmit ACK to peer `100.43.116.216:2086' but not session found!
May 03 09:36:55-275977 transport-2479 ERROR Trying to transmit ACK to peer `100.43.116.216:2086' but not session found!
May 03 10:20:55-270897 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
May 03 10:21:25-255442 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
May 03 10:23:55-329101 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
...
May 03 12:06:25-606721 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
May 03 12:10:55-581271 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
May 03 12:14:55-602462 transport-2479 ERROR Trying to transmit ACK to peer `138.246.2.199:2086' but not session found!
May 03 12:49:51-788932 mesh-tun-2474 WARNING malformed PING
May 03 12:49:56-763964 mesh-tun-2474 WARNING malformed PING
...
Here we got a good performing PING-loop until killed...
...
May 03 13:49:08-362102 mesh-tun-2474 WARNING malformed PING
May 03 13:49:13-353204 mesh-tun-2474 WARNING malformed PING
May 03 13:49:18-366592 mesh-tun-2474 WARNING malformed PING
May 03 13:49:23-374326 mesh-tun-2474 WARNING malformed PING
gnunet@Xubu-14:~$ gnunet-arm -e
TagsNo tags attached.

Activities

ell

2014-05-03 21:11

reporter   ~0008277

The infinite loop can also be realized around the message:

ay 03 20:56:31-302550 mesh-3824 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 03 20:56:36-303677 mesh-3824 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 03 20:56:41-307956 mesh-3824 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.

Bart Polot

2014-05-05 12:48

reporter   ~0008279

Thanks for the report! I'll look into it, maybe add some more debug messages since seems that you can reproduce it :)

ell

2014-05-06 12:45

reporter   ~0008283

svn Revision 33170:

gnunet@Xubu-14:~$ gnunet-transport -c /etc/gnunet.conf -t
Configuration for plugin `tcp' did work!
Configuration for plugin `tcp' is working!
Configuration for plugin `udp' did work!
Configuration for plugin `udp' is working!
gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 06 10:25:31-730556 transport-12471 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 10:29:11-990137 transport-12471 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 10:30:05-115797 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 06 10:30:05-117048 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 06 10:30:10-119224 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 06 10:30:10-119991 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
....
Loop with 5-second period till killed
May 06 12:40:22-460661 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 06 12:40:27-466037 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.
May 06 12:40:27-466685 mesh-12468 ERROR Assertion failed at gnunet-service-mesh_tunnel.c:991.

ell

2014-05-06 13:33

reporter   ~0008284

Revision 33173

nunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 06 13:03:59-868547 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 13:04:29-174060 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 13:04:52-098426 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 13:05:29-125060 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 13:06:29-557882 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!
May 06 13:06:59-574488 transport-31188 ERROR Trying to transmit ACK to peer `178.27.37.173:2086' but not session found!

Till Di 6. Mai 13:27:53 CEST 2014 no more errors seens.
This revision seems to be a big step forward.

ell

2014-05-06 13:54

reporter   ~0008285

Last edited: 2014-05-06 15:25

View 4 revisions

But later on this comes (Rev. 33173):

gnunet@Xubu-14:~$ May 06 13:50:07-677680 transport-tcp-31188 ERROR Trying to print invalid `tcp' address with size 22
May 06 13:50:07-750784 transport-tcp-31188 ERROR Trying to print invalid `tcp' address with size 10
May 06 13:50:15-679587 transport-tcp-31188 ERROR Trying to print invalid `tcp' address with size 22

The traffic-statistic of gnunet-gtk indicates that all transport activity has stopped after the transport-tcp-31188 ERROR

Stopping and restarting now gives:

gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 06 14:24:23-284002 mesh-chn-32587 WARNING MID 0 not expected (1 - 64), dropping!
May 06 14:26:08-154531 transport-tcp-32590 ERROR Trying to print invalid `tcp' address with size 22
May 06 14:26:08-155443 transport-tcp-32590 ERROR Trying to print invalid `tcp' address with size 10

But now the the traffic-statistic of gnunet-gtk indicates ongoing transport
activity.

Observing nearly one hour, transport activity oozes away.

ell

2014-05-06 20:22

reporter   ~0008286

Last edited: 2014-05-06 20:39

View 2 revisions

And here again a PING-Loop caused by
Revision 33175

gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 06 18:12:48-288746 ats-proportional-12446 ERROR Using proportionality factor 4
May 06 18:14:42-542327 mesh-chn-12439 WARNING MID 0 not expected (1 - 64), dropping!
May 06 18:23:41-305473 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 18:23:41-306253 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 18:23:41-369563 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 18:23:41-369912 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 18:23:41-370518 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 19:06:20-215442 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 22
May 06 19:06:20-215512 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 19:36:44-847890 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 19:37:14-772915 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 19:39:11-927348 mesh-12439 WARNING External protocol violation detected at gnunet-service-mesh_connection.c:1995.
May 06 19:39:11-928755 mesh-con-12439 WARNING Received PID 1, (prev 4294967295), ACK 0
May 06 19:41:18-849402 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 22
May 06 19:41:18-920435 transport-tcp-12443 ERROR Trying to print invalid `tcp' address with size 10
May 06 19:45:44-538132 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:04:44-603343 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:06:44-534537 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:07:44-626915 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:08:14-536186 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:09:44-806028 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:11:12-613513 mesh-tun-12439 WARNING malformed PING
May 06 20:11:17-610554 mesh-tun-12439 WARNING malformed PING
May 06 20:11:22-605451 mesh-tun-12439 WARNING malformed PING
May 06 20:11:27-599083 mesh-tun-12439 WARNING malformed PING
May 06 20:11:32-616501 mesh-tun-12439 WARNING malformed PING
May 06 20:11:37-616950 mesh-tun-12439 WARNING malformed PING
May 06 20:11:42-630614 mesh-tun-12439 WARNING malformed PING
May 06 20:11:47-626394 mesh-tun-12439 WARNING malformed PING
May 06 20:11:52-639415 mesh-tun-12439 WARNING malformed PING
May 06 20:11:57-638616 mesh-tun-12439 WARNING malformed PING
May 06 20:12:02-636996 mesh-tun-12439 WARNING malformed PING
May 06 20:12:07-636229 mesh-tun-12439 WARNING malformed PING
May 06 20:12:12-640368 mesh-tun-12439 WARNING malformed PING
May 06 20:12:14-720323 transport-12443 ERROR Trying to transmit ACK to peer `177.99.60.170:8928' but not session found!
May 06 20:12:17-645544 mesh-tun-12439 WARNING malformed PING
May 06 20:12:22-654105 mesh-tun-12439 WARNING malformed PING
May 06 20:12:27-661720 mesh-tun-12439 WARNING malformed PING
May 06 20:12:32-670779 mesh-tun-12439 WARNING malformed PING
May 06 20:12:37-672293 mesh-tun-12439 WARNING malformed PING
May 06 20:12:42-690878 mesh-tun-12439 WARNING malformed PING
May 06 20:12:47-679622 mesh-tun-12439 WARNING malformed PING

Bart Polot

2014-05-07 13:03

reporter   ~0008292

Please try to reproduce with svn HEAD, the WARNING message has been update for verbosity.

ell

2014-05-07 14:42

reporter   ~0008293

Last edited: 2014-05-07 14:48

View 2 revisions

I did a complete svn checkout because svn up got me into makefile problems
Revision 33203:
Now I have a new sock-problem:

gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
May 07 14:32:02-303561 arm-12369 WARNING Unable to bind listening socket for service `cadet' to address `/tmp/gnunet-system-runtime//gnunet-service-mesh.sock': Address already in use
gnunet@Xubu-14:~$ May 07 14:33:21-496283 transport-tcp-12379 WARNING Received WELCOME message from my own identity `668D' on address `10.0.2.15:37742'
May 07 14:33:21-496464 transport-12379 WARNING External protocol violation detected at plugin_transport_tcp.c:2048.


gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 07 14:46:46-855577 arm-12684 WARNING Unable to bind listening socket for service `cadet' to address `/tmp/gnunet-system-runtime//gnunet-service-mesh.sock': Address already in use
May 07 14:46:55-796214 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:46:55-864990 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:46:56-368354 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:46:57-367786 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:46:59-370914 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:47:03-371459 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:47:11-374338 mesh-12690 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:47:16-751917 transport-tcp-12694 WARNING Received WELCOME message from my own identity `668D' on address `10.0.2.15:37785'
May 07 14:47:16-751963 transport-12694 WARNING External protocol violation detected at plugin_transport_tcp.c:2048.

Bart Polot

2014-05-07 14:43

reporter   ~0008294

OK, seems that I failed to rename the socket. Will fix ASAP.

Bart Polot

2014-05-07 14:47

reporter   ~0008295

The sock problem should be fixed in r33204 :)

ell

2014-05-07 14:53

reporter   ~0008296

Revision 33204:

gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 07 14:51:44-194920 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:44-196575 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:44-278757 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:44-280454 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:44-786111 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:44-786581 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:45-786734 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:45-787632 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:47-788927 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:47-789538 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:51-792289 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:51-793051 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:59-798108 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:51:59-799098 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:52:15-799762 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:52:15-800374 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:52:40-103064 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:52:45-105122 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:52:47-805800 cadet-22717 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:52:47-806686 mesh-22708 ERROR Failed checksum validation for a message on tunnel `SAJL'
May 07 14:52:50-106329 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:52:55-107372 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:53:00-108630 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:53:05-110901 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:53:10-111994 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.
May 07 14:53:15-113038 cadet-22717 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.

Bart Polot

2014-05-07 15:02

reporter   ~0008297

You have both cadet AND mesh running, it shouldn't happen. This isn't what is causing the errors, but a separate issue. Commit r33205 fixes it.

ell

2014-05-07 15:03

reporter   ~0008298

Maybe it is interesting:
gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ clearMay 07 15:00:41-456112 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:00:41-456269 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:00:41-457077 cadet-tun-23067 WARNING e got 106830969
May 07 15:00:41-457188 cadet-tun-23067 WARNING e towards 36EK
May 07 15:00:41-457291 cadet-tun-23067 WARNING got 3362737747
May 07 15:00:41-457392 cadet-tun-23067 WARNING towards H0BN
May 07 15:00:41-457641 mesh-tun-23058 WARNING e got 106830969
May 07 15:00:41-458532 mesh-tun-23058 WARNING e towards 36EK
May 07 15:00:41-458651 mesh-tun-23058 WARNING got 519334014
May 07 15:00:41-458753 mesh-tun-23058 WARNING towards M638
gnunet-arm -eMay 07 15:00:41-465653 cadet-tun-23067 WARNING Wrong PONG challenge
May 07 15:00:41-465964 cadet-23067 WARNING External protocol violation detected at gnunet-service-cadet_tunnel.c:1593.
May 07 15:00:46-381683 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:00:46-382119 cadet-tun-23067 WARNING e got 3429402955
May 07 15:00:46-382421 cadet-tun-23067 WARNING e towards KK85
May 07 15:00:46-382720 cadet-tun-23067 WARNING got 3007234852
May 07 15:00:46-383018 cadet-tun-23067 WARNING towards 0LP7
May 07 15:00:51-381428 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:00:51-381787 cadet-tun-23067 WARNING e got 423814975
May 07 15:00:51-382153 cadet-tun-23067 WARNING e towards D2RR
May 07 15:00:51-382349 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:00:51-382463 mesh-tun-23058 WARNING e got 423814975
May 07 15:00:51-382521 mesh-tun-23058 WARNING e towards D2RR
May 07 15:00:51-382575 mesh-tun-23058 WARNING got 4131410372
May 07 15:00:51-382628 mesh-tun-23058 WARNING towards BA5L
May 07 15:00:51-382760 cadet-tun-23067 WARNING got 389202376
May 07 15:00:51-382983 cadet-tun-23067 WARNING towards DMS2
May 07 15:00:56-391456 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:00:56-391603 mesh-tun-23058 WARNING e got 2125550624
May 07 15:00:56-391685 mesh-tun-23058 WARNING e towards GHLQ
May 07 15:00:56-391770 mesh-tun-23058 WARNING got 3821037979
May 07 15:00:56-391849 mesh-tun-23058 WARNING towards 87OS
May 07 15:00:56-393392 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:00:56-393520 cadet-tun-23067 WARNING e got 2125550624
May 07 15:00:56-393604 cadet-tun-23067 WARNING e towards GHLQ
May 07 15:00:56-393683 cadet-tun-23067 WARNING got 398705179
May 07 15:00:56-393763 cadet-tun-23067 WARNING towards 2AQ3
May 07 15:01:01-386419 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:01:01-386575 cadet-tun-23067 WARNING e got 822006467
May 07 15:01:01-386656 cadet-tun-23067 WARNING e towards VGN5
May 07 15:01:01-386733 cadet-tun-23067 WARNING got 3517939890
May 07 15:01:01-386849 cadet-tun-23067 WARNING towards Q8F7
May 07 15:01:01-388586 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:01:01-388715 mesh-tun-23058 WARNING e got 822006467
May 07 15:01:01-388799 mesh-tun-23058 WARNING e towards VGN5
May 07 15:01:01-388877 mesh-tun-23058 WARNING got 580260826
May 07 15:01:01-388956 mesh-tun-23058 WARNING towards 78TP
May 07 15:01:06-387029 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:01:06-387151 mesh-tun-23058 WARNING e got 3303178294
May 07 15:01:06-387211 mesh-tun-23058 WARNING e towards O416
May 07 15:01:06-387266 mesh-tun-23058 WARNING got 1097290487
May 07 15:01:06-387319 mesh-tun-23058 WARNING towards SUVR
May 07 15:01:06-387530 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:01:06-387602 cadet-tun-23067 WARNING e got 3303178294
May 07 15:01:06-387657 cadet-tun-23067 WARNING e towards O416
May 07 15:01:06-387712 cadet-tun-23067 WARNING got 3265799092
May 07 15:01:06-387772 cadet-tun-23067 WARNING towards L7MC
May 07 15:01:11-388515 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:01:11-388636 mesh-tun-23058 WARNING e got 2099313820
May 07 15:01:11-388697 mesh-tun-23058 WARNING e towards L9MS
May 07 15:01:11-388752 mesh-tun-23058 WARNING got 792339414
May 07 15:01:11-388805 mesh-tun-23058 WARNING towards TF5T
May 07 15:01:11-390465 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:01:11-390576 cadet-tun-23067 WARNING e got 2099313820
May 07 15:01:11-390636 cadet-tun-23067 WARNING e towards L9MS
May 07 15:01:11-390692 cadet-tun-23067 WARNING got 2459994660
May 07 15:01:11-390748 cadet-tun-23067 WARNING towards 9LCQ
May 07 15:01:16-390359 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:01:16-390665 cadet-tun-23067 WARNING e got 2674381120
May 07 15:01:16-390944 cadet-tun-23067 WARNING e towards L2QR
May 07 15:01:16-391232 cadet-tun-23067 WARNING got 2397669665
May 07 15:01:16-391521 cadet-tun-23067 WARNING towards 3U99
May 07 15:01:16-391596 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:01:16-391872 mesh-tun-23058 WARNING e got 2674381120
May 07 15:01:16-391934 mesh-tun-23058 WARNING e towards L2QR
May 07 15:01:16-391988 mesh-tun-23058 WARNING got 1390611748
May 07 15:01:16-392042 mesh-tun-23058 WARNING towards CIFM
May 07 15:01:21-400603 mesh-tun-23058 WARNING malformed PING on SAJL
May 07 15:01:21-401007 mesh-tun-23058 WARNING e got 435451063
May 07 15:01:21-401389 mesh-tun-23058 WARNING e towards 1F1B
May 07 15:01:21-401793 mesh-tun-23058 WARNING got 2414387962
May 07 15:01:21-402347 mesh-tun-23058 WARNING towards KJHA
May 07 15:01:21-402732 cadet-tun-23067 WARNING malformed PING on SAJL
May 07 15:01:21-402871 cadet-tun-23067 WARNING e got 435451063
May 07 15:01:21-402953 cadet-tun-23067 WARNING e towards 1F1B
May 07 15:01:21-403028 cadet-tun-23067 WARNING got 2421645787
May 07 15:01:21-403103 cadet-tun-23067 WARNING towards BAAJ
May 07 15:01:23-428905 cadet-23067 ERROR Assertion failed at gnunet-service-cadet_tunnel.c:991.

ell

2014-05-07 15:06

reporter   ~0008299

Revision 33205.
gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 07 15:04:55-911161 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:04:55-911682 cadet-tun-627 WARNING e got 517336705
May 07 15:04:55-911791 cadet-tun-627 WARNING e towards CRCR
May 07 15:04:55-911892 cadet-tun-627 WARNING got 3772551862
May 07 15:04:55-911996 cadet-tun-627 WARNING towards G6NL
May 07 15:05:00-869922 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:00-870234 cadet-tun-627 WARNING e got 1604948321
May 07 15:05:00-870516 cadet-tun-627 WARNING e towards 3ECF
May 07 15:05:00-871032 cadet-tun-627 WARNING got 1480180313
May 07 15:05:00-871313 cadet-tun-627 WARNING towards C35F
May 07 15:05:05-873966 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:05-875314 cadet-tun-627 WARNING e got 1935027977
May 07 15:05:05-875515 cadet-tun-627 WARNING e towards 8QQ3
May 07 15:05:05-875573 cadet-tun-627 WARNING got 768496935
May 07 15:05:05-875765 cadet-tun-627 WARNING towards TL3K
May 07 15:05:10-877943 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:10-878069 cadet-tun-627 WARNING e got 3762762439
May 07 15:05:10-878132 cadet-tun-627 WARNING e towards 6BA7
May 07 15:05:10-878190 cadet-tun-627 WARNING got 1562277552
May 07 15:05:10-878247 cadet-tun-627 WARNING towards OQIS
May 07 15:05:15-933679 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:15-937197 cadet-tun-627 WARNING e got 1509064352
May 07 15:05:15-938247 cadet-tun-627 WARNING e towards HJ66
May 07 15:05:15-938681 cadet-tun-627 WARNING got 1383774760
May 07 15:05:15-939565 cadet-tun-627 WARNING towards N5VU
May 07 15:05:20-872540 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:20-872662 cadet-tun-627 WARNING e got 836609275
May 07 15:05:20-872725 cadet-tun-627 WARNING e towards AVUL
May 07 15:05:20-872781 cadet-tun-627 WARNING got 1587990986
May 07 15:05:20-872838 cadet-tun-627 WARNING towards 8DVF
May 07 15:05:25-885169 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:25-885626 cadet-tun-627 WARNING e got 1956411973
May 07 15:05:25-886908 cadet-tun-627 WARNING e towards BCRQ
May 07 15:05:25-887200 cadet-tun-627 WARNING got 2814040020
May 07 15:05:25-887507 cadet-tun-627 WARNING towards P9ON
May 07 15:05:30-881179 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:30-881551 cadet-tun-627 WARNING e got 3297829916
May 07 15:05:30-881958 cadet-tun-627 WARNING e towards KI8S
May 07 15:05:30-882282 cadet-tun-627 WARNING got 3159114730
May 07 15:05:30-882600 cadet-tun-627 WARNING towards 6Q6H
May 07 15:05:35-891812 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:35-891975 cadet-tun-627 WARNING e got 941835923
May 07 15:05:35-892058 cadet-tun-627 WARNING e towards J7UQ
May 07 15:05:35-892135 cadet-tun-627 WARNING got 1655459760
May 07 15:05:35-892214 cadet-tun-627 WARNING towards 4FLV
May 07 15:05:40-890052 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:40-890177 cadet-tun-627 WARNING e got 29111482
May 07 15:05:40-890237 cadet-tun-627 WARNING e towards B88R
May 07 15:05:40-890293 cadet-tun-627 WARNING got 2489085908
May 07 15:05:40-890347 cadet-tun-627 WARNING towards Q2PJ
May 07 15:05:45-898441 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:45-898568 cadet-tun-627 WARNING e got 892349824
May 07 15:05:45-898630 cadet-tun-627 WARNING e towards 4IUS
May 07 15:05:45-898684 cadet-tun-627 WARNING got 1431796345
May 07 15:05:45-898739 cadet-tun-627 WARNING towards 0J86
May 07 15:05:50-900436 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:50-900751 cadet-tun-627 WARNING e got 1499734615
May 07 15:05:50-901031 cadet-tun-627 WARNING e towards 1F4P
May 07 15:05:50-901308 cadet-tun-627 WARNING got 1544930094
May 07 15:05:50-901585 cadet-tun-627 WARNING towards RRF5
May 07 15:05:55-895282 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:05:55-895606 cadet-tun-627 WARNING e got 1902954035
May 07 15:05:55-895887 cadet-tun-627 WARNING e towards VFLU
May 07 15:05:55-896283 cadet-tun-627 WARNING got 677248280
May 07 15:05:55-896563 cadet-tun-627 WARNING towards 9JB9
May 07 15:06:00-911974 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:06:00-912298 cadet-tun-627 WARNING e got 1297567026
May 07 15:06:00-912582 cadet-tun-627 WARNING e towards AAS4
May 07 15:06:00-913067 cadet-tun-627 WARNING got 1029616188
May 07 15:06:00-913350 cadet-tun-627 WARNING towards 4BM3
May 07 15:06:05-921204 cadet-tun-627 WARNING malformed PING on SAJL
May 07 15:06:05-921531 cadet-tun-627 WARNING e got 1782604698
May 07 15:06:05-921809 cadet-tun-627 WARNING e towards MP51
May 07 15:06:05-922156 cadet-tun-627 WARNING got 3795410628
May 07 15:06:05-922434 cadet-tun-627 WARNING towards K4GM

Bart Polot

2014-05-07 15:09

reporter   ~0008300

Seems clear to me now that both peers don't agree on the encryption keys to use. The errors by PING PONG are a good indicator.

BTW, what is your peer ID? (gnunet-peerinfo -s)

ell

2014-05-07 15:15

reporter   ~0008301

Multiuser environment:

1.) gnunet@Xubu-14:~$ gnunet-peerinfo -s
I am peer `668DK7QUCG4E1ITNK1JNACHNPOG9CBBR1U03A0NFR5PSMQHJCDMG'.

2.) ell@Xubu-14:~/gnunet$ gnunet-peerinfo -s
I am peer `ABU7AB0NUTE6JCK64UU0R5IJTUBF36GH6GQHQO344A0HVQRVN0O0'.

Bart Polot

2014-05-07 15:17

reporter   ~0008302

Ok, I changed a relevant behavior in r33206, please check again!

ell

2014-05-07 15:21

reporter   ~0008303

R 33206:
gnunet@Xubu-14:~$ gnunet-arm -c /etc/gnunet.conf -s
gnunet@Xubu-14:~$ May 07 15:19:56-353537 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:19:56-361216 cadet-tun-11408 WARNING e got 2277315319
May 07 15:19:56-361286 cadet-tun-11408 WARNING e towards NR2K
May 07 15:19:56-361340 cadet-tun-11408 WARNING got 265780467
May 07 15:19:56-361394 cadet-tun-11408 WARNING towards SC8R
May 07 15:20:01-280978 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:20:01-283924 cadet-tun-11408 WARNING e got 206347900
May 07 15:20:01-284223 cadet-tun-11408 WARNING e towards QH5G
May 07 15:20:01-284499 cadet-tun-11408 WARNING got 1317958461
May 07 15:20:01-284777 cadet-tun-11408 WARNING towards 5CRJ
May 07 15:20:06-280882 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:20:06-282337 cadet-tun-11408 WARNING e got 3050112254
May 07 15:20:06-282621 cadet-tun-11408 WARNING e towards TFJU
May 07 15:20:06-282898 cadet-tun-11408 WARNING got 2154870373
May 07 15:20:06-283175 cadet-tun-11408 WARNING towards OGL1
May 07 15:20:11-278765 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:20:11-278895 cadet-tun-11408 WARNING e got 406702863
May 07 15:20:11-278956 cadet-tun-11408 WARNING e towards CMD7
May 07 15:20:11-279011 cadet-tun-11408 WARNING got 1811048796
May 07 15:20:11-279065 cadet-tun-11408 WARNING towards KDNF

ell

2014-05-07 15:26

reporter   ~0008304

Maybe of interest:

....
y 07 15:25:06-439444 cadet-tun-11408 WARNING e got 638930960
May 07 15:25:06-439529 cadet-tun-11408 WARNING e towards 96MR
May 07 15:25:06-439608 cadet-tun-11408 WARNING got 2271644808
May 07 15:25:06-439688 cadet-tun-11408 WARNING towards LQT3
May 07 15:25:11-434916 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:25:11-435020 cadet-tun-11408 WARNING e got 3135691854
May 07 15:25:11-435067 cadet-tun-11408 WARNING e towards CHDN
May 07 15:25:11-435112 cadet-tun-11408 WARNING got 716924910
May 07 15:25:11-435157 cadet-tun-11408 WARNING towards NNRK
May 07 15:25:14-405153 transport-tcp-11411 WARNING Received WELCOME message from my own identity `668D' on address `10.0.2.15:37967'
May 07 15:25:14-405636 transport-11411 WARNING External protocol violation detected at plugin_transport_tcp.c:2048.
May 07 15:25:16-434165 cadet-tun-11408 WARNING malformed PING on SAJL
May 07 15:25:16-434309 cadet-tun-11408 WARNING e got 3922075170
May 07 15:25:16-434374 cadet-tun-11408 WARNING e towards BIAP
May 07 15:25:16-434430 cadet-tun-11408 WARNING got 1876665000
...

Bart Polot

2014-05-07 15:43

reporter   ~0008305

AFAIK, the transport errors are independent from the PING loop.

Also, after trying to connect myself, I can confirm that there were some bugs in the code. Right now peer SAJL is misbehaving, since it is not running the newest version of GNUnet. This causes a lost ephemeral key to create this PING loop.

Once everyone is running r33208 or higher, the problem should dissappear.

Issue History

Date Modified Username Field Change
2014-05-03 16:14 ell New Issue
2014-05-03 16:14 ell Status new => assigned
2014-05-03 16:14 ell Assigned To => Bart Polot
2014-05-03 21:11 ell Note Added: 0008277
2014-05-05 12:48 Bart Polot Note Added: 0008279
2014-05-05 12:48 Bart Polot Status assigned => acknowledged
2014-05-06 12:45 ell Note Added: 0008283
2014-05-06 13:33 ell Note Added: 0008284
2014-05-06 13:54 ell Note Added: 0008285
2014-05-06 14:09 ell Note Edited: 0008285 View Revisions
2014-05-06 14:49 ell Note Edited: 0008285 View Revisions
2014-05-06 15:25 ell Note Edited: 0008285 View Revisions
2014-05-06 20:22 ell Note Added: 0008286
2014-05-06 20:39 ell Note Edited: 0008286 View Revisions
2014-05-07 13:03 Bart Polot Note Added: 0008292
2014-05-07 14:42 ell Note Added: 0008293
2014-05-07 14:43 Bart Polot Note Added: 0008294
2014-05-07 14:47 Bart Polot Note Added: 0008295
2014-05-07 14:48 ell Note Edited: 0008293 View Revisions
2014-05-07 14:53 ell Note Added: 0008296
2014-05-07 15:02 Bart Polot Note Added: 0008297
2014-05-07 15:03 ell Note Added: 0008298
2014-05-07 15:06 ell Note Added: 0008299
2014-05-07 15:09 Bart Polot Note Added: 0008300
2014-05-07 15:15 ell Note Added: 0008301
2014-05-07 15:17 Bart Polot Note Added: 0008302
2014-05-07 15:21 ell Note Added: 0008303
2014-05-07 15:26 ell Note Added: 0008304
2014-05-07 15:43 Bart Polot Note Added: 0008305
2014-05-07 15:43 Bart Polot Status acknowledged => resolved
2014-05-07 15:43 Bart Polot Fixed in Version => SVN HEAD
2014-05-07 15:43 Bart Polot Resolution open => fixed
2014-05-09 18:34 Christian Grothoff Category mesh service => cadet service
2014-05-15 20:24 Christian Grothoff Fixed in Version SVN HEAD => 0.11.0pre66
2014-05-15 20:24 Christian Grothoff Target Version => 0.11.0pre66
2018-06-07 00:25 Christian Grothoff Status resolved => closed