Sony Devices Binding

Same thing here. Today I tried the WOL with SimpleIP. The magic packet was send but the tv didnt turn on:

2019-03-14 20:04:13.307 [DEBUG] [y.internal.simpleip.SimpleIpProtocol] - Sending WOL packet to FC:F1:52:A5:02:57 (192.168.0.14)
2019-03-14 20:04:13.308 [DEBUG] [y.internal.simpleip.SimpleIpProtocol] - Sending '*SCPOWR0000000000000001'
2019-03-14 20:04:14.072 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:04:26.316 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:04:38.320 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:04:50.322 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:05:02.325 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
...

Then it used my item defined with the WoL bindung and it turned on directly:

2019-03-14 20:07:20.828 [INFO ] [nhab.binding.wol.internal.WolBinding] - Wake-on-LAN packet sent [broadcastIp=192.168.0.255, macaddress=fcf152a50257]
2019-03-14 20:07:21.470 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:07:33.472 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:07:45.476 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:07:57.478 [DEBUG] [ny.internal.net.SocketChannelSession] - Connecting to 192.168.0.14:20060
2019-03-14 20:08:08.424 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - Found Sony WebScalarAPI service: uuid:00000000-0000-1010-8000-fcf152a50257

Not a big thing. Using nhab.binding.wol.internal.WolBinding works good for me with some rules but if not needed it would be nice.

I think I spotted an error you two might be triggering - wait for the next version. Iā€™m going to be gone for the next 5 days - so Iā€™ll catch up when I get backā€¦

I think chopping of last octet an replacing it with 255 will work in 99,9%. So i think this is totally fine.

Anyway an idea for some later optimization:
Maybe you can get a value from org.eclipse.smarthome.network.
The primary subnet of openhab can be defined there via Paper UI > Configuration > System Network Settings. With the IP and subnet mask the broadcast address can be calculated (sure you know this). On the downside i think its not required to set this so most users would not have done it. On the other hand its a dropdown value so maybe the information is there anyway.

With the new Version 2.5.0.201903121651 my Scalar thing is still not going online. Not much i can say about that at this moment so just a big log again. (14MB ziped to som KB). Zip-files are not allowed so after download rename it(delete ā€œ.logā€).
SCALAR.7z.log (247.8 KB)

Ok it works only when I just turned off the TV. Otherwise after some time it doesnā€™t work ā€œno route to Hostā€. Another problem is that the binding will forget the Mac adress and refresh value after some time. So I have created the TV within a. things file.

I cant see the ā€œno route to hostā€ error in my logs but it did not work for me too. To test it you have to turn off your tv for more than 5 minutes. You will see the binding is no longer online after that time. I even can hear my tv make a click sound. I think we wait to the next version.

In the meantime i use the integrated WoL Binding ā€œWOL (Wake-on-LAN) Bindingā€ (binding-wol1 - 1.13.0)

I defined an item like this:

Switch WoL_WZ_TV   "TV WoL"  <screen>  { wol="192.168.0.255#FC:F1:52:A5:02:57", autoupdate="false" }

I used autoupdate="false" because sending the WoL packet dosent mean the tv is really turned on. Maybe its unplugged or something. So after sending ON command to the item, wich triggers sending the WoL packet, it stays OFF.
To sync it with the real state of the tv read from the binding it use this simple rule:

rule "WoL_WZ_TV aktualisieren auf SonySimpleIP_Power.state"
when
	Item SonySimpleIP_Power changed 
then
	logInfo( "tv_wol.rules", "Rule 'WoL_WZ_TV aktualisieren auf SonySimpleIP_Power.state' triggered" )
	WoL_WZ_TV.postUpdate(SonySimpleIP_Power.state)	
end

This updates my WoL item when the tv is going ON or OFF even for instance if the tv remote is used.
Another rule helps me to send an OFF via the binding when i switch of my WoL item:

rule "WoL_WZ_TV zum Ausschalten nutzen"
when
	Item WoL_WZ_TV received command OFF  
then
	logInfo( "tv_wol.rules", "Rule 'WoL_WZ_TV zum Ausschalten nutzen' triggered" )
	SonySimpleIP_Power.sendCommand(OFF)	
end

Works good.

Hi, thanks for the new binding. SimpleIP is working just fine. But i got problems with Scalar.
I got it registered with the 4-digit code, but since then it does not connect properly.
Can somebody support?

Attached i have a debug log (some seconds in normal logging, then switched to debug logging at some point)

sony_log.txt (556.2 KB)

@freke

Are you still around? Iā€™m integrating your sonyaudio into the main sony one (working great so far and it covers SOOO many more devices as well - and itā€™s exposing some issues I had in mine with version handling!!).

I have a quick(?) question for youā€¦

When you receive the notification - is the version on the notification always ā€œ1.0ā€ (seems like it is). Example: if I call setPowerStatus using v1.1 style - the notification I get back is still 1.1 style but the notification itself says 1.0 style. Hereā€™s a bit of the log - you can see my transport calling it with the v1.1 style and both your binding/mine receiving back a 1.0 notification even though itā€™s a 1.1 style:

2019-03-21 14:41:16.769 [DEBUG] [s.i.s.t.SonyWebSocketTransport:174  ] - Sending {"id":16,"method":"setPowerStatus","version":"1.1","params":[{"status":"off"}]} to ws://192.168.1.167:10000/sony/system
2019-03-21 14:41:16.775 [DEBUG] [b.s.i.s.models.ScalarWebResult:94   ] - >>> result: 16, [], []
2019-03-21 14:41:16.775 [DEBUG] [s.i.s.t.SonyWebSocketTransport:201  ] - Response received from server: {"id":16,"result":[]}
2019-03-21 14:41:18.433 [DEBUG] [s.i.s.t.SonyWebSocketTransport:210  ] - Event received from server: {"method":"notifyPowerStatus","params":[{"standbyDetail":"","status":"standby"}],"version":"1.0"}
2019-03-21 14:41:18.431 [DEBUG] [.b.s.i.p.SonyAudioClientSocket:149  ] - Message received from server: {"method":"notifyPowerStatus","params":[{"standbyDetail":"","status":"standby"}],"version":"1.0"}
2019-03-21 14:41:18.432 [DEBUG] [.b.s.i.p.SonyAudioClientSocket:160  ] - Event received from server: {"method":"notifyPowerStatus","params":[{"standbyDetail":"","status":"standby"}],"version":"1.0"}

for now - Iā€™m just assuming the notify format is the same version style as the originating calling version (so if Iā€™m calling setPowerStatus 1.1 - the notification will be a 1.1 style).

Note: the above is on my HT-NT5 for referenceā€¦

@andirs

The problem you are having is that the device is turned off when you started openHAB and it canā€™t get information from the TV when itā€™s off. Thatā€™s what Iā€™m trying to solve with creating the device definitions but am not there yet.

For now - turn on the TV, start openHAB and it should come online - once itā€™s online , you can turn the TV on/off whatever and it should remain online. Just needs to be on when the binding is first starting up

As I said - this should be a bit temporary until Iā€™ve got the definition thing the way I want itā€¦

Just to let everyone know - the next update is pretty darn big. Iā€™m integrating the sonyaudio stuff (websocket connections) and Iā€™ve learned ALOT about the sony api and what I may have been doing wrong with it (mainly with the various API versions). However - itā€™s taking me awhile to get through everything - expect an update maybe next week (or the next).

Note: the update will hopefully fix the WOL thing as wellā€¦

5 Likes

Thanks for your reply. Unfortunately not working.
I turned on the TV and restarted OH2 completely, but still the same issue.
I unregistered OH as remote control restartet everything and reconnected and now the same issue.

Here from my logs (not in debug):

2019-03-22 08:39:08.439 [hingStatusInfoChangedEvent] - 'sony:scalar:mysonytv' changed from OFFLINE (COMMUNICATION_ERROR): Access Code requested. Please update the Access Code with what is shown on the device screen to OFFLINE (COMMUNICATION_ERROR): Storage doesn't exist.
2019-03-22 08:39:09.574 [me.event.ThingUpdatedEvent] - Thing 'sony:scalar:mysonytv' has been updated.
2019-03-22 08:39:09.578 [hingStatusInfoChangedEvent] - 'sony:scalar:mysonytv' changed from OFFLINE (COMMUNICATION_ERROR): Storage doesn't exist. to ONLINE
2019-03-22 08:39:25.845 [hingStatusInfoChangedEvent] - 'sony:scalar:mysonytv' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Storage doesn't exist.
2019-03-22 08:39:26.866 [me.event.ThingUpdatedEvent] - Thing 'sony:scalar:mysonytv' has been updated.

Edit:
Ok the issue might be somewhere else. I completely removed the scalar thing, but these log are still coming regularly.

2019-03-22 08:43:46.092 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ScalarWebHandler tried updating the thing status although the handler was already disposed.
2019-03-22 08:43:47.182 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ScalarWebHandler tried updating thing sony:scalar:mysonytv although the handler was already disposed.

Edit2:
After a restart the thing seems to be really gone, but after adding the thing again, to problem reoccours just like before :frowning:

@andirs
Thanks - Iā€™ll need to look harder into that error then - something is leaking out to the thing and pulling it off line. Iā€™ll see what I can do. As for the messages occurring - thatā€™s something I have fixed in my version that youā€™ll get in the next (wasnā€™t properly cleaning up a thread)

1 Like

Just a quick update - still working on the code. Iā€™ve had to do some extensive reworks based on some (wrong) assumptions I made with the prior code and Iā€™m still testing through those changes. On the plus side, the binding now works with my soundbar and has enabled scalar on my bluray players. Iā€™ve also ordered a AVR (dn1080) to test with (suppose to arrive next week - may or may not be able to test with it before the next release). I think a version might be good to release next week.

Please note that there will be some backward compatibility issues with this (Iā€™m dropping one channel) and I definitely will have some files for you all to send me back.

Stay tunedā€¦

Tim

2 Likes

@andirs
Iā€™m having troubles finding that ā€œstorage doesnā€™t existā€ issue. Could you stop your openhab, blow the log away, and restart openhab - wait until it goes offline again with ā€œstorage doesnā€™t existā€ - then send me the log? I need to see all the steps itā€™s taking to get there.

Note: instead of posting to the log - could you just put it into send.firefox.com and post the link. That way itā€™s not taking up resourcesā€¦

Thanks,
Tim

Hi Tim,

of course, i am happy to help. Here you go:

For a short time the thing goes online (which can also be seen in the log) and then i am able to control the TV, but shortly after that it goes offline

Storage doesn't exist.

If you got questions feel free to ask :slight_smile:

@andirs

Are you running this on a PI by any chance? It looks like the connection attempt is running longer than it should and is being cancelled each time (which may be a result of an slow processor like the PI). Regardless - could you go into the thing configuration and bump the ā€œRetry Pollingā€ setting up (make it like 60) and see if it goes online.

Thanks,
Tim

Yes i am running it on an RPi 3. I guess recources shouldnā€™t be an issue since there is plenty of CPU and memory recources left. Changing the polling to 60s made that the thing stayed online for approx. 60s and then went offline with the same error. Maybe i should just deactivate the polling :smiley:

Edit: When deactivating the polling (-1s) it actually seems that the Thing stays online and operable. However i donā€™t know what could be the negative long term effects.

Furthermore i noticed the (new) behaviour that the tv channel switches remain ON when i switch to a new channel. In the old binding version i can remeber that it was different. I am not sure if a switch immediately went OFF again or if only the last switch remained ON and the others turned OFF. This way several (in an extreme case all) channels could be ON at the same time. Donā€™t know if this is intended, so thought i report :slight_smile:

From working with the NEEO binding - I know PIs have limited capabilities and the sony addon will definitely stress it out at startup because it does a BUNCH of calls/processing to startup (and on each polling). With polling disabled, youā€™re seeing some of the side effects - if there is a channel that affects other channels, those other channels wonā€™t change because the polling is disabled (so the other channels wonā€™t turn to OFF because it doesnā€™t know itā€™s off). Outside of what you noticed, there will be side effects to volume and a few other things that are ā€˜relatedā€™.

Just an experiment - Try setting it to some huge value (like 600 for 10 minutes) and see if it comes online (stays online) and your ON/OFF goes away (of course after 10 minutes). Iā€™m betting it will. If it doesnā€™t - itā€™s something in my code.

Performance will eventually be looked at (like I did with NEEO addon and got it to run reasonably on a PI3) - but itā€™s not very high on the priority right now unfortunatelyā€¦

EDIT:
Another interesting thing - you can keep it at -1, look in your log for ā€œAttempting connection to Scalar Web deviceā€¦ā€ and note the timestamp. Then look after that to the ā€œONLINEā€ debug message to see itā€™s timestamp - that should tell you how long it took to do the initial (and polling) time. Would be interesting to hear what it was (then you can intelligently set the polling to that time plus some extra)

Thanks for your suggestions. Here is what i found out:

I set the ā€œretry pollingā€ to 600s. During the first 10 minutes i can change channels and the ON/OFF switches issue is not present like when I set i to -1s. When activating a new channel the previous goes off. But after 10 minutes the Thing goes off again:

2019-04-04 17:25:07.888 [hingStatusInfoChangedEvent] - 'sony:scalar:18e7d15c5870' changed from OFFLINE (COMMUNICATION_ERROR): Storage doesn't exist. to ONLINE
2019-04-04 17:35:18.543 [hingStatusInfoChangedEvent] - 'sony:scalar:18e7d15c5870' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Storage doesn't exist.

What i also found out is that my Thing changes over time (i suspect when the port changes in the Scalar Web URL). When it changes all settings are reset. So my access code is ā€œRQSTā€ again and my retry polling is also the default value again. Observed that behaviour several times now. Donā€™t know if it is related, but it seems this is (also) a bug.

@andirs
Interesting about the port change - if thatā€™s the case, I see why all the values change back as well (since thatā€™s part of discovery). Let me think on that one

1 Like