Ankündigung

**pfischi** · 02.12.2014, 17:02

Abend,

Ich habe heute Abend sturmfrei, dann schau ich mir mal das Cover-Problem an. Da du nicht der erste in den letzten Tagen ist, glaube ich an ein Problem im Widget.

Gruss,

Stefan

**pole23** · 03.12.2014, 22:02

Sag Bescheid, wenn ich irgendwie helfen oder testen kann.

**rolandu** · 04.12.2014, 11:19

Hallo pfischi,

finde die Sonos-Anbindung super - DANKE! -, hab aber leider ein Problem:

Bei mir läuft der sonos_broker mit Parameter -d (also Debug-Modus) ohne irgendwelche ERROR-Messages einwandfrei. smarthome und smartvisu-integration laufen - bis auf ein fehlendes Cover.
Starte ich diesen jedoch ohne einen Parameter, sollte er als Daemon laufen, was er aber nicht tut. Der Prozess beendet sich nach wenigen Sekunden bzw. Millisekunden und hinterlässt im Log (loglevel = debug) nur die Meldung:

Code:

2014-12-04 11:13:56,318 DEBUG    MainThread   Google-TTS disabled! -- sonos_broker:__init__:250

Diese wird auch in der SSH-Session ausgegeben (siehe Anhang).

Kannst du mir in dieser Sache weiterhelfen?

LG, Roland

Angehängte Dateien

04-12-2014 11-17-07.png (12,8 KB, 119x aufgerufen)

**pole23** · 04.12.2014, 11:55

Hallo,

je nachdem, welche Eintellungen die in den Configs eingetragen hast, erscheinen diese auch nur auf der Konsole. Wo lässt du das Logfile hinschreiben?

Was ergibt denn folgender Befehl, wenn du den Broker startest?

Code:

ps -ef | grep -v grep | grep sonos_broker

**rolandu** · 04.12.2014, 12:29

wie bereits gesagt läuft der broker nach dem start nicht (scheint nicht bei den prozessen am system auf - siehe "ps -ef").
das log-file lass ich ins selbe verzeichnis schreiben, wo das sonos_broker-skript liegt. mit parameter -d wird das auch ganz schön gefüllt...
nachfolgend der konsolen-output von "./sonos_broker -d" - vielleicht lässt sich daraus was ablesen...

Code:

[/opt/local/bin] # ./sonos_broker -d
2014-12-04 12:25:09,520 DEBUG    MainThread   Google-TTS disabled! -- sonos_broker:__init__:250
2014-12-04 12:25:09,521 INFO     MainThread   Sonos Broker v0.4 -- sonos_broker:start:258
2014-12-04 12:25:09,522 INFO     MainThread   Starting server with ip address 10.0.0.3 ... be sure this is correct. -- sonos_broker:start:260
2014-12-04 12:25:10,526 DEBUG    Thread-2     active threads: 3 -- sonos_service.py:get_speakers_periodically:75
2014-12-04 12:25:10,527 INFO     Thread-2     scan devices ... -- sonos_service.py:get_speakers_periodically:76
2014-12-04 12:25:10,529 INFO     MainThread   Starting http server, use <Ctrl-C> to stop -- sonos_broker:start:265
2014-12-04 12:25:10,607 DEBUG    Thread-2     Created service AVTransport, ver 1, id AVTransport, base_url http://10.0.0.32:1400, control_url /AVTransport/Control -- services.py:__init__:113
2014-12-04 12:25:10,608 DEBUG    Thread-2     Created service ContentDirectory, ver 1, id ContentDirectory, base_url http://10.0.0.32:1400, control_url /ContentDirectory/Control -- services.py:__init__:113
2014-12-04 12:25:10,609 DEBUG    Thread-2     Created service DeviceProperties, ver 1, id DeviceProperties, base_url http://10.0.0.32:1400, control_url /DeviceProperties/Control -- services.py:__init__:113
2014-12-04 12:25:10,610 DEBUG    Thread-2     Created service RenderingControl, ver 1, id RenderingControl, base_url http://10.0.0.32:1400, control_url /RenderingControl/Control -- services.py:__init__:113
2014-12-04 12:25:10,610 DEBUG    Thread-2     Created service ZoneGroupTopology, ver 1, id ZoneGroupTopology, base_url http://10.0.0.32:1400, control_url /ZoneGroupTopology/Control -- services.py:__init__:113
2014-12-04 12:25:10,611 DEBUG    Thread-2     Created service AlarmClock, ver 1, id AlarmClock, base_url http://10.0.0.32:1400, control_url /AlarmClock/Control -- services.py:__init__:113
2014-12-04 12:25:10,612 INFO     Thread-2     Sending GetZoneGroupState None to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:10,638 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:ZoneGroupTopology:1#GetZoneGroupState', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetZoneGroupState xmlns:u="urn:schemas-upnp-org:service:ZoneGroupTopology:1"/>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,664 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,673 DEBUG    Thread-2     "POST /ZoneGroupTopology/Control HTTP/1.1" 200 2801 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,677 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '2801', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetZoneGroupStateResponse xmlns:u="urn:schemas-upnp-org:service:ZoneGroupTopology:1"><ZoneGroupState>&lt;ZoneGroups&gt;&lt;ZoneGroup Coordinator=&quot;RINCON_000E58F33BE401400&quot; ID=&quot;RINCON_000E58F33BE401400:17&quot;&gt;&lt;ZoneGroupMember UUID=&quot;RINCON_000E58F33BE401400&quot; Location=&quot;http://10.0.0.14:1400/xml/device_description.xml&quot; ZoneName=&quot;Küche&quot; Icon=&quot;x-rincon-roomicon:kitchen&quot; Configuration=&quot;1&quot; SoftwareVersion=&quot;27.2-80271&quot; MinCompatibleVersion=&quot;26.0-00000&quot; LegacyCompatibleVersion=&quot;24.0-0000&quot; BootSeq=&quot;66&quot; WirelessMode=&quot;0&quot; ChannelFreq=&quot;2462&quot; BehindWifiExtender=&quot;0&quot;/&gt;&lt;/ZoneGroup&gt;&lt;ZoneGroup Coordinator=&quot;RINCON_000E581DBBBA01400&quot; ID=&quot;RINCON_000E581DBBBA01400:0&quot;&gt;&lt;ZoneGroupMember UUID=&quot;RINCON_000E581DBBBA01400&quot; Location=&quot;http://10.0.0.13:1400/xml/device_description.xml&quot; ZoneName=&quot;BRIDGE WZ&quot; Icon=&quot;x-rincon-roomicon:viper&quot; Configuration=&quot;1&quot; Invisible=&quot;1&quot; IsZoneBridge=&quot;1&quot; SoftwareVersion=&quot;27.2-80071&quot; MinCompatibleVersion=&quot;26.0-00000&quot; LegacyCompatibleVersion=&quot;24.0-0000&quot; BootSeq=&quot;52&quot; WirelessMode=&quot;0&quot; ChannelFreq=&quot;2462&quot; BehindWifiExtender=&quot;0&quot;/&gt;&lt;/ZoneGroup&gt;&lt;ZoneGroup Coordinator=&quot;RINCON_000E58D50A6801400&quot; ID=&quot;RINCON_000E58F33BE401400:16&quot;&gt;&lt;ZoneGroupMember UUID=&quot;RINCON_000E58D50A6801400&quot; Location=&quot;http://10.0.0.6:1400/xml/device_description.xml&quot; ZoneName=&quot;Bad&quot; Icon=&quot;x-rincon-roomicon:bathroom&quot; Configuration=&quot;1&quot; SoftwareVersion=&quot;27.2-80271&quot; MinCompatibleVersion=&quot;26.0-00000&quot; LegacyCompatibleVersion=&quot;24.0-0000&quot; BootSeq=&quot;16&quot; WirelessMode=&quot;0&quot; ChannelFreq=&quot;2462&quot; BehindWifiExtender=&quot;0&quot;/&gt;&lt;/ZoneGroup&gt;&lt;ZoneGroup Coordinator=&quot;RINCON_B8E9372084BE01400&quot; ID=&quot;RINCON_B8E9372084BE01400:8&quot;&gt;&lt;ZoneGroupMember UUID=&quot;RINCON_B8E9372084BE01400&quot; Location=&quot;http://10.0.0.32:1400/xml/device_description.xml&quot; ZoneName=&quot;Terrasse&quot; Icon=&quot;x-rincon-roomicon:patio&quot; Configuration=&quot;1&quot; SoftwareVersion=&quot;27.2-80271&quot; MinCompatibleVersion=&quot;26.0-00000&quot; LegacyCompatibleVersion=&quot;24.0-0000&quot; BootSeq=&quot;24&quot; WirelessMode=&quot;0&quot; ChannelFreq=&quot;2462&quot; BehindWifiExtender=&quot;0&quot;/&gt;&lt;/ZoneGroup&gt;&lt;/ZoneGroups&gt;</ZoneGroupState></u:GetZoneGroupStateResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,679 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:10,681 DEBUG    Thread-2     Created service AVTransport, ver 1, id AVTransport, base_url http://10.0.0.14:1400, control_url /AVTransport/Control -- services.py:__init__:113
2014-12-04 12:25:10,682 DEBUG    Thread-2     Created service ContentDirectory, ver 1, id ContentDirectory, base_url http://10.0.0.14:1400, control_url /ContentDirectory/Control -- services.py:__init__:113
2014-12-04 12:25:10,683 DEBUG    Thread-2     Created service DeviceProperties, ver 1, id DeviceProperties, base_url http://10.0.0.14:1400, control_url /DeviceProperties/Control -- services.py:__init__:113
2014-12-04 12:25:10,684 DEBUG    Thread-2     Created service RenderingControl, ver 1, id RenderingControl, base_url http://10.0.0.14:1400, control_url /RenderingControl/Control -- services.py:__init__:113
2014-12-04 12:25:10,685 DEBUG    Thread-2     Created service ZoneGroupTopology, ver 1, id ZoneGroupTopology, base_url http://10.0.0.14:1400, control_url /ZoneGroupTopology/Control -- services.py:__init__:113
2014-12-04 12:25:10,686 DEBUG    Thread-2     Created service AlarmClock, ver 1, id AlarmClock, base_url http://10.0.0.14:1400, control_url /AlarmClock/Control -- services.py:__init__:113
2014-12-04 12:25:10,687 DEBUG    Thread-2     Created service AVTransport, ver 1, id AVTransport, base_url http://10.0.0.13:1400, control_url /AVTransport/Control -- services.py:__init__:113
2014-12-04 12:25:10,688 DEBUG    Thread-2     Created service ContentDirectory, ver 1, id ContentDirectory, base_url http://10.0.0.13:1400, control_url /ContentDirectory/Control -- services.py:__init__:113
2014-12-04 12:25:10,689 DEBUG    Thread-2     Created service DeviceProperties, ver 1, id DeviceProperties, base_url http://10.0.0.13:1400, control_url /DeviceProperties/Control -- services.py:__init__:113
2014-12-04 12:25:10,690 DEBUG    Thread-2     Created service RenderingControl, ver 1, id RenderingControl, base_url http://10.0.0.13:1400, control_url /RenderingControl/Control -- services.py:__init__:113
2014-12-04 12:25:10,691 DEBUG    Thread-2     Created service ZoneGroupTopology, ver 1, id ZoneGroupTopology, base_url http://10.0.0.13:1400, control_url /ZoneGroupTopology/Control -- services.py:__init__:113
2014-12-04 12:25:10,692 DEBUG    Thread-2     Created service AlarmClock, ver 1, id AlarmClock, base_url http://10.0.0.13:1400, control_url /AlarmClock/Control -- services.py:__init__:113
2014-12-04 12:25:10,693 DEBUG    Thread-2     Created service AVTransport, ver 1, id AVTransport, base_url http://10.0.0.6:1400, control_url /AVTransport/Control -- services.py:__init__:113
2014-12-04 12:25:10,694 DEBUG    Thread-2     Created service ContentDirectory, ver 1, id ContentDirectory, base_url http://10.0.0.6:1400, control_url /ContentDirectory/Control -- services.py:__init__:113
2014-12-04 12:25:10,695 DEBUG    Thread-2     Created service DeviceProperties, ver 1, id DeviceProperties, base_url http://10.0.0.6:1400, control_url /DeviceProperties/Control -- services.py:__init__:113
2014-12-04 12:25:10,696 DEBUG    Thread-2     Created service RenderingControl, ver 1, id RenderingControl, base_url http://10.0.0.6:1400, control_url /RenderingControl/Control -- services.py:__init__:113
2014-12-04 12:25:10,697 DEBUG    Thread-2     Created service ZoneGroupTopology, ver 1, id ZoneGroupTopology, base_url http://10.0.0.6:1400, control_url /ZoneGroupTopology/Control -- services.py:__init__:113
2014-12-04 12:25:10,698 DEBUG    Thread-2     Created service AlarmClock, ver 1, id AlarmClock, base_url http://10.0.0.6:1400, control_url /AlarmClock/Control -- services.py:__init__:113
2014-12-04 12:25:10,705 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,711 DEBUG    Thread-2     "GET /status/zp HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,716 DEBUG    Thread-2     Dispatching method GetVolume -- services.py:__getattr__:173
2014-12-04 12:25:10,717 INFO     Thread-2     Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:10,720 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetVolume', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetVolume xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetVolume>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,727 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,732 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 288 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,736 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '288', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetVolumeResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentVolume>21</CurrentVolume></u:GetVolumeResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,737 INFO     Thread-2     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:10,738 DEBUG    Thread-2     Dispatching method GetBass -- services.py:__getattr__:173
2014-12-04 12:25:10,739 INFO     Thread-2     Sending GetBass [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:10,742 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetBass', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetBass xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetBass>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,749 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,755 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 279 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,759 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '279', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBassResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentBass>0</CurrentBass></u:GetBassResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,760 INFO     Thread-2     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:10,761 DEBUG    Thread-2     Dispatching method GetTreble -- services.py:__getattr__:173
2014-12-04 12:25:10,762 INFO     Thread-2     Sending GetTreble [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:10,765 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetTreble', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTreble xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetTreble>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,772 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,777 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 287 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,781 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '287', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTrebleResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentTreble>0</CurrentTreble></u:GetTrebleResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,782 INFO     Thread-2     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:10,783 DEBUG    Thread-2     Dispatching method GetLoudness -- services.py:__getattr__:173
2014-12-04 12:25:10,784 INFO     Thread-2     Sending GetLoudness [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:10,787 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetLoudness', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetLoudness xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetLoudness>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,794 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,799 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 295 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,803 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '295', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetLoudnessResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentLoudness>0</CurrentLoudness></u:GetLoudnessResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,804 INFO     Thread-2     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:10,805 DEBUG    Thread-2     Dispatching method GetTransportSettings -- services.py:__getattr__:173
2014-12-04 12:25:10,806 INFO     Thread-2     Sending GetTransportSettings [('InstanceID', 0)] to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:10,810 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AVTransport:1#GetTransportSettings', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTransportSettings xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
      <InstanceID>0</InstanceID>
    </u:GetTransportSettings>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,817 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,827 DEBUG    Thread-2     "POST /MediaRenderer/AVTransport/Control HTTP/1.1" 200 348 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,830 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '348', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTransportSettingsResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><PlayMode>SHUFFLE</PlayMode><RecQualityMode>NOT_IMPLEMENTED</RecQualityMode></u:GetTransportSettingsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,831 INFO     Thread-2     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:10,839 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,845 DEBUG    Thread-2     "GET /xml/device_description.xml HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,863 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,871 DEBUG    Thread-2     "GET /status/zp HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,876 DEBUG    Thread-2     Dispatching method GetVolume -- services.py:__getattr__:173
2014-12-04 12:25:10,877 INFO     Thread-2     Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:10,880 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetVolume', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetVolume xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetVolume>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,887 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,895 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 288 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,898 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '288', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetVolumeResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentVolume>59</CurrentVolume></u:GetVolumeResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,899 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:10,900 DEBUG    Thread-2     Dispatching method GetBass -- services.py:__getattr__:173
2014-12-04 12:25:10,901 INFO     Thread-2     Sending GetBass [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:10,904 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetBass', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetBass xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetBass>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,911 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,919 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 279 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,922 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '279', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBassResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentBass>0</CurrentBass></u:GetBassResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,924 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:10,925 DEBUG    Thread-2     Dispatching method GetTreble -- services.py:__getattr__:173
2014-12-04 12:25:10,926 INFO     Thread-2     Sending GetTreble [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:10,928 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetTreble', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTreble xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetTreble>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,935 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,942 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 287 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,946 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '287', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTrebleResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentTreble>0</CurrentTreble></u:GetTrebleResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:10,947 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:10,948 DEBUG    Thread-2     Dispatching method GetLoudness -- services.py:__getattr__:173
2014-12-04 12:25:10,949 INFO     Thread-2     Sending GetLoudness [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:10,952 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetLoudness', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetLoudness xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetLoudness>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:10,959 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:10,966 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 295 -- connectionpool.py:_make_request:364
2014-12-04 12:25:10,969 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '295', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetLoudnessResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentLoudness>1</CurrentLoudness></u:GetLoudnessResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,499 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:12,500 DEBUG    Thread-2     Dispatching method GetTransportSettings -- services.py:__getattr__:173
2014-12-04 12:25:12,501 INFO     Thread-2     Sending GetTransportSettings [('InstanceID', 0)] to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:12,503 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AVTransport:1#GetTransportSettings', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTransportSettings xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
      <InstanceID>0</InstanceID>
    </u:GetTransportSettings>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:12,510 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,517 DEBUG    Thread-2     "POST /MediaRenderer/AVTransport/Control HTTP/1.1" 200 347 -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,521 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '347', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTransportSettingsResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><PlayMode>NORMAL</PlayMode><RecQualityMode>NOT_IMPLEMENTED</RecQualityMode></u:GetTransportSettingsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,522 INFO     Thread-2     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:12,530 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,538 DEBUG    Thread-2     "GET /xml/device_description.xml HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,557 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,565 DEBUG    Thread-2     "GET /status/zp HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,569 DEBUG    Thread-2     Dispatching method GetVolume -- services.py:__getattr__:173
2014-12-04 12:25:12,570 INFO     Thread-2     Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:12,573 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetVolume', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetVolume xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetVolume>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:12,580 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,589 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 288 -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,592 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '288', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetVolumeResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentVolume>14</CurrentVolume></u:GetVolumeResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,593 INFO     Thread-2     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:12,594 DEBUG    Thread-2     Dispatching method GetBass -- services.py:__getattr__:173
2014-12-04 12:25:12,595 INFO     Thread-2     Sending GetBass [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:12,598 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetBass', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetBass xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetBass>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:12,607 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,615 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 279 -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,619 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '279', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBassResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentBass>0</CurrentBass></u:GetBassResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,620 INFO     Thread-2     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:12,621 DEBUG    Thread-2     Dispatching method GetTreble -- services.py:__getattr__:173
2014-12-04 12:25:12,622 INFO     Thread-2     Sending GetTreble [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:12,624 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetTreble', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTreble xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetTreble>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:12,631 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,640 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 287 -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,644 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '287', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTrebleResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentTreble>0</CurrentTreble></u:GetTrebleResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,645 INFO     Thread-2     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:12,646 DEBUG    Thread-2     Dispatching method GetLoudness -- services.py:__getattr__:173
2014-12-04 12:25:12,647 INFO     Thread-2     Sending GetLoudness [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:12,650 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetLoudness', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetLoudness xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetLoudness>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:12,659 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:12,668 DEBUG    Thread-2     "POST /MediaRenderer/RenderingControl/Control HTTP/1.1" 200 295 -- connectionpool.py:_make_request:364
2014-12-04 12:25:12,672 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '295', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetLoudnessResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentLoudness>1</CurrentLoudness></u:GetLoudnessResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:12,673 INFO     Thread-2     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:12,674 DEBUG    Thread-2     Dispatching method GetTransportSettings -- services.py:__getattr__:173
2014-12-04 12:25:12,675 INFO     Thread-2     Sending GetTransportSettings [('InstanceID', 0)] to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:12,677 DEBUG    Thread-2     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AVTransport:1#GetTransportSettings', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:GetTransportSettings xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">
      <InstanceID>0</InstanceID>
    </u:GetTransportSettings>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:13,644 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,652 DEBUG    Thread-2     "POST /MediaRenderer/AVTransport/Control HTTP/1.1" 200 348 -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,655 DEBUG    Thread-2     Received {'CONTENT-LENGTH': '348', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetTransportSettingsResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><PlayMode>SHUFFLE</PlayMode><RecQualityMode>NOT_IMPLEMENTED</RecQualityMode></u:GetTransportSettingsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:13,657 INFO     Thread-2     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:13,664 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,673 DEBUG    Thread-2     "GET /xml/device_description.xml HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,687 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,688 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,689 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,691 INFO     Thread-2     Event listener started -- events.py:start:309
2014-12-04 12:25:13,694 DEBUG    Thread-6     Event listener running on ('10.0.0.3', 1400) -- events.py:run:260
2014-12-04 12:25:13,699 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,708 DEBUG    Thread-2     "SUBSCRIBE /ZoneGroupTopology/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,716 DEBUG    Thread-7     Event 0 received for sid: uuid:RINCON_B8E9372084BE01400_sub0000002498 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,717 DEBUG    Thread-2     Subscribed to http://10.0.0.32:1400/ZoneGroupTopology/Event, sid: uuid:RINCON_B8E9372084BE01400_sub0000002498 -- events.py:subscribe:443
2014-12-04 12:25:13,718 DEBUG    Thread-7     Current thread is <Thread(Thread-7, started -204039280)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,723 DEBUG    Thread-7     "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,731 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,740 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/AVTransport/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,744 DEBUG    Thread-2     Subscribed to http://10.0.0.32:1400/MediaRenderer/AVTransport/Event, sid: uuid:RINCON_B8E9372084BE01400_sub0000002499 -- events.py:subscribe:443
2014-12-04 12:25:13,750 DEBUG    Thread-10    Event 0 received for sid: uuid:RINCON_B8E9372084BE01400_sub0000002499 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,756 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,757 DEBUG    Thread-10    Current thread is <Thread(Thread-10, started -220861552)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,769 DEBUG    Thread-10    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,773 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/RenderingControl/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,777 DEBUG    Thread-2     Subscribed to http://10.0.0.32:1400/MediaRenderer/RenderingControl/Event, sid: uuid:RINCON_B8E9372084BE01400_sub0000002500 -- events.py:subscribe:443
2014-12-04 12:25:13,786 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,789 DEBUG    Thread-12    Event 0 received for sid: uuid:RINCON_B8E9372084BE01400_sub0000002500 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,792 DEBUG    Thread-12    Current thread is <Thread(Thread-12, started -229250160)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,799 DEBUG    Thread-12    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,800 DEBUG    Thread-2     "SUBSCRIBE /AlarmClock/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,805 DEBUG    Thread-2     Subscribed to http://10.0.0.32:1400/AlarmClock/Event, sid: uuid:RINCON_B8E9372084BE01400_sub0000002501 -- events.py:subscribe:443
2014-12-04 12:25:13,807 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,810 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,813 DEBUG    Thread-14    Event 0 received for sid: uuid:RINCON_B8E9372084BE01400_sub0000002501 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,814 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,815 DEBUG    Thread-14    Current thread is <Thread(Thread-14, started -237638768)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,822 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,825 DEBUG    Thread-14    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,832 DEBUG    Thread-2     "SUBSCRIBE /ZoneGroupTopology/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,838 DEBUG    Thread-15    Event 0 received for sid: uuid:RINCON_000E58D50A6801400_sub0000005304 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,840 DEBUG    Thread-2     Subscribed to http://10.0.0.6:1400/ZoneGroupTopology/Event, sid: uuid:RINCON_000E58D50A6801400_sub0000005304 -- events.py:subscribe:443
2014-12-04 12:25:13,840 DEBUG    Thread-15    Current thread is <Thread(Thread-15, started -237638768)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,847 DEBUG    Thread-15    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,854 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,861 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/AVTransport/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,864 DEBUG    Thread-2     Subscribed to http://10.0.0.6:1400/MediaRenderer/AVTransport/Event, sid: uuid:RINCON_000E58D50A6801400_sub0000005305 -- events.py:subscribe:443
2014-12-04 12:25:13,871 DEBUG    Thread-18    Event 0 received for sid: uuid:RINCON_000E58D50A6801400_sub0000005305 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,876 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,877 DEBUG    Thread-18    Current thread is <Thread(Thread-18, started -254415984)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,892 DEBUG    Thread-18    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,895 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/RenderingControl/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,899 DEBUG    Thread-2     Subscribed to http://10.0.0.6:1400/MediaRenderer/RenderingControl/Event, sid: uuid:RINCON_000E58D50A6801400_sub0000005306 -- events.py:subscribe:443
2014-12-04 12:25:13,903 DEBUG    Thread-19    Event 0 received for sid: uuid:RINCON_000E58D50A6801400_sub0000005306 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,905 DEBUG    Thread-19    Current thread is <Thread(Thread-19, started -254415984)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,913 DEBUG    Thread-19    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,920 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,925 DEBUG    Thread-2     "SUBSCRIBE /AlarmClock/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,930 DEBUG    Thread-2     Subscribed to http://10.0.0.6:1400/AlarmClock/Event, sid: uuid:RINCON_000E58D50A6801400_sub0000005307 -- events.py:subscribe:443
2014-12-04 12:25:13,933 DEBUG    Thread-21    Event 0 received for sid: uuid:RINCON_000E58D50A6801400_sub0000005307 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,935 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,936 DEBUG    Thread-21    Current thread is <Thread(Thread-21, started -254415984)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,937 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,940 DEBUG    Thread-21    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,941 DEBUG    Thread-2     Cache hit -- services.py:send_command:326
2014-12-04 12:25:13,950 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,961 DEBUG    Thread-2     "SUBSCRIBE /ZoneGroupTopology/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,968 DEBUG    Thread-23    Event 0 received for sid: uuid:RINCON_000E58F33BE401400_sub0000002155 -- events.py:do_NOTIFY:220
2014-12-04 12:25:13,969 DEBUG    Thread-2     Subscribed to http://10.0.0.14:1400/ZoneGroupTopology/Event, sid: uuid:RINCON_000E58F33BE401400_sub0000002155 -- events.py:subscribe:443
2014-12-04 12:25:13,970 DEBUG    Thread-23    Current thread is <Thread(Thread-23, started -254415984)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:13,977 DEBUG    Thread-23    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:13,983 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:13,994 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/AVTransport/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:13,997 DEBUG    Thread-2     Subscribed to http://10.0.0.14:1400/MediaRenderer/AVTransport/Event, sid: uuid:RINCON_000E58F33BE401400_sub0000002156 -- events.py:subscribe:443
2014-12-04 12:25:14,007 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:14,012 DEBUG    Thread-26    Event 0 received for sid: uuid:RINCON_000E58F33BE401400_sub0000002156 -- events.py:do_NOTIFY:220
2014-12-04 12:25:14,013 DEBUG    Thread-26    Current thread is <Thread(Thread-26, started -287970416)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:14,028 DEBUG    Thread-26    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:14,030 DEBUG    Thread-2     "SUBSCRIBE /MediaRenderer/RenderingControl/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:14,035 DEBUG    Thread-2     Subscribed to http://10.0.0.14:1400/MediaRenderer/RenderingControl/Event, sid: uuid:RINCON_000E58F33BE401400_sub0000002157 -- events.py:subscribe:443
2014-12-04 12:25:14,044 INFO     Thread-2     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:14,048 DEBUG    Thread-28    Event 0 received for sid: uuid:RINCON_000E58F33BE401400_sub0000002157 -- events.py:do_NOTIFY:220
2014-12-04 12:25:14,050 DEBUG    Thread-28    Current thread is <Thread(Thread-28, started -296359024)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:14,055 DEBUG    Thread-28    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:14,060 DEBUG    Thread-2     "SUBSCRIBE /AlarmClock/Event HTTP/1.1" 200 None -- connectionpool.py:_make_request:364
2014-12-04 12:25:14,064 DEBUG    Thread-2     Subscribed to http://10.0.0.14:1400/AlarmClock/Event, sid: uuid:RINCON_000E58F33BE401400_sub0000002158 -- events.py:subscribe:443
2014-12-04 12:25:14,066 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,067 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,071 DEBUG    Thread-30    Event 0 received for sid: uuid:RINCON_000E58F33BE401400_sub0000002158 -- events.py:do_NOTIFY:220
2014-12-04 12:25:14,072 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,073 DEBUG    Thread-30    Current thread is <Thread(Thread-30, started -304747632)> -- events.py:do_NOTIFY:221
2014-12-04 12:25:14,076 DEBUG    Thread-1     Dispatching method ListAlarms -- services.py:__getattr__:173
2014-12-04 12:25:14,079 DEBUG    Thread-30    "NOTIFY / HTTP/1.1" 200 - -- events.py:log_message:243
2014-12-04 12:25:14,080 INFO     Thread-1     Sending ListAlarms None to 10.0.0.32 -- services.py:send_command:330
2014-12-04 12:25:14,083 DEBUG    Thread-1     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AlarmClock:1#ListAlarms', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:ListAlarms xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"/>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:14,091 INFO     Thread-1     Starting new HTTP connection (1): 10.0.0.32 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:14,101 DEBUG    Thread-1     "POST /AlarmClock/Control HTTP/1.1" 200 394 -- connectionpool.py:_make_request:364
2014-12-04 12:25:14,104 DEBUG    Thread-1     Received {'CONTENT-LENGTH': '394', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS5)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:ListAlarmsResponse xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"><CurrentAlarmList>&lt;Alarms&gt;&lt;/Alarms&gt;</CurrentAlarmList><CurrentAlarmListVersion>RINCON_000E58F33BE401400:0</CurrentAlarmListVersion></u:ListAlarmsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:14,106 INFO     Thread-1     Received status 200 from 10.0.0.32 -- services.py:send_command:345
2014-12-04 12:25:14,107 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,108 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,109 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,111 DEBUG    Thread-1     Dispatching method ListAlarms -- services.py:__getattr__:173
2014-12-04 12:25:14,112 INFO     Thread-1     Sending ListAlarms None to 10.0.0.6 -- services.py:send_command:330
2014-12-04 12:25:14,114 DEBUG    Thread-1     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AlarmClock:1#ListAlarms', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:ListAlarms xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"/>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:14,121 INFO     Thread-1     Starting new HTTP connection (1): 10.0.0.6 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:14,130 DEBUG    Thread-1     "POST /AlarmClock/Control HTTP/1.1" 200 394 -- connectionpool.py:_make_request:364
2014-12-04 12:25:14,133 DEBUG    Thread-1     Received {'CONTENT-LENGTH': '394', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZP120)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:ListAlarmsResponse xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"><CurrentAlarmList>&lt;Alarms&gt;&lt;/Alarms&gt;</CurrentAlarmList><CurrentAlarmListVersion>RINCON_000E58F33BE401400:0</CurrentAlarmListVersion></u:ListAlarmsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:14,135 INFO     Thread-1     Received status 200 from 10.0.0.6 -- services.py:send_command:345
2014-12-04 12:25:14,136 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,137 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,138 DEBUG    Thread-1     Cache hit -- services.py:send_command:326
2014-12-04 12:25:14,140 DEBUG    Thread-1     Dispatching method ListAlarms -- services.py:__getattr__:173
2014-12-04 12:25:14,141 INFO     Thread-1     Sending ListAlarms None to 10.0.0.14 -- services.py:send_command:330
2014-12-04 12:25:14,143 DEBUG    Thread-1     Sending {'SOAPACTION': 'urn:schemas-upnp-org:service:AlarmClock:1#ListAlarms', 'Content-Type': 'text/xml; charset="utf-8"'}, <?xml version="1.0" ?>
<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Body>
    <u:ListAlarms xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"/>
  </s:Body>
</s:Envelope>
 -- services.py:send_command:331
2014-12-04 12:25:14,150 INFO     Thread-1     Starting new HTTP connection (1): 10.0.0.14 -- connectionpool.py:_new_conn:188
2014-12-04 12:25:14,161 DEBUG    Thread-1     "POST /AlarmClock/Control HTTP/1.1" 200 394 -- connectionpool.py:_make_request:364
2014-12-04 12:25:14,165 DEBUG    Thread-1     Received {'CONTENT-LENGTH': '394', 'EXT': '', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'Connection': 'close', 'Server': 'Linux UPnP/1.0 Sonos/27.2-80271 (ZPS3)'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:ListAlarmsResponse xmlns:u="urn:schemas-upnp-org:service:AlarmClock:1"><CurrentAlarmList>&lt;Alarms&gt;&lt;/Alarms&gt;</CurrentAlarmList><CurrentAlarmListVersion>RINCON_000E58F33BE401400:0</CurrentAlarmListVersion></u:ListAlarmsResponse></s:Body></s:Envelope> -- services.py:send_command:334
2014-12-04 12:25:14,167 INFO     Thread-1     Received status 200 from 10.0.0.14 -- services.py:send_command:345
2014-12-04 12:25:14,170 INFO     Thread-1     registered clients:  -- udp_broker.py:udp_send:43
2014-12-04 12:25:14,171 INFO     Thread-1     sending sonos speaker data: {
    "additional_zone_members": "",
    "alarms": {},
    "bass": 0,
    "hardware_version": "1.16.4.1-2",
    "ip": "10.0.0.32",
    "led": 1,
    "loudness": 1,
    "mac_address": "B8:E9:37:20:84:BE",
    "max_volume": -1,
    "model": "Sonos PLAY:5",
    "mute": 0,
    "pause": 0,
    "play": 0,
    "playlist_position": 0,
    "playmode": "normal",
    "radio_show": "",
    "radio_station": "",
    "serial_number": "B8-E9-37-20-84-BE:1",
    "software_version": "27.2-80271",
    "status": true,
    "stop": 1,
    "streamtype": "music",
    "track_album_art": "",
    "track_artist": "",
    "track_duration": "0:00:00",
    "track_position": "00:00:00",
    "track_title": "",
    "track_uri": "",
    "treble": 0,
    "uid": "rincon_b8e9372084be01400",
    "volume": 59,
    "zone_icon": "x-rincon-roomicon:patio",
    "zone_name": "Terrasse"
} -- udp_broker.py:udp_send:44
2014-12-04 12:25:14,174 INFO     Thread-1     registered clients:  -- udp_broker.py:udp_send:43
2014-12-04 12:25:14,175 INFO     Thread-1     sending sonos speaker data: {
    "additional_zone_members": "",
    "alarms": {},
    "bass": 0,
    "hardware_version": "1.16.3.1-2",
    "ip": "10.0.0.6",
    "led": 1,
    "loudness": 0,
    "mac_address": "00:0E:58:D5:0A:68",
    "max_volume": -1,
    "model": "Sonos CONNECT:AMP",
    "mute": 0,
    "pause": 1,
    "play": 0,
    "playlist_position": 0,
    "playmode": "shuffle",
    "radio_show": "",
    "radio_station": "",
    "serial_number": "00-0E-58-D5-0A-68:7",
    "software_version": "27.2-80271",
    "status": true,
    "stop": 0,
    "streamtype": "music",
    "track_album_art": "http://10.0.0.6:1400/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a3sLTdTAqH1mvaohyVasgig%3fsid%3d9%26flags%3d32",
    "track_artist": "Rainhard Fendrich",
    "track_duration": "0:03:42",
    "track_position": "00:00:00",
    "track_title": "I am from Austria",
    "track_uri": "x-sonos-spotify:spotify%3atrack%3a3sLTdTAqH1mvaohyVasgig?sid=9&flags=32",
    "treble": 0,
    "uid": "rincon_000e58d50a6801400",
    "volume": 21,
    "zone_icon": "x-rincon-roomicon:bathroom",
    "zone_name": "Bad"
} -- udp_broker.py:udp_send:44
2014-12-04 12:25:14,178 INFO     Thread-1     registered clients:  -- udp_broker.py:udp_send:43
2014-12-04 12:25:14,179 INFO     Thread-1     sending sonos speaker data: {
    "additional_zone_members": "",
    "alarms": {},
    "bass": 0,
    "hardware_version": "1.8.1.2-2",
    "ip": "10.0.0.14",
    "led": 1,
    "loudness": 1,
    "mac_address": "00:0E:58:F3:3B:E4",
    "max_volume": -1,
    "model": "Sonos PLAY:3",
    "mute": 0,
    "pause": 1,
    "play": 0,
    "playlist_position": 0,
    "playmode": "shuffle",
    "radio_show": "",
    "radio_station": "",
    "serial_number": "00-0E-58-F3-3B-E4:6",
    "software_version": "27.2-80271",
    "status": true,
    "stop": 0,
    "streamtype": "music",
    "track_album_art": "http://10.0.0.14:1400/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a04aUaW4vKs51qw7FbQ3zwd%3fsid%3d9%26flags%3d32",
    "track_artist": "Freddy Quinn",
    "track_duration": "0:03:43",
    "track_position": "00:00:00",
    "track_title": "Leise rieselt der Schnee",
    "track_uri": "x-sonos-spotify:spotify%3atrack%3a04aUaW4vKs51qw7FbQ3zwd?sid=9&flags=32",
    "treble": 0,
    "uid": "rincon_000e58f33be401400",
    "volume": 14,
    "zone_icon": "x-rincon-roomicon:kitchen",
    "zone_name": "Küche"
} -- udp_broker.py:udp_send:44

Angehängte Dateien

04-12-2014 12-20-51.png (8,1 KB, 116x aufgerufen)

**rolandu** · 04.12.2014, 14:23

Das Cover-Problem hab ich gelöst. Anbei mein modifiziertes sonos.html-Widget.

Der neue code für das widget.mini.js:

Code:

$(document).delegate('[data-widget="sonos.cover"]',{update:function(d, a){$(this).attr('src', a);}});

LG, Roland

Angehängte Dateien

sonos.zip (1,3 KB, 12x aufgerufen)

**pfischi** · 04.12.2014, 16:51

Hi,

Danke schonmal für die Arbeit am Plugin. Ich werde das die Tage testen und entsprechend in die Codebasis aufnehmen. Zu deinem Problem: Sollte der Prozess tatsächlich nicht in der Prozessliste auftauchen, so hängt er sich eventuell bei Loggen auf (evtl. falsche Pfade?). Kannst du mal bitte dein Broker config-Datei posten?

Grüsse,

Stefan

**rolandu** · 04.12.2014, 21:47

In meiner config steht nix besonderes, der Pfad fürs Log ist derselbe, wie der des brokers (den hat das setup.py auf meinem Qnap gewählt):

Code:

#This is the config file for sonos broker
#Adapt and uncomment the lines to your purpose

########################################################################
[logging]

#Sets the log level for the server. WARNING is the default value.
#Possible values are: debug, info, warning, error, critical
#Default logfile path: /tmp/sonos_broker.log

loglevel = debug
logfile = /opt/local/bin/sonos_broker.log

########################################################################
[sonos_broker]

#Binding host address. Default: 0.0.0.0
host = 0.0.0.0

#Server port. Default: 12900
#port = 12900

########################################################################
[google_tts]

#Enabled Google-Text-To-Speech. Default: false
#enabled = true

#Select the path where sonos broker will save the converted mp3 files
#Before a web request is made, sonos broker will check, if the requested file already exists.
#Possible paths could be: local webserver, mounted smb share ...

#save_path = /var/www

#Specifies the destination url which sonos broker refers to the sonos speakers. This url must point to 'save_path'.
#server_url = http://192.168.0.10/your/www/path/here

#Maximum file size quota in megabytes. Up to this size, sonos broker will save files to 'save_path'.
#Default: 100
#quota = 200

Ich glaube auch nicht, dass es am logging liegt, da wie bereits erwähnt ein "-d"-Aufruf sehr wohl log-files erzeugt...

Liebe Grüße,
Roland

**pfischi** · 04.12.2014, 22:52

Kannst du mal das "debug" auskommentieren und auch den Pfad zum Logfile. Dein gepostetes Log von der Debug-Ausgabe sieht gut aus, keine Fehler.

Stefan

**rolandu** · 05.12.2014, 08:08

hab ich getestet: auch bei deaktiviertem/auskommentiertem logging stürzt der broker anscheinend ab. ich mach ein "ps -ef" sobald der prompt wieder verfügbar ist, aber da ist der prozess schon wieder weg

**rolandu** · 05.12.2014, 12:14

ich hab für mich eine Lösung gefunden:
nach intensivem Debugging scheint es so, dass auf meinem QNAP-NAS der SysLogHandler, welchen die Klasse Daemonize (daemon.py) standardmäßig verwendet, nicht funktioniert. Muss es mir erst im Detail ansehen, aber inzw. hab ich einfach aus dem SysLogHandler einen RotatingFileHandler gemacht, und jetzt läufts...

Hier die veränderte Stelle in der daemon.py:

Code:

        # Initialize syslog.
        # It will work on OS X and Linux. No FreeBSD support, guys, I don't want to import re here
        # to parse your peculiar platform string.
        #if sys.platform == "darwin":
        #    syslog_address = "/var/run/syslog"
        #else:
        #    syslog_address = "/dev/log"
        #syslog = handlers.SysLogHandler(syslog_address)
        #if self.verbose:
        #    syslog.setLevel(logging.DEBUG)
        #else:
        #    syslog.setLevel(logging.INFO)
        # Try to mimic to normal syslog messages.

        #syslog.setFormatter(formatter)

        #self.logger.addHandler(syslog)

        fileLogger = handlers.RotatingFileHandler('/tmp/sonos_broker_daemon.log', 'a', 10000, 5)
        formatter = logging.Formatter("%(asctime)s %(name)s: %(message)s",
                                      "%b %e %H:%M:%S")
        fileLogger.setFormatter(formatter)
        self.logger.addHandler(fileLogger)

**pfischi** · 05.12.2014, 17:21

Zitat von rolandu Beitrag anzeigen

ich hab für mich eine Lösung gefunden:
nach intensivem Debugging scheint es so, dass auf meinem QNAP-NAS der SysLogHandler, welchen die Klasse Daemonize (daemon.py) standardmäßig verwendet, nicht funktioniert. Muss es mir erst im Detail ansehen, aber inzw. hab ich einfach aus dem SysLogHandler einen RotatingFileHandler gemacht, und jetzt läufts...

Hier die veränderte Stelle in der daemon.py:

Code:

        # Initialize syslog.
        # It will work on OS X and Linux. No FreeBSD support, guys, I don't want to import re here
        # to parse your peculiar platform string.
        #if sys.platform == "darwin":
        #    syslog_address = "/var/run/syslog"
        #else:
        #    syslog_address = "/dev/log"
        #syslog = handlers.SysLogHandler(syslog_address)
        #if self.verbose:
        #    syslog.setLevel(logging.DEBUG)
        #else:
        #    syslog.setLevel(logging.INFO)
        # Try to mimic to normal syslog messages.

        #syslog.setFormatter(formatter)

        #self.logger.addHandler(syslog)

        fileLogger = handlers.RotatingFileHandler('/tmp/sonos_broker_daemon.log', 'a', 10000, 5)
        formatter = logging.Formatter("%(asctime)s %(name)s: %(message)s",
                                      "%b %e %H:%M:%S")
        fileLogger.setFormatter(formatter)
        self.logger.addHandler(fileLogger)

Danke für dein Debugging. Ich schaue mir das gleich mal genauer an. Ich werde die Loggerinstanz nehmen, die eh die ganzen Brokerlogs plottet. Ehrlich gesagt habe ich hier einfach vergessen, den Logger umzuschreiben.

Gruß,

Stefan

**pfischi** · 05.12.2014, 20:59

Abend,

ich habe jetzt alle Bugfixes im Code eingepflegt. Der Loghandler im daemon.py ist nun korrekt und das Widget sollte nun bei allen das Cover anzeigen (dickes Danke an rolandu). Wie immer erstmal im Dev-Branch bei Github eingepflegt, wenn ich die Interactive Shell und die Snapshot-Funktion fertig habe, gibts ein neues Release. Beim Widget bitte beachten: die sonos.html, sowie die widget.min.js und widget.js müssen angepasst werden (bei den Javascript-Dateien die Zeile neue Zeile mit der alten ersetzen).

Gruss,

Stefan

**milymat** · 28.12.2014, 06:18

Ich hab gelesen es wurde Google TTS hinzugefügt, heißt das ihr schafft es über Google TTS Sprache auf den Sonos Boxen auszugeben ? Wenn ja wie ist die Latenz zwischen Starten des Befehls und bis man etwas hört ?

**pfischi** · 28.12.2014, 11:05

Ja, funktioniert. Text auf die Boxen schicken und wird als Sprache ausgegeben. Zur Verzögerung: Wie immer kommt es darauf an. Wenn du TTS im Broker so einrichtest, das die Ansagen Lokal gespeichert und später wiederverwendet werden, dann sind die Verzögerungen minimal. Ohne diese Einrichtung wird der Broker den Stream-Mode verwenden, d.h. er fragt jedesmal die Google API an und gibt den Text als Stream wieder. Intern wird das Ganze als Radiostream behandelt. Es kommt dadurch zu einer spürbaren Verzögerung, da der Sonos-Speaker ordentlich puffert. Ich empfehle daher das Ganze nach Anleitung einzurichten und den "lokalen" Modus zu verwenden.

Gruß, Stefan.

Ankündigung

Sonos Anbindung

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar