View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0003910GNUnetcore servicepublic2015-07-24 00:152018-06-07 00:24
ReporterBart Polot Assigned ToChristian Grothoff  
PrioritynormalSeveritymajorReproducibilityalways
Status closedResolutionfixed 
Product VersionGit master 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0003910: Various core assertions related to neighbours unexpectely not found in neighbour map
DescriptionRunning a peer with the default configuration (not even a config file) I get a mix of core ERROR messages (gnunet-service-core_neighbours.c lines 335, 381, 503).
Steps To ReproduceRunning a peer connected to the Internet. Host is a vm behind quadruple NAT (local machine, Wifi AP, DSL Router, ISP-level NAT)
Additional InformationJul 24 00:01:33-368631 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:01:33-368974 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:02:26-076884 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:02:26-185946 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:02:40-303542 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:02:40-305941 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:02:40-747043 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:02:40-805922 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:02:40-808479 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:02:41-249589 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:03:11-930217 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:03:12-049834 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:03:33-370537 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:03:33-371274 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:04:26-077568 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:04:26-186303 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:04:41-487462 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:04:41-489833 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:04:41-934298 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:04:41-989521 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:04:41-992223 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:04:42-433296 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:05:11-930526 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:05:12-049996 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:05:33-369928 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:05:33-370285 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:06:26-077690 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:06:26-186806 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:07:11-931731 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:07:12-050931 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:07:23-446558 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:07:23-448780 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:07:23-948600 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:381.
Jul 24 00:07:23-950855 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:335.
Jul 24 00:07:24-500569 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:07:33-370875 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:07:33-370983 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:08:26-078398 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.
Jul 24 00:08:26-187534 core-31512 ERROR Assertion failed at gnunet-service-core_neighbours.c:503.


[bart@arch-vm ~]$ gnunet-core
Fri Jul 24 00:08:06 2015: connection established RNGR (timeout in 284 s)
Fri Jul 24 00:08:06 2015: connection established VYGR (timeout in 286 s)
Fri Jul 24 00:08:06 2015: connection established DEB8 (timeout in 286 s)
Fri Jul 24 00:08:06 2015: connection established DSTJ (timeout in 298 s)
Fri Jul 24 00:08:06 2015: connection established 60JY (timeout in 297 s)

[bart@arch-vm ~]$ gnunet-statistics -s core
         core # bytes encrypted: 265897559
         core # avg payload per encrypted message: 9509
         core # bytes of messages of type 138 received: 236828132
         core # encrypted bytes given to transport: 267876155
         core # bytes of messages of type 137 received: 23033304
         core # bytes of messages of type 147 received: 1124771
         core # bytes of payload decrypted: 27385339
         core # bytes decrypted: 27684823
         core # bytes of messages of type 148 received: 4263137
         core # bytes of messages of type 282 received: 109756
         core # bytes of messages of type 268 received: 1080
         core # bytes of messages of type 262 received: 12852
         core # bytes of messages of type 257 received: 720
         core # valid typemap confirmations received: 6
         core # bytes of messages of type 17 received: 21640
         core # bytes of messages of type 322 received: 2640
         core # type maps received: 35
         core # type map refreshes sent: 22
         core # peers connected: 6
         core # session keys confirmed via PONG: 7
         core # PONG messages decrypted: 10
         core # PONG messages received: 10
         core # PONG messages created: 11
         core # PING messages received: 11
         core # PING messages transmitted: 11
         core # EPHEMERAL_KEY messages received: 9
         core # ephemeral keys received: 9
         core # key exchanges initiated: 8
         core # neighbour entries allocated: 6
         core # bytes of messages of type 139 received: 368
         core # bytes of messages of type 146 received: 45181
         core # messages discarded (expired prior to transmission): 5
         core # timeouts prevented via PONG: 2
         core # keepalive messages sent: 2
         core # bytes of messages of type 258 received: 700
         core # bytes of messages of type 256 received: 2156
         core # key exchanges stopped: 2
         core # sessions terminated by transport disconnect: 2
         core # bytes of messages of type 266 received: 108
         core # rekey operations confirmed via PONG: 1
         core # DATA message dropped (out of order): 16
         core # updates to my type map: 6
TagsNo tags attached.

Relationships

related to 0004025 closedChristian Grothoff Supurious SEND_OK causes GNUNET_break (GNUNET_NO == n->is_ready); assertion in transport_api.c to fail 

Activities

Christian Grothoff

2015-08-03 13:36

manager   ~0009521

The warnings are because a peer that should be in the neighbour's map is not found in it.

I've gone manually over the code on both the core and the transport-API side, and the transport API checks for the very same invariants before calling the core callbacks, so this should really never fail on the core side -- and the logic is rather simple, so it is unlikely that I overlooked something.

Right now, I only have two possible explanations:
1) there is some "general" memory corruption in the CORE service, which happens to corrupt the hash map. This, we might find using valgrind -- if this is reproducable.

2) your hardware has defective memory (yes, this happens). You should run memtest86 or other test tools to verify that this is not the issue here.

Bart Polot

2015-08-04 16:24

manager   ~0009534

Running memtest86 overnight has shown no errors.

Christian Grothoff

2015-08-04 17:29

manager   ~0009535

Well, I've not seen this _ever_, so please try valgrind next. Also, adding the hardening options to configure and/or using memorysanitizer might also help.

Bart Polot

2015-09-03 17:27

manager   ~0009599

Just seen this on a different machine, fresh install:

Sep 03 15:20:54-344774 core-1662 ERROR Assertion failed at gnunet-service-core_neighbours.c:341.
Sep 03 15:20:55-344846 core-1662 ERROR Assertion failed at gnunet-service-core_neighbours.c:513.
Sep 03 15:20:57-611449 core-1662 ERROR Assertion failed at gnunet-service-core_neighbours.c:388.
Sep 03 15:20:57-613659 core-1662 ERROR Assertion failed at gnunet-service-core_neighbours.c:341.
Sep 03 15:20:58-613791 core-1662 ERROR Assertion failed at gnunet-service-core_neighbours.c:513.

Bart Polot

2015-09-03 17:28

manager   ~0009600

$ gnunet-statistics -s core | sort
         core # avg payload per encrypted message: 18796
         core # bytes decrypted: 40107722
         core # bytes encrypted: 70910597
         core # bytes of messages of type 137 received: 17779736
         core # bytes of messages of type 138 received: 52761996
         core # bytes of messages of type 139 received: 2048
         core # bytes of messages of type 146 received: 2148
         core # bytes of messages of type 147 received: 70304
         core # bytes of messages of type 148 received: 135677
         core # bytes of messages of type 17 received: 3668
         core # bytes of messages of type 256 received: 10348
         core # bytes of messages of type 257 received: 1332
         core # bytes of messages of type 258 received: 500
         core # bytes of messages of type 262 received: 6480
         core # bytes of messages of type 266 received: 252
         core # bytes of messages of type 268 received: 3840
         core # bytes of messages of type 269 received: 280
         core # bytes of messages of type 282 received: 51340
         core # bytes of messages of type 322 received: 4884
         core # bytes of payload decrypted: 40063310
         core # DATA message dropped (out of order): 656
         core # encrypted bytes given to transport: 70831339
         core # EPHEMERAL_KEY messages received: 82
         core # ephemeral keys received: 82
         core # keepalive messages sent: 17
         core # key exchanges initiated: 24
         core # key exchanges stopped: 7
         core # messages discarded (expired prior to transmission): 3
         core # neighbour entries allocated: 17
         core # old ephemeral keys ignored: 15
         core # peers connected: 12
         core # PING messages dropped (out of order): 3
         core # PING messages received: 70
         core # PING messages transmitted: 127
         core # PONG messages created: 60
         core # PONG messages decrypted: 46
         core # PONG messages dropped (out of order): 2
         core # PONG messages received: 48
         core # rekey operations confirmed via PONG: 10
         core # send requests dropped (disconnected): 4
         core # session keys confirmed via PONG: 23
         core # sessions terminated by timeout: 5
         core # sessions terminated by transport disconnect: 7
         core # timeouts prevented via PONG: 12
         core # type map refreshes sent: 260
         core # type maps received: 41
         core # updates to my type map: 6
         core # valid typemap confirmations received: 24

$ gnunet-core
 Do Sep 03 15:27:35 2015: connection established T34P (timeout in 298 s)
 Do Sep 03 15:27:35 2015: key received 6YNB (timeout in 0 ms)
 Do Sep 03 15:27:35 2015: connection established H8ND (timeout in 223 s)
 Do Sep 03 15:27:35 2015: key sent CXYJ (timeout in 0 ms)
 Do Sep 03 15:27:35 2015: connection established G3FK (timeout in 296 s)
 Do Sep 03 15:27:35 2015: rekeying 6DEV (timeout in 218 s)
 Do Sep 03 15:27:35 2015: connection established DK5W (timeout in 297 s)
 Do Sep 03 15:27:35 2015: connection established FWGD (timeout in 299 s)
 Do Sep 03 15:27:35 2015: key sent GN10 (timeout in 0 ms)
 Do Sep 03 15:27:35 2015: rekeying K3PJ (timeout in 218 s)
 Do Sep 03 15:27:35 2015: key received 60JY (timeout in 0 ms)
 Do Sep 03 15:27:35 2015: connection established DSTJ (timeout in 295 s)
 Do Sep 03 15:27:35 2015: connection established QNRR (timeout in 229 s)
 Do Sep 03 15:27:35 2015: key received VMDC (timeout in 0 ms)
 Do Sep 03 15:27:35 2015: connection established Y8RR (timeout in 224 s)
 Do Sep 03 15:27:35 2015: connection established CBD2 (timeout in 299 s)
 Do Sep 03 15:27:35 2015: connection established STRN (timeout in 295 s)

Bart Polot

2015-09-03 17:28

manager   ~0009601

Machine has public IP, no NAT, svn HEAD.

Christian Grothoff

2015-09-05 10:54

manager   ~0009609

Do you get this while running core under valgrind?

Bart Polot

2015-09-05 11:47

manager   ~0009610

No, but it only happens very rarely. I just happened to see this while setting up a new (bootstrap) peer. This is literally the second time I see it.

Bart Polot

2015-09-05 11:49

manager   ~0009611

Now that re-read the original report, I noticed that this time I was also running with *no configuration file* (normally I remove all ats quotas). May or may not be relevant...

Christian Grothoff

2015-10-28 14:07

manager   ~0009819

Just fixed another possibly-related issue. Setting to feedback as I want to know if this is still happening post SVN 36611.

Christian Grothoff

2015-10-31 16:11

manager   ~0009869

Not seen for a while on various peers.

Issue History

Date Modified Username Field Change
2015-07-24 00:15 Bart Polot New Issue
2015-07-24 00:15 Bart Polot Status new => assigned
2015-07-24 00:15 Bart Polot Assigned To => Christian Grothoff
2015-08-03 13:36 Christian Grothoff Note Added: 0009521
2015-08-03 13:36 Christian Grothoff Severity minor => major
2015-08-03 13:36 Christian Grothoff Target Version 0.11.0pre66 =>
2015-08-03 13:36 Christian Grothoff Status assigned => feedback
2015-08-03 13:57 Christian Grothoff Summary Various core assertions => Various core assertions related to neighbours unexpectely not found in neighbour map
2015-08-04 16:24 Bart Polot Note Added: 0009534
2015-08-04 16:24 Bart Polot Status feedback => assigned
2015-08-04 17:29 Christian Grothoff Note Added: 0009535
2015-09-03 17:27 Bart Polot Note Added: 0009599
2015-09-03 17:28 Bart Polot Note Added: 0009600
2015-09-03 17:28 Bart Polot Note Added: 0009601
2015-09-05 10:54 Christian Grothoff Note Added: 0009609
2015-09-05 11:47 Bart Polot Note Added: 0009610
2015-09-05 11:49 Bart Polot Note Added: 0009611
2015-10-26 16:26 Christian Grothoff Relationship added related to 0004025
2015-10-28 14:07 Christian Grothoff Note Added: 0009819
2015-10-28 14:07 Christian Grothoff Status assigned => feedback
2015-10-31 16:11 Christian Grothoff Note Added: 0009869
2015-10-31 16:11 Christian Grothoff Status feedback => resolved
2015-10-31 16:11 Christian Grothoff Fixed in Version => 0.11.0pre66
2015-10-31 16:11 Christian Grothoff Resolution open => fixed
2015-10-31 16:12 Christian Grothoff Target Version => 0.11.0pre66
2018-06-07 00:24 Christian Grothoff Status resolved => closed