View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0002390 | GNUnet | transport service | public | 2012-05-31 23:45 | 2012-06-02 19:15 |
| Reporter | Christian Grothoff | Assigned To | Christian Grothoff | ||
| Priority | immediate | Severity | major | Reproducibility | random |
| Status | closed | Resolution | fixed | ||
| Product Version | Git master | ||||
| Target Version | 0.9.3 | Fixed in Version | 0.9.3 | ||
| Summary | 0002390: WARNING Processing code for message of type 0 did not call GNUNET_SERVER_receive_done after 1338500609704ms | ||||
| Description | I got this from 'gnunet-service-transport' (util log message) after running my peer at home for a while. Very odd (13385...ms certainly never passed). | ||||
| Tags | No tags attached. | ||||
|
|
Got it a few times now. |
|
|
This can also cause gnunet-service-transport to hang on exit with left-over tasks that print this warning. Looks like a leak. |
|
|
Just got the assertion we added to diagnose this more: Jun 01 21:55:18-353672 transport-2297 ERROR Assertion failed at server.c:820. |
|
|
grothoff@spec:~$ gnunet-arm -s==3033== Invalid read of size 2 ==3033== at 0x5685FC6: warn_no_receive_done (server.c:820) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== Address 0x6cd5078 is 136 bytes inside a block of size 144 free'd ==3033== at 0x4C240FD: free (vg_replace_malloc.c:366) ==3033== by 0x5654E8F: GNUNET_xfree_ (common_allocation.c:201) ==3033== by 0x5687A08: GNUNET_SERVER_client_disconnect (server.c:1402) ==3033== by 0x5686F73: GNUNET_SERVER_client_drop (server.c:1230) ==3033== by 0x56868EB: process_incoming (server.c:1075) ==3033== by 0x565D0F7: receive_ready (connection.c:1055) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== ==3033== Invalid write of size 8 ==3033== at 0x568608C: warn_no_receive_done (server.c:821) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== Address 0x6cd5020 is 48 bytes inside a block of size 144 free'd ==3033== at 0x4C240FD: free (vg_replace_malloc.c:366) ==3033== by 0x5654E8F: GNUNET_xfree_ (common_allocation.c:201) ==3033== by 0x5687A08: GNUNET_SERVER_client_disconnect (server.c:1402) ==3033== by 0x5686F73: GNUNET_SERVER_client_drop (server.c:1230) ==3033== by 0x56868EB: process_incoming (server.c:1075) ==3033== by 0x565D0F7: receive_ready (connection.c:1055) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== ==3033== Invalid read of size 8 ==3033== at 0x5686110: warn_no_receive_done (server.c:825) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== Address 0x6cd5028 is 56 bytes inside a block of size 144 free'd ==3033== at 0x4C240FD: free (vg_replace_malloc.c:366) ==3033== by 0x5654E8F: GNUNET_xfree_ (common_allocation.c:201) ==3033== by 0x5687A08: GNUNET_SERVER_client_disconnect (server.c:1402) ==3033== by 0x5686F73: GNUNET_SERVER_client_drop (server.c:1230) ==3033== by 0x56868EB: process_incoming (server.c:1075) ==3033== by 0x565D0F7: receive_ready (connection.c:1055) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== ==3033== Invalid read of size 2 ==3033== at 0x5686123: warn_no_receive_done (server.c:825) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== Address 0x6cd5078 is 136 bytes inside a block of size 144 free'd ==3033== at 0x4C240FD: free (vg_replace_malloc.c:366) ==3033== by 0x5654E8F: GNUNET_xfree_ (common_allocation.c:201) ==3033== by 0x5687A08: GNUNET_SERVER_client_disconnect (server.c:1402) ==3033== by 0x5686F73: GNUNET_SERVER_client_drop (server.c:1230) ==3033== by 0x56868EB: process_incoming (server.c:1075) ==3033== by 0x565D0F7: receive_ready (connection.c:1055) ==3033== by 0x5682B60: run_ready (scheduler.c:602) ==3033== by 0x568336A: GNUNET_SCHEDULER_run (scheduler.c:790) ==3033== by 0x5690985: GNUNET_SERVICE_run (service.c:1780) ==3033== by 0x4049A7: main (gnunet-service-transport.c:645) ==3033== |
|
|
Line numbers changed, bug stays: grothoff@spec:~$ gnunet-service-arm ==24200== Memcheck, a memory error detector ==24200== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al. ==24200== Using Valgrind-3.6.0.SVN-Debian and LibVEX; rerun with -h for copyright info ==24200== Command: gnunet-service-transport -c /home/grothoff/.gnunet/gnunet.conf ==24200== ==24200== Invalid read of size 2 ==24200== at 0x568BD5B: warn_no_receive_done (server.c:820) ==24200== by 0x56883ED: run_ready (scheduler.c:602) ==24200== by 0x5688BF7: GNUNET_SCHEDULER_run (scheduler.c:790) ==24200== by 0x56977F7: GNUNET_SERVICE_run (service.c:1780) ==24200== by 0x404EA9: main (gnunet-service-transport.c:645) ==24200== Address 0x6da61b8 is 136 bytes inside a block of size 144 free'd ==24200== at 0x4C240FD: free (vg_replace_malloc.c:366) ==24200== by 0x5658E73: GNUNET_xfree_ (common_allocation.c:201) ==24200== by 0x568DF19: GNUNET_SERVER_client_disconnect (server.c:1392) ==24200== by 0x568D344: GNUNET_SERVER_client_drop (server.c:1230) ==24200== by 0x568CB1B: process_incoming (server.c:1075) ==24200== by 0x566170D: receive_ready (connection.c:1055) ==24200== by 0x56883ED: run_ready (scheduler.c:602) ==24200== by 0x5688BF7: GNUNET_SCHEDULER_run (scheduler.c:790) ==24200== by 0x56977F7: GNUNET_SERVICE_run (service.c:1780) ==24200== by 0x404EA9: main (gnunet-service-transport.c:645) ==24200== ==24200== Invalid write of size 8 ==24200== at 0x568BE21: warn_no_receive_done (server.c:821) ==24200== by 0x56883ED: run_ready (scheduler.c:602) ==24200== by 0x5688BF7: GNUNET_SCHEDULER_run (scheduler.c:790) ==24200== by 0x56977F7: GNUNET_SERVICE_run (service.c:1780) ==24200== by 0x404EA9: main (gnunet-service-transport.c:645) ==24200== Address 0x6da6160 is 48 bytes inside a block of size 144 free'd ==24200== at 0x4C240FD: free (vg_replace_malloc.c:366) ==24200== by 0x5658E73: GNUNET_xfree_ (common_allocation.c:201) ==24200== by 0x568DF19: GNUNET_SERVER_client_disconnect (server.c:1392) ==24200== by 0x568D344: GNUNET_SERVER_client_drop (server.c:1230) ==24200== by 0x568CB1B: process_incoming (server.c:1075) ==24200== by 0x566170D: receive_ready (connection.c:1055) ==24200== by 0x56883ED: run_ready (scheduler.c:602) ==24200== by 0x5688BF7: GNUNET_SCHEDULER_run (scheduler.c:790) ==24200== by 0x56977F7: GNUNET_SERVICE_run (service.c:1780) ==24200== by 0x404EA9: main (gnunet-service-transport.c:645) |
|
|
The problem does not seem to arise if I disable TCP (which uses SERVER) and the error message also now relates to TCP's WELCOME messages: Jun 01 23:07:44-882626 util-24421 WARNING Processing code for message of type 61 did not call GNUNET_SERVER_receive_done after 60087ms So likely there is some mismanagement of GNUNET_SERVER_Client's in the TCP/session management code. |
|
|
Hopefully fixed in SVN 21730. |
|
|
Should be fixed in SVN 21731. |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2012-05-31 23:45 | Christian Grothoff | New Issue | |
| 2012-05-31 23:45 | Christian Grothoff | Status | new => assigned |
| 2012-05-31 23:45 | Christian Grothoff | Assigned To | => Matthias Wachs |
| 2012-06-01 08:09 | Christian Grothoff | Note Added: 0005975 | |
| 2012-06-01 08:09 | Christian Grothoff | Reproducibility | have not tried => random |
| 2012-06-01 08:09 | Christian Grothoff | Target Version | => 0.9.3 |
| 2012-06-01 15:20 | Christian Grothoff | Note Added: 0005979 | |
| 2012-06-01 19:23 | Christian Grothoff | Target Version | 0.9.3 => |
| 2012-06-01 21:57 | Christian Grothoff | Note Added: 0005990 | |
| 2012-06-01 21:58 | Christian Grothoff | Note Added: 0005991 | |
| 2012-06-01 22:43 | Christian Grothoff | Note Added: 0005992 | |
| 2012-06-01 23:10 | Christian Grothoff | Note Added: 0005993 | |
| 2012-06-01 23:10 | Christian Grothoff | Priority | high => urgent |
| 2012-06-01 23:10 | Christian Grothoff | Priority | urgent => immediate |
| 2012-06-01 23:10 | Christian Grothoff | Target Version | => 0.9.3 |
| 2012-06-02 18:59 | Christian Grothoff | Note Added: 0005995 | |
| 2012-06-02 19:03 | Christian Grothoff | Note Added: 0005996 | |
| 2012-06-02 19:03 | Christian Grothoff | Status | assigned => resolved |
| 2012-06-02 19:03 | Christian Grothoff | Fixed in Version | => 0.9.3 |
| 2012-06-02 19:03 | Christian Grothoff | Resolution | open => fixed |
| 2012-06-02 19:03 | Christian Grothoff | Assigned To | Matthias Wachs => Christian Grothoff |
| 2012-06-02 19:15 | Christian Grothoff | Status | resolved => closed |
