View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0003119GNUnetcadet servicepublic2013-11-18 21:282013-12-24 20:54
ReporterChristian Grothoff Assigned ToBart Polot  
PriorityhighSeveritymajorReproducibilityalways
Status closedResolutionfixed 
Product VersionGit master 
Target Version0.10.0Fixed in Version0.10.0 
Summary0003119: various assertion failures in mesh during FS test on sparcbot
DescriptionNov 18 21:03:08-393952 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2508.
Nov 18 21:03:08-394917 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_peer.c:843.
Nov 18 21:03:08-395146 mesh-p2p-103327 WARNING * type unknown: 271
Nov 18 21:03:08-726256 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-730481 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-734059 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-738536 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-742660 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-746498 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-750756 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-754977 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-759240 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-763376 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-767416 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-771923 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-776655 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-781438 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-786469 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-791207 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-795993 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-800555 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-805306 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-810238 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-814833 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-819769 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-826416 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-831179 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:08-835855 mesh-103327 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:09-823802 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:09-871907 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:09-927836 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:09-982957 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-032090 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-084098 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-135913 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-182521 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-236092 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-286800 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-334100 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-385102 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-436785 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-483710 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-535725 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-586759 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-629411 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:10-673943 mesh-103326 ERROR Assertion failed at gnunet-service-mesh_connection.c:2515.
Nov 18 21:03:11-023163 mesh-103327 WARNING External protocol violation detected at gnunet-service-mesh_channel.c:1622.
Download speed was 280 KiB/s
PASS: test_gnunet_service_fs_p2p_mesh
TagsNo tags attached.

Activities

Bart Polot

2013-11-21 18:20

reporter   ~0007670

Flow control assertions, will disappear on successful channel level callbacks.

Bart Polot

2013-11-26 13:38

reporter   ~0007693

Can't reproduce, FS tries to destroy a NULL channel:

(gdb) bt
#0 0x00007f424ef16740 in GNUNET_MESH_channel_destroy (channel=0x0) at mesh_api.c:1464
#1 0x0000000000417840 in reset_mesh (mh=0x15509b0) at gnunet-service-fs_mesh_client.c:222
#2 0x000000000041799c in reset_mesh_task (cls=0x15509b0, tc=0x7ffff228be30) at gnunet-service-fs_mesh_client.c:272
#3 0x00007f424e8cf7eb in run_ready (rs=0x152e550, ws=0x152e5e0) at scheduler.c:593
#4 0x00007f424e8d0079 in GNUNET_SCHEDULER_run (task=0x7f424e8dc20c <service_task>, task_cls=0x7ffff228c1d0) at scheduler.c:808
#5 0x00007f424e8dde3a in GNUNET_SERVICE_run (argc=3, argv=0x7ffff228c448, service_name=0x41ae4b "fs", options=GNUNET_SERVICE_OPTION_NONE, task=0x40556c <run>, task_cls=0x0) at service.c:1478
#6 0x00000000004057d7 in main (argc=3, argv=0x7ffff228c448) at gnunet-service-fs.c:721


(gdb) bt full
#0 0x00007f424ef16740 in GNUNET_MESH_channel_destroy (channel=0x0) at mesh_api.c:1464
        h = 0x8000000dc
        msg = {header = {size = 0, type = 0}, channel_id = 0, peer = {public_key = {q_y = "\260\275(\362\377\177\000\000\340G@\000\000\000\000\000@\304(\362\377\177\000\000\000\000\000\000\000\000\000"}}, port = 1317645595, opt = 32578}
        th = 0x200000000
        __FUNCTION__ = "GNUNET_MESH_channel_destroy"
#1 0x0000000000417840 in reset_mesh (mh=0x15509b0) at gnunet-service-fs_mesh_client.c:222
        channel = 0x0
        __FUNCTION__ = "reset_mesh"
#2 0x000000000041799c in reset_mesh_task (cls=0x15509b0, tc=0x7ffff228be30) at gnunet-service-fs_mesh_client.c:272
        mh = 0x15509b0
#3 0x00007f424e8cf7eb in run_ready (rs=0x152e550, ws=0x152e5e0) at scheduler.c:593
        p = GNUNET_SCHEDULER_PRIORITY_DEFAULT
        pos = 0x15584b0
        tc = {reason = GNUNET_SCHEDULER_REASON_TIMEOUT, read_ready = 0x152e550, write_ready = 0x152e5e0}
        __FUNCTION__ = "run_ready"
#4 0x00007f424e8d0079 in GNUNET_SCHEDULER_run (task=0x7f424e8dc20c <service_task>, task_cls=0x7ffff228c1d0) at scheduler.c:808
        rs = 0x152e550
        ws = 0x152e5e0
        timeout = {rel_value_us = 0}
        ret = 1
        shc_int = 0x15337c0
        shc_term = 0x1531190
        shc_quit = 0x152f010
        shc_hup = 0x152f0c0
        shc_pipe = 0x152ef60
        last_tr = 136
        busy_wait_warning = 0
        pr = 0x1530f90
        c = 0 '\000'
        __FUNCTION__ = "GNUNET_SCHEDULER_run"
#5 0x00007f424e8dde3a in GNUNET_SERVICE_run (argc=3, argv=0x7ffff228c448, service_name=0x41ae4b "fs", options=GNUNET_SERVICE_OPTION_NONE, task=0x40556c <run>, task_cls=0x0) at service.c:1478
        err = 0
        ret = 3
        cfg_fn = 0x15258a0 "~/.gnunet/gnunet.conf"
        opt_cfg_fn = 0x1525ae0 "/tmp/testbedXCqBUm/0/config"
        loglev = 0x0
        logfile = 0x0
        do_daemonize = 0
        i = 4216172
        skew_offset = 139922787350157
        skew_variance = 1
        clock_offset = 139922787394085
        sctx = {cfg = 0x1525880, server = 0x152f430, addrs = 0x0, service_name = 0x41ae4b "fs", task = 0x40556c <run>, task_cls = 0x0, v4_denied = 0x0, v6_denied = 0x0, v4_allowed = 0x153d160, v6_allowed = 0x152e4f0, my_handlers = 0x1528ba0,
          addrlens = 0x0, lsocks = 0x152e460, shutdown_task = 0, 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 = 0x1525880
        xdg = 0x0
        service_options = {{shortName = 99 'c', name = 0x7f424e8eaa6d "config", argumentHelp = 0x7f424e8eaa74 "FILENAME", description = 0x7f424e8eaa80 "use configuration file FILENAME", require_argument = 1,
            processor = 0x7f424e8be4b4 <GNUNET_GETOPT_set_string>, scls = 0x7ffff228c288}, {shortName = 100 'd', name = 0x7f424e8eaaa0 "daemonize", argumentHelp = 0x0, description = 0x7f424e8eaab0 "do daemonize (detach from terminal)",
            require_argument = 0, processor = 0x7f424e8be487 <GNUNET_GETOPT_set_one>, scls = 0x7ffff228c274}, {shortName = 104 'h', name = 0x7f424e8eaad4 "help", argumentHelp = 0x0, description = 0x7f424e8eaad9 "print this help",
            require_argument = 0, processor = 0x7f424e8bdf4e <GNUNET_GETOPT_format_help_>, scls = 0x0}, {shortName = 76 'L', name = 0x7f424e8eaae9 "log", argumentHelp = 0x7f424e8eaaed "LOGLEVEL",
            description = 0x7f424e8eaaf8 "configure logging to use LOGLEVEL", require_argument = 1, processor = 0x7f424e8be4b4 <GNUNET_GETOPT_set_string>, scls = 0x7ffff228c280}, {shortName = 108 'l', name = 0x7f424e8eab1a "logfile",
            argumentHelp = 0x7f424e8eab22 "LOGFILE", description = 0x7f424e8eab30 "configure logging to write logs to LOGFILE", require_argument = 1, processor = 0x7f424e8be4b4 <GNUNET_GETOPT_set_string>, scls = 0x7ffff228c278}, {
            shortName = 118 'v', name = 0x7f424e8eab5b "version", argumentHelp = 0x0, description = 0x7f424e8eab63 "print the version number", require_argument = 0, processor = 0x7f424e8bdf08 <GNUNET_GETOPT_print_version_>,
            scls = 0x7f424e8eab7c}, {shortName = 0 '\000', name = 0x0, argumentHelp = 0x0, description = 0x0, require_argument = 0, processor = 0x0, scls = 0x0}}
        __FUNCTION__ = "GNUNET_SERVICE_run"
#6 0x00000000004057d7 in main (argc=3, argv=0x7ffff228c448) at gnunet-service-fs.c:721
No locals.
(gdb) up 1
#1 0x0000000000417840 in reset_mesh (mh=0x15509b0) at gnunet-service-fs_mesh_client.c:222
222 GNUNET_MESH_channel_destroy (channel);


(gdb) p *mh
$1 = {pending_head = 0x0, pending_tail = 0x0, waiting_map = 0x152f5c0, channel = 0x0, wh = 0x0, target = {public_key = {q_y = "7\252\271\320\332\324\314G\252\tk\300$\211\\,\224\226\061L\001%\257\002/Gcc\f\261\262\327"}}, timeout_task = 162,
  reset_task = 0}
(gdb)

Christian Grothoff

2013-11-28 13:21

manager   ~0007737

Bart, that should be fixed now.

Christian Grothoff

2013-11-28 13:22

manager   ~0007738

Also, I get those breaks on machines other than sparcbot as well.

Bart Polot

2013-11-28 13:44

reporter   ~0007739

Last edited: 2013-11-28 13:45

 The assertion that is repeated a lot of times is really a warning when mesh drops traffic, so not anything too critical.

It should be fixed however with the full channel callback system.

All other assertions seem to be fixed.

Bart Polot

2013-11-28 19:01

reporter   ~0007741

After r30950 there should be a fair reduction in assertions (and maybe a tiny performance bump) as channels are smarter about cancelling unnecessary traffic.

Some assertions remain due to channels generating more traffic that the connection has allowed them to, for instance to send back ACK for incoming traffic when the queue is full of outgoing traffic.

Bart Polot

2013-11-29 03:50

reporter   ~0007743

Antoher step in the right direction: r30959 avoids dropping "unsolicited" management traffic when a connection buffer is full.

Drops are not completely gone. Since management traffic is still "accounted for" it can use the queue slots reserved for pre-aproved clients and when they send their traffic, IT gets dropped.

Next step: don't count management traffic as occuping a place in the queue.

Bart Polot

2013-11-29 19:13

reporter   ~0007750

Last errors should be gone with r30982.

Issue History

Date Modified Username Field Change
2013-11-18 21:28 Christian Grothoff New Issue
2013-11-18 21:28 Christian Grothoff Status new => assigned
2013-11-18 21:28 Christian Grothoff Assigned To => Bart Polot
2013-11-18 21:53 Christian Grothoff Reproducibility have not tried => always
2013-11-20 00:23 Christian Grothoff Target Version => 0.10.0
2013-11-21 18:20 Bart Polot Note Added: 0007670
2013-11-21 18:20 Bart Polot Status assigned => confirmed
2013-11-26 13:38 Bart Polot Note Added: 0007693
2013-11-26 13:38 Bart Polot Status confirmed => feedback
2013-11-28 13:21 Christian Grothoff Note Added: 0007737
2013-11-28 13:21 Christian Grothoff Status feedback => assigned
2013-11-28 13:22 Christian Grothoff Note Added: 0007738
2013-11-28 13:44 Bart Polot Note Added: 0007739
2013-11-28 13:44 Bart Polot Status assigned => acknowledged
2013-11-28 13:45 Bart Polot Note Edited: 0007739
2013-11-28 19:01 Bart Polot Note Added: 0007741
2013-11-29 03:50 Bart Polot Note Added: 0007743
2013-11-29 19:13 Bart Polot Note Added: 0007750
2013-11-29 19:13 Bart Polot Status acknowledged => resolved
2013-11-29 19:13 Bart Polot Fixed in Version => Git master
2013-11-29 19:13 Bart Polot Resolution open => fixed
2013-12-08 23:55 Christian Grothoff Fixed in Version Git master => 0.10.0
2013-12-24 20:54 Christian Grothoff Status resolved => closed
2014-05-09 18:34 Christian Grothoff Category mesh service => cadet service