I followed the tutorial and the normal Update that happened to the devices is not happening. I successfully pushed the changes to the repository and the image was built, but the Balena server somewhere is not updating the device.
Any Ideas on how to debug, fix, log or something about this problem?
I also tried with Microservices, but I had the same result. This why I tried with the simplest App, but something is not working.
Hi. Is the device showing online in the dashboard? You will need to have the device connected to the cloud first.
sure I can see it connected in the dashboard. 100% sure that it is connected. I have already tried to create apps using Up Borad and the RASPI3 and this is the fisrt time a App it is not working.
Hey could you link to the device and enable support access please?
Sorry for the delay. This is the URL link from the device. I granted you 6h. Let me know If I have to put more
@CameronDiver
Hello, I’m unfortunately unable to SSH into the device. The fact that the device never reported its version means it never managed to finalise registration with our backend. If the device is on your premises, you may be able to SSH in and get some logs. Might also worth re-provisioning if all else fails.
Every time I restart the device it is re-provisioned and is never reporting the version. Which logs do you required and how I can connect?
Hi, is support access still granted to this device? I am unable to access it via the dashboard. Thanks.
AS I restarted now is another device:
https://423e740cb8ab07d6de809b815749c593.balena-devices.com
Yes I granted the 6H. I case you can not connect can you tell me which logs do you need me to get by SSH? and how I can connect using SSH? (while you answer I’ll be trying to find a tutorial in your site.
@dfunckt Using Balena CLI i got this:
$ balena ssh 423e740
╭────────────────────────────────────────────────────────────────────╮
│ │
│ Update available 10.10.3 → 11.5.0 │
│ │
│ https://github.com/balena-io/balena-cli/blob/master/INSTALL.md │
│ │
╰────────────────────────────────────────────────────────────────────╯Connecting to: 423e740
Invalid Version: nullAdditional information may be available by setting a DEBUG=1 environment
variable: “set DEBUG=1” on a Windows command prompt, or “export DEBUG=1”
on Linux or macOS.If you need help, don’t hesitate in contacting our support forums at
https://forums.balena.ioFor bug reports or feature requests, have a look at the GitHub issues or
create a new one at: Issues · balena-io/balena-cli · GitHub
Hi again, thanks for the link I can see that device now. Could you tell me if you flashed the device using a production or development image? Thanks.
yes I did prod.
I also update my CLI to balena-CLI v11.5.0 and I got:
$ ./balena ssh 423e740
error: The device ‘423e740cb8ab07d6de809b815749c593’ does not support direct host OS access, please update the device to at least version balenaOS ‘2.7.5’
Connection to ssh.balena-devices.com closed.
OK, so it looks like your device is /really/ struggling and, as you observe, is not even managing to provision successfully. Would you be able to flash a development image to the device, which will allow you to ssh directly to it (without authentication) and grab some logs? Thanks.
Im gonna flash 2 different boards with the development version. Ill let you know when is done.
Thanks!
Great, thanks.
The new device https://2a096aab9e59e16395189cc7c408c431.balena-devices.com/ and also have Granted Support Access.
I still get this mesasge using CLI:
./balena ssh 2a096aa
error: The device ‘2a096aab9e59e16395189cc7c408c431’ does not support direct host OS access, please update the device to at least version balenaOS ‘2.7.5’
Connection to ssh.balena-devices.com closed.
Hi, you should be able to ssh directly to that device on port 22222 now (just using your regular ssh client, username should be root and password is empty). Once you’re logged in, can you grab the journal (journalctl -n 250) so we can take a look and hopefully work out what is preventing the devices from provisioning fully. Thanks!
I set up 2 devices un Dev version exposing the URL and with support access.
https://c5cb1ed33a6c22db47f4abec959297a1.balena-devices.com
https://f99c1e7760feef58e2ccc41a9ab95ba0.balena-devices.com
both the same preblom as before, not reporting the version and also no getting update.
Yeah, due to the provision process no completing you’ll need to login to these devices and grab some logs so we can debug further. As it stands the devices aren’t getting as far as bringing up their VPNs so I cannot access them unfortunately.
~# journalctl -n 250
-- Logs begin at Fri 2013-01-18 08:50:21 UTC, end at Tue 2019-07-09 11:04:25 UT>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/>
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### before setting led, R>
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### after setting led, Re>
Jan 18 08:50:24 f99c1e7 kernel: rk_gmac-dwmac ff290000.ethernet eth0: Link is U>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
lines 1-23...skipping...
-- Logs begin at Fri 2013-01-18 08:50:21 UTC, end at Tue 2019-07-09 11:04:25 UT>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/>
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_pat>
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### before setting led, R>
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### after setting led, Re>
Jan 18 08:50:24 f99c1e7 kernel: rk_gmac-dwmac ff290000.ethernet eth0: Link is U>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliabl>
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_in>
lines 1-24...skipping...
-- Logs begin at Fri 2013-01-18 08:50:21 UTC, end at Tue 2019-07-09 11:04:25 UTC. --
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:82 rx_index: 81
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 4 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 82
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:83 rx_index: 82
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 5 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 83
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:84 rx_index: 83
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 6 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 84
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:85 rx_index: 84
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/sys/devices/platform/ff0d0000.dwmmc/mmc_host/mmc2/mmc2:0001/mmc2:0001:1': not supported by any plugin
Jan 18 08:50:24 f99c1e7 ModemManager[465]: Couldn't check support for device '/sys/devices/platform/ff290000.ethernet': not supported by any plugin
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 7 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 85
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:86 rx_index: 85
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 0 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 86
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:87 rx_index: 86
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### before setting led, Reg26 = 0xd1 , Reg28 = 0x9770
Jan 18 08:50:24 f99c1e7 kernel: setLedConfiguration: #### after setting led, Reg26 = 0x91 , Reg28 = 0x9200
Jan 18 08:50:24 f99c1e7 kernel: rk_gmac-dwmac ff290000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 1 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 87
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:88 rx_index: 87
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 2 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 88
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:89 rx_index: 88
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 3 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 89
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Send additional packet 90
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:90 rx_index: 89
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 4 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 90
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Send additional packet 91
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:91 rx_index: 90
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 5 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 91
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Send additional packet 92
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:92 rx_index: 91
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 6 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 92
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Send end packet 221
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Send FW last command
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :hci_download_patch tx_index:93 rx_index: 92
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Received reliable seqno 7 from card
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :rtk_hw_cfg.rx_index 221
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth :Init Process finished
Jan 18 08:50:24 f99c1e7 rtk_hciattach[455]: Realtek Bluetooth post process
Jan 18 08:50:24 f99c1e7 kernel: rtk_btcoex: Open BTCOEX
Jan 18 08:50:24 f99c1e7 kernel: rtk_btcoex: create_udpsocket: connect_port: 30001
Jan 18 08:50:24 f99c1e7 kernel: rtk_btcoex: send msg INVITE_REQ with len:11
Jan 18 08:50:24 f99c1e7 avahi-daemon[545]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::e8b1:cd30:e4c6:b5a5.
Jan 18 08:50:24 f99c1e7 avahi-daemon[545]: New relevant interface eth0.IPv6 for mDNS.
Jan 18 08:50:24 f99c1e7 avahi-daemon[545]: Registering new address record for fe80::e8b1:cd30:e4c6:b5a5 on eth0.*.
Jan 18 08:50:24 f99c1e7 kernel: rtk_btcoex: BTCOEX hci_rev 0x0e2f
Jan 18 08:50:24 f99c1e7 kernel: rtk_btcoex: BTCOEX lmp_subver 0x9f73
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2121] dhcp4 (eth0): address 192.168.4.10
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2124] dhcp4 (eth0): plen 24
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2127] dhcp4 (eth0): expires in 86400 seconds
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2130] dhcp4 (eth0): nameserver '192.168.4.1'
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2132] dhcp4 (eth0): gateway 192.168.4.1
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2143] dhcp4 (eth0): state changed unknown -> bound
Jan 18 08:50:25 f99c1e7 avahi-daemon[545]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.4.10.
Jan 18 08:50:25 f99c1e7 avahi-daemon[545]: New relevant interface eth0.IPv4 for mDNS.
Jan 18 08:50:25 f99c1e7 avahi-daemon[545]: Registering new address record for 192.168.4.10 on eth0.IPv4.
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2338] device (eth0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2475] device (eth0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2526] device (eth0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2606] manager: NetworkManager state is now CONNECTED_LOCAL
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2729] manager: NetworkManager state is now CONNECTED_SITE
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2759] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.2802] dns-mgr: Writing DNS information to /sbin/resolvconf
Jan 18 08:50:25 f99c1e7 dnsmasq[547]: dnsmasq[547]: reading /etc/resolv.dnsmasq
Jan 18 08:50:25 f99c1e7 dnsmasq[547]: dnsmasq[547]: using nameserver 8.8.8.8#53
Jan 18 08:50:25 f99c1e7 dnsmasq[547]: dnsmasq[547]: using nameserver 192.168.4.1#53
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.3173] device (eth0): Activation: successful, device activated.
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.3194] manager: NetworkManager state is now CONNECTED_GLOBAL
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.3216] manager: startup complete
Jan 18 08:50:25 f99c1e7 nm-dispatcher[568]: resin-ntp-config: Found config.json in /mnt/boottmp/config.json .
Jan 18 08:50:25 f99c1e7 systemd[1]: Starting Bluetooth service...
Jan 18 08:50:25 f99c1e7 nm-dispatcher[568]: 200 OK
Jan 18 08:50:25 f99c1e7 nm-dispatcher[568]: resin-ntp-config: Found config.json in /mnt/boottmp/config.json .
Jan 18 08:50:25 f99c1e7 nm-dispatcher[568]: 200 OK
Jan 18 08:50:25 f99c1e7 systemd[1]: Started Bluetooth service.
Jan 18 08:50:25 f99c1e7 systemd[1]: Reached target Bluetooth.
Jan 18 08:50:25 f99c1e7 NetworkManager[513]: <info> [1358499025.5274] bluez: use BlueZ version 5
Jan 18 08:50:25 f99c1e7 os-config[542]: https://api.balena-cloud.com/os/v1/config: The OpenSSL library reported an error: error:14090086:SSL routines:ssl3_get_server_certificate:certificate verify failed>
Jan 18 08:50:26 f99c1e7 bash[528]: [WARNING] resin-device-register: Not connected. Trying again...
Jan 18 08:50:28 f99c1e7 bash[528]: [WARNING] resin-device-register: Not connected. Trying again...
Jul 09 10:55:50 f99c1e7 chronyd[451]: 2013-01-18T08:50:30Z Selected source 178.32.220.7
Jul 09 10:55:50 f99c1e7 chronyd[451]: 2013-01-18T08:50:30Z System clock wrong by 204170719.739258 seconds, adjustment started
Jul 09 10:55:50 f99c1e7 chronyd[451]: 2019-07-09T10:55:50Z System clock was stepped by 204170719.739258 seconds
Jul 09 10:55:50 f99c1e7 os-config[542]: Service configuration retrieved
Jul 09 10:55:50 f99c1e7 os-config[542]: Stopping prepare-openvpn.service...
Jul 09 10:55:50 f99c1e7 os-config[542]: Stopping openvpn.service...
Jul 09 10:55:50 f99c1e7 os-config[542]: Awaiting prepare-openvpn.service to exit...
Jul 09 10:55:50 f99c1e7 os-config[542]: Awaiting openvpn.service to exit...
Jul 09 10:55:50 f99c1e7 os-config[542]: /etc/openvpn/ca.crt updated
Jul 09 10:55:50 f99c1e7 os-config[542]: /etc/openvpn/openvpn.conf updated
Jul 09 10:55:50 f99c1e7 os-config[542]: Starting prepare-openvpn.service...
Jul 09 10:55:50 f99c1e7 systemd[1]: Starting Prepare OpenVPN...
Jul 09 10:55:50 f99c1e7 os-config[542]: Starting openvpn.service...
Jul 09 10:55:50 f99c1e7 os-config[542]: /home/root/.ssh/authorized_keys_remote updated
Jul 09 10:55:50 f99c1e7 prepare-openvpn[648]: prepare-openvpn: [INFO] Resin.io VPN authentication.
Jul 09 10:55:50 f99c1e7 systemd[1]: Started Prepare OpenVPN.
Jul 09 10:55:50 f99c1e7 systemd[1]: Started OpenVPN.
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 WARNING: file '/var/volatile/vpn-auth' is group or others accessible
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 OpenVPN 2.4.3 arm-poky-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 10 2019
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 library versions: OpenSSL 1.0.2o 27 Mar 2018, LZO 2.10
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]18.232.192.190:443
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 Socket Buffers: R=[87380->87380] S=[16384->16384]
Jul 09 10:55:50 f99c1e7 openvpn[654]: Tue Jul 9 10:55:50 2019 Attempting to establish TCP connection with [AF_INET]18.232.192.190:443 [nonblock]
Jul 09 10:55:51 f99c1e7 bash[480]: [resin-init-flasher] INFO: Flash internal device... will take around 5 minutes...
Jul 09 10:55:51 f99c1e7 bash[480]: [resin-init-flasher] INFO: mmcblk1 is our install media, skip it...
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 TCP connection established with [AF_INET]18.232.192.190:443
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 TCP_CLIENT link local: (not bound)
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 TCP_CLIENT link remote: [AF_INET]18.232.192.190:443
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Jul 09 10:55:51 f99c1e7 bash[480]: [ERROR] resin-device-progress : Device registration not complete, provisioning progress cannot be reported.
Jul 09 10:55:51 f99c1e7 bash[480]: [resin-init-flasher] ERROR: Failed to find any block devices in mmcblk1.
Jul 09 10:55:51 f99c1e7 bash[480]: [resin-init-flasher] Cleanup.
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 TLS: Initial packet from [AF_INET]18.232.192.190:443, sid=fdde4506 ba40aac6
Jul 09 10:55:51 f99c1e7 openvpn[654]: Tue Jul 9 10:55:51 2019 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Jul 09 10:55:51 f99c1e7 systemd[1]: resin-init-flasher.service: Main process exited, code=exited, status=1/FAILURE
Jul 09 10:55:51 f99c1e7 systemd[1]: resin-init-flasher.service: Failed with result 'exit-code'.
Jul 09 10:55:51 f99c1e7 systemd[1]: Failed to start Resin init flasher service.
Jul 09 10:55:52 f99c1e7 bash[528]: [INFO] resin-device-register : Registered device with ID: 1658829 and UUID: f99c1e7760feef58e2ccc41a9ab95ba0.
Jul 09 10:55:52 f99c1e7 bash[528]: [INFO] resin-device-pinning : Pinning information missing. Skipping.
Jul 09 10:55:52 f99c1e7 systemd[1]: Started Resin device register.
Jul 09 10:55:52 f99c1e7 systemd[1]: Reached target Multi-User System.
Jul 09 10:55:52 f99c1e7 systemd[1]: Starting Update UTMP about System Runlevel Changes...
Jul 09 10:55:52 f99c1e7 systemd[1]: Started Update UTMP about System Runlevel Changes.
Jul 09 10:55:52 f99c1e7 systemd[1]: Startup finished in 12.393s (kernel) + 14.680s (userspace) = 27.073s.
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 VERIFY OK: depth=1, C=AU, ST=Some-State, O=Internet Widgits Pty Ltd
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 VERIFY KU OK
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 Validating certificate extended key usage
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 VERIFY EKU OK
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 VERIFY OK: depth=0, C=US, ST=WA, L=Seattle, O=Resin.io, OU=VPN, CN=ResinVPN
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Jul 09 10:55:52 f99c1e7 openvpn[654]: Tue Jul 9 10:55:52 2019 [ResinVPN] Peer Connection Initiated with [AF_INET]18.232.192.190:443
Jul 09 10:55:53 f99c1e7 openvpn[654]: Tue Jul 9 10:55:53 2019 SENT CONTROL [ResinVPN]: 'PUSH_REQUEST' (status=1)
Jul 09 10:55:53 f99c1e7 openvpn[654]: Tue Jul 9 10:55:53 2019 AUTH: Received control message: AUTH_FAILED
Jul 09 10:55:53 f99c1e7 openvpn[654]: Tue Jul 9 10:55:53 2019 SIGTERM[soft,auth-failure] received, process exiting
Jul 09 10:56:04 f99c1e7 systemd[1]: openvpn.service: Service hold-off time over, scheduling restart.
Jul 09 10:56:04 f99c1e7 systemd[1]: openvpn.service: Scheduled restart job, restart counter is at 1.
Jul 09 10:56:04 f99c1e7 systemd[1]: Stopped OpenVPN.
Jul 09 10:56:04 f99c1e7 systemd[1]: Starting Prepare OpenVPN...
Jul 09 10:56:04 f99c1e7 prepare-openvpn[672]: prepare-openvpn: [INFO] Resin.io VPN authentication.
Jul 09 10:56:04 f99c1e7 systemd[1]: Started Prepare OpenVPN.
Jul 09 10:56:04 f99c1e7 systemd[1]: Started OpenVPN.
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 WARNING: file '/var/volatile/vpn-auth' is group or others accessible
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 OpenVPN 2.4.3 arm-poky-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 10 2019
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 library versions: OpenSSL 1.0.2o 27 Mar 2018, LZO 2.10
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]34.237.229.125:443
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 Socket Buffers: R=[87380->87380] S=[16384->16384]
Jul 09 10:56:04 f99c1e7 openvpn[676]: Tue Jul 9 10:56:04 2019 Attempting to establish TCP connection with [AF_INET]34.237.229.125:443 [nonblock]
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 TCP connection established with [AF_INET]34.237.229.125:443
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 TCP_CLIENT link local: (not bound)
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 TCP_CLIENT link remote: [AF_INET]34.237.229.125:443
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 TLS: Initial packet from [AF_INET]34.237.229.125:443, sid=3650d77e 80a1653c
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 VERIFY OK: depth=1, C=AU, ST=Some-State, O=Internet Widgits Pty Ltd
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 VERIFY KU OK
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 Validating certificate extended key usage
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 VERIFY EKU OK
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 VERIFY OK: depth=0, C=US, ST=WA, L=Seattle, O=Resin.io, OU=VPN, CN=ResinVPN
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Jul 09 10:56:05 f99c1e7 openvpn[676]: Tue Jul 9 10:56:05 2019 [ResinVPN] Peer Connection Initiated with [AF_INET]34.237.229.125:443
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 SENT CONTROL [ResinVPN]: 'PUSH_REQUEST' (status=1)
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 PUSH: Received control message: 'PUSH_REPLY,sndbuf 0,rcvbuf 0,route 52.4.252.97,ping 10,ping-restart 60,socket-flags TCP_NODELAY,ifconfig 10>
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: timers and/or timeouts modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: --sndbuf/--rcvbuf options modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Socket Buffers: R=[336640->336640] S=[44800->44800]
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: --socket-flags option modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Socket flags: TCP_NODELAY=1 succeeded
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: --ifconfig/up options modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: route options modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: peer-id set
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: adjusting link_mtu to 1627
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 OPTIONS IMPORT: data channel crypto options modified
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Data Channel: using negotiated cipher 'AES-256-GCM'
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 ROUTE_GATEWAY 192.168.4.1/255.255.255.0 IFACE=eth0 HWADDR=0c:9d:92:0c:6a:7e
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 TUN/TAP device resin-vpn opened
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 TUN/TAP TX queue length set to 100
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 /sbin/ip link set dev resin-vpn up mtu 1500
Jul 09 10:56:07 f99c1e7 NetworkManager[513]: <info> [1562669767.1077] manager: (resin-vpn): new Tun device (/org/freedesktop/NetworkManager/Devices/6)
Jul 09 10:56:07 f99c1e7 systemd-udevd[677]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 /sbin/ip addr add dev resin-vpn local 100.64.22.151 peer 52.4.252.97
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 /etc/openvpn-misc/upscript.sh resin-vpn 1500 1555 100.64.22.151 52.4.252.97 init
Jul 09 10:56:07 f99c1e7 openvpn[676]: resin-ntp-config: Found config.json in /mnt/boottmp/config.json .
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 /sbin/ip route add 52.4.252.97/32 via 52.4.252.97
Jul 09 10:56:07 f99c1e7 openvpn[676]: ip: RTNETLINK answers: File exists
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 ERROR: Linux route add command failed: external program exited with error status: 2
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 GID set to openvpn
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 UID set to openvpn
Jul 09 10:56:07 f99c1e7 openvpn[676]: Tue Jul 9 10:56:07 2019 Initialization Sequence Completed
Jul 09 11:01:27 f99c1e7 NetworkManager[513]: <info> [1562670087.0949] device (wlan0): set-hw-addr: set MAC address to 62:4B:B4:34:A9:28 (scanning)
Jul 09 11:01:27 f99c1e7 kernel: IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul 09 11:01:27 f99c1e7 NetworkManager[513]: <info> [1562670087.1342] device (wlan0): supplicant interface state: ready -> disabled
Jul 09 11:01:27 f99c1e7 NetworkManager[513]: <info> [1562670087.1556] device (wlan0): supplicant interface state: disabled -> inactive
Jul 09 11:01:27 f99c1e7 wpa_supplicant[587]: wlan0: Reject scan trigger since one is already pending
Jul 09 11:03:28 f99c1e7 kernel: usb 1-1: reset high-speed USB device number 2 using dwc2
Jul 09 11:03:28 f99c1e7 kernel: usb 1-1: USB disconnect, device number 2
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1: new high-speed USB device number 3 using dwc2
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1: New USB device found, idVendor=05e3, idProduct=0610
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1: Product: USB2.0 Hub
Jul 09 11:03:29 f99c1e7 kernel: hub 1-1:1.0: USB hub found
Jul 09 11:03:29 f99c1e7 kernel: hub 1-1:1.0: 4 ports detected
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1.2: new high-speed USB device number 4 using dwc2
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1.2: New USB device found, idVendor=1a40, idProduct=0101
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Jul 09 11:03:29 f99c1e7 kernel: usb 1-1.2: Product: USB 2.0 Hub
Jul 09 11:03:29 f99c1e7 kernel: hub 1-1.2:1.0: USB hub found
Jul 09 11:03:29 f99c1e7 kernel: hub 1-1.2:1.0: 4 ports detected
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.1: new low-speed USB device number 5 using dwc2
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.1: New USB device found, idVendor=0a81, idProduct=0101
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.1: Product: USB Keyboard
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.1: Manufacturer: CHESEN
Jul 09 11:03:30 f99c1e7 kernel: input: CHESEN USB Keyboard as /devices/platform/ff540000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.0/0003:0A81:0101.0002/input/input4
Jul 09 11:03:30 f99c1e7 kernel: hid-generic 0003:0A81:0101.0002: input,hidraw1: USB HID v1.10 Keyboard [CHESEN USB Keyboard] on usb-ff540000.usb-1.2.1/input0
Jul 09 11:03:30 f99c1e7 kernel: input: CHESEN USB Keyboard as /devices/platform/ff540000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.1/0003:0A81:0101.0003/input/input5
Jul 09 11:03:30 f99c1e7 kernel: hid-generic 0003:0A81:0101.0003: input,hidraw2: USB HID v1.10 Device [CHESEN USB Keyboard] on usb-ff540000.usb-1.2.1/input1
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.2: new low-speed USB device number 6 using dwc2
Jul 09 11:03:30 f99c1e7 systemd-logind[449]: Watching system buttons on /dev/input/event5 (CHESEN USB Keyboard)
Jul 09 11:03:30 f99c1e7 systemd-logind[449]: Watching system buttons on /dev/input/event4 (CHESEN USB Keyboard)
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.2: New USB device found, idVendor=046d, idProduct=c077
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.2: Product: USB Optical Mouse
Jul 09 11:03:30 f99c1e7 kernel: usb 1-1.2.2: Manufacturer: Logitech
Jul 09 11:03:30 f99c1e7 kernel: input: Logitech USB Optical Mouse as /devices/platform/ff540000.usb/usb1/1-1/1-1.2/1-1.2.2/1-1.2.2:1.0/0003:046D:C077.0004/input/input6
Jul 09 11:03:30 f99c1e7 kernel: hid-generic 0003:046D:C077.0004: input,hidraw3: USB HID v1.11 Mouse [Logitech USB Optical Mouse] on usb-ff540000.usb-1.2.2/input0
Jul 09 11:04:23 f99c1e7 systemd[1]: Starting SSH Key Generation...
Jul 09 11:04:23 f99c1e7 systemd[1]: Created slice system-dropbear.slice.
Jul 09 11:04:23 f99c1e7 dropbearkey[713]: Generating key, this may take a while...
Jul 09 11:04:25 f99c1e7 dropbearkey[713]: Public key portion is:
Jul 09 11:04:25 f99c1e7 dropbearkey[713]: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC4VG4JFwSQb+ysdr/P9Kpna3zod1Yn3DsK3BPp4Is0sUsI0+bJpzkyNNevmryqnJNIVlBgBwJrEDiqC5i0lrFXPr5T/YrToU0aLxx+pTOUiM35nHOzhh8Qi5E+U>
Jul 09 11:04:25 f99c1e7 dropbearkey[713]: Fingerprint: md5 73:1f:b3:98:4d:d6:09:5d:4d:fc:b7:4a:3c:54:f2:8e
Jul 09 11:04:25 f99c1e7 systemd[1]: Started SSH Key Generation.
Jul 09 11:04:25 f99c1e7 systemd[1]: Starting SSH Per-Connection Server (192.168.4.6:40108)...
Jul 09 11:04:25 f99c1e7 systemd[1]: Started SSH Per-Connection Server (192.168.4.6:40108).