View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0003910 | GNUnet | core service | public | 2015-07-24 00:15 | 2018-06-07 00:24 |
Reporter | Bart Polot | Assigned To | Christian Grothoff | ||
Priority | normal | Severity | major | Reproducibility | always |
Status | closed | Resolution | fixed | ||
Product Version | Git master | ||||
Target Version | 0.11.0pre66 | Fixed in Version | 0.11.0pre66 | ||
Summary | 0003910: Various core assertions related to neighbours unexpectely not found in neighbour map | ||||
Description | Running 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 Reproduce | Running a peer connected to the Internet. Host is a vm behind quadruple NAT (local machine, Wifi AP, DSL Router, ISP-level NAT) | ||||
Additional Information | Jul 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 | ||||
Tags | No tags attached. | ||||
related to | 0004025 | closed | Christian Grothoff | Supurious SEND_OK causes GNUNET_break (GNUNET_NO == n->is_ready); assertion in transport_api.c to fail |
|
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. |
|
Running memtest86 overnight has shown no errors. |
|
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. |
|
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. |
|
$ 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) |
|
Machine has public IP, no NAT, svn HEAD. |
|
Do you get this while running core under valgrind? |
|
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. |
|
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... |
|
Just fixed another possibly-related issue. Setting to feedback as I want to know if this is still happening post SVN 36611. |
|
Not seen for a while on various peers. |
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 |