Ankündigung

Einklappen
Keine Ankündigung bisher.

Sonos Anbindung

Einklappen
X
 
  • Filter
  • Zeit
  • Anzeigen
Alles löschen
neue Beiträge

  • pfischi
    antwortet
    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.

    Einen Kommentar schreiben:


  • milymat
    antwortet
    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 ?

    Einen Kommentar schreiben:


  • pfischi
    antwortet
    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

    Einen Kommentar schreiben:


  • pfischi
    antwortet
    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

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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)

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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

    Einen Kommentar schreiben:


  • pfischi
    antwortet
    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

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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

    Einen Kommentar schreiben:


  • pfischi
    antwortet
    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

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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

    Einen Kommentar schreiben:


  • pole23
    antwortet
    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

    Einen Kommentar schreiben:


  • rolandu
    antwortet
    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

    Einen Kommentar schreiben:


  • pole23
    antwortet
    Sag Bescheid, wenn ich irgendwie helfen oder testen kann.

    Einen Kommentar schreiben:


  • pfischi
    antwortet
    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

    Einen Kommentar schreiben:

Lädt...
X