UPnP support

databeestje

That's weird. Cause it works for me.

sullrich

There definately is some race conditions present in miniupnpd:

82817 root 1 130 0 1892K 416K RUN 544:53 44.78% miniupnpd

I should note that nothing is even using it right now!

Superman

I just happened to be quickly browsing the miniupnpd homepage, and noticed that this updated source is now available: miniupnpd20060930.tar.gz.

Here's the changelog since 20060919:

2006/09/29:
  Improved compliance of the XML Descriptions
  pretty print for testupnpdescgen

2006/09/25:
  improved the Error 404 response.
  Better serviceType and serviceId for dummy service...

2006/09/24:
  updating the XML description generator

Just in case anyone needed this info.

I would like to compile the binary and try it out myself, but not being a developer I don't know exactly how to go about it. I tried the few things I know but I couldn't get it to compile properly.

rsw686

Well miniupnpd is broken in RC3 now. I installed it clean and the package and I get this error in the log.

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.

Anything changed that would affect this between the 09-27-06 snapshot and RC3. It worked then just fine.

ollopa

@rsw686:

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.