2020-12-16 12:45:47.073 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'sony:dial:94db565a279d' to inbox.
2020-12-16 12:49:32.927 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:33.009 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:33.092 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:37.932 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:38.018 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:38.094 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:42.935 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:43.021 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:43.098 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:47.938 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:48.024 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:48.103 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:49.014 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:49:49.017 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:49:49.020 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@13d7f6
2020-12-16 12:49:49.020 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@d3ac61
2020-12-16 12:49:49.020 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a942db
2020-12-16 12:49:49.023 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136082,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:49.023 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@ae35bc
2020-12-16 12:49:49.026 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:10000 - successful
2020-12-16 12:49:49.035 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136082,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:49:49.040 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136082,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:49:49.046 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136083,"method":"getSourceList","version":"1.1","params":[{"scheme":"dlna"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:49.057 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136083,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]})
2020-12-16 12:49:49.062 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136083,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]}
2020-12-16 12:49:49.067 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136084,"method":"getSourceList","version":"1.1","params":[{"scheme":"storage"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:49.080 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136084,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]})
2020-12-16 12:49:49.085 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136084,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]}
2020-12-16 12:49:49.112 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136085,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:49.118 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136085,"result":[[]]})
2020-12-16 12:49:49.122 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136085,"result":[[]]}
2020-12-16 12:49:52.941 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:53.027 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:53.105 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:49:57.943 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:49:58.029 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:49:58.107 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:02.946 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:03.032 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:03.109 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:07.949 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:08.051 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:08.113 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:08.818 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:50:08.890 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:50:08.897 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:50:08.901 [DEBUG] [nding.sony.internal.ircc.IrccHandler] - Attempting connection to IRCC device...
2020-12-16 12:50:08.992 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml
2020-12-16 12:50:09.126 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-3
1 > GET http://xxx.xxx.xxx.xxx:50001/Ircc.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.134 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread OH-thingHandler-3
1 < 200
1 < Accept-Ranges: none
1 < Connection: close
1 < content: text/xml; charset=utf-8
1 < Content-Length: 2575
1 < Date: Wed, 16 Dec 2020 11:50:08 GMT
1 < Server: Linux/3.10 UPnP/1.0 Sony-BDP/2.0
<?xml version="1.0"?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000003-0000-1010-8000-94db565a279d</UDN>
    <iconList>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.png</url>
      </icon>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.png</url>
      </icon>
    </iconList>
    <serviceList>
      <service>
        <serviceType>urn:schemas-sony-com:service:IRCC:1</serviceType>
        <serviceId>urn:schemas-sony-com:serviceId:IRCC</serviceId>
        <SCPDURL>/IRCCSCPD.xml</SCPDURL>
        <controlURL>/upnp/control/IRCC</controlURL>
        <eventSubURL></eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_IRCC_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_IRCC_Version>1.0</av:X_IRCC_Version>
      <av:X_IRCC_CategoryList>
        <av:X_IRCC_Category>
          <av:X_CategoryInfo>AAMAABxa</av:X_CategoryInfo>
        </av:X_IRCC_Category>
      </av:X_IRCC_CategoryList>
    </av:X_IRCC_DeviceInfo>
    <av:X_UNR_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_UNR_Version>1.3</av:X_UNR_Version>
      <av:X_CERS_ActionList_URL>http://xxx.xxx.xxx.xxx:50002/actionList</av:X_CERS_ActionList_URL>
    </av:X_UNR_DeviceInfo>
    <av:X_RDIS_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_RDIS_Version>1.0</av:X_RDIS_Version>
      <av:X_RDIS_SESSION_CONTROL>false</av:X_RDIS_SESSION_CONTROL>
      <av:X_RDIS_ENTRY_PORT>50004</av:X_RDIS_ENTRY_PORT>
    </av:X_RDIS_DeviceInfo>
  </device>
</root>


2020-12-16 12:50:09.150 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and got IRCCRoot response: <?xml version="1.0"?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000003-0000-1010-8000-94db565a279d</UDN>
    <iconList>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.png</url>
      </icon>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.png</url>
      </icon>
    </iconList>
    <serviceList>
      <service>
        <serviceType>urn:schemas-sony-com:service:IRCC:1</serviceType>
        <serviceId>urn:schemas-sony-com:serviceId:IRCC</serviceId>
        <SCPDURL>/IRCCSCPD.xml</SCPDURL>
        <controlURL>/upnp/control/IRCC</controlURL>
        <eventSubURL></eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_IRCC_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_IRCC_Version>1.0</av:X_IRCC_Version>
      <av:X_IRCC_CategoryList>
        <av:X_IRCC_Category>
          <av:X_CategoryInfo>AAMAABxa</av:X_CategoryInfo>
        </av:X_IRCC_Category>
      </av:X_IRCC_CategoryList>
    </av:X_IRCC_DeviceInfo>
    <av:X_UNR_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_UNR_Version>1.3</av:X_UNR_Version>
      <av:X_CERS_ActionList_URL>http://xxx.xxx.xxx.xxx:50002/actionList</av:X_CERS_ActionList_URL>
    </av:X_UNR_DeviceInfo>
    <av:X_RDIS_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_RDIS_Version>1.0</av:X_RDIS_Version>
      <av:X_RDIS_SESSION_CONTROL>false</av:X_RDIS_SESSION_CONTROL>
      <av:X_RDIS_ENTRY_PORT>50004</av:X_RDIS_ENTRY_PORT>
    </av:X_RDIS_DeviceInfo>
  </device>
</root>

2020-12-16 12:50:09.152 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found service: urn:schemas-sony-com:serviceId:IRCC -- org.openhab.binding.sony.internal.upnp.models.UpnpService@91a77f
2020-12-16 12:50:09.154 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml -- urn:schemas-sony-com:serviceId:IRCC and getting SCPD: http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2020-12-16 12:50:09.158 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread OH-thingHandler-3
2 > GET http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2 > Connection: close
2 > User-Agent: OpenHab/Sony/Binding
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.169 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Client response received on thread OH-thingHandler-3
2 < 200
2 < Accept-Ranges: none
2 < Connection: close
2 < content: text/xml; charset=utf-8
2 < Content-Length: 1760
2 < Date: Wed, 16 Dec 2020 11:50:08 GMT
2 < Last-Modified: Tue, 20 Nov 2018 06:32:36 GMT
2 < Server: Linux/3.10 UPnP/1.0 Sony-BDP/2.0
<?xml version="1.0"?>
<scpd xmlns="urn:schemas-upnp-org:service-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  
  <actionList>
    <action>
      <name>X_SendIRCC</name>
      <argumentList>
        <argument>
          <name>IRCCCode</name>
          <direction>in</direction>
          <relatedStateVariable>X_A_ARG_TYPE_IRCCCode</relatedStateVariable>
        </argument>
      </argumentList>
    </action>
        
    <action>
      <name>X_GetStatus</name>
      <argumentList>
        <argument>
          <name>CategoryCode</name>
          <direction>in</direction>
          <relatedStateVariable>X_A_ARG_TYPE_Category</relatedStateVariable>
        </argument>
        <argument>
          <name>CurrentStatus</name>
          <direction>out</direction>
          <relatedStateVariable>X_A_ARG_TYPE_CurrentStatus</relatedStateVariable>
        </argument>
        <argument>
          <name>CurrentCommandInfo</name>
          <direction>out</direction>
          <relatedStateVariable>X_A_ARG_TYPE_CurrentCommandInfo</relatedStateVariable>
        </argument>
      </argumentList>
    </action>
  </actionList>
  
  <serviceStateTable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_IRCCCode</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_Category</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_CurrentStatus</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_CurrentCommandInfo</name>
      <dataType>string</dataType>
    </stateVariable>
  </serviceStateTable>
</scpd>


2020-12-16 12:50:09.186 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml -- urn:schemas-sony-com:serviceId:IRCC and adding SCPD: http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml -- org.openhab.binding.sony.internal.upnp.models.UpnpScpd@db3c4d
2020-12-16 12:50:09.188 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and finding action: http://xxx.xxx.xxx.xxx:50002/actionList
2020-12-16 12:50:09.193 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Sending client request on thread OH-thingHandler-3
3 > GET http://xxx.xxx.xxx.xxx:50002/actionList
3 > Connection: close
3 > User-Agent: OpenHab/Sony/Binding
3 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
3 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.201 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Client response received on thread OH-thingHandler-3
3 < 200
3 < Cache-Control: no-cache
3 < Connection: close
3 < content: text/xml
3 < Date: Wed, 16 Dec 2020 11:50:08 GMT
3 < Pragma: no-cache
3 < Server: Linux/3.10 Sony-BDP/2.0
3 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<actionList>
  <action name="register" mode="3" url="http://xxx.xxx.xxx.xxx:50002/register"/>
  <action name="getText" url="http://xxx.xxx.xxx.xxx:50002/getText"/>
  <action name="sendText" url="http://xxx.xxx.xxx.xxx:50002/sendText"/>
  <action name="getContentInformation" url="http://xxx.xxx.xxx.xxx:50002/getContentInformation"/>
  <action name="getSystemInformation" url="http://xxx.xxx.xxx.xxx:50002/getSystemInformation"/>
  <action name="getRemoteCommandList" url="http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList"/>
  <action name="getStatus" url="http://xxx.xxx.xxx.xxx:50002/getStatus"/>
  <action name="getHistoryList" url="http://xxx.xxx.xxx.xxx:50002/getHistoryList"/>
</actionList>


2020-12-16 12:50:09.211 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found action: http://xxx.xxx.xxx.xxx:50002/actionList -- org.openhab.binding.sony.internal.ircc.models.IrccActionList@1c03d03
2020-12-16 12:50:09.213 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting system information: http://xxx.xxx.xxx.xxx:50002/getSystemInformation
2020-12-16 12:50:09.218 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Sending client request on thread OH-thingHandler-3
4 > GET http://xxx.xxx.xxx.xxx:50002/getSystemInformation
4 > Connection: close
4 > User-Agent: OpenHab/Sony/Binding
4 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
4 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.226 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Client response received on thread OH-thingHandler-3
4 < 200
4 < Cache-Control: no-cache
4 < Connection: close
4 < content: text/xml
4 < Date: Wed, 16 Dec 2020 11:50:08 GMT
4 < Pragma: no-cache
4 < Server: Linux/3.10 Sony-BDP/2.0
4 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<systemInformation>
  <name>BDPlayer</name>
  <generation>2016</generation>
  <remoteType>RMT-B119A</remoteType>
  <remoteType>RMT-B120A</remoteType>
  <remoteType>RMT-B122A</remoteType>
  <remoteType>RMT-B123A</remoteType>
  <remoteType>RMT-B126A</remoteType>
  <remoteType>RMT-B119J</remoteType>
  <remoteType>RMT-B127J</remoteType>
  <remoteType>RMT-B119P</remoteType>
  <remoteType>RMT-B120P</remoteType>
  <remoteType>RMT-B121P</remoteType>
  <remoteType>RMT-B122P</remoteType>
  <remoteType bundled="true">RMT-B127P</remoteType>
  <remoteType>RMT-B119C</remoteType>
  <remoteType>RMT-B120C</remoteType>
  <remoteType>RMT-B122C</remoteType>
  <remoteType>RMT-B127C</remoteType>
  <remoteType>RMT-B127T</remoteType>
  <remoteType>RMT-B115A</remoteType>
  <actionHeader name="CERS-DEVICE-ID"/>
  <supportContentsClass>
    <class>video</class>
    <class>music</class>
  </supportContentsClass>
  <supportSource>
    <source>BD</source>
    <source>DVD</source>
    <source>CD</source>
    <source>Net</source>
  </supportSource>
  <supportFunction>
    <function name="Notification"/>
    <function name="WOL">
      <functionItem field="MAC" value="94-db-56-5a-27-9d"/>
    </function>
  </supportFunction>
</systemInformation>


2020-12-16 12:50:09.242 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found system information: http://xxx.xxx.xxx.xxx:50002/getSystemInformation -- org.openhab.binding.sony.internal.ircc.models.IrccSystemInformation@903b26
2020-12-16 12:50:09.244 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting remote commands: http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList
2020-12-16 12:50:09.247 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Sending client request on thread OH-thingHandler-3
5 > GET http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList
5 > Connection: close
5 > User-Agent: OpenHab/Sony/Binding
5 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
5 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.254 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Client response received on thread OH-thingHandler-3
5 < 200
5 < Cache-Control: no-cache
5 < Connection: close
5 < content: text/xml
5 < Date: Wed, 16 Dec 2020 11:50:08 GMT
5 < Pragma: no-cache
5 < Server: Linux/3.10 Sony-BDP/2.0
5 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<remoteCommandList>
  <command name="Confirm" type="ircc" value="AAAAAwAAHFoAAAA9Aw==" />
  <command name="Up" type="ircc" value="AAAAAwAAHFoAAAA5Aw==" />
  <command name="Down" type="ircc" value="AAAAAwAAHFoAAAA6Aw==" />
  <command name="Right" type="ircc" value="AAAAAwAAHFoAAAA8Aw==" />
  <command name="Left" type="ircc" value="AAAAAwAAHFoAAAA7Aw==" />
  <command name="Home" type="ircc" value="AAAAAwAAHFoAAABCAw==" />
  <command name="Options" type="ircc" value="AAAAAwAAHFoAAAA/Aw==" />
  <command name="Return" type="ircc" value="AAAAAwAAHFoAAABDAw==" />
  <command name="Num1" type="ircc" value="AAAAAwAAHFoAAAAAAw==" />
  <command name="Num2" type="ircc" value="AAAAAwAAHFoAAAABAw==" />
  <command name="Num3" type="ircc" value="AAAAAwAAHFoAAAACAw==" />
  <command name="Num4" type="ircc" value="AAAAAwAAHFoAAAADAw==" />
  <command name="Num5" type="ircc" value="AAAAAwAAHFoAAAAEAw==" />
  <command name="Num6" type="ircc" value="AAAAAwAAHFoAAAAFAw==" />
  <command name="Num7" type="ircc" value="AAAAAwAAHFoAAAAGAw==" />
  <command name="Num8" type="ircc" value="AAAAAwAAHFoAAAAHAw==" />
  <command name="Num9" type="ircc" value="AAAAAwAAHFoAAAAIAw==" />
  <command name="Num0" type="ircc" value="AAAAAwAAHFoAAAAJAw==" />
  <command name="Power" type="ircc" value="AAAAAwAAHFoAAAAVAw==" />
  <command name="Display" type="ircc" value="AAAAAwAAHFoAAABBAw==" />
  <command name="Audio" type="ircc" value="AAAAAwAAHFoAAABkAw==" />
  <command name="SubTitle" type="ircc" value="AAAAAwAAHFoAAABjAw==" />
  <command name="Favorites" type="ircc" value="AAAAAwAAHFoAAABeAw==" />
  <command name="Yellow" type="ircc" value="AAAAAwAAHFoAAABpAw==" />
  <command name="Blue" type="ircc" value="AAAAAwAAHFoAAABmAw==" />
  <command name="Red" type="ircc" value="AAAAAwAAHFoAAABnAw==" />
  <command name="Green" type="ircc" value="AAAAAwAAHFoAAABoAw==" />
  <command name="Play" type="ircc" value="AAAAAwAAHFoAAAAaAw==" />
  <command name="Stop" type="ircc" value="AAAAAwAAHFoAAAAYAw==" />
  <command name="Pause" type="ircc" value="AAAAAwAAHFoAAAAZAw==" />
  <command name="Rewind" type="ircc" value="AAAAAwAAHFoAAAAbAw==" />
  <command name="Forward" type="ircc" value="AAAAAwAAHFoAAAAcAw==" />
  <command name="Prev" type="ircc" value="AAAAAwAAHFoAAABXAw==" />
  <command name="Next" type="ircc" value="AAAAAwAAHFoAAABWAw==" />
  <command name="Replay" type="ircc" value="AAAAAwAAHFoAAAB2Aw==" />
  <command name="Advance" type="ircc" value="AAAAAwAAHFoAAAB1Aw==" />
  <command name="Angle" type="ircc" value="AAAAAwAAHFoAAABlAw==" />
  <command name="TopMenu" type="ircc" value="AAAAAwAAHFoAAAAsAw==" />
  <command name="PopUpMenu" type="ircc" value="AAAAAwAAHFoAAAApAw==" />
  <command name="Eject" type="ircc" value="AAAAAwAAHFoAAAAWAw==" />
  <command name="Karaoke" type="ircc" value="AAAAAwAAHFoAAABKAw==" />
  <command name="Netflix" type="ircc" value="AAAAAwAAHFoAAABLAw==" />
  <command name="Mode3D" type="ircc" value="AAAAAwAAHFoAAABNAw==" />
</remoteCommandList>


2020-12-16 12:50:09.265 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting remote commands: http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList -- org.openhab.binding.sony.internal.ircc.models.IrccRemoteCommands@1b84ded
2020-12-16 12:50:09.267 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:50:09.379 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-3
1 > POST http://xxx.xxx.xxx.xxx:50001/upnp/control/IRCC
1 > Accept: text/xml;charset=utf-8
1 > Connection: close
1 > Content-Type: text/xml;charset=utf-8
1 > SOAPACTION: "urn:schemas-sony-com:service:IRCC:1#X_SendIRCC"
1 > User-Agent: OpenHab/Sony/Binding
1 > X-Auth-PSK: 2060
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
<?xml version="1.0"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:X_SendIRCC xmlns:u="urn:schemas-sony-com:service:IRCC:1">
<IRCCCode>nonexistentcommand</IRCCCode>
    </u:X_SendIRCC>
  </s:Body>
</s:Envelope>


2020-12-16 12:50:09.388 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread OH-thingHandler-3
1 < 200
1 < Connection: close
1 < content: text/xml; charset=utf-8
1 < Content-Length: 266
1 < Date: Wed, 16 Dec 2020 11:50:08 GMT
1 < EXT: 
1 < Server: Linux/3.10 UPnP/1.0 Sony-BDP/2.0
<?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:X_SendIRCCResponse xmlns:u="urn:schemas-sony-com:service:IRCC:1"></u:X_SendIRCCResponse></s:Body></s:Envelope>

2020-12-16 12:50:09.394 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread OH-thingHandler-3
2 > GET http://xxx.xxx.xxx.xxx:50002/getStatus
2 > Connection: close
2 > User-Agent: OpenHab/Sony/Binding
2 > X-Auth-PSK: 2060
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:09.433 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Client response received on thread OH-thingHandler-3
2 < 200
2 < Cache-Control: no-cache
2 < Connection: close
2 < content: text/xml
2 < Date: Wed, 16 Dec 2020 11:50:08 GMT
2 < Pragma: no-cache
2 < Server: Linux/3.10 Sony-BDP/2.0
2 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<statusList>
  <status name="disc">
    <statusItem field="type" value="CD"/>
    <statusItem field="mediaType" value="CD-ROM"/>
    <statusItem field="mediaFormat" value="CD-DA"/>
  </status>
</statusList>


2020-12-16 12:50:09.439 [DEBUG] [ding.sony.internal.ircc.IrccProtocol] - Command map already defined - ignoring: /etc/openhab2/transform/ircc-94db565a279d.map
2020-12-16 12:50:09.445 [DEBUG] [g.sony.internal.AbstractThingHandler] - Starting state polling every 30 seconds
2020-12-16 12:50:09.452 [DEBUG] [g.sony.internal.AbstractThingHandler] - Executing any cached commands
2020-12-16 12:50:09.457 [DEBUG] [g.sony.internal.AbstractThingHandler] - Starting state polling every 30 seconds
2020-12-16 12:50:09.461 [DEBUG] [g.sony.internal.AbstractThingHandler] - Executing any cached commands
2020-12-16 12:50:09.464 [DEBUG] [nding.sony.internal.ircc.IrccHandler] - IRCC System now connected
2020-12-16 12:50:12.952 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:13.053 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:13.115 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:17.960 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:18.056 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:18.117 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:19.021 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:50:19.024 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:50:19.027 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a942db
2020-12-16 12:50:19.027 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@d3ac61
2020-12-16 12:50:19.029 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@ae35bc
2020-12-16 12:50:19.029 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@13d7f6
2020-12-16 12:50:19.032 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:10000 - successful
2020-12-16 12:50:19.033 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136086,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:19.044 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136086,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:50:19.048 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136086,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:50:19.056 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136087,"method":"getSourceList","version":"1.1","params":[{"scheme":"dlna"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:19.067 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136087,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]})
2020-12-16 12:50:19.071 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136087,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]}
2020-12-16 12:50:19.076 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136088,"method":"getSourceList","version":"1.1","params":[{"scheme":"storage"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:19.094 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136088,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]})
2020-12-16 12:50:19.100 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136088,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]}
2020-12-16 12:50:19.123 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136089,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:19.131 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136089,"result":[[]]})
2020-12-16 12:50:19.139 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136089,"result":[[]]}
2020-12-16 12:50:22.964 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:23.058 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:23.120 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:26.215 [TRACE] [l.providers.sources.SonyGithubSource] - Metainfo was not modified - returning last version from etag "0e74a0f3c0e5392c0af460445e0db7f54d01943c"
2020-12-16 12:50:26.218 [DEBUG] [l.providers.sources.SonyGithubSource] - Ignoring update from github  - processing is disabled
2020-12-16 12:50:27.978 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:28.061 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:28.123 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:32.986 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:33.064 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:33.126 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:37.990 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:38.068 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:38.129 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:39.463 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:50001 - successful
2020-12-16 12:50:39.472 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Sending client request on thread OH-thingHandler-5
3 > GET http://xxx.xxx.xxx.xxx:50002/getStatus
3 > Connection: close
3 > User-Agent: OpenHab/Sony/Binding
3 > X-Auth-PSK: 2060
3 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
3 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:39.492 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Client response received on thread OH-thingHandler-5
3 < 200
3 < Cache-Control: no-cache
3 < Connection: close
3 < content: text/xml
3 < Date: Wed, 16 Dec 2020 11:50:38 GMT
3 < Pragma: no-cache
3 < Server: Linux/3.10 Sony-BDP/2.0
3 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<statusList>
  <status name="disc">
    <statusItem field="type" value="CD"/>
    <statusItem field="mediaType" value="CD-ROM"/>
    <statusItem field="mediaFormat" value="CD-DA"/>
  </status>
</statusList>


2020-12-16 12:50:39.536 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Sending client request on thread OH-thingHandler-5
4 > GET http://xxx.xxx.xxx.xxx:50002/getContentInformation
4 > Connection: close
4 > User-Agent: OpenHab/Sony/Binding
4 > X-Auth-PSK: 2060
4 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
4 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:50:39.560 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Client response received on thread OH-thingHandler-5
4 < 200
4 < Cache-Control: no-cache
4 < Connection: close
4 < content: text/xml
4 < Date: Wed, 16 Dec 2020 11:50:38 GMT
4 < Pragma: no-cache
4 < Server: Linux/3.10 Sony-BDP/2.0
4 < Transfer-Encoding: chunked
4 < X-CERS-STATUS-CODE: DI02 NoMetadata
<?xml version="1.0" encoding="UTF-8"?>
<contentInformation>
  <infoItem field="class" value="music"/>
  <infoItem field="source" value="CD"/>
  <infoItem field="mediaType" value="CD-ROM"/>
  <infoItem field="mediaFormat" value="CD-DA"/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
  <infoItem field="track" value=""/>
</contentInformation>


2020-12-16 12:50:42.993 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:43.103 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:43.131 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:47.999 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:48.108 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:48.150 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:49.027 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:50:49.028 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:50:49.030 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a942db
2020-12-16 12:50:49.030 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@13d7f6
2020-12-16 12:50:49.031 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@ae35bc
2020-12-16 12:50:49.031 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@d3ac61
2020-12-16 12:50:49.031 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136090,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:49.036 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:10000 - successful
2020-12-16 12:50:49.040 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136090,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:50:49.042 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136090,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:50:49.045 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136091,"method":"getSourceList","version":"1.1","params":[{"scheme":"dlna"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:49.054 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136091,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]})
2020-12-16 12:50:49.056 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136091,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]}
2020-12-16 12:50:49.058 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136092,"method":"getSourceList","version":"1.1","params":[{"scheme":"storage"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:49.069 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136092,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]})
2020-12-16 12:50:49.071 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136092,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]}
2020-12-16 12:50:49.082 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136093,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:49.090 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136093,"result":[[]]})
2020-12-16 12:50:49.093 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136093,"result":[[]]}
2020-12-16 12:50:53.001 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:53.110 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:53.153 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:50:58.005 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:50:58.115 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:50:58.156 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:02.582 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Found Sony IRCC service: uuid:00000003-0000-1010-8000-94db565a279d
2020-12-16 12:51:02.585 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:51:02.622 [DEBUG] [ternal.dial.DialDiscoveryParticipant] - Found Sony DIAL service: uuid:00000004-0000-1010-8000-94db565a279d
2020-12-16 12:51:02.625 [DEBUG] [ternal.dial.DialDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:51:02.654 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000000-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:52323/dmr.xml, Root: true
2020-12-16 12:51:02.657 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - Found Sony WebScalarAPI service: uuid:00000000-0000-1010-8000-94db565a279d
2020-12-16 12:51:02.660 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000004-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:50201/dial.xml, Root: true
2020-12-16 12:51:02.662 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:51:03.007 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:03.117 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:03.158 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:03.861 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000001-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:64321/bdp-bx-ms.xml, Root: true
2020-12-16 12:51:07.791 [WARN ] [ore.internal.binding.BindingResource] - Cannot get config id for binding id 'appletv', probably because binding does not exist.
2020-12-16 12:51:08.010 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:08.120 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:08.160 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:09.601 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Sending client request on thread OH-thingHandler-3
5 > GET http://xxx.xxx.xxx.xxx:50002/getStatus
5 > Connection: close
5 > User-Agent: OpenHab/Sony/Binding
5 > X-Auth-PSK: 2060
5 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
5 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:51:13.012 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:13.122 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:13.162 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:14.479 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:50001 - unsuccessful - going offline: connect timed out
java.net.SocketTimeoutException: connect timed out
	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202]
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202]
	at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202]
	at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$2(AbstractThingHandler.java:317) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:18.014 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:18.125 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:18.165 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:19.030 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:51:19.032 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:51:19.035 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@13d7f6
2020-12-16 12:51:19.035 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a942db
2020-12-16 12:51:19.038 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@d3ac61
2020-12-16 12:51:19.038 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136094,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:19.042 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@ae35bc
2020-12-16 12:51:23.016 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:23.127 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:23.168 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:24.050 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:10000 - unsuccessful - going offline: connect timed out
java.net.SocketTimeoutException: connect timed out
	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202]
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202]
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202]
	at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202]
	at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$2(AbstractThingHandler.java:317) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:24.497 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:51:24.501 [DEBUG] [nding.sony.internal.ircc.IrccHandler] - Attempting connection to IRCC device...
2020-12-16 12:51:24.515 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml
2020-12-16 12:51:24.657 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-5
1 > GET http://xxx.xxx.xxx.xxx:50001/Ircc.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:51:26.580 [TRACE] [l.providers.sources.SonyGithubSource] - Metainfo was not modified - returning last version from etag "0e74a0f3c0e5392c0af460445e0db7f54d01943c"
2020-12-16 12:51:26.581 [DEBUG] [l.providers.sources.SonyGithubSource] - Ignoring update from github  - processing is disabled
2020-12-16 12:51:28.019 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:28.131 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:28.172 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:29.042 [DEBUG] [.protocols.AbstractScalarWebProtocol] - Communication error executing method getSchemeList() on service avContent: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@19ffd0b threw an exception: null
java.io.IOException: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@19ffd0b threw an exception: null
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.handleExecute(AbstractScalarWebProtocol.java:341) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.execute(AbstractScalarWebProtocol.java:275) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getSchemes(ScalarWebAvContentProtocol.java:1311) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshSchemes(ScalarWebAvContentProtocol.java:2395) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshState(ScalarWebAvContentProtocol.java:2422) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebProtocolFactory.lambda$2(ScalarWebProtocolFactory.java:168) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:29.088 [DEBUG] [protocols.ScalarWebAvContentProtocol] - Exception occurred retrieving the scheme list: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@19ffd0b threw an exception: null
2020-12-16 12:51:29.091 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#schemes=
2020-12-16 12:51:29.094 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136095,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:34.190 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:34.195 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:34.201 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:39.091 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:51:39.094 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Attempting connection to Scalar Web device...
2020-12-16 12:51:39.098 [DEBUG] [.protocols.AbstractScalarWebProtocol] - Communication error executing method getSchemeList() on service avContent: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@16e13a0 threw an exception: null
java.io.IOException: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@16e13a0 threw an exception: null
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.handleExecute(AbstractScalarWebProtocol.java:341) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.execute(AbstractScalarWebProtocol.java:275) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getSchemes(ScalarWebAvContentProtocol.java:1311) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getSchemes(ScalarWebAvContentProtocol.java:1293) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getSources(ScalarWebAvContentProtocol.java:1343) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshSources(ScalarWebAvContentProtocol.java:2405) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshState(ScalarWebAvContentProtocol.java:2423) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebProtocolFactory.lambda$2(ScalarWebProtocolFactory.java:168) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:39.130 [DEBUG] [protocols.ScalarWebAvContentProtocol] - Exception occurred retrieving the scheme list: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@16e13a0 threw an exception: null
2020-12-16 12:51:39.149 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136096,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:39.217 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-4
1 > GET http://xxx.xxx.xxx.xxx:52323/dmr.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:51:39.667 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:51:39.672 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Exception occurred querying IRCC client - trying default client: java.net.SocketTimeoutException: connect timed out
java.io.IOException: java.net.SocketTimeoutException: connect timed out
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.ircc.IrccClientFactory.queryIrccClient(IrccClientFactory.java:198) ~[?:?]
	at org.openhab.binding.sony.internal.ircc.IrccClientFactory.get(IrccClientFactory.java:93) ~[?:?]
	at org.openhab.binding.sony.internal.ircc.IrccProtocol.<init>(IrccProtocol.java:139) ~[?:?]
	at org.openhab.binding.sony.internal.ircc.IrccHandler.connect(IrccHandler.java:231) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.doConnect(AbstractThingHandler.java:116) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$1(AbstractThingHandler.java:256) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:39.684 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Creating default IRCC client for http://xxx.xxx.xxx.xxx:50001/Ircc.xml
2020-12-16 12:51:39.750 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Testing Default IRCC client to see if it's a TV/AVR or BLURAY: http://xxx.xxx.xxx.xxx:50001/Ircc.xml/sony/ircc/IRCCSCPD.xml
2020-12-16 12:51:39.835 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-5
1 > GET http://xxx.xxx.xxx.xxx:50001/sony/ircc/IRCCSCPD.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:51:40.066 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:40.071 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:40.075 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:45.659 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:45.661 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:45.663 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:49.154 [DEBUG] [.protocols.AbstractScalarWebProtocol] - Communication error executing method getCurrentExternalTerminalsStatus() on service avContent: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@1dfdded threw an exception: null
java.io.IOException: Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@1dfdded threw an exception: null
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.handleExecute(AbstractScalarWebProtocol.java:341) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.AbstractScalarWebProtocol.execute(AbstractScalarWebProtocol.java:275) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getTerminalStatus(ScalarWebAvContentProtocol.java:1480) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.getTerminalStatuses(ScalarWebAvContentProtocol.java:1506) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshCurrentExternalTerminalsStatus(ScalarWebAvContentProtocol.java:2352) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol.refreshState(ScalarWebAvContentProtocol.java:2439) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebProtocolFactory.lambda$2(ScalarWebProtocolFactory.java:168) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:49.184 [DEBUG] [protocols.ScalarWebAvContentProtocol] - Error getting terminal statuses Execution of org.openhab.binding.sony.internal.scalarweb.models.ScalarWebRequest@1dfdded threw an exception: null
2020-12-16 12:51:49.187 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_albumname=UNDEF
2020-12-16 12:51:49.190 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_applicationname=UNDEF
2020-12-16 12:51:49.193 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_artist=UNDEF
2020-12-16 12:51:49.196 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_audiochannel=UNDEF
2020-12-16 12:51:49.198 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_audiocodec=UNDEF
2020-12-16 12:51:49.201 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_audiofrequency=UNDEF
2020-12-16 12:51:49.204 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_bivlserviceid=UNDEF
2020-12-16 12:51:49.206 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_bivleassetid=UNDEF
2020-12-16 12:51:49.209 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_bivlprovider=UNDEF
2020-12-16 12:51:49.212 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_broadcastfreq=UNDEF
2020-12-16 12:51:49.215 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_broadcastfreqband=UNDEF
2020-12-16 12:51:49.216 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_channelname=UNDEF
2020-12-16 12:51:49.218 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_channelsurfingvisibility=UNDEF
2020-12-16 12:51:49.219 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_chaptercount=UNDEF
2020-12-16 12:51:49.221 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_chapterindex=UNDEF
2020-12-16 12:51:49.223 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_clipcount=UNDEF
2020-12-16 12:51:49.225 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_contentkind=UNDEF
2020-12-16 12:51:49.226 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_contenttype=UNDEF
2020-12-16 12:51:49.228 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_createdtime=UNDEF
2020-12-16 12:51:49.229 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_dabcomponentlabel=UNDEF
2020-12-16 12:51:49.231 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_dabdynamiclabel=UNDEF
2020-12-16 12:51:49.232 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_dabensemblelabel=UNDEF
2020-12-16 12:51:49.234 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_dabservicelabel=UNDEF
2020-12-16 12:51:49.235 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_description=UNDEF
2020-12-16 12:51:49.237 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_directremotenum=UNDEF
2020-12-16 12:51:49.239 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_dispnum=UNDEF
2020-12-16 12:51:49.240 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_durationmsec=UNDEF
2020-12-16 12:51:49.242 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_durationsec=UNDEF
2020-12-16 12:51:49.243 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_epgvisibility=UNDEF
2020-12-16 12:51:49.245 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_eventid=UNDEF
2020-12-16 12:51:49.247 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_fileno=UNDEF
2020-12-16 12:51:49.249 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_filesizebyte=UNDEF
2020-12-16 12:51:49.251 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_folderno=UNDEF
2020-12-16 12:51:49.252 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_genre=UNDEF
2020-12-16 12:51:49.254 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_globalplaybackcount=UNDEF
2020-12-16 12:51:49.256 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_hasresume=UNDEF
2020-12-16 12:51:49.257 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_is3d=UNDEF
2020-12-16 12:51:49.259 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_is4k=UNDEF
2020-12-16 12:51:49.260 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isalreadyplayed=UNDEF
2020-12-16 12:51:49.262 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isautodelete=UNDEF
2020-12-16 12:51:49.264 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isbrowsable=UNDEF
2020-12-16 12:51:49.265 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isnew=UNDEF
2020-12-16 12:51:49.267 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isplayable=UNDEF
2020-12-16 12:51:49.269 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isplaylist=UNDEF
2020-12-16 12:51:49.270 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_isprotected=UNDEF
2020-12-16 12:51:49.272 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_issoundphoto=UNDEF
2020-12-16 12:51:49.273 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_mediatype=UNDEF
2020-12-16 12:51:49.275 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_originaldispnum=UNDEF
2020-12-16 12:51:49.276 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_output=UNDEF
2020-12-16 12:51:49.278 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_parentalcountry=UNDEF
2020-12-16 12:51:49.280 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_parentalrating=UNDEF
2020-12-16 12:51:49.281 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_parentalsystem=UNDEF
2020-12-16 12:51:49.283 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_parentindex=UNDEF
2020-12-16 12:51:49.284 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_path=UNDEF
2020-12-16 12:51:49.286 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_playlistname=UNDEF
2020-12-16 12:51:49.287 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_podcastname=UNDEF
2020-12-16 12:51:49.289 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_productid=UNDEF
2020-12-16 12:51:49.290 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_programmediatype=UNDEF
2020-12-16 12:51:49.292 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_programnum=UNDEF
2020-12-16 12:51:49.293 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_programservicetype=UNDEF
2020-12-16 12:51:49.295 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_programtitle=UNDEF
2020-12-16 12:51:49.296 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_remoteplaytype=UNDEF
2020-12-16 12:51:49.298 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_repeattype=UNDEF
2020-12-16 12:51:49.299 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_service=UNDEF
2020-12-16 12:51:49.301 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_sizemb=UNDEF
2020-12-16 12:51:49.302 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_source=UNDEF
2020-12-16 12:51:49.304 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_sourcelabel=UNDEF
2020-12-16 12:51:49.305 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_state=UNDEF
2020-12-16 12:51:49.307 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_statesupplement=UNDEF
2020-12-16 12:51:49.309 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_startdatetime=UNDEF
2020-12-16 12:51:49.310 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_storageuri=UNDEF
2020-12-16 12:51:49.312 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_subtitlelanguage=UNDEF
2020-12-16 12:51:49.313 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_subtitletitle=UNDEF
2020-12-16 12:51:49.315 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_synccontentpriority=UNDEF
2020-12-16 12:51:49.316 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_title=UNDEF
2020-12-16 12:51:49.318 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_totalcount=UNDEF
2020-12-16 12:51:49.320 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_tripletstr=UNDEF
2020-12-16 12:51:49.321 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_usercontentflag=UNDEF
2020-12-16 12:51:49.323 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_videocodec=UNDEF
2020-12-16 12:51:49.324 [TRACE] [.internal.scalarweb.ScalarWebHandler] - Ignoring state update during OFFLINE: avContent#cn_visibility=UNDEF
2020-12-16 12:51:49.530 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Default IRCC client may not be a TV/AVR - trying BLURAY: http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2020-12-16 12:51:49.530 [DEBUG] [nal.scalarweb.ScalarWebClientFactory] - Testing Default Scalar Web client: http://xxx.xxx.xxx.xxx:10000/sony/guide
2020-12-16 12:51:49.536 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread OH-thingHandler-5
2 > GET http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2 > Connection: close
2 > User-Agent: OpenHab/Sony/Binding
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:51:50.844 [DEBUG] [al.transports.SonyWebSocketTransport] - Execution of 136096 took too long and is being cancelled
2020-12-16 12:51:50.846 [DEBUG] [al.transports.SonyWebSocketTransport] - Execution of 136094 took too long and is being cancelled
2020-12-16 12:51:50.848 [DEBUG] [al.transports.SonyWebSocketTransport] - Execution of 136095 took too long and is being cancelled
2020-12-16 12:51:51.391 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:51.394 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:51.398 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:52.651 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:51:52.651 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:51:52.659 [DEBUG] [nal.scalarweb.ScalarWebClientFactory] - Testing Default Scalar Web client: http://xxx.xxx.xxx.xxx:54480/sony/guide
2020-12-16 12:51:52.659 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Default IRCC detection failed - assuming TV/AVR: http://xxx.xxx.xxx.xxx:50001/Ircc.xml/sony/ircc
2020-12-16 12:51:52.664 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Default SCPD detection failed - assuming result: <?xml version="1.0"?><scpd xmlns="urn:schemas-upnp-org:service-1-0"><actionList><action><name>X_SendIRCC</name><argumentList><argument><name>IRCCCode</name><direction>in</direction><relatedStateVariable>X_A_ARG_TYPE_IRCCCode</relatedStateVariable></argument></argumentList></action></actionList></scpd>
2020-12-16 12:51:55.772 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:51:56.394 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:51:56.398 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:51:56.402 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:51:58.891 [DEBUG] [enhab.binding.sony.internal.SonyAuth] - Requesting access: 2060
2020-12-16 12:51:58.891 [DEBUG] [nal.scalarweb.ScalarWebDeviceManager] - Could not retrieve methods: java.net.NoRouteToHostException: No route to host (Host unreachable)
java.io.IOException: java.net.NoRouteToHostException: No route to host (Host unreachable)
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.models.ScalarWebResult.asArray(ScalarWebResult.java:237) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.models.api.SupportedApi.getSupportApiAlternate(SupportedApi.java:214) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebDeviceManager.<init>(ScalarWebDeviceManager.java:121) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebDeviceManager.<init>(ScalarWebDeviceManager.java:84) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.getDefaultClient(ScalarWebClientFactory.java:137) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.queryScalarWebSclient(ScalarWebClientFactory.java:227) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.get(ScalarWebClientFactory.java:104) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.get(ScalarWebClientFactory.java:81) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebHandler.connect(ScalarWebHandler.java:245) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.doConnect(AbstractThingHandler.java:116) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$1(AbstractThingHandler.java:256) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:51:58.932 [DEBUG] [nal.scalarweb.ScalarWebDeviceManager] - Service guide doesn't contain switchNotifications - ignoring notifications
2020-12-16 12:51:58.943 [DEBUG] [al.scalarweb.models.ScalarWebService] - Method getServiceProtocols doesn't exist in the service guide
2020-12-16 12:51:58.946 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:51:58.955 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:01.397 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:01.400 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:01.404 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:06.399 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:06.402 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:06.407 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:08.967 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:52:08.969 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Attempting connection to Scalar Web device...
2020-12-16 12:52:09.054 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-5
1 > GET http://xxx.xxx.xxx.xxx:52323/dmr.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:09.059 [DEBUG] [nal.scalarweb.ScalarWebClientFactory] - Testing Default Scalar Web client: http://xxx.xxx.xxx.xxx:10000/sony/guide
2020-12-16 12:52:09.154 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:09.162 [DEBUG] [nal.scalarweb.ScalarWebClientFactory] - Testing Default Scalar Web client: http://xxx.xxx.xxx.xxx:54480/sony/guide
2020-12-16 12:52:09.278 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:09.366 [DEBUG] [nal.scalarweb.ScalarWebDeviceManager] - Could not retrieve methods: java.net.ConnectException: Connection refused (Connection refused)
java.io.IOException: java.net.ConnectException: Connection refused (Connection refused)
	at org.openhab.binding.sony.internal.net.HttpResponse.createException(HttpResponse.java:247) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.models.ScalarWebResult.asArray(ScalarWebResult.java:237) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.models.api.SupportedApi.getSupportApiAlternate(SupportedApi.java:214) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebDeviceManager.<init>(ScalarWebDeviceManager.java:121) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebDeviceManager.<init>(ScalarWebDeviceManager.java:84) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.getDefaultClient(ScalarWebClientFactory.java:137) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.queryScalarWebSclient(ScalarWebClientFactory.java:227) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.get(ScalarWebClientFactory.java:104) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebClientFactory.get(ScalarWebClientFactory.java:81) ~[?:?]
	at org.openhab.binding.sony.internal.scalarweb.ScalarWebHandler.connect(ScalarWebHandler.java:245) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.doConnect(AbstractThingHandler.java:116) ~[?:?]
	at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$1(AbstractThingHandler.java:256) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_202]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_202]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_202]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_202]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
2020-12-16 12:52:09.381 [DEBUG] [nal.scalarweb.ScalarWebDeviceManager] - Service guide doesn't contain switchNotifications - ignoring notifications
2020-12-16 12:52:09.386 [DEBUG] [al.scalarweb.models.ScalarWebService] - Method getServiceProtocols doesn't exist in the service guide
2020-12-16 12:52:09.387 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:09.391 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:11.351 [DEBUG] [ternal.dial.DialDiscoveryParticipant] - Found Sony DIAL service: uuid:00000004-0000-1010-8000-94db565a279d
2020-12-16 12:52:11.352 [DEBUG] [ternal.dial.DialDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:52:11.354 [DEBUG] [sony.internal.dial.DialClientFactory] - Querying DIAL client: http://xxx.xxx.xxx.xxx:50201/dial.xml
2020-12-16 12:52:11.401 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:11.411 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:11.404 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:11.422 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread upnp-main-94332
1 > GET http://xxx.xxx.xxx.xxx:50201/dial.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.439 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread upnp-main-94332
1 < 200
1 < Application-URL: http://xxx.xxx.xxx.xxx:50202/apps/
1 < Connection: close
1 < content: text/xml
1 < Date: Sun, 01 Jun 2014 00:00:14 GMT
1 < Server: Linux/3.10 Sony-BDP/2.0
<?xml version="1.0"?>
<root xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
 xsi:schemaLocation="urn:schemas-upnp-org:device-1-0 Device.xsd"
 xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000004-0000-1010-8000-94db565a279d</UDN>
    <serviceList>
      <service>
        <serviceType>urn:dial-multiscreen-org:service:dial:1</serviceType>
        <serviceId>urn:dial-multiscreen-org:serviceId:dial</serviceId>
        <SCPDURL>/dialSCPD.xml</SCPDURL>
        <controlURL>/dial/control</controlURL>
        <eventSubURL>/dial/event</eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_DIALEX_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_DIALEX_AppsListURL>http://xxx.xxx.xxx.xxx:50202/appslist</av:X_DIALEX_AppsListURL>
      <av:X_DIALEX_DeviceID>B0:00:08:91:58:68</av:X_DIALEX_DeviceID>
      <av:X_DIALEX_DeviceType>BDP_DIAL</av:X_DIALEX_DeviceType>
    </av:X_DIALEX_DeviceInfo>
  </device>
</root>


2020-12-16 12:52:11.448 [DEBUG] [sony.internal.dial.DialClientFactory] - Creating DIAL client: http://xxx.xxx.xxx.xxx:50202/apps/ - <?xml version="1.0"?>
<root xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
 xsi:schemaLocation="urn:schemas-upnp-org:device-1-0 Device.xsd"
 xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000004-0000-1010-8000-94db565a279d</UDN>
    <serviceList>
      <service>
        <serviceType>urn:dial-multiscreen-org:service:dial:1</serviceType>
        <serviceId>urn:dial-multiscreen-org:serviceId:dial</serviceId>
        <SCPDURL>/dialSCPD.xml</SCPDURL>
        <controlURL>/dial/control</controlURL>
        <eventSubURL>/dial/event</eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_DIALEX_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_DIALEX_AppsListURL>http://xxx.xxx.xxx.xxx:50202/appslist</av:X_DIALEX_AppsListURL>
      <av:X_DIALEX_DeviceID>B0:00:08:91:58:68</av:X_DIALEX_DeviceID>
      <av:X_DIALEX_DeviceType>BDP_DIAL</av:X_DIALEX_DeviceType>
    </av:X_DIALEX_DeviceInfo>
  </device>
</root>

2020-12-16 12:52:11.451 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:11.484 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'sony:dial:94db565a279d' to inbox.
2020-12-16 12:52:11.487 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000004-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:50201/dial.xml, Root: true
2020-12-16 12:52:11.490 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - Found sony device but ignored because of no scalar service: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000004-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:50201/dial.xml, Root: true
2020-12-16 12:52:11.522 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Found Sony IRCC service: uuid:00000003-0000-1010-8000-94db565a279d
2020-12-16 12:52:11.524 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:52:11.528 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml
2020-12-16 12:52:11.582 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread upnp-main-94334
1 > GET http://xxx.xxx.xxx.xxx:50001/Ircc.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.593 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread upnp-main-94334
1 < 200
1 < Accept-Ranges: none
1 < Connection: close
1 < content: text/xml; charset=utf-8
1 < Content-Length: 2575
1 < Date: Sun, 01 Jun 2014 00:00:14 GMT
1 < Server: Linux/3.10 UPnP/1.0 Sony-BDP/2.0
<?xml version="1.0"?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000003-0000-1010-8000-94db565a279d</UDN>
    <iconList>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.png</url>
      </icon>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.png</url>
      </icon>
    </iconList>
    <serviceList>
      <service>
        <serviceType>urn:schemas-sony-com:service:IRCC:1</serviceType>
        <serviceId>urn:schemas-sony-com:serviceId:IRCC</serviceId>
        <SCPDURL>/IRCCSCPD.xml</SCPDURL>
        <controlURL>/upnp/control/IRCC</controlURL>
        <eventSubURL></eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_IRCC_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_IRCC_Version>1.0</av:X_IRCC_Version>
      <av:X_IRCC_CategoryList>
        <av:X_IRCC_Category>
          <av:X_CategoryInfo>AAMAABxa</av:X_CategoryInfo>
        </av:X_IRCC_Category>
      </av:X_IRCC_CategoryList>
    </av:X_IRCC_DeviceInfo>
    <av:X_UNR_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_UNR_Version>1.3</av:X_UNR_Version>
      <av:X_CERS_ActionList_URL>http://xxx.xxx.xxx.xxx:50002/actionList</av:X_CERS_ActionList_URL>
    </av:X_UNR_DeviceInfo>
    <av:X_RDIS_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_RDIS_Version>1.0</av:X_RDIS_Version>
      <av:X_RDIS_SESSION_CONTROL>false</av:X_RDIS_SESSION_CONTROL>
      <av:X_RDIS_ENTRY_PORT>50004</av:X_RDIS_ENTRY_PORT>
    </av:X_RDIS_DeviceInfo>
  </device>
</root>


2020-12-16 12:52:11.604 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and got IRCCRoot response: <?xml version="1.0"?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  <device>
    <deviceType>urn:schemas-upnp-org:device:Basic:1</deviceType>
    <friendlyName>BDP-S6700</friendlyName>
    <manufacturer>Sony Corporation</manufacturer>
    <manufacturerURL>http://www.sony.net/</manufacturerURL>
    <modelDescription></modelDescription>
    <modelName>Blu-ray Disc Player</modelName>
    <modelURL></modelURL>
    <UDN>uuid:00000003-0000-1010-8000-94db565a279d</UDN>
    <iconList>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>120</width>
        <height>120</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_large.png</url>
      </icon>
      <icon>
        <mimetype>image/jpeg</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.jpg</url>
      </icon>
      <icon>
        <mimetype>image/png</mimetype>
        <width>48</width>
        <height>48</height>
        <depth>24</depth>
        <url>/bdp_bx_device_icon_small.png</url>
      </icon>
    </iconList>
    <serviceList>
      <service>
        <serviceType>urn:schemas-sony-com:service:IRCC:1</serviceType>
        <serviceId>urn:schemas-sony-com:serviceId:IRCC</serviceId>
        <SCPDURL>/IRCCSCPD.xml</SCPDURL>
        <controlURL>/upnp/control/IRCC</controlURL>
        <eventSubURL></eventSubURL>
      </service>
    </serviceList>
    <presentationURL></presentationURL>
    <av:X_IRCC_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_IRCC_Version>1.0</av:X_IRCC_Version>
      <av:X_IRCC_CategoryList>
        <av:X_IRCC_Category>
          <av:X_CategoryInfo>AAMAABxa</av:X_CategoryInfo>
        </av:X_IRCC_Category>
      </av:X_IRCC_CategoryList>
    </av:X_IRCC_DeviceInfo>
    <av:X_UNR_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_UNR_Version>1.3</av:X_UNR_Version>
      <av:X_CERS_ActionList_URL>http://xxx.xxx.xxx.xxx:50002/actionList</av:X_CERS_ActionList_URL>
    </av:X_UNR_DeviceInfo>
    <av:X_RDIS_DeviceInfo xmlns:av="urn:schemas-sony-com:av">
      <av:X_RDIS_Version>1.0</av:X_RDIS_Version>
      <av:X_RDIS_SESSION_CONTROL>false</av:X_RDIS_SESSION_CONTROL>
      <av:X_RDIS_ENTRY_PORT>50004</av:X_RDIS_ENTRY_PORT>
    </av:X_RDIS_DeviceInfo>
  </device>
</root>

2020-12-16 12:52:11.606 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found service: urn:schemas-sony-com:serviceId:IRCC -- org.openhab.binding.sony.internal.upnp.models.UpnpService@812c1a
2020-12-16 12:52:11.607 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml -- urn:schemas-sony-com:serviceId:IRCC and getting SCPD: http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2020-12-16 12:52:11.611 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread upnp-main-94334
2 > GET http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml
2 > Connection: close
2 > User-Agent: OpenHab/Sony/Binding
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.617 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Client response received on thread upnp-main-94334
2 < 200
2 < Accept-Ranges: none
2 < Connection: close
2 < content: text/xml; charset=utf-8
2 < Content-Length: 1760
2 < Date: Sun, 01 Jun 2014 00:00:14 GMT
2 < Last-Modified: Tue, 20 Nov 2018 06:32:36 GMT
2 < Server: Linux/3.10 UPnP/1.0 Sony-BDP/2.0
<?xml version="1.0"?>
<scpd xmlns="urn:schemas-upnp-org:service-1-0">
  <specVersion>
    <major>1</major>
    <minor>0</minor>
  </specVersion>
  
  <actionList>
    <action>
      <name>X_SendIRCC</name>
      <argumentList>
        <argument>
          <name>IRCCCode</name>
          <direction>in</direction>
          <relatedStateVariable>X_A_ARG_TYPE_IRCCCode</relatedStateVariable>
        </argument>
      </argumentList>
    </action>
        
    <action>
      <name>X_GetStatus</name>
      <argumentList>
        <argument>
          <name>CategoryCode</name>
          <direction>in</direction>
          <relatedStateVariable>X_A_ARG_TYPE_Category</relatedStateVariable>
        </argument>
        <argument>
          <name>CurrentStatus</name>
          <direction>out</direction>
          <relatedStateVariable>X_A_ARG_TYPE_CurrentStatus</relatedStateVariable>
        </argument>
        <argument>
          <name>CurrentCommandInfo</name>
          <direction>out</direction>
          <relatedStateVariable>X_A_ARG_TYPE_CurrentCommandInfo</relatedStateVariable>
        </argument>
      </argumentList>
    </action>
  </actionList>
  
  <serviceStateTable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_IRCCCode</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_Category</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_CurrentStatus</name>
      <dataType>string</dataType>
    </stateVariable>
    <stateVariable sendEvents="no">
      <name>X_A_ARG_TYPE_CurrentCommandInfo</name>
      <dataType>string</dataType>
    </stateVariable>
  </serviceStateTable>
</scpd>


2020-12-16 12:52:11.631 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml -- urn:schemas-sony-com:serviceId:IRCC and adding SCPD: http://xxx.xxx.xxx.xxx:50001/IRCCSCPD.xml -- org.openhab.binding.sony.internal.upnp.models.UpnpScpd@f4353d
2020-12-16 12:52:11.633 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and finding action: http://xxx.xxx.xxx.xxx:50002/actionList
2020-12-16 12:52:11.637 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Sending client request on thread upnp-main-94334
3 > GET http://xxx.xxx.xxx.xxx:50002/actionList
3 > Connection: close
3 > User-Agent: OpenHab/Sony/Binding
3 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
3 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.671 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Client response received on thread upnp-main-94334
3 < 200
3 < Cache-Control: no-cache
3 < Connection: close
3 < content: text/xml
3 < Date: Sun, 01 Jun 2014 00:00:14 GMT
3 < Pragma: no-cache
3 < Server: Linux/3.10 Sony-BDP/2.0
3 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<actionList>
  <action name="register" mode="3" url="http://xxx.xxx.xxx.xxx:50002/register"/>
  <action name="getText" url="http://xxx.xxx.xxx.xxx:50002/getText"/>
  <action name="sendText" url="http://xxx.xxx.xxx.xxx:50002/sendText"/>
  <action name="getContentInformation" url="http://xxx.xxx.xxx.xxx:50002/getContentInformation"/>
  <action name="getSystemInformation" url="http://xxx.xxx.xxx.xxx:50002/getSystemInformation"/>
  <action name="getRemoteCommandList" url="http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList"/>
  <action name="getStatus" url="http://xxx.xxx.xxx.xxx:50002/getStatus"/>
  <action name="getHistoryList" url="http://xxx.xxx.xxx.xxx:50002/getHistoryList"/>
</actionList>


2020-12-16 12:52:11.683 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found action: http://xxx.xxx.xxx.xxx:50002/actionList -- org.openhab.binding.sony.internal.ircc.models.IrccActionList@c0aae8
2020-12-16 12:52:11.685 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting system information: http://xxx.xxx.xxx.xxx:50002/getSystemInformation
2020-12-16 12:52:11.690 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Sending client request on thread upnp-main-94334
4 > GET http://xxx.xxx.xxx.xxx:50002/getSystemInformation
4 > Connection: close
4 > User-Agent: OpenHab/Sony/Binding
4 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
4 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.711 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Client response received on thread upnp-main-94334
4 < 200
4 < Cache-Control: no-cache
4 < Connection: close
4 < content: text/xml
4 < Date: Sun, 01 Jun 2014 00:00:14 GMT
4 < Pragma: no-cache
4 < Server: Linux/3.10 Sony-BDP/2.0
4 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<systemInformation>
  <name>BDPlayer</name>
  <generation>2016</generation>
  <remoteType>RMT-B119A</remoteType>
  <remoteType>RMT-B120A</remoteType>
  <remoteType>RMT-B122A</remoteType>
  <remoteType>RMT-B123A</remoteType>
  <remoteType>RMT-B126A</remoteType>
  <remoteType>RMT-B119J</remoteType>
  <remoteType>RMT-B127J</remoteType>
  <remoteType>RMT-B119P</remoteType>
  <remoteType>RMT-B120P</remoteType>
  <remoteType>RMT-B121P</remoteType>
  <remoteType>RMT-B122P</remoteType>
  <remoteType bundled="true">RMT-B127P</remoteType>
  <remoteType>RMT-B119C</remoteType>
  <remoteType>RMT-B120C</remoteType>
  <remoteType>RMT-B122C</remoteType>
  <remoteType>RMT-B127C</remoteType>
  <remoteType>RMT-B127T</remoteType>
  <remoteType>RMT-B115A</remoteType>
  <actionHeader name="CERS-DEVICE-ID"/>
  <supportContentsClass>
    <class>video</class>
    <class>music</class>
  </supportContentsClass>
  <supportSource>
    <source>BD</source>
    <source>DVD</source>
    <source>CD</source>
    <source>Net</source>
  </supportSource>
  <supportFunction>
    <function name="Notification"/>
    <function name="WOL">
      <functionItem field="MAC" value="94-db-56-5a-27-9d"/>
    </function>
  </supportFunction>
</systemInformation>


2020-12-16 12:52:11.723 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and found system information: http://xxx.xxx.xxx.xxx:50002/getSystemInformation -- org.openhab.binding.sony.internal.ircc.models.IrccSystemInformation@136dbb6
2020-12-16 12:52:11.724 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting remote commands: http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList
2020-12-16 12:52:11.728 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Sending client request on thread upnp-main-94334
5 > GET http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList
5 > Connection: close
5 > User-Agent: OpenHab/Sony/Binding
5 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
5 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:11.857 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Client response received on thread upnp-main-94334
5 < 200
5 < Cache-Control: no-cache
5 < Connection: close
5 < content: text/xml
5 < Date: Sun, 01 Jun 2014 00:00:15 GMT
5 < Pragma: no-cache
5 < Server: Linux/3.10 Sony-BDP/2.0
5 < Transfer-Encoding: chunked
<?xml version="1.0" encoding="UTF-8"?>
<remoteCommandList>
  <command name="Confirm" type="ircc" value="AAAAAwAAHFoAAAA9Aw==" />
  <command name="Up" type="ircc" value="AAAAAwAAHFoAAAA5Aw==" />
  <command name="Down" type="ircc" value="AAAAAwAAHFoAAAA6Aw==" />
  <command name="Right" type="ircc" value="AAAAAwAAHFoAAAA8Aw==" />
  <command name="Left" type="ircc" value="AAAAAwAAHFoAAAA7Aw==" />
  <command name="Home" type="ircc" value="AAAAAwAAHFoAAABCAw==" />
  <command name="Options" type="ircc" value="AAAAAwAAHFoAAAA/Aw==" />
  <command name="Return" type="ircc" value="AAAAAwAAHFoAAABDAw==" />
  <command name="Num1" type="ircc" value="AAAAAwAAHFoAAAAAAw==" />
  <command name="Num2" type="ircc" value="AAAAAwAAHFoAAAABAw==" />
  <command name="Num3" type="ircc" value="AAAAAwAAHFoAAAACAw==" />
  <command name="Num4" type="ircc" value="AAAAAwAAHFoAAAADAw==" />
  <command name="Num5" type="ircc" value="AAAAAwAAHFoAAAAEAw==" />
  <command name="Num6" type="ircc" value="AAAAAwAAHFoAAAAFAw==" />
  <command name="Num7" type="ircc" value="AAAAAwAAHFoAAAAGAw==" />
  <command name="Num8" type="ircc" value="AAAAAwAAHFoAAAAHAw==" />
  <command name="Num9" type="ircc" value="AAAAAwAAHFoAAAAIAw==" />
  <command name="Num0" type="ircc" value="AAAAAwAAHFoAAAAJAw==" />
  <command name="Power" type="ircc" value="AAAAAwAAHFoAAAAVAw==" />
  <command name="Display" type="ircc" value="AAAAAwAAHFoAAABBAw==" />
  <command name="Audio" type="ircc" value="AAAAAwAAHFoAAABkAw==" />
  <command name="SubTitle" type="ircc" value="AAAAAwAAHFoAAABjAw==" />
  <command name="Favorites" type="ircc" value="AAAAAwAAHFoAAABeAw==" />
  <command name="Yellow" type="ircc" value="AAAAAwAAHFoAAABpAw==" />
  <command name="Blue" type="ircc" value="AAAAAwAAHFoAAABmAw==" />
  <command name="Red" type="ircc" value="AAAAAwAAHFoAAABnAw==" />
  <command name="Green" type="ircc" value="AAAAAwAAHFoAAABoAw==" />
  <command name="Play" type="ircc" value="AAAAAwAAHFoAAAAaAw==" />
  <command name="Stop" type="ircc" value="AAAAAwAAHFoAAAAYAw==" />
  <command name="Pause" type="ircc" value="AAAAAwAAHFoAAAAZAw==" />
  <command name="Rewind" type="ircc" value="AAAAAwAAHFoAAAAbAw==" />
  <command name="Forward" type="ircc" value="AAAAAwAAHFoAAAAcAw==" />
  <command name="Prev" type="ircc" value="AAAAAwAAHFoAAABXAw==" />
  <command name="Next" type="ircc" value="AAAAAwAAHFoAAABWAw==" />
  <command name="Replay" type="ircc" value="AAAAAwAAHFoAAAB2Aw==" />
  <command name="Advance" type="ircc" value="AAAAAwAAHFoAAAB1Aw==" />
  <command name="Angle" type="ircc" value="AAAAAwAAHFoAAABlAw==" />
  <command name="TopMenu" type="ircc" value="AAAAAwAAHFoAAAAsAw==" />
  <command name="PopUpMenu" type="ircc" value="AAAAAwAAHFoAAAApAw==" />
  <command name="Eject" type="ircc" value="AAAAAwAAHFoAAAAWAw==" />
  <command name="Karaoke" type="ircc" value="AAAAAwAAHFoAAABKAw==" />
  <command name="Netflix" type="ircc" value="AAAAAwAAHFoAAABLAw==" />
  <command name="Mode3D" type="ircc" value="AAAAAwAAHFoAAABNAw==" />
</remoteCommandList>


2020-12-16 12:52:11.880 [DEBUG] [sony.internal.ircc.IrccClientFactory] - Querying IRCC client http://xxx.xxx.xxx.xxx:50001/Ircc.xml and getting remote commands: http://xxx.xxx.xxx.xxx:50002/getRemoteCommandList -- org.openhab.binding.sony.internal.ircc.models.IrccRemoteCommands@a8c476
2020-12-16 12:52:11.883 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:11.892 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:52:16.409 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:16.414 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:16.417 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:19.405 [TRACE] [g.sony.internal.AbstractThingHandler] - Ignoring thing status of UNKNOWN
2020-12-16 12:52:19.409 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Attempting connection to Scalar Web device...
2020-12-16 12:52:19.517 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-4
1 > GET http://xxx.xxx.xxx.xxx:52323/dmr.xml
1 > Connection: close
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding

2020-12-16 12:52:19.522 [DEBUG] [nal.scalarweb.ScalarWebClientFactory] - Testing Default Scalar Web client: http://xxx.xxx.xxx.xxx:10000/sony/guide
2020-12-16 12:52:19.596 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-4
1 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
1 > Accept: application/json
1 > Connection: close
1 > Content-Type: application/json
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136104,"method":"getVersions","version":"1.0","params":[]}

2020-12-16 12:52:19.660 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread OH-thingHandler-4
1 < 200
1 < Connection: close
1 < content: application/json
1 < Content-Length: 32
{"id":136104,"result":[["1.0"]]}

2020-12-16 12:52:19.729 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-4
1 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
1 > Accept: application/json
1 > Connection: close
1 > Content-Type: application/json
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136105,"method":"getVersions","version":"1.0","params":[]}

2020-12-16 12:52:19.743 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread OH-thingHandler-4
1 < 200
1 < Connection: close
1 < content: application/json
1 < Content-Length: 32
{"id":136105,"result":[["1.0"]]}

2020-12-16 12:52:19.750 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread OH-thingHandler-4
2 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
2 > Accept: application/json
2 > Connection: close
2 > Content-Type: application/json
2 > User-Agent: OpenHab/Sony/Binding
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136106,"method":"getMethodTypes","version":"1.0","params":["1.0"]}

2020-12-16 12:52:19.928 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Client response received on thread OH-thingHandler-4
2 < 200
2 < Connection: close
2 < content: application/json
2 < Content-Length: 334
{"id":136106,"results":[["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getServiceProtocols",[],["string","string*"],"1.0"],["getSupportedApiInfo",["{\"services\":\"string*\"}"],["{\"service\":\"string\", \"protocols\":\"string*\", \"apis\":\"ApiInfo[]\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"]]}

2020-12-16 12:52:19.933 [DEBUG] [nal.scalarweb.ScalarWebDeviceManager] - Service guide doesn't contain switchNotifications - ignoring notifications
2020-12-16 12:52:19.991 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Sending client request on thread OH-thingHandler-4
1 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
1 > Accept: application/json
1 > Connection: close
1 > Content-Type: application/json
1 > User-Agent: OpenHab/Sony/Binding
1 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
1 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136107,"method":"getServiceProtocols","version":"1.0","params":[]}

2020-12-16 12:52:20.261 [DEBUG] [inding.sony.internal.net.HttpRequest] - 1 * Client response received on thread OH-thingHandler-4
1 < 200
1 < Connection: close
1 < content: application/json
1 < Content-Length: 217
{"id":136107,"results":[["audio",["xhrpost:jsonizer","websocket:jsonizer"]],["avContent",["xhrpost:jsonizer","websocket:jsonizer"]],["guide",["xhrpost:jsonizer"]],["system",["xhrpost:jsonizer","websocket:jsonizer"]]]}

2020-12-16 12:52:20.282 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Sending client request on thread OH-thingHandler-4
2 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
2 > Accept: application/json
2 > Connection: close
2 > Content-Type: application/json
2 > User-Agent: OpenHab/Sony/Binding
2 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
2 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136108,"method":"getSupportedApiInfo","version":"1.0","params":[{"services":["system"]}]}

2020-12-16 12:52:20.351 [DEBUG] [inding.sony.internal.net.HttpRequest] - 2 * Client response received on thread OH-thingHandler-4
2 < 200
2 < Connection: close
2 < content: application/json
2 < Content-Length: 1261
{"id":136108,"result":[[{"apis":[{"name":"getDeviceMiscSettings","versions":[{"version":"1.0"}]},{"name":"getInterfaceInformation","versions":[{"version":"1.0"}]},{"name":"getMethodTypes","versions":[{"version":"1.0"}]},{"name":"getPowerSettings","versions":[{"version":"1.0"}]},{"name":"getPowerStatus","versions":[{"version":"1.1"}]},{"name":"getSettingsTree","versions":[{"version":"1.1"}]},{"name":"getStorageList","versions":[{"authLevel":"generic","version":"1.1"},{"version":"1.2"}]},{"name":"getSystemInformation","versions":[{"version":"1.3"}]},{"name":"getVersions","versions":[{"version":"1.0"}]},{"name":"setClientInfo","versions":[{"version":"1.0"}]},{"name":"setDeviceMiscSettings","versions":[{"version":"1.0"}]},{"name":"setPowerSettings","versions":[{"version":"1.0"}]},{"name":"setPowerStatus","versions":[{"version":"1.1"}]},{"name":"switchNotifications","versions":[{"protocols":["websocket:jsonizer"],"version":"1.0"}]}],"notifications":[{"name":"notifyPowerStatus","versions":[{"version":"1.0"}]},{"name":"notifySettingsUpdate","versions":[{"version":"1.1"}]},{"name":"notifyStorageStatus","versions":[{"authLevel":"generic","version":"1.1"},{"version":"1.2"}]}],"protocols":["xhrpost:jsonizer","websocket:jsonizer"],"service":"system"}]]}

2020-12-16 12:52:20.366 [DEBUG] [al.transports.SonyWebSocketTransport] - Starting websocket connection to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:20.498 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onConnect(WebSocketSession[websocket=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@1ce3eff],behavior=CLIENT,connection=WebSocketClientConnection@180c2ff::SocketChannelEndPoint@970c99{/xxx.xxx.xxx.xxx:10000<->/192.168.200.40:53192,OPEN,fill=-,flush=-,to=6/300000}{io=0/0,kio=0,kro=1}->WebSocketClientConnection@180c2ff[s=ConnectionState@129181f[OPENING],f=org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$Flusher@1d0fd03[IDLE][queueSize=0,aggregateSize=-1,terminated=null],g=Generator[CLIENT,validating],p=Parser@a652fc[ExtensionStack,s=START,c=0,len=0,f=null]],remote=WebSocketRemoteEndpoint@557bb5[batching=true],incoming=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@1ce3eff],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.common.WebSocketSession,outgoing=org.eclipse.jetty.websocket.client.io.WebSocketClientConnection]])
2020-12-16 12:52:20.505 [DEBUG] [al.transports.SonyWebSocketTransport] - Connected successfully to server ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:20.509 [DEBUG] [al.transports.SonyWebSocketTransport] - Websocket connection successful to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:20.512 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.531 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Sending client request on thread OH-thingHandler-4
3 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
3 > Accept: application/json
3 > Connection: close
3 > Content-Type: application/json
3 > User-Agent: OpenHab/Sony/Binding
3 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
3 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136109,"method":"getSupportedApiInfo","version":"1.0","params":[{"services":["audio"]}]}

2020-12-16 12:52:20.553 [DEBUG] [inding.sony.internal.net.HttpRequest] - 3 * Client response received on thread OH-thingHandler-4
3 < 200
3 < Connection: close
3 < content: application/json
3 < Content-Length: 317
{"id":136109,"result":[[{"apis":[{"name":"getMethodTypes","versions":[{"version":"1.0"}]},{"name":"getVersions","versions":[{"version":"1.0"}]},{"name":"switchNotifications","versions":[{"protocols":["websocket:jsonizer"],"version":"1.0"}]}],"protocols":["xhrpost:jsonizer","websocket:jsonizer"],"service":"audio"}]]}

2020-12-16 12:52:20.561 [DEBUG] [al.transports.SonyWebSocketTransport] - Starting websocket connection to ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:20.585 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onConnect(WebSocketSession[websocket=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@105a84e],behavior=CLIENT,connection=WebSocketClientConnection@77652e::SocketChannelEndPoint@7dd0b5{/xxx.xxx.xxx.xxx:10000<->/192.168.200.40:53196,OPEN,fill=-,flush=-,to=5/300000}{io=0/0,kio=0,kro=1}->WebSocketClientConnection@77652e[s=ConnectionState@44f94e[OPENING],f=org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$Flusher@316b50[IDLE][queueSize=0,aggregateSize=-1,terminated=null],g=Generator[CLIENT,validating],p=Parser@1642bad[ExtensionStack,s=START,c=0,len=0,f=null]],remote=WebSocketRemoteEndpoint@11ca1cc[batching=true],incoming=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@105a84e],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.common.WebSocketSession,outgoing=org.eclipse.jetty.websocket.client.io.WebSocketClientConnection]])
2020-12-16 12:52:20.589 [DEBUG] [al.transports.SonyWebSocketTransport] - Connected successfully to server ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:20.593 [DEBUG] [al.transports.SonyWebSocketTransport] - Websocket connection successful to ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:20.596 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.613 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Sending client request on thread OH-thingHandler-4
4 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
4 > Accept: application/json
4 > Connection: close
4 > Content-Type: application/json
4 > User-Agent: OpenHab/Sony/Binding
4 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
4 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136110,"method":"getSupportedApiInfo","version":"1.0","params":[{"services":["avContent"]}]}

2020-12-16 12:52:20.661 [DEBUG] [inding.sony.internal.net.HttpRequest] - 4 * Client response received on thread OH-thingHandler-4
4 < 200
4 < Connection: close
4 < content: application/json
4 < Content-Length: 1638
{"id":136110,"result":[[{"apis":[{"name":"getAvailablePlaybackFunction","versions":[{"version":"1.0"}]},{"name":"getContentCount","versions":[{"version":"1.3"}]},{"name":"getContentList","versions":[{"version":"1.4"}]},{"name":"getCurrentExternalTerminalsStatus","versions":[{"version":"1.0"}]},{"name":"getMethodTypes","versions":[{"version":"1.0"}]},{"name":"getPlaybackModeSettings","versions":[{"version":"1.0"}]},{"name":"getPlayingContentInfo","versions":[{"version":"1.2"}]},{"name":"getSchemeList","versions":[{"version":"1.0"}]},{"name":"getSourceList","versions":[{"version":"1.1"}]},{"name":"getSupportedPlaybackFunction","versions":[{"version":"1.0"}]},{"name":"getVersions","versions":[{"version":"1.0"}]},{"name":"pausePlayingContent","versions":[{"version":"1.1"}]},{"name":"presetBroadcastStation","versions":[{"version":"1.0"}]},{"name":"scanPlayingContent","versions":[{"version":"1.0"}]},{"name":"setPlayContent","versions":[{"version":"1.2"}]},{"name":"setPlayNextContent","versions":[{"version":"1.0"}]},{"name":"setPlayPreviousContent","versions":[{"version":"1.0"}]},{"name":"setPlaybackModeSettings","versions":[{"version":"1.0"}]},{"name":"startContentBrowsing","versions":[{"version":"1.0"}]},{"name":"stopPlayingContent","versions":[{"version":"1.1"}]},{"name":"switchNotifications","versions":[{"protocols":["websocket:jsonizer"],"version":"1.0"}]}],"notifications":[{"name":"notifyAvailablePlaybackFunction","versions":[{"version":"1.0"}]},{"name":"notifyPlayingContentInfo","versions":[{"authLevel":"private","version":"1.0"}]}],"protocols":["xhrpost:jsonizer","websocket:jsonizer"],"service":"avContent"}]]}

2020-12-16 12:52:20.676 [DEBUG] [al.transports.SonyWebSocketTransport] - Starting websocket connection to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:20.695 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onConnect(WebSocketSession[websocket=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@6a4457],behavior=CLIENT,connection=WebSocketClientConnection@1e3ab54::SocketChannelEndPoint@1420239{/xxx.xxx.xxx.xxx:10000<->/192.168.200.40:53200,OPEN,fill=-,flush=-,to=2/300000}{io=1/0,kio=1,kro=1}->WebSocketClientConnection@1e3ab54[s=ConnectionState@2f273f[OPENING],f=org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$Flusher@1f9b11[IDLE][queueSize=0,aggregateSize=-1,terminated=null],g=Generator[CLIENT,validating],p=Parser@602ecd[ExtensionStack,s=START,c=0,len=0,f=null]],remote=WebSocketRemoteEndpoint@116a872[batching=true],incoming=JettyAnnotatedEventDriver[org.openhab.binding.sony.internal.transports.SonyWebSocketTransport$WebSocketCallback@6a4457],outgoing=ExtensionStack[queueSize=0,extensions=[],incoming=org.eclipse.jetty.websocket.common.WebSocketSession,outgoing=org.eclipse.jetty.websocket.client.io.WebSocketClientConnection]])
2020-12-16 12:52:20.698 [DEBUG] [al.transports.SonyWebSocketTransport] - Connected successfully to server ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:20.700 [DEBUG] [al.transports.SonyWebSocketTransport] - Websocket connection successful to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:20.702 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.703 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.707 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.710 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:20.714 [DEBUG] [web.protocols.ScalarWebLoginProtocol] - WOL packet is not supported - specify the IP address and mac address in config if you want a WOL packet sent
2020-12-16 12:52:20.716 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136111,"method":"getPowerStatus","version":"1.1","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.414 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.426 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.427 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:21.593 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136111,"result":[{"standbyDetail":"","status":"active"}]})
2020-12-16 12:52:21.595 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136111,"result":[{"standbyDetail":"","status":"active"}]}
2020-12-16 12:52:21.597 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136112,"method":"getSystemInformation","version":"1.3","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.676 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136112,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]})
2020-12-16 12:52:21.678 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136112,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]}
2020-12-16 12:52:21.681 [DEBUG] [web.protocols.ScalarWebLoginProtocol] - WebScalar System now connected
2020-12-16 12:52:21.683 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136113,"method":"getSystemInformation","version":"1.3","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.697 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136113,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]})
2020-12-16 12:52:21.701 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136113,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]}
2020-12-16 12:52:21.704 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136114,"method":"getInterfaceInformation","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.716 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136114,"result":[{"interfaceVersion":"2.2.0","modelName":"BDP-S6700","productCategory":"videoPlayer","productName":"BX","serverName":""}]})
2020-12-16 12:52:21.719 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136114,"result":[{"interfaceVersion":"2.2.0","modelName":"BDP-S6700","productCategory":"videoPlayer","productName":"BX","serverName":""}]}
2020-12-16 12:52:21.723 [DEBUG] [web.protocols.ScalarWebLoginProtocol] - Command map already defined - ignoring: /etc/openhab2/transform/scalar-94db565a279d.map
2020-12-16 12:52:21.726 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136115,"method":"switchNotifications","version":"1.0","params":[{"enabled":[],"disabled":[]}]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.743 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136115,"result":[{"disabled":[{"name":"notifyPowerStatus","version":"1.0"},{"name":"notifySettingsUpdate","version":"1.1"},{"name":"notifyStorageStatus","version":"1.1"},{"name":"notifyStorageStatus","version":"1.2"}],"enabled":[]}]})
2020-12-16 12:52:21.746 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136115,"result":[{"disabled":[{"name":"notifyPowerStatus","version":"1.0"},{"name":"notifySettingsUpdate","version":"1.1"},{"name":"notifyStorageStatus","version":"1.1"},{"name":"notifyStorageStatus","version":"1.2"}],"enabled":[]}]}
2020-12-16 12:52:21.750 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136116,"method":"switchNotifications","version":"1.0","params":[{"enabled":[{"name":"notifyPowerStatus","version":"1.0"},{"name":"notifySettingsUpdate","version":"1.1"},{"name":"notifyStorageStatus","version":"1.1"},{"name":"notifyStorageStatus","version":"1.2"}]}]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:21.766 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136116,"result":[{"disabled":[],"enabled":[{"name":"notifyPowerStatus","version":"1.0"},{"name":"notifySettingsUpdate","version":"1.1"},{"name":"notifyStorageStatus","version":"1.1"},{"name":"notifyStorageStatus","version":"1.2"}]}]})
2020-12-16 12:52:21.769 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136116,"result":[{"disabled":[],"enabled":[{"name":"notifyPowerStatus","version":"1.0"},{"name":"notifySettingsUpdate","version":"1.1"},{"name":"notifyStorageStatus","version":"1.1"},{"name":"notifyStorageStatus","version":"1.2"}]}]}
2020-12-16 12:52:21.772 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136117,"method":"switchNotifications","version":"1.0","params":[{"enabled":[],"disabled":[]}]} to ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:21.786 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136117,"result":[{"disabled":[],"enabled":[]}]})
2020-12-16 12:52:21.788 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136117,"result":[{"disabled":[],"enabled":[]}]}
2020-12-16 12:52:21.790 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136118,"method":"switchNotifications","version":"1.0","params":[{"enabled":[],"disabled":[]}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.808 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136118,"result":[{"disabled":[{"name":"notifyAvailablePlaybackFunction","version":"1.0"},{"name":"notifyPlayingContentInfo","version":"1.0"}],"enabled":[]}]})
2020-12-16 12:52:21.810 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136118,"result":[{"disabled":[{"name":"notifyAvailablePlaybackFunction","version":"1.0"},{"name":"notifyPlayingContentInfo","version":"1.0"}],"enabled":[]}]}
2020-12-16 12:52:21.813 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136119,"method":"switchNotifications","version":"1.0","params":[{"enabled":[{"name":"notifyPlayingContentInfo","version":"1.0"}],"disabled":[{"name":"notifyAvailablePlaybackFunction","version":"1.0"}]}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.830 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136119,"result":[{"disabled":[{"name":"notifyAvailablePlaybackFunction","version":"1.0"}],"enabled":[{"name":"notifyPlayingContentInfo","version":"1.0"}]}]})
2020-12-16 12:52:21.832 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136119,"result":[{"disabled":[{"name":"notifyAvailablePlaybackFunction","version":"1.0"}],"enabled":[{"name":"notifyPlayingContentInfo","version":"1.0"}]}]}
2020-12-16 12:52:21.835 [TRACE] [b.protocols.ScalarWebProtocolFactory] - Generic protocol for guide service (no specific protocol written)
2020-12-16 12:52:21.855 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136120,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.927 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136120,"result":[[]]})
2020-12-16 12:52:21.929 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136120,"result":[[]]}
2020-12-16 12:52:21.931 [DEBUG] [web.protocols.ScalarWebAudioProtocol] - Unknown getVolumeInformation method version: null
2020-12-16 12:52:21.933 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136121,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.943 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136121,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:52:21.945 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136121,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:52:21.948 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136122,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:21.958 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136122,"result":[[]]})
2020-12-16 12:52:21.960 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136122,"result":[[]]}
2020-12-16 12:52:21.970 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136123,"method":"getPlaybackModeSettings","version":"1.0","params":[{"target":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:22.257 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136123,"result":[[{"candidate":[{"isAvailable":false,"title":"Repeat All","titleTextID":"repeatAll","value":"all"},{"isAvailable":false,"title":"Repeat Folder","titleTextID":"repeatFolder","value":"folder"},{"isAvailable":false,"title":"Repeat Track","titleTextID":"repeatTrack","value":"track"},{"isAvailable":false,"title":"Repeat Off","titleTextID":"repeatOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"repeatType","title":"Repeat","titleTextID":"playbackMode-repeatType","type":"enumTarget","uri":"storage:usb1"},{"candidate":[{"isAvailable":false,"title":"Shuffle Folder","titleTextID":"shuffleFolder","value":"folder"},{"isAvailable":false,"title":"Shuffle OFF","titleTextID":"shuffleOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"shuffleType","title":"Shuffle","titleTextID":"playbackMode-shuffleType","type":"enumTarget","uri":"storage:usb1"},{"candidate":[{"isAvailable":false,"title":"Repeat All","titleTextID":"repeatAll","value":"all"},{"isAvailable":false,"title":"Repeat Track","titleTextID":"repeatTrack","value":"track"},{"isAvailable":false,"title":"Repeat Off","titleTextID":"repeatOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"repeatType","title":"Repeat","titleTextID":"playbackMode-repeatType","type":"enumTarget","uri":"storage:cd"},{"candidate":[{"isAvailable":false,"title":"Shuffle Folder","titleTextID":"shuffleFolder","value":"folder"},{"isAvailable":false,"title":"Shuffle OFF","titleTextID":"shuffleOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"shuffleType","title":"Shuffle","titleTextID":"playbackMode-shuffleType","type":"enumTarget","uri":"storage:cd"}]]})
2020-12-16 12:52:22.263 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136123,"result":[[{"candidate":[{"isAvailable":false,"title":"Repeat All","titleTextID":"repeatAll","value":"all"},{"isAvailable":false,"title":"Repeat Folder","titleTextID":"repeatFolder","value":"folder"},{"isAvailable":false,"title":"Repeat Track","titleTextID":"repeatTrack","value":"track"},{"isAvailable":false,"title":"Repeat Off","titleTextID":"repeatOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"repeatType","title":"Repeat","titleTextID":"playbackMode-repeatType","type":"enumTarget","uri":"storage:usb1"},{"candidate":[{"isAvailable":false,"title":"Shuffle Folder","titleTextID":"shuffleFolder","value":"folder"},{"isAvailable":false,"title":"Shuffle OFF","titleTextID":"shuffleOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"shuffleType","title":"Shuffle","titleTextID":"playbackMode-shuffleType","type":"enumTarget","uri":"storage:usb1"},{"candidate":[{"isAvailable":false,"title":"Repeat All","titleTextID":"repeatAll","value":"all"},{"isAvailable":false,"title":"Repeat Track","titleTextID":"repeatTrack","value":"track"},{"isAvailable":false,"title":"Repeat Off","titleTextID":"repeatOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"repeatType","title":"Repeat","titleTextID":"playbackMode-repeatType","type":"enumTarget","uri":"storage:cd"},{"candidate":[{"isAvailable":false,"title":"Shuffle Folder","titleTextID":"shuffleFolder","value":"folder"},{"isAvailable":false,"title":"Shuffle OFF","titleTextID":"shuffleOff","value":"off"}],"currentValue":"off","isAvailable":false,"target":"shuffleType","title":"Shuffle","titleTextID":"playbackMode-shuffleType","type":"enumTarget","uri":"storage:cd"}]]}
2020-12-16 12:52:22.293 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136124,"method":"getSystemInformation","version":"1.3","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:22.309 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136124,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]})
2020-12-16 12:52:22.312 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136124,"result":[{"macAddr":"94:db:56:5a:27:9d","version":"M32.R.0527","wirelessMacAddr":"8c:c8:4b:db:ae:55"}]}
2020-12-16 12:52:22.318 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136125,"method":"getPowerStatus","version":"1.1","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:22.330 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136125,"result":[{"standbyDetail":"","status":"active"}]})
2020-12-16 12:52:22.333 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136125,"result":[{"standbyDetail":"","status":"active"}]}
2020-12-16 12:52:22.336 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136126,"method":"getDeviceMiscSettings","version":"1.0","params":[{"target":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:22.924 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136126,"result":[[{"currentValue":"BDP-S6700","deviceUIInfo":"","isAvailable":true,"target":"deviceName","title":"IDMR_TEXT_BT_DEVICE_NAME_STRING","titleTextID":"system-networkdevicename","type":"stringTarget"},{"candidate":[{"isAvailable":true,"title":"On","titleTextID":"","value":"on"},{"isAvailable":true,"title":"Off","titleTextID":"","value":"off"}],"currentValue":"off","deviceUIInfo":"","isAvailable":true,"target":"swAutoUpdate","title":"Auto Update","titleTextID":"system-autoupdate","type":"booleanTarget"},{"candidate":[{"isAvailable":true,"title":"Auto","titleTextID":"","value":"auto"},{"isAvailable":true,"title":"Manual","titleTextID":"","value":"manual"}],"currentValue":"manual","deviceUIInfo":"","isAvailable":true,"target":"gracenote","title":"Gracenote Settings","titleTextID":"system-gracenote","type":"enumTarget"}]]})
2020-12-16 12:52:22.927 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136126,"result":[[{"currentValue":"BDP-S6700","deviceUIInfo":"","isAvailable":true,"target":"deviceName","title":"IDMR_TEXT_BT_DEVICE_NAME_STRING","titleTextID":"system-networkdevicename","type":"stringTarget"},{"candidate":[{"isAvailable":true,"title":"On","titleTextID":"","value":"on"},{"isAvailable":true,"title":"Off","titleTextID":"","value":"off"}],"currentValue":"off","deviceUIInfo":"","isAvailable":true,"target":"swAutoUpdate","title":"Auto Update","titleTextID":"system-autoupdate","type":"booleanTarget"},{"candidate":[{"isAvailable":true,"title":"Auto","titleTextID":"","value":"auto"},{"isAvailable":true,"title":"Manual","titleTextID":"","value":"manual"}],"currentValue":"manual","deviceUIInfo":"","isAvailable":true,"target":"gracenote","title":"Gracenote Settings","titleTextID":"system-gracenote","type":"enumTarget"}]]}
2020-12-16 12:52:22.931 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136127,"method":"getPowerSettings","version":"1.0","params":[{"target":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:22.997 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136127,"result":[[{"candidate":[{"isAvailable":true,"title":"On","value":"on"},{"isAvailable":true,"title":"Off","value":"off"}],"currentValue":"off","target":"quickStartMode","title":"Quick Start Mode","titleTextID":"system-networkstandby","type":"booleanTarget"},{"candidate":[{"isAvailable":true,"title":"On","value":"on"},{"isAvailable":true,"title":"Off","value":"off"}],"currentValue":"on","target":"wolMode","title":"Remote Start","titleTextID":"system-remotestart","type":"booleanTarget"}]]})
2020-12-16 12:52:23.000 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136127,"result":[[{"candidate":[{"isAvailable":true,"title":"On","value":"on"},{"isAvailable":true,"title":"Off","value":"off"}],"currentValue":"off","target":"quickStartMode","title":"Quick Start Mode","titleTextID":"system-networkstandby","type":"booleanTarget"},{"candidate":[{"isAvailable":true,"title":"On","value":"on"},{"isAvailable":true,"title":"Off","value":"off"}],"currentValue":"on","target":"wolMode","title":"Remote Start","titleTextID":"system-remotestart","type":"booleanTarget"}]]}
2020-12-16 12:52:23.004 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136128,"method":"getStorageList","version":"1.2","params":[{"isRegistered":"","uri":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:23.061 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136128,"result":[[{"deviceName":"USB","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"front","systemAreaCapacityMB":-1,"uri":"storage:usb1","volumeLabel":"","wholeCapacityMB":-1},{"deviceName":"USB","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"rear","systemAreaCapacityMB":-1,"uri":"storage:usb2","volumeLabel":"","wholeCapacityMB":-1},{"deviceName":"CD","format":"","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"internal","systemAreaCapacityMB":-1,"type":"","uri":"storage:cd","volumeLabel":"","wholeCapacityMB":-1}]]})
2020-12-16 12:52:23.064 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136128,"result":[[{"deviceName":"USB","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"front","systemAreaCapacityMB":-1,"uri":"storage:usb1","volumeLabel":"","wholeCapacityMB":-1},{"deviceName":"USB","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"rear","systemAreaCapacityMB":-1,"uri":"storage:usb2","volumeLabel":"","wholeCapacityMB":-1},{"deviceName":"CD","format":"","formattable":"unknown","freeCapacityMB":-1,"isAvailable":"false","mounted":"unmounted","permission":"","position":"internal","systemAreaCapacityMB":-1,"type":"","uri":"storage:cd","volumeLabel":"","wholeCapacityMB":-1}]]}
2020-12-16 12:52:23.069 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_parenturi (cid=cn_parenturi, ctgy=cn_parenturi, path=) accepting String of type scalarwebavcontrolcontentparenturi
2020-12-16 12:52:23.072 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_uri (cid=cn_uri, ctgy=cn_uri, path=) accepting String of type scalarwebavcontrolcontenturi
2020-12-16 12:52:23.074 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_idx (cid=cn_idx, ctgy=cn_idx, path=) accepting Number of type scalarwebavcontrolcontentidx
2020-12-16 12:52:23.076 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_childcount (cid=cn_childcount, ctgy=cn_childcount, path=) accepting Number of type scalarwebavcontrolcontentchildcount
2020-12-16 12:52:23.078 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_cmd (cid=cn_cmd, ctgy=cn_cmd, path=) accepting String of type scalarwebavcontrolcontentcmd
2020-12-16 12:52:23.080 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_albumname (cid=cn_albumname, ctgy=cn_albumname, path=) accepting String of type scalarwebavcontrolcontentalbumname
2020-12-16 12:52:23.082 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_artist (cid=cn_artist, ctgy=cn_artist, path=) accepting String of type scalarwebavcontrolcontentartist
2020-12-16 12:52:23.084 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_audiochannel (cid=cn_audiochannel, ctgy=cn_audiochannel, path=) accepting String of type scalarwebavcontrolcontentaudiochannel
2020-12-16 12:52:23.086 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_audiocodec (cid=cn_audiocodec, ctgy=cn_audiocodec, path=) accepting String of type scalarwebavcontrolcontentaudiocodec
2020-12-16 12:52:23.088 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_audiofrequency (cid=cn_audiofrequency, ctgy=cn_audiofrequency, path=) accepting String of type scalarwebavcontrolcontentaudiofrequency
2020-12-16 12:52:23.090 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_broadcastfreq (cid=cn_broadcastfreq, ctgy=cn_broadcastfreq, path=) accepting Number:Frequency of type scalarwebavcontrolcontentbroadcastfreq
2020-12-16 12:52:23.092 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_broadcastfreqband (cid=cn_broadcastfreqband, ctgy=cn_broadcastfreqband, path=) accepting String of type scalarwebavcontrolcontentbroadcastband
2020-12-16 12:52:23.094 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_channelname (cid=cn_channelname, ctgy=cn_channelname, path=) accepting String of type scalarwebavcontrolcontentchannelname
2020-12-16 12:52:23.096 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_channelsurfingvisibility (cid=cn_channelsurfingvisibility, ctgy=cn_channelsurfingvisibility, path=) accepting String of type scalarwebavcontrolcontentchannelsurfingvisibility
2020-12-16 12:52:23.098 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_chaptercount (cid=cn_chaptercount, ctgy=cn_chaptercount, path=) accepting Number of type scalarwebavcontrolcontentchaptercount
2020-12-16 12:52:23.100 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_contentkind (cid=cn_contentkind, ctgy=cn_contentkind, path=) accepting String of type scalarwebavcontrolcontentcontentkind
2020-12-16 12:52:23.101 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_contenttype (cid=cn_contenttype, ctgy=cn_contenttype, path=) accepting String of type scalarwebavcontrolcontentcontenttype
2020-12-16 12:52:23.103 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_createdtime (cid=cn_createdtime, ctgy=cn_createdtime, path=) accepting String of type scalarwebavcontrolcontentcreatedtime
2020-12-16 12:52:23.105 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_directremotenum (cid=cn_directremotenum, ctgy=cn_directremotenum, path=) accepting Number of type scalarwebavcontrolcontentdirectremotenum
2020-12-16 12:52:23.107 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_dispnum (cid=cn_dispnum, ctgy=cn_dispnum, path=) accepting String of type scalarwebavcontrolcontentdispnum
2020-12-16 12:52:23.109 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_durationmsec (cid=cn_durationmsec, ctgy=cn_durationmsec, path=) accepting Number:Time of type scalarwebavcontrolcontentdurationmsec
2020-12-16 12:52:23.111 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_epgvisibility (cid=cn_epgvisibility, ctgy=cn_epgvisibility, path=) accepting String of type scalarwebavcontrolcontentepgvisibility
2020-12-16 12:52:23.112 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_fileno (cid=cn_fileno, ctgy=cn_fileno, path=) accepting String of type scalarwebavcontrolcontentfileno
2020-12-16 12:52:23.115 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_filesizebyte (cid=cn_filesizebyte, ctgy=cn_filesizebyte, path=) accepting Number:DataAmount of type scalarwebavcontrolcontentfilesizebyte
2020-12-16 12:52:23.116 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_folderno (cid=cn_folderno, ctgy=cn_folderno, path=) accepting String of type scalarwebavcontrolcontentfolderno
2020-12-16 12:52:23.119 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_genre (cid=cn_genre, ctgy=cn_genre, path=) accepting String of type scalarwebavcontrolcontentgenre
2020-12-16 12:52:23.122 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_is3d (cid=cn_is3d, ctgy=cn_is3d, path=) accepting String of type scalarwebavcontrolcontentis3d
2020-12-16 12:52:23.123 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_isalreadyplayed (cid=cn_isalreadyplayed, ctgy=cn_isalreadyplayed, path=) accepting String of type scalarwebavcontrolcontentisalreadyplayed
2020-12-16 12:52:23.126 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_isbrowsable (cid=cn_isbrowsable, ctgy=cn_isbrowsable, path=) accepting String of type scalarwebavcontrolcontentisbrowsable
2020-12-16 12:52:23.127 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_isplayable (cid=cn_isplayable, ctgy=cn_isplayable, path=) accepting String of type scalarwebavcontrolcontentisplayable
2020-12-16 12:52:23.130 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_isprotected (cid=cn_isprotected, ctgy=cn_isprotected, path=) accepting String of type scalarwebavcontrolcontentisprotected
2020-12-16 12:52:23.131 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_originaldispnum (cid=cn_originaldispnum, ctgy=cn_originaldispnum, path=) accepting String of type scalarwebavcontrolcontentoriginaldispnum
2020-12-16 12:52:23.134 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_parentalcountry (cid=cn_parentalcountry, ctgy=cn_parentalcountry, path=) accepting String of type scalarwebavcontrolcontentparentalcountry
2020-12-16 12:52:23.135 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_parentalrating (cid=cn_parentalrating, ctgy=cn_parentalrating, path=) accepting String of type scalarwebavcontrolcontentparentalrating
2020-12-16 12:52:23.138 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_parentalsystem (cid=cn_parentalsystem, ctgy=cn_parentalsystem, path=) accepting String of type scalarwebavcontrolcontentparentalsystem
2020-12-16 12:52:23.139 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_parentindex (cid=cn_parentindex, ctgy=cn_parentindex, path=) accepting Number of type scalarwebavcontrolcontentparentindex
2020-12-16 12:52:23.141 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_path (cid=cn_path, ctgy=cn_path, path=) accepting String of type scalarwebavcontrolcontentpath
2020-12-16 12:52:23.143 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_playlistname (cid=cn_playlistname, ctgy=cn_playlistname, path=) accepting String of type scalarwebavcontrolcontentplaylistname
2020-12-16 12:52:23.145 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_podcastname (cid=cn_podcastname, ctgy=cn_podcastname, path=) accepting String of type scalarwebavcontrolcontentpodcastname
2020-12-16 12:52:23.147 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_productid (cid=cn_productid, ctgy=cn_productid, path=) accepting String of type scalarwebavcontrolcontentproductid
2020-12-16 12:52:23.149 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_programmediatype (cid=cn_programmediatype, ctgy=cn_programmediatype, path=) accepting String of type scalarwebavcontrolcontentprogrammediatype
2020-12-16 12:52:23.151 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_programnum (cid=cn_programnum, ctgy=cn_programnum, path=) accepting Number of type scalarwebavcontrolcontentprogramnum
2020-12-16 12:52:23.153 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_remoteplaytype (cid=cn_remoteplaytype, ctgy=cn_remoteplaytype, path=) accepting String of type scalarwebavcontrolcontentremoteplaytype
2020-12-16 12:52:23.155 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_sizemb (cid=cn_sizemb, ctgy=cn_sizemb, path=) accepting Number:DataAmount of type scalarwebavcontrolcontentsizemb
2020-12-16 12:52:23.157 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_startdatetime (cid=cn_startdatetime, ctgy=cn_startdatetime, path=) accepting String of type scalarwebavcontrolcontentstartdatetime
2020-12-16 12:52:23.159 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_storageuri (cid=cn_storageuri, ctgy=cn_storageuri, path=) accepting String of type scalarwebavcontrolcontentstorageuri
2020-12-16 12:52:23.161 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_subtitlelanguage (cid=cn_subtitlelanguage, ctgy=cn_subtitlelanguage, path=) accepting String of type scalarwebavcontrolcontentsubtitlelanguage
2020-12-16 12:52:23.163 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_subtitletitle (cid=cn_subtitletitle, ctgy=cn_subtitletitle, path=) accepting String of type scalarwebavcontrolcontentsubtitletitle
2020-12-16 12:52:23.165 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_title (cid=cn_title, ctgy=cn_title, path=) accepting String of type scalarwebavcontrolcontenttitle
2020-12-16 12:52:23.167 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_tripletstr (cid=cn_tripletstr, ctgy=cn_tripletstr, path=) accepting String of type scalarwebavcontrolcontenttripletstr
2020-12-16 12:52:23.169 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_usercontentflag (cid=cn_usercontentflag, ctgy=cn_usercontentflag, path=) accepting Switch of type scalarwebavcontrolcontentusercontentflag
2020-12-16 12:52:23.171 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_videocodec (cid=cn_videocodec, ctgy=cn_videocodec, path=) accepting String of type scalarwebavcontrolcontentvideocodec
2020-12-16 12:52:23.173 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#cn_visibility (cid=cn_visibility, ctgy=cn_visibility, path=) accepting String of type scalarwebavcontrolcontentvisibility
2020-12-16 12:52:23.174 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#schemes (cid=schemes, ctgy=schemes, path=) accepting String of type scalarwebavcontrolschemes
2020-12-16 12:52:23.177 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#sources (cid=sources, ctgy=sources, path=) accepting String of type scalarwebavcontrolsources
2020-12-16 12:52:23.178 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_source-main (cid=main, ctgy=tm_source, path=main) accepting String of type scalarwebavcontroltermstatussource
2020-12-16 12:52:23.181 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_uri-main (cid=main, ctgy=tm_uri, path=main) accepting String of type scalarwebavcontroltermstatusuri
2020-12-16 12:52:23.182 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_title-main (cid=main, ctgy=tm_title, path=main) accepting String of type scalarwebavcontroltermstatustitle
2020-12-16 12:52:23.185 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_connection-main (cid=main, ctgy=tm_connection, path=main) accepting String of type scalarwebavcontroltermstatusconnection
2020-12-16 12:52:23.186 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_label-main (cid=main, ctgy=tm_label, path=main) accepting String of type scalarwebavcontroltermstatuslabel
2020-12-16 12:52:23.189 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#tm_icon-main (cid=main, ctgy=tm_icon, path=main) accepting Image of type scalarwebavcontroltermstatusicon
2020-12-16 12:52:23.190 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_cmd-main (cid=main, ctgy=pl_cmd, path=main) accepting String of type scalarwebavcontrolplcommand
2020-12-16 12:52:23.192 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_presetid-main (cid=main, ctgy=pl_presetid, path=main) accepting Number of type scalarwebavcontrolplpreset
2020-12-16 12:52:23.194 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_bivlassetid-main (cid=main, ctgy=pl_bivlassetid, path=main) accepting String of type scalarwebavcontrolplbivlassetid
2020-12-16 12:52:23.196 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_bivlprovider-main (cid=main, ctgy=pl_bivlprovider, path=main) accepting String of type scalarwebavcontrolplbivlprovider
2020-12-16 12:52:23.198 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_bivlserviceid-main (cid=main, ctgy=pl_bivlserviceid, path=main) accepting String of type scalarwebavcontrolplbivlserviceid
2020-12-16 12:52:23.201 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_dispnum-main (cid=main, ctgy=pl_dispnum, path=main) accepting String of type scalarwebavcontrolpldispnum
2020-12-16 12:52:23.202 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_durationsec-main (cid=main, ctgy=pl_durationsec, path=main) accepting Number:Time of type scalarwebavcontrolpldurationsec
2020-12-16 12:52:23.205 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_mediatype-main (cid=main, ctgy=pl_mediatype, path=main) accepting String of type scalarwebavcontrolplmediatype
2020-12-16 12:52:23.207 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_originaldispnum-main (cid=main, ctgy=pl_originaldispnum, path=main) accepting String of type scalarwebavcontrolploriginaldispnum
2020-12-16 12:52:23.210 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_playspeed-main (cid=main, ctgy=pl_playspeed, path=main) accepting String of type scalarwebavcontrolplplayspeed
2020-12-16 12:52:23.212 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_programnum-main (cid=main, ctgy=pl_programnum, path=main) accepting Number of type scalarwebavcontrolplprogramnum
2020-12-16 12:52:23.214 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_programtitle-main (cid=main, ctgy=pl_programtitle, path=main) accepting String of type scalarwebavcontrolplprogramtitle
2020-12-16 12:52:23.216 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_source-main (cid=main, ctgy=pl_source, path=main) accepting String of type scalarwebavcontrolplsource
2020-12-16 12:52:23.218 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_startdatetime-main (cid=main, ctgy=pl_startdatetime, path=main) accepting String of type scalarwebavcontrolplstartdatetime
2020-12-16 12:52:23.220 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_title-main (cid=main, ctgy=pl_title, path=main) accepting String of type scalarwebavcontrolpltitle
2020-12-16 12:52:23.222 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_tripletstr-main (cid=main, ctgy=pl_tripletstr, path=main) accepting String of type scalarwebavcontrolpltripletstr
2020-12-16 12:52:23.224 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_uri-main (cid=main, ctgy=pl_uri, path=main) accepting String of type scalarwebavcontrolpluri
2020-12-16 12:52:23.226 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_albumname-main (cid=main, ctgy=pl_albumname, path=main) accepting String of type scalarwebavcontrolplalbumname
2020-12-16 12:52:23.228 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_applicationname-main (cid=main, ctgy=pl_applicationname, path=main) accepting String of type scalarwebavcontrolplapplicationname
2020-12-16 12:52:23.230 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_artist-main (cid=main, ctgy=pl_artist, path=main) accepting String of type scalarwebavcontrolplartist
2020-12-16 12:52:23.232 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_audiochannel-main (cid=main, ctgy=pl_audiochannel, path=main) accepting String of type scalarwebavcontrolplaudiochannel
2020-12-16 12:52:23.234 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_audiocodec-main (cid=main, ctgy=pl_audiocodec, path=main) accepting String of type scalarwebavcontrolplaudiocodec
2020-12-16 12:52:23.235 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_audiofrequency-main (cid=main, ctgy=pl_audiofrequency, path=main) accepting String of type scalarwebavcontrolplaudiofrequency
2020-12-16 12:52:23.238 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_broadcastfreq-main (cid=main, ctgy=pl_broadcastfreq, path=main) accepting Number:Frequency of type scalarwebavcontrolplbroadcastfreq
2020-12-16 12:52:23.239 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_broadcastfreqband-main (cid=main, ctgy=pl_broadcastfreqband, path=main) accepting String of type scalarwebavcontrolplbroadcastfreqband
2020-12-16 12:52:23.242 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_channelname-main (cid=main, ctgy=pl_channelname, path=main) accepting String of type scalarwebavcontrolplchannelname
2020-12-16 12:52:23.244 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_chaptercount-main (cid=main, ctgy=pl_chaptercount, path=main) accepting Number of type scalarwebavcontrolplchaptercount
2020-12-16 12:52:23.246 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_chapterindex-main (cid=main, ctgy=pl_chapterindex, path=main) accepting Number of type scalarwebavcontrolplchapterindex
2020-12-16 12:52:23.248 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_contentkind-main (cid=main, ctgy=pl_contentkind, path=main) accepting String of type scalarwebavcontrolplcontentkind
2020-12-16 12:52:23.251 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_dabcomponentlabel-main (cid=main, ctgy=pl_dabcomponentlabel, path=main) accepting String of type scalarwebavcontrolpldabcomponentlabel
2020-12-16 12:52:23.253 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_dabdynamiclabel-main (cid=main, ctgy=pl_dabdynamiclabel, path=main) accepting String of type scalarwebavcontrolpldabdynamiclabel
2020-12-16 12:52:23.255 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_dabensemblelabel-main (cid=main, ctgy=pl_dabensemblelabel, path=main) accepting String of type scalarwebavcontrolpldabensemblelabel
2020-12-16 12:52:23.257 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_dabservicelabel-main (cid=main, ctgy=pl_dabservicelabel, path=main) accepting String of type scalarwebavcontrolpldabservicelabel
2020-12-16 12:52:23.259 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_durationmsec-main (cid=main, ctgy=pl_durationmsec, path=main) accepting Number:Time of type scalarwebavcontrolpldurationmsec
2020-12-16 12:52:23.260 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_fileno-main (cid=main, ctgy=pl_fileno, path=main) accepting String of type scalarwebavcontrolplfileno
2020-12-16 12:52:23.263 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_genre-main (cid=main, ctgy=pl_genre, path=main) accepting String of type scalarwebavcontrolplgenre
2020-12-16 12:52:23.264 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_index-main (cid=main, ctgy=pl_index, path=main) accepting Number of type scalarwebavcontrolplindex
2020-12-16 12:52:23.267 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_is3d-main (cid=main, ctgy=pl_is3d, path=main) accepting String of type scalarwebavcontrolplis3d
2020-12-16 12:52:23.269 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_output-main (cid=main, ctgy=pl_output, path=main) accepting String of type scalarwebavcontrolploutput
2020-12-16 12:52:23.271 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_parentindex-main (cid=main, ctgy=pl_parentindex, path=main) accepting Number of type scalarwebavcontrolplparentindex
2020-12-16 12:52:23.272 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_parenturi-main (cid=main, ctgy=pl_parenturi, path=main) accepting String of type scalarwebavcontrolplparenturi
2020-12-16 12:52:23.275 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_path-main (cid=main, ctgy=pl_path, path=main) accepting String of type scalarwebavcontrolplpath
2020-12-16 12:52:23.276 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_playlistname-main (cid=main, ctgy=pl_playlistname, path=main) accepting String of type scalarwebavcontrolplplaylistname
2020-12-16 12:52:23.279 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_playstepspeed-main (cid=main, ctgy=pl_playstepspeed, path=main) accepting Number of type scalarwebavcontrolplplaystepspeed
2020-12-16 12:52:23.281 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_podcastname-main (cid=main, ctgy=pl_podcastname, path=main) accepting String of type scalarwebavcontrolplpodcastname
2020-12-16 12:52:23.283 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_positionmsec-main (cid=main, ctgy=pl_positionmsec, path=main) accepting Number:Time of type scalarwebavcontrolplpositionmsec
2020-12-16 12:52:23.285 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_positionsec-main (cid=main, ctgy=pl_positionsec, path=main) accepting Number:Time of type scalarwebavcontrolplpositionsec
2020-12-16 12:52:23.287 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_repeattype-main (cid=main, ctgy=pl_repeattype, path=main) accepting String of type scalarwebavcontrolplrepeattype
2020-12-16 12:52:23.289 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_service-main (cid=main, ctgy=pl_service, path=main) accepting String of type scalarwebavcontrolplservice
2020-12-16 12:52:23.291 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_sourcelabel-main (cid=main, ctgy=pl_sourcelabel, path=main) accepting String of type scalarwebavcontrolplsourcelabel
2020-12-16 12:52:23.293 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_state-main (cid=main, ctgy=pl_state, path=main) accepting String of type scalarwebavcontrolplstate
2020-12-16 12:52:23.295 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_statesupplement-main (cid=main, ctgy=pl_statesupplement, path=main) accepting String of type scalarwebavcontrolplstatesupplement
2020-12-16 12:52:23.296 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_subtitleindex-main (cid=main, ctgy=pl_subtitleindex, path=main) accepting Number of type scalarwebavcontrolplsubtitleindex
2020-12-16 12:52:23.299 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_totalcount-main (cid=main, ctgy=pl_totalcount, path=main) accepting Number of type scalarwebavcontrolpltotalcount
2020-12-16 12:52:23.300 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#pl_videocodec-main (cid=main, ctgy=pl_videocodec, path=main) accepting String of type scalarwebavcontrolplvideocodec
2020-12-16 12:52:23.303 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#playbackmode-repeattype-storageusb1 (cid=repeattype-storageusb1, ctgy=playbackmode, path=repeatType,storage:usb1) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.304 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#playbackmode-shuffletype-storageusb1 (cid=shuffletype-storageusb1, ctgy=playbackmode, path=shuffleType,storage:usb1) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.306 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#playbackmode-repeattype-storagecd (cid=repeattype-storagecd, ctgy=playbackmode, path=repeatType,storage:cd) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.308 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: avContent#playbackmode-shuffletype-storagecd (cid=shuffletype-storagecd, ctgy=playbackmode, path=shuffleType,storage:cd) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.310 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#language (cid=language, ctgy=language, path=) accepting String of type scalarsystemlanguage
2020-12-16 12:52:23.312 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#powerstatus (cid=powerstatus, ctgy=powerstatus, path=) accepting Switch of type scalarsystempowerstatus
2020-12-16 12:52:23.315 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#sysCmd (cid=sysCmd, ctgy=sysCmd, path=) accepting String of type scalarsystemircc
2020-12-16 12:52:23.318 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#devicemiscsettings-devicename (cid=devicename, ctgy=devicemiscsettings, path=deviceName) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.322 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#devicemiscsettings-swautoupdate (cid=swautoupdate, ctgy=devicemiscsettings, path=swAutoUpdate) accepting Switch of type scalargeneralsettingswitch
2020-12-16 12:52:23.325 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#devicemiscsettings-gracenote (cid=gracenote, ctgy=devicemiscsettings, path=gracenote) accepting String of type scalargeneralsettingstring
2020-12-16 12:52:23.329 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#powersettings-quickstartmode (cid=quickstartmode, ctgy=powersettings, path=quickStartMode) accepting Switch of type scalargeneralsettingswitch
2020-12-16 12:52:23.332 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#powersettings-wolmode (cid=wolmode, ctgy=powersettings, path=wolMode) accepting Switch of type scalargeneralsettingswitch
2020-12-16 12:52:23.336 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_deviceName-usb1 (cid=usb1, ctgy=st_deviceName, path=) accepting String of type scalarsystemstoragedevicename
2020-12-16 12:52:23.342 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_error-usb1 (cid=usb1, ctgy=st_error, path=) accepting String of type scalarsystemstorageerror
2020-12-16 12:52:23.345 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_fileSystem-usb1 (cid=usb1, ctgy=st_fileSystem, path=) accepting String of type scalarsystemstoragefilesystem
2020-12-16 12:52:23.348 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_finalizeStatus-usb1 (cid=usb1, ctgy=st_finalizeStatus, path=) accepting String of type scalarsystemstoragefinalizestatus
2020-12-16 12:52:23.356 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_format-usb1 (cid=usb1, ctgy=st_format, path=) accepting String of type scalarsystemstorageformat
2020-12-16 12:52:23.358 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formatStatus-usb1 (cid=usb1, ctgy=st_formatStatus, path=) accepting String of type scalarsystemstorageformatstatus
2020-12-16 12:52:23.362 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formattable-usb1 (cid=usb1, ctgy=st_formattable, path=) accepting String of type scalarsystemstorageformattable
2020-12-16 12:52:23.365 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_freeCapacityMB-usb1 (cid=usb1, ctgy=st_freeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragefreecapacitymb
2020-12-16 12:52:23.369 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasNonStandardData-usb1 (cid=usb1, ctgy=st_hasNonStandardData, path=) accepting String of type scalarsystemstoragehasnonstandarddata
2020-12-16 12:52:23.373 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasUnsupportedContents-usb1 (cid=usb1, ctgy=st_hasUnsupportedContents, path=) accepting String of type scalarsystemstoragehasunsupportedcontents
2020-12-16 12:52:23.377 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isAvailable-usb1 (cid=usb1, ctgy=st_isAvailable, path=) accepting String of type scalarsystemstorageisavailable
2020-12-16 12:52:23.379 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isLocked-usb1 (cid=usb1, ctgy=st_isLocked, path=) accepting String of type scalarsystemstorageislocked
2020-12-16 12:52:23.383 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isManagementInfoFull-usb1 (cid=usb1, ctgy=st_isManagementInfoFull, path=) accepting String of type scalarsystemstorageismanagementinfofull
2020-12-16 12:52:23.386 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isProtected-usb1 (cid=usb1, ctgy=st_isProtected, path=) accepting String of type scalarsystemstorageisprotected
2020-12-16 12:52:23.390 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isRegistered-usb1 (cid=usb1, ctgy=st_isRegistered, path=) accepting String of type scalarsystemstorageisregistered
2020-12-16 12:52:23.394 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSelfRecorded-usb1 (cid=usb1, ctgy=st_isSelfRecorded, path=) accepting String of type scalarsystemstorageisselfrecorded
2020-12-16 12:52:23.397 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSqvSupported-usb1 (cid=usb1, ctgy=st_isSqvSupported, path=) accepting String of type scalarsystemstorageissqvsupported
2020-12-16 12:52:23.400 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_lun-usb1 (cid=usb1, ctgy=st_lun, path=) accepting Number of type scalarsystemstoragelun
2020-12-16 12:52:23.404 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_mounted-usb1 (cid=usb1, ctgy=st_mounted, path=) accepting String of type scalarsystemstoragemounted
2020-12-16 12:52:23.408 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_permission-usb1 (cid=usb1, ctgy=st_permission, path=) accepting String of type scalarsystemstoragepermission
2020-12-16 12:52:23.413 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_position-usb1 (cid=usb1, ctgy=st_position, path=) accepting String of type scalarsystemstorageposition
2020-12-16 12:52:23.417 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_protocol-usb1 (cid=usb1, ctgy=st_protocol, path=) accepting String of type scalarsystemstorageprotocol
2020-12-16 12:52:23.419 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_registrationDate-usb1 (cid=usb1, ctgy=st_registrationDate, path=) accepting String of type scalarsystemstorageregistrationdate
2020-12-16 12:52:23.420 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_systemAreaCapacityMB-usb1 (cid=usb1, ctgy=st_systemAreaCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragesystemareacapacitymb
2020-12-16 12:52:23.422 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToFinalize-usb1 (cid=usb1, ctgy=st_timeSecToFinalize, path=) accepting Number:Time of type scalarsystemstoragetimesectofinalize
2020-12-16 12:52:23.424 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToGetContents-usb1 (cid=usb1, ctgy=st_timeSecToGetContents, path=) accepting Number:Time of type scalarsystemstoragetimesectogetcontents
2020-12-16 12:52:23.426 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_type-usb1 (cid=usb1, ctgy=st_type, path=) accepting String of type scalarsystemstoragetype
2020-12-16 12:52:23.428 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_uri-usb1 (cid=usb1, ctgy=st_uri, path=) accepting String of type scalarsystemstorageuri
2020-12-16 12:52:23.430 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_usbDeviceType-usb1 (cid=usb1, ctgy=st_usbDeviceType, path=) accepting String of type scalarsystemstorageusbdevicetype
2020-12-16 12:52:23.431 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_volumeLabel-usb1 (cid=usb1, ctgy=st_volumeLabel, path=) accepting String of type scalarsystemstoragevolumelabel
2020-12-16 12:52:23.434 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_wholeCapacityMB-usb1 (cid=usb1, ctgy=st_wholeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragewholecapacitymb
2020-12-16 12:52:23.436 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_deviceName-usb2 (cid=usb2, ctgy=st_deviceName, path=) accepting String of type scalarsystemstoragedevicename
2020-12-16 12:52:23.437 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_error-usb2 (cid=usb2, ctgy=st_error, path=) accepting String of type scalarsystemstorageerror
2020-12-16 12:52:23.439 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_fileSystem-usb2 (cid=usb2, ctgy=st_fileSystem, path=) accepting String of type scalarsystemstoragefilesystem
2020-12-16 12:52:23.441 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_finalizeStatus-usb2 (cid=usb2, ctgy=st_finalizeStatus, path=) accepting String of type scalarsystemstoragefinalizestatus
2020-12-16 12:52:23.442 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_format-usb2 (cid=usb2, ctgy=st_format, path=) accepting String of type scalarsystemstorageformat
2020-12-16 12:52:23.444 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formatStatus-usb2 (cid=usb2, ctgy=st_formatStatus, path=) accepting String of type scalarsystemstorageformatstatus
2020-12-16 12:52:23.446 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formattable-usb2 (cid=usb2, ctgy=st_formattable, path=) accepting String of type scalarsystemstorageformattable
2020-12-16 12:52:23.447 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_freeCapacityMB-usb2 (cid=usb2, ctgy=st_freeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragefreecapacitymb
2020-12-16 12:52:23.449 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasNonStandardData-usb2 (cid=usb2, ctgy=st_hasNonStandardData, path=) accepting String of type scalarsystemstoragehasnonstandarddata
2020-12-16 12:52:23.451 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasUnsupportedContents-usb2 (cid=usb2, ctgy=st_hasUnsupportedContents, path=) accepting String of type scalarsystemstoragehasunsupportedcontents
2020-12-16 12:52:23.453 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isAvailable-usb2 (cid=usb2, ctgy=st_isAvailable, path=) accepting String of type scalarsystemstorageisavailable
2020-12-16 12:52:23.454 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isLocked-usb2 (cid=usb2, ctgy=st_isLocked, path=) accepting String of type scalarsystemstorageislocked
2020-12-16 12:52:23.457 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isManagementInfoFull-usb2 (cid=usb2, ctgy=st_isManagementInfoFull, path=) accepting String of type scalarsystemstorageismanagementinfofull
2020-12-16 12:52:23.459 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isProtected-usb2 (cid=usb2, ctgy=st_isProtected, path=) accepting String of type scalarsystemstorageisprotected
2020-12-16 12:52:23.461 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isRegistered-usb2 (cid=usb2, ctgy=st_isRegistered, path=) accepting String of type scalarsystemstorageisregistered
2020-12-16 12:52:23.463 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSelfRecorded-usb2 (cid=usb2, ctgy=st_isSelfRecorded, path=) accepting String of type scalarsystemstorageisselfrecorded
2020-12-16 12:52:23.467 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSqvSupported-usb2 (cid=usb2, ctgy=st_isSqvSupported, path=) accepting String of type scalarsystemstorageissqvsupported
2020-12-16 12:52:23.469 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_lun-usb2 (cid=usb2, ctgy=st_lun, path=) accepting Number of type scalarsystemstoragelun
2020-12-16 12:52:23.471 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_mounted-usb2 (cid=usb2, ctgy=st_mounted, path=) accepting String of type scalarsystemstoragemounted
2020-12-16 12:52:23.472 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_permission-usb2 (cid=usb2, ctgy=st_permission, path=) accepting String of type scalarsystemstoragepermission
2020-12-16 12:52:23.474 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_position-usb2 (cid=usb2, ctgy=st_position, path=) accepting String of type scalarsystemstorageposition
2020-12-16 12:52:23.475 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_protocol-usb2 (cid=usb2, ctgy=st_protocol, path=) accepting String of type scalarsystemstorageprotocol
2020-12-16 12:52:23.477 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_registrationDate-usb2 (cid=usb2, ctgy=st_registrationDate, path=) accepting String of type scalarsystemstorageregistrationdate
2020-12-16 12:52:23.480 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_systemAreaCapacityMB-usb2 (cid=usb2, ctgy=st_systemAreaCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragesystemareacapacitymb
2020-12-16 12:52:23.483 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToFinalize-usb2 (cid=usb2, ctgy=st_timeSecToFinalize, path=) accepting Number:Time of type scalarsystemstoragetimesectofinalize
2020-12-16 12:52:23.485 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToGetContents-usb2 (cid=usb2, ctgy=st_timeSecToGetContents, path=) accepting Number:Time of type scalarsystemstoragetimesectogetcontents
2020-12-16 12:52:23.487 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_type-usb2 (cid=usb2, ctgy=st_type, path=) accepting String of type scalarsystemstoragetype
2020-12-16 12:52:23.489 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_uri-usb2 (cid=usb2, ctgy=st_uri, path=) accepting String of type scalarsystemstorageuri
2020-12-16 12:52:23.493 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_usbDeviceType-usb2 (cid=usb2, ctgy=st_usbDeviceType, path=) accepting String of type scalarsystemstorageusbdevicetype
2020-12-16 12:52:23.495 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_volumeLabel-usb2 (cid=usb2, ctgy=st_volumeLabel, path=) accepting String of type scalarsystemstoragevolumelabel
2020-12-16 12:52:23.497 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_wholeCapacityMB-usb2 (cid=usb2, ctgy=st_wholeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragewholecapacitymb
2020-12-16 12:52:23.499 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_deviceName-cd (cid=cd, ctgy=st_deviceName, path=) accepting String of type scalarsystemstoragedevicename
2020-12-16 12:52:23.501 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_error-cd (cid=cd, ctgy=st_error, path=) accepting String of type scalarsystemstorageerror
2020-12-16 12:52:23.503 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_fileSystem-cd (cid=cd, ctgy=st_fileSystem, path=) accepting String of type scalarsystemstoragefilesystem
2020-12-16 12:52:23.505 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_finalizeStatus-cd (cid=cd, ctgy=st_finalizeStatus, path=) accepting String of type scalarsystemstoragefinalizestatus
2020-12-16 12:52:23.507 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_format-cd (cid=cd, ctgy=st_format, path=) accepting String of type scalarsystemstorageformat
2020-12-16 12:52:23.508 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formatStatus-cd (cid=cd, ctgy=st_formatStatus, path=) accepting String of type scalarsystemstorageformatstatus
2020-12-16 12:52:23.510 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_formattable-cd (cid=cd, ctgy=st_formattable, path=) accepting String of type scalarsystemstorageformattable
2020-12-16 12:52:23.512 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_freeCapacityMB-cd (cid=cd, ctgy=st_freeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragefreecapacitymb
2020-12-16 12:52:23.514 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasNonStandardData-cd (cid=cd, ctgy=st_hasNonStandardData, path=) accepting String of type scalarsystemstoragehasnonstandarddata
2020-12-16 12:52:23.516 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_hasUnsupportedContents-cd (cid=cd, ctgy=st_hasUnsupportedContents, path=) accepting String of type scalarsystemstoragehasunsupportedcontents
2020-12-16 12:52:23.518 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isAvailable-cd (cid=cd, ctgy=st_isAvailable, path=) accepting String of type scalarsystemstorageisavailable
2020-12-16 12:52:23.520 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isLocked-cd (cid=cd, ctgy=st_isLocked, path=) accepting String of type scalarsystemstorageislocked
2020-12-16 12:52:23.522 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isManagementInfoFull-cd (cid=cd, ctgy=st_isManagementInfoFull, path=) accepting String of type scalarsystemstorageismanagementinfofull
2020-12-16 12:52:23.523 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isProtected-cd (cid=cd, ctgy=st_isProtected, path=) accepting String of type scalarsystemstorageisprotected
2020-12-16 12:52:23.525 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isRegistered-cd (cid=cd, ctgy=st_isRegistered, path=) accepting String of type scalarsystemstorageisregistered
2020-12-16 12:52:23.527 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSelfRecorded-cd (cid=cd, ctgy=st_isSelfRecorded, path=) accepting String of type scalarsystemstorageisselfrecorded
2020-12-16 12:52:23.529 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_isSqvSupported-cd (cid=cd, ctgy=st_isSqvSupported, path=) accepting String of type scalarsystemstorageissqvsupported
2020-12-16 12:52:23.531 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_lun-cd (cid=cd, ctgy=st_lun, path=) accepting Number of type scalarsystemstoragelun
2020-12-16 12:52:23.533 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_mounted-cd (cid=cd, ctgy=st_mounted, path=) accepting String of type scalarsystemstoragemounted
2020-12-16 12:52:23.535 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_permission-cd (cid=cd, ctgy=st_permission, path=) accepting String of type scalarsystemstoragepermission
2020-12-16 12:52:23.537 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_position-cd (cid=cd, ctgy=st_position, path=) accepting String of type scalarsystemstorageposition
2020-12-16 12:52:23.539 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_protocol-cd (cid=cd, ctgy=st_protocol, path=) accepting String of type scalarsystemstorageprotocol
2020-12-16 12:52:23.541 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_registrationDate-cd (cid=cd, ctgy=st_registrationDate, path=) accepting String of type scalarsystemstorageregistrationdate
2020-12-16 12:52:23.543 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_systemAreaCapacityMB-cd (cid=cd, ctgy=st_systemAreaCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragesystemareacapacitymb
2020-12-16 12:52:23.545 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToFinalize-cd (cid=cd, ctgy=st_timeSecToFinalize, path=) accepting Number:Time of type scalarsystemstoragetimesectofinalize
2020-12-16 12:52:23.546 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_timeSecToGetContents-cd (cid=cd, ctgy=st_timeSecToGetContents, path=) accepting Number:Time of type scalarsystemstoragetimesectogetcontents
2020-12-16 12:52:23.549 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_type-cd (cid=cd, ctgy=st_type, path=) accepting String of type scalarsystemstoragetype
2020-12-16 12:52:23.550 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_uri-cd (cid=cd, ctgy=st_uri, path=) accepting String of type scalarsystemstorageuri
2020-12-16 12:52:23.553 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_usbDeviceType-cd (cid=cd, ctgy=st_usbDeviceType, path=) accepting String of type scalarsystemstorageusbdevicetype
2020-12-16 12:52:23.555 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_volumeLabel-cd (cid=cd, ctgy=st_volumeLabel, path=) accepting String of type scalarsystemstoragevolumelabel
2020-12-16 12:52:23.557 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Creating channel: system#st_wholeCapacityMB-cd (cid=cd, ctgy=st_wholeCapacityMB, path=) accepting Number:DataAmount of type scalarsystemstoragewholecapacitymb
2020-12-16 12:52:23.696 [DEBUG] [nternal.transports.SonyHttpTransport] - Closing http client
2020-12-16 12:52:23.758 [DEBUG] [g.sony.internal.AbstractThingHandler] - Starting state polling every 30 seconds
2020-12-16 12:52:23.760 [DEBUG] [g.sony.internal.AbstractThingHandler] - Executing any cached commands
2020-12-16 12:52:23.764 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:52:23.766 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:52:23.768 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a1f3ec
2020-12-16 12:52:23.769 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Writing thing definition: BDP-S6700
2020-12-16 12:52:23.771 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@e4b156
2020-12-16 12:52:23.782 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136129,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:23.848 [DEBUG] [l.providers.sources.SonyFolderSource] - File for thing definition already exists (write ignored): /var/lib/openhab2/sony/definitions/types/BDP-S6700.json
2020-12-16 12:52:24.078 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136129,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:52:24.081 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136129,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:52:24.084 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136130,"method":"getSourceList","version":"1.1","params":[{"scheme":"dlna"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.104 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136130,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]})
2020-12-16 12:52:24.106 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136130,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]}
2020-12-16 12:52:24.108 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136131,"method":"getSourceList","version":"1.1","params":[{"scheme":"storage"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.120 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136131,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]})
2020-12-16 12:52:24.124 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136131,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]}
2020-12-16 12:52:24.163 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136132,"method":"getPlayingContentInfo","version":"1.2","params":[{"output":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.277 [TRACE] [l.providers.sources.SonyGithubSource] - Metainfo was not modified - returning last version from etag "0e74a0f3c0e5392c0af460445e0db7f54d01943c"
2020-12-16 12:52:24.280 [DEBUG] [l.providers.sources.SonyGithubSource] - Ignoring write thing definition - processing is disabled: BDP-S6700
2020-12-16 12:52:24.282 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136133,"method":"getVersions","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:24.412 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136132,"result":[[{"contentKind":"","parentUri":"","source":"extInput:others","stateInfo":{"state":"STOPPED","supplement":""},"uri":"extInput:others"}]]})
2020-12-16 12:52:24.414 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136132,"result":[[{"contentKind":"","parentUri":"","source":"extInput:others","stateInfo":{"state":"STOPPED","supplement":""},"uri":"extInput:others"}]]}
2020-12-16 12:52:24.414 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136133,"result":[["1.0","1.1","1.2","1.3"]]})
2020-12-16 12:52:24.416 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136133,"result":[["1.0","1.1","1.2","1.3"]]}
2020-12-16 12:52:24.418 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136134,"method":"getMethodTypes","version":"1.0","params":["1.0"]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:24.440 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136135,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.471 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136135,"result":[[]]})
2020-12-16 12:52:24.474 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136135,"result":[[]]}
2020-12-16 12:52:24.476 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136134,"results":[["getDeviceMiscSettings",["{\"target\":\"string\"}"],["{\"target\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"Boolean\", \"candidate\":\"GeneralSettingsCandidate[]\"}*"],"1.0"],["getInterfaceInformation",[],["{\"productCategory\":\"string\", \"productName\":\"string\", \"modelName\":\"string\", \"serverName\":\"string\", \"interfaceVersion\":\"string\"}"],"1.0"],["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getPowerSettings",["{\"target\":\"string\"}"],["{\"target\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"Boolean\", \"candidate\":\"GeneralSettingsCandidate[]\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"],["setClientInfo",["{\"target\":\"string\", \"value\":\"string\"}*"],[],"1.0"],["setDeviceMiscSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["setPowerSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]})
2020-12-16 12:52:24.479 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136134,"results":[["getDeviceMiscSettings",["{\"target\":\"string\"}"],["{\"target\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"Boolean\", \"candidate\":\"GeneralSettingsCandidate[]\"}*"],"1.0"],["getInterfaceInformation",[],["{\"productCategory\":\"string\", \"productName\":\"string\", \"modelName\":\"string\", \"serverName\":\"string\", \"interfaceVersion\":\"string\"}"],"1.0"],["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getPowerSettings",["{\"target\":\"string\"}"],["{\"target\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"Boolean\", \"candidate\":\"GeneralSettingsCandidate[]\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"],["setClientInfo",["{\"target\":\"string\", \"value\":\"string\"}*"],[],"1.0"],["setDeviceMiscSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["setPowerSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]}
2020-12-16 12:52:24.483 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136136,"method":"getMethodTypes","version":"1.0","params":["1.1"]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:24.497 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136136,"results":[["getPowerStatus",[],["{\"status\":\"string\", \"standbyDetail\":\"string\"}"],"1.1"],["getSettingsTree",["{\"usage\":\"string\"}"],["{\"settings\":\"SettingsTreeList[]\"}"],"1.1"],["getStorageList",["{\"uri\":\"string\"}"],["{\"uri\":\"string\", \"deviceName\":\"string\", \"volumeLabel\":\"string\", \"permission\":\"string\", \"position\":\"string\", \"formattable\":\"string\", \"mounted\":\"string\", \"wholeCapacityMB\":\"int\", \"freeCapacityMB\":\"int\", \"systemAreaCapacityMB\":\"int\", \"formatting\":\"string\", \"isAvailable\":\"string\", \"lun\":\"int\", \"type\":\"string\", \"format\":\"string\", \"error\":\"string\"}*"],"1.1"],["setPowerStatus",["{\"status\":\"string\", \"standbyDetail\":\"string\"}"],[],"1.1"]]})
2020-12-16 12:52:24.496 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@cca637
2020-12-16 12:52:24.496 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136136,"results":[["getPowerStatus",[],["{\"status\":\"string\", \"standbyDetail\":\"string\"}"],"1.1"],["getSettingsTree",["{\"usage\":\"string\"}"],["{\"settings\":\"SettingsTreeList[]\"}"],"1.1"],["getStorageList",["{\"uri\":\"string\"}"],["{\"uri\":\"string\", \"deviceName\":\"string\", \"volumeLabel\":\"string\", \"permission\":\"string\", \"position\":\"string\", \"formattable\":\"string\", \"mounted\":\"string\", \"wholeCapacityMB\":\"int\", \"freeCapacityMB\":\"int\", \"systemAreaCapacityMB\":\"int\", \"formatting\":\"string\", \"isAvailable\":\"string\", \"lun\":\"int\", \"type\":\"string\", \"format\":\"string\", \"error\":\"string\"}*"],"1.1"],["setPowerStatus",["{\"status\":\"string\", \"standbyDetail\":\"string\"}"],[],"1.1"]]}
2020-12-16 12:52:24.505 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136137,"method":"getMethodTypes","version":"1.0","params":["1.2"]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:24.505 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@1918b0d
2020-12-16 12:52:24.516 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136137,"results":[["getStorageList",["{\"uri\":\"string\", \"isRegistered\":\"string\"}"],["{\"uri\":\"string\", \"deviceName\":\"string\", \"volumeLabel\":\"string\", \"permission\":\"string\", \"position\":\"string\", \"formattable\":\"string\", \"mounted\":\"string\", \"wholeCapacityMB\":\"int\", \"freeCapacityMB\":\"int\", \"systemAreaCapacityMB\":\"int\", \"isAvailable\":\"string\", \"lun\":\"int\", \"type\":\"string\", \"protocol\":\"string\", \"format\":\"string\", \"error\":\"string\", \"isRegistered\":\"string\", \"registrationDate\":\"string\", \"isSqvSupported\":\"string\", \"hasNonStandardData\":\"string\", \"isProtected\":\"string\", \"isLocked\":\"string\", \"formatStatus\":\"string\", \"finalizeStatus\":\"string\", \"timeSecToFinalize\":\"int\", \"isSelfRecorded\":\"string\", \"isManagementInfoFull\":\"string\", \"timeSecToGetContents\":\"int\", \"hasUnsupportedContents\":\"string\", \"usbDeviceType\":\"string\", \"fileSystem\":\"string\"}*"],"1.2"]]})
2020-12-16 12:52:24.518 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136137,"results":[["getStorageList",["{\"uri\":\"string\", \"isRegistered\":\"string\"}"],["{\"uri\":\"string\", \"deviceName\":\"string\", \"volumeLabel\":\"string\", \"permission\":\"string\", \"position\":\"string\", \"formattable\":\"string\", \"mounted\":\"string\", \"wholeCapacityMB\":\"int\", \"freeCapacityMB\":\"int\", \"systemAreaCapacityMB\":\"int\", \"isAvailable\":\"string\", \"lun\":\"int\", \"type\":\"string\", \"protocol\":\"string\", \"format\":\"string\", \"error\":\"string\", \"isRegistered\":\"string\", \"registrationDate\":\"string\", \"isSqvSupported\":\"string\", \"hasNonStandardData\":\"string\", \"isProtected\":\"string\", \"isLocked\":\"string\", \"formatStatus\":\"string\", \"finalizeStatus\":\"string\", \"timeSecToFinalize\":\"int\", \"isSelfRecorded\":\"string\", \"isManagementInfoFull\":\"string\", \"timeSecToGetContents\":\"int\", \"hasUnsupportedContents\":\"string\", \"usbDeviceType\":\"string\", \"fileSystem\":\"string\"}*"],"1.2"]]}
2020-12-16 12:52:24.522 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136138,"method":"getMethodTypes","version":"1.0","params":["1.3"]} to ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:24.534 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136138,"results":[["getSystemInformation",[],["{\"product\":\"string\", \"region\":\"string\", \"language\":\"string\", \"model\":\"string\", \"serial\":\"string\", \"macAddr\":\"string\", \"name\":\"string\", \"generation\":\"string\", \"area\":\"string\", \"cid\":\"string\", \"helpUrl\":\"string\", \"deviceID\":\"string\", \"version\":\"string\", \"duid\":\"string\", \"updatableVersion\":\"string\", \"wirelessMacAddr\":\"string\", \"esn\":\"string\", \"iconUrl\":\"string\", \"ssid\":\"string\", \"bdAddr\":\"string\"}"],"1.3"]]})
2020-12-16 12:52:24.537 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136138,"results":[["getSystemInformation",[],["{\"product\":\"string\", \"region\":\"string\", \"language\":\"string\", \"model\":\"string\", \"serial\":\"string\", \"macAddr\":\"string\", \"name\":\"string\", \"generation\":\"string\", \"area\":\"string\", \"cid\":\"string\", \"helpUrl\":\"string\", \"deviceID\":\"string\", \"version\":\"string\", \"duid\":\"string\", \"updatableVersion\":\"string\", \"wirelessMacAddr\":\"string\", \"esn\":\"string\", \"iconUrl\":\"string\", \"ssid\":\"string\", \"bdAddr\":\"string\"}"],"1.3"]]}
2020-12-16 12:52:24.542 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136139,"method":"getVersions","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:24.566 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136139,"result":[["1.0"]]})
2020-12-16 12:52:24.568 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136139,"result":[["1.0"]]}
2020-12-16 12:52:24.571 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136140,"method":"getMethodTypes","version":"1.0","params":["1.0"]} to ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:24.582 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136140,"results":[["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getVersions",[],["string*"],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]})
2020-12-16 12:52:24.585 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136140,"results":[["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getVersions",[],["string*"],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]}
2020-12-16 12:52:24.589 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136141,"method":"getVersions","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.599 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136141,"result":[["1.0","1.1","1.2","1.3","1.4"]]})
2020-12-16 12:52:24.601 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136141,"result":[["1.0","1.1","1.2","1.3","1.4"]]}
2020-12-16 12:52:24.603 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136142,"method":"getMethodTypes","version":"1.0","params":["1.0"]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.619 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136142,"results":[["getAvailablePlaybackFunction",["{\"output\":\"string\"}"],["{\"functions\":\"FunctionInfo[]\", \"output\":\"string\", \"uri\":\"string\"}*"],"1.0"],["getCurrentExternalTerminalsStatus",[],["{\"uri\":\"string\", \"title\":\"string\", \"connection\":\"string\", \"active\":\"string\", \"label\":\"string\", \"outputs\":\"string*\", \"meta\":\"string\", \"iconUrl\":\"string\"}*"],"1.0"],["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getPlaybackModeSettings",["{\"target\":\"string\", \"uri\":\"string\"}"],["{\"target\":\"string\", \"uri\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"bool\", \"candidate\":\"PlaybackModeSettingsCandidate[]\"}*"],"1.0"],["getSchemeList",[],["{\"scheme\":\"string\"}*"],"1.0"],["getSupportedPlaybackFunction",["{\"uri\":\"string\"}"],["{\"functions\":\"SupportedFunctionInfo[]\", \"uri\":\"string\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"],["presetBroadcastStation",["{\"uri\":\"string\", \"frequency\":\"int\"}"],[],"1.0"],["scanPlayingContent",["{\"output\":\"string\", \"direction\":\"string\"}"],[],"1.0"],["setPlayNextContent",["{\"output\":\"string\"}"],[],"1.0"],["setPlayPreviousContent",["{\"output\":\"string\"}"],[],"1.0"],["setPlaybackModeSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["startContentBrowsing",["{\"uri\":\"string\"}"],["{\"status\":\"string\", \"errorMessage\":\"string\"}"],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]})
2020-12-16 12:52:24.624 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136142,"results":[["getAvailablePlaybackFunction",["{\"output\":\"string\"}"],["{\"functions\":\"FunctionInfo[]\", \"output\":\"string\", \"uri\":\"string\"}*"],"1.0"],["getCurrentExternalTerminalsStatus",[],["{\"uri\":\"string\", \"title\":\"string\", \"connection\":\"string\", \"active\":\"string\", \"label\":\"string\", \"outputs\":\"string*\", \"meta\":\"string\", \"iconUrl\":\"string\"}*"],"1.0"],["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getPlaybackModeSettings",["{\"target\":\"string\", \"uri\":\"string\"}"],["{\"target\":\"string\", \"uri\":\"string\", \"currentValue\":\"string\", \"deviceUIInfo\":\"string\", \"title\":\"string\", \"titleTextID\":\"string\", \"type\":\"string\", \"isAvailable\":\"bool\", \"candidate\":\"PlaybackModeSettingsCandidate[]\"}*"],"1.0"],["getSchemeList",[],["{\"scheme\":\"string\"}*"],"1.0"],["getSupportedPlaybackFunction",["{\"uri\":\"string\"}"],["{\"functions\":\"SupportedFunctionInfo[]\", \"uri\":\"string\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"],["presetBroadcastStation",["{\"uri\":\"string\", \"frequency\":\"int\"}"],[],"1.0"],["scanPlayingContent",["{\"output\":\"string\", \"direction\":\"string\"}"],[],"1.0"],["setPlayNextContent",["{\"output\":\"string\"}"],[],"1.0"],["setPlayPreviousContent",["{\"output\":\"string\"}"],[],"1.0"],["setPlaybackModeSettings",["{\"settings\":\"GeneralSettings[]\"}"],[],"1.0"],["startContentBrowsing",["{\"uri\":\"string\"}"],["{\"status\":\"string\", \"errorMessage\":\"string\"}"],"1.0"],["switchNotifications",["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\"}"],["{\"enabled\":\"ApiIdentity[]\", \"disabled\":\"ApiIdentity[]\", \"unsupported\":\"ApiIdentity[]\"}"],"1.0"]]}
2020-12-16 12:52:24.631 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136143,"method":"getMethodTypes","version":"1.0","params":["1.1"]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.643 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136143,"results":[["getSourceList",["{\"scheme\":\"string\"}"],["{\"source\":\"string\", \"title\":\"string\", \"isPlayable\":\"bool\", \"isBrowsable\":\"bool\", \"playAction\":\"string\", \"outputs\":\"string*\", \"meta\":\"string\", \"iconUrl\":\"string\"}*"],"1.1"],["pausePlayingContent",["{\"output\":\"string\"}"],[],"1.1"],["stopPlayingContent",["{\"output\":\"string\", \"keepLastFrame\":\"bool\"}"],[],"1.1"]]})
2020-12-16 12:52:24.645 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136143,"results":[["getSourceList",["{\"scheme\":\"string\"}"],["{\"source\":\"string\", \"title\":\"string\", \"isPlayable\":\"bool\", \"isBrowsable\":\"bool\", \"playAction\":\"string\", \"outputs\":\"string*\", \"meta\":\"string\", \"iconUrl\":\"string\"}*"],"1.1"],["pausePlayingContent",["{\"output\":\"string\"}"],[],"1.1"],["stopPlayingContent",["{\"output\":\"string\", \"keepLastFrame\":\"bool\"}"],[],"1.1"]]}
2020-12-16 12:52:24.647 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136144,"method":"getMethodTypes","version":"1.0","params":["1.2"]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.660 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136144,"results":[["getPlayingContentInfo",["{\"output\":\"string\"}"],["{\"uri\":\"string\", \"source\":\"string\", \"sourceLabel\":\"string\", \"title\":\"string\", \"output\":\"string\", \"stateInfo\":\"StateInfo\", \"positionSec\":\"double\", \"positionMsec\":\"int\", \"durationSec\":\"double\", \"durationMsec\":\"int\", \"playSpeedStep\":\"int\", \"repeatType\":\"string\", \"dispNum\":\"string\", \"originalDispNum\":\"string\", \"tripletStr\":\"string\", \"programNum\":\"int\", \"programTitle\":\"string\", \"startDateTime\":\"string\", \"mediaType\":\"string\", \"playSpeed\":\"string\", \"bivl_serviceId\":\"string\", \"bivl_assetId\":\"string\", \"bivl_provider\":\"string\", \"chapterIndex\":\"int\", \"chapterCount\":\"int\", \"subtitleIndex\":\"int\", \"artist\":\"string\", \"genre\":\"string*\", \"albumName\":\"string\", \"contentKind\":\"string\", \"fileNo\":\"string\", \"channelName\":\"string\", \"playlistName\":\"string\", \"podcastName\":\"string\", \"totalCount\":\"int\", \"broadcastFreq\":\"int\", \"broadcastFreqBand\":\"string\", \"dabInfo\":\"DabInfo\", \"audioInfo\":\"AudioInfo[]\", \"parentUri\":\"string\", \"service\":\"string\", \"index\":\"int\", \"parentIndex\":\"int\", \"videoInfo\":\"VideoInfo\", \"is3D\":\"string\", \"path\":\"string\", \"applicationName\":\"string\"}*"],"1.2"],["setPlayContent",["{\"uri\":\"string\", \"positionSec\":\"double\", \"positionMsec\":\"int\", \"resume\":\"bool\", \"requester\":\"string\", \"repeatType\":\"string\", \"keepLastFrame\":\"bool\", \"output\":\"string\"}"],[],"1.2"]]})
2020-12-16 12:52:24.665 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136144,"results":[["getPlayingContentInfo",["{\"output\":\"string\"}"],["{\"uri\":\"string\", \"source\":\"string\", \"sourceLabel\":\"string\", \"title\":\"string\", \"output\":\"string\", \"stateInfo\":\"StateInfo\", \"positionSec\":\"double\", \"positionMsec\":\"int\", \"durationSec\":\"double\", \"durationMsec\":\"int\", \"playSpeedStep\":\"int\", \"repeatType\":\"string\", \"dispNum\":\"string\", \"originalDispNum\":\"string\", \"tripletStr\":\"string\", \"programNum\":\"int\", \"programTitle\":\"string\", \"startDateTime\":\"string\", \"mediaType\":\"string\", \"playSpeed\":\"string\", \"bivl_serviceId\":\"string\", \"bivl_assetId\":\"string\", \"bivl_provider\":\"string\", \"chapterIndex\":\"int\", \"chapterCount\":\"int\", \"subtitleIndex\":\"int\", \"artist\":\"string\", \"genre\":\"string*\", \"albumName\":\"string\", \"contentKind\":\"string\", \"fileNo\":\"string\", \"channelName\":\"string\", \"playlistName\":\"string\", \"podcastName\":\"string\", \"totalCount\":\"int\", \"broadcastFreq\":\"int\", \"broadcastFreqBand\":\"string\", \"dabInfo\":\"DabInfo\", \"audioInfo\":\"AudioInfo[]\", \"parentUri\":\"string\", \"service\":\"string\", \"index\":\"int\", \"parentIndex\":\"int\", \"videoInfo\":\"VideoInfo\", \"is3D\":\"string\", \"path\":\"string\", \"applicationName\":\"string\"}*"],"1.2"],["setPlayContent",["{\"uri\":\"string\", \"positionSec\":\"double\", \"positionMsec\":\"int\", \"resume\":\"bool\", \"requester\":\"string\", \"repeatType\":\"string\", \"keepLastFrame\":\"bool\", \"output\":\"string\"}"],[],"1.2"]]}
2020-12-16 12:52:24.670 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136145,"method":"getMethodTypes","version":"1.0","params":["1.3"]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.680 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136145,"results":[["getContentCount",["{\"uri\":\"string\", \"type\":\"string*\", \"target\":\"string\", \"view\":\"string\", \"path\":\"string\"}"],["{\"count\":\"int\", \"capability\":\"int\"}"],"1.3"]]})
2020-12-16 12:52:24.682 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136145,"results":[["getContentCount",["{\"uri\":\"string\", \"type\":\"string*\", \"target\":\"string\", \"view\":\"string\", \"path\":\"string\"}"],["{\"count\":\"int\", \"capability\":\"int\"}"],"1.3"]]}
2020-12-16 12:52:24.684 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136146,"method":"getMethodTypes","version":"1.0","params":["1.4"]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:24.696 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136146,"results":[["getContentList",["{\"uri\":\"string\", \"stIdx\":\"int\", \"cnt\":\"int\", \"type\":\"string*\", \"target\":\"string\", \"view\":\"string\", \"sort\":\"string\", \"path\":\"string\"}"],["{\"uri\":\"string\", \"title\":\"string\", \"index\":\"int\", \"dispNum\":\"string\", \"originalDispNum\":\"string\", \"tripletStr\":\"string\", \"programNum\":\"int\", \"programMediaType\":\"string\", \"directRemoteNum\":\"int\", \"epgVisibility\":\"string\", \"channelSurfingVisibility\":\"string\", \"visibility\":\"string\", \"startDateTime\":\"string\", \"channelName\":\"string\", \"fileSizeByte\":\"int\", \"isProtected\":\"string\", \"isAlreadyPlayed\":\"string\", \"productID\":\"string\", \"contentType\":\"string\", \"storageUri\":\"string\", \"chapterCount\":\"int\", \"durationMsec\":\"int\", \"audioInfo\":\"AudioInfo[]\", \"subtitleInfo\":\"SubtitleInfo[]\", \"parentalInfo\":\"ParentalInfo[]\", \"sizeMB\":\"int\", \"createdTime\":\"string\", \"userContentFlag\":\"bool\", \"content\":\"ContentInfo\", \"folderNo\":\"string\", \"fileNo\":\"string\", \"artist\":\"string\", \"genre\":\"string*\", \"albumName\":\"string\", \"contentKind\":\"string\", \"isPlayable\":\"string\", \"isBrowsable\":\"string\", \"remotePlayType\":\"string*\", \"playlistName\":\"string\", \"podcastName\":\"string\", \"broadcastFreq\":\"int\", \"broadcastFreqBand\":\"string\", \"parentUri\":\"string\", \"parentIndex\":\"int\", \"videoInfo\":\"VideoInfo\", \"is3D\":\"string\", \"path\":\"string\"}*"],"1.4"]]})
2020-12-16 12:52:24.700 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136146,"results":[["getContentList",["{\"uri\":\"string\", \"stIdx\":\"int\", \"cnt\":\"int\", \"type\":\"string*\", \"target\":\"string\", \"view\":\"string\", \"sort\":\"string\", \"path\":\"string\"}"],["{\"uri\":\"string\", \"title\":\"string\", \"index\":\"int\", \"dispNum\":\"string\", \"originalDispNum\":\"string\", \"tripletStr\":\"string\", \"programNum\":\"int\", \"programMediaType\":\"string\", \"directRemoteNum\":\"int\", \"epgVisibility\":\"string\", \"channelSurfingVisibility\":\"string\", \"visibility\":\"string\", \"startDateTime\":\"string\", \"channelName\":\"string\", \"fileSizeByte\":\"int\", \"isProtected\":\"string\", \"isAlreadyPlayed\":\"string\", \"productID\":\"string\", \"contentType\":\"string\", \"storageUri\":\"string\", \"chapterCount\":\"int\", \"durationMsec\":\"int\", \"audioInfo\":\"AudioInfo[]\", \"subtitleInfo\":\"SubtitleInfo[]\", \"parentalInfo\":\"ParentalInfo[]\", \"sizeMB\":\"int\", \"createdTime\":\"string\", \"userContentFlag\":\"bool\", \"content\":\"ContentInfo\", \"folderNo\":\"string\", \"fileNo\":\"string\", \"artist\":\"string\", \"genre\":\"string*\", \"albumName\":\"string\", \"contentKind\":\"string\", \"isPlayable\":\"string\", \"isBrowsable\":\"string\", \"remotePlayType\":\"string*\", \"playlistName\":\"string\", \"podcastName\":\"string\", \"broadcastFreq\":\"int\", \"broadcastFreqBand\":\"string\", \"parentUri\":\"string\", \"parentIndex\":\"int\", \"videoInfo\":\"VideoInfo\", \"is3D\":\"string\", \"path\":\"string\"}*"],"1.4"]]}
2020-12-16 12:52:24.713 [DEBUG] [y.internal.transports.SonyAuthFilter] - Trying to renew our authorization cookie
2020-12-16 12:52:24.766 [DEBUG] [y.internal.transports.SonyAuthFilter] - Could not renew authorization cookie: java.net.ConnectException: Connection refused (Connection refused)
2020-12-16 12:52:24.776 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Sending client request on thread OH-thingHandler-1
5 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
5 > Accept: application/json
5 > Connection: close
5 > Content-Type: application/json
5 > User-Agent: OpenHab/Sony/Binding
5 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
5 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136147,"method":"getVersions","version":"1.0","params":[]}

2020-12-16 12:52:24.791 [DEBUG] [inding.sony.internal.net.HttpRequest] - 5 * Client response received on thread OH-thingHandler-1
5 < 200
5 < Connection: close
5 < content: application/json
5 < Content-Length: 32
{"id":136147,"result":[["1.0"]]}

2020-12-16 12:52:24.798 [DEBUG] [inding.sony.internal.net.HttpRequest] - 6 * Sending client request on thread OH-thingHandler-1
6 > POST http://xxx.xxx.xxx.xxx:10000/sony/guide
6 > Accept: application/json
6 > Connection: close
6 > Content-Type: application/json
6 > User-Agent: OpenHab/Sony/Binding
6 > X-CERS-DEVICE-ID: MediaRemote:00-11-22-33-44-55
6 > X-CERS-DEVICE-INFO: OpenHab/Sony/Binding
{"id":136149,"method":"getMethodTypes","version":"1.0","params":["1.0"]}

2020-12-16 12:52:24.815 [DEBUG] [inding.sony.internal.net.HttpRequest] - 6 * Client response received on thread OH-thingHandler-1
6 < 200
6 < Connection: close
6 < content: application/json
6 < Content-Length: 334
{"id":136149,"results":[["getMethodTypes",["string"],["string","string*","string*","string"],"1.0"],["getServiceProtocols",[],["string","string*"],"1.0"],["getSupportedApiInfo",["{\"services\":\"string*\"}"],["{\"service\":\"string\", \"protocols\":\"string*\", \"apis\":\"ApiInfo[]\"}*"],"1.0"],["getVersions",[],["string*"],"1.0"]]}

2020-12-16 12:52:24.819 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Writing device capability: BDP-S6700
2020-12-16 12:52:24.821 [DEBUG] [l.providers.sources.SonyFolderSource] - File for thing definition already exists (write ignored): /var/lib/openhab2/sony/definitions/capabilities/BDP-S6700.json
2020-12-16 12:52:25.089 [TRACE] [l.providers.sources.SonyGithubSource] - Metainfo was not modified - returning last version from etag "0e74a0f3c0e5392c0af460445e0db7f54d01943c"
2020-12-16 12:52:25.091 [DEBUG] [l.providers.sources.SonyGithubSource] - Ignoring device capabilities - processing is disabled: BDP-S6700
2020-12-16 12:52:25.512 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:25.596 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:25.702 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:26.782 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"method":"notifyStorageStatus","params":[{"format":"cdda","formattable":"notFormatting","isAvailable":"true","mounted":"mounted","position":"internal","type":"cdrom","uri":"storage:cd"}],"version":"1.2"})
2020-12-16 12:52:26.784 [DEBUG] [al.transports.SonyWebSocketTransport] - Event received from server: {"method":"notifyStorageStatus","params":[{"format":"cdda","formattable":"notFormatting","isAvailable":"true","mounted":"mounted","position":"internal","type":"cdrom","uri":"storage:cd"}],"version":"1.2"}
2020-12-16 12:52:26.962 [TRACE] [l.providers.sources.SonyGithubSource] - Metainfo was not modified - returning last version from etag "0e74a0f3c0e5392c0af460445e0db7f54d01943c"
2020-12-16 12:52:26.965 [DEBUG] [l.providers.sources.SonyGithubSource] - Ignoring update from github  - processing is disabled
2020-12-16 12:52:27.559 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000001-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:64321/bdp-bx-ms.xml, Root: true
2020-12-16 12:52:27.561 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - Found sony device but ignored because of no scalar service: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000001-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:64321/bdp-bx-ms.xml, Root: true
2020-12-16 12:52:27.639 [DEBUG] [ternal.ircc.IrccDiscoveryParticipant] - Could not find the IRCC service for device: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:00000000-0000-1010-8000-94db565a279d, Descriptor: http://xxx.xxx.xxx.xxx:52323/dmr.xml, Root: true
2020-12-16 12:52:27.641 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - Found Sony WebScalarAPI service: uuid:00000000-0000-1010-8000-94db565a279d
2020-12-16 12:52:27.644 [DEBUG] [larweb.ScalarWebDiscoveryParticipant] - No specific thing type found for BDP-S6700
2020-12-16 12:52:30.331 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onError(null)
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.331 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onError(null)
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.338 [DEBUG] [al.transports.SonyWebSocketTransport] - Exception occurred during websocket communication for ws://xxx.xxx.xxx.xxx:10000/sony/audio: null
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.344 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onClose(1006, EofException)
2020-12-16 12:52:30.344 [DEBUG] [al.transports.SonyWebSocketTransport] - Exception occurred during websocket communication for ws://xxx.xxx.xxx.xxx:10000/sony/system: null
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.353 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onClose(1006, EofException)
2020-12-16 12:52:30.515 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:30.599 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:30.707 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:30.974 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onError(null)
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.986 [DEBUG] [al.transports.SonyWebSocketTransport] - Exception occurred during websocket communication for ws://xxx.xxx.xxx.xxx:10000/sony/avContent: null
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:283) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.flush(FrameFlusher.java:264) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.FrameFlusher.process(FrameFlusher.java:193) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:516) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.client.io.WebSocketClientConnection.outgoingFrame(WebSocketClientConnection.java:72) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:184) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:428) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:1.8.0_202]
	at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:1.8.0_202]
	at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:1.8.0_202]
	at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:1.8.0_202]
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:263) ~[bundleFile:9.4.20.v20190813]
	... 23 more
2020-12-16 12:52:30.999 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onClose(1006, EofException)
2020-12-16 12:52:35.519 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:35.603 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:35.710 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:40.522 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:40.607 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:40.716 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:45.527 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:45.611 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:45.720 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:50.533 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:50.633 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:50.725 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:53.760 [DEBUG] [.internal.scalarweb.ScalarWebHandler] - Refreshing all state
2020-12-16 12:52:53.761 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Scheduling refreshState on all protocols
2020-12-16 12:52:53.762 [DEBUG] [g.sony.internal.AbstractThingHandler] - Checking connectivity to xxx.xxx.xxx.xxx:10000 - successful
2020-12-16 12:52:53.763 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAudioProtocol@a1f3ec
2020-12-16 12:52:53.764 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebGenericProtocol@cca637
2020-12-16 12:52:53.764 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebAvContentProtocol@e4b156
2020-12-16 12:52:53.766 [DEBUG] [b.protocols.ScalarWebProtocolFactory] - Executing refreshState on org.openhab.binding.sony.internal.scalarweb.protocols.ScalarWebSystemProtocol@1918b0d
2020-12-16 12:52:53.767 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136150,"method":"getSchemeList","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:53.776 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136150,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]})
2020-12-16 12:52:53.778 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136150,"result":[[{"scheme":"storage"},{"scheme":"dlna"}]]}
2020-12-16 12:52:53.781 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136151,"method":"getSourceList","version":"1.1","params":[{"scheme":"dlna"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:53.790 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136151,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]})
2020-12-16 12:52:53.792 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136151,"result":[[{"iconUrl":"","isBrowsable":false,"isPlayable":false,"meta":"meta:dlna:music","playAction":"","source":"dlna:music","title":"Home Network"}]]}
2020-12-16 12:52:53.795 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136152,"method":"getSourceList","version":"1.1","params":[{"scheme":"storage"}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:53.805 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136152,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]})
2020-12-16 12:52:53.807 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136152,"result":[[{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:usb","playAction":"changeSource","source":"storage:usb1","title":"USB"},{"iconUrl":"","isBrowsable":true,"isPlayable":true,"meta":"meta:storage:cd","playAction":"changeSource","source":"storage:cd","title":"CD"}]]}
2020-12-16 12:52:53.819 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136153,"method":"getPlayingContentInfo","version":"1.2","params":[{"output":""}]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:54.018 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136153,"result":[[{"contentKind":"","parentUri":"","source":"extInput:others","stateInfo":{"state":"STOPPED","supplement":""},"uri":"extInput:others"}]]})
2020-12-16 12:52:54.021 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136153,"result":[[{"contentKind":"","parentUri":"","source":"extInput:others","stateInfo":{"state":"STOPPED","supplement":""},"uri":"extInput:others"}]]}
2020-12-16 12:52:54.040 [DEBUG] [al.transports.SonyWebSocketTransport] - Sending {"id":136154,"method":"getCurrentExternalTerminalsStatus","version":"1.0","params":[]} to ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:52:54.048 [TRACE] [al.transports.SonyWebSocketTransport] - websocket.onMessage({"id":136154,"result":[[]]})
2020-12-16 12:52:54.050 [DEBUG] [al.transports.SonyWebSocketTransport] - Response received from server: {"id":136154,"result":[[]]}
2020-12-16 12:52:55.536 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:52:55.636 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:52:55.728 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:53:00.539 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:53:00.639 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:53:00.731 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent
2020-12-16 12:53:05.543 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/system
2020-12-16 12:53:05.643 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/audio
2020-12-16 12:53:05.734 [DEBUG] [al.transports.SonyWebSocketTransport] - Pinging ws://xxx.xxx.xxx.xxx:10000/sony/avContent