View Issue Details

IDProjectCategoryView StatusLast Update
0001612GNUnethostlist daemonpublic2010-12-23 23:50
ReporterLRN Assigned ToChristian Grothoff  
PrioritynormalSeveritycrashReproducibilityhave not tried
Status closedResolutionfixed 
Summary0001612: gnunet-daemon-hostlist crashes
DescriptionAt some point gnunet-daemon-hostlist crashes
Steps To ReproduceRun gnunet-daemon-hostlist. From the log and backtrace it might be guessed that this is a bug in handling peer disconnection. Probably could be reproduced by connecting and disconnecting peers.
Additional Informationbt: (top of the stack is omitted, Windows error reporting functions are there)
    #19 0x750f8f5c in msvcrt!abort () from E:\Windows\syswow64\msvcrt.dll
    #20 0x004038d2 in handler_disconnect (cls=0x0, peer=0x28fc38) at hostlist-client.c:1185
    #21 0x004014cb in disconnect_handler (cls=0x0, peer=0x28fc38) at gnunet-daemon-hostlist.c:193
    #22 0x69501996 in main_notify_handler (cls=0x1e27998, msg=0x28fc30) at core_api.c:449
    #23 0x62482da7 in receive_task (cls=0x1e27b40, tc=0x28fce8) at client.c:543
    #24 0x6249fe81 in run_ready (sched=0x28fd48, rs=0x6efe10, ws=0x1e24bc0) at scheduler.c:670
    #25 0x624a0268 in GNUNET_SCHEDULER_run (task=0x6249c4d8 <program_main>, task_cls=0x28fea0) at scheduler.c:813
    #26 0x6249cbba in GNUNET_PROGRAM_run (argc=9, argv=0x6ec050, binaryName=0x40716b "hostlist", binaryHelp=0x4071a8 "GNUnet hostlist server and client", options=0x407280,
        task=0x40153f <run>, task_cls=0x0) at program.c:227
    #27 0x0040174e in main (argc=9, argv=0x6ec050) at gnunet-daemon-hostlist.c:342

daemon-hostlist log contents:
    nov 02 22:37:36 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:37:36 hostlist-9748 DEBUG Socket 420 is ready to read
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 47 / 0x1e3cab0
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 32 / 0x1e27a08
    nov 02 22:37:36 hostlist-9748 ERROR Task 47 took 14615773708288ms to be scheduled
    nov 02 22:37:36 hostlist-9748 DEBUG Running task: 47 / 0x1e3cab0
    nov 02 22:37:36 hostlist-9748 DEBUG receive_ready read 72/65535 bytes from `[::1]:2091' (0x1e3cab0)!
    nov 02 22:37:36 hostlist-9748 DEBUG Adding task: 79 / 0x1e3cb50
    nov 02 22:37:36 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:37:36 hostlist-9748 DEBUG Socket 416 is ready to read
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 79 / 0x1e3cb50
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 32 / 0x1e27a08
    nov 02 22:37:36 hostlist-9748 ERROR Task 32 took 15101105012736ms to be scheduled
    nov 02 22:37:36 hostlist-9748 DEBUG Running task: 32 / 0x1e27a08
    nov 02 22:37:36 hostlist-9748 DEBUG receive_ready read 72/65535 bytes from `[::1]:2092' (0x1e27a08)!
    nov 02 22:37:36 hostlist-9748 DEBUG Adding task: 80 / 0x1e27b40
    nov 02 22:37:36 hostlist-9748 DEBUG Running task: 79 / 0x1e3cb50
    nov 02 22:37:36 hostlist-9748 DEBUG Received message of type 22 and size 72
    nov 02 22:37:36 hostlist-9748 DEBUG Adding task: 81 / 0x1e3cab0
    nov 02 22:37:36 hostlist-9748 DEBUG Receiving `DISCONNECT' message for `E1IE'.
    nov 02 22:37:36 hostlist-9748 DEBUG Removing neighbour `E1IE' from list of connected peers.
    nov 02 22:37:36 hostlist-9748 DEBUG Removing neighbour `E1IE' from list of connected peers.
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 81 / 0x1e3cab0
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 80 / 0x1e27b40
    nov 02 22:37:36 hostlist-9748 DEBUG Running task: 80 / 0x1e27b40
    nov 02 22:37:36 hostlist-9748 DEBUG Received message of type 68 and size 72
    nov 02 22:37:36 hostlist-9748 DEBUG Processing message of type 68 and size 72 from core service
    nov 02 22:37:36 hostlist-9748 DEBUG Scheduling transmit_ready (0x6e8358).
    nov 02 22:37:36 hostlist-9748 DEBUG Adding task: 82 / 0x6e8358
    nov 02 22:37:36 hostlist-9748 DEBUG Adding task: 83 / 0x1e27a08
    nov 02 22:37:36 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:37:36 hostlist-9748 DEBUG Socket 396 is ready to write
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 82 / 0x6e8358
    nov 02 22:37:36 hostlist-9748 DEBUG Checking readiness of task: 81 / 0x1e3cab0
    nov 02 22:37:36 hostlist-9748 DEBUG Running task: 82 / 0x6e8358
    nov 02 22:37:36 hostlist-9748 DEBUG transmit_ready running (0x6e8358).
    nov 02 22:37:36 hostlist-9748 DEBUG transmit_ready transmitted 46/46 bytes to `[::1]:2088' (0x6e8358)
    nov 02 22:39:33 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:39:33 hostlist-9748 DEBUG Socket 420 is ready to read
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 81 / 0x1e3cab0
    nov 02 22:39:33 hostlist-9748 ERROR Task 81 took 504662952247296ms to be scheduled
    nov 02 22:39:33 hostlist-9748 DEBUG Running task: 81 / 0x1e3cab0
    nov 02 22:39:33 hostlist-9748 DEBUG receive_ready read 80/65535 bytes from `[::1]:2091' (0x1e3cab0)!
    nov 02 22:39:33 hostlist-9748 DEBUG Adding task: 84 / 0x1e3cb50
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 84 / 0x1e3cb50
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:39:33 hostlist-9748 DEBUG Running task: 84 / 0x1e3cb50
    nov 02 22:39:33 hostlist-9748 DEBUG Received message of type 21 and size 80
    nov 02 22:39:33 hostlist-9748 DEBUG Adding task: 85 / 0x1e3cab0
    nov 02 22:39:33 hostlist-9748 DEBUG Receiving `CONNECT' message for `E1IE'.
    nov 02 22:39:33 hostlist-9748 DEBUG Creating entry for neighbour `E1IE'.
    nov 02 22:39:33 hostlist-9748 DEBUG Initializing bandwidth of 1024 Bps
    nov 02 22:39:33 hostlist-9748 DEBUG Tracker 0x1e27b18 initialized with 1024 Bps and max carry 5
    nov 02 22:39:33 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:39:33 hostlist-9748 DEBUG Socket 420 is ready to read
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 85 / 0x1e3cab0
    nov 02 22:39:33 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:39:33 hostlist-9748 DEBUG Running task: 85 / 0x1e3cab0
    nov 02 22:39:33 hostlist-9748 DEBUG receive_ready read 72/65535 bytes from `[::1]:2091' (0x1e3cab0)!
    nov 02 22:39:33 hostlist-9748 DEBUG Adding task: 86 / 0x1e3cb50
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 86 / 0x1e3cb50
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:39:34 hostlist-9748 DEBUG Running task: 86 / 0x1e3cb50
    nov 02 22:39:34 hostlist-9748 DEBUG Received message of type 22 and size 72
    nov 02 22:39:34 hostlist-9748 DEBUG Adding task: 87 / 0x1e3cab0
    nov 02 22:39:34 hostlist-9748 DEBUG Receiving `DISCONNECT' message for `E1IE'.
    nov 02 22:39:34 hostlist-9748 DEBUG Removing neighbour `E1IE' from list of connected peers.
    nov 02 22:39:34 hostlist-9748 DEBUG Removing neighbour `E1IE' from list of connected peers.
    nov 02 22:39:34 hostlist-9748 DEBUG 1 sockets are ready
    nov 02 22:39:34 hostlist-9748 DEBUG Socket 416 is ready to read
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 87 / 0x1e3cab0
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 83 / 0x1e27a08
    nov 02 22:39:34 hostlist-9748 ERROR Task 83 took 505247067799552ms to be scheduled
    nov 02 22:39:34 hostlist-9748 DEBUG Running task: 83 / 0x1e27a08
    nov 02 22:39:34 hostlist-9748 DEBUG receive_ready read 72/65535 bytes from `[::1]:2092' (0x1e27a08)!
    nov 02 22:39:34 hostlist-9748 DEBUG Adding task: 88 / 0x1e27b40
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 88 / 0x1e27b40
    nov 02 22:39:34 hostlist-9748 DEBUG Checking readiness of task: 87 / 0x1e3cab0
    nov 02 22:39:34 hostlist-9748 DEBUG Running task: 88 / 0x1e27b40
    nov 02 22:39:34 hostlist-9748 DEBUG Received message of type 68 and size 72
    nov 02 22:39:34 hostlist-9748 DEBUG Processing message of type 68 and size 72 from core service
    nov 02 22:39:34 hostlist-9748 ERROR Assertion failed at hostlist-client.c:1185.
TagsNo tags attached.

Relationships

related to 0001582 closedChristian Grothoff counter of "neighbour entries allocated" is very high 
related to 0001583 closedChristian Grothoff core receives disconnect notification from transport for peer long gone 

Activities

Matthias Wachs

2010-11-03 09:25

reporter   ~0004136

Assertions fails because hostlist-client receives more core disconnect handler calls than core connect calls.

For every call to core connect handler stat_connection_count is incremented, for every call to core disconnect handler the value is decremented.

The assertion fails if more disconnect calls then connect calls arrive.
Explanations:

- Peer had already connected before hostlist-client was up

Matthias Wachs

2010-11-03 09:31

reporter   ~0004137

Perhaps this should not be an assertion since you can not blame hostlist-client for how often the handlers are called and instead just ensure that the value is >= 0

Christian Grothoff

2010-11-19 14:01

manager   ~0004182

Likely resolved with recent core_api changes.

Issue History

Date Modified Username Field Change
2010-11-02 20:55 LRN New Issue
2010-11-02 20:55 LRN Status new => assigned
2010-11-02 20:55 LRN Assigned To => Matthias Wachs
2010-11-02 21:01 Christian Grothoff Relationship added related to 0001582
2010-11-02 21:01 Christian Grothoff Relationship added related to 0001583
2010-11-03 09:25 Matthias Wachs Note Added: 0004136
2010-11-03 09:31 Matthias Wachs Note Added: 0004137
2010-11-13 22:10 Christian Grothoff Assigned To Matthias Wachs => Christian Grothoff
2010-11-19 14:01 Christian Grothoff Note Added: 0004182
2010-11-19 14:01 Christian Grothoff Status assigned => resolved
2010-11-19 14:01 Christian Grothoff Resolution open => fixed
2010-12-23 23:50 Christian Grothoff Status resolved => closed