Beta - Ezlo Linux v.2.0.13.1550.8 for Ezlo Plus, Ezlo Secure, Vera Edge controllers

[blacey]

I just checked my Vera Edge and it appears to still be running version 2.0.17.1645.1

root@HUB45006642:~# /opt/firmware/bin/at88util -v
2.0.17.1645.1

It also seems there isn’t anything interesting in the logs. Going to reboot it to see that prods the Edge into upgrading…

root@HUB45006642:/tmp/log/firmware# ls -lrt
-rw-r--r--    1 root     root             0 Jan  6 00:17 update.log
-rw-r--r--    1 spread   spread           0 Jan  6 00:17 spread.log
-rw-r--r--    1 root     root             0 Jan  6 00:17 migration.log
-rw-r--r--    1 root     root             0 Jan  6 00:17 install_default_packages.log
-rw-r--r--    1 root     root             0 Jan  6 00:17 ha-restart.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-update_manager.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-scenes_manager.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-hardware_manager.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-external_controllers.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-extensions_manager.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-cored.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-camerasd.log
-rw-r--r--    1 root     root             0 Jan 10 00:17 ha-backupd.log
-rw-r--r--    1 root     root           142 Jan 10 12:22 ha-uid.log
-rw-r--r--    1 root     root        188580 Jan 10 13:21 ha-networkd.log
-rw-r--r--    1 root     root        122546 Jan 10 13:23 ha-zwaved.log
-rw-r--r--    1 root     root        431778 Jan 10 13:23 ha-luad.log

[blacey]

@blacey

Going to reboot it to see that prods the Edge into upgrading…

No go. Still running 2.0.17… If I check the ha-luad.log, I see the following:

root@HUB45006642:/tmp/log/firmware# cat ha-uid.log 

**** uid Restarted at Mon Jan 10 13:37:40 EST 2022

Logs folder was changed: //var/log/firmware
2022-01-10 13:37:49 INFO : ui_service: at-f9c569079c19d12f1c4f6bbf [2021-07-01T12:53:26+0000]
2022-01-10 13:37:49 INFO : ui_service: Spread: connected to "4803" with private group "#ui_service#localhost"
2022-01-10 13:37:49.593346 INFO : Notice, cache-cloud-info from DB is ignored
2022-01-10 13:37:49.670253 INFO : Notice, cache-owner-info is not present in DB yet
2022-01-10 13:37:49.704084 ERROR: Failed to register custom services, reason: cannot use at() with null
2022-01-10 13:37:50.012161 INFO : NMA client instance is created
2022-01-10 13:37:50.057373 INFO : Starting local server with certificate 0
2022-01-10 13:37:50.091622 INFO : Will start wss LocalNMA server on port 17000
2022-01-10 13:37:50.092393 INFO : Waiting for LocalNMA server open...
2022-01-10 13:37:50.631870 INFO : Done, LocalNMA server started
2022-01-10 13:37:50.632244 INFO : Try to open non-secure vhost
2022-01-10 13:37:50.632897 INFO : VHost created successfully on port 17001
2022-01-10 13:37:50.633324 INFO : LocalNMA main loop will run in poll/reset mode
2022-01-10 13:37:50.637526 INFO : Done, LocalNMA server is running on port 17000
2022-01-10 13:37:50.649801 INFO : Request local mode credentials and certificates. Current are v32
2022-01-10 13:37:52.685382 WARN : setAvahiService: avahi configuration write success
2022-01-10 13:37:53.133360 INFO : runMdns: avahi is restarted
2022-01-10 13:37:56.377363 INFO : [1/3] Getting controller information
2022-01-10 13:37:56.844274 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:38:01.377851 INFO : [2/3] Getting controller information
2022-01-10 13:38:01.756098 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:38:06.377612 INFO : [3/3] Getting controller information
2022-01-10 13:38:06.668324 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:38:06.669309 INFO : [0/20] Connecting to cloud coordinator at https://cloud.ezlo.com:7000/getserver
2022-01-10 13:38:07.143481 INFO : [0/15] NmaClient will re-connect to: wss://nma-server8-cloud.ezlo.com:443
2022-01-10 13:38:07.207383 INFO : NLWS: Client connection polling thread started
2022-01-10 13:38:07.706554 INFO : Connected to wss://nma-server8-cloud.ezlo.com:443/
2022-01-10 13:38:07.914268 INFO : Received new command: registered
2022-01-10 13:38:07.992759 INFO : Registered on wss://nma-server8-cloud.ezlo.com:443/
2022-01-10 13:38:07.995446 INFO : Received new command: hub.data.list
2022-01-10 13:38:08.117178 INFO : Received new command: hub.network.get
2022-01-10 13:38:08.117815 INFO : Process COMMON command: hub
2022-01-10 13:38:22.915513 INFO : Received new command: hub.devices.list
2022-01-10 13:38:22.924904 INFO : Received new command: hub.items.list
2022-01-10 13:38:22.938760 INFO : Received new command: hub.scenes.list
2022-01-10 13:38:22.949667 INFO : Received new command: hub.room.list

Right now, the vera edge has access to port 80 and 443 and I can see the traffic passing without being blocked. So, it there an authentication issue or does it need access to some other port?

[Leonardo_Soto]

Hello @blacey

Yes, a reboot might be required, please let me know if it actually downgraded after doing so.

[blacey]

@Leonardo_Soto

please let me know if it actually downgraded after doing so

No, it did not downgrade after several reboots…

[valentina]

Hey @blacey
We downgraded the controller to versions 2.0.13.1550.8 and then 2.0.12.1514.2 but the controller is still not coming as online successfully. Only reports partially to the NMA platform through the API.
As it seems it didn’t fully transition to the Ezlo platform (see image below), we suggest you let us revert the firmware to Vera again, and then we can try the Linux firmware one more time until the value changes to 1.

Please let us know if you wish to proceed.

[blacey]

Well, you welcome to do that but I would like to point out that the Edge has been running Linux firmware for a very long time and has run 100s of CI test cases so I am not sure why it doesn’t think that it is running the Linux firmware. I haven’t changed anything on the Edge hence why I think it is a cloud change that caused the connectivity issues.

Did you see this?

root@HUB45006642:/tmp/log/firmware# cat ha-uid.log 

**** uid Restarted at Mon Jan 10 13:42:01 EST 2022

2022-01-10 13:42:06 INFO : ui_service: at-f156322dcf269056b60bf3ee [2021-04-06T13:40:55+0000]
2022-01-10 13:42:06 INFO : ui_service: Spread: connected to "4803" with private group "#ui_service#localhost"
2022-01-10 13:42:06.941641 INFO : Notice, cache-cloud-info from DB is ignored
2022-01-10 13:42:07.021961 INFO : Notice, cache-owner-info is not present in DB yet
2022-01-10 13:42:07.241407 INFO : NMA client instance is created
2022-01-10 13:42:07.258472 WARN : setAvahiService: avahi configuration write success
2022-01-10 13:42:07.604307 INFO : runMdns: avahi is restarted
2022-01-10 13:42:07.606595 WARN : No local mode credentials and certificates
2022-01-10 13:42:07.611673 INFO : Request local mode credentials and certificates. Current are v0
2022-01-10 13:42:10.629635 INFO : [1/3] Getting controller information
2022-01-10 13:42:11.057323 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:42:15.630042 INFO : [2/3] Getting controller information
2022-01-10 13:42:15.932981 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:42:17.651600 ERROR: Service avahi-daemon not running, restarting...
2022-01-10 13:42:20.629891 INFO : [3/3] Getting controller information
2022-01-10 13:42:20.917230 ERROR: Failed to get controller information: curl send error: The requested URL returned error: 401 Unauthorized(22)
2022-01-10 13:42:20.918219 INFO : [0/20] Connecting to cloud coordinator at https://cloud.ezlo.com:7000/getserver
2022-01-10 13:42:21.401206 INFO : [0/15] NmaClient will re-connect to: wss://nma-server8-cloud.ezlo.com:443
2022-01-10 13:42:21.467618 INFO : NLWS: Client connection polling thread started
2022-01-10 13:42:21.959120 INFO : Connected to wss://nma-server8-cloud.ezlo.com:443/
2022-01-10 13:42:22.085577 INFO : Received new command: registered
2022-01-10 13:42:22.152047 INFO : Registered on wss://nma-server8-cloud.ezlo.com:443/
2022-01-10 13:42:22.158595 INFO : Received new command: hub.data.list
2022-01-10 13:42:22.619477 INFO : Received new command: hub.network.get
2022-01-10 13:42:22.620114 INFO : Process COMMON command: hub
2022-01-10 13:42:28.992504 INFO : Received new command: hub.info.get
2022-01-10 13:42:37.087716 INFO : Received new command: hub.devices.list
2022-01-10 13:42:37.089989 INFO : Received new command: hub.items.list
2022-01-10 13:42:37.096073 INFO : Received new command: hub.scenes.list
2022-01-10 13:42:37.099408 INFO : Received new command: hub.room.list
2022-01-10 13:42:37.099850 INFO : Process COMMON command: hub
2022-01-10 13:42:37.103100 ERROR: Received unsupported command: hub.room.list
2022-01-10 17:32:16.366609 WARN : No local mode credentials and certificates
2022-01-10 17:42:16.366642 WARN : No local mode credentials and certificates
2022-01-10 17:52:16.366730 WARN : No local mode credentials and certificates
2022-01-10 18:02:16.366627 WARN : No local mode credentials and certificates
2022-01-10 18:12:16.366613 WARN : No local mode credentials and certificates

and

root@HUB45006642:/tmp/log/firmware# cat ha-networkd.log 

**** networkd Restarted at Mon Jan 10 13:42:01 EST 2022

2022-01-10 13:42:05.386914 INFO : Mobile Network Configuration
operatorsWhiteList................................
autoRegistration..................................true
pingPeriodActive..................................30
pingPeriodNotActive...............................900
modemWatchdogTimer................................300
APN Settings......................................8
.....CC Network\310260............................wholesale
.....CC Network\310410............................reseller, ccdata
.....Hologram.....................................hologram
.....KYIVSTAR.....................................internet
.....MTS UKR......................................internet
.....T-Mobile\310260..............................iot.tmowholesale, fast.t-mobile.com
.....USIM.........................................internet
.....lifecell.....................................internet
2022-01-10 13:42:05 INFO : network: at-f156322dcf269056b60bf3ee [2021-04-06T13:40:55+0000]
2022-01-10 13:42:05 INFO : network: Spread: connected to "4803" with private group "#network#localhost"
2022-01-10 13:42:06.509862 INFO : Interface eth0.2 went up
2022-01-10 13:42:06.510321 INFO : Interface eth0.2 got internet
Device "apcli0" does not exist.
2022-01-10 13:42:07.209601 INFO : Internet is now available
2022-01-10 13:42:07.238313 INFO : Interface apcli0 went down
2022-01-10 13:42:07.238744 INFO : Interface apcli0 lost internet
2022-01-10 13:42:07.394836 INFO : Interface ra0 went down
kmod: module is not loaded
killall: ap_client: no process killed
switch reg write offset=2004, value=ff0003
switch reg write offset=2104, value=ff0003
switch reg write offset=2204, value=ff0003
switch reg write offset=2304, value=ff0003
switch reg write offset=2404, value=ff0003
switch reg write offset=2504, value=ff0003
switch reg write offset=2010, value=810000c0
switch reg write offset=2110, value=810000c0
switch reg write offset=2210, value=810000c0
switch reg write offset=2310, value=810000c0
switch reg write offset=2410, value=810000c0
switch reg write offset=2510, value=810000c0
switch reg write offset=2610, value=81000000
switch reg write offset=2710, value=81000000
switch reg write offset=2604, value=20ff0003
switch reg write offset=2704, value=20ff0003
Special Tag Disabled
switch reg write offset=2610, value=81000000
switch reg write offset=2014, value=10002
switch reg write offset=2114, value=10001
switch reg write offset=2214, value=10001
switch reg write offset=2314, value=10001
switch reg write offset=2414, value=10001
switch reg write offset=2514, value=10002
REG_ESW_WT_MAC_ATC is 0x7ff0002
done.
Interface doesn't accept private ioctl...
set (8BE2): Network is down
2022-01-10 13:42:19.420882 INFO : Disabling apcli0 interface
2022-01-10 13:42:19.421302 INFO : Resetting client_wifi interface
2022-01-10 13:42:19.421674 INFO : Disabling ra0 interface
2022-01-10 13:42:19.421987 INFO : Resetting ap_wifi interface
2022-01-10 13:42:22.428084 INFO : Tunnels initializing...
2022-01-10 13:42:22.429080 INFO : Waiting for new streams creating...
2022-01-10 13:42:22.429545 INFO : Tunnels initializing...
2022-01-10 13:42:22.429986 INFO : Waiting for new streams creating...
2022-01-10 13:42:42.578514 INFO : Tunnels monitoring...
2022-01-10 13:42:42.579292 INFO : Requesting token...
2022-01-10 13:42:52.582039 WARN : Cloud response getting is timed out
2022-01-10 13:42:52.582558 INFO : Wait timeout 60 seconds
2022-01-10 17:24:01.707316 INFO : Requesting token...
2022-01-10 17:24:11.709473 WARN : Cloud response getting is timed out
2022-01-10 17:24:11.709942 INFO : Wait timeout 60 seconds
2022-01-10 17:25:11.710381 INFO : Requesting token...
2022-01-10 17:25:21.712546 WARN : Cloud response getting is timed out

[Leonardo_Soto]

@blacey

Did you see this?

We are gonna check the logs and see what can be done, we’ll reply as soon as possible.

[valentina]

Hello @blacey
After analyzing your logs, I can suggest two options:

1. We will escalate the case internally to our cloud team. Although this can take longer, we will not risk your current configuration and test cases.
2. Perform the hub.firmware.luup.switch to go back to Vera firmware - then move the unit to Linux firmware. This option is the fastest but you will lose your existing settings as the firmware version 2.0.12.1514.2 doesn’t fully support backup restore.

Please let me know which option you’d like to take.

[blacey]

@valentina, let’s go with option 2. Thanks!