Hi Forzaalfa,
It looks like the connection to your Ezlo hub cannot be established. Are all parameters (ip, serial, etc) correct?
Cheers Rene
Well, there are some indications that they are talking? I think the credentials are ok…
This is a while after luup reload:
2020-09-16 21:06:34.544 luup_log:60: EzloBridge_debug: Try to Reconnect, attempt 1.
2020-09-16 21:06:34.545 luup_log:60: luws: wsopen("wss://x.x.x.x:17000")
2020-09-16 21:06:34.633 luup_log:60: luws: wsopen() successful SSL/TLS negotiation
2020-09-16 21:06:34.633 luup_log:60: luws: wsopen() upgrading connection to WebSocket
2020-09-16 21:06:34.634 luup_log:60: luws: wsupgrade({ path="/", msghandler=function: 0x564decb801a0, ip="x.x.x.x", port=17000, socket=SSL connection: 0x564deb809578, options={ max_payload_size=65535, receive_timeout=0, receive_chunk_size=2048, connect=function: 0x564decb83f60, use_masking=true }, connected=false, proto="wss", readstate="start" })
2020-09-16 21:06:34.634 luup_log:60: luws: wsupgrade() sending "GET / HTTP/1.1\r\
Host: x.x.x.x\r\
Upgrade: websocket\r\
Connection: Upgrade\r\
Sec-WebSocket-Key: jijNeCbFi2OztOb5PC7NxA==\r\
Sec-WebSocket-Version: 13\r\
\r\
"
2020-09-16 21:06:34.635 luup_log:60: luws: wsupgrade() received "HTTP/1.1 101 Switching Protocols", nil
2020-09-16 21:06:34.635 luup_log:60: luws: wsupgrade() received "Upgrade: WebSocket", nil
2020-09-16 21:06:34.635 luup_log:60: luws: wsupgrade() received "Connection: Upgrade", nil
2020-09-16 21:06:34.635 luup_log:60: luws: wsupgrade() received "Sec-WebSocket-Accept: NzxorZb1bjyZB8EPY4Q18O9eYcA=", nil
2020-09-16 21:06:34.635 luup_log:60: luws: wsupgrade() received "", nil
2020-09-16 21:06:34.635 luup_log:60: luws: wsupdate() upgrade response: { 1="HTTP/1.1 101 Switching Protocols", 2="Upgrade: WebSocket", 3="Connection: Upgrade", 4="Sec-WebSocket-Accept: NzxorZb1bjyZB8EPY4Q18O9eYcA=" }
2020-09-16 21:06:34.636 luup_log:60: luws: wsupgrade() upgrade succeeded!
2020-09-16 21:06:34.636 luup_log:60: luws: wsopen() successful WebSocket startup, wsconn { path="/", msghandler=function: 0x564decb801a0, ip="x.x.x.x", port=17000, proto="wss", socket=SSL connection: 0x564deb809578, options={ max_payload_size=65535, receive_timeout=0, receive_chunk_size=2048, connect=function: 0x564decb83f60, use_masking=true }, connected=true, lastMessage=1600286794.6361(09/16/20.21:06:34), readstate="start" }
2020-09-16 21:06:34.637 luup_log:60: EzloBridge_debug: Connection reopened, login
2020-09-16 21:06:35.644 luup_log:60: luws: wshandleincoming() accepted, now 0 bytes to go
2020-09-16 21:06:35.644 luup_log:60: EzloBridge_debug: MessageHandler false, receiver error: closed
2020-09-16 21:06:35.646 luup_log:60: EzloBridge_debug: MessageHandler, opcode = false? receiver error: closed
Hi Forzaalfa,
For some reason the socket connection gets closed. Two things I can think of.
- A problem with the Ezlo Plus. You can try to remove and add it to your account again. Also make sure it runs the latest firmware.
- The lua-socket on your Pi is too old. make sure it is at least version 3.0rc1-2 see luarocks for the latest
Not sure this truly is it though.
The log part is for a reconnect, does the first try at startup look the same?
Cheers Rene
Cheers Rene
Hi Rene
getting this in the log for sensor in ezlo plus, it’s a aquara motion sensor. I don’t think it is properly configured as configure var is set to 0, but it works. In openluup i am getting
luup.variable_set:: 20018.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 0 now: 1 #hooks:0
2020-12-22 20:04:49.178 luup_log:24: EzloBridge_error: Item 5fddfc0712233512250fa089 has unmapped name security_threat.
2020-12-22 20:04:49.179 luup.variable_set:: 20018.urn:micasaverde-com:serviceId:SecuritySensor1.Tripped was: 1 now: 0 #hooks:0
2020-12-22 20:04:49.180 luup_log:24: EzloBridge_error: Item 5fddfc0712233512250fa089 has unmapped name security_threat.
Hi @ElCid,
The plugin is not setting the configure variable as it is only for the zwave devices really and not for virtual ones. The security_tread item on the Ezlo devices is not used (hence unmapped), not quite sure what its purpose is, maybe links to the tamper switch. I see your sensor trips and untrips and that with armed/disarmed is all that is supported.
Cheers Rene
Thank you for clarifying. Cheers
Hi Rene,
after a while i wanted to give another try to openLuup and ezlo, i have clean install of openLuup and factory reset ezlo with only 2 dimmers included, i receive the following error:
Connecting to Ezlo Hub…Unable to connect to Hub
here is the log from LuaUPnP.log
2020-12-23 11:09:01.726 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Unable to connect to Hub now: Getting tokens from Ezlo Portal #hooks:0
2020-12-23 11:09:06.400 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.WssUserID was: now: 934340a0-a7dd-11e9-bb96-67bdc8303c0f #hooks:0
2020-12-23 11:09:06.400 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.WssToken was: now: Tahjp5MUAHiBtbPc4UY%CoUHe-5GiRJkttNg79ar~*nbWtr*ZjvfmFhbPY9Pev~wriVs0C2A4q%0t#Cqu5v@Eyt!SRhWKM-yFL!uc1A1Ul$
2020-12-23 11:09:06.400 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.TokenExpires was: 0 now: 1608804543 #hooks:0
2020-12-23 11:09:06.401 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Getting tokens from Ezlo Portal now: Opening web-socket to Hub. #hooks:0
2020-12-23 11:09:06.402 luup_log:8: EzloBridge_error: Could not connect to Hub, Could not open WebSocket. Connection to 192.168.0.110:17000 failed: connec
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.WssUserID was: 934340a0-a7dd-11e9-bb96-67bdc8303c0f now: #hooks:0
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.WssToken was: Tahjp5MUAHiBtbPc4UY%CoUHe-5GiRJkttNg79ar~*nbWtr*ZjvfmFhbPY9Pev~wriVs0C2A4q%0t#Cqu5v@Eyt!SRhWKM-yFL!uc1A1Ul@QNB0!$
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:rboer-com:serviceId:EzloBridge1.TokenExpires was: 1608804543 now: 0 #hooks:0
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Opening web-socket to Hub. now: Unable to connect to Hub #hooks:0
2020-12-23 11:09:06.402 luup.set_failure:: status = 2
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 2 now: 2 #hooks:0
2020-12-23 11:09:06.402 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 1608716419 now: 1608718146 #hooks:0
2020-12-23 11:09:06.402 openLuup.scheduler:: [8] Ezlo Bridge device startup completed: status=, msg=Unable to connect to Hub, name=EzloBridge
Hi @eonnet,
Please make sure the correct version of lua sockets is installed. See a few post s back for details.
Cheers Rene
Hello Rene,
the installed lua-socket is 3.0
lua-socket is already the newest version (3.0~rc1+git+ac3201d-4).
Hi Eonnet,
The version that comes with the PI debian install is not current. Please install the latest using luarocks
luarocks install luasocket
You may need to install luarocks first.
Hi @reneboer
before you suggested this i remove my controller from ezlo account and i added it again. i installed luarocks and luasocket from luarocks but i now have another problem
it display unable to logon on ezlo portal…
here is the log
2020-12-23 21:27:50.127 openLuup.scheduler:: [4] Alternate App Store device startup completed: status=true, msg=OK, name=AltAppStore
2020-12-23 21:27:50.127 openLuup.scheduler:: [5] Ezlo Bridge device startup
2020-12-23 21:27:50.129 luup_log:5: EzloBridge: EzloBridge device #5 is initializing!
2020-12-23 21:27:50.129 luup_log:5: EzloBridge: Version 1.15.
2020-12-23 21:27:50.129 luup_log:5: EzloBridge: We are running on openLuup.
2020-12-23 21:27:50.129 luup_log:5: EzloBridge: Bridging to 192.168.0.110
2020-12-23 21:27:50.129 luup_log:5: EzloBridge_info: device clone numbering starts at 10000.
2020-12-23 21:27:50.129 luup_log:5: var.GetSet: empty data value for variable IncludeDevices
2020-12-23 21:27:50.129 luup_log:5: var.GetSet: empty data value for variable ExcludeDevices
2020-12-23 21:27:50.129 luup_log:5: EzloBridge: EzloBridge maps remote Zwave controller
2020-12-23 21:27:50.129 luup.variable_set:: 5.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Unable to logon to Ezlo portal now: Getting tokens from Ezlo Portal #hooks:0
2020-12-23 21:27:54.137 luup_log:5: EzloBridge_debug: Sync keys response {"keys":{"69df4f69-b9d3-4f43-935b-b24d219fce55":{"data":null,"meta":{"entity":{"uuid":"934340a0-a7dd-11e9-bb96-6$
2020-12-23 21:27:54.137 luup_log:5: EzloBridge_error: Unable to logon to portal Controller serial not found.
2020-12-23 21:27:54.137 luup.variable_set:: 5.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Getting tokens from Ezlo Portal now: Unable to logon to Ezlo portal #hooks:0
2020-12-23 21:27:54.137 luup.set_failure:: status = 2
2020-12-23 21:27:54.137 luup.variable_set:: 5.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 2 now: 2 #hooks:0
2020-12-23 21:27:54.138 luup.variable_set:: 5.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 1608753390 now: 1608755274 #hooks:0
2020-12-23 21:27:54.138 openLuup.scheduler:: [5] Ezlo Bridge device startup completed: status=, msg=Unable to logon to Ezlo portal, name=EzloBridge
2020-12-23 21:27:54.138 luup_log:3: ALTUI: startupDeferred, called on behalf of device:3
2020-12-23 21:27:54.139 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Version was: v2.52 now: v2.52 #hooks:0
p.s. i have access to controller from app and from ezlo api tool so the controller is present on ezlo account.
Hi @eonnet,
The log suggests the Hub with the serial configured is not on the account used. Have you double checked that?
If that does not help can you set the Log Level to Debug and see what else the log tells?
Cheers Rene
Hi @reneboer,
i double checked the serial and username and pass:
here is the whole LuaUPnP.log
2020-12-24 12:07:11.620 :: openLuup LOG ROTATION :: (runtime 0.0 days)
2020-12-24 12:07:11.620 openLuup.init:: init phase completed
2020-12-24 12:07:11.620 openLuup.io.server:: starting HTTP:3480 server on port: 3480 tcp{server}: 0x5649fe1f6448
2020-12-24 12:07:11.620 openLuup.io.server:: starting SMTP server on port: 2525 tcp{server}: 0x5649fe1f90b8
2020-12-24 12:07:11.621 openLuup.io.server:: starting POP3 server on port: 11011 tcp{server}: 0x5649fe1fbfa8
2020-12-24 12:07:11.621 openLuup.historian:: starting data historian
2020-12-24 12:07:11.621 openLuup.historian:: using memory cache size (per-variable): 1024
2020-12-24 12:07:11.621 openLuup.scheduler:: starting
2020-12-24 12:07:11.621 openLuup.scheduler:: [2] openLuup device startup
2020-12-24 12:07:11.621 luup_log:2: v20.5.22
2020-12-24 12:07:11.621 luup_log:2: sync in 48.4 s
2020-12-24 12:07:11.622 luup.variable_watch:: callback=housemode_watcher, watching=2.openLuup.HouseMode
2020-12-24 12:07:11.622 luup.register_handler:: global_function_name=openLuup_email, request=openLuup@openLuup.lo$
2020-12-24 12:07:11.622 luup.register_handler:: global_function_name=openLuup_images, request=images@openLuup.loc$
2020-12-24 12:07:11.623 luup.register_handler:: global_function_name=openLuup_events, request=events@openLuup.loc$
2020-12-24 12:07:11.623 luup.register_handler:: global_function_name=openLuup_mailbox, request=mail@openLuup.local
2020-12-24 12:07:11.623 luup.chdev.append:: [AltAppStore] Alternate App Store
2020-12-24 12:07:11.623 luup.chdev.sync:: [2] openLuup, syncing children
2020-12-24 12:07:11.623 luup_log:2: 4Mb, 0.1%cpu, 0.0days
2020-12-24 12:07:11.623 openLuup.scheduler:: [2] openLuup device startup completed: status=true, msg=sync in $
2020-12-24 12:07:11.623 openLuup.scheduler:: [3] Alternate UI device startup
2020-12-24 12:07:11.623 luup_log:3: ALTUI: initstatus(3) starting version: v2.52
2020-12-24 12:07:11.623 openLuup.scheduler:: [3] Alternate UI device startup completed: status=, msg=, name=
2020-12-24 12:07:11.624 openLuup.scheduler:: [4] Alternate App Store device startup
2020-12-24 12:07:11.624 luup_log:4: AltAppStore : starting...
2020-12-24 12:07:11.624 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine1 was: AltAppStore now: Al$
2020-12-24 12:07:11.624 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine2 was: now: #hooks:0
2020-12-24 12:07:11.624 luup_log:4: AltAppStore : v20.3.30
2020-12-24 12:07:11.624 luup.set_failure:: status = 0
2020-12-24 12:07:11.624 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #$
2020-12-24 12:07:11.624 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now:$
2020-12-24 12:07:11.624 openLuup.scheduler:: [4] Alternate App Store device startup completed: status=true, msg=O$
2020-12-24 12:07:11.624 openLuup.scheduler:: [8] Ezlo Bridge device startup
2020-12-24 12:07:12.176 luup_log:8: EzloBridge: EzloBridge device #8 is initializing!
2020-12-24 12:07:12.384 luup_log:8: EzloBridge: Version 1.15.
2020-12-24 12:07:12.384 luup_log:8: EzloBridge: We are running on openLuup.
2020-12-24 12:07:12.384 luup_log:8: EzloBridge: Bridging to 192.168.0.110
2020-12-24 12:07:12.385 luup_log:8: EzloBridge_info: device clone numbering starts at 10000.
2020-12-24 12:07:12.385 luup_log:8: var.GetSet: empty data value for variable IncludeDevices
2020-12-24 12:07:12.385 luup_log:8: var.GetSet: empty data value for variable ExcludeDevices
2020-12-24 12:07:12.386 luup_log:8: EzloBridge: EzloBridge maps remote Zwave controller
2020-12-24 12:07:12.386 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Unable to logon to $
2020-12-24 12:07:16.176 luup_log:8: EzloBridge_debug: Sync keys response {"keys":{"69df4f69-b9d3-4f43-935b-b24d21$
2020-12-24 12:07:16.492 luup_log:8: EzloBridge_error: Unable to logon to portal Controller serial not found.
2020-12-24 12:07:16.493 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Getting tokens from$
2020-12-24 12:07:16.493 luup.set_failure:: status = 2
2020-12-24 12:07:16.493 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 2 now: 2 #$
2020-12-24 12:07:16.493 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 160880$
2020-12-24 12:07:16.493 openLuup.scheduler:: [8] Ezlo Bridge device startup completed: status=, msg=Unable to log$
2020-12-24 12:07:16.493 luup_log:3: ALTUI: startupDeferred, called on behalf of device:3
2020-12-24 12:07:16.495 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Version was: v2.52 now: v2.52 #hooks:0
2020-12-24 12:07:16.523 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:07:16.524 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:07:16.524 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToSend was: now: #hooks:0
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.RemoteVariablesToWatch was: now: #h$
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToWatch was: now: #hooks:0
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: [] #hooks:0
2020-12-24 12:07:16.525 luup_log:3: ALTUI: Wkflow - enableWorkflows(3,0,0)
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: #hooks:0
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: [] now: #h$
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsVariableBag was: now: #hoo$
2020-12-24 12:07:16.525 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: now: [] #h$
2020-12-24 12:07:16.525 luup.register_handler:: global_function_name=myALTUI_Handler, request=ALTUI_Handler
2020-12-24 12:07:16.527 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:07:16.528 luup.register_handler:: global_function_name=ALTUI_LuaRunHandler, request=ALTUI_LuaRunHan$
2020-12-24 12:07:16.529 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:07:16.529 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: now: [] #hooks:0
2020-12-24 12:07:16.529 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.PendingReset was: 0 now: 0 #hooks:0
2020-12-24 12:07:39.370 luup.set_failure:: status = 0
2020-12-24 12:07:39.370 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #$
2020-12-24 12:07:39.370 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now:$
2020-12-24 12:07:39.370 luup_log:3: ALTUI: startup completed
2020-12-24 12:07:45.700 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x5649fe1be098
2020-12-24 12:07:45.716 openLuup.server:: GET / HTTP/1.1 tcp{client}: 0x5649fe1be098
2020-12-24 12:07:45.717 openLuup.server:: request completed (194 bytes, 0 chunks, 0 ms) tcp{client}: 0x5649fe1be0$
2020-12-24 12:07:45.821 openLuup.server:: GET /data_request?id=lr_ALTUI_Handler&command=home HTTP/1.1 tcp{client}$
Forgot to turn on debug, here is with debug turned on.
2020-12-24 12:32:41.483 :: openLuup LOG ROTATION :: (runtime 0.0 days)
2020-12-24 12:32:41.483 openLuup.init:: init phase completed
2020-12-24 12:32:41.483 openLuup.io.server:: starting HTTP:3480 server on port: 3480 tcp{server}: 0x55e11ef1b118
2020-12-24 12:32:41.483 openLuup.io.server:: starting SMTP server on port: 2525 tcp{server}: 0x55e11ef1d348
2020-12-24 12:32:41.483 openLuup.io.server:: starting POP3 server on port: 11011 tcp{server}: 0x55e11ef20238
2020-12-24 12:32:41.483 openLuup.historian:: starting data historian
2020-12-24 12:32:41.483 openLuup.historian:: using memory cache size (per-variable): 1024
2020-12-24 12:32:41.483 openLuup.scheduler:: starting
2020-12-24 12:32:41.484 openLuup.scheduler:: [2] openLuup device startup
2020-12-24 12:32:41.484 luup_log:2: v20.5.22
2020-12-24 12:32:41.484 luup_log:2: sync in 78.5 s
2020-12-24 12:32:41.484 luup.variable_watch:: callback=housemode_watcher, watching=2.openLuup.HouseMode
2020-12-24 12:32:41.484 luup.register_handler:: global_function_name=openLuup_email, request=openLuup@openLuup.lo$
2020-12-24 12:32:41.484 luup.register_handler:: global_function_name=openLuup_images, request=images@openLuup.loc$
2020-12-24 12:32:41.484 luup.register_handler:: global_function_name=openLuup_events, request=events@openLuup.loc$
2020-12-24 12:32:41.484 luup.register_handler:: global_function_name=openLuup_mailbox, request=mail@openLuup.local
2020-12-24 12:32:41.484 luup.chdev.append:: [AltAppStore] Alternate App Store
2020-12-24 12:32:41.485 luup.chdev.sync:: [2] openLuup, syncing children
2020-12-24 12:32:41.485 luup_log:2: 4Mb, 0.1%cpu, 0.0days
2020-12-24 12:32:41.485 openLuup.scheduler:: [2] openLuup device startup completed: status=true, msg=sync in $
2020-12-24 12:32:41.485 openLuup.scheduler:: [3] Alternate UI device startup
2020-12-24 12:32:41.485 luup_log:3: ALTUI: initstatus(3) starting version: v2.52
2020-12-24 12:32:41.485 openLuup.scheduler:: [3] Alternate UI device startup completed: status=, msg=, name=
2020-12-24 12:32:41.485 openLuup.scheduler:: [4] Alternate App Store device startup
2020-12-24 12:32:41.485 luup_log:4: AltAppStore : starting...
2020-12-24 12:32:41.485 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine1 was: AltAppStore now: Al$
2020-12-24 12:32:41.485 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine2 was: now: #hooks:0
2020-12-24 12:32:41.485 luup_log:4: AltAppStore : v20.3.30
2020-12-24 12:32:41.485 luup.set_failure:: status = 0
2020-12-24 12:32:41.485 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #$
2020-12-24 12:32:41.486 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now:$
2020-12-24 12:32:41.486 openLuup.scheduler:: [4] Alternate App Store device startup completed: status=true, msg=O$
2020-12-24 12:32:41.486 openLuup.scheduler:: [8] Ezlo Bridge device startup
2020-12-24 12:32:41.488 luup_log:8: EzloBridge: EzloBridge device #8 is initializing!
2020-12-24 12:32:41.488 luup_log:8: EzloBridge: Version 1.15.
2020-12-24 12:32:41.488 luup_log:8: EzloBridge: We are running on openLuup.
2020-12-24 12:32:41.488 luup_log:8: EzloBridge: Bridging to 192.168.0.110
2020-12-24 12:32:41.488 luup_log:8: EzloBridge_info: device clone numbering starts at 10000.
2020-12-24 12:32:41.488 luup_log:8: var.GetSet: empty data value for variable IncludeDevices
2020-12-24 12:32:41.488 luup_log:8: var.GetSet: empty data value for variable ExcludeDevices
2020-12-24 12:32:41.488 luup_log:8: EzloBridge: EzloBridge maps remote Zwave controller
2020-12-24 12:32:41.488 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Unable to logon to $
2020-12-24 12:32:45.158 luup_log:8: EzloBridge_debug: Sync keys response {"keys":{"69df4f69-b9d3-4f43-935b-b24d21$
2020-12-24 12:32:45.158 luup_log:8: EzloBridge_error: Unable to logon to portal Controller serial not found.
2020-12-24 12:32:45.158 luup.variable_set:: 8.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Getting tokens from$
2020-12-24 12:32:45.158 luup.set_failure:: status = 2
2020-12-24 12:32:45.158 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 2 now: 2 #$
2020-12-24 12:32:45.158 luup.variable_set:: 8.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 160880$
2020-12-24 12:32:45.158 openLuup.scheduler:: [8] Ezlo Bridge device startup completed: status=, msg=Unable to log$
2020-12-24 12:32:45.158 luup_log:3: ALTUI: startupDeferred, called on behalf of device:3
2020-12-24 12:32:45.161 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Version was: v2.52 now: v2.52 #hooks:0
2020-12-24 12:32:45.184 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:32:45.185 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":$
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToSend was: now: #hooks:0
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.RemoteVariablesToWatch was: now: #h$
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToWatch was: now: #hooks:0
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: [] #hooks:0
2020-12-24 12:32:45.186 luup_log:3: ALTUI: Wkflow - enableWorkflows(3,0,0)
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: #hooks:0
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: [] now: #h$
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsVariableBag was: now: #hoo$
2020-12-24 12:32:45.186 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: now: [] #h$
2020-12-24 12:32:45.186 luup.register_handler:: global_function_name=myALTUI_Handler, request=ALTUI_Handler
2020-12-24 12:32:45.189 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:32:45.189 luup.register_handler:: global_function_name=ALTUI_LuaRunHandler, request=ALTUI_LuaRunHan$
2020-12-24 12:32:45.190 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:32:45.190 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: now: [] #hooks:0
2020-12-24 12:32:45.190 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.PendingReset was: 0 now: 0 #hooks:0
2020-12-24 12:32:45.193 luup.set_failure:: status = 0
2020-12-24 12:32:45.193 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #$
2020-12-24 12:32:45.193 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now:$
2020-12-24 12:32:45.193 luup_log:3: ALTUI: startup completed
2020-12-24 12:32:45.193 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11ef5d6d8
2020-12-24 12:32:45.193 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=80955251$
2020-12-24 12:32:45.297 openLuup.server:: request completed (24917 bytes, 2 chunks, 103 ms) tcp{client}: 0x55e11e$
2020-12-24 12:32:45.420 openLuup.server:: GET /data_request?id=user_data&output_format=json&DataVersion=809552248$
2020-12-24 12:32:45.528 openLuup.server:: request completed (53682 bytes, 4 chunks, 107 ms) tcp{client}: 0x55e11e$
2020-12-24 12:32:48.584 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=80956150$
2020-12-24 12:33:22.887 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{clien$
2020-12-24 12:33:35.150 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11f05e198
2020-12-24 12:33:35.281 openLuup.server:: GET /data_request?id=lr_ALTUI_Handler&command=home HTTP/1.1 tcp{client}$
2020-12-24 12:33:35.285 openLuup.server:: request completed (18045 bytes, 2 chunks, 4 ms) tcp{client}: 0x55e11f05$
2020-12-24 12:33:35.328 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11f091318
2020-12-24 12:33:35.328 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11f094268
2020-12-24 12:33:35.340 openLuup.server:: GET /J_ALTUI_jquery.ui.touch-punch.min.js HTTP/1.1 tcp{client}: 0x55e11$
2020-12-24 12:33:35.340 openLuup.server:: request completed (31597 bytes, 2 chunks, 0 ms) tcp{client}: 0x55e11f09$
2020-12-24 12:33:35.340 openLuup.server:: GET /J_ALTUI_api.js HTTP/1.1 tcp{client}: 0x55e11f094268
2020-12-24 12:33:35.341 openLuup.server:: request completed (55724 bytes, 4 chunks, 0 ms) tcp{client}: 0x55e11f09$
2020-12-24 12:33:35.348 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:35.349 openLuup.server:: GET /J_ALTUI_utils.js HTTP/1.1 tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:35.909 openLuup.server:: request completed (202128 bytes, 13 chunks, 559 ms) tcp{client}: 0x55e1$
2020-12-24 12:33:35.912 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11efb1938
2020-12-24 12:33:35.912 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11ef5b618
2020-12-24 12:33:35.912 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11ef55e48
2020-12-24 12:33:35.912 openLuup.server:: GET / HTTP/1.1 tcp{client}: 0x55e11f05e198
2020-12-24 12:33:35.912 openLuup.server:: request completed (194 bytes, 0 chunks, 0 ms) tcp{client}: 0x55e11f05e198
2020-12-24 12:33:35.912 openLuup.server:: GET /J_ALTUI_plugins.js HTTP/1.1 tcp{client}: 0x55e11f091318
2020-12-24 12:33:36.437 openLuup.server:: request completed (231053 bytes, 15 chunks, 524 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:36.437 openLuup.server:: GET /J_ALTUI_uimgr.js HTTP/1.1 tcp{client}: 0x55e11f094268
2020-12-24 12:33:38.836 openLuup.server:: request completed (717135 bytes, 45 chunks, 2399 ms) tcp{client}: 0x55e11f094268
2020-12-24 12:33:38.837 openLuup.io.server:: HTTP:3480 connection from 192.168.0.202 tcp{client}: 0x55e11f12bf88
2020-12-24 12:33:38.837 openLuup.server:: GET /data_request?id=lr_ALTUI_Handler&command=home HTTP/1.1 tcp{client}: 0x55e11f05e198
2020-12-24 12:33:38.838 openLuup.server:: GET /J_ALTUI_iphone.js HTTP/1.1 tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:38.838 openLuup.server:: request completed (22770 bytes, 2 chunks, 0 ms) tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:38.839 openLuup.server:: GET /J_ALTUI_verabox.js HTTP/1.1 tcp{client}: 0x55e11efb1938
2020-12-24 12:33:39.385 openLuup.server:: request completed (97222 bytes, 7 chunks, 546 ms) tcp{client}: 0x55e11efb1938
2020-12-24 12:33:39.385 openLuup.server:: GET /J_ALTUI_multibox.js HTTP/1.1 tcp{client}: 0x55e11ef5b618
2020-12-24 12:33:39.386 openLuup.server:: request completed (40237 bytes, 3 chunks, 0 ms) tcp{client}: 0x55e11ef5b618
2020-12-24 12:33:39.386 openLuup.server:: GET /J_ALTUI_upnp.js HTTP/1.1 tcp{client}: 0x55e11ef55e48
2020-12-24 12:33:39.386 openLuup.server:: request completed (22906 bytes, 2 chunks, 0 ms) tcp{client}: 0x55e11ef55e48
2020-12-24 12:33:39.390 openLuup.server:: request completed (18045 bytes, 2 chunks, 552 ms) tcp{client}: 0x55e11f05e198
2020-12-24 12:33:39.390 openLuup.server:: GET /apple-touch-icon-precomposed.png HTTP/1.1 tcp{client}: 0x55e11f12bf88
2020-12-24 12:33:39.408 openLuup.servlet:: file not found:apple-touch-icon-precomposed.png
2020-12-24 12:33:39.408 openLuup.server:: request completed (147 bytes, 0 chunks, 17 ms) tcp{client}: 0x55e11f12bf88
2020-12-24 12:33:39.450 openLuup.server:: GET /apple-touch-icon.png HTTP/1.1 tcp{client}: 0x55e11f12bf88
2020-12-24 12:33:39.450 openLuup.servlet:: file not found:apple-touch-icon.png
2020-12-24 12:33:39.451 openLuup.server:: request completed (135 bytes, 0 chunks, 0 ms) tcp{client}: 0x55e11f12bf88
2020-12-24 12:33:39.497 openLuup.server:: GET /J_ALTUI_jquery.ui.touch-punch.min.js HTTP/1.1 tcp{client}: 0x55e11f091318
2020-12-24 12:33:39.497 openLuup.server:: request completed (31597 bytes, 2 chunks, 0 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:39.499 openLuup.server:: GET /J_ALTUI_api.js HTTP/1.1 tcp{client}: 0x55e11f094268
2020-12-24 12:33:39.500 openLuup.server:: request completed (55724 bytes, 4 chunks, 0 ms) tcp{client}: 0x55e11f094268
2020-12-24 12:33:39.743 openLuup.server:: GET /J_ALTUI_utils.js HTTP/1.1 tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:39.744 openLuup.server:: request completed (202128 bytes, 13 chunks, 0 ms) tcp{client}: 0x55e11f0c87c8
2020-12-24 12:33:39.744 openLuup.server:: GET /J_ALTUI_verabox.js HTTP/1.1 tcp{client}: 0x55e11efb1938
2020-12-24 12:33:39.744 openLuup.server:: request completed (97222 bytes, 7 chunks, 0 ms) tcp{client}: 0x55e11efb1938
2020-12-24 12:33:40.514 openLuup.server:: GET /J_ALTUI_plugins.js HTTP/1.1 tcp{client}: 0x55e11ef55e48
2020-12-24 12:33:41.334 openLuup.server:: request completed (231053 bytes, 15 chunks, 819 ms) tcp{client}: 0x55e11ef55e48
2020-12-24 12:33:41.334 openLuup.server:: GET /J_ALTUI_iphone.js HTTP/1.1 tcp{client}: 0x55e11efb1938
2020-12-24 12:33:41.334 openLuup.server:: request completed (22770 bytes, 2 chunks, 0 ms) tcp{client}: 0x55e11efb1938
2020-12-24 12:33:41.334 openLuup.server:: GET /J_ALTUI_uimgr.js HTTP/1.1 tcp{client}: 0x55e11ef5b618
2020-12-24 12:33:43.933 openLuup.server:: request completed (717135 bytes, 45 chunks, 2598 ms) tcp{client}: 0x55e11ef5b618
2020-12-24 12:33:44.501 openLuup.server:: GET /data_request?id=user_data&output_format=json&DataVersion=undefined&_=1608809619569 HTTP/1.1 tcp{client}: 0x55e11f091318
2020-12-24 12:33:44.609 openLuup.server:: request completed (53682 bytes, 4 chunks, 107 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:44.914 openLuup.server:: GET /data_request?id=lr_ALTUI_Handler&command=getCustomPages&_=1608809619570 HTTP/1.1 tcp{client}: 0x55e11f091318
2020-12-24 12:33:44.915 openLuup.server:: GET /data_request?id=lr_ALTUI_Handler&command=getWorkflows&_=1608809619571 HTTP/1.1 tcp{client}: 0x55e11f094268
2020-12-24 12:33:45.016 openLuup.server:: request completed (2 bytes, 1 chunks, 101 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:45.016 openLuup.server:: request completed (2 bytes, 1 chunks, 100 ms) tcp{client}: 0x55e11f094268
2020-12-24 12:33:45.111 openLuup.server:: GET /data_request?id=variableget&DeviceNum=0&serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1&Variable=Mode&_=1608809619574 HTTP/$
2020-12-24 12:33:45.212 openLuup.server:: request completed (1 bytes, 1 chunks, 100 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:46.917 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=1&Timeout=60&MinimumDelay=1500&_=1608809619575 HTTP/1.1 tcp{client}: 0x55e11f091$
2020-12-24 12:33:47.020 openLuup.server:: request completed (24917 bytes, 2 chunks, 103 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:33:47.237 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=809561505&Timeout=60&MinimumDelay=1500&_=1608809619576 HTTP/1.1 tcp{client}: 0x5$
2020-12-24 12:33:55.250 openLuup.server:: GET /data_request?id=variableget&DeviceNum=0&serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1&Variable=Mode&_=1608809619577 HTTP/$
2020-12-24 12:33:55.351 openLuup.server:: request completed (1 bytes, 1 chunks, 100 ms) tcp{client}: 0x55e11f094268
2020-12-24 12:34:00.063 luup_log:2: synchronising to on-the-minute
2020-12-24 12:34:00.063 luup.call_timer:: interval: time=2m, days={}
2020-12-24 12:34:00.063 luup_log:2: 2 minute timer launched
2020-12-24 12:34:00.063 luup_log:2: 4Mb, 0.2%cpu, 0.0days
2020-12-24 12:34:00.465 openLuup.server:: request completed (5185 bytes, 1 chunks, 13227 ms) tcp{client}: 0x55e11f091318
2020-12-24 12:34:00.627 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=809561512&Timeout=60&MinimumDelay=1500&_=1608809619578 HTTP/1.1 tcp{client}: 0x5$
… you’re still running an older version of openLuup.
its a dockere container, but also i have new install today of openLuup on a ubuntu server vm and i have the same problem
2020-12-24 12:36:35.348 :: openLuup LOG ROTATION :: (runtime 0.0 days)
2020-12-24 12:36:35.348 openLuup.init:: init phase completed
2020-12-24 12:36:35.348 openLuup.io.server:: starting HTTP:3480 server on port: 3480 tcp{server}: 0x55cf0cf3f538
2020-12-24 12:36:35.348 openLuup.io.server:: starting SMTP server on port: 2525 tcp{server}: 0x55cf0cf421a8
2020-12-24 12:36:35.348 openLuup.io.server:: starting POP3 server on port: 11011 tcp{server}: 0x55cf0cf45098
2020-12-24 12:36:35.348 openLuup.historian:: starting data historian
2020-12-24 12:36:35.348 openLuup.historian:: using memory cache size (per-variable): 1024
2020-12-24 12:36:35.348 openLuup.scheduler:: starting
2020-12-24 12:36:35.348 openLuup.scheduler:: [2] openLuup device startup
2020-12-24 12:36:35.348 luup_log:2: v20.5.22
2020-12-24 12:36:35.348 luup_log:2: sync in 84.7 s
2020-12-24 12:36:35.349 luup.variable_watch:: callback=housemode_watcher, watching=2.openLuup.HouseMode
2020-12-24 12:36:35.349 luup.register_handler:: global_function_name=openLuup_email, request=openLuup@openLuup.local
2020-12-24 12:36:35.349 luup.register_handler:: global_function_name=openLuup_images, request=images@openLuup.local
2020-12-24 12:36:35.349 luup.register_handler:: global_function_name=openLuup_events, request=events@openLuup.local
2020-12-24 12:36:35.349 luup.register_handler:: global_function_name=openLuup_mailbox, request=mail@openLuup.local
2020-12-24 12:36:35.349 luup.chdev.append:: [AltAppStore] Alternate App Store
2020-12-24 12:36:35.349 luup.chdev.sync:: [2] openLuup, syncing children
2020-12-24 12:36:35.349 luup_log:2: 4Mb, 0.1%cpu, 0.0days
2020-12-24 12:36:35.349 openLuup.scheduler:: [2] openLuup device startup completed: status=true, msg=sync in 84.7 s, name=L_openLuup
2020-12-24 12:36:35.349 openLuup.scheduler:: [3] Alternate UI device startup
2020-12-24 12:36:35.349 luup_log:3: ALTUI: initstatus(3) starting version: v2.53
2020-12-24 12:36:35.349 openLuup.scheduler:: [3] Alternate UI device startup completed: status=, msg=, name=
2020-12-24 12:36:35.349 openLuup.scheduler:: [4] Alternate App Store device startup
2020-12-24 12:36:35.349 luup_log:4: AltAppStore : starting...
2020-12-24 12:36:35.349 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine1 was: AltAppStore now: AltAppStore #hooks:0
2020-12-24 12:36:35.349 luup.variable_set:: 4.urn:upnp-org:serviceId:altui1.DisplayLine2 was: now: #hooks:0
2020-12-24 12:36:35.349 luup_log:4: AltAppStore : v20.3.30
2020-12-24 12:36:35.349 luup.set_failure:: status = 0
2020-12-24 12:36:35.349 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #hooks:0
2020-12-24 12:36:35.349 luup.variable_set:: 4.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now: 0 #hooks:0
2020-12-24 12:36:35.349 openLuup.scheduler:: [4] Alternate App Store device startup completed: status=true, msg=OK, name=AltAppStore
2020-12-24 12:36:35.349 openLuup.scheduler:: [5] Ezlo Bridge device startup
2020-12-24 12:36:35.351 luup_log:5: EzloBridge: EzloBridge device #5 is initializing!
2020-12-24 12:36:35.351 luup_log:5: EzloBridge: Version 1.15.
2020-12-24 12:36:35.351 luup_log:5: EzloBridge: We are running on openLuup.
2020-12-24 12:36:35.351 luup_log:5: EzloBridge: Bridging to 192.168.0.110
2020-12-24 12:36:35.351 luup_log:5: EzloBridge_info: device clone numbering starts at 10000.
2020-12-24 12:36:35.351 luup_log:5: var.GetSet: empty data value for variable IncludeDevices
2020-12-24 12:36:35.351 luup_log:5: var.GetSet: empty data value for variable ExcludeDevices
2020-12-24 12:36:35.351 luup_log:5: EzloBridge: EzloBridge maps remote Zwave controller
2020-12-24 12:36:35.351 luup.variable_set:: 5.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Unable to logon to Ezlo portal now: Getting tokens from Ezlo Portal #hooks:0
2020-12-24 12:36:38.586 luup_log:5: EzloBridge_debug: Sync keys response {"keys":{"69df4f69-b9d3-4f43-935b-b24d219fce55":{"data":null,"meta":{"entity":{"uuid":"934340a0-a7dd-11e9-bb96-67bdc8303c0f","type":"user"},"target":{"uuid":"a65>
2020-12-24 12:36:38.586 luup_log:5: EzloBridge_error: Unable to logon to portal Controller serial not found.
2020-12-24 12:36:38.586 luup.variable_set:: 5.urn:upnp-org:serviceId:altui1.DisplayLine2 was: Getting tokens from Ezlo Portal now: Unable to logon to Ezlo portal #hooks:0
2020-12-24 12:36:38.586 luup.set_failure:: status = 2
2020-12-24 12:36:38.586 luup.variable_set:: 5.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 2 now: 2 #hooks:0
2020-12-24 12:36:38.586 luup.variable_set:: 5.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 1608813366 now: 1608813398 #hooks:0
2020-12-24 12:36:38.586 openLuup.scheduler:: [5] Ezlo Bridge device startup completed: status=, msg=Unable to logon to Ezlo portal, name=EzloBridge
2020-12-24 12:36:38.586 luup_log:3: ALTUI: startupDeferred, called on behalf of device:3
2020-12-24 12:36:38.587 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Version was: v2.53 now: v2.53 #hooks:0
2020-12-24 12:36:38.603 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":{"url":"","callback":"sendValueToStorage_emoncms","parameters":[{"default":1,"type":"number","key":"node... now: {"emoncm>
2020-12-24 12:36:38.604 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":{"url":"","callback":"sendValueToStorage_emoncms","parameters":[{"key":"nodeid","type":"number","default... now: {"emoncm>
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.DataStorageProviders was: {"emoncms":{"url":"","callback":"sendValueToStorage_emoncms","parameters":[{"default":1,"type":"number","key":"node... now: {"emoncm>
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToSend was: now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.RemoteVariablesToWatch was: now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.VariablesToWatch was: now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: [] #hooks:0
2020-12-24 12:36:38.605 luup_log:3: ALTUI: Wkflow - enableWorkflows(3,0,0)
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: [] now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: [] now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsVariableBag was: now: #hooks:0
2020-12-24 12:36:38.605 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.WorkflowsActiveState was: now: [] #hooks:0
2020-12-24 12:36:38.605 luup.register_handler:: global_function_name=myALTUI_Handler, request=ALTUI_Handler
2020-12-24 12:36:38.607 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:36:38.607 luup.register_handler:: global_function_name=ALTUI_LuaRunHandler, request=ALTUI_LuaRunHandler
2020-12-24 12:36:38.608 luup.call_action:: 0.urn:micasaverde-com:serviceId:HomeAutomationGateway1.RunLua
2020-12-24 12:36:38.608 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.Timers was: now: [] #hooks:0
2020-12-24 12:36:38.608 luup.variable_set:: 3.urn:upnp-org:serviceId:altui1.PendingReset was: 0 now: 0 #hooks:0
2020-12-24 12:36:38.611 luup.set_failure:: status = 0
2020-12-24 12:36:38.611 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: 0 now: 0 #hooks:0
2020-12-24 12:36:38.611 luup.variable_set:: 3.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: 0 now: 0 #hooks:0
2020-12-24 12:36:38.611 luup_log:3: ALTUI: startup completed
2020-12-24 12:36:38.611 openLuup.io.server:: HTTP:3480 connection from 192.168.0.205 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:36:38.612 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813362512&Timeout=60&MinimumDelay=1500&_=1608813372218 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:36:38.714 openLuup.server:: request completed (24919 bytes, 2 chunks, 102 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:36:38.854 openLuup.server:: GET /data_request?id=user_data&output_format=json&DataVersion=813362248&_=1608813372219 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:36:38.962 openLuup.server:: request completed (53289 bytes, 4 chunks, 107 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:36:41.163 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395505&Timeout=60&MinimumDelay=1500&_=1608813372220 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:37:41.426 openLuup.server:: request completed (3650 bytes, 1 chunks, 60262 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:37:41.563 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395505&Timeout=60&MinimumDelay=1500&_=1608813372221 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:38:00.013 luup_log:2: synchronising to on-the-minute
2020-12-24 12:38:00.013 luup.call_timer:: interval: time=2m, days={}
2020-12-24 12:38:00.013 luup_log:2: 2 minute timer launched
2020-12-24 12:38:00.013 luup_log:2: 5Mb, 0.1%cpu, 0.0days
2020-12-24 12:38:00.215 openLuup.server:: request completed (5181 bytes, 1 chunks, 18651 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:38:00.666 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395512&Timeout=60&MinimumDelay=1500&_=1608813372222 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:39:00.930 openLuup.server:: request completed (3650 bytes, 1 chunks, 60264 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:39:02.256 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395512&Timeout=60&MinimumDelay=1500&_=1608813372223 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:40:00.100 luup_log:0: 4Mb, 0.1%cpu, 0.0days
2020-12-24 12:40:00.502 openLuup.server:: request completed (5041 bytes, 1 chunks, 58246 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:40:01.563 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395519&Timeout=60&MinimumDelay=1500&_=1608813372224 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:41:01.806 openLuup.server:: request completed (3510 bytes, 1 chunks, 60243 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:41:01.956 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395519&Timeout=60&MinimumDelay=1500&_=1608813372225 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:42:00.104 luup_log:0: 2Mb, 0.1%cpu, 0.0days
2020-12-24 12:42:00.207 openLuup.server:: request completed (5041 bytes, 1 chunks, 58249 ms) tcp{client}: 0x55cf0cdf2af8
2020-12-24 12:42:00.507 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=813395526&Timeout=60&MinimumDelay=1500&_=1608813372226 HTTP/1.1 tcp{client}: 0x55cf0cdf2af8
I removed and included the controller 2 times in past 24h when i removed it the first time this started to happen, previousle it was getting devices and stuck on that.
Hi @eonnet,
Can you try this script. It connects like the plugin, but has more debugging. You can stop it with ctrl-C.
Usage is:
lua Ezlo_ws_client_as.lua ip serial uid pwd
Ezlo_ws_client_as.zip (15.3 KB)
Cheers Rene
Sent pm with the result
This shows that it’s not the latest. Update from the development branch.
Hi,
Version 2.0 is in the ALTUI App Store for download. Changes are:
- Fix for set watches after Luup reload. This makes it now works well with Reactor or other plugins that set watches on bridged devices.
- Optimized query of hub data.
- Several fixes.
Cheers Rene
1 Like