Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Turning on LEEDEVICE, when it's already on, should not change output behavior #967

Closed
1 task done
dermotduffy opened this issue Aug 15, 2020 · 19 comments · Fixed by #1378
Closed
1 task done

Turning on LEEDEVICE, when it's already on, should not change output behavior #967

dermotduffy opened this issue Aug 15, 2020 · 19 comments · Fixed by #1378
Assignees
Labels

Comments

@dermotduffy
Copy link
Contributor

dermotduffy commented Aug 15, 2020

  • I confirm that this is an issue rather than a question.

Bug report

Turning on the component LEDDEVICE via the API, when the LEDDEVICE is already on, should not result in any noticeable output behavior. However, it appears to 'reset' the connection to WLED causing WLED to stop showing streamed UDP data. I don't know if this is specific to WLED, or a more general issue.

Steps to reproduce

  • Turn LEDDEVICE on in the Hyperion UI.
  • Set a color with infinite duration.
  • Observe WLED output: Color shows up as expected.
  • Turn on LEDDEVICE via the API:
echo '{"command":"componentstate", "componentstate":{"component":"LEDDEVICE", "state": true} }' | nc  hyperion 19444

What is expected?

No change should be observed.

What is actually happening?

WLED appears to lose the "connection" to Hyperion, and resets to it's state to that prior to streaming the data from Hyperion.

System

Fresh build from head yesterday.

Hyperion Server:

Hyperion Server OS:

  • Distribution: Raspbian GNU/Linux 10 (buster)
  • Arch: arm
  • Kernel: linux (5.4.51+ (WS: 32))
  • Browser: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.116 Safari/537.36
@Lord-Grey
Copy link
Collaborator

@dermotduffy Please share a Debug log of hyperion that we can follow what is happening on hyperion side.
You might help us pointing to the time-stamps when you opened the device and when you executed the API call.

@dermotduffy
Copy link
Contributor Author

dermotduffy commented Aug 15, 2020

Hyperion UI before (note LEDDEVICE on):

image

WLED correctly receiving data from Hyperion:

image

Turn LEDDEVICE on:

(~) $ echo '{"command":"componentstate", "componentstate":{"component":"LEDDEVICE", "state": true} }' | nc  hyperion 19444 
{"command":"componentstate","success":true,"tan":0}

WLED stops receiving data from Hyperion:

image

Logs:

  • 10.100.0.44: Hyperion
  • 10.100.0.20: Machine the nc connection is made from (above)

Relevant section:

 2020-08-15T18:40:40.048Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:40:40.057Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:40:43.372Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:40:43.378Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:40:43.517Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:41:13.357Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
------ NC COMMAND ABOVE -----> 2020-08-15T18:41:13.363Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:41:13.489Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:41:19.643Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:1056:handleLoggingCommand()) log streaming activated for client ::ffff:10.100.0.21

Larger log (all available in UI):

 2020-08-15T18:20:17.635Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:20:17.640Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:20:21.540Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:20:21.547Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:20:21.724Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:20:25.037Z [hyperiond WEBSOCKET] (DEBUG) (WebSocketClient.cpp:204:sendClose()) send close: 1000 
 2020-08-15T18:20:26.714Z [hyperiond WEBSOCKET] (DEBUG) (WebSocketClient.cpp:30:WebSocketClient()) New connection from ::ffff:10.100.0.21
 2020-08-15T18:20:26.732Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.21' switch to Hyperion instance 0
 2020-08-15T18:20:51.513Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:20:51.518Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:20:51.522Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:20:51.655Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:20:53.961Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:20:53.968Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:20:57.169Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:21:07.410Z [hyperiond WEBSOCKET] (DEBUG) (WebSocketClient.cpp:204:sendClose()) send close: 1000 
 2020-08-15T18:21:08.902Z [hyperiond WEBSOCKET] (DEBUG) (WebSocketClient.cpp:30:WebSocketClient()) New connection from ::ffff:10.100.0.21
 2020-08-15T18:21:08.917Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.21' switch to Hyperion instance 0
 2020-08-15T18:21:21.515Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:21:21.522Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:21:21.640Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:21:22.517Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:21:22.522Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:21:22.533Z [hyperiond LEDDEVICE] (DEBUG) (LedDeviceWled.cpp:157:powerOff()) 
 2020-08-15T18:21:22.538Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:153:put()) PUT: [http://wled-tv-lights/json/state] [{"on":false}]
 2020-08-15T18:21:22.543Z [hyperiond COMPONENTREG] (DEBUG) (ComponentRegister.cpp:36:setNewComponentState()) LED device: disabled
 2020-08-15T18:21:22.852Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:182:getResponse()) Reply.httpStatusCode [200]
 2020-08-15T18:21:29.957Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:21:39.145Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:21:39.156Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:21:39.213Z [hyperiond LEDDEVICE] (WARNING) Could not bind local address: 0.0.0.0, (-1) Unknown error
 2020-08-15T18:21:39.221Z [hyperiond LEDDEVICE] (DEBUG) (LedDeviceWled.cpp:139:powerOn()) 
 2020-08-15T18:21:39.222Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:153:put()) PUT: [http://wled-tv-lights/json/state] [{"on":true}]
 2020-08-15T18:21:39.285Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:182:getResponse()) Reply.httpStatusCode [200]
 2020-08-15T18:21:39.289Z [hyperiond COMPONENTREG] (DEBUG) (ComponentRegister.cpp:36:setNewComponentState()) LED device: enabled
 2020-08-15T18:21:51.527Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:21:51.538Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:21:51.681Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:22:01.358Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:22:01.362Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:22:01.368Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:22:21.514Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:22:21.522Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:22:21.650Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:22:41.926Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:255:clearInput()) Removed source priority 1
 2020-08-15T18:22:41.933Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 240
 2020-08-15T18:22:45.963Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:158:registerInput()) Register new input 'Web Configuration@::ffff:10.100.0.21/COLOR' with priority 1 as inactive
 2020-08-15T18:22:45.969Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:198:setInput()) Priority 1 is now active
 2020-08-15T18:22:45.969Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 1
 2020-08-15T18:22:51.518Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:22:51.532Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:22:51.533Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:22:51.692Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:23:01.211Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:23:01.218Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:23:21.518Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:23:21.526Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:23:21.687Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:23:51.527Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:23:51.533Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:23:51.650Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:24:21.521Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:24:21.527Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:24:21.664Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:24:51.524Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:24:51.531Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:24:51.718Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:25:21.519Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:25:21.525Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:25:21.653Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:25:51.530Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:25:51.536Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:25:51.697Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:26:21.523Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:26:21.531Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:26:21.679Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:26:51.528Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:26:51.535Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:26:51.661Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:27:21.528Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:27:21.537Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:27:21.687Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:27:51.534Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:27:51.540Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:27:51.720Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:28:21.528Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:28:21.536Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:28:21.687Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:28:51.529Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:28:51.536Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:28:51.697Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:29:21.528Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:29:21.534Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:29:21.664Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:29:51.534Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:29:51.540Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:29:51.657Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:30:21.549Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:30:21.556Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:30:21.703Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:30:51.538Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:30:51.544Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:30:51.692Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:31:21.534Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:31:21.539Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:31:21.663Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:31:51.546Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:31:51.553Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:31:51.701Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:32:21.542Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:32:21.547Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:32:21.683Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:32:51.539Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:32:51.547Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:32:51.691Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:33:21.537Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:33:21.547Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:33:21.706Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:33:51.541Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:33:51.547Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:33:51.664Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:34:21.552Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:34:21.560Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:34:21.565Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:34:21.720Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:34:51.554Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:34:51.561Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:34:51.712Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:35:21.546Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:35:21.551Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:35:21.677Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:35:51.603Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:35:51.608Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:35:51.765Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:36:12.418Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:36:12.425Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:36:12.596Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:36:43.347Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:36:43.353Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:36:43.479Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:13.373Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:13.378Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:13.519Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:30.078Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:255:clearInput()) Removed source priority 1
 2020-08-15T18:37:30.083Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 240
 2020-08-15T18:37:38.373Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:158:registerInput()) Register new input 'Web Configuration@::ffff:10.100.0.21/COLOR' with priority 1 as inactive
 2020-08-15T18:37:38.379Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:198:setInput()) Priority 1 is now active
 2020-08-15T18:37:38.379Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 1
 2020-08-15T18:37:39.731Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:255:clearInput()) Removed source priority 1
 2020-08-15T18:37:39.736Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 240
 2020-08-15T18:37:43.348Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:43.353Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:43.521Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:45.361Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:45.370Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:45.392Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:45.400Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:45.403Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:45.422Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:158:registerInput()) Register new input 'Home Assistant@::ffff:10.100.0.20/COLOR' with priority 128 as inactive
 2020-08-15T18:37:45.428Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:198:setInput()) Priority 128 is now active
 2020-08-15T18:37:45.433Z [hyperiond HYPERION] (DEBUG) (PriorityMuxer.cpp:333:setCurrentTime()) Set visible priority to 128
 2020-08-15T18:37:45.495Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:45.502Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:45.506Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:54.946Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:37:54.952Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:54.953Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:54.979Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:37:54.985Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:54.989Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:55.038Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:37:55.041Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:37:55.045Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:38:13.354Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
 2020-08-15T18:38:13.359Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:38:13.362Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:38:13.498Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:38:43.362Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:38:43.367Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:38:43.515Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:38:54.048Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:1056:handleLoggingCommand()) log streaming activated for client ::ffff:10.100.0.21
 2020-08-15T18:38:54.230Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:1065:handleLoggingCommand()) log streaming deactivated for client  ::ffff:10.100.0.21
 2020-08-15T18:39:13.351Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:39:13.357Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:39:13.531Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:39:43.381Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:39:43.388Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:39:43.510Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:40:13.356Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:40:13.361Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:40:13.511Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:40:40.048Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:40:40.057Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:40:43.372Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:40:43.378Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:40:43.517Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:41:13.357Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
 2020-08-15T18:41:13.363Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
 2020-08-15T18:41:13.489Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
 2020-08-15T18:41:19.643Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:1056:handleLoggingCommand()) log streaming activated for client ::ffff:10.100.0.21

@Lord-Grey Lord-Grey self-assigned this Aug 15, 2020
@Lord-Grey Lord-Grey added needs investigation Further testing is required and removed Waiting For Review labels Aug 15, 2020
@Lord-Grey
Copy link
Collaborator

@dermotduffy Would you mind redoing the test again, please?

I do see that you disabled and enabled the device

 2020-08-15T18:21:22.522Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
2020-08-15T18:21:22.533Z [hyperiond LEDDEVICE] (DEBUG) (LedDeviceWled.cpp:157:powerOff()) 
 2020-08-15T18:21:22.538Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:153:put()) PUT: [http://wled-tv-lights/json/state] [{"on":false}]
 2020-08-15T18:21:22.543Z [hyperiond COMPONENTREG] (DEBUG) (ComponentRegister.cpp:36:setNewComponentState()) LED device: disabled
 2020-08-15T18:21:22.852Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:182:getResponse()) Reply.httpStatusCode [200]

 2020-08-15T18:21:39.221Z [hyperiond LEDDEVICE] (DEBUG) (LedDeviceWled.cpp:139:powerOn()) 
 2020-08-15T18:21:39.222Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:153:put()) PUT: [http://wled-tv-lights/json/state] [{"on":true}]
 2020-08-15T18:21:39.285Z [hyperiond LEDDEVICE] (DEBUG) (ProviderRestApi.cpp:182:getResponse()) Reply.httpStatusCode [200]
 2020-08-15T18:21:39.289Z [hyperiond COMPONENTREG] (DEBUG) (ComponentRegister.cpp:36:setNewComponentState()) LED device: enabled

But you did not provide anything after 18:41:13 that shows that an active device switch has happened.
Or did you stopped WLED and expected that hyperion LED-Device after sending the API Command would have light WLED again?

If it is the latter, then nothing can be done about it, given that this device works via UDP and hyperion will not recognise the unavailability of WLED. To continue the stream you would need to disable the device (manually or via API) and enable it afterwards.

@dermotduffy
Copy link
Contributor Author

I tested again, same results. But perhaps this is incorrect expectations on my end, and I don't quite follow what you mean in your last paragraph

In this test, I do not touch WLED. It is available throughout, and I do not interact with it at all beyond watching the output.

  • LEDDEVICE on.
  • Set a color in the Hyperion UI.
  • (Visual check: That color will correctly showing up on WLED)
  • API call to turn LEDDEVICE on (even though it is already on).

My expectation is that the WLED will continue to show that same color after the last API call (as semantically the API call should not have changed anything).

@Lord-Grey
Copy link
Collaborator

Lord-Grey commented Aug 16, 2020

@dermotduffy

In this test, I do not touch WLED

Thanks for confirming. I was looking for that.

Just to validate that I got the test result right.
WLED is showing correct colour after step 3.

"Step 4: API call to turn LEDDEVICE on" -> and then the WLED does what ? Turning off ? Flicker?

Would you mind sharing the log output after you send the API call to turn on the LED-device which is already enabled?
Do you see the same behaviour when running an effect?

In case you test #968 with PR #960, could you test this scenario too?

@dermotduffy
Copy link
Contributor Author

After step 4, WLED goes back to it's non-Hyperion mode (it drops the "WLED is receiving live Hyperion data..." banner) and just goes back to whatever WLED's last setting was. For example, in the screenshot I included earlier, it just goes back to showing solid red which was the prior color set in the native WLED interface (Hyperion had been sending green).

Yes -- happy to test this also against your PR!

@Lord-Grey
Copy link
Collaborator

As said before, I do not know how WLED react or can be configured.... as I lack a device myself (until now).

In case, Smoothing is off:

If you set a Color in Hyperion (e.g. green) then there will be one! update send to the device.
Only if there are further changes, new updates are send to the device.

Depending on WLED's behaviour, it may drop the "receiving hyperion data" banner, if no updates were received in a given timespan. That would explain the situation which is perfectly fine from my perspective.
Not sure, if WLED will then by itself change to the color before streaming.

Depending on the Smoothing timing you might also run in the same situation.

For me it looks like that WLED does some independent actions which you see the effects on....

@Lord-Grey
Copy link
Collaborator

WLED config

Timeout | 100..65000 | Time after which to resume normal mode once stream has stopped

Looks like that config item is causing your behaviour seen...

@dermotduffy
Copy link
Contributor Author

dermotduffy commented Aug 16, 2020

If it was a WLED timeout issue, then I would expect to see this behavior all the time (e.g. put up a Hyperion color, wait, then it should eventually disappear). However, I don't (at least not within any timeframe I've noticed) -- however I immediately see this behavior after the API command on the Hyperion side. Thus, it really does not seem like this is an issue with a WLED timeout ...

Going to try the new build now...

@dermotduffy
Copy link
Contributor Author

New build shows the same (IMO: broken) behavior.

  • Ensure LEDDEVICE is on.
  • Set a Hyperion color.
  • It will show up on WLED just fine.
  • Send an API command to turn LEDDEVICE on ...

... WLED resets immediately, losing the Hyperion banner and returns to its native settings.

@Lord-Grey
Copy link
Collaborator

Toobad. Seems i need to get hold of a WLED myself...
Any debug-log files you might want to share?

@dermotduffy
Copy link
Contributor Author

dermotduffy commented Aug 16, 2020

@Lord-Grey Happy to share whatever you think might be useful -- just let me know? Here's the latest failed test run:

2020-08-16T19:07:08.204Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
2020-08-16T19:07:08.213Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
2020-08-16T19:07:08.375Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Connection closed
2020-08-16T19:07:22.095Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:119:closedConnection()) Previous line repeats 1 times
2020-08-16T19:07:22.100Z [hyperiond JSONSERVER] (DEBUG) (JsonServer.cpp:103:newConnection()) New connection from: ::ffff:10.100.0.44 
2020-08-16T19:07:22.104Z [hyperiond JSONCLIENTCONNECTION] (DEBUG) (JsonAPI.cpp:107:handleInstanceSwitch()) Client '::ffff:10.100.0.20' switch to Hyperion instance 0
2020-08-16T19:07:33.644Z [hyperiond WEBSOCKET] (DEBUG) (JsonAPI.cpp:1056:handleLoggingCommand()) log streaming activated for client ::ffff:10.100.0.21

If there's anything else I can share, definitely let me know...

@Lord-Grey
Copy link
Collaborator

@dermotduffy I got hold of a WLED device myself now.
I tested the scenario myself, as well as checked with the WLED development team (see here).
It is as I outlined above. The WLED turns back to the state before streaming, if no updates received in a configured timeframe (timeout parameter).

For the static color update in hyperion only one update is sent (as normally the devices hold that color).
In the WLED scenario this is detected as a "streaming-stopped" scenario and therefore WLED falls back to the original state.

To overcome the WLED fallback behavior, please set the timeout = 65000 ms. (see https://github.com/Aircoookie/WLED/wiki/Settings)

Timeout | 100..65000 | Time after which to resume normal mode once stream has stopped. 65000 will keep the data indefinitely

Would you mind testing with the timeout parameter and report back, please?

@dermotduffy
Copy link
Contributor Author

@Lord-Grey Firstly, thank you continuing to investigate this issue, or misunderstanding.

Without touching the API, with the timeout parameter at the default 2500ms, I can set a color in Hyperion and it will 'hold' on WLED indefinitely. If Hyperion only sends a single color update, why does WLED hold it (far longer) than 2500ms by default? Regardless, the moment I send the API command to turn on LEDDEVICE (when it is already on), WLED will immediately reset.

In my view, this is a fundamentally surprising behaviour. Turning something on, that is already on, should have no observable impact -- and this is demonstrably not the case. Are you able to reproduce this effect?

Now, to the timeout value: If I set it to 65000ms, I confirm I do NOT observe this behaviour. The hold of color that WLED had appears to 'stick' despite the LEDDEVICE API call.

... but that honestly feels besides the point of this bug: setting something to 'on', that is already 'on', should not be able to cause any observable impact regardless of any settings for anything outside of Hyperion, i.e. why is there not a check in the API code to take no action when LEDDEVICE is already on, and discard the API call? If truly no action was taken by Hyperion, then WLED would not reset (regardless of its timeout value).

@Lord-Grey
Copy link
Collaborator

@dermotduffy The observation is not linked to the API usage. This is just a co-incidence.
You can go to the UI and set a Color manually (as per step 2).
Do not send the API request!!!
but after the timeout you will see the same behavior.

In case you enable a device which is already enabled, the request is ignored.
You can check the code....

void LedDevice::setEnable(bool enable)
{
	bool isSwitched = false;
	// switch off device when disabled, default: set black to LEDs when they should go off
	if ( _isEnabled  && !enable)
	{
		isSwitched = switchOff();
	}
	else
	{
		// switch on device when enabled
		if ( !_isEnabled  && enable)
		{
			isSwitched = switchOn();
		}
	}
....

@dermotduffy
Copy link
Contributor Author

@dermotduffy The observation is not linked to the API usage. This is just a co-incidence.
You can go to the UI and set a Color manually (as per step 2).
Do not send the API request!!!
but after the timeout you will see the same behavior.

I do not. An experiment I just performed:

Run 1:

  • Verify wled timeout is 2500ms (the default).
  • Set the color manually in the Hyperion UI.,
  • Verify color appears in WLED.
  • Start a 60 second timer ...
  • Verify that after 60 seconds, the color is still in WLED.

Run 2:

  • Verify wled timeout is 2500ms (the default).
  • Set the color manually in the Hyperion UI.,
  • Verify color appears in WLED.
  • Start a 60 second timer ...
  • After 3 seconds, send the API request included in this bug:
echo '{"command":"componentstate", "componentstate":{"component":"LEDDEVICE", "state": true} }' | nc  hyperion 19444
  • WLED will immediately reset to the prior settings after sending the API call.

Thank you for the code, I agree that appears like it should cope with this situation, so I cannot explain what's going on here.

Would you mind repeat the above experiment on your side with your WLED device and see what behavior you get?

@Lord-Grey
Copy link
Collaborator

@dermotduffy Thanks for the update.

Could you test with smoothing off?
Just disable Smoothing via "Remote Control" and run the test scenario 1.
There you should see the effect, I described.

I will further investigate what happens when smoothing is on and the API call.
In addition, may I ask you to share your smoothing configuration, please?

@Lord-Grey
Copy link
Collaborator

Lord-Grey commented Aug 30, 2020

I can reproduce with smoothing on and the device enablement trigger.

The situation is due to the fact that the Smoothing ColorQueue is cleared on a LED-Device update

	if(component == hyperion::COMP_LEDDEVICE)
	{
		clearQueuedColors();
	}

which makes WLED there is no stream any longer.

I need to think about it.... Thanks for your patience.

PS: Nevertheless, the WLED Timeout should be set to 65000 disabling the stream timeout detection.

@dermotduffy
Copy link
Contributor Author

Aha. Yes, it's smoothing related! If I disable smoothing, then the WLED timeout actually behaves as I would have expected (i.e. 2500ms only holds the color for 2.5ms, 10000ms holds it for 10s, etc).

My smoothing config:

smoothing

It is presumably the 'Continuous output' option that is causing it to appear to 'bypass' the WLED timeout, and the code snippet you found that causes it 'reset' upon LED device change.

Phew -- thank you for getting to the bottom of this!

@Lord-Grey Lord-Grey added Bug and removed needs investigation Further testing is required labels Aug 31, 2020
Lord-Grey added a commit to Lord-Grey/hyperion.ng that referenced this issue Nov 21, 2021
@Lord-Grey Lord-Grey mentioned this issue Nov 21, 2021
14 tasks
Lord-Grey added a commit that referenced this issue Dec 14, 2021
* Fix #967

* Start Smoothing in pause mode to avoid resource usage, if hyperion is started without active priority

* Update Changelog
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants