View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0003864GNUnetrps servicepublic2015-06-26 16:502018-06-07 00:24
ReporterBart Polot Assigned Toch3  
PrioritynormalSeveritycrashReproducibilityrandom
Status closedResolutionfixed 
Product VersionGit master 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0003864: rps crashes in mq
DescriptionTrying to figure out some rps-mesh crashes I ran into this one:

Jun 26 16:43:00-969864 cadet-api-26020 DEBUG Received a message: { LOCAL_ACK}
Jun 26 16:43:00-969872 cadet-api-26020 DEBUG Got an ACK!
Jun 26 16:43:00-969880 cadet-api-26020 DEBUG on channel 80000001!
Jun 26 16:43:00-969886 cadet-api-26020 DEBUG message processed
Jun 26 16:43:00-969896 cadet-api-26020 DEBUG
Jun 26 16:43:00-969903 cadet-api-26020 DEBUG Received a message: { LOCAL_ACK}
Jun 26 16:43:00-969910 cadet-api-26020 DEBUG Got an ACK!
Jun 26 16:43:00-969916 cadet-api-26020 DEBUG on channel 80000000!
Jun 26 16:43:00-969922 cadet-api-26020 DEBUG message processed
Jun 26 16:43:01-239264 rps-26020 DEBUG Received a ns estimate - logest: 8.667253, std_dev: -nan (old_size: 8)
Jun 26 16:43:01-239285 rps-26020 DEBUG Changing estimate to 7.408001
Jun 26 16:43:01-239294 rps-26020 DEBUG sampler_size is now 8
Jun 26 16:43:01-239301 rps-26020 DEBUG sampler_size is now 8
Jun 26 16:43:01-239307 rps-26020 DEBUG sampler_size is now 8
Jun 26 16:43:01-733892 cadet-api-26020 DEBUG
Jun 26 16:43:01-738987 cadet-api-26020 DEBUG Received a message: { LOCAL_DATA}
Jun 26 16:43:01-739006 cadet-api-26020 DEBUG Got a data message!
Jun 26 16:43:01-739018 cadet-api-26020 DEBUG FWD data on channel NNNN [B0000002]
Jun 26 16:43:01-739047 cadet-api-26020 DEBUG 12 bytes
Jun 26 16:43:01-739055 cadet-api-26020 DEBUG payload type 951 (UNKNOWN)
Jun 26 16:43:01-739062 cadet-api-26020 DEBUG checking handler for type 950
Jun 26 16:43:01-739069 cadet-api-26020 DEBUG checking handler for type 951
Jun 26 16:43:01-739082 rps-26020 DEBUG PULL REQUEST received (NNNN)
Jun 26 16:43:01-739092 rps-26020 DEBUG PULL REQUEST from peer NNNN received, going to send 3 peers
Jun 26 16:43:01-739108 cadet-api-26020 DEBUG CADET NOTIFY TRANSMIT READY
Jun 26 16:43:01-739116 cadet-api-26020 DEBUG on channel 80000003
Jun 26 16:43:01-739123 cadet-api-26020 DEBUG allow_send 1
Jun 26 16:43:01-739130 cadet-api-26020 DEBUG to destination
Jun 26 16:43:01-739136 cadet-api-26020 DEBUG payload size 104
Jun 26 16:43:01-739143 cadet-api-26020 DEBUG total size 112
Jun 26 16:43:01-739150 cadet-api-26020 DEBUG call client notify tmt rdy
Jun 26 16:43:01-739158 cadet-api-26020 DEBUG CADET NOTIFY TRANSMIT READY END
Jun 26 16:43:01-739165 cadet-api-26020 DEBUG callback completed successfully
Jun 26 16:43:01-739171 cadet-api-26020 DEBUG message processed
Jun 26 16:43:01-739187 cadet-api-26020 DEBUG
Jun 26 16:43:01-739195 cadet-api-26020 DEBUG # Send callback, buffer 112
Jun 26 16:43:01-739202 cadet-api-26020 DEBUG # payload, 12 bytes on 80000002 (0x1278750)
Jun 26 16:43:01-739210 cadet-api-26020 DEBUG # payload, 12 bytes on 80000004 (0x12797c0)
Jun 26 16:43:01-739216 cadet-api-26020 DEBUG # payload, 12 bytes on 80000005 (0x1278a40)
Jun 26 16:43:01-739222 cadet-api-26020 DEBUG # payload, 12 bytes on 80000006 (0x1278690)
Jun 26 16:43:01-739229 cadet-api-26020 DEBUG # payload, 112 bytes on 80000003 (0x1278940)
Jun 26 16:43:01-739237 cadet-api-26020 DEBUG # sending, type 952 (UNKNOWN)
Jun 26 16:43:01-739244 cadet-api-26020 DEBUG # total size: 112
Jun 26 16:43:01-739251 cadet-api-26020 DEBUG # nothing ready to transmit
Jun 26 16:43:01-739257 cadet-api-26020 DEBUG # Send callback() END
Jun 26 16:43:01-865310 rps-26020 DEBUG Now acting malicious type 3
Jun 26 16:43:01-865336 rps-26020 WARNING Trying to add peers to an empty peermap.
Jun 26 16:43:01-865347 rps-26020 DEBUG Attacked peer is FFFF
Jun 26 16:43:01-865373 rps-26020 DEBUG Going to execute next round maliciously.
Jun 26 16:43:01-865382 rps-26020 DEBUG Going to send 0 pushes
Jun 26 16:43:01-865390 rps-26020 DEBUG Sending PUSH to peer FFFF of view.
Jun 26 16:43:01-865405 rps-26020 ERROR Assertion failed at gnunet-service-rps.c:840.


Program terminated with signal SIGABRT, Aborted.
#0 0x00007f3c2f428528 in raise () from /usr/lib/libc.so.6
(gdb) bt
#0 0x00007f3c2f428528 in raise () from /usr/lib/libc.so.6
#1 0x00007f3c2f42993a in abort () from /usr/lib/libc.so.6
#2 0x00007f3c311520d7 in GNUNET_abort_ () at common_logging.c:290
#3 0x00000000004067b2 in get_mq (peer_map=0x1271880, peer_id=0x60fc00 <attacked_peer>) at gnunet-service-rps.c:840
#4 0x0000000000409273 in send_push (peer_id=0x60fc00 <attacked_peer>) at gnunet-service-rps.c:1838
#5 0x0000000000409b98 in do_mal_round (cls=0x0, tc=0x7ffd05ecb270) at gnunet-service-rps.c:2043
#6 0x00007f3c3118cf17 in run_ready (rs=0x1265820, ws=0x12658b0) at scheduler.c:587
#7 0x00007f3c3118d827 in GNUNET_SCHEDULER_run (task=0x7f3c3119a345 <service_task>, task_cls=0x7ffd05ecb600)
    at scheduler.c:867
#8 0x00007f3c3119c091 in GNUNET_SERVICE_run (argc=3, argv=0x7ffd05ecb888, service_name=0x40de47 "rps",
    options=GNUNET_SERVICE_OPTION_NONE, task=0x40c53e <run>, task_cls=0x0) at service.c:1503
#9 0x000000000040cbe2 in main (argc=3, argv=0x7ffd05ecb888) at gnunet-service-rps.c:2849
(gdb)
Steps To Reproducegnunet-rps-profiler
Additional Information(gdb) bt full
#0 0x00007f3c2f428528 in raise () from /usr/lib/libc.so.6
No symbol table info available.
#1 0x00007f3c2f42993a in abort () from /usr/lib/libc.so.6
No symbol table info available.
#2 0x00007f3c311520d7 in GNUNET_abort_ () at common_logging.c:290
No locals.
#3 0x00000000004067b2 in get_mq (peer_map=0x1271880, peer_id=0x60fc00 <attacked_peer>) at gnunet-service-rps.c:840
        peer_ctx = 0x1278800
        __FUNCTION__ = "get_mq"
#4 0x0000000000409273 in send_push (peer_id=0x60fc00 <attacked_peer>) at gnunet-service-rps.c:1838
        ev = 0x1275ae0
        mq = 0x8000007f8
        __FUNCTION__ = "send_push"
#5 0x0000000000409b98 in do_mal_round (cls=0x0, tc=0x7ffd05ecb270) at gnunet-service-rps.c:2043
        num_pushes = 0
        i = 0
        time_next_round = {rel_value_us = 140724702851680}
        tmp_att_peer = 0x5196cc1c89b9a
        __FUNCTION__ = "do_mal_round"
#6 0x00007f3c3118cf17 in run_ready (rs=0x1265820, ws=0x12658b0) at scheduler.c:587
        p = GNUNET_SCHEDULER_PRIORITY_DEFAULT
        pos = 0x1278a90
        tc = {reason = GNUNET_SCHEDULER_REASON_TIMEOUT, read_ready = 0x1265820, write_ready = 0x12658b0}
        __FUNCTION__ = "run_ready"
#7 0x00007f3c3118d827 in GNUNET_SCHEDULER_run (task=0x7f3c3119a345 <service_task>, task_cls=0x7ffd05ecb600)
    at scheduler.c:867
        rs = 0x1265820
        ws = 0x12658b0
        timeout = {rel_value_us = 0}
        ret = 0
        shc_int = 0x1267270
        shc_term = 0x1267330
        shc_quit = 0x12674b0
        shc_hup = 0x1267570
        shc_pipe = 0x12673f0
        last_tr = 166
        busy_wait_warning = 0
        pr = 0x1267a30
        c = 0 '\000'
        __FUNCTION__ = "GNUNET_SCHEDULER_run"
#8 0x00007f3c3119c091 in GNUNET_SERVICE_run (argc=3, argv=0x7ffd05ecb888, service_name=0x40de47 "rps",
    options=GNUNET_SERVICE_OPTION_NONE, task=0x40c53e <run>, task_cls=0x0) at service.c:1503
        err = 0
        ret = 3
        cfg_fn = 0x125c700 "~/.config/gnunet.conf"
        opt_cfg_fn = 0x125c850 "/tmp/testbedDJkAO2/3/config"
        loglev = 0x0
        logfile = 0x0
        do_daemonize = 0
        i = 4244798
        skew_offset = 140724702853248
        skew_variance = 4203600
        clock_offset = 1435329752
        sctx = {cfg = 0x125c720, server = 0x1275b80, addrs = 0x125f580, service_name = 0x40de47 "rps",
          task = 0x40c53e <run>, task_cls = 0x0, v4_denied = 0x0, v6_denied = 0x0, v4_allowed = 0x126eac0,
          v6_allowed = 0x126e2f0, my_handlers = 0x12689b0, addrlens = 0x12682b0, lsocks = 0x0,
          shutdown_task = 0x126c670, timeout = {rel_value_us = 18446744073709551615}, ret = 1, ready_confirm_fd = -1,
          require_found = 1, match_uid = 0, match_gid = 1, options = GNUNET_SERVICE_OPTION_NONE}
        cfg = 0x125c720
        xdg = 0x0
        service_options = {{shortName = 99 'c', name = 0x7f3c311aaa0d "config",
            argumentHelp = 0x7f3c311aaa14 "FILENAME", description = 0x7f3c311aaa20 "use configuration file FILENAME",
            require_argument = 1, processor = 0x7f3c3117a255 <GNUNET_GETOPT_set_string>, scls = 0x7ffd05ecb6b8}, {
            shortName = 100 'd', name = 0x7f3c311aaa40 "daemonize", argumentHelp = 0x0,
---Type <return> to continue, or q <return> to quit---
            description = 0x7f3c311aaa50 "do daemonize (detach from terminal)", require_argument = 0,
            processor = 0x7f3c3117a228 <GNUNET_GETOPT_set_one>, scls = 0x7ffd05ecb6a4}, {shortName = 104 'h',
            name = 0x7f3c311aaa74 "help", argumentHelp = 0x0, description = 0x7f3c311aaa79 "print this help",
            require_argument = 0, processor = 0x7f3c31179cf3 <GNUNET_GETOPT_format_help_>, scls = 0x0}, {
            shortName = 76 'L', name = 0x7f3c311aaa89 "log", argumentHelp = 0x7f3c311aaa8d "LOGLEVEL",
            description = 0x7f3c311aaa98 "configure logging to use LOGLEVEL", require_argument = 1,
            processor = 0x7f3c3117a255 <GNUNET_GETOPT_set_string>, scls = 0x7ffd05ecb6b0}, {shortName = 108 'l',
            name = 0x7f3c311aaaba "logfile", argumentHelp = 0x7f3c311aaac2 "LOGFILE",
            description = 0x7f3c311aaad0 "configure logging to write logs to LOGFILE", require_argument = 1,
            processor = 0x7f3c3117a255 <GNUNET_GETOPT_set_string>, scls = 0x7ffd05ecb6a8}, {shortName = 118 'v',
            name = 0x7f3c311aaafb "version", argumentHelp = 0x0,
            description = 0x7f3c311aab03 "print the version number", require_argument = 0,
            processor = 0x7f3c31179cad <GNUNET_GETOPT_print_version_>, scls = 0x7f3c311aab1c}, {shortName = 0 '\000',
            name = 0x0, argumentHelp = 0x0, description = 0x0, require_argument = 0, processor = 0x0, scls = 0x0}}
        __FUNCTION__ = "GNUNET_SERVICE_run"
#9 0x000000000040cbe2 in main (argc=3, argv=0x7ffd05ecb888) at gnunet-service-rps.c:2849
No locals.
(gdb)
TagsNo tags attached.

Activities

Bart Polot

2015-06-26 16:53

manager   ~0009344

(gdb) up 3
#3 0x00000000004067b2 in get_mq (peer_map=0x1271880, peer_id=0x60fc00 <attacked_peer>) at gnunet-service-rps.c:840
840 GNUNET_assert (NULL == peer_ctx->is_live_task);
(gdb) p *peer_ctx
$1 = {peer_flags = 0, mq = 0x0, send_channel = 0x1278750, recv_channel = 0x0, outstanding_ops = 0x1275da0,
  num_outstanding_ops = 1, is_live_task = 0x1278640, peer_id = {public_key = {
      q_y = "{\336\366Ȳ\252\327P\004\323_)\023M\257\314C*\023fX\371\247\361^\305{\312?\305", <incomplete sequence \364\263>}}}
(gdb) p *peer_ctx->is_live_task
$2 = {next = 0x1279770, prev = 0x0, channel = 0x1278750, notify = 0x406496 <cadet_ntfy_tmt_rdy_cb>,
  notify_cls = 0x1278800, timeout = {abs_value_us = 18446744073709551615}, timeout_task = 0x0, size = 12}
(gdb) p *peer_ctx->send_channel
$3 = {next = 0x1263a10, prev = 0x1278940, cadet = 0x125f9f0, chid = 2147483650, port = 0, peer = 3, ctx = 0x0,
  packet_size = 12, options = GNUNET_CADET_OPTION_DEFAULT, allow_send = 0}
(gdb)

Bart Polot

2015-06-26 16:55

manager   ~0009345

I'll keep the log and coredumps around if you need more info.

ch3

2015-06-26 19:05

developer   ~0009347

I didn't see that one, but now it should be fixed.
Would be nice if you could confirm.

Bart Polot

2015-06-26 19:06

manager   ~0009348

I just came across it once, it's kind of hard to reproduce. Feel free to close it, I'll reopen it if I see it again...

Issue History

Date Modified Username Field Change
2015-06-26 16:50 Bart Polot New Issue
2015-06-26 16:50 Bart Polot Status new => assigned
2015-06-26 16:50 Bart Polot Assigned To => ch3
2015-06-26 16:53 Bart Polot Note Added: 0009344
2015-06-26 16:55 Bart Polot Note Added: 0009345
2015-06-26 19:05 ch3 Note Added: 0009347
2015-06-26 19:06 Bart Polot Note Added: 0009348
2015-06-26 19:16 ch3 Status assigned => resolved
2015-06-26 19:16 ch3 Resolution open => fixed
2017-02-26 02:17 Christian Grothoff Fixed in Version => 0.11.0pre66
2017-02-26 02:17 Christian Grothoff Target Version => 0.11.0pre66
2018-06-07 00:24 Christian Grothoff Status resolved => closed