Nanoleaf binding fails after receiving API response from controller

pne1913 · March 1, 2020, 8:52pm

Hello,

Been trying to get my Nanoleaf panels linked in to OH, but the binding seems to fail when the Rhythm module is attached. Please see log trace below (serial/auth key XXXX’d out).

2020-03-01 15:30:27.164 [DEBUG] [al.handler.NanoleafControllerHandler] - Run update job
2020-03-01 15:30:27.164 [DEBUG] [al.handler.NanoleafControllerHandler] - Update channels for controller nanoleaf:controller:5d62aece
2020-03-01 15:30:27.164 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - RequestBuilder: Sending Request gizmohub.jnet.local:16021 /api/v1/XXXXXX/ 
2020-03-01 15:30:27.165 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Sending Request http://gizmohub.jnet.local:16021/api/v1/XXXXXXX/ no query parameters
2020-03-01 15:30:27.165 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Request method:GET uri:http://gizmohub.jnet.local:16021/api/XXXXXXX/ params{}

2020-03-01 15:30:27.196 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - API response from Nanoleaf controller: {"name":"Nanoleaf-DFD8","serialNo":"XXXXXX","manufacturer":"Nanoleaf","firmwareVersion":"3.0.8","model":"NL22","state":{"on":{"value":true},"brightness":{"value":100,"max":100,"min":0},"hue":{"value":0,"max":360,"min":0},"sat":{"value":0,"max":100,"min":0},"ct":{"value":4000,"max":6500,"min":1200},"colorMode":"effect"},"effects":{"select":"Color Burst","effectsList":["Color Burst","Fireworks","Flames","Forest","Inner Peace","Meteor Shower","Nemo","Northern Lights","Paint Splatter","Pulse Pop Beats","Rhythmic Northern Lights","Ripple","Romantic","Snowfall","Sound Bar","Streaking Notes"]},"panelLayout":{"layout":{"numPanels":10,"sideLength":150,"positionData":[{"panelId":85,"x":0,"y":173,"o":180,"shapeType":0},{"panelId":111,"x":149,"y":259,"o":120,"shapeType":0},{"panelId":42,"x":299,"y":259,"o":120,"shapeType":0},{"panelId":132,"x":149,"y":173,"o":300,"shapeType":0},{"panelId":116,"x":-74,"y":43,"o":60,"shapeType":0},{"panelId":124,"x":224,"y":303,"o":180,"shapeType":0},{"panelId":88,"x":374,"y":303,"o":60,"shapeType":0},{"panelId":109,"x":-74,"y":129,"o":0,"shapeType":0},{"panelId":138,"x":74,"y":129,"o":0,"shapeType":0}]},"globalOrientation":{"value":0,"max":360,"min":0}},"rhythm":{"rhythmConnected":true,"rhythmActive":false,"rhythmId":436,"hardwareVersion":"2.0","firmwareVersion":"2.4.2","auxAvailable":false,"rhythmMode":0,"rhythmPos":{"x":-149,"y":0,"o":240}}}
2020-03-01 15:30:27.196 [DEBUG] [nding.nanoleaf.internal.OpenAPIUtils] - API response code: 200
2020-03-01 15:30:27.198 [DEBUG] [al.handler.NanoleafControllerHandler] - Set to device type lightPanels
2020-03-01 15:30:27.199 [TRACE] [al.handler.NanoleafControllerHandler] - Configuration property: key deviceType value lightPanels
2020-03-01 15:30:27.199 [TRACE] [al.handler.NanoleafControllerHandler] - Configuration property: key address value gizmohub.jnet.local
2020-03-01 15:30:27.199 [TRACE] [al.handler.NanoleafControllerHandler] - Configuration property: key port value 16021
2020-03-01 15:30:27.199 [TRACE] [al.handler.NanoleafControllerHandler] - Configuration property: key refreshInterval value 60
2020-03-01 15:30:27.200 [TRACE] [al.handler.NanoleafControllerHandler] - Configuration property: key authToken value XXXXXX
2020-03-01 15:30:27.200 [DEBUG] [al.handler.NanoleafControllerHandler] - Thing property:  key serialNumber value XXXXXX
2020-03-01 15:30:27.200 [DEBUG] [al.handler.NanoleafControllerHandler] - Thing property:  key firmwareVersion value 3.0.8
2020-03-01 15:30:27.200 [DEBUG] [al.handler.NanoleafControllerHandler] - Thing property:  key modelId value 
2020-03-01 15:30:27.200 [DEBUG] [al.handler.NanoleafControllerHandler] - Thing property:  key vendor value 
2020-03-01 15:30:27.201 [WARN ] [al.handler.NanoleafControllerHandler] - Update job failed
java.lang.IndexOutOfBoundsException: Index: 9, Size: 9
	at java.util.ArrayList.rangeCheck(ArrayList.java:657) ~[?:1.8.0_242]
	at java.util.ArrayList.get(ArrayList.java:433) ~[?:1.8.0_242]
	at org.openhab.binding.nanoleaf.internal.model.Layout.getLayoutView(Layout.java:78) ~[?:?]
	at org.openhab.binding.nanoleaf.internal.handler.NanoleafControllerHandler.updateFromControllerInfo(NanoleafControllerHandler.java:650) ~[?:?]
	at org.openhab.binding.nanoleaf.internal.handler.NanoleafControllerHandler.runUpdate(NanoleafControllerHandler.java:351) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_242]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_242]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_242]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_242]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]

When I unplug the Rhythm module, the binding generally works, although somewhat unreliably. It seems to choke a lot when selecting various effects.

The only Thing I have defined is the controller itself. I have a few Items linked to state channels for control.
This is pretty frustrating, and completely breaks OpenHAB integration. Any suggestions would be greatly appreciated!

stefan.hoehn · March 14, 2020, 11:19am

@pne1913

Sorry, I only noticed your posting now. Can you please answer all questions below one by one because I would like to find this issue

Which version of openhab are you using? Make sure you use at least version 2.5.2
Do you have squared or triangle panels? (I presume it is triangles as the rhythm module is not available for canvas). Note that I do not have them myself and triangle layouts may be much more complex than canvas ones. Therefore I guess the problem lies here.
Do you know how to set the logging level to debug or trace?
Do you know how copy a specific version of the binding to the addon folder if I provided you an update to test a fix (if I can provide one)?

FYI: I know a way how I could easily prevent this issue and I will but I really like to know the root cause of the problem, so if you are able to set it it trace and I see the result that comes from your device I am pretty sure I can see what is going on.

cheers
Stefan

pne1913 · March 24, 2020, 2:16am

@stefan.hoehn
Hi Stefan,

Sorry for the delayed response.

Yes, I’m using 2.5.2
Triangular
I thought the logdump I posted included the full trace/debug output.
Not immediately, but I could take a few hours and I’m sure I could figure it out.

Thanks!
Jordan

stefan.hoehn · March 24, 2020, 5:08am

Ok, then please go ahead and use the latest 2.5.3 version which is already out, make sure you have the log level set to trace. Then try it once with the rhythm module and then with the module. Make sure you write the times down so I can relate the logs to the particular events. Then provide the logs to me.

Cheers
Stefan

pne1913 · March 25, 2020, 8:42pm

@stefan.hoehn

Hello Stefan,

Less than five minutes after I replied to you, I saw that 2.5.3 had hit my repository, and as soon as I updated it, things started working! The binding now properly detects the Rhythm module. However, there are still some issues.
First, the rhythmMode channel doesn’t send a proper API request to the controller, and we get a 422 in response.

2020-03-25 16:27:44.503 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - RequestBuilder: Sending Request gizmohub.jnet.local:16021 /api/v1/XXXXX/rhythm/rhythmMode 
2020-03-25 16:27:44.503 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Sending Request http://gizmohub.jnet.local:16021/api/v1/XXXXX/rhythm/rhythmMode no query parameters
2020-03-25 16:27:44.503 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Request method:PUT uri:http://gizmohub.jnet.local:16021/api/v1/XXXXX/rhythm/rhythmMode params{}

2020-03-25 16:27:44.504 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Content {"rhythmConnected":false,"rhythmActive":false,"rhythmId":0,"hardwareVersion":"","firmwareVersion":"","auxAvailable":false,"rhythmMode":1}
2020-03-25 16:27:44.561 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - API response from Nanoleaf controller: 
2020-03-25 16:27:44.561 [DEBUG] [nding.nanoleaf.internal.OpenAPIUtils] - API response code: 422
2020-03-25 16:27:44.561 [WARN ] [al.handler.NanoleafControllerHandler] - Handling command 1 to channelUID nanoleaf:controller:5d62aece:rhythmMode failed: OpenAPI request failed. HTTP response code 422

I have a bash script+rules file that I’d been using until now to control the Nanoleaf, and I can send an API query like this:

curl -X PUT -H "Content-Type: application/json" -d '{"rhythmMode":'$MODE'}' "http://gizmohub.jnet.local:16021/api/v1/XXXXX/rhythm/rhythmMode"

My guess is that the controller doesn’t like all the other parameters, like rhythmConnected, rhythmActive, etc that the binding is sending it.

Second, and this could just be my misinterpretation of the online docs, but using a Dimmer on the ‘color’ channel does not actually dim the panels, as the docs state it should. It terminates the Effect in use and sets the brightness and color temperature. Again, using my bash script+rules file, I’m able to achieve the desired result with:

    echo "Brt: $2"
    curl -v -X PUT -H "Content-Type: application/json" -d '{"brightness":{"value":'$2'}}' "http://gizmohub.jnet.local:16021/api/v1/XXXXX/state/"

Thanks!
Jordan

stefan.hoehn · March 29, 2020, 4:25pm

Hi @pne1913

Thanks for your detailed analysis.

Unfortunately I don’t have triangles myself. Only “mraepple” has some of them. I am currently waiting on Nanoleaf to get some triangles so I can support the binding and the community better. Until then, you may want to contact Martin (mraepple) if he can reproduce what you are saying.

As soon as I have my own triangles I am happy to jump on it to track down the issue.

cheers
Stefan

pne1913 · April 4, 2020, 9:49pm

@stefan.hoehn @mraepple

Hello,

I do not yet have enough expertise with the OpenHAB architecture to start compiling and developing on my own, but I think I can see the problem. Playing around with curl, I get the same HTTP 422 response when I send the same JSON data that the binding is sending. As soon as I strip out the read-only API parameters, the request works fine. So I think that’s the fix.

Looking through Rhythm.java, it looks to me like every API flag is exposed to the JSON serializer. When the sendRythmCommand() function generates the content of the Request object, it’s using the entire Ryhthm object, instead of just the one parameter.

Request setNewRhythmRequest = requestBuilder(API_RHYTHM_MODE, HttpMethod.PUT);
setNewRhythmRequest.content(new StringContentProvider(gson.toJson(rhythm)), "application/json");
sendOpenAPIRequest(setNewRhythmRequest);

Not knowing much about the underlying OpenHAB engine, I don’t know if this is the right approach, but I would recommend something like this instead, where we only pull out the rhythmMode parameter from the Rhythm object:

Request setNewRhythmRequest = requestBuilder(API_RHYTHM_MODE, HttpMethod.PUT);
setNewRhythmRequest.content(new StringContentProvider(gson.toJson(rhythm.getRhythmMode())), "application/json");
sendOpenAPIRequest(setNewRhythmRequest);

Another approach might be to create a RhythmMode class that only exposes the rhythmMode parameter to the JSON serializer. In which case:

private void sendRhythmCommand(Command command) throws NanoleafException {
  RhythmMode rhythmMode = new RhythmMode(); // doesn't currently exist
  if (command instanceof DecimalType) {
    rhythmMode.setRhythmMode(((DecimalType) command).intValue());
  } else {
    logger.error("Unhandled command type: {}", command.getClass().getName());
    throw new NanoleafException("Unhandled command type");
  }
  Request setNewRhythmRequest = requestBuilder(API_RHYTHM_MODE, HttpMethod.PUT);
  setNewRhythmRequest.content(new StringContentProvider(gson.toJson(rhythmMode)), "application/json");
  sendOpenAPIRequest(setNewRhythmRequest);
}

If either of you are interested in compiling a modified version, I’d be happy to test it out.

Hope you’re healthy!
Jordan

stefan.hoehn · April 7, 2020, 7:27pm

Hi Jordan,

sorry for not answering earlier but I had a lot to do the last days.

I decided to approach the first idea first:

I exchanged

setNewRhythmRequest.content(new StringContentProvider(gson.toJson(rhythm)), “application/json”);

by

setNewRhythmRequest.content(new StringContentProvider(gson.toJson(rhythm.getRhythmMode())), “application/json”);

I have compiled that version and you can download it here (within the next 7 days)

Hope that it helps. Otherwise you would need to tell me how the RhythMode-class would look like compared to the Rhythm:

    private boolean rhythmConnected;
    private boolean rhythmActive;
    private int rhythmId;
    private String hardwareVersion = "";
    private String firmwareVersion = "";
    private boolean auxAvailable;
    private int rhythmMode;
    private @Nullable RhythmPos rhythmPos;

Cheers
Stefan

pne1913 · April 18, 2020, 10:52pm

@stefan.hoehn @mraepple

Stefan,

The change you made doesn’t appear to be working. It looks like it’s not passing a valid JSON string to OpenAPI.

2020-04-18 18:39:33.957 [DEBUG] [al.handler.NanoleafControllerHandler] - Received command 0 for channel nanoleaf:controller:5d62aece:rhythmMode
2020-04-18 18:39:33.958 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - RequestBuilder: Sending Request gizmohub.jnet.local:16021 /api/v1/XXXXX/rhythm/rhythmMode 
2020-04-18 18:39:33.959 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Sending Request http://gizmohub.jnet.local:16021/api/XXXXX/rhythm/rhythmMode no query parameters
2020-04-18 18:39:33.960 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Request method:PUT uri:http://gizmohub.jnet.local:16021/api/v1/XXXXX/rhythm/rhythmMode params{}

2020-04-18 18:39:33.961 [TRACE] [nding.nanoleaf.internal.OpenAPIUtils] - Content 0

2020-04-18 18:39:34.411 [WARN ] [al.handler.NanoleafControllerHandler] - Handling command 0 to channelUID nanoleaf:controller:5d62aece:rhythmMode failed: Failed to send OpenAPI request

So it looks like the binding is just passing a straight 0 or a 1, based on my selection of MIC or AUX- it’s not packaging it up as a JSON string.

Jordan

stefan.hoehn · April 19, 2020, 5:45am

Can you switch on the trace level for logging as it then logs all requests and responses.

pne1913 · April 22, 2020, 8:42pm

@stefan.hoehn

The nanoleaf binding is already set to trace in the output above.

mpuff · April 23, 2020, 2:16pm

i get in the latest 2.5.4 version this error:

2020-04-23 14:12:33.849 [hingStatusInfoChangedEvent] - 'nanoleaf:controller:D6249CABB6F5' changed from OFFLINE (COMMUNICATION_ERROR): Communication failed. Please check configuration. to ONLINE

stefan.hoehn · April 23, 2020, 2:21pm

Please provide the logs with the level set to “trace” with the logs before this.

pne1913 · April 26, 2020, 9:29pm

@stefan.hoehn

I’m sorry, I don’t understand what you’re asking. The log output I’ve posted is already at trace.