Unable to join the KTBRN1 to an existing Thread (1.1) network

sjlongland commented 5 years ago

Hi,

I'm trying to get the KTBRN1 to join an existing network and become a border router on that network. For this I know the following (not the real values, I know the real ones, I'll use examples here):

Channel: 11
Master Key: 00112233445566778899aabbccddeeff
Network name: OpenThread
Extended PAN ID: dead00beef00cafe
PAN ID: 0x1234

In theory, the documentation says I can set these as defaults in /opt/kirale/kibra.cfg:

{
  "autostart": "1",
  "bbr_seq": "3",
  "dongle_channel": 11,
  "dongle_commcred": "KIRALE",
  "dongle_name": "Test",
  "dongle_netkey": "0x00112233445566778899aabbccddeeff",
  "dongle_netname": "OpenThread",
  "dongle_panid": "0x1234",
  "dongle_serial": "KTWM102-11+201904+8404D20000000769",
  "dongle_sjitter": "120",
  "dongle_xpanid": "0xdead00beef00cafe",
  "mlr_timeout": "3600",
  "prefix": "fd34:fe56:7891:10::/64",
  "prefix_active": "1",
  "prefix_dhcp": "0",
  "prefix_dua": "0",
  "rereg_delay": "6"
}

After editing kibra.cfg, I reboot… I've also tried service kibra restart, both have the same effect: that effect being that with the exception of netkey, all other parameters are ignored:

stuartl@vk4msl-ws:~$ curl http://10.87.144.140/db/cfg
{
  "action_coapserver": "none",
  "action_dhcp": "none",
  "action_diags": "none",
  "action_dns": "none",
  "action_kibra": "none",
  "action_mdns": "none",
  "action_nat": "none",
  "action_network": "none",
  "action_serial": "none",
  "all_network_bbrs": "ff32:40:fd49:6eed:6c21::3",
  "autostart": "1",
  "bagent_port": "49191",
  "bbr_port": "5683",
  "bbr_seq": "3",
  "bbr_status": "secondary",
  "bridging_mark": "3523217257",
  "bridging_table": "84:04:D2:00:07:69",
  "coap_req": "",
  "discovered": "0",
  "dongle_channel": "24", // *NOT* 11 as requested
  "dongle_commcred": "KIRALE",
  "dongle_heui64": "ff-23-8a-22-6a-0e-7d-7f",
  "dongle_ll": "fe80::604f:4eeb:4ad7:b6f3",
  "dongle_mac": "86:04:d2:00:07:69",
  "dongle_mleid": "fd49:6eed:6c21:0:2b1:f805:5603:5c13",
  "dongle_name": "Test",
  "dongle_netkey": "0x00112233445566778899aabbccddeeff", // This is correct
  "dongle_netname": "kite_cdc9", // *NOT* OpenThread as requested
  "dongle_panid": "0x931e", // *NOT* 0x1234 as requested
  "dongle_prefix": "fd49:6eed:6c21::/64",
  "dongle_rloc": "fd49:6eed:6c21::ff:fe00:5c00",
  "dongle_role": "leader",
  "dongle_secpol": "02a0ff00",
  "dongle_serial": "KTWM102-11+201904+8404D20000000769",
  "dongle_sjitter": "120",
  "dongle_status": "joined",
  "dongle_xpanid": "0x590c555821949d00", // *NOT* 0xdead00beef00cafe as requested
  "dua_next_status": "",
  "exterior_ifname": "eth0",
  "exterior_ifnumber": "3",
  "exterior_ipv4": "10.87.144.140",
  "exterior_ipv6_ll": "fe80::81:deff:fecc:d71",
  "exterior_mac": "02:81:de:cc:0d:71",
  "exterior_port_mc": "49191",
  "interior_ifname": "enx8404d2000769",
  "interior_ifnumber": "5",
  "interior_mac": "84:04:D2:00:07:69",
  "kibra_model": "KTBRN1",
  "kibra_vendor": "Kirale",
  "kibra_version": "KiBRA v1.3.0",
  "mcast_admin_fwd": "1",
  "mcast_out_fwd": "1",
  "mlr_timeout": "3600",
  "prefix": "fd34:fe56:7891:10::/64",
  "prefix_active": "1",
  "prefix_dhcp": "0",
  "prefix_dua": "0",
  "rereg_delay": "6",
  "serial_device": "/dev/ttyACM0",
  "status_coapserver": "running",
  "status_dhcp": "running",
  "status_diags": "running",
  "status_dns": "running",
  "status_kibra": "running",
  "status_mdns": "running",
  "status_nat": "running",
  "status_network": "running",
  "status_serial": "running"
}

Is there some other trick needed to make it use the settings as given?

KiraleDev commented 5 years ago

Hi @sjlongland,

Several things:

KiNOS devices are able to join a network in two different manners: via Thread Commissioning or out of band. The Commissioning method is recommended, but if OOB is desired, more parameters have to be configured (see config outband section in Kirale Command-Line Shell Reference Guide). This translates to the following kibra.cfg parameters: dongle_outband, dongle_channel, dongle_panid, dongle_netname, dongle_prefix, dongle_netkey, dongle_xpanid and dongle_commcred.
Even if a set of out of band parameters is provided, KiBRA is designed not to reset the NCP configuration on start. This allows the NCP to still be part of the network even when Linux services are restarted, for example. This means that in case some configuration has already been applied to the NCP, it has to be reset before applying a new one via KiBRA. This can be achieved this way:
```
root@KTBRN1:~# service kibra stop
root@KTBRN1:~# cd /opt/kibra/pyenv
root@KTBRN1:~# source bin/activate
root@KTBRN1:~# python -m kitools
KSH@ttyACM0> clear
KSH@ttyACM0> ^C
```
I notice you are running KiBRA v1.3.0. The KiBRA v1.3.2, which fixes a few issues, is already available in our website.

Please let me know if you require some further help.

sjlongland commented 5 years ago

Hi, much appreciated… that gets me a little closer, although I note it still fails to configure the dongle:

2019-08-26 09:49:03,411 - INFO [ksh]: Waiting until dongle is joined...
2019-08-26 09:49:03,412 - INFO [ksh]: show status
2019-08-26 09:49:03,420 - INFO [ksh]: none
2019-08-26 09:49:04,422 - INFO [ksh]: config outband
2019-08-26 09:49:04,426 - INFO [ksh]: 
2019-08-26 09:49:04,427 - INFO [ksh]: config xpanid 0xdead00beef00cafe
2019-08-26 09:49:04,430 - INFO [ksh]: 
2019-08-26 09:49:04,431 - INFO [ksh]: config mkey 0x00112233445566778899aabbccddeeff
2019-08-26 09:49:04,434 - INFO [ksh]: 
2019-08-26 09:49:04,436 - INFO [ksh]: config sjitter 120
2019-08-26 09:49:04,441 - INFO [ksh]: Invalid syntax
2019-08-26 09:49:04,442 - INFO [ksh]: Configure dongle channel 11.
2019-08-26 09:49:04,443 - INFO [ksh]: config channel 11

It doesn't seem to like the sjitter parameter… the Kirale CLI reference doesn't tell me what this is, and removing it from the .cnf file does not help. I'll give the update to 1.3.2 a try in a moment. :-)

sjlongland commented 5 years ago

Seems version 1.3.2 does the exact same thing, sends a config sjitter 120 instruction which the embedded radio device does not understand.

KiraleDev commented 5 years ago

You can ignore that error. It's a parameter used in the Thread Harness, it's simply not being configured but shouldn't harm. What's the rest of the logs? Did the device complete the attaching process?

sjlongland commented 5 years ago

Ahh okay, yes, I'm familiar with that behemoth. :-)

^M2019-08-26 10:15:16,510 - INFO [ksh]: config xpanid 0xdead00beef00cafe
^M2019-08-26 10:15:16,513 - INFO [ksh]: 
^M2019-08-26 10:15:16,514 - INFO [ksh]: config mkey 0x00112233445566778899aabbccddeeff
^M2019-08-26 10:15:16,517 - INFO [ksh]: 
^M2019-08-26 10:15:16,518 - INFO [ksh]: config sjitter 120
^M2019-08-26 10:15:16,526 - INFO [ksh]: Invalid syntax
^M2019-08-26 10:15:16,527 - INFO [ksh]: Configure dongle channel 11.
^M2019-08-26 10:15:16,528 - INFO [ksh]: config channel 11
^M2019-08-26 10:15:16,530 - INFO [ksh]: 
^M2019-08-26 10:15:16,531 - INFO [ksh]: Configure dongle panid 0xd6ab.
^M2019-08-26 10:15:16,532 - INFO [ksh]: config panid 0x1234
^M2019-08-26 10:15:16,534 - INFO [ksh]: 
^M2019-08-26 10:15:16,535 - INFO [ksh]: Configure dongle network name OpenThread.
^M2019-08-26 10:15:16,536 - INFO [ksh]: config netname "OpenThread"
^M2019-08-26 10:15:16,538 - INFO [ksh]: 
^M2019-08-26 10:15:16,539 - INFO [ksh]: Configure dongle comissioner credential KIRALE.
^M2019-08-26 10:15:16,540 - INFO [ksh]: config commcred "KIRALE"
^M2019-08-26 10:15:16,542 - INFO [ksh]: 
^M2019-08-26 10:15:16,543 - INFO [ksh]: Set dongle as leader.
^M2019-08-26 10:15:16,544 - INFO [ksh]: config role leader
^M2019-08-26 10:15:16,546 - INFO [ksh]: 
^M2019-08-26 10:15:16,547 - INFO [ksh]: config brouter on
^M2019-08-26 10:15:16,549 - INFO [ksh]: 
^M2019-08-26 10:15:16,550 - INFO [ksh]: Border router has been enabled.
^M2019-08-26 10:15:16,551 - INFO [ksh]: ifup
^M2019-08-26 10:15:16,556 - INFO [ksh]: Configuration settings missing
^M2019-08-26 10:15:16,557 - INFO [ksh]: show status
^M2019-08-26 10:15:16,566 - INFO [ksh]: none
^M2019-08-26 10:15:16,567 - INFO [ksh]: Waiting until dongle is joined...
^M2019-08-26 10:15:16,568 - INFO [ksh]: show status
^M2019-08-26 10:15:16,576 - INFO [ksh]: none

Those are the last few logs (with actual network credentials replaced with the OpenThread defaults). ip addr shows:

5: enx8404d2000769: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1280 qdisc pfifo_fast state UNKNOWN group default qlen 5000
    link/ether 84:04:d2:00:07:69 brd ff:ff:ff:ff:ff:ff
    inet6 fd49:6eed:6c21:0:2b1:f805:5603:5c13/64 scope global 
       valid_lft forever preferred_lft forever
    inet6 fd49:6eed:6c21::ff:fe00:5c00/64 scope global 
       valid_lft forever preferred_lft forever
    inet6 fe80::8604:d2ff:fe00:769/64 scope link 
       valid_lft forever preferred_lft forever

…which doesn't look like any of the IP addresses currently being deployed on the mesh, so I guess not.

I'll try shutting down some of the nodes temporarily and see if it will connect to a smaller network. The other nodes are CC2538s running OpenThread with CC2592 PA/LNA front-ends; I've turned them down to 8dBm (from their maximum of 22dBm), however it could be the sheer number and amount of chatter (they're all downloading firmware updates via CoAP block-wise transfer) is preventing the KTBRN1 from connecting.

KiraleDev commented 5 years ago

One more parameter missing: since you don't want to create a new network, but join an existing one, you should override the default Leader role:

"dongle_role": "router",

KiraleDev commented 5 years ago

And it seems some out of band parameter is still missing:

^M2019-08-26 10:15:16,556 - INFO [ksh]: Configuration settings missing

sjlongland commented 5 years ago

On 26/8/19 9:19 pm, Kirale Developer wrote:

One more parameter missing: since you don't want to create a new network, but join an existing one, you should override the default Leader role:

|"dongle_role": "router",|

It doesn't seem to like that either:

2019-08-26 11:23:44,818 - INFO [ksh]: Set dongle as router.
2019-08-26 11:23:44,819 - INFO [ksh]: config role router
2019-08-26 11:23:44,827 - INFO [ksh]: Invalid parameter
2019-08-26 11:23:44,828 - INFO [ksh]: config brouter on

but I'll leave it sit overnight and see how it is in the morning. :-) -- Stuart Longland (aka Redhatter, VK4MSL)

I haven't lost my mind... ...it's backed up on a tape somewhere.

KiraleDev commented 5 years ago

Sorry, my fault, the configuration role is reed, not router.

"dongle_role": "reed",

sjlongland commented 5 years ago

And it seems some out of band parameter is still missing

I specified the channel, network name, master key, PAN ID and extended PAN ID… that's all that's needed to connect. Everything else is derived from those parameters.

sjlongland commented 5 years ago

So… reading the documentation:

If the out-of-band commissioning mode is set, a set of parameters have to be configured before attaching. So they are channel (i.e. config channel),

Configured as 11…

PAN ID (i.e. config panid),

Configured as 0x1234

network name (i.e. config netname),

Set as OpenThread

mesh local prefix (i.e. config mlprefix),

This is derived from the xpanid: https://github.com/openthread/openthread/blob/master/src/core/thread/mle.cpp#L162-L166… which is given

master key (i.e. config mkey),

This was given as 0x00112233445566778899aabbccddeeff

extended PAN ID (i.e. config xpanid)

This was provided as 0xdead00beef00cafe

and commissioning credential (i.e. config commcred).

I didn't provide this, but it's only needed for commissioning new devices which I am not doing; in any case KiBRA has supplied its own value here.

Given the above, what's missing?

sjlongland commented 5 years ago

If I manually derive mlprefix, and specify that as dongle_mlprefix, it seems KiBRA ignores this setting and tries to bring the interface up anyway. I have to use kitools to set it manually, then I can start KiBRA.

I'm now able to ping devices on the mesh network, but haven't seen the border router acquire a off-mesh prefix IP. I'll work at getting the border router VPNing to the cloud server and see how I go there.

sjlongland commented 5 years ago

The stack traces at the end are worrying…

2019-08-27 04:26:56,551 - INFO [ksh]: Configure dongle comissioner credential KIRALE.
2019-08-27 04:26:56,552 - INFO [ksh]: config commcred "KIRALE"
2019-08-27 04:26:56,554 - INFO [ksh]:
2019-08-27 04:26:56,554 - INFO [ksh]: Set dongle as reed.
2019-08-27 04:26:56,555 - INFO [ksh]: config role reed
2019-08-27 04:26:56,557 - INFO [ksh]:
2019-08-27 04:26:56,557 - INFO [ksh]: config brouter on
2019-08-27 04:26:56,559 - INFO [ksh]:
2019-08-27 04:26:56,559 - INFO [ksh]: Border router has been enabled.
2019-08-27 04:26:56,560 - INFO [ksh]: ifup
2019-08-27 04:26:56,562 - INFO [ksh]:
2019-08-27 04:26:56,562 - INFO [ksh]: show status
2019-08-27 04:26:59,359 - INFO [ksh]: booting
2019-08-27 04:26:59,361 - INFO [ksh]: Waiting until dongle is joined...
2019-08-27 04:26:59,362 - INFO [ksh]: show status
2019-08-27 04:26:59,365 - INFO [ksh]: attaching
2019-08-27 04:27:00,367 - INFO [ksh]: show status
2019-08-27 04:27:00,379 - INFO [ksh]: attaching
2019-08-27 04:27:01,381 - INFO [ksh]: show status
2019-08-27 04:27:01,384 - INFO [ksh]: joined
2019-08-27 04:27:02,386 - INFO [ksh]: show role
2019-08-27 04:27:02,401 - INFO [ksh]: leader
2019-08-27 04:27:02,402 - INFO [ksh]: show status
2019-08-27 04:27:02,405 - INFO [ksh]: joined
2019-08-27 04:27:02,406 - INFO [ksh]: show heui64
2019-08-27 04:27:02,411 - INFO [ksh]: ff-23-8a-22-6a-0e-7d-7f
2019-08-27 04:27:02,412 - INFO [ksh]: show ipaddr
2019-08-27 04:27:02,421 - INFO [ksh]: [R] fe80::a084:995:3b8e:8ff0
[R] fdde:ad00:beef:0:f69f:e8c4:4912:b5bf
[R] fdde:ad00:beef::ff:fe00:6000
[R] ff02::1
[R] ff03::1
[R] ff33:40:fdde:ad00:beef::1
[R] ff32:40:fdde:ad00:beef::1
[R] ff02::2
[R] ff03::2
[R] ff03::fc
2019-08-27 04:27:02,423 - INFO [ksh]: Link local address is fe80::a084:995:3b8e:8ff0.
2019-08-27 04:27:02,424 - INFO [ksh]: EID address is fdde:ad00:beef:0:f69f:e8c4:4912:b5bf.
2019-08-27 04:27:02,425 - INFO [ksh]: RLOC address is fdde:ad00:beef::ff:fe00:6000.
2019-08-27 04:27:02,426 - INFO [ksh]: config bagent on
2019-08-27 04:27:02,429 - INFO [ksh]:
2019-08-27 04:27:02,430 - INFO [ksh]: Border agent has been enabled.
2019-08-27 04:27:02,431 - INFO [ktask]: Task [serial] has now started.
2019-08-27 04:27:02,432 - INFO [ktask]: Loading task [network]...
2019-08-27 04:27:02,433 - INFO [ktask]: Task [network] is waiting for [serial] to start.
2019-08-27 04:27:02,435 - INFO [shell]: echo 1 > /proc/sys/net/ipv4/conf/all/forwarding
2019-08-27 04:27:02,460 - INFO [shell]: echo 1 > /proc/sys/net/ipv6/conf/all/forwarding
2019-08-27 04:27:02,483 - INFO [network]: Forwarding has been enabled.
2019-08-27 04:27:02,485 - INFO [shell]: echo 0 > /proc/sys/net/ipv6/conf/enx8404d2000769/accept_dad
2019-08-27 04:27:02,508 - INFO [network]: DAD has been disabled for enx8404d2000769.
2019-08-27 04:27:02,510 - INFO [shell]: echo 65536 > /proc/sys/net/core/optmem_max
2019-08-27 04:27:02,546 - INFO [network]: Configuring interior interface enx8404d2000769 with address fdde:ad00:beef::ff:fe00:6000.
2019-08-27 04:27:02,553 - INFO [network]: Configuring interior interface enx8404d2000769 with address fdde:ad00:beef:0:f69f:e8c4:4912:b5bf.
2019-08-27 04:27:02,594 - INFO [network]: Traffic rate limit established to 125 kbps on interface enx8404d2000769.
2019-08-27 04:27:02,595 - INFO [shell]: tc qdisc add dev enx8404d2000769 root handle 1: cbq avpkt 1000 bandwidth 12mbit
2019-08-27 04:27:02,654 - INFO [shell]: tc class add dev enx8404d2000769 parent 1: classid 1:1 cbq rate 125kbit allot 1500 prio 5 bounded isolated
2019-08-27 04:27:02,674 - INFO [shell]: tc filter add dev enx8404d2000769 parent 1: protocol ipv6 prio 16 u32 match ip6 dst ::/0 flowid 1:1
2019-08-27 04:27:02,711 - INFO [iptables]: Adding ip6tables general rules.
2019-08-27 04:27:02,712 - INFO [shell]: ip6tables -F -t mangle
2019-08-27 04:27:02,749 - INFO [shell]: ip6tables -F -t nat
2019-08-27 04:27:02,785 - INFO [shell]: ip6tables -F -t filter
2019-08-27 04:27:02,817 - INFO [shell]: ip6tables -w -t filter -A INPUT -i eth0 -d ff00::/8 -p icmpv6 --icmpv6-type echo-request -j DROP
2019-08-27 04:27:02,837 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -m length --length 1281:0xffff -j REJECT
2019-08-27 04:27:02,857 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p icmpv6 --icmpv6-type neighbor-solicitation -j ACCEPT
2019-08-27 04:27:02,877 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p icmpv6 --icmpv6-type echo-request -j ACCEPT
2019-08-27 04:27:02,898 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --sport 5683 -j ACCEPT
2019-08-27 04:27:02,920 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --dport 5683 -j ACCEPT
2019-08-27 04:27:02,941 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --sport 61631 -j ACCEPT
2019-08-27 04:27:02,962 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --dport 61631 -j ACCEPT
2019-08-27 04:27:02,984 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --dport dhcpv6-client -j ACCEPT
2019-08-27 04:27:03,008 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --sport 123 -j ACCEPT
2019-08-27 04:27:03,030 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -p udp --sport 53 -j ACCEPT
2019-08-27 04:27:03,052 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o enx8404d2000769 -j DROP
2019-08-27 04:27:03,071 - INFO [shell]: ip6tables -w -t filter -A OUTPUT -o eth0 -p ipv6 -d fd34:fe56:7891:10::/64 -j DROP
2019-08-27 04:27:03,091 - INFO [shell]: ip6tables -w -t filter -A FORWARD -o enx8404d2000769 -m length --length 1281:0xffff -j REJECT
2019-08-27 04:27:03,111 - INFO [shell]: ip6tables -w -t filter -A FORWARD -m mark --mark "3523217257" -j ACCEPT
2019-08-27 04:27:03,131 - INFO [shell]: ip6tables -w -t filter -A FORWARD -p icmpv6 --icmpv6-type echo-request -d fd34:fe56:7891:10::/64 -j ACCEPT
2019-08-27 04:27:03,152 - INFO [shell]: ip6tables -w -t filter -A FORWARD -p icmpv6 --icmpv6-type echo-reply -s fd34:fe56:7891:10::/64 -j ACCEPT
2019-08-27 04:27:03,173 - INFO [shell]: ip6tables -w -t filter -A FORWARD -p udp -m state --state ESTABLISHED -j ACCEPT
2019-08-27 04:27:03,196 - INFO [shell]: ip6tables -w -t filter -A FORWARD -p icmpv6 -m state --state ESTABLISHED,RELATED -j ACCEPT
2019-08-27 04:27:03,218 - INFO [shell]: ip6tables -w -t filter -A FORWARD -d fd34:fe56:7891:10::/64 -j DROP
2019-08-27 04:27:03,237 - INFO [iptables]: Redirecting MM port traffic to interior interface.
2019-08-27 04:27:03,239 - INFO [shell]: ip6tables -w -t mangle -I OUTPUT -o lo -d fdde:ad00:beef::ff:fe00:6000 -p udp --dport 61631 -j MARK --set-mark "3523217257"
2019-08-27 04:27:03,260 - INFO [ktask]: Task [network] has now started.
2019-08-27 04:27:03,262 - INFO [ktask]: Loading task [dhcp]...
2019-08-27 04:27:03,263 - INFO [ktask]: Task [dhcp] is waiting for [network] to start.
2019-08-27 04:27:03,263 - INFO [ktask]: Task [dhcp] is waiting for [serial] to start.
2019-08-27 04:27:03,264 - INFO [ktask]: Task [dhcp] has now started.
2019-08-27 04:27:03,265 - INFO [ktask]: Loading task [nat]...
2019-08-27 04:27:03,266 - INFO [ktask]: Task [nat] is waiting for [serial] to start.
2019-08-27 04:27:03,266 - INFO [ktask]: Task [nat] has now started.
2019-08-27 04:27:03,267 - INFO [ktask]: Loading task [dns]...
2019-08-27 04:27:03,268 - INFO [ktask]: Task [dns] is waiting for [network] to start.
2019-08-27 04:27:03,268 - INFO [ktask]: Task [dns] is waiting for [serial] to start.
2019-08-27 04:27:03,269 - INFO [ktask]: Task [dns] is waiting for [nat] to start.
2019-08-27 04:27:03,269 - INFO [ktask]: Task [dns] has now started.
2019-08-27 04:27:03,270 - INFO [ktask]: Loading task [mdns]...
2019-08-27 04:27:03,270 - INFO [mdns]: Configuring Avahi daemon.
2019-08-27 04:27:03,276 - INFO [shell]: service avahi-daemon reload
2019-08-27 04:27:03,395 - INFO [mdns]: mDNS service updated.
2019-08-27 04:27:03,396 - INFO [ktask]: Task [mdns] has now started.
2019-08-27 04:27:03,398 - INFO [ktask]: Loading task [diags]...
2019-08-27 04:27:03,399 - INFO [ktask]: Task [diags] is waiting for [serial] to start.
2019-08-27 04:27:03,400 - INFO [ktask]: Task [diags] is waiting for [network] to start.
2019-08-27 04:27:03,401 - INFO [ktask]: Task [diags] has now started.
2019-08-27 04:27:03,402 - INFO [ktask]: Loading task [coapserver]...
2019-08-27 04:27:03,403 - INFO [ktask]: Task [coapserver] is waiting for [serial] to start.
2019-08-27 04:27:03,404 - INFO [ktask]: Task [coapserver] is waiting for [network] to start.
2019-08-27 04:27:03,404 - INFO [ktask]: Task [coapserver] is waiting for [diags] to start.
2019-08-27 04:27:03,406 - INFO [mdns]: Enabling Border Agent NAT.
2019-08-27 04:27:03,407 - INFO [shell]: jool bib add 10.87.144.140#49191 fdde:ad00:beef::ff:fe00:6000#49191 --udp
2019-08-27 04:27:03,424 - INFO [shell]: iptables -w -t mangle -I PREROUTING -i eth0 -d 10.87.144.140 -p udp --dport 49191 -j MARK --set-mark 3523217257
2019-08-27 04:27:03,446 - INFO [shell]: ip6tables -w -t nat -I PREROUTING -i eth0 -d fe80::81:deff:fecc:d71 -p udp --dport 49191 -j DNAT --to [fdde:ad00:beef::ff:fe00:6000]:49191
2019-08-27 04:27:03,468 - INFO [shell]: ip6tables -w -t nat -I POSTROUTING -o eth0 -s fdde:ad00:beef::ff:fe00:6000 -p udp --sport 49191 -j SNAT --to [fe80::81:deff:fecc:d71]:49191
2019-08-27 04:27:03,491 - INFO [shell]: ip6tables -w -t mangle -I PREROUTING -i eth0 -d fe80::81:deff:fecc:d71 -p udp --dport 49191 -j MARK --set-mark 3523217257
2019-08-27 04:27:04,443 - INFO [ksh]: config prefix add fd34:fe56:7891:10:: 64 0x1301
2019-08-27 04:27:04,453 - INFO [ksh]: Command not allowed
2019-08-27 04:27:04,454 - INFO [ksh]: Config prefix add fd34:fe56:7891:10::/64
2019-08-27 04:27:04,457 - INFO [ksh]: config service add 44970 01 04000600000e10
2019-08-27 04:27:04,463 - INFO [ksh]: Command not allowed
2019-08-27 04:27:04,464 - INFO [ksh]: BBR update: Seq. = 4 MLR Timeout = 3600, Rereg. Delay = 6
2019-08-27 04:27:05,399 - INFO [mdns]: Enabling Border Agent NAT.
2019-08-27 04:27:05,400 - INFO [shell]: jool bib add 10.87.144.140#49191 fdde:ad00:beef::ff:fe00:6000#49191 --udp
2019-08-27 04:27:05,438 - INFO [shell]: iptables -w -t mangle -I PREROUTING -i eth0 -d 10.87.144.140 -p udp --dport 49191 -j MARK --set-mark 3523217257
2019-08-27 04:27:05,483 - INFO [shell]: ip6tables -w -t nat -I PREROUTING -i eth0 -d fe80::81:deff:fecc:d71 -p udp --dport 49191 -j DNAT --to [fdde:ad00:beef::ff:fe00:6000]:49191
2019-08-27 04:27:05,531 - INFO [shell]: ip6tables -w -t nat -I POSTROUTING -o eth0 -s fdde:ad00:beef::ff:fe00:6000 -p udp --sport 49191 -j SNAT --to [fe80::81:deff:fecc:d71]:49191
2019-08-27 04:27:05,578 - INFO [shell]: ip6tables -w -t mangle -I PREROUTING -i eth0 -d fe80::81:deff:fecc:d71 -p udp --dport 49191 -j MARK --set-mark 3523217257
2019-08-27 04:27:05,631 - INFO [shell]: service avahi-daemon reload
2019-08-27 04:27:05,777 - INFO [mdns]: mDNS service updated.
2019-08-27 04:27:06,269 - INFO [shell]: /sbin/modprobe jool
2019-08-27 04:27:06,291 - INFO [shell]: jool instance display
2019-08-27 04:27:06,308 - INFO [shell]: +--------------------+-----------------+-----------+
|          Namespace |            Name | Framework |
+--------------------+-----------------+-----------+
|         0xc0ed0200 |         default | netfilter |
+--------------------+-----------------+-----------+
2019-08-27 04:27:06,310 - INFO [nat]: Prefix 64:ff9b::/96 added to NAT64 engine.
2019-08-27 04:27:06,310 - INFO [shell]: jool pool4 add --udp 10.87.144.140
2019-08-27 04:27:06,327 - INFO [shell]: jool pool4 add --icmp 10.87.144.140
2019-08-27 04:27:06,344 - INFO [nat]: 10.87.144.140 used as stateful NAT64 masking address.
2019-08-27 04:27:06,848 - INFO [protocol]: Retransmission, Message ID: 17074.
2019-08-27 04:27:11,613 - INFO [protocol]: Retransmission, Message ID: 17074.
2019-08-27 04:27:21,142 - INFO [protocol]: Retransmission, Message ID: 17074.
2019-08-27 04:27:40,195 - INFO [protocol]: Retransmission, Message ID: 17074.
2019-08-27 04:27:40,209 - INFO [diags]: New node! "405a"
2019-08-27 04:27:40,226 - INFO [diags]: Setting this BBR as Secondary
2019-08-27 04:27:40,857 - INFO [coapserver]: Starting DUA handler
2019-08-27 04:27:40,872 - INFO [coapserver]: Starting Multicast handler
2019-08-27 04:27:40,899 - INFO [coapserver]: Joining All Network BBRs group: ff32:40:fdde:ad00:beef::3
2019-08-27 04:27:40,906 - INFO [iptables]: Blocking local traffic to ff32:40:fdde:ad00:beef::3
2019-08-27 04:27:40,907 - INFO [shell]: ip6tables -w -t filter -I INPUT -s fe80::81:deff:fecc:d71 -d ff32:40:fdde:ad00:beef::3 -j DROP
2019-08-27 04:27:40,960 - INFO [coapserver]: Launching CoAP Servers in MM port
2019-08-27 04:27:40,965 - INFO [coapserver]: Launching CoAP Servers in BB port
2019-08-27 04:27:40,968 - INFO [ktask]: Task [coapserver] has now started.
2019-08-27 04:27:40,974 - INFO [__main__]: All tasks have now started.
2019-08-27 04:27:41,858 - INFO [shell]: service avahi-daemon reload
2019-08-27 04:27:41,979 - INFO [mdns]: mDNS service updated.
2019-08-27 04:27:42,253 - ERROR [base_events]: Future exception was never retrieved
future: <Future finished exception=timeout('timed out')>
Traceback (most recent call last):
  File "/usr/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/opt/kirale/pyenv/lib/python3.7/site-packages/kibra/ndproxy.py", line 127, in run_daemon
    data, src = self.icmp6_sock.recvfrom(1280)
socket.timeout: timed out
2019-08-27 04:27:42,260 - ERROR [base_events]: Future exception was never retrieved
future: <Future finished exception=timeout('timed out')>
Traceback (most recent call last):
  File "/usr/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/opt/kirale/pyenv/lib/python3.7/site-packages/kibra/mcrouter.py", line 118, in run_daemon
    data = self.mc6r_sock.recv(1280)
socket.timeout: timed out

KiraleDev commented 5 years ago

@sjlongland as I mentioned before this full list of parameters is required by KiNOS stack to skip Thread Commissioning and attach to an existing network: dongle_outband, dongle_channel, dongle_panid, dongle_netname, dongle_prefix, dongle_netkey, dongle_xpanid and dongle_commcred.

Please try this:

{
  "autostart": "1",
  "dongle_channel": "11",
  "dongle_commcred": "THREAD",
  "dongle_netkey": "0x00112233445566778899aabbccddeeff",
  "dongle_netname": "OpenThread",
  "dongle_outband": "1",
  "dongle_panid": "0x1234",
  "dongle_prefix": "fd00:db8::", <-- replace it by the existing in your network
  "dongle_role": "reed",
  "dongle_xpanid": "0xdead00beef00cafe"
}

And don't forget to reset the NCP before launching KiBRA with the new parameters:

root@KTBRN1:~# service kibra stop
root@KTBRN1:~# /opt/kibra/pyenv/bin/python -m kitools
KSH@ttyACM0> clear
KSH@ttyACM0> ^C
root@KTBRN1:~# nano /opt/kirale/kibra.cfg
root@KTBRN1:~# service kibra start

We'll fix the socket timeout exception in the next KiBRA release.

KiraleDev commented 5 years ago

Regarding Mesh-Local prefix, Thread Specification says this: Mesh-Local Prefix is an IPv6 Unique Local Address (ULA) prefix used for communication within the Thread Network. The value of the prefix MUST be generated according to IPv6 prefix format described in section 3 of RFC 4193. We do not know how OpenThread handles this but in case of KiNOS, it must be set up when you use out-of-band commissioning method.

KiraleDev commented 5 years ago

@sjlongland please make use of the new released KiBRA 1.4.0 which solves some issues and introduces new enhancements.

Notice that some configuration parameters have been renamed (e.g.: dongle_channel to ncp_channel).

KiraleDev commented 4 years ago

Closing issue due to inactivity.

KiraleTech / KiBRA

Unable to join the KTBRN1 to an existing Thread (1.1) network #6