View Issue Details

IDProjectCategoryView StatusLast Update
0001730GNUnettransport servicepublic2011-09-19 10:45
Reportermrwiggles Assigned ToMatthias Wachs  
PriorityurgentSeveritycrashReproducibilitysometimes
Status closedResolutionfixed 
Product VersionGit master 
Summary0001730: Transport service crash
DescriptionLooks to me like the send_periodic_ping task is not canceled when disconnect_session is called.

==22739== Invalid read of size 4
==22739== at 0x45971A5: tcp_plugin_send (plugin_transport_tcp.c:1193)
==22739== by 0x804C204: try_transmission_to_peer (gnunet-service-transport.c:1751)
==22739== by 0x804E0A6: send_periodic_ping (gnunet-service-transport.c:3760)
==22739== by 0x405AEA8: GNUNET_SCHEDULER_run (scheduler.c:648)
==22739== by 0x4061758: GNUNET_SERVICE_run (service.c:1627)
==22739== by 0x8049FE4: main (gnunet-service-transport.c:6239)
==22739== Address 0x4307A00 is 272 bytes inside a block of size 388 free'd
==22739== at 0x402213F: free (vg_replace_malloc.c:233)
==22739== by 0x403D6A0: GNUNET_xfree_ (common_allocation.c:196)
==22739== by 0x45947F0: disconnect_session (plugin_transport_tcp.c:885)
==22739== by 0x405B41C: GNUNET_SERVER_client_disconnect (server.c:1205)
==22739== by 0x405B9A1: process_incoming (server.c:878)
==22739== by 0x4040B3F: signal_timeout (connection.c:1120)
==22739== by 0x4041E06: receive_ready (connection.c:1178)
==22739== by 0x405AEA8: GNUNET_SCHEDULER_run (scheduler.c:648)
==22739== by 0x4061758: GNUNET_SERVICE_run (service.c:1627)
==22739== by 0x8049FE4: main (gnunet-service-transport.c:6239)
TagsNo tags attached.

Activities

mrwiggles

2011-07-07 15:49

reporter   ~0004480

==725== Invalid read of size 4
==725== at 0x43971A5: tcp_plugin_send (plugin_transport_tcp.c:1193)
==725== by 0x804C0D4: try_transmission_to_peer (gnunet-service-transport.c:1754)
==725== by 0x804DF76: send_periodic_ping (gnunet-service-transport.c:3763)
==725== by 0x405AEA8: GNUNET_SCHEDULER_run (scheduler.c:648)
==725== by 0x4061758: GNUNET_SERVICE_run (service.c:1627)
==725== by 0x8049EB4: main (gnunet-service-transport.c:6245)
==725== Address 0x4822AD8 is 272 bytes inside a block of size 388 free'd
==725== at 0x402213F: free (vg_replace_malloc.c:233)
==725== by 0x403D6A0: GNUNET_xfree_ (common_allocation.c:196)
==725== by 0x43947F0: disconnect_session (plugin_transport_tcp.c:885)
==725== by 0x405B41C: GNUNET_SERVER_client_disconnect (server.c:1205)
==725== by 0x405B9A1: process_incoming (server.c:878)
==725== by 0x4041F11: receive_ready (connection.c:1213)
==725== by 0x405AEA8: GNUNET_SCHEDULER_run (scheduler.c:648)
==725== by 0x4061758: GNUNET_SERVICE_run (service.c:1627)
==725== by 0x8049EB4: main (gnunet-service-transport.c:6245)

Matthias Wachs

2011-07-07 16:48

reporter   ~0004481

Line causing the code:
tcp_plugin:1192 GNUNET_assert (session != NULL);
-> tcp_plugin:1193 GNUNET_assert (session->client != NULL);

So is session != NULL

But session should be NULLed in:
transport-service:plugin_env_session_end:2400 pos->session = NULL;

mrwiggles

2011-07-07 17:50

reporter   ~0004482

Not sure if this gdb trace adds anything or not...

#0 0x04000832 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
(gdb) bt
#0 0x04000832 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1 0x04162690 in raise () from /lib/libc.so.6
#2 0x04163f91 in abort () from /lib/libc.so.6
#3 0x04397608 in tcp_plugin_send (cls=0x42ad3c8, target=0x46bf770, msg=0x46bf7c4 "", msgbuf_size=82, priority=3, timeout={rel_value = 180000},
    session=0x4366ea0, addr=0x431a978, addrlen=6, force_address=1, cont=0x804d250 <transmit_send_continuation>, cont_cls=0x46bf758)
    at plugin_transport_tcp.c:1130
#4 0x0804c0d5 in try_transmission_to_peer (n=<value optimized out>) at gnunet-service-transport.c:1754
#5 0x0804df77 in send_periodic_ping (cls=0x431a930, tc=0xbeddb938) at gnunet-service-transport.c:3763
#6 0x0405aea9 in GNUNET_SCHEDULER_run (task=0x405f4b0 <service_task>, task_cls=0xbeddba88) at scheduler.c:648
#7 0x04061759 in GNUNET_SERVICE_run (argc=5, argv=0xbeddbbd4, serviceName=0x8055a2c "transport", opt=GNUNET_SERVICE_OPTION_NONE, task=0x8053ce0 <run>,
    task_cls=0x0) at service.c:1627

mrwiggles

2011-07-07 17:58

reporter   ~0004483

Again, I don't know if this is of any help.

#1 0x04162690 in raise () from /lib/libc.so.6
#2 0x04163f91 in abort () from /lib/libc.so.6
#3 0x04397608 in tcp_plugin_send (cls=0x42ad5b0, target=0x441a068, msg=0x441a0bc "\002X", msgbuf_size=676, priority=16777215, timeout=
      {rel_value = 180000}, session=0x44907b0, addr=0x437d670, addrlen=6, force_address=0, cont=0x804d250 <transmit_send_continuation>,
    cont_cls=0x441a050) at plugin_transport_tcp.c:1130
#4 0x0804c0d5 in try_transmission_to_peer (n=<value optimized out>) at gnunet-service-transport.c:1754
#5 0x0804f9f5 in transmit_client_message (cls=0x44fa938, n=0x42de358) at gnunet-service-transport.c:5560
#6 0x0804cf49 in setup_peer_check_blacklist (peer=0x4953448, do_hello=1, cont=0x804f970 <transmit_client_message>, cont_cls=0x44fa938)
    at gnunet-service-transport.c:3438
#7 0x0405be71 in GNUNET_SERVER_inject (server=0x42a4e00, sender=0x42afbc0, message=0x4953438) at server.c:721
#8 0x0405bfc7 in client_message_tokenizer_callback (cls=0x42a4e00, client=0x42afbc0, message=0x4953438) at server.c:961
#9 0x0405ce28 in GNUNET_SERVER_mst_receive (mst=0x42afc50, client_identity=0x42afbc0, buf=0x0, size=0, purge=0, one_shot=-1) at server_mst.c:229
#10 0x0405b796 in process_mst (client=0x42afbc0, ret=0) at server.c:796
#11 0x04041f12 in receive_ready (cls=0x42afad0, tc=0xbeee7938) at connection.c:1213
#12 0x0405aea9 in GNUNET_SCHEDULER_run (task=0x405f4b0 <service_task>, task_cls=0xbeee7a88) at scheduler.c:648
#13 0x04061759 in GNUNET_SERVICE_run (argc=5, argv=0xbeee7bd4, serviceName=0x8055a2c "transport", opt=GNUNET_SERVICE_OPTION_NONE, task=0x8053ce0 <run>,
    task_cls=0x0) at service.c:1627
#14 0x08049eb5 in main (argc=Cannot access memory at address 0x135f
) at gnunet-service-transport.c:6245

mrwiggles

2011-07-11 10:29

reporter   ~0004496

Line numbers from current svn head.

==29577== Invalid read of size 8
==29577== at 0x68B9F94: tcp_plugin_send (plugin_transport_tcp.c:1193)
==29577== by 0x404FE0: try_transmission_to_peer (gnunet-service-transport.c:1766)
==29577== by 0x405399: transmit_to_peer (gnunet-service-transport.c:1854)
==29577== by 0x40CCEB: transmit_client_message (gnunet-service-transport.c:5580)
==29577== by 0x407CDA: setup_peer_check_blacklist (gnunet-service-transport.c:3458)
==29577== by 0x40CEDD: handle_send (gnunet-service-transport.c:5639)
==29577== by 0x54709B6: GNUNET_SERVER_inject (server.c:721)
==29577== by 0x5470E25: client_message_tokenizer_callback (server.c:961)
==29577== by 0x5471BB9: GNUNET_SERVER_mst_receive (server_mst.c:271)
==29577== by 0x5470D01: process_incoming (server.c:889)
==29577== by 0x545457D: receive_ready (connection.c:1213)
==29577== by 0x546EA7E: run_ready (scheduler.c:648)
==29577== Address 0x6584008 is 280 bytes inside a block of size 424 free'd
==29577== at 0x4C27DAC: free (vg_replace_malloc.c:366)
==29577== by 0x544ED56: GNUNET_xfree_ (common_allocation.c:196)
==29577== by 0x68B95F2: disconnect_session (plugin_transport_tcp.c:885)
==29577== by 0x68BB106: disconnect_notify (plugin_transport_tcp.c:1885)
==29577== by 0x5471346: GNUNET_SERVER_client_disconnect (server.c:1205)
==29577== by 0x5470CBC: process_incoming (server.c:878)
==29577== by 0x545457D: receive_ready (connection.c:1213)
==29577== by 0x546EA7E: run_ready (scheduler.c:648)
==29577== by 0x546EE84: GNUNET_SCHEDULER_run (scheduler.c:795)
==29577== by 0x5476AA2: GNUNET_SERVICE_run (service.c:1627)
==29577== by 0x40F295: main (gnunet-service-transport.c:6612)

mrwiggles

2011-07-11 10:35

reporter   ~0004497

Same error, different place...

==19328== Invalid read of size 8
==19328== at 0x68B9F94: tcp_plugin_send (plugin_transport_tcp.c:1193)
==19328== by 0x404FE0: try_transmission_to_peer (gnunet-service-transport.c:1766)
==19328== by 0x405399: transmit_to_peer (gnunet-service-transport.c:1854)
==19328== by 0x408AB6: send_periodic_ping (gnunet-service-transport.c:3783)
==19328== by 0x546EA7E: run_ready (scheduler.c:648)
==19328== by 0x546EE84: GNUNET_SCHEDULER_run (scheduler.c:795)
==19328== by 0x5476AA2: GNUNET_SERVICE_run (service.c:1627)
==19328== by 0x40F295: main (gnunet-service-transport.c:6612)
==19328== Address 0x64eb4c8 is 280 bytes inside a block of size 424 free'd
==19328== at 0x4C27DAC: free (vg_replace_malloc.c:366)
==19328== by 0x544ED56: GNUNET_xfree_ (common_allocation.c:196)
==19328== by 0x68B95F2: disconnect_session (plugin_transport_tcp.c:885)
==19328== by 0x68BB106: disconnect_notify (plugin_transport_tcp.c:1885)
==19328== by 0x5471346: GNUNET_SERVER_client_disconnect (server.c:1205)
==19328== by 0x5470CBC: process_incoming (server.c:878)
==19328== by 0x545457D: receive_ready (connection.c:1213)
==19328== by 0x546EA7E: run_ready (scheduler.c:648)
==19328== by 0x546EE84: GNUNET_SCHEDULER_run (scheduler.c:795)
==19328== by 0x5476AA2: GNUNET_SERVICE_run (service.c:1627)
==19328== by 0x40F295: main (gnunet-service-transport.c:6612)

mrwiggles

2011-07-14 15:00

reporter   ~0004501

recent valgrind trace:

==25275== Invalid write of size 8
==25275== at 0x4088DA: send_periodic_ping (gnunet-service-transport.c:3704)
==25275== by 0x546910D: run_ready (scheduler.c:648)
==25275== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==25275== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==25275== by 0x40FF4C: main (gnunet-service-transport.c:6798)
==25275== Address 0x6792188 is 24 bytes inside a block of size 96 free'd
==25275== at 0x4C268FE: free (vg_replace_malloc.c:366)
==25275== by 0x5448BF1: GNUNET_xfree_ (common_allocation.c:196)
==25275== by 0x4065CD: plugin_env_session_end (gnunet-service-transport.c:2514)
==25275== by 0x68A35CB: disconnect_session (plugin_transport_tcp.c:881)
==25275== by 0x68A52A2: disconnect_notify (plugin_transport_tcp.c:1898)
==25275== by 0x546B994: GNUNET_SERVER_client_disconnect (server.c:1205)
==25275== by 0x546B312: process_incoming (server.c:878)
==25275== by 0x544E4A4: receive_ready (connection.c:1213)
==25275== by 0x546910D: run_ready (scheduler.c:648)
==25275== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==25275== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==25275== by 0x40FF4C: main (gnunet-service-transport.c:6798)
==25275==
==25275== Invalid read of size 8
==25275== at 0x4088E6: send_periodic_ping (gnunet-service-transport.c:3706)
==25275== by 0x546910D: run_ready (scheduler.c:648)
==25275== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==25275== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==25275== by 0x40FF4C: main (gnunet-service-transport.c:6798)
==25275== Address 0x6792178 is 8 bytes inside a block of size 96 free'd
==25275== at 0x4C268FE: free (vg_replace_malloc.c:366)
==25275== by 0x5448BF1: GNUNET_xfree_ (common_allocation.c:196)
==25275== by 0x4065CD: plugin_env_session_end (gnunet-service-transport.c:2514)
==25275== by 0x68A35CB: disconnect_session (plugin_transport_tcp.c:881)
==25275== by 0x68A52A2: disconnect_notify (plugin_transport_tcp.c:1898)
==25275== by 0x546B994: GNUNET_SERVER_client_disconnect (server.c:1205)
==25275== by 0x546B312: process_incoming (server.c:878)
==25275== by 0x544E4A4: receive_ready (connection.c:1213)
==25275== by 0x546910D: run_ready (scheduler.c:648)
==25275== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==25275== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==25275== by 0x40FF4C: main (gnunet-service-transport.c:6798)

Christian Grothoff

2011-07-14 19:08

manager   ~0004502

Conceivably fixed in 15962. Not sure.

mrwiggles

2011-07-14 19:13

reporter   ~0004504

Still exists...

==2419== Invalid write of size 8
==2419== at 0x4088FF: send_periodic_ping (gnunet-service-transport.c:3704)
==2419== by 0x546910D: run_ready (scheduler.c:648)
==2419== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==2419== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==2419== by 0x40FF95: main (gnunet-service-transport.c:6802)
==2419== Address 0x65e67f8 is 24 bytes inside a block of size 102 free'd
==2419== at 0x4C268FE: free (vg_replace_malloc.c:366)
==2419== by 0x5448BF1: GNUNET_xfree_ (common_allocation.c:196)
==2419== by 0x40B5AA: disconnect_neighbour (gnunet-service-transport.c:4925)
==2419== by 0x40762E: neighbour_timeout_task (gnunet-service-transport.c:3030)
==2419== by 0x546910D: run_ready (scheduler.c:648)
==2419== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==2419== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==2419== by 0x40FF95: main (gnunet-service-transport.c:6802)
==2419==
==2419== Invalid read of size 8
==2419== at 0x40890B: send_periodic_ping (gnunet-service-transport.c:3706)
==2419== by 0x546910D: run_ready (scheduler.c:648)
==2419== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==2419== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==2419== by 0x40FF95: main (gnunet-service-transport.c:6802)
==2419== Address 0x65e67e8 is 8 bytes inside a block of size 102 free'd
==2419== at 0x4C268FE: free (vg_replace_malloc.c:366)
==2419== by 0x5448BF1: GNUNET_xfree_ (common_allocation.c:196)
==2419== by 0x40B5AA: disconnect_neighbour (gnunet-service-transport.c:4925)
==2419== by 0x40762E: neighbour_timeout_task (gnunet-service-transport.c:3030)
==2419== by 0x546910D: run_ready (scheduler.c:648)
==2419== by 0x5469510: GNUNET_SCHEDULER_run (scheduler.c:795)
==2419== by 0x547112F: GNUNET_SERVICE_run (service.c:1627)
==2419== by 0x40FF95: main (gnunet-service-transport.c:6802)

Christian Grothoff

2011-07-15 14:35

manager   ~0004508

How about this:

$ svn diff
Index: gnunet-service-transport.c
===================================================================
--- gnunet-service-transport.c (revision 16013)
+++ gnunet-service-transport.c (working copy)
@@ -5381,7 +5381,7 @@
               GNUNET_SCHEDULER_cancel (peer_address->revalidate_task);
               peer_address->revalidate_task = GNUNET_SCHEDULER_NO_TASK;
             }
- GNUNET_SCHEDULER_add_now (send_periodic_ping, peer_address);
+ peer_address->revalidate_task = GNUNET_SCHEDULER_add_now (&send_periodic_ping, peer_address);
          }
          peer_address->timeout
            = GNUNET_TIME_relative_to_absolute (GNUNET_CONSTANTS_IDLE_CONNECTION_TIMEOUT);

Christian Grothoff

2011-07-15 14:36

manager   ~0004509

Last patch is in SVN 16015.

mrwiggles

2011-07-15 15:24

reporter   ~0004512

Seems to be fixed, yay!!

mrwiggles

2011-07-15 15:25

reporter   ~0004513

scheduling task but not keeping track of task handle...

Issue History

Date Modified Username Field Change
2011-07-07 14:18 mrwiggles New Issue
2011-07-07 14:18 mrwiggles Status new => assigned
2011-07-07 14:18 mrwiggles Assigned To => Matthias Wachs
2011-07-07 15:49 mrwiggles Note Added: 0004480
2011-07-07 16:48 Matthias Wachs Note Added: 0004481
2011-07-07 17:50 mrwiggles Note Added: 0004482
2011-07-07 17:58 mrwiggles Note Added: 0004483
2011-07-11 10:29 mrwiggles Note Added: 0004496
2011-07-11 10:35 mrwiggles Note Added: 0004497
2011-07-14 15:00 mrwiggles Note Added: 0004501
2011-07-14 19:08 Christian Grothoff Note Added: 0004502
2011-07-14 19:13 mrwiggles Note Added: 0004504
2011-07-15 14:29 mrwiggles Priority normal => urgent
2011-07-15 14:35 Christian Grothoff Note Added: 0004508
2011-07-15 14:36 Christian Grothoff Note Added: 0004509
2011-07-15 14:38 Christian Grothoff Status assigned => feedback
2011-07-15 15:24 mrwiggles Note Added: 0004512
2011-07-15 15:25 mrwiggles Note Added: 0004513
2011-07-15 15:25 mrwiggles Status feedback => closed
2011-07-15 15:25 mrwiggles Resolution open => fixed
2011-07-15 15:25 mrwiggles Fixed in Version => Git master
2011-09-19 10:45 Christian Grothoff Fixed in Version Git master => 0.9.0pre3
2011-09-19 10:45 Christian Grothoff Target Version => 0.9.0pre3