UPnP not working in Emby, but works in other applications

[OronDF343]

Emby server is not mapping the ports with UPnP even though the router supports UPnP. I verified this on the router's web UI - other applications such as qBittorrent are able to use UPnP on the network just fine.

OS: Windows 7 x64 Emby version: 3.2.5 (probably also affects also older versions) Router: TP-Link TD-W9980 v1

[LukePulverenti]

Hi, thanks for the report. Can you please attach an Emby server log? Thanks !

[OronDF343]

Log: server-63625878715.txt

I just set it up on my new PC, same as before

[LukePulverenti]

Is there still an issue with the latest release? I don't have a TP-Link router for testing but I don't see any issues with linksys. Thanks.

[OronDF343]

Still doesn't work for me

[randomevents]

Confirmed as working on a EdgeRouter Lite, NetGear NightHawk r7000 and generic piece of kit from Monoprice.

[LukePulverenti]

@OronDF343 are you still seeing an issue? thanks.

[OronDF343]

@LukePulverenti Yes. I've updated to 3.2.33.0 to confirm it.

[LukePulverenti]

Why do you think you're having an issue?

[OronDF343]

I don't know much about UPnP internals, but I think either some sort of incompatibility is happening here or Emby isn't actually sending the UPnP request, since all other apps using UPnP on this network work. I am able to find the DLNA stuff in Wireshark, but none of it makes sense to me, and I suspect I'm not looking at the right packets.

[LukePulverenti]

How are you measuring working or not working?

[OronDF343]

1) Checking if I can access Emby using my external IP, in the browser, on both HTTPS and HTTP (also tested my DuckDNS address) 2) Checking on the router's admin pages if Emby (or its port numbers) is listed in the "UPnP Settings List" (where other applications such as qBittorrent show up if they are configured correctly)

[randomevents]

Can you enable and disable the UPnP setting in advanced, restart your server and send your log. It would also be helpful if you could do the same thing, but turn off your windows firewall before the restart. Five minutes should be more than enough time. Those two logs would be helpful to look at.

[OronDF343]

Still working on the logs, but I found it in the debug log:

2017-10-11 08:06:27.038 Debug PortMapper: Found NAT device: uuid:9f0865b3-f5da-4ad5-85b7-7404637fdf39::urn:schemas-upnp-org:service:WANIPConnection:1
2017-10-11 08:06:27.038 Debug PortMapper: Calling Nat.Handle on uuid:9f0865b3-f5da-4ad5-85b7-7404637fdf39::urn:schemas-upnp-org:service:WANIPConnection:1
2017-10-11 08:06:27.040 Debug PortMapper: Found device at: http://192.168.1.2:1900/gatedesc.xml
2017-10-11 08:06:27.040 Debug PortMapper: Parsed device as: 192.168.1.2:1900
2017-10-11 08:06:27.040 Debug PortMapper: Fetching service list: 192.168.1.2:1900
2017-10-11 08:06:27.040 Debug PortMapper: NAT device found: 192.168.1.103
2017-10-11 08:06:27.043 Debug PortMapper: Creating port map on port 8096
2017-10-11 08:06:27.045 Debug PortMapper: Initiating request to: http://192.168.1.2:1900
2017-10-11 08:06:29.798 Debug HttpServer: Validating host localhost
2017-10-11 08:06:29.798 Info HttpServer: HTTP GET http://localhost:8096/emby/System/Endpoint. UserAgent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:55.0) Gecko/20100101 Firefox/55.2.0 Waterfox/55.2.0
2017-10-11 08:06:29.802 Info HttpServer: HTTP Response 200 to ::1. Time: 4ms. http://localhost:8096/emby/System/Endpoint 
2017-10-11 08:06:30.349 Info HttpClient: HttpClientManager POST: http://192.168.1.2:1900
2017-10-11 08:06:30.362 Error HttpClient: Error ProtocolError getting response from http://192.168.1.2:1900
    *** Error Report ***
    Version: 3.2.33.0
    Command line: C:\Users\Oron\AppData\Roaming\Emby-Server\System\MediaBrowser.ServerApplication.exe C:\Users\Oron\AppData\Roaming\Emby-Server\System\MediaBrowser.ServerApplication.exe
    Operating system: Microsoft Windows NT 6.1.7601 Service Pack 1
    64-Bit OS: True
    64-Bit Process: True
    User Interactive: True
    Processor count: 16
    Program data path: C:\Users\Oron\AppData\Roaming\Emby-Server
    Application directory: C:\Users\Oron\AppData\Roaming\Emby-Server\System
    System.Net.WebException: The remote server returned an error: (500) Internal Server Error.
       at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
       at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
    System.Net.WebException
       at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
       at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)

2017-10-11 08:06:30.363 Error PortMapper: Error creating port map: The remote server returned an error: (500) Internal Server Error.

Looks like there is an incompatibility with this particular router?

Also, the router does not log anything other than DHCPD notices for some reason.

EDIT: Captured stuff in Wireshark and found a potential problem!

Here is the request from Emby:

Hypertext Transfer Protocol
    POST / HTTP/1.1\r\n
    SOAPACTION: "#AddPortMapping"\r\n
    Content-Type: text/xml; charset="utf-8"\r\n
    Host: 192.168.1.2:1900\r\n
    Content-Length: 527\r\n
    Accept-Encoding: deflate\r\n
    Connection: Keep-Alive\r\n
    \r\n
    [Full request URI: http://192.168.1.2:1900/]
    [HTTP request 1/1]
    [Response in frame: 15999]
    File Data: 527 bytes

eXtensible Markup Language
    <s:Envelope
        xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"
        s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
        <s:Body>
            <u:AddPortMapping
                xmlns:u="">
                <NewRemoteHost>
                    </NewRemoteHost>
                <NewExternalPort>
                    8096
                    </NewExternalPort>
                <NewProtocol>
                    TCP
                    </NewProtocol>
                <NewInternalPort>
                    8096
                    </NewInternalPort>
                <NewInternalClient>
                    192.168.1.103
                    </NewInternalClient>
                <NewEnabled>
                    1
                    </NewEnabled>
                <NewPortMappingDescription>
                    Emby Server
                    </NewPortMappingDescription>
                <NewLeaseDuration>
                    0
                    </NewLeaseDuration>
                </u:AddPortMapping>
            </s:Body>
        </s:Envelope>

The error from the router:

Hypertext Transfer Protocol
    HTTP/1.1 500 Internal Server Error\r\n
    CONTENT-LENGTH: 411\r\n
    CONTENT-TYPE: text/xml; charset="utf-8"\r\n
    DATE: Tue, 10 Feb 1970 16:04:25 GMT\r\n
    EXT:\r\n
    SERVER: Linux/2.6.36, UPnP/1.0, Portable SDK for UPnP devices/1.6.19\r\n
    X-User-Agent: redsonic\r\n
    \r\n
    [HTTP response 1/1]
    [Time since request: 0.005657000 seconds]
    [Request in frame: 15995]
    File Data: 411 bytes

eXtensible Markup Language
    <s:Envelope
        xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"
        s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
        <s:Body>
            <s:Fault>
                <faultcode>
                    s:Client
                    </faultcode>
                <faultstring>
                    UPnPError
                    </faultstring>
                <detail>
                    <UPnPError
                        xmlns="urn:schemas-upnp-org:control-1-0">
                        <errorCode>
                            -1
                            </errorCode>
                        <errorDescription>
                            Invalid Action
                            </errorDescription>
                        </UPnPError>
                    </detail>
                </s:Fault>
            </s:Body>
        </s:Envelope>

Here is an example of a successful request from qBittorrent for comparison:

Hypertext Transfer Protocol
    POST /upnp/control/WANIPConn1 HTTP/1.1\r\n
    Host: 192.168.1.1:1900\r\n
    Content-Type: text/xml; charset="utf-8"\r\n
    Content-Length: 620\r\n
    Soapaction: "urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping"\r\n
    \r\n
    [Full request URI: http://192.168.1.1:1900/upnp/control/WANIPConn1]
    [HTTP request 1/1]
    [Response in frame: 108589]
    File Data: 620 bytes

eXtensible Markup Language
    <?xml
    <s:Envelope
        xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"
        s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
        <s:Body>
            <u:AddPortMapping
                xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
                <NewRemoteHost>
                    </NewRemoteHost>
                <NewExternalPort>
                    8999
                    </NewExternalPort>
                <NewProtocol>
                    TCP
                    </NewProtocol>
                <NewInternalPort>
                    8999
                    </NewInternalPort>
                <NewInternalClient>
                    192.168.1.103
                    </NewInternalClient>
                <NewEnabled>
                    1
                    </NewEnabled>
                <NewPortMappingDescription>
                    qBittorrent/3.3.16 at 192.168.1.103:8999
                    </NewPortMappingDescription>
                <NewLeaseDuration>
                    0
                    </NewLeaseDuration>
                </u:AddPortMapping>
            </s:Body>
        </s:Envelope>

Looking at the error message and comparing the two requests, the problem is most likely the empty xmlns:u attribute for u:AddPortMapping. The SOAPACTION is also missing the xmlns details.

(NOTE: If you have noticed that each of these requests is to a different router, you are correct. Emby did not contact the correct router - It sent the request to a second router that extends the wireless network with WDS, a TP-Link Archer C2, to which my PC is now connected. However, this is a recent change in my networking setup, long after I first opened this issue. Therefore, that can be ignored for now, but this means that the UPnP issue most likely affects all TP-Link routers.)

[randomevents]

can you pastebin the xml from http://192.168.1.2:1900/gatedesc.xml ?

[OronDF343]

Have you seen my edit to my previous comment? Anyway, here is the XML: https://pastebin.com/ce2HbBFE

In addition to the edit above, the request URL from Emby may be incorrect

[randomevents]

What was your original setup before? What happens when you turn off UPnP on this router?

[OronDF343]

Original setup was to connect to the main router (TD-W9980 at 192.168.1.1) directly over Wi-Fi.

[LukePulverenti]

I found something that looks suspect. The url sent to the router is always the root url, missing the /upnp/xxxx sub-directories.

Looking at the code: https://github.com/MediaBrowser/Emby/blob/dev/Mono.Nat/Upnp/UpnpNatDevice.cs#L114

controlUrl is never populated, but then it is used later to build the url, and since it is null, the entire sub-directory never becomes part of the final url.

[LukePulverenti]

Ah yes, looking at the original code this is based on, at some point along the way i ripped out an entire method that was querying the services list and filling in that info.