UPnP support

ollopa

Oct 2 22:11:51 miniupnpd[977]: Failed to open socket for SSDP. EXITING
Oct 2 22:11:51 miniupnpd[977]: bind(udp): Address already in use
Oct 2 22:11:49 php: : Resyncing configuration for all packages.

That looks like you still had a copy of miniupnpd running in memory when you installed the package.

Did you try rebooting the router yet?

sullrich

@rsw686:

Oct 2 22:11:51 miniupnpd[977]: bind(udp): Address already in use

It's already running, I bet. Kill it before starting it again.

Either that or our code is not killing it correctly.

rsw686

@sullrich:

@rsw686:

Oct 2 22:11:51 miniupnpd[977]: bind(udp): Address already in use

It's already running, I bet. Kill it before starting it again.

Either that or our code is not killing it correctly.

I tried rebooting the system. Played around with this some more in VMware installing RC3 and then the package. Same thing happens. Only thing that comes to mind is that it runs the rc.d startup script before it syncs the package and then runs it again.

Not only that but now when I run Azereus it still talks to miniupnpd and sets up the port forwarding but it doesn't actually open them up in the firewall. Azereus shows DHT firewalled and before the firewall logs would fill with accepted packets and now it doesn't.

rsw686

When I run

pfctl -aminiupnpd -sn
rdr on fxp1 inet proto udp from any to any port = 6881 label "Azureus UPnP 6881 UDP" -> 10.10.1.150 port 6881
rdr on fxp1 inet proto tcp from any to any port = 6881 label "Azureus UPnP 6881 TCP" -> 10.10.1.150 port 6881

pfctl -aminiupnpd -sr
pass in log quick on fxp1 inet proto udp from any to any port = 6881 keep state label "Azureus UPnP 6881 UDP"
pass in log quick on fxp1 inet proto tcp from any to any port = 6881 keep state label "Azureus UPnP 6881 TCP"

However status.php only shows

pfctl -sn
rdr-anchor "miniupnpd" all

pfctl -sr
anchor "miniupnpd" all
block drop in quick all label "Default block all just to be sure."
block drop out quick all label "Default block all just to be sure."

Jonb

I did have this problem with RC3 as well but I did an uninstall reboot and install then a reboot and that has seemed to wrok

databeestje

I have not researched it yet, but it does seem like it is starting the package twice. It's probably not checking if it is started allready. or something along those lines.

With regards to the port mapping missing, I have no clue whatsoever.

rsw686

@databeestje:

I have not researched it yet, but it does seem like it is starting the package twice. It's probably not checking if it is started allready. or something along those lines.

With regards to the port mapping missing, I have no clue whatsoever.

Okay wanted to give some more information on this. Miniupnpd works now. I had to click change on the miniupnpd settings page and then clear and the status page. This seemed to kill both processes and get it started correctly. The rules are working and Azereus passes the firewall test. The firewall log fills with accepted packets. As you can see below both running instances closed out.

Oct 4 02:24:42 miniupnpd[1319]: Unknown soap method
Oct 4 02:24:38 miniupnpd[1298]: received signal 15, exiting
Oct 4 02:24:35 miniupnpd[804]: received signal 15, exiting

There is defiantly 2 instances of minupnpd being started. Happens everytime I reboot. Looks at the log below. It resyncs the package configuration twice and on the 2nd time miniupnpd fails because it is already started. Not only does it do the package resync twice but the RRD graphs and some other items as well. This all appeared after the 09-27-06 snapshot. First showed up in RC3 and still around in RC3b, which is what I'm running.

Oct 4 02:23:11 check_reload_status: reloading filter
Oct 4 02:23:11 miniupnpd[1010]: Failed to open socket for SSDP. EXITING
Oct 4 02:23:11 miniupnpd[1010]: bind(udp): Address already in use
Oct 4 02:23:10 php: : Resyncing configuration for all packages.
Oct 4 02:23:05 php: : Creating rrd graph index
Oct 4 02:23:05 php: : Creating rrd update script
Oct 4 02:23:05 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 68.100.53.135.
Oct 4 02:22:58 login: login on console as root
Oct 4 02:22:48 sshlockout[840]: sshlockout starting up
Oct 4 02:22:48 sshlockout[840]: sshlockout starting up
Oct 4 02:22:48 login: login on console as root
Oct 4 02:22:39 dnsmasq[579]: reading /var/dhcpd/var/db/dhcpd.leases
Oct 4 02:22:37 check_reload_status: rc.newwanip starting
Oct 4 02:22:37 check_reload_status: check_reload_status is starting
Oct 4 02:22:37 last message repeated 4 times
Oct 4 02:22:36 miniupnpd[804]: Unknown soap method
Oct 4 02:22:34 php: : Resyncing configuration for all packages.
Oct 4 02:22:30 dhcpd: For info, please visit http://www.isc.org/sw/dhcp/
Oct 4 02:22:30 dhcpd: All rights reserved.
Oct 4 02:22:30 dhcpd: Copyright 2004-2006 Internet Systems Consortium.
Oct 4 02:22:30 dhcpd: Internet Systems Consortium DHCP Server V3.0.4
Oct 4 06:22:29 php: : Creating rrd graph index
Oct 4 06:22:29 php: : Creating rrd update script
Oct 4 06:22:29 php: : Create RRD database /var/db/rrd/wan-quality.rrd
Oct 4 06:22:29 php: : Create RRD database /var/db/rrd/wan-packets.rrd
Oct 4 06:22:29 php: : Create RRD database /var/db/rrd/wan-traffic.rrd
Oct 4 06:22:28 php: : Create RRD database /var/db/rrd/lan-packets.rrd
Oct 4 06:22:28 php: : Create RRD database /var/db/rrd/lan-traffic.rrd
Oct 4 02:22:28 dnsmasq[579]: reading /var/dhcpd/var/db/dhcpd.leases

rsw686

I dug into this further. Due to the following added changelogs miniupnpd starts three times.

[14721] Add rc.start_packages file
[14722] Use /etc/rc.start_packages

Firstly, the packages are being synced twice evident in dmesg and the logs where RRD is starting twice and then the below code in miniupnpd.inc starts the package. Then the rc.start_packages files starts it a third time.

start_service("miniupnpd");
restart_service("miniupnpd");

In my previous posts look at the process ids. There are three different ones.

Oct 4 02:24:38 miniupnpd[1298]: received signal 15, exiting
Oct 4 02:24:35 miniupnpd[804]: received signal 15, exiting
Oct 4 02:23:11 miniupnpd[1010]: bind(udp): Address already in use
Oct 4 02:22:36 miniupnpd[804]: Unknown soap method

sullrich

I just fixed these issues. Please reinstall the miniupnpd package.

rsw686

@sullrich:

I just fixed these issues. Please reinstall the miniupnpd package.

Thanks alot. The changes work great.

databeestje

miniupnpd version 20060930 commited, reinstall package to get to it.

Cheers.

rsw686

@databeestje:

miniupnpd version 20060930 commited, reinstall package to get to it.

Cheers.

Wow …

Oct 5 17:09:05 last message repeated 23845 times
Oct 5 17:08:34 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:34 miniupnpd[1359]: recv (state0): Connection reset by peer
Oct 5 17:08:34 last message repeated 5583 times
Oct 5 17:08:27 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:27 miniupnpd[1359]: recv (state0): Connection reset by peer

Is this a new error or is the error just being displayed now. It has completely filled my system log in 15 min. Also the firewall log still fills with accepted packets.

sullrich

@rsw686:

Wow …

Oct 5 17:09:05 last message repeated 23845 times
Oct 5 17:08:34 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:34 miniupnpd[1359]: recv (state0): Connection reset by peer
Oct 5 17:08:34 last message repeated 5583 times
Oct 5 17:08:27 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:27 miniupnpd[1359]: recv (state0): Connection reset by peer

Is this a new error or is the error just being displayed now. It has completely filled my system log in 15 min. Also the firewall log still fills with accepted packets.

What is UPNP communicating with? XBOX?

rsw686

@sullrich:

@rsw686:

Wow …

Oct 5 17:09:05 last message repeated 23845 times
Oct 5 17:08:34 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:34 miniupnpd[1359]: recv (state0): Connection reset by peer
Oct 5 17:08:34 last message repeated 5583 times
Oct 5 17:08:27 miniupnpd[1359]: Unsupported HTTP Command SUBSCRIBE
Oct 5 17:08:27 miniupnpd[1359]: recv (state0): Connection reset by peer

Is this a new error or is the error just being displayed now. It has completely filled my system log in 15 min. Also the firewall log still fills with accepted packets.

What is UPNP communicating with? XBOX?

Nope I just had Azereus open. Just like in the past with the older version. This is a clean RC3 install with a,b,c patches and the miniupnpd package.

sullrich

Ruh roh. Looks like the new miniupnpd binary has added a regression then.

rsw686

@sullrich:

Ruh roh. Looks like the new miniupnpd binary has added a regression then.

I'd say so. I loaded the old binary version back and the error is gone.

hoba

Embedded users interested in this package have a look at http://forum.pfsense.org/index.php/topic,1788.msg13490.html#msg13490 :)

KiaN

Upgraded and …

Oct 4 08:09:40 	miniupnpd[1423]: Unknown soap method
Oct 4 08:25:08 	miniupnpd[1423]: Unknown soap method
Oct 4 08:47:17 	miniupnpd[1423]: Unknown soap method
Oct 4 09:26:39 	miniupnpd[1423]: Unknown soap method

hoba

Looks like something is dirty if it needs soap… ;D

rsw686

From my post referenced above about adding miniupnpd on embedded.

http://forum.pfsense.org/index.php/topic,1788.msg13498.html#msg13498

Miniupnpd uses the miniupnp.sh script to start the service. This file contains your ip address and nic interface hardcoded. Not a big deal as the sync_package_miniupnpd() recreates it. However it doesn't seem to run this when syncing packages at startup. I looked in the code and it looks like the miniupnpd.xml file should have a custom_php_resync_config_command section which calles sync_package_miniupnpd(). I think the thought was that once its configured theres really no need to keep recreating the same startup file.

Shouldn't the below be added to the miniupnpd.xml file so the package is resynced at startup. Wouldn't hardly add any extra time to boot and would insure the package is configured properly.

<custom_php_resync_config_command>sync_package_miniupnpd();</custom_php_resync_config_command>

I could be wrong but I looked into the pfsense-utils.inc file and don't see how this would get called without the above xml section.