search

ofekp / TinyUPnP

A very small UPnP IGD implementation for your ESP8266 for automatic port forwarding
GNU Lesser General Public License v2.1
104 stars 15 forks source link

Timeout expired while waiting for the gateway router to respond to M-SEARCH message #66

Open marcodutto opened 4 years ago

marcodutto commented 4 years ago

Hi, I'm trying for the first time the code and of course I'm not lucky! :-( I checked other open issues but find no help. :-( I'm not expert with the UPnP protocol so it's even hard for me to understand which part may be wrong in the output. Facts I know:

  1. I can confirm you that 192.168.1.1 is correct IP of the router.
  2. The router has UPnP enabled (because it's selected and also because some software is using it)
  3. I tried with 3 different "LISTEN_PORT"s: 43210, then 1900, then 11900. The output that follows it's always the same but if I check on the router I can find an active UPnP rule set to my IP for port 43210

Protocol | WAN Port | LAN Port | Destination | Description TCP | 43210 | 43210 | 192.168.1.108 | DAIKIN-BRIDGE

As if the router accepted first request and then stop! Any clue?

Thank you so much!!

Starting...
connectWiFi
.......
Connected to SSID_NAME_IS_CORRECT
IP address: 192.168.1.108
Testing WiFi connection for [192.168.1.108] ==> GOOD
Testing internet connection ==> GOOD
isGatewayInfoValid [(IP unset)] port [0] path [] actionPort [0] actionPath [] serviceTypeName []
Gateway info is not valid

Sending M-SEARCH to [239.255.255.250] Port [1900]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [181]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:2
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [181]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [176]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:2
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [176]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANPPPConnection:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [177]
endPacketRes [1]
M-SEARCH packets sent
Gateway IP [192.168.1.1]
Timeout expired while waiting for the gateway router to respond to M-SEARCH message
ERROR: Invalid router info, cannot continue

isGatewayInfoValid [(IP unset)] port [0] path [] actionPort [0] actionPath [] serviceTypeName []
Gateway info is not valid
Invalid router info, cannot continue
This was printed because adding the required port mapping failed
ofekp commented 4 years ago

What exact commit are you using from this repo? Make sure to use either master branch i.e. this https://github.com/ofekp/TinyUPnP/commit/dcb7ef3162ea1445cb3c84c676d880062d02275b or the last tag v3.1.4 Otherwise you will not have this fix

Are you using ESP32 or ESP8266? You did not mention.

Can you please execute the workaround I describe in https://github.com/ofekp/TinyUPnP/issues/51#issuecomment-583057472 If you are on linux device, it will be easier, you just need to run upnpc -l right after installing miniupnpc Please paste the output here.

marcodutto commented 4 years ago

Hi and thank you so much for answering!

I'm using dcb7ef3 which seems to be last one. Sorry for not specifying from the beginning, I'm using ESP8266. Not sure if this may help, I'm using version 2.5.2 of esp8266 libraries because newer versions are causing me some memory issue on another project. So in case let me know if this may be part of the issue, in case I'll make another installation.

So I started again from loading and running the code on the board. This is the output:


Starting...
connectWiFi
.......
Connected to XXXXXXXXXXXXXX
IP address: 192.168.1.108
Testing WiFi connection for [192.168.1.108] ==> GOOD
Testing internet connection ==> GOOD
isGatewayInfoValid [(IP unset)] port [0] path [] actionPort [0] actionPath [] serviceTypeName []
Gateway info is not valid

Sending M-SEARCH to [239.255.255.250] Port [1900]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [181]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:device:InternetGatewayDevice:2
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [181]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [176]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:2
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [176]
endPacketRes [1]
M-SEARCH * HTTP/1.1
HOST: 239.255.255.250:1900
MAN: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANPPPConnection:1
USER-AGENT: unix/5.1 UPnP/2.0 TinyUPnP/1.0

M-SEARCH packet length is [177]
endPacketRes [1]
M-SEARCH packets sent
Gateway IP [192.168.1.1]
Timeout expired while waiting for the gateway router to respond to M-SEARCH message
ERROR: Invalid router info, cannot continue

isGatewayInfoValid [(IP unset)] port [0] path [] actionPort [0] actionPath [] serviceTypeName []
Gateway info is not valid
Invalid router info, cannot continue
This was printed because adding the required port mapping failed

This time nothing appeared on upnp list on the router. Right after the previous test I executed the "upnpc-shared.exe -l" and this is the output:


C:\Users\Marco\Desktop\upnpc>upnpc-shared.exe -l
upnpc : miniupnpc library test client, version 1.9.
 (c) 2005-2014 Thomas Bernard.
Go to http://miniupnp.free.fr/ or http://miniupnp.tuxfamily.org/
for more information.
List of UPNP devices found on the network :
 desc: http://192.168.1.1:5000/rootDesc.xml
 st: urn:schemas-upnp-org:device:InternetGatewayDevice:1

Found valid IGD : http://192.168.1.1:5000/rorahnW/ctl/IPConn
Local LAN ip address : 192.168.1.54
Connection Type : IP_Routed
Status : Connected, uptime=5111421s, LastConnectionError : ERROR_NONE
  Time started : Mon Jul 06 15:32:27 2020
MaxBitRateDown : 215997000 bps (215.9 Mbps)   MaxBitRateUp 21599000 bps (21.5 Mbps)
ExternalIPAddress = XX.10.151.42
 i protocol exPort->inAddr:inPort description remoteHost leaseTime
GetGenericPortMappingEntry() returned 713 (SpecifiedArrayIndexInvalid)

Is this helping in any way? Thank you so much again!!

ofekp commented 4 years ago

@marcodutto Sorry for the delay, I'm a busy bee. Very strange, since the package clearly sent an M-SEARCH with urn:schemas-upnp-org:device:InternetGatewayDevice:1 which is also exactly what the upnpc lib found. Are you familiar with wireshark/tcp-dump? I would very much like to capture the udp packets sent from the upnpc lib. Let me know if you can do it, if not, I will try to guide you. Oh, please, if you can, put the package logs in txt files and attach them here, this makes reading the issue much easier for me.

marcodutto commented 4 years ago

Don't worry for delay... Luckily we are all busy! :) Last time I run tcpdump was minimum 15yrs ago when I was playing with Slackware with some friends and I've never been able to read the output! So... first question I'm running on windows... can I use WinDump with WinPcap or it's better that I get into my Raspberry via SSH and use tmpdump from there? Is it better to be wired to the router or WiFi? After that... how can I proceed to dump something you may find somehow useful? (parameters/other stuff/...)

ofekp commented 4 years ago

@marcodutto Apologies, busy, busy 😄

OK, if you're still with me, this is what I want you to do. Please use RPi via SSH for this, it will make it much easier. Also, note that I am going to refer to commands that I have attached below.

  1. Register to UDP multicast address
  2. Listen to incoming multicast packets
  3. Fire up the ESP8266.
  4. You should see some packets being received in the RPi, copy the result to a text file. There should be many packets received since I send multiple options from TinyUPnP.
  5. You can now stop listening to incoming packets (just stop the tcpdump execution)
  6. You can also unregister from the multicast packets
  7. Listen to egress packets from RPi
  8. Open another RPi ssh window and fire up miniupnpc (i.e. upnpc -l)
  9. Copy the results to a text file.
  10. GI'ME the results here so we can inspect the differences together and maybe spot what's wrong.

Any problem, reach me here, I will (eventually 🤦) answer. Thanks!

Register/unregister to multicast sudo ip addr add 239.255.255.250/32 dev wlan0 autojoin sudo ip addr del 239.255.255.250/32 dev wlan0

Listen to incoming multicast packets sudo tcpdump -s0 -vv -X '(src 192.168.1.39 or src 192.168.1.40) and host 239.255.255.250'

Egress from RPi sudo tcpdump -n udp port 1900 -X

marcodutto commented 4 years ago

I know that eventually you'll come up with "Oh gosh! He's doing that stupid error that I've been answering 100s of times not to do!" 🤦 I start by apologising!

Here (hopefully) you may find what you asked me to produce... I repeat... hopefully!

  1. Dump of multicast packets while firing up ESP8266 with your code (in this case I replaced the "src" part with the actual IP of ESP... hope this is good!) ("xyz" replace my provider's name... masked just in case...)
pi@raspberrypi:~ $ sudo tcpdump -s0 -vv -X '(src 192.168.1.107 or src 192.168.1.108) and host 239.255.255.250'
tcpdump: listening on wlan0, link-type EN10MB (Ethernet), capture size 262144 bytes
17:09:45.926787 IP (tos 0x0, ttl 1, id 10, offset 0, flags [none], proto UDP (17), length 205)
    ESP_322C58.homenet.xyz.it.49437 > 239.255.255.250.1900: [udp sum ok] UDP, length 177
        0x0000:  4500 00cd 000a 0000 0111 0708 c0a8 016c  E..............l
        0x0010:  efff fffa c11d 076c 00b9 9b5d 4d2d 5345  .......l...]M-SE
        0x0020:  4152 4348 202a 2048 5454 502f 312e 310d  ARCH.*.HTTP/1.1.
        0x0030:  0a48 4f53 543a 2032 3339 2e32 3535 2e32  .HOST:.239.255.2
        0x0040:  3535 2e32 3530 3a31 3930 300d 0a4d 414e  55.250:1900..MAN
        0x0050:  3a20 2273 7364 703a 6469 7363 6f76 6572  :."ssdp:discover
        0x0060:  220d 0a4d 583a 2032 0d0a 5354 3a20 7572  "..MX:.2..ST:.ur
        0x0070:  6e3a 7363 6865 6d61 732d 7570 6e70 2d6f  n:schemas-upnp-o
        0x0080:  7267 3a73 6572 7669 6365 3a57 414e 5050  rg:service:WANPP
        0x0090:  5043 6f6e 6e65 6374 696f 6e3a 310d 0a55  PConnection:1..U
        0x00a0:  5345 522d 4147 454e 543a 2075 6e69 782f  SER-AGENT:.unix/
        0x00b0:  352e 3120 5550 6e50 2f32 2e30 2054 696e  5.1.UPnP/2.0.Tin
        0x00c0:  7955 506e 502f 312e 300d 0a0d 0a         yUPnP/1.0....
17:10:33.020492 IP (tos 0x0, ttl 1, id 10, offset 0, flags [none], proto UDP (17), length 205)
    ESP_322C58.homenet.xyz.it.49437 > 239.255.255.250.1900: [udp sum ok] UDP, length 177
        0x0000:  4500 00cd 000a 0000 0111 0708 c0a8 016c  E..............l
        0x0010:  efff fffa c11d 076c 00b9 9b5d 4d2d 5345  .......l...]M-SE
        0x0020:  4152 4348 202a 2048 5454 502f 312e 310d  ARCH.*.HTTP/1.1.
        0x0030:  0a48 4f53 543a 2032 3339 2e32 3535 2e32  .HOST:.239.255.2
        0x0040:  3535 2e32 3530 3a31 3930 300d 0a4d 414e  55.250:1900..MAN
        0x0050:  3a20 2273 7364 703a 6469 7363 6f76 6572  :."ssdp:discover
        0x0060:  220d 0a4d 583a 2032 0d0a 5354 3a20 7572  "..MX:.2..ST:.ur
        0x0070:  6e3a 7363 6865 6d61 732d 7570 6e70 2d6f  n:schemas-upnp-o
        0x0080:  7267 3a73 6572 7669 6365 3a57 414e 5050  rg:service:WANPP
        0x0090:  5043 6f6e 6e65 6374 696f 6e3a 310d 0a55  PConnection:1..U
        0x00a0:  5345 522d 4147 454e 543a 2075 6e69 782f  SER-AGENT:.unix/
        0x00b0:  352e 3120 5550 6e50 2f32 2e30 2054 696e  5.1.UPnP/2.0.Tin
        0x00c0:  7955 506e 502f 312e 300d 0a0d 0a         yUPnP/1.0....
  1. Dump of egress packets 
    pi@raspberrypi:~ $ sudo tcpdump -n udp port 1900 -X
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on wlan0, link-type EN10MB (Ethernet), capture size 262144 bytes
17:15:30.969315 IP 192.168.1.136.50802 > 239.255.255.250.1900: UDP, length 137
    0x0000:  4500 00a5 aece 4000 0211 174f c0a8 0188  E.....@....O....
    0x0010:  efff fffa c672 076c 0091 ede4 4d2d 5345  .....r.l....M-SE
    0x0020:  4152 4348 202a 2048 5454 502f 312e 310d  ARCH.*.HTTP/1.1.
    0x0030:  0a48 4f53 543a 2032 3339 2e32 3535 2e32  .HOST:.239.255.2
    0x0040:  3535 2e32 3530 3a31 3930 300d 0a53 543a  55.250:1900..ST:
    0x0050:  2075 726e 3a73 6368 656d 6173 2d75 706e  .urn:schemas-upn
    0x0060:  702d 6f72 673a 6465 7669 6365 3a49 6e74  p-org:device:Int
    0x0070:  6572 6e65 7447 6174 6577 6179 4465 7669  ernetGatewayDevi
    0x0080:  6365 3a31 0d0a 4d41 4e3a 2022 7373 6470  ce:1..MAN:."ssdp
    0x0090:  3a64 6973 636f 7665 7222 0d0a 4d58 3a20  :discover"..MX:.
    0x00a0:  320d 0a0d 0a                             2....
17:15:30.979889 IP 192.168.1.1.1900 > 192.168.1.136.50802: UDP, length 428
    0x0000:  4500 01c8 6b01 0000 4011 8a4a c0a8 0101  E...k...@..J....
    0x0010:  c0a8 0188 076c c672 01b4 a9b2 4854 5450  .....l.r....HTTP
    0x0020:  2f31 2e31 2032 3030 204f 4b0d 0a43 4143  /1.1.200.OK..CAC
    0x0030:  4845 2d43 4f4e 5452 4f4c 3a20 6d61 782d  HE-CONTROL:.max-
    0x0040:  6167 653d 3132 300d 0a44 4154 453a 2053  age=120..DATE:.S
    0x0050:  756e 2c20 3230 2053 6570 2032 3032 3020  un,.20.Sep.2020.
    0x0060:  3136 3a31 353a 3330 2047 4d54 0d0a 5354  16:15:30.GMT..ST
    0x0070:  3a20 7572 6e3a 7363 6865 6d61 732d 7570  :.urn:schemas-up
    0x0080:  6e70 2d6f 7267 3a64 6576 6963 653a 496e  np-org:device:In
    0x0090:  7465 726e 6574 4761 7465 7761 7944 6576  ternetGatewayDev
    0x00a0:  6963 653a 310d 0a55 534e 3a20 7575 6964  ice:1..USN:.uuid
    0x00b0:  3a34 6433 6432 3334 652d 6638 3434 2d34  :4d3d234e-f844-4
    0x00c0:  3435 302d 3930 6139 2d34 3432 3832 6565  450-90a9-44282ee
    0x00d0:  3638 3338 623a 3a75 726e 3a73 6368 656d  6838b::urn:schem
    0x00e0:  6173 2d75 706e 702d 6f72 673a 6465 7669  as-upnp-org:devi
    0x00f0:  6365 3a49 6e74 6572 6e65 7447 6174 6577  ce:InternetGatew
    0x0100:  6179 4465 7669 6365 3a31 0d0a 4558 543a  ayDevice:1..EXT:
    0x0110:  0d0a 5345 5256 4552 3a20 486f 6d65 7761  ..SERVER:.Homewa
    0x0120:  7265 2055 506e 502f 312e 310d 0a4c 4f43  re.UPnP/1.1..LOC
    0x0130:  4154 494f 4e3a 2068 7474 703a 2f2f 3139  ATION:.http://19
    0x0140:  322e 3136 382e 312e 313a 3530 3030 2f72  2.168.1.1:5000/r
    0x0150:  6f6f 7444 6573 632e 786d 6c0d 0a4f 5054  ootDesc.xml..OPT
    0x0160:  3a20 2268 7474 703a 2f2f 7363 6865 6d61  :."http://schema
    0x0170:  732e 7570 6e70 2e6f 7267 2f75 706e 702f  s.upnp.org/upnp/
    0x0180:  312f 302f 223b 206e 733d 3031 0d0a 3031  1/0/";.ns=01..01
    0x0190:  2d4e 4c53 3a20 310d 0a42 4f4f 5449 442e  -NLS:.1..BOOTID.
    0x01a0:  5550 4e50 2e4f 5247 3a20 310d 0a43 4f4e  UPNP.ORG:.1..CON
    0x01b0:  4649 4749 442e 5550 4e50 2e4f 5247 3a20  FIGID.UPNP.ORG:.
    0x01c0:  3133 3337 0d0a 0d0a                      1337....
ofekp commented 4 years ago

Perfect execution 👏 👏 👏

I did not find a major issue, but can you test this branch and tell me what the result was: https://github.com/ofekp/TinyUPnP/pull/67 I made it perfectly the same packet as what is being sent by miniupnpc. Let's see... If it does not work, can you do the capture of ingress packets again so I will verify the packet I sent.

Thanks!

marcodutto commented 4 years ago

Little update: I honestly didn't checked your branch 67 yet but I'm writing here because today I received my first ESP32 boards and I immediately decided to make a quick test. I modified my code accordingly (includes, etc.) and with this board the upnp call works and in my router the port is listed. In next days as soon as I'll have some time I'll try to make some comparative tests to understand if the changes I made to the code are the reason to the success or maybe the 8266 has some issue that the 32 doesn't. I'll keep you posted...

ofekp commented 4 years ago

Glad you got it working! I would love to know what the issue with the ESP8266 is, if you have any update please let me know. Thank you.