Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Invalid router info #59

Closed
taxilly opened this issue Apr 5, 2020 · 10 comments
Closed

Invalid router info #59

taxilly opened this issue Apr 5, 2020 · 10 comments

Comments

@taxilly
Copy link

taxilly commented Apr 5, 2020 •
edited
Loading

Been trying to get this to work using an Wemos D1 Mini (ESP8266), IGD connection goes well then drops the ball and TCP connection times out. Using latest master (cd9771c)

21:01:38.043 -> [INFO] MDNS setup is successful!
21:01:38.077 -> [INFO] Http Station server started
21:01:38.110 -> Testing WiFi connection for [192.168.0.134] ==> GOOD
21:01:38.178 -> Testing internet connection ==> GOOD
21:01:38.760 -> isGatewayInfoValid [(IP unset)] port [0] path [] actionPort [0] actionPath [] serviceTypeName []
21:01:38.861 -> Gateway info is not valid
21:01:38.895 -> 
21:01:38.895 -> Sending M-SEARCH to [239.255.255.250] Port [1900]
21:01:38.930 -> M-SEARCH * HTTP/1.1
21:01:38.964 -> HOST: 239.255.255.250:1900
21:01:38.997 -> MAN: "ssdp:discover"
21:01:39.031 -> MX: 5
21:01:39.031 -> ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
21:01:39.102 -> 
21:01:39.102 -> 
21:01:39.102 -> M-SEARCH sent
21:01:39.102 -> Received packet of size [443] ip [192.168.0.1] port [1900]
21:01:39.169 -> UDP packet read bytes [443] out of [443]
21:01:39.202 -> Gateway packet content:
21:01:39.240 -> HTTP/1.1 200 OK
21:01:39.273 -> CACHE-CONTROL: max-age=3600
21:01:39.307 -> ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1
21:01:39.307 -> USN: uuid:30343438-3030-3000-0000-1835d1a8dec5::urn:schemas-upnp-org:device:InternetGatewayDevice:1
21:01:39.446 -> EXT:
21:01:39.446 -> SERVER: RedHatEnterpriseServer/6.10 UPnP/1.1 MiniUPnPd/1.9
21:01:39.512 -> LOCATION: http://192.168.0.1:5000/rootDesc.xml
21:01:39.546 -> OPT: "http://schemas.upnp.org/upnp/1/0/"; ns=01
21:01:39.613 -> 01-NLS: 1585848159
21:01:39.613 -> BOOTID.UPNP.ORG: 1585848159
21:01:39.646 -> CONFIGID.UPNP.ORG: 1337
21:01:39.680 -> 
21:01:39.680 -> 
21:01:39.680 -> INTERNET_GATEWAY_DEVICE found
21:01:39.713 -> IGD location found [http://192.168.0.1:5000/rootDesc.xml]
21:01:39.782 -> 192.168.0.1
21:01:39.782 -> 5000
21:01:39.819 -> /rootDesc.xml
21:01:39.819 -> Connecting to IGD with host [192.168.0.1] port [5000]
21:01:39.961 -> Connected to IGD
21:01:39.961 -> called getIGDEventURLs
21:01:39.995 -> deviceInfo->actionPath [] deviceInfo->path [/rootDesc.xml]
21:01:40.195 -> HTTP/1.1 200 OK
21:01:40.195 -> Content-Type: text/xml; charset="utf-8"
21:01:40.228 -> Connection: close
21:01:40.261 -> Content-Length: 2619
21:01:40.261 -> Server: RedHatEnterpriseServer/6.10 UPnP/1.1 MiniUPnPd/1.9
21:01:40.330 -> Ext:
21:01:40.330 -> 
21:01:40.330 -> <?xml version="1.0"?>
21:01:45.280 -> <root xmlns="urn:schemas-upnp-org:device-1-0" configId="1337"><specVersion><major>1</major><minor>1</minor></specVersion><device><deviceType>urn:schemas-upnp-org:device:InternetGatewayDevice:1</deviceType><friendlyName>ARRIS TG2492LG-85 Router</friendlyName><manufacturer>ARRIS</manufacturer><manufacturerURL>http://www.arrisi.com/</manufacturerURL><modelDescription>ARRIS TG2492LG-85 Router</modelDescription><modelName>ARRIS TG2492LG-85 Router</modelName><modelNumber>4.5.5.44_0410</modelNumber><modelURL>http://www.arrisi.com/</modelURL><serialNumber>AAAP90448000</serialNumber><UDN>uuid:30343438-3030-3000-0000-1835d1a8dec5</UDN><serviceList><service><serviceType>urn:schemas-upnp-org:service:Layer3Forwarding:1</serviceType><serviceId>urn:upnp-org:serviceId:L3Forwarding1</serviceId><SCPDURL>/L3F.xml</SCPDURL><controlURL>/ctl/L3F</controlURL><eventSubURL>/evt/L3F</eventSubURL></service></serviceList><deviceList><device><deviceType>urn:schemas-upnp-org:device:WANDevice:1</deviceType><friendlyName>WANDevice</friendlyName><manufacturer>ARRIS</manufacturer><manufacturerURL>http://www.arrisi.com/</manufacturerURL><modelDescription>WANDevice</modelDescription><modelName>WANDevice</modelName><modelNumber>20190410</modelNumber><modelURL>http://www.arrisi.com/</modelURL><serialNumber>AAAP90448000</serialNumber><UDN>uuid:30343438-3030-3000-0000-1835d1a8dec6</UDN><UPC>TG2492LG-85</UPC><serviceList><service><serviceType>urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1</serviceType><serviceId>urn:upnp-org:serviceId:WANCommonIFC1</serviceId><SCPDURL>/WANCfg.xml</SCPDURL><controlURL>/ctl/CmnIfCfg</controlURL><eventSubURL>/evt/CmnIfCfg</eventSubURL></service></serviceList><deviceList><device><deviceType>urn:schemas-upnp-org:device:WANConnectionDevice:1</deviceType><friendlyName>WANConnectionDevice</friendlyName><manufacturer>ARRIS</manufacturer><manufacturerURL>http://www.arrisi.com/</manufacturerURL><modelDescription>Residential Gateway</modelDescription><modelName>TG2492LG-85</modelName><modelNumber>20190410</modelNumber><modelURL>http://www.arrisi.com/</modelURL><serialNumber>AAAP90448000</serialNumber><UDN>uuid:30343438-3030-3000-0000-1835d1a8dec7</UDN><UPC>TG2492LG-85</UPC><serviceList><service><serviceType>urn:schemas-upnp-org:service:WANIPConnection:1</serviceType><serviceId>urn:upnp-org:serviceId:WANIPConn1</serviceId><SCPDURL>/WANIPCn.xml</SCPDURL><controlURL>/ctl/IPConn</controlURL><eventSubURL>/evt/IPConn</eventSubURL></service></serviceList></device></deviceList></device></deviceList><presentationURL>http://192.168.0.1/</presentationURL></device></root>called getIGDEventURLs
21:01:48.370 -> deviceInfo->actionPath [] deviceInfo->path [/rootDesc.xml]
21:01:54.370 -> TCP connection timeout while executing getIGDEventURLs
21:01:54.849 -> called getIGDEventURLs
21:01:54.849 -> deviceInfo->actionPath [] deviceInfo->path [/rootDesc.xml]
21:02:00.846 -> TCP connection timeout while executing getIGDEventURLs
21:02:00.879 -> Timeout expired while adding a new port mapping
21:02:00.947 -> ERROR: Invalid router info, cannot continue
21:02:00.981 ->

Any help is appreciated :)
@ofekp
Copy link
Owner

ofekp commented Apr 5, 2020

I added few more logs, can you please run again with branch #60

You'll have to replace the code in your library to get this to use the new code.

Please attach logs as text files. Thanks.

@taxilly
Copy link
Author

taxilly commented Apr 6, 2020

Thanks for the quick response - here's the log:

log.txt

@ofekp
Copy link
Owner

ofekp commented Apr 6, 2020 •
edited
Loading

Are you sure you're using the code from the branch? This makes no sense.
Can you verify by inserting an error and making sure the compilation fails? Or adding a log line or something please? Thanks

Also, can you try to increase the timeout to 30000? It looks like this:
https://github.com/ofekp/TinyUPnP/blob/master/examples/SimpleServerEsp32/SimpleServerEsp32.ino#L23

@taxilly
Copy link
Author

taxilly commented Apr 6, 2020 •
edited
Loading

Ah, my bad - here's the correct log @ofekp

log.txt

Most of the time the program crashes from a soft WDT reset, stack trace:


Decoding stack results
0x40211085: uart_write(uart_t*, char const*, size_t) at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/uart.cpp line 509
0x40100452: millis() at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/core_esp8266_wiring.cpp line 188
0x4020e3e8: HardwareSerial::write(unsigned char const*, unsigned int) at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/HardwareSerial.h line 165
0x4020e895: Print::print(String const&) at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/Print.cpp line 126
0x4020db03: TinyUPnP::getIGDEventURLs(_gatewayInfo*) at /Users/cass/Documents/Arduino/libraries/TinyUPnP/src/TinyUPnP.cpp line 708
0x40211ac8: UdpContext::unref() at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/libraries/ESP8266WiFi/src/include/UdpContext.h line 91
0x402107e5: __delay(unsigned long) at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/core_esp8266_wiring.cpp line 57
0x4020df67: TinyUPnP::getGatewayInfo(_gatewayInfo*, long) at /Users/cass/Documents/Arduino/libraries/TinyUPnP/src/TinyUPnP.cpp line 212
0x4020e092: TinyUPnP::commitPortMappings() at /Users/cass/Documents/Arduino/libraries/TinyUPnP/src/TinyUPnP.cpp line 98
0x4020f091: String::invalidate() at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/WString.cpp line 140
0x40201480: initUPnP() at /Users/cass/Code/Projects/Sites/hydroponics/hardware/wemos_2/sketch_apr04a/sketch_apr04a.ino line 296
0x40203dfe: setup() at /Users/cass/Code/Projects/Sites/hydroponics/hardware/wemos_2/sketch_apr04a/sketch_apr04a.ino line 56
0x402102e4: loop_wrapper() at /Users/cass/Library/Arduino15/packages/esp8266/hardware/esp8266/2.6.3/cores/esp8266/core_esp8266_main.cpp line 177

@taxilly
Copy link
Author

taxilly commented Apr 6, 2020 •
edited
Loading

Tried it with a different D1 Mini, port listing seems to have been set at some point - but soft reset happens 90% of the time
log2.txt

@taxilly
Copy link
Author

taxilly commented Apr 6, 2020

From my cursory testing and messing about with trying to fix the soft WDT reset I think I have found the cause -- debugPrint(line); in getIGDEventURLs takes so long to be printed to serial monitor that the watchdog timer isn't reset in time causing the D1 Mini to reset.

Commenting out this line stops this behaviour, obviously.

@ofekp
Copy link
Owner

ofekp commented Apr 7, 2020 •
edited
Loading

Looks like your router is not splitting the XML to multiple lines, it sends the response with a somewhat large XML file back in one line.
Multiple options here (I would try both in this order):

  1. disable the debug print you have found
  2. disable debug logs entirely by commenting out this line

You can make sure your router accepted the new rule using the UI page or using upnpc in linux.
Please give it a try.

@ofekp
Copy link
Owner

ofekp commented May 9, 2020

Hey, does this work for you?
Let me know if we can close this please,
Thanks.

@taxilly
Copy link
Author

taxilly commented Aug 30, 2020

Yeah sorry for inactivity, commenting the line fixes it.

@taxilly taxilly closed this as completed Aug 30, 2020
@ofekp
Copy link
Owner

ofekp commented Aug 31, 2020

@taxilly Thank you.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ofekp @taxilly