n8henrie / fauxmo

Emulated Belkin WeMo devices that work with the Amazon Echo
https://n8henrie.com/2016/02/fauxmo-home-automation-with-the-amazon-echo-raspberry-pi-and-homeassistant/
Other
377 stars 78 forks source link

No Device found #92

Closed hoper83 closed 4 years ago

hoper83 commented 4 years ago

WHYT

I have search by App android and by input echo.

This is my config.json file:

{
    "FAUXMO": {
        "ip_address": "192.168.1.101"
    },
    "PLUGINS": {
        "SimpleHTTPPlugin": {
            "DEVICES": [
                {
                    "port": 12345,
                    "on_cmd": "http://192.168.1.101:81/on.php",
                    "off_cmd": "http://192.168.1.101:81/off.php ",
                    "method": "GET",
                    "name": "luce soggiorno",
                      }
                  ]
          }      
      }    
}

Please make sure you've taken these steps before submitting a new issue:

n8henrie commented 4 years ago

Hello,

Sounds like you're trying to use Fauxmo with a non-Echo Alexa device?

If so, please refer to the FAQ: https://github.com/n8henrie/fauxmo/blob/master/README.md#troubleshooting--faq and let me know if I can otherwise be of assistance.

If not, please clarify and include your log as per the issue template.

hoper83 commented 4 years ago

I have tried also with "echo input" and "echo plus".

Below is the setup.xml file:

<root>
<specVersion>
<major>1</major>
<minor>0</minor>
</specVersion>
<device>
<deviceType>urn:Belkin:device:controllee:1</deviceType>
<friendlyName>luce soggiorno</friendlyName>
<manufacturer>Belkin International Inc.</manufacturer>
<modelName>Emulated Socket</modelName>
<modelNumber>3.1415</modelNumber>
<UDN>
uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a
</UDN>
<serviceList>
<service>
<serviceType>urn:Belkin:service:basicevent:1</serviceType>
<serviceId>urn:Belkin:serviceId:basicevent1</serviceId>
<controlURL>/upnp/control/basicevent1</controlURL>
<eventSubURL>/upnp/event/basicevent1</eventSubURL>
<SCPDURL>/eventservice.xml</SCPDURL>
</service>
<service>
<serviceType>urn:Belkin:service:metainfo:1</serviceType>
<serviceId>urn:Belkin:serviceId:metainfo1</serviceId>
<controlURL>/upnp/control/metainfo1</controlURL>
<eventSubURL>/upnp/event/metainfo1</eventSubURL>
<SCPDURL>/metainfoservice.xml</SCPDURL>
</service>
</serviceList>
</device>
</root>

Below the logs:

log.docx

EDIT: Pasting into post content --@n8henrie

osmc@osmc:~$ sudo python3.7 -m fauxmo.cli -c config.json -vvv
2019-12-15 19:09:22 fauxmo:41       INFO     Fauxmo v0.4.9
2019-12-15 19:09:22 fauxmo:42       DEBUG    3.7.0 (default, Dec 14 2019, 19:16:42)
[GCC 6.3.0 20170516]
2019-12-15 19:09:22 fauxmo:25       DEBUG    Attempting to get IP address automatically
2019-12-15 19:09:22 fauxmo:41       DEBUG    Using IP address: 192.168.1.101
2019-12-15 19:09:23 fauxmo:111      DEBUG    plugin_vars: {}
2019-12-15 19:09:23 fauxmo:114      DEBUG    device config: {'port': 12340, 'on_cmd': 'http://192.168.1.101/on.php', 'off_cmd': 'http://192.168.1.101/off.php ', 'method': 'GET', 'name': 'luce soggiorno'}
2019-12-15 19:09:23 asyncio:1386     INFO     <Server sockets=[<socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340)>]> is serving
2019-12-15 19:09:23 fauxmo:133      DEBUG    Started fauxmo device: {'name': 'luce soggiorno', 'plugin': <fauxmo.plugins.simplehttpplugin.SimpleHTTPPlugin object at 0x763be190>}
2019-12-15 19:09:23 fauxmo:135      INFO     Starting UDP server
2019-12-15 19:09:23 asyncio:1243     DEBUG    Datagram endpoint remote_addr=None created: (<_SelectorDatagramTransport fd=8 read=idle write=<idle, bufsize=0>>, <fauxmo.protocols.SSDPServer object at 0x763be0d0>)
2019-12-15 19:09:23 asyncio:1712     DEBUG    poll took 658.111 ms: 1 events
2019-12-15 19:09:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 4b91d51f-a756-4738-97d0-49169bebef49\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 90082811-59cd-4b90-ba44-c3a4c75f18a3\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 0c9e78cb-4723-4169-8612-17600cd02f44\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:23 asyncio:1716     DEBUG    poll 3853.165 ms took 59.626 ms: 1 events
2019-12-15 19:09:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 40859):
2019-12-15 19:09:23 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 255.255.255.255:1900
CACHE-CONTROL: max-age=10
SERVICE_NAME: ControlServer-MLib
MESSAGE_TYPE: CONTROLLER_START
SPEC_VER: MSpec-1.00

2019-12-15 19:09:27 asyncio:1720     INFO     poll 3788.004 ms took 3789.441 ms: timeout
2019-12-15 19:09:29 asyncio:1712     INFO     poll took 1143.318 ms: 1 events
2019-12-15 19:09:29 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 55989):
2019-12-15 19:09:29 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/79.0.3945.79 Windows

2019-12-15 19:09:30 asyncio:1712     DEBUG    poll took 999.707 ms: 1 events
2019-12-15 19:09:30 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 55989):
2019-12-15 19:09:30 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/79.0.3945.79 Windows

2019-12-15 19:09:31 asyncio:1712     INFO     poll took 1009.511 ms: 1 events
2019-12-15 19:09:31 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 55989):
2019-12-15 19:09:31 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/79.0.3945.79 Windows

2019-12-15 19:09:32 asyncio:1712     INFO     poll took 1008.226 ms: 1 events
2019-12-15 19:09:32 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 55989):
2019-12-15 19:09:32 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 1
ST: urn:dial-multiscreen-org:service:dial:1
USER-AGENT: Google Chrome/79.0.3945.79 Windows

2019-12-15 19:09:37 asyncio:1712     INFO     poll took 4855.163 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.137 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: upnp:rootdevice
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::upnp:rootdevice
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.124 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.130 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:InternetGatewayDevice:2
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:InternetGatewayDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.140 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:Layer3Forwarding:1
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:Layer3Forwarding:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.132 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.137 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANDevice:2
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.142 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.159 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:8e99503f-b2a6-e811-9696-180f767603d4
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.134 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANConnectionDevice:2
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANConnectionDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.135 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANPPPConnection:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANPPPConnection:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:37 asyncio:1712     DEBUG    poll took 0.142 ms: 1 events
2019-12-15 19:09:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:09:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:09:53 asyncio:1712     INFO     poll took 16272.354 ms: 1 events
2019-12-15 19:09:53 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:53 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:53 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:53 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 331e6fef-ab0b-4485-9c8c-0e6d184a0ad1\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:53 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:53 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:53 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:53 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 7b702527-7207-4588-833a-6fbd8c8a5c71\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:53 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:09:53 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:09:53 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:09:53 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 744b50b5-ec06-4bcc-9b30-f9b3b7baec20\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:09:53 asyncio:1716     DEBUG    poll 2777.575 ms took 57.533 ms: 1 events
2019-12-15 19:09:53 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 34996):
2019-12-15 19:09:53 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 255.255.255.255:1900
CACHE-CONTROL: max-age=10
SERVICE_NAME: ControlServer-MLib
MESSAGE_TYPE: CONTROLLER_START
SPEC_VER: MSpec-1.00

2019-12-15 19:09:56 asyncio:1720     INFO     poll 2713.631 ms took 2716.936 ms: timeout
2019-12-15 19:10:00 asyncio:1712     INFO     poll took 3239.070 ms: 1 events
2019-12-15 19:10:00 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 60620):
2019-12-15 19:10:00 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
Man: "ssdp:discover"
MX: 3

2019-12-15 19:10:01 asyncio:1712     DEBUG    poll took 991.182 ms: 1 events
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 7fc20dec-105c-4ef6-9b7c-69eb171b5e3d\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 910c6522-f4a1-4554-bb3c-759be9d05a5c\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 509f35d3-c8ee-4343-a0e0-6e6831bb5667\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: f22e8ef5-c7ad-41ef-aae2-adb47ad270f6\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 74e6a08b-8b08-475d-8ba6-4b41afbefb82\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.115', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.115', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: cfd8e4d5-e8d6-4208-ae67-799766d27708\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 59911c1b-08a8-495f-b61e-e25bb2585a21\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: ea9ac7df-9cdf-41d5-a182-8481b758954a\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: d963d493-8d0e-45f3-bbb8-e982a65b8bfd\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 2475f160-b21f-4f62-94d4-7a85e157e4f9\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: ssdp:all

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: b1af1ef9-c649-40c1-a46c-39abf1def188\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:01 fauxmo:343      DEBUG    Received data below from ('192.168.1.109', 50000):
2019-12-15 19:10:01 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 3
ST: upnp:rootdevice

2019-12-15 19:10:01 fauxmo:418      DEBUG    Sending response to ('192.168.1.109', 50000) with mx 3.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:01 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: cd38d0c9-7760-4e3e-946f-ba477662cd3c\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: upnp:rootdevice\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::upnp:rootdevice\r\n\r\n'
2019-12-15 19:10:01 asyncio:1716     DEBUG    poll 268.672 ms took 8.069 ms: 1 events
2019-12-15 19:10:01 asyncio:170      DEBUG    <Server sockets=[<socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340)>]> got a new connection from ('192.168.1.109', 57350): <socket.socket fd=9, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340), raddr=('192.168.1.109', 57350)>
2019-12-15 19:10:01 fauxmo:41       DEBUG    Connection made with: ('192.168.1.109', 57350)
2019-12-15 19:10:01 fauxmo:52       DEBUG    Received message:
GET /setup.xml HTTP/1.1
Content-Type: application/json
User-Agent: Dalvik/2.1.0 (Linux; U; Android 7.1.2; AEOCK Build/NS6431)
Host: 192.168.1.101:12340
Connection: Keep-Alive
Accept-Encoding: gzip

2019-12-15 19:10:01 fauxmo:54       INFO     setup.xml requested by Echo
2019-12-15 19:10:01 fauxmo:100      DEBUG    Fauxmo response to setup request:
HTTP/1.1 200 OK
CONTENT-LENGTH: 954
CONTENT-TYPE: text/xml
DATE: Sun, 15 Dec 2019 18:10:01 GMT
LAST-MODIFIED: Sat, 01 Jan 2000 00:01:15 GMT
SERVER: Unspecified, UPnP/1.0, Unspecified
X-User-Agent: Fauxmo
CONNECTION: close

<?xml version="1.0"?><root><specVersion><major>1</major><minor>0</minor></specVersion><device><deviceType>urn:Belkin:device:controllee:1</deviceType><friendlyName>luce soggiorno</friendlyName><manufacturer>Belkin International Inc.</manufacturer><modelName>Emulated Socket</modelName><modelNumber>3.1415</modelNumber><UDN>uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a</UDN><serviceList><service><serviceType>urn:Belkin:service:basicevent:1</serviceType><serviceId>urn:Belkin:serviceId:basicevent1</serviceId><controlURL>/upnp/control/basicevent1</controlURL><eventSubURL>/upnp/event/basicevent1</eventSubURL><SCPDURL>/eventservice.xml</SCPDURL></service><service><serviceType>urn:Belkin:service:metainfo:1</serviceType><serviceId>urn:Belkin:serviceId:metainfo1</serviceId><controlURL>/upnp/control/metainfo1</controlURL><eventSubURL>/upnp/event/metainfo1</eventSubURL><SCPDURL>/metainfoservice.xml</SCPDURL></service></serviceList></device></root>
2019-12-15 19:10:01 asyncio:1716     DEBUG    poll 238.694 ms took 14.751 ms: 1 events
2019-12-15 19:10:01 asyncio:170      DEBUG    <Server sockets=[<socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340)>]> got a new connection from ('192.168.1.109', 57352): <socket.socket fd=9, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340), raddr=('192.168.1.109', 57352)>
2019-12-15 19:10:01 fauxmo:41       DEBUG    Connection made with: ('192.168.1.109', 57352)
2019-12-15 19:10:01 fauxmo:52       DEBUG    Received message:
POST /upnp/control/basicevent1 HTTP/1.1
SOAPACTION: "urn:Belkin:service:basicevent:1#GetBinaryState"
Content-Type: text/xml; charset="utf-8"
Accept:
User-Agent: Dalvik/2.1.0 (Linux; U; Android 7.1.2; AEOCK Build/NS6431)
Host: 192.168.1.101:12340
Connection: Keep-Alive
Accept-Encoding: gzip
Content-Length: 299

<?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryState xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>1</BinaryState></u:GetBinaryState></s:Body></s:Envelope>
2019-12-15 19:10:01 fauxmo:63       INFO     request BasicEvent1
2019-12-15 19:10:01 fauxmo:111      DEBUG    Handling action for plugin type <fauxmo.plugins.simplehttpplugin.SimpleHTTPPlugin object at 0x763be190>
2019-12-15 19:10:01 fauxmo:137      INFO     Attempting to get state for luce soggiorno
2019-12-15 19:10:01 fauxmo:150      INFO     luce soggiorno state: unknown
2019-12-15 19:10:01 fauxmo:185      DEBUG    HTTP/1.1 200 OK
CONTENT-LENGTH: 277
CONTENT-TYPE: text/xml
DATE: Sun, 15 Dec 2019 18:10:01 GMT
LAST-MODIFIED: Sat, 01 Jan 2000 00:01:15 GMT
SERVER: Unspecified, UPnP/1.0, Unspecified
X-User-Agent: Fauxmo
CONNECTION: close

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryStateResponse xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>0</BinaryState></u:GetBinaryStateResponse></s:Body></s:Envelope>
2019-12-15 19:10:02 asyncio:1716     DEBUG    poll 782.601 ms took 536.090 ms: 1 events
2019-12-15 19:10:02 asyncio:170      DEBUG    <Server sockets=[<socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340)>]> got a new connection from ('192.168.1.115', 33332): <socket.socket fd=9, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340), raddr=('192.168.1.115', 33332)>
2019-12-15 19:10:02 fauxmo:41       DEBUG    Connection made with: ('192.168.1.115', 33332)
2019-12-15 19:10:02 fauxmo:52       DEBUG    Received message:
GET /setup.xml HTTP/1.1
Content-Type: application/json
User-Agent: Dalvik/2.1.0 (Linux; U; Android 7.1.2; AEOLR Build/NS6431)
Host: 192.168.1.101:12340
Connection: Keep-Alive
Accept-Encoding: gzip

2019-12-15 19:10:02 fauxmo:54       INFO     setup.xml requested by Echo
2019-12-15 19:10:02 fauxmo:100      DEBUG    Fauxmo response to setup request:
HTTP/1.1 200 OK
CONTENT-LENGTH: 954
CONTENT-TYPE: text/xml
DATE: Sun, 15 Dec 2019 18:10:02 GMT
LAST-MODIFIED: Sat, 01 Jan 2000 00:01:15 GMT
SERVER: Unspecified, UPnP/1.0, Unspecified
X-User-Agent: Fauxmo
CONNECTION: close

<?xml version="1.0"?><root><specVersion><major>1</major><minor>0</minor></specVersion><device><deviceType>urn:Belkin:device:controllee:1</deviceType><friendlyName>luce soggiorno</friendlyName><manufacturer>Belkin International Inc.</manufacturer><modelName>Emulated Socket</modelName><modelNumber>3.1415</modelNumber><UDN>uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a</UDN><serviceList><service><serviceType>urn:Belkin:service:basicevent:1</serviceType><serviceId>urn:Belkin:serviceId:basicevent1</serviceId><controlURL>/upnp/control/basicevent1</controlURL><eventSubURL>/upnp/event/basicevent1</eventSubURL><SCPDURL>/eventservice.xml</SCPDURL></service><service><serviceType>urn:Belkin:service:metainfo:1</serviceType><serviceId>urn:Belkin:serviceId:metainfo1</serviceId><controlURL>/upnp/control/metainfo1</controlURL><eventSubURL>/upnp/event/metainfo1</eventSubURL><SCPDURL>/metainfoservice.xml</SCPDURL></service></serviceList></device></root>
2019-12-15 19:10:02 asyncio:1716     DEBUG    poll 213.177 ms took 9.663 ms: 1 events
2019-12-15 19:10:02 asyncio:170      DEBUG    <Server sockets=[<socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340)>]> got a new connection from ('192.168.1.115', 33334): <socket.socket fd=9, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('192.168.1.101', 12340), raddr=('192.168.1.115', 33334)>
2019-12-15 19:10:02 fauxmo:41       DEBUG    Connection made with: ('192.168.1.115', 33334)
2019-12-15 19:10:02 fauxmo:52       DEBUG    Received message:
POST /upnp/control/basicevent1 HTTP/1.1
SOAPACTION: "urn:Belkin:service:basicevent:1#GetBinaryState"
Content-Type: text/xml; charset="utf-8"
Accept:
User-Agent: Dalvik/2.1.0 (Linux; U; Android 7.1.2; AEOLR Build/NS6431)
Host: 192.168.1.101:12340
Connection: Keep-Alive
Accept-Encoding: gzip
Content-Length: 299

<?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryState xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>1</BinaryState></u:GetBinaryState></s:Body></s:Envelope>
2019-12-15 19:10:02 fauxmo:63       INFO     request BasicEvent1
2019-12-15 19:10:02 fauxmo:111      DEBUG    Handling action for plugin type <fauxmo.plugins.simplehttpplugin.SimpleHTTPPlugin object at 0x763be190>
2019-12-15 19:10:02 fauxmo:137      INFO     Attempting to get state for luce soggiorno
2019-12-15 19:10:02 fauxmo:150      INFO     luce soggiorno state: unknown
2019-12-15 19:10:02 fauxmo:185      DEBUG    HTTP/1.1 200 OK
CONTENT-LENGTH: 277
CONTENT-TYPE: text/xml
DATE: Sun, 15 Dec 2019 18:10:02 GMT
LAST-MODIFIED: Sat, 01 Jan 2000 00:01:15 GMT
SERVER: Unspecified, UPnP/1.0, Unspecified
X-User-Agent: Fauxmo
CONNECTION: close

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryStateResponse xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>0</BinaryState></u:GetBinaryStateResponse></s:Body></s:Envelope>
2019-12-15 19:10:03 asyncio:1716     DEBUG    poll 704.531 ms took 209.126 ms: 1 events
2019-12-15 19:10:03 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 60620):
2019-12-15 19:10:03 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
Man: "ssdp:discover"
MX: 3

2019-12-15 19:10:06 asyncio:1712     INFO     poll took 1901.519 ms: 1 events
2019-12-15 19:10:06 fauxmo:343      DEBUG    Received data below from ('192.168.1.105', 60620):
2019-12-15 19:10:06 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
Man: "ssdp:discover"
MX: 3

2019-12-15 19:10:07 asyncio:1712     INFO     poll took 1439.359 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.207 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: upnp:rootdevice
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::upnp:rootdevice
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.217 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.224 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:InternetGatewayDevice:2
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:InternetGatewayDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.187 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:Layer3Forwarding:1
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:Layer3Forwarding:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.202 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.172 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANDevice:2
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.179 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.203 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:8e99503f-b2a6-e811-9696-180f767603d4
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.185 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANConnectionDevice:2
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANConnectionDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.199 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANPPPConnection:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANPPPConnection:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:07 asyncio:1712     DEBUG    poll took 0.174 ms: 1 events
2019-12-15 19:10:07 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:07 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:23 asyncio:1712     INFO     poll took 16258.962 ms: 1 events
2019-12-15 19:10:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:10:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:10:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: 2c3676eb-c8a2-4492-9323-c291da9d6bce\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:10:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:10:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: a858997b-4991-42d7-b5af-5bd2a6b3fe74\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 53047):
2019-12-15 19:10:23 fauxmo:344      DEBUG    M-SEARCH * HTTP/1.1
ST: ssdp:all
MX: 5
MAN: "ssdp:discover"
HOST: 239.255.255.250:1900
Content-Length: 0

2019-12-15 19:10:23 fauxmo:418      DEBUG    Sending response to ('192.168.1.104', 53047) with mx 5.0:
b'HTTP/1.1 200 OK\r\nCACHE-CONTROL: max-age=86400\r\nDATE: Sun, 15 Dec 2019 18:10:23 GMT\r\nEXT:\r\nLOCATION: http://192.168.1.101:12340/setup.xml\r\nOPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01\r\n01-NLS: a5eea4bf-f24f-41b4-a7b0-5f243c014648\r\nSERVER: Fauxmo, UPnP/1.0, Unspecified\r\nST: ssdp:all\r\nUSN: uuid:Socket-1_0-e098cabc-82ab-32cd-b4f1-ae5f9cddcb9a::ssdp:all\r\n\r\n'
2019-12-15 19:10:23 asyncio:1716     DEBUG    poll 347.798 ms took 52.203 ms: 1 events
2019-12-15 19:10:23 fauxmo:343      DEBUG    Received data below from ('192.168.1.104', 51844):
2019-12-15 19:10:23 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 255.255.255.255:1900
CACHE-CONTROL: max-age=10
SERVICE_NAME: ControlServer-MLib
MESSAGE_TYPE: CONTROLLER_START
SPEC_VER: MSpec-1.00

2019-12-15 19:10:28 asyncio:1720     INFO     poll 3635.322 ms took 3637.685 ms: timeout
2019-12-15 19:10:37 asyncio:1712     INFO     poll took 9240.816 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.216 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: upnp:rootdevice
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::upnp:rootdevice
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.197 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:1e64503f-b2a6-e811-9696-180f767603d4
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.213 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:InternetGatewayDevice:2
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:InternetGatewayDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.193 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:Layer3Forwarding:1
USN: uuid:1e64503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:Layer3Forwarding:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.205 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.326 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANDevice:2
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.294 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
USN: uuid:5e7e503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.154 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: uuid:8e99503f-b2a6-e811-9696-180f767603d4
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.143 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:device:WANConnectionDevice:2
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:device:WANConnectionDevice:2
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.156 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANPPPConnection:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANPPPConnection:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337

2019-12-15 19:10:37 asyncio:1712     DEBUG    poll took 0.143 ms: 1 events
2019-12-15 19:10:37 fauxmo:343      DEBUG    Received data below from ('192.168.1.1', 50518):
2019-12-15 19:10:37 fauxmo:344      DEBUG    NOTIFY * HTTP/1.1
HOST: 239.255.255.250:1900
CACHE-CONTROL: max-age=60
lOCATION: http://192.168.1.1:58230/rootDesc0.xml
SERVER: ADBB/EPICENTRO UPnP/1.1 MiniUPnPd/1.8
NT: urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
USN: uuid:8e99503f-b2a6-e811-9696-180f767603d4::urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
NTS: ssdp:alive
OPT: "http://schemas.upnp.org/upnp/1/0/";
01-NLS: 1
BOOTID.UPNP.ORG: 1
CONFIGID.UPNP.ORG: 1337
n8henrie commented 4 years ago

Thanks for the update. So sounds like you're also having this issue with an actual Echo device.

Please edit your comment to include the log content (edit, then copy and paste it into your comment). Please surround relevant code output with trip backticks (```) to mark a codeblock, as per the issue template. See also: https://help.github.com/en/github/writing-on-github/creating-and-highlighting-code-blocks

The goal is for other users to be able to find this issue and how we resolved it by using the search function, which won't work for attachments.

n8henrie commented 4 years ago

Are you sure the config you posted is correct? Your logs show http://192.168.1.101:12340, but your config says you're using port 12345.

It's odd that it's not finding anything, I can see that it is finding the device and querying its state:


<?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="
http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="
http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryState
xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>1</BinaryState></u:GetBinaryState></s:Body></s:Envelope>

Are you asking it to "discover devices" from the Echo device? If not, can you try that?

hoper83 commented 4 years ago

Sorry, the correct config is port 12340.

I searched for devices both with alexa app android and with echo input and with echo plus, but in any case I don't find any new device.

n8henrie commented 4 years ago

Hmm. I'll see if I can reproduce the issue. Sometimes you have to discover devices 2 or 3 times in a row before they show up (not sure why).

I can definitely see that it is discovering your device, since it is trying to query its status. Any chance that you have some kind of a firewall up on the device hosting the PHP script?

hoper83 commented 4 years ago

I have discovered new devices many time, but every time "nothing". I have also checked that the firewall on distro osmc raspbian is not active. The only firewall that is active is located on my router, however i have disable it but the result is ever same. I remain available for any necessary tests.

n8henrie commented 4 years ago

I cannot replicate the issue. I used essentially your same config and was able to discover luce soggiorno on the first try and showed that it worked (successfully tried to call on.php and off.php).

n8henrie commented 4 years ago

I'm about to push Fauxmo v0.5.0 -- I don't see why it would change anything, but please try updating and see if you have better luck.

n8henrie commented 4 years ago

Are you sure your firewall is off? The last part of your log mentions a firewall:

NT: urn:schemas-upnp-org:service:WANIPv6FirewallControl:1
hoper83 commented 4 years ago

I have disabled firewall and upnp agent on router. Ever same result. However I have discovered other device Alexa compatible haven't any problems. Them i have verified that the wemo device in last version needs relative Alexa skill must be actived before for correct recognition.

n8henrie commented 4 years ago

Them i have verified that the wemo device in last version needs relative Alexa skill must be actived before for correct recognition.

Last version of what? I don't think I've ever activated an Alexa skill for Fauxmo.

I'd like to try a little experiment -- instead of using your PHP script, can you try running a Python HTTP server on the same device running Fauxmo and see if that works?

For example, you can run: python3 -m http.server and Python will start up an HTTP server in a local directory, and will print what port it is running on.

Change your on_cmd and off_cmd to reflect that location (likely something like http://127.0.0.1:8000) and see if anything changes.

If it is able to see the device, in the terminal running the HTTP server you should see requests coming in whenever you ask alexa to turn the device on or off. Let me know if you have any better luck with discovery with this setup (although there is still room for a firewall issue in between Alexa and the device running Fauxmo).

You may also experiment with the use_fake_state setting introduced in v0.5.0 (see the readme).

n8henrie commented 4 years ago

Bump.

This issue is pending a response and is blocked until I have more info. To keep the issue list groomed, I will often close these stalled issues if they go a prolonged time without a response. In this case, I will give it another week or so.

n8henrie commented 4 years ago

I haven't gotten a reply, so I'm closing this issue as dead. Please feel free to let me know if I should re-open.