search

KiraleTech / KiBRA

Kirale's Thread Border Router reference implementation
https://www.kirale.com
MIT License
12 stars 3 forks source link

IP addresses incorrectly prefixed when setting up border router #1

Closed sjlongland closed 5 years ago

sjlongland commented 5 years ago

Hi all,

I'm just trying out the Kirale border router with a KTDG102 dongle… I'm using the virtual machine image which I have running under KVM. At first it refused to see the dongle, but then I tried flashing the dongle firmware (with this image), and things started working, but then the border router would fail setting up the network.

I tweaked the software a little bit to reveal the stack trace and parameters being entered:

root@kiralebr:~/py36env/KiBRA# git diff
diff --git a/kibra/ktask.py b/kibra/ktask.py
index 33a717a..82474ee 100644
--- a/kibra/ktask.py
+++ b/kibra/ktask.py
@@ -93,8 +93,8 @@ class Ktask(Thread):
                         logging.info('Task [%s] has now started.', self.name)
                     except Exception as exc:
                         db.set(self.status_key, status.ERRORED)
-                        logging.error('Task [%s] errored on start: %s',
-                                      self.name, exc)
+                        logging.error('Task [%s] errored on start',
+                                      self.name, exc_info=1)
                     db.set(self.action_key, action.NONE)
                 elif task_action is action.KILL:
                     self.is_alive = False
diff --git a/kibra/network.py b/kibra/network.py
index 75699c1..e0ebe79 100644
--- a/kibra/network.py
+++ b/kibra/network.py
@@ -183,10 +183,10 @@ def _ifup():
     IP.link('set', index=idx, state='up', txqlen=5000)

     # Add inside IPv6 addresses
-    logging.info('Configuring interior interface %s with address %s.',
+    logging.info('Configuring interior interface %s with address %r.',
                  db.get('interior_ifname'), db.get('dongle_rloc'))
     IP.addr('add', index=idx, address=db.get('dongle_rloc'), prefixlen=64)
-    logging.info('Configuring interior interface %s with address %s.',
+    logging.info('Configuring interior interface %s with address %r.',
                  db.get('interior_ifname'), db.get('dongle_eid'))
     IP.addr('add', index=idx, address=db.get('dongle_eid'), prefixlen=64)

…which gave me what was going on…

2019-06-28 12:07:35,846 - INFO [network]: Configuring interior interface enx8404d20004a6 with address '[R] fd85:4a3c:b40e::ff:fe00:ac00'.
2019-06-28 12:07:35,850 - ERROR [ktask]: Task [network] errored on start
Traceback (most recent call last):
  File "/root/py36env/KiBRA/kibra/ktask.py", line 91, in run
    self.kstart()
  File "/root/py36env/KiBRA/kibra/network.py", line 313, in kstart
    _ifup()
  File "/root/py36env/KiBRA/kibra/network.py", line 188, in _ifup
    IP.addr('add', index=idx, address=db.get('dongle_rloc'), prefixlen=64)
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/iproute/linux.py", line 1279, in addr
    terminate=lambda x: x['header']['type'] ==
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 373, in nlm_request
    return tuple(self._genlm_request(*argv, **kwarg))
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 861, in nlm_request
    self.put(msg, msg_type, msg_flags, msg_seq=msg_seq)
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 612, in put
    self.sendto_gate(msg, addr)
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/rtnl/iprsocket.py", line 61, in _gate_linux
    msg.encode()
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/__init__.py", line 1073, in encode
    offset = self.encode_nlas(offset)
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/__init__.py", line 1382, in encode_nlas
    nla.encode()
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/__init__.py", line 1672, in encode
    self['value'] = inet_pton(family, self.value)
OSError: illegal IP address string passed to inet_pton

I don't think that [R] belongs there. If I alter the code a little bit:

diff --git a/kibra/network.py b/kibra/network.py
index 75699c1..997201c 100644
--- a/kibra/network.py
+++ b/kibra/network.py
@@ -183,12 +183,15 @@ def _ifup():
     IP.link('set', index=idx, state='up', txqlen=5000)

     # Add inside IPv6 addresses
-    logging.info('Configuring interior interface %s with address %s.',
-                 db.get('interior_ifname'), db.get('dongle_rloc'))
-    IP.addr('add', index=idx, address=db.get('dongle_rloc'), prefixlen=64)
-    logging.info('Configuring interior interface %s with address %s.',
-                 db.get('interior_ifname'), db.get('dongle_eid'))
-    IP.addr('add', index=idx, address=db.get('dongle_eid'), prefixlen=64)
+    addr = db.get('dongle_rloc').split(' ')[-1]
+    logging.info('Configuring interior interface %s with address %r.',
+                 db.get('interior_ifname'), addr)
+    IP.addr('add', index=idx, address=addr, prefixlen=64)
+
+    addr = db.get('dongle_eid').split(' ')[-1]
+    logging.info('Configuring interior interface %s with address %r.',
+                 db.get('interior_ifname'), addr)
+    IP.addr('add', index=idx, address=addr, prefixlen=64)

     # Add dongle neighbour
     IP.neigh(

… it gets a little further, but still fails as it then tries to add a multicast address. This is the log I have now:

(py36env) root@kiralebr:~/py36env/KiBRA# python -m kibra
/root/py36env/lib/python3.6/site-packages/pyroute2/__init__.py:6: UserWarning: Module kibra was already imported from None, but /root/py36env/KiBRA is being added to sys.path
  import pkg_resources
2019-06-28 12:22:17,520 - INFO [webserver]: Loading web server...
2019-06-28 12:23:14,592 - INFO [ktask]: Loading task [serial]...
2019-06-28 12:23:14,592 - INFO [ksh]: Trying to find a KiNOS device...
2019-06-28 12:23:14,596 - INFO [ktask]: Loading task [network]...
2019-06-28 12:23:14,597 - INFO [ktask]: Task [network] is waiting for [serial] to start.
2019-06-28 12:23:14,600 - INFO [ktask]: Loading task [dhcp]...
2019-06-28 12:23:14,600 - INFO [ktask]: Task [dhcp] is waiting for [network] to start.
2019-06-28 12:23:14,601 - INFO [ktask]: Loading task [nat]...
2019-06-28 12:23:14,602 - INFO [ktask]: Loading task [dns]...
2019-06-28 12:23:14,603 - INFO [ktask]: Task [dns] is waiting for [network] to start.
2019-06-28 12:23:14,604 - INFO [ktask]: Loading task [mdns]...
2019-06-28 12:23:14,604 - INFO [ktask]: Task [mdns] is waiting for [diags] to start.
2019-06-28 12:23:14,605 - INFO [ktask]: Loading task [diags]...
2019-06-28 12:23:14,605 - INFO [ktask]: Task [diags] is waiting for [serial] to start.
2019-06-28 12:23:14,606 - INFO [ktask]: Task [nat] is waiting for [serial] to start.
2019-06-28 12:23:16,167 - INFO [ksh]: KiNOS device was found on /dev/ttyACM1!
2019-06-28 12:23:16,168 - INFO [ksh]: Serial device is /dev/ttyACM1.
ttyACM1|> show snum
ttyACM1|> KTWM102-11+201802+8404D200000004A6
ttyACM1|> show snum
ttyACM1|> KTWM102-11+201802+8404D200000004A6
ttyACM1|> show hwconfig
ttyACM1|> USB Interface
ttyACM1|>   Serial       : on
ttyACM1|>   DFU          : on
ttyACM1|>   Ethernet     : on
ttyACM1|> UART Interface : off
ttyACM1|> Activity LED   : on
ttyACM1|> Low-Power Mode : off
2019-06-28 12:23:16,272 - INFO [network]: Trying to obtain a prefix via Prefix Delegation...
2019-06-28 12:23:16,272 - INFO [network]: It was not possible to obtain a global prefix.
2019-06-28 12:23:16,272 - INFO [network]: Generated the ULA prefix fdde:5b57:6035::/48.
2019-06-28 12:23:16,275 - INFO [network]: Using 10.87.130.137 as exterior IPv4 address.
2019-06-28 12:23:16,278 - INFO [ksh]: Waiting until dongle is joined...
2019-06-28 12:23:17,286 - INFO [ksh]: Configure dongle comissioner credential KIRALE.
ttyACM1|> config commcred "KIRALE"
2019-06-28 12:23:17,288 - INFO [ksh]: Set dongle as leader.
ttyACM1|> config role leader
ttyACM1|> ifup
2019-06-28 12:23:17,290 - INFO [ksh]: Waiting until dongle is joined...
2019-06-28 12:23:50,328 - INFO [ksh]: Waiting until dongle becomes router...
ttyACM1|> show role
ttyACM1|> leader
2019-06-28 12:23:50,345 - INFO [ksh]: Waiting until dongle becomes router...
ttyACM1|> show role
ttyACM1|> leader
ttyACM1|> show role
ttyACM1|> leader
ttyACM1|> show status
ttyACM1|> joined
ttyACM1|> show ipaddr
ttyACM1|> [R] fe80::d413:246f:a08f:f07f
ttyACM1|> [R] fd08:1f7f:e7a3:0:f8bf:a281:9c6d:4033
ttyACM1|> [R] fd08:1f7f:e7a3::ff:fe00:9400
ttyACM1|> [R] ff02::1
ttyACM1|> [R] ff03::1
ttyACM1|> [R] ff33:40:fd08:1f7f:e7a3::1
ttyACM1|> [R] ff32:40:fd08:1f7f:e7a3::1
ttyACM1|> [R] ff02::2
ttyACM1|> [R] ff03::2
ttyACM1|> [R] ff03::fc
2019-06-28 12:23:50,456 - INFO [ksh]: EID address is [R] fe80::d413:246f:a08f:f07f.
2019-06-28 12:23:50,456 - INFO [ksh]: EID address is [R] fd08:1f7f:e7a3:0:f8bf:a281:9c6d:4033.
2019-06-28 12:23:50,456 - INFO [ksh]: RLOC address is [R] fd08:1f7f:e7a3::ff:fe00:9400.
2019-06-28 12:23:50,456 - INFO [ksh]: EID address is [R] ff02::1.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff03::1.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff33:40:fd08:1f7f:e7a3::1.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff32:40:fd08:1f7f:e7a3::1.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff02::2.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff03::2.
2019-06-28 12:23:50,457 - INFO [ksh]: EID address is [R] ff03::fc.
ttyACM1|> config brouter on
ttyACM1|> Command not allowed
2019-06-28 12:23:50,465 - INFO [ksh]: Border router has been enabled.
ttyACM1|> config bagent on
2019-06-28 12:23:50,465 - INFO [ksh]: Border router has been enabled.
ttyACM1|> config bagent on
2019-06-28 12:23:50,467 - INFO [ksh]: Border agent has been enabled.
2019-06-28 12:23:50,467 - INFO [ktask]: Task [serial] has now started.
2019-06-28 12:23:50,931 - INFO [ktask]: Task [diags] is waiting for [network] to start.
2019-06-28 12:23:50,999 - INFO [network]: Forwarding has been enabled.
2019-06-28 12:23:51,003 - INFO [network]: DAD has been disabled for enx8404d20004a6.
2019-06-28 12:23:51,007 - INFO [network]: Configuring interior interface enx8404d20004a6 with address 'fd08:1f7f:e7a3::ff:fe00:9400'.
2019-06-28 12:23:51,007 - INFO [network]: Configuring interior interface enx8404d20004a6 with address 'ff03::fc'.
2019-06-28 12:23:51,008 - ERROR [ktask]: Task [network] errored on start
Traceback (most recent call last):
  File "/root/py36env/KiBRA/kibra/ktask.py", line 91, in run
    self.kstart()
  File "/root/py36env/KiBRA/kibra/network.py", line 316, in kstart
    _ifup()
  File "/root/py36env/KiBRA/kibra/network.py", line 194, in _ifup
    IP.addr('add', index=idx, address=addr, prefixlen=64)
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/iproute/linux.py", line 1279, in addr
    terminate=lambda x: x['header']['type'] ==
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 373, in nlm_request
    return tuple(self._genlm_request(*argv, **kwarg))
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 864, in nlm_request
    callback=callback):
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 376, in get
    return tuple(self._genlm_get(*argv, **kwarg))
  File "/root/py36env/lib/python3.6/site-packages/pyroute2/netlink/nlsocket.py", line 701, in get
    raise msg['header']['error']
pyroute2.netlink.exceptions.NetlinkError: (99, 'Cannot assign requested address')
KiraleDev commented 5 years ago

Hi @sjlongland, you are right, the latest KiNOS release includes the addresses status information, but the VM images and master KiBRA branch have not been updated to support the changes.

You could try using the older KiNOS image to verify the functionality.

In any case new releases of KiNOS and KiBRA are expected soon based on the brand new Thread 1.2.0, along with the release of a new Thread Backbone Border Router device with integrated Ethernet.

Due to that reason, Thread 1.1.1 Border Router support is going to be dropped.

KiraleDev commented 5 years ago

@sjlongland for your information, the KTBRN1 has been released: https://www.kirale.com/products/ktbrn1/

This repo has been updated with the new Thread 1.2.0 features and Thread 1.1.1 Border Router and VM support has officially ended now. I'm closing this issue for that reason.