UPnP support

Superman

Please start a new thread with your RC2F issues.

Actually I think it was because of the manual changes I had made to test miniupnpd initially…before it was a package. Because this time after my fresh install from RC2 with all the updates sequentially, it updated fine...

Now on the the miniupnpd issues. I install the package, and no errors are noted but it just doesn't work. There's no new options on any interfaces, and on the services status page miniupnpd shows as stopped, but it will not start...

Do I need to reboot first? Nothing is mentioned during the install, so I assume no...

Superman

Okay, sorry, maybe I spoke too soon. I reloaded the main page, then found the minupnpd addition under diagnostics…now I think it's working...

Thanks!!

ZPrime

Still working on getting a tcpdump (libpcap-format) from the 360 for you. Just realized that I don't have any more ethernet hubs at home so I have to steal one from work tomorrow. :)

I did update miniupnpd to your latest version and I'm still getting output like this:

Aug 21 02:15:12 	miniupnpd[95978]: Unknown udp packet received from 192.168.42.36:1025
Aug 21 02:15:12 	miniupnpd[95978]: Unknown udp packet received from 192.168.42.36:1025
Aug 21 02:15:12 	miniupnpd[95978]: Unknown udp packet received from 192.168.42.36:36301
Aug 21 02:15:12 	miniupnpd[95978]: Unknown udp packet received from 192.168.42.36:36301
Aug 21 02:15:12 	last message repeated 9 times

This is what I see when I first turn it on. Unknown packets, but nothing else.
The 360 has a section to test your router/connectivity (to insure that UPnP is working and it can map the ports it needs) and that's when I see all of this below:

Aug 21 02:16:02 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 21 02:16:02 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:16831
Aug 21 02:16:02 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 21 02:16:02 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:2009
Aug 21 02:16:02 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 21 02:16:02 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:16831
Aug 21 02:16:02 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 21 02:16:02 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:2009
Aug 21 02:16:03 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 21 02:16:03 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:16831
Aug 21 02:16:03 	miniupnpd[95978]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 21 02:16:03 	miniupnpd[95978]: SSDP M-SEARCH packet received from 192.168.42.36:2009
Aug 21 02:15:12 	last message repeated 9 times

I did get a capture of the initial SSDP broadcasts from the 360 but I don't know if it is switching over to a unicast after the initial discovery, which is why I want to get you a better dump with a hub in the middle.
Here's what it does first:

M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:1

Then immediately afterward (within a few microseconds):```
M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANPPPConnection:1


Only difference is service type (PPP or IP Connection).

It then fires a DNS query for "xeas.xboxlive.com".  My DNS server replies (I've got a Win2k3 DC on the LAN doing DNS).  AFter that it fires off the same pair of multicasted SSDP queries, two more times (it goes IP,PPP,IP,PPP).  It resolves the same name in DNS a second time, and then the test completes and informs me that my router is "strict".  A working UPNP router returns as "Open."

I should be able to get you bidirectional captures from a working system (360 to a Linksys router that supports UPnP) as well as the pfsense box so you can compare and see what's different.  I just need to get a hub over here.

databeestje

I'm not sure what MSN is trying to do here. Although I see something I could change with regards to the description.


Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#DeletePortMapping
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: Port 42193 protocol TCP allready redirected to 192.168.11.50:42193
Aug 19 19:58:34 	miniupnpd[720]: AddportMapping TCP, for 192.168.11.50, port 42193, description : miniupnpd
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: GetSpecificPortMappingEntry : rhost='(null)' 42193 TCP found => 192.168.11.50:42193 desc='miniupnpd'
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetExternalIPAddress
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: GetSpecificPortMappingEntry : rhost='(null)' 42193 TCP found => 192.168.11.50:42193 desc='miniupnpd'
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: AddportMapping TCP, for 192.168.11.50, port 42193, description : MSGR
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:34 	miniupnpd[720]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 19 19:58:34 	miniupnpd[720]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 19 19:58:34 	miniupnpd[720]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 19 19:58:33 	miniupnpd[720]: SSDP M-SEARCH packet received from 192.168.11.50:9397</m:varname></m:varname>

Weird, MSN adds a portmapping, then query's the mappings, tries mapping it again and then removes it.

Perhaps it also checks the description which is not "MSGR" but "miniupnpd". I think I can change that.
If you enable the upnp framework you should see a "Internet Connection" symbol in the network connections. When you ask the status it immediately dissapears. When you ask the properties it shows all the upnp mappings. But they are all called miniupnpd. But at least this part works.

databeestje

With regards to the eMule version that spams your syslog. Since it fired 2.4 million messages at your miniupnpd and did not remove the port mappings I consider it a broken client and I will not fix it. There is nothing to fix.

databeestje

With regards to the XBOX, if I understand you correctly it does not even try adding a portmapping like the MSN case, am I correct?

nsumner

BTW: I certainly can't explain this but today when I try to run the upnptest.exe program it fails on 7 and 8 while 2 days ago it was working. Nothing has changed but it now fails again… Here is what I see in the logs:

Aug 20 09:00:28 miniupnpd[11684]: SSDP M-SEARCH packet received from 192.168.17.105:1430
Aug 20 09:00:28 miniupnpd[11684]: ST:upnp:rootdevice
Aug 20 09:00:25 miniupnpd[11684]: SSDP M-SEARCH packet received from 192.168.17.105:1430
Aug 20 09:00:25 miniupnpd[11684]: ST:upnp:rootdevice
Aug 20 09:00:23 miniupnpd[11684]: /dummy not found, responding ERROR 404
Aug 20 09:00:23 miniupnpd[11684]: /dummy not found, responding ERROR 404
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : GET /dummy (HTTP/1.1)
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : GET /WANCfg.xml (HTTP/1.1)
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : GET /WANCfg.xml (HTTP/1.1)
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : GET /rootDesc.xml (HTTP/1.1)
Aug 20 09:00:23 miniupnpd[11684]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetExternalIPAddress
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 20 09:00:23 miniupnpd[11684]: HTTP REQUEST : GET /WANIPCn.xml (HTTP/1.1)
Aug 20 09:00:22 miniupnpd[11684]: HTTP REQUEST : GET /WANIPCn.xml (HTTP/1.1)
Aug 20 09:00:22 miniupnpd[11684]: HTTP REQUEST : GET /rootDesc.xml (HTTP/1.1)
Aug 20 09:00:22 miniupnpd[11684]: HTTP REQUEST : GET /rootDesc.xml (HTTP/1.1)
Aug 20 09:00:22 miniupnpd[11684]: SSDP M-SEARCH packet received from 192.168.17.105:1430
Aug 20 09:00:22 miniupnpd[11684]: ST:upnp:rootdevice

OKAY hold the press. I just tried again now for now explainable reason and it worked on all of them again. Again no changes made to the router. Here is what I get in the logs now (much longer)

Aug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#DeletePortMapping
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetExternalIPAddress
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: GetSpecificPortMappingEntry : rhost='(null)' 1345 TCP found => 192.168.17.105:1345 desc='miniupnpd'
Aug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: GetSpecificPortMappingEntry : rhost='(null)' 1345 TCP found => 192.168.17.105:1345 desc='miniupnpd'
Aug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: AddportMapping TCP, for 192.168.17.105, port 1345, description : Test Port Map
Aug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 21 12:52:29 miniupnpd[2363]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 21 12:52:29 miniupnpd[2363]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 21 12:52:29 miniupnpd[2363]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)</m:varname></m:varname></m:varname></m:varname></m:varname></m:varname>

ZPrime

Yeah it doesn't look like the XBox is actually trying to map anything, but I can't be 100% sure - I'm just going off of what the logs say at this point. I'm bringing a hub home with me tonight so I'll be able to get a full capture of both sides of the conversation.

ZPrime

OK, I have some captures finally. :) They are in LibPCap format and were generated by Wireshark (the project formerly known as Ethereal) so should be viewable by just about anyone.

There are four .pcap files in a single .zip.

192.168.42.x is my internal range here. .1 is the pfsense box. .254 is a Linksys WRT54G running Sveasoft Talisman (which has working UPnP support). .2 is my Windows 2003 server - it does DHCP and DNS for the network, and it is what I was capturing from as well.

xbox360-startup.pcap is the dump from the bootup while connected to the pfsense box. Not much interesting here - you'll see the SSDP packets where it just checks for the router, and then a bunch of UDP as it connects to XBox Live.

xbox360-test_live_connection.pcap is the results of the "test my connection to Live" from the Xbox, while still routed through the pfsense box. You'll see a bunch of SSDP queries but then nothing else other than the UDP traffic once it signs in to Live.

xbox360-startup-linksys.pcap - the name is obvious. SAme as the first, but with the default route of .254 and the pfsense box off the LAN. The Linksys does UPnP. Since the Xbox doesn't yet need a hole punched in the firewall, it doesn't try to do any more with UPnP other than check for the router.

xbox360-test_linksys_works.pcap - this is the money shot. You can see that there's a brief SSDP exchange over multicasting, and then there's a unicast exchange, and then the 360 and the Linksys start a TCP conversation. It's not on port 80 so Wireshark doesn't decode it all pretty, but if you look at the data it's just SOAP/XML/HTTP exchange. I'm guessing that this is where it actually does the magic of opening the port in the firewall. If you can mimic the Linksys's responses here it should work.

Hmm. I think I might know what the problem is. The Location: line that miniupnpd spits back is "http://<firewall ip="">:1900/rootDesc.xml" Note the uppercase D in "rootDesc.xml". $5 says that the 360 does an lcase() on the URL and tries to hit it like that…? Although I don't see any such attempt and 404 - it never appears to even try a TCP connection with the PFSense box (or at least there's no packets showing this, and I logged *). The source for Sveasoft is open and we could port over their work, but it's probably GPL vs BSD license and I know that is frowned upon. :-\

I don't know the slightest bit about BSD developent or else I'd try to lend a hand. I've had some courses in C/C++ so I might be at least remotely helpful, but I don't have a clue about how to actually work on a real project (about all I've done is 2-3 source file jobs, with a header or two and maybe one library involved).</firewall>

databeestje

The current installable package uses port 2869 perhaps this makes a difference.

This is defined in /etc/inc/system.inc near the bottom (last function).

Perhaps this makes a difference. Not sure though. I do that just to mimick other devices.

Cheers

databeestje

Oh noes!

Do not run the miniupnpd on port 1900!

That's for the MCAST socket. Which is probably the cause of other programs stumbling
A random 2500-5000 high port for the HTTP server should suffice.

start miniupnpd with -i vr0 -a 192.168.42.254 -p 2869

e.g. client send mcast query to port 1900.

miniupnpd responds with location http://$ip:$port

e.g. http://192.168.42.254:2869

Which is correct. So don't start miniupnpd on port 1900!

ZPrime

OK, I'll try this. I just used the copy of system.inc from your website and that was the value defined in it I guess. :)

I'll make the port change tonight and test again.

ZPrime

Changing the port (I used 2898) didn't do anything. Here's another capture after that change. (PCAP format again)

I'm starting to think that the SSDP packets (the response to the "M-SEARCH" queries) aren't thorough enough, since the Linksys provides more data than miniupnpd does.
For instance, the Xbox does a discovery for WANIPConnection:

M-SEARCH * HTTP/1.1
Host: 239.255.255.250:1900
Man: "ssdp:discover"
MX: 2
ST: urn:schemas-upnp-org:service:WANIPConnection:1

And here are the two responses:
PFSense/miniupnpd

HTTP/1.1 200 OK
Cache-Control: max-age=120
ST: upnp:rootdevice
USN: uuid:00000000-0000-0000-0000-000000000000::upnp:rootdevice
EXT:
Server: miniupnpd/1.0
Location: http://192.168.42.1:2898/rootDesc.xml

Linksys

HTTP/1.1 200 OK
ST:urn:schemas-upnp-org:service:WANIPConnection:1
USN:uuid:000f-6657-a36802e44090::urn:schemas-upnp-org:service:WANIPConnection:1
Location: http://192.168.42.254:5431/dyndev/uuid:000f-6657-a36800e44090
Server: Custom/1.0 UPnP/1.0 Proc/Ver
EXT:
Cache-Control:max-age=1800
DATE: Tue, 22 Aug 2006 00:09:47 GMT

As you can see, the Linksys is outputting a few parts differently. On the Linksys, the "ST:" line is identical to the ST that the Xbox was requesting. On PF, it is not (miniupnpd appears to only have one type of response). I think this is the root of the problem - since the answer to the XBox's query doesn't exactly match, it doesn't attempt to connect to the daemon's unicast port and do a normal mapping routine.

Can we change miniupnpd so it parrots back the right response?

Skud

I've tried it out and although I couldn't get the package to work, I did get it working via the manual instructions.

So far I've tested it with:

Limewire 4.12.4 (Rules add and delete properly)
uTorrent (Rules add and delete properly)
Windows Live Messenger (Again, works properly and the connection diagnostics report that I am "Connected to the internet via a uPnP Symmetric NAT"
uPnPTest (All Passed except for rule#6 because I don't use the windows firewall service and have it disabled)

As for the package, it would install and it was listed on the main page. I chose my interface, but nothing would ever appear in the logs. I even ran "miniupnpd with -i xl0 -a 10.1.42.1 -p 2869" and still nothing. So, I did the manual installation and it worked.

Keep it up people!!

Since I don't have paypal (yes, I know I'm weird and all that stuff) I'm going to have bradenmcg paypal it for me and I'll just pay him back since we work together..

Thanks guys!!
Riley

Skud

Spoke too soon.

The mappings still appear to work, but when I view the states in the web interface I get the following error:

"Fatal error: Call to undefined function: gettext() in /usr/local/www/status_upnp.php on line 57"

Riley

sullrich

You need to upgrade to RC2e or later. Search the forum for RC2e.

Skud

Ahh, yeah, that's it..

I had installed 2e a couple of days ago and I bet when I installed the uPnP update manaully, I overwrote some of those files..

It's working now.

Riley

ZPrime

So Windows Messenger likes it, but not the 360. Weird.

I wonder if it would play nice with the original Xbox…

Would this UPnP book from Intel be useful at all? I'd donate a copy to databeestje or any of the other developers if it would help implementation along.

I've also found a "royalty free" UPnP framework from EBS Embedded Software. I'm inquiring about pricing as well as licensing terms - if I can just plunk down cash for a framework that is 100% compliant and it can just be dropped in, this would be fantastic… as PFSense could then lay claim to be the first open firewall that fully supports UPnP. It might be worth doing even if the UPnP subsystem would have to be distributed separately as binaries/no source due to licensing issues. Free/Open and most Linux flavors do this sort of thing already anyway and it doesn't hurt them at all. That part would of course be up to our wonderful dev team though. ;D

ZPrime

Well, EBS's royalty free framework is $12,000. I don't mind dropping some benjamins here and there to help progress along on OSS that i believe in, but I don't have 12k to blow for pfSense, unfortunately. ;D

Skud

I've been doing a little more testing and I found that it's working 100% on my LAN interface, but it's not quite working on my WLAN interface.

Quick rundown

WLAN –> Linksys WRT54G being used as an AP. It's UPnP and DHCP are turned off. The WLAN NIC in the pfsense box is connected to port 1 on the Linksys (not the WAN port)

Here is the log output from a MSN Live messenger sign-on from a laptop connected to the WLAN interface. MSN reports it is connected to the internet through a NON-UPnP symmetric NAT router.

Aug 23 23:06:19 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:19 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:19 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:19 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:06:18 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:18 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:18 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:18 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:06:18 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:18 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:18 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:18 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:06:17 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:17 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:17 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:17 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:06:17 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:17 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:17 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:17 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:06:16 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:16 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:06:16 	miniupnpd[541]: SSDP M-SEARCH packet received from 192.168.1.200:62964
Aug 23 23:06:16 	miniupnpd[541]: ST: urn:schemas-upnp-org:service:WANIPConnection:1

Here is a WORKING sample from a MSN Live messenger sign-on from a PC connected to the LAN side. MSN reports it is connected to the internet through a UPnP Symmetric NAT router. As you can see there is quite a bit more output and more stuff going on.

Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#DeletePortMapping
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: Port 42193 protocol TCP allready redirected to 10.1.42.100:42193
Aug 23 23:16:33 	miniupnpd[2952]: AddportMapping TCP, for 10.1.42.100, port 42193, description : miniupnpd
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: GetSpecificPortMappingEntry : rhost='(null)' 42193 TCP found => 10.1.42.100:42193 desc='miniupnpd'
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetExternalIPAddress
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: GetSpecificPortMappingEntry : rhost='(null)' 42193 TCP found => 10.1.42.100:42193 desc='miniupnpd'
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: AddportMapping TCP, for 10.1.42.100, port 42193, description : MSGR
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#AddPortMapping
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:service:WANIPConnection:1#GetSpecificPortMappingEntry
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: QueryStateVariable(0"><m:varname>ConnectionStatusAug 23 23:16:33 	miniupnpd[2952]: SOAPAction: urn:schemas-upnp-org:control-1-0#QueryStateVariable
Aug 23 23:16:33 	miniupnpd[2952]: HTTP REQUEST : POST /control/WANIPConnection (HTTP/1.1)
Aug 23 23:16:33 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:33 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:33 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:33 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:16:33 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:33 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:33 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:33 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:16:32 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:32 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:32 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:32 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:16:32 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:32 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:32 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:32 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:16:31 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:31 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:31 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:31 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1
Aug 23 23:16:31 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:31 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANPPPConnection:1
Aug 23 23:16:31 	miniupnpd[2952]: SSDP M-SEARCH packet received from 10.1.42.100:47879
Aug 23 23:16:31 	miniupnpd[2952]: ST: urn:schemas-upnp-org:service:WANIPConnection:1</m:varname></m:varname>

I will do a little bit more testing in case it might actually be the Linksys that I am using as an AP. Maybe it is trying to proxy the UPnP packets even though it's UPnP is turned off.

I was originally using my pfsense box as an AP with a wireless card, but it started dropping packets tonight and I needed it. So I hooked up the linksys to use as an AP instead.

Thanks!!
Riley