Skip to content
Snippets Groups Projects
New look: Off

Deploy a bandwidth scanner that supports congestion control to check that it's used properly to the 2nd hop

    • Closed Issue created by juga @juga

    As @mikeperry commented in IRC, we could deploy the bandwidth scanner (sbws or onbasca) in a testing machine to check that congestion control is negotiated to 2nd hop and not the 1st, since C-Tor negotiates it to the last Exit hop, but the bandwidth scanners are building the circuits themselves with the EXTENDCIRCUIT control port command.

    For this, we would need to:

    • force bwscanner >= 1 in the bandwidth scanner code
    • @mikeperry would have a C-Tor branch with extra logging enabled
    Edited by juga

    Designs

      Child items ...

      2. Activity

      • juga assigned to @juga

        assigned to @juga

      • juga moved from team#229 (moved)

        moved from team#229 (moved)

      • juga changed milestone to %Network Health OKRs 2022 Q1-Q2 (Metrics excluded)

        changed milestone to %Network Health OKRs 2022 Q1-Q2 (Metrics excluded)

      • juga added Next label

        added Next label

      • juga assigned to @juga

        assigned to @juga

        • juga
          juga @juga ·
          Author Owner

          @gk I think this issues is not specific to any of the 2 bandwidth scanners, so i'm creating it here, but feel free to move it to onbasca if you think we could do this as part of it.

        • Georg Koppen
          Georg Koppen @gk ·
          Owner

          juga (@juga):

          juga commented:

          @gk I think this issues is not specific to any of the 2 bandwidth scanners, so i'm creating it here, but feel free to move it to onbasca if you think we could do this as part of it.

          What about moving it to the analysis project?

        • Please register or sign in to reply
      • juga added S61-O2-Maybe - FINISHED Sponsor 61 - FINISHED labels

        added S61-O2-Maybe - FINISHED Sponsor 61 - FINISHED labels

      • juga added Q2 label

        added Q2 label

      • juga changed title from Deploy a bandwidth scanner that support congestion control to check that it's used properly to the 2nd hop to Deploy a bandwidth scanner that supports congestion control to check that it's used properly to the 2nd hop

        changed title from Deploy a bandwidth scanner that support congestion control to check that it's used properly to the 2nd hop to Deploy a bandwidth scanner that supports congestion control to check that it's used properly to the 2nd hop

      • juga changed the description

        changed the description

      • Mike Perry
        Mike Perry @mikeperry ·
        Developer

        Ok, here is a branch of 0.4.7.7 instrumented with logs: https://gitlab.torproject.org/mikeperry/tor/-/commits/sbws_cc_logs - d3d5b2e04921610e97aa4ecbd1b689ef88db39cb

        That branch has notice and warn level logs for various things. From my read of the code, and initial testing, we're definitely gonna find bugs with this, so we should try to do this next week, as soon as possible.

        There are logs at notice that are "normal" when CC is enabled. There are some warns that can happen from directory activity. There's some more notice logs that contain BAD_IF_CC_DISABLED that are bad if sbws sees them when it is not operating in bwscanner_cc=1 mode.

        So, we have two sets of tests:

        1. A run with this binary that behaves as if bwscanner_cc=1 is set
        2. A run with this binary that behaves as if bwscanner_cc=1 is not set

        These should be run on a test scan, and not a real sbws instance. We need notice and above level logs in both cases. We should not need info level logs.

        I will explain more in the s61 sync, and we can discuss. Some details are already on the pad.

      • Georg Koppen
        Georg Koppen @gk ·
        Owner

        @juga: I just moved this ticket to Doing given that we should do those tests earlier than later.

      • Georg Koppen added Doing label

        added Doing label

      • Georg Koppen removed Next label

        removed Next label

      • Georg Koppen added K4 O3 labels

        added K4 O3 labels

        • juga
          juga @juga ·
          Author Owner

          I've run sbws with mike's branch. These are some of the logs, without forcing bwscanner_cc=1:

          [...]
May 02 14:28:50.703 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
May 02 14:28:50.703 [warn] Edge FC CIRC=1 CC circ, purpose 5 controller 0 0, len 1
May 02 14:28:50.721 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
May 02 14:28:50.721 [warn] Edge FC CIRC=1 CC circ, purpose 5 controller 0 0, len 1
[Many more]
May 02 14:29:08.961 [notice] Tor 0.4.7.7-dev (git-d3d5b2e04921610e) opening log file.
May 02 14:29:09.878 [notice] Got CC for non-sbws Exit CIRC=10, purpose 5, controller: 0 0
May 02 14:29:27.648 [notice] Got CC=0 circ for sbws exit-hop CIRC=11, purpose 5
May 02 14:29:27.657 [notice] Got CC=0 circ for sbws exit-hop CIRC=12, purpose 5
May 02 14:29:27.667 [notice] Got CC=0 circ for sbws exit-hop CIRC=13, purpose 5
May 02 14:29:28.453 [warn] Edge FC CIRC=13 CC circ, purpose 5 controller 1 1, len 2
May 02 14:29:28.453 [warn] Edge FC CIRC=13 CC circ, purpose 5 controller 1 1, len 2
[Many more]
May 02 14:30:07.964 [warn] Edge FC CIRC=11 CC circ, purpose 5 controller 1 1, len 2
May 02 14:30:07.967 [notice] Got CC=0 circ for sbws exit-hop CIRC=14, purpose 5
May 02 14:30:07.968 [warn] Edge FC CIRC=11 CC circ, purpose 5 controller 1 1, len 2`

          Forcing it:

          [...]
May 02 14:39:25.958 [warn] Edge FC CIRC=1 CC circ, purpose 5 controller 0 0, len 1
May 02 14:39:26.029 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
May 02 14:39:26.029 [warn] Edge FC CIRC=2 CC circ, purpose 5 controller 0 0, len 1
[Many more]
May 02 14:39:43.995 [notice] Tor 0.4.7.7-dev (git-d3d5b2e04921610e) opening log file.
May 02 14:39:45.494 [warn] Edge FC CIRC=6 CC circ, purpose 5 controller 0 0, len 1
May 02 14:39:45.669 [warn] Edge FC CIRC=6 CC circ, purpose 5 controller 0 0, len 1
[Many more]
May 02 14:39:45.669 [warn] Edge FC CIRC=6 CC circ, purpose 5 controller 0 0, len 1
May 02 14:40:02.729 [notice] Got CC=1 circ for sbws exit-hop CIRC=10, purpose 5
May 02 14:40:02.736 [notice] Got first-hop CC for sbws CIRC=11, purpose 5
May 02 14:40:02.736 [notice] Got CC=1 circ for sbws exit-hop CIRC=11, purpose 5
May 02 14:40:02.747 [notice] Got CC=1 circ for sbws exit-hop CIRC=12, purpose 5
May 02 14:40:03.231 [warn] One-hop CC for CIRC=11, purpose 5, controller 1 1
May 02 14:40:03.310 [notice] BAD_IF_CC_DISABLED: Got CC for sbws CIRC=12, purpose 5, controller: 1 1
May 02 14:40:03.354 [notice] BAD_IF_CC_DISABLED: Got CC for sbws CIRC=11, purpose 5, controller: 1 1
May 02 14:40:03.443 [notice] BAD_IF_CC_DISABLED: Got CC for sbws CIRC=10, purpose 5, controller: 1 1
May 02 14:40:03.525 [warn] Edge FC CIRC=12 CC circ, purpose 5 controller 1 1, len 2
May 02 14:40:03.525 [warn] Edge FC CIRC=12 CC circ, purpose 5 controller 1 1, len 2

          Let me know if you would like the whole log.

        • Mike Perry
          Mike Perry @mikeperry ·
          Developer

          May 02 14:29:28.453 [warn] Edge FC CIRC=13 CC circ, purpose 5 controller 1 1, len 2

          This log is due to a missing check for the CC object. Fixed in fixup d1a43ef1e18b9e00f7fb6d69f2fd9981b6d2e7f1 of sbws_cc_logs. Sorry.

          May 02 14:40:03.231 [warn] One-hop CC for CIRC=11, purpose 5, controller 1 1

          These logs are interesting, but only if the same circuit id (11 in this case) shows up as using congestion control when it is disabled, or not using congestion control when it is enabled.

          So we should run this again with the fixup, and then I can do some grepping on the full logs. So far it actually looks OK, though.

        • Please register or sign in to reply
      • juga added 1h of time spent

        added 1h of time spent

        • juga
          juga @juga ·
          Author Owner
        • Mike Perry
          Mike Perry @mikeperry ·
          Developer

          This log (sha256sum 39dfd57a75a4cea379089dc1f6188e4ee537fc6f4fb66e9cf5b300d6ad4c5f49) contains several lines like: BAD_IF_CC_DISABLED: Got CC for sbws CIRC=

          This means that this sbws instances was using FlowCtrl=1-2 exits for the second hop, which should not happen if bwscanner_cc=1 is not set. sbws should have only chosen FlowCtrl=1 exits in this case. This may be an sbws bug?

          This log (sha256sum 119b8b2b30d0b974a8a5f742b437a01d85cf9d37ec310628fcb0d161cc8be92e) contains several lines like: Got CC=0 circ for sbws exit-hop CIRC=.

          This means that sbws instances were not picking FlowCtrl=1-2 Exits for the second hop, which is the opposite of what we expect.

          I would guess that perhaps you reversed the two logs, but this second log also has BAD_IF_CC_DISABLED: Got CC for sbws CIRC=, which means that it did pick a FlowCtrl=1-2 Exit for the second hop, at least once.

          So something seems broken here, wrt sbws path building :/

        • juga
          juga @juga ·
          Author Owner

          @mikeperry your tor logs are being very useful to find sbws bugs. First i found sbws#40134 (closed), which was not the issue in the previous logs since i had already applied the patch. Now i found sbws#40136 (closed). I hoped i'd just add one more condition and the rest would magically work, but it was more complex, and here was a bit tricky to modify sbws to support the other cases.

          In the new logs, i've wait until it was measuring an exit without 2 in FlowCtrl in the case bwscanner is not 1 or greater and an exit with 2 in FlowCtrl in the case bwscanner>=1.

          The logs:

          • without bwscanner_cc=1: notice.log Now there is not any line with Got CC=1 nor BAD_IF_CC_DISABLED.
          • with bwscanner_cc=1: notice.log Now there is not any line with Got CC=0.

          They both have lines like Got first-hop CC for sbws CIRC= and One-hop CC for CIRC=. I guess that's ok even in the 1st case?

        • Mike Perry
          Mike Perry @mikeperry ·
          Developer

          They both have lines like Got first-hop CC for sbws CIRC= and One-hop CC for CIRC=. I guess that's ok even in the 1st case?

          Yes, this is OK. This is a side-effect of the control port negotiating congestion control at every hop. I believe it is OK, since the ccontrol on the first hop cpath should not be used for streams attached to a two-hop circuit. And from the rest of the logs, it looks like these circuits are not using congestion control when it is off, and are when it is on.

          So, these logs look good.

        • Please register or sign in to reply
      • juga added 30m of time spent

        added 30m of time spent

      • juga mentioned in issue sbws#40136 (closed)

        mentioned in issue sbws#40136 (closed)

      • juga mentioned in merge request sbws!130 (closed)

        mentioned in merge request sbws!130 (closed)

      • juga mentioned in issue sbws#40137 (closed)

        mentioned in issue sbws#40137 (closed)

      • juga
        juga @juga ·
        Author Owner

        i left running last sbws commit (with sbws#40136 (closed) fixed) in a test server with mike's tor branch. I'll upload logs later.

      • juga added 30m of time spent

        added 30m of time spent

      • juga added 1h of time spent

        added 1h of time spent

      • juga marked this issue as related to sbws#40138 (closed)

        marked this issue as related to sbws#40138 (closed)

      • juga mentioned in issue sbws#40138 (closed)

        mentioned in issue sbws#40138 (closed)

      • juga mentioned in merge request sbws!132 (closed)

        mentioned in merge request sbws!132 (closed)

      • juga mentioned in merge request sbws!134 (closed)

        mentioned in merge request sbws!134 (closed)

      • juga mentioned in merge request sbws!135 (merged)

        mentioned in merge request sbws!135 (merged)

      • juga closed

        closed

      Please register or sign in to reply