• State Verified Answer
  • Replies 19 replies
  • Answers 1 answer
  • Subscribers 74 subscribers
  • Views 4802 views
  • Users 0 members are here
Attachments (0)
Nordic Case Info
  • Case ID: 251819
Options
This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

Losing connection with Thread CoAP Google Cloud example

thread_yoda

Dear Nordic Support Team,

I haven't seen any forum posts directly applicable to the issue I'm seeing so I hope you can point me in the right direction.

The basic Thread CoAP Google Cloud example has been working fine, but I noticed a couple of peculiarities. I'm a still using the Thread SDK v4.0.0 as I didn't see there were specific items in the 4.1.0 SDK release to address any of these issues. 

1) The first issue is that when I leave the network on for some period of time, it seems to not be able to send DTLS application data packets anymore. For example, I would press the buttons to try and increment or decrement the count, but I only see MAC level exchanges. I can see from the sniffer that there are no "DTLS Application Data" exchanges. 

In order to reconnect I have to power cycle the Thread FTD. It then re-establishes the DTLS connection, then everything is back to normal. How I can I avoid having to do this periodically?

2) The second issue is that the network does not seem to recover from a power cycle of the border router. This happens when I have the network unplugged for quite some time. My expectation is that the network should resume from where it left off, but that has not been my experience. I have to re-form the border router using the OTBR web interface, then do a re-flash of the FTD to let it join again. At this point, the network is back and works as per normal.

How can I solve these two issues.

Thanks for your help in advance.

Parents
  • 0

    Hi,

    When you say Thread FTD, are you referring to the NCP device connected to the border router, the CoAP Google Cloud device, or some other device in the network?

    Can you check the wpantund status ('sudo wpanctl status') on the border router when both these issues occur? Can you also post the output of 'ipaddr' and 'router table' commands on a CLI node in the network (CLI should also be enabled in the CoAP Google Cloud example), and the 'ifconfig' output from the border router? (you can remove/hide any global IPv6 addresses for privacy reasons)

    You can also check the syslog of the border router (step 3 in this section, remove the '| grep ot-cli-ftd' part of the command), to see if anything can give you a clue to what is causing the issues.

    Best regards,
    Jørgen

  • 0 in reply to Jørgen Holmefjord

    border router ifconfig outputborder router wpanctl statusUbiqua sniffer outputFTD ipaddr and router table output

    Here are the various output that you requested. I could not attach the syslog as a file to the web portal so here it is: 

    Jun 23 06:25:02 raspberrypi liblogging-stdlog: [origin software="rsyslogd" swVersion="8.24.0" x-pid="336" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
    Jun 23 06:32:44 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
    Jun 23 06:32:45 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
    Jun 23 06:32:45 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 28min 37.530978s random time.
    Jun 23 06:32:45 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 18min 51.275962s random time.
    Jun 23 06:39:03 raspberrypi dhclient[1612]: DHCPREQUEST of 10.200.242.104 on eth0 to 10.200.242.135 port 67
    Jun 23 06:39:03 raspberrypi dhclient[1612]: DHCPACK of 10.200.242.104 from 10.200.242.135
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7534] dhcp4 (eth0): address 10.200.242.104
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7536] dhcp4 (eth0): plen 24 (255.255.255.0)
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7537] dhcp4 (eth0): gateway 10.200.242.135
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7538] dhcp4 (eth0): server identifier 10.200.242.135
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7538] dhcp4 (eth0): lease time 86400
    Jun 23 06:39:03 raspberrypi dbus[363]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7539] dhcp4 (eth0): hostname 'raspberrypi'
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7540] dhcp4 (eth0): nameserver '10.200.242.135'
    Jun 23 06:39:03 raspberrypi NetworkManager[382]: <info> [1592894343.7541] dhcp4 (eth0): state changed bound -> bound
    Jun 23 06:39:03 raspberrypi systemd[1]: Starting Network Manager Script Dispatcher Service...
    Jun 23 06:39:03 raspberrypi dhclient[1612]: bound to 10.200.242.104 -- renewal in 32596 seconds.
    Jun 23 06:39:03 raspberrypi dbus[363]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
    Jun 23 06:39:03 raspberrypi systemd[1]: Started Network Manager Script Dispatcher Service.
    Jun 23 06:39:03 raspberrypi nm-dispatcher: req:1 'dhcp4-change' [eth0]: new request (3 scripts)
    Jun 23 06:39:03 raspberrypi nm-dispatcher: req:1 'dhcp4-change' [eth0]: start running ordered scripts...
    Jun 23 06:39:03 raspberrypi ap-helper[19465]: Unsupported action: 'dhcp4-change'
    Jun 23 06:39:03 raspberrypi dhcpv6-helper[19467]: Unsupported action: 'dhcp4-change'
    Jun 23 07:17:01 raspberrypi CRON[19489]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 08:17:01 raspberrypi CRON[19527]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 09:17:01 raspberrypi CRON[19567]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 10:17:01 raspberrypi CRON[19605]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 11:17:01 raspberrypi CRON[19645]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 050630.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 052132.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 053634.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 055136.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 060638.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 062140.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 063642.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 065144.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 070646.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 072148.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 073650.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 075152.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 080654.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 082156.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 083658.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 085200.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 090702.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 092204.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 093706.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 095208.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 100710.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 102212.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 103714.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 105216.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 110718.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 112220.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 11:52:24 raspberrypi MQTT-SNGateway[1523]: 20200623 113722.000 #033[0m#033[0;33mADVERTISE #033[0m#033[0;37m---> #033[0m#033[0;32mClients #033[0m#033[0;34m 05 00 01 03 84#033[0m#033[0;37m
    Jun 23 12:17:01 raspberrypi CRON[19685]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 13:17:01 raspberrypi CRON[19724]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 13:49:58 raspberrypi systemd[1]: Starting Daily apt download activities...
    Jun 23 13:50:00 raspberrypi systemd[1]: Started Daily apt download activities.
    Jun 23 13:50:00 raspberrypi systemd[1]: apt-daily.timer: Adding 5h 30min 59.960197s random time.
    Jun 23 13:50:00 raspberrypi systemd[1]: apt-daily.timer: Adding 6h 28min 40.323674s random time.
    Jun 23 14:17:01 raspberrypi CRON[19808]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 15:17:01 raspberrypi CRON[19847]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 15:42:19 raspberrypi dhclient[1612]: DHCPREQUEST of 10.200.242.104 on eth0 to 10.200.242.135 port 67
    Jun 23 15:42:19 raspberrypi dhclient[1612]: DHCPACK of 10.200.242.104 from 10.200.242.135
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2025] dhcp4 (eth0): address 10.200.242.104
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2027] dhcp4 (eth0): plen 24 (255.255.255.0)
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2028] dhcp4 (eth0): gateway 10.200.242.135
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2029] dhcp4 (eth0): server identifier 10.200.242.135
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2030] dhcp4 (eth0): lease time 86400
    Jun 23 15:42:19 raspberrypi dbus[363]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2031] dhcp4 (eth0): hostname 'raspberrypi'
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2032] dhcp4 (eth0): nameserver '10.200.242.135'
    Jun 23 15:42:19 raspberrypi NetworkManager[382]: <info> [1592926939.2033] dhcp4 (eth0): state changed bound -> bound
    Jun 23 15:42:19 raspberrypi systemd[1]: Starting Network Manager Script Dispatcher Service...
    Jun 23 15:42:19 raspberrypi dhclient[1612]: bound to 10.200.242.104 -- renewal in 37260 seconds.
    Jun 23 15:42:19 raspberrypi dbus[363]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
    Jun 23 15:42:19 raspberrypi systemd[1]: Started Network Manager Script Dispatcher Service.
    Jun 23 15:42:19 raspberrypi nm-dispatcher: req:1 'dhcp4-change' [eth0]: new request (3 scripts)
    Jun 23 15:42:19 raspberrypi nm-dispatcher: req:1 'dhcp4-change' [eth0]: start running ordered scripts...
    Jun 23 15:42:19 raspberrypi ap-helper[19876]: Unsupported action: 'dhcp4-change'
    Jun 23 15:42:19 raspberrypi dhcpv6-helper[19878]: Unsupported action: 'dhcp4-change'
    Jun 23 16:17:01 raspberrypi CRON[19899]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
    Jun 23 16:31:47 raspberrypi systemd[1]: Created slice User Slice of pi.
    Jun 23 16:31:47 raspberrypi systemd[1]: Starting User Manager for UID 1000...
    Jun 23 16:31:47 raspberrypi systemd[1]: Started Session c1 of user pi.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Listening on GnuPG cryptographic agent (access for web browsers).
    Jun 23 16:31:47 raspberrypi systemd[19922]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
    Jun 23 16:31:47 raspberrypi systemd[19922]: Reached target Paths.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
    Jun 23 16:31:47 raspberrypi systemd[19922]: Reached target Timers.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Listening on GnuPG cryptographic agent and passphrase cache.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Reached target Sockets.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Reached target Basic System.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Reached target Default.
    Jun 23 16:31:47 raspberrypi systemd[19922]: Startup finished in 54ms.
    Jun 23 16:31:47 raspberrypi systemd[1]: Started User Manager for UID 1000.
    Jun 23 17:12:08 raspberrypi systemd[1]: Started Session c2 of user pi.

  • 0 in reply to thread_yoda

    Thank you for providing the images. I cannot see obvious issues. Could you open J-Link RTT Viewer and check if there are any logs of the Google Cloud device that could explain the behavior?

    Are you able to ping the Google DNS from the Google Cloud device's CLI after you see this issue occur?

    ping 64:ff9b::0808:0808

  • 0 in reply to Jørgen Holmefjord

    I don't have experience to setup J-Link RTT Viewer. What's the best way to do that?
    Also, when the google cloud device is connected, I don't get any ping response from the CLI when I try to ping Google DNS server. But I can still change the temperature or the counter and it is updated in the cloud. Strange. :(

  • 0 in reply to thread_yoda

    Would you be able to reproduce this on your end? To be sure you will see the problem, just leave it overnight and check in the morning and you can see the same thing. It may be easier this way. :)

  • 0 in reply to thread_yoda

    So when it is working, I can ping the google iot core server address. I'll try to ping this again when it stops working. 

  • 0 in reply to thread_yoda

    So it has been a couple of hours and pressing the buttons no longer updates the counter. I can still ping the google iot core IPv6 address. It seems like this is a problem on the thread node device itself because I can see that it is not sending DTLS application data. 

Reply Children
Related
Terms of service