[uPnP] Problem with uPnP, adding forward: router stops forwarding

[TRaNe]

Hi,

I've been using the D-Link 614+ router until last weekend. Bought my self a WL-500g, configured(enabled UPNP) it and replaced the D-Link. Now i'm not able to do a audio conversation through MSN Messenger any more... Does this mean that the Asus isn't completly UPNP compatible?

best regards
TRaNe

[rej]

Hi all

I was trying to set up at webserver at a local PC, and I wanted to make it available on the internet.

I then used the uPnP functionality in order not to have to reboot the router, to open the port 80 (under control panel -> network connections there is a link to the gateway, here it is possible to set up the same as in the virtual server page on the routers homepage). This resulted in that I could not access the internet at all!

Of course I tried to open the port directly on the router, and here it worked fine!

This leads me to believe that there is a bug in the uPnP implementation on the router. Looking at the port forwarding page under status an log showed me this:

129.112.214.229 tcp 80 192.168.1.2
anywhere tcp 81 192.168.1.2:81

The first line is port 80 forwarding set up on the router, whereas the second line shows the forwarding of port 81 from the uPnP interface (note, I changed the IP address for security reasons).

Should they not look the same?

I hope somebody can shed some light on this.

BR,
René

[Antiloop]

just received this message:



Dear ...,

Attachment is the beta version of firmware for WL-500g and please upload to WL-500g and have a test on the problem.

B.R.

attached: WL-500g FW 1.7.5.7-beta.zip


i'll upload this tonight to the chupa server as I am at work now

[Technik]

just received this message:



Dear ...,

Attachment is the beta version of firmware for WL-500g and please upload to WL-500g and have a test on the problem.

B.R.

attached: WL-500g FW 1.7.5.7-beta.zip


i'll upload this tonight to the chupa server as I am at work now

Wow! What a good news! ;) But I am afraid it won't be better than current Oleg's customized FW... We will see... I am waiting for the Client mode support in web configurator and for newer OV511 webcam driver... :)

[Antiloop]

hmm.. weird log after updating:

Jan 1 01:00:22 dhcp client: deconfig: lease is lost
Jan 1 01:00:22 alarm: UDP connection access to xxx.xxx.xxx.xxx:68 from 213.46.108.65:67
Jan 1 01:00:22 alarm: UDP connection access to xxx.xxx.xxx.xxx:68 from 213.46.108.65:67
Jan 1 01:00:25 dhcp client: bound IP address xxx.xxx.xxx.xxx from server 212.142.28.181
Jan 1 01:00:25 alarm: TCP connection access to xxx.xxx.xxx.xxx:1413 from 217.67.235.13:110
Apr 27 20:16:00 FTP server: daemon is started
Apr 27 20:16:01 alarm: TCP connection access to xxx.xxx.xxx.xxx:113 from 217.67.235.13:45758
Apr 27 20:16:02 alarm: TCP connection access to xxx.xxx.xxx.xxx:1413 from 217.67.235.13:110
Apr 27 20:16:02 init: device '/dev/tty4' does not exist.
Apr 27 20:16:02 init: device '/dev/tty3' does not exist.
Apr 27 20:16:02 init: device '/dev/tty2' does not exist.
Apr 27 20:16:02 init: Process '-/bin/sh' (pid 849) exited. Scheduling it for restart.
Apr 27 20:16:03 init: Process '-/bin/sh' (pid 848) exited. Scheduling it for restart.
Apr 27 20:16:04 alarm: TCP connection access to xxx.xxx.xxx.xxx:113 from 217.67.235.13:45758
Apr 27 20:16:04 init: Process '-/bin/sh' (pid 865) exited. Scheduling it for restart.
Apr 27 20:16:04 init: device '/dev/tty2' does not exist.
Apr 27 20:16:05 init: Process '-/bin/sh' (pid 866) exited. Scheduling it for restart.
Apr 27 20:16:06 init: Process '-/bin/sh' (pid 867) exited. Scheduling it for restart.
Apr 27 20:16:06 init: device '/dev/tty2' does not exist.
Apr 27 20:16:07 NTP client: time is synchronized to 131.107.1.10
Apr 27 20:16:07 init: Process '-/bin/sh' (pid 876) exited. Scheduling it for restart.
Apr 27 20:16:08 init: Process '-/bin/sh' (pid 884) exited. Scheduling it for restart.
Apr 27 20:16:08 init: device '/dev/tty2' does not exist.
Apr 27 20:16:09 init: Process '-/bin/sh' (pid 885) exited. Scheduling it for restart.
Apr 27 20:16:10 alarm: TCP connection access to xxx.xxx.xxx.xxx:113 from 217.67.235.13:45758
Apr 27 20:16:10 init: Process '-/bin/sh' (pid 886) exited. Scheduling it for restart.
Apr 27 20:16:10 init: device '/dev/tty2' does not exist.
Apr 27 20:16:12 init: Process '-/bin/sh' (pid 911) exited. Scheduling it for restart.
Apr 27 20:16:13 alarm: TCP connection access to xxx.xxx.xxx.xxx:1376 from 207.46.107.68:1863
Apr 27 20:16:13 alarm: TCP connection access to xxx.xxx.xxx.xxx:1376 from 207.46.107.68:1863
Apr 27 20:16:13 init: Process '-/bin/sh' (pid 891) exited. Scheduling it for restart.
Apr 27 20:16:14 alarm: TCP connection access to xxx.xxx.xxx.xxx:1376 from 207.46.107.68:1863
Apr 27 20:16:15 init: Process '-/bin/sh' (pid 922) exited. Scheduling it for restart.
Apr 27 20:16:15 init: device '/dev/tty2' does not exist.
Apr 27 20:16:16 init: Process '-/bin/sh' (pid 923) exited. Scheduling it for restart.
Apr 27 20:16:16 alarm: TCP connection access to xxx.xxx.xxx.xxx:1376 from 207.46.107.68:1863


and so on..

[Antiloop]

find firmware 1.7.5.7 beta below to download.

http://files.wl500g.info/asus/wl500g/firmware/beta/WL-500g%20FW%201.7.5.7-beta.zip

TRY THIS ONLY AT YOUR RISK.

i don't know if uPnP behaves always like this,
see attached.. routers stays alive

i've choosen port 81 because when i fill in port 80 i can't access internet pages anymore (i get my printer page instead)

[Antiloop]

oh and last but not least, i cannot access port 81 (or 80) from WAN

(note i'm not doing this local as I have 2 Internet connections available)

AARGH.. that line was dead.. have to test over :P

[rej]

What does that specific entry say on the Status & Log -> Port Forwarding Page?

BR,
René

[rej]

OK, I guess you cannot see that for entries to port 80, since this may block all web traffic including traffic to the router page. But can you make an entry with a port forward of e.g. port 5000 to one of your local PC's and check out the entry on the Status & Log -> Port Forwarding page on the router?

Thanks,
René

[copycat]

Any interesting new stuff in the beta driver?

[Antiloop]

Destination Prot. Port Range Redirect to
212.86.124.11 tcp 8082 192.168.0.1:80
212.86.124.11 tcp 8082 192.168.0.1:80
212.86.124.11 tcp 3389 192.168.0.254
anywhere tcp 81 192.168.0.100:80
anywhere tcp 11977 192.168.0.3:2437

ok.. i can access port 81 from my other internet connection (be sure it's up when testing :o )

ok.. everything went well, router is still functioning normal

the only disadvantage there is I think, is that it assigns ANYWHERE to it..
it should not be necessary, because an entry just like the other 3 (1 virtual server, the other 2(?) are for my WAN setup) would be fine
then it would not cause that websites aren't reachable when you add port 80 via uPnP..

tell me your thougths soon please, for a fast reply I have to mail in the morning to Asus then they are still at work.

note: the IP shown is not my real ip.

[Antiloop]

Any interesting new stuff in the beta driver?


hehe you would not believe what's in :D (pointing to Oleg)
but they are using some parts of CR2

nice to see they are 'learning' and adding good improvements to the standard firmware for the normal users

[rej]

the only disadvantage there is I think, is that it assigns ANYWHERE to it..
it should not be necessary, because an entry just like the other 3 (1 virtual server, the other 2(?) are for my WAN setup) would be fine
then it would not cause that websites aren't reachable when you add port 80 via uPnP..

tell me your thougths soon please, for a fast reply I have to mail in the morning to Asus then they are still at work.
That is my thought as well. What it says is that request for ANYWHERE on port 80 goes to the specific internal IP address. This means that a request for www.google.com from the LAN is redirected to the specified IP. That can't possible be the way it is supposed to work (at least that is not the way my old Dlink router and Fujitsu Siemens router works).

The lucky thing is that for e.g. Messenger this issue shouldn't be an issue, since it uses random ports, meaning that only in the extremely unlucky situation if two messenger clients are using the same port there will be a problem.

Anyway, please mail your contact in Asus with our observations, then I am sure they will se the problem. I am not a programming expert, but I would expect that replacing "ANYWHERE" with the WAN IP shouldn't be that hard.

Thanks for your support on this!
BR,
René

[Antiloop]

okay..

this test still continues ofcourse

the UPnP still has not been fixed in firmware 9.8.1.2

it still behaves like in firmware 1.7.5.7

[Antiloop]

UPnP ISSUE IS SOLVED

DOWNLOAD LATEST FIRMWARE TO FIX THIS (1.8.1.3 OR HIGHER)

find it here
579

[i-beast-a]

Hi,

I've enabled upnp on my router so when I started a piece of software on one of my pc's it automatically set a port-forwarding rule in my WL500g.

But now I want to remove this rule in my router. I've disabled Upnp but the rule is still in the "port forwarding" - list.

How do I remove this???

I use firmware 1.9.2.7.

Everything else works perfect!!!

[i-beast-a]

no one who can help???

[WlanMan]

Hi

I dont use upnp so i habe none of this leftover rules, but i read asus now saves upnp into nvram for next boot. Possible that they dont remove this if you deactivate upnp from the Web (Oleg ? :)).

I think, you can a: Reset to defaults and set it up again, b: use new 1.9.2.7-1 custom FW and delete the nvram parameters by hand.

I looked into my nv space.
do a
nvram show | grep vts_ on the telnet console, this should show you all saved routing rules, for me my self defindet, and hopefully also your upnp-addet ones. you can then carefully delete all entrys which have the number of the rule you want to remove, eg. all which ends with "X3" (use the number here you want).

Example:

vts_port_x0=49152
vts_protono_x0=
vts_desc_x0=Bittorrent
vts_proto_x0=BOTH
vts_ipaddr_x0=192.168.1.10
See nvram commands how to do this.

Greets

[i-beast-a]

thanx for the reply!

starting all over from scratch was ofcourse also the option that I kept in mind :D

I will go over to the modified firmware because there is a real bug in this one.

My router completely resets after 10 minutes of web-radio.....
The rest of this firmware is fine.

greatingz from holland...

[i-beast-a]

@Wlanman:
I've switched over to the custom firmware without removing the settings. Also the Upnp port forwarding is still there.

But if I log in with telnet, I only see the rules that I've made myself!

The rules that are generated by upnp are not in this list :confused: :confused: :confused: :confused:

any advice?????????

[Styno]

Weird router behaviour after a firmware upgrade is mostly caused by improper upgrading.

You might want to try to 'reset to defaults' by pressing the button on the back for more then 10 seconds while the power is still applied to the router. After this reset you need to fill in the configuration again WITHOUT uploading an old configuration file. You need to do it through the webinterface by hand.

Most likely the router reset and uPnP problems will be over after you've done this.

[i-beast-a]

Hi,

I've done all that!
everything worked fine until I installed software on my pc which opened a port via Upnp. This worked fine but now i want to remove these rules again.

So it has nothing to do with upgrading......

How do I remove rules that are automatically created by upnp???

Resetting and starting all over is ofcourse possible.....but that is the easy way :D

[Oleg]

Disable upnp and reboot your router.

[i-beast-a]

that is exactly the problem!

I've disabled upnp and restarted....but the rules are still there!

[Styno]

So, do it again: Restore factory defaults and set your settings again. This time disable UPnP too BEFORE you start the app in Windows.

[barsju]

Hi, I runnig wl500g behind a adsl modem (Netopia 3351) from my ISP. Both devices has UPnP enabled, and when I connect directly to my adsl modem I can start a video chat session. But when I plug in my wl500g I cant get it to work. I have tried to put my pc in dmz but with no luck. I run iptraf and can see that there is some hectic tcp activity with some MS servers, and at one point I could actually see some UDP pacets from my buddy to my pc. But today I can't even get that.

Any ideas? Need more info? All help appreciated!

Sjur

PS: Running Oleg FW 1.9.2.8c CR3

[MrMagu]

Sounds like you have "double nating". Do you really need that? Set the Netopia router in bridge mode and let the ASUS handle the firewalling.

[barsju]

Ok, so how do I do that? :) My ISP is nextgentel and my adsl modem is Netopia 3351 (fw 8.3.3r1). I have found a setting in the adsl modem that says Put device in bridge mode. I guess that is what I should try. But after I do that nothing works, and I can't connect to the modem and have to reset it. So I guess I need to configure wl500g a bit too? What should the WAN setting be for the router? And how do I get the IP and routing info? I have dynamic IP.

As I share my connection with some neighbours I can't mess around with it to much, so hopefully I can get some answers here before I try again..

Sjur

[MrMagu]

Check Nextgentel support pages? You can't be the only one with this problem.

Or try this:
http://www.satszene.ch/hb9dww/echolink%20faq/bridge_netopia%203341-3351.htm

Disclaimer: I neither have Netopia router or Nextgentel.

[barsju]

Sigh. I was kinda hoping you had NGT.. You being Norwegian and all.. OH well. But what I am really more interested in is if I need to make any changes in my wl500g? What should the WAN settings be? Still automatic ip? As there probably isn't anyone with my exact problem, maybe someone can make a qualified guess?

Sjur

[Spot]

Sigh. I was kinda hoping you had NGT.. You being Norwegian and all.. OH well. But what I am really more interested in is if I need to make any changes in my wl500g? What should the WAN settings be? Still automatic ip? As there probably isn't anyone with my exact problem, maybe someone can make a qualified guess?

Sjur

If you set your modem in bridge mode, your router must handle some new stuff/parameters like connection type and so on...

1. Shut down your modem...

2. I suggest you to set wl500g in gateway mode and launch a quick setup first... Take also a look at dhcp section and enable it.

3. Reboot your router...

4. And finaly start your modem!

This should work :)

[Spot]

@ barsju...

Some more infos about my own experience using msn messenger:

Regardless firewall and upnp settings, everithing works fine except audio features! The only way I can get it work is when I connect to some one who use the same MSN version as me... 7 beta.

[barsju]

Still having tourble with this. Has anyone got msn videochat running through wl500g?

Now I have swithced on IP-Passthrough feature on the wl500g, and that works fine. But I still cannot get msn videochat to work through the wl500g. I can how ever make it work when I bypass the wl500g and connect my pc directly to the modem.

I have watched what happens with iptraf and I can see:
- UDP packets to 255.255.255.255 on port 1900 (MSN UPnP discovery)
- UDP packets to and from local ip and peers-ip on typical upnp port.
- UDP packets to and from external ip to peers ip on typical upnp port.

So that should indicate that the outgoing packets actually go through the router but gets blocked by the modem, as my peer does not receive any packets form me. But then again, when I try without the router it works, indicating that the problem lies within the router...

Anyone have any ideas on how to find out where the problem really is? Or any other ideas on how to fix this? I read a review of wl500gx that said that it had bad/non functioning UPnP support and that they couldn't get MSN to work through it, and that the ports that were opened did not get closed. Is this true, and has it been fixed in custom firmware?

S

PS: I have of course tried other video chat software, but I don't have a standard webcam but a camcorder with a webcam function. Problem is that the webcam/usb driver is real crap and it only works with msn.

[barsju]

Because of a feature/bug UPnP ports never gets closed on the wl500g. When they are opened the entries are stored in nvram so they will even survive a reboot. So if you have opened and used UPnP at one point there might be open ports in your firewall. An easy way to remove them is to reset to factory default. If that is not an option you can clear them from nvram.

Here is how you do that:

First check for unwanted forwarding rules in iptables:

iptables -L FORWARD

If there are open ports that you can't account for they are likely caused by UPnP. Now check nvram for those entries:

nvram show | grep "forward_port"

If you find entries there you can remove them one by one like this:

nvram unset forward_portX
where X is for the rule number (ex. forward_port0)

I have also written this script to help to remove a number of rules:


#!/bin/sh
tlr=$1
while [ $tlr -le $2 ]
do
nvram unset forward_port$tlr
tlr=`expr $tlr + 1`
done

It takes to and from rule number as parameters. You can run f.eks like this:

./clearUPnP 0 10
which will clear rules from 0 to 10.

If someone would like to write a script that will clear all forward_port rules on boot, that would be a nice extension. Unless of course Asus or Oleg change this behaviour in comming FW releases.

S.
Edit: Don't forget to
nvarm commit before you reboot!

[barsju]

I guess this script would also do the trick:


#!/bin/sh
for line in `nvram show | grep "port_forward" | sed "s/ //"`
do
i=`expr index $line "="`
let i=i-1
rule=`expr substr $line 1 $i`
nvram unset $rule
done


It should remove all rules that starts with "port_forward", and can for instance be started from post-boot, to remove all UPnP ports upon reboot of router.

Haven't really tested it properly as I have already removed the entries from nvram, so use at own risk! I can suggest replacing the last line in the loop with:

echo "nvram unset $rule"
to make sure you don't get any unexpected behaviour, before you run it for real.

S.

[tomilius]

There's no forum for bugs so once again I'm just making this problem known here (in case people don't already know). I didn't find it specifically when searching but maybe I'm just no good at searching... Now that I'm into compiling and such I'm going to compile upnp in debug mode and try to isolate the issue.

For me, upnp will die after x amount of time. That's all I know for now. Azureus lets me know, and I set up crond to restart it when it's gone and log in such a case, and it's true that it is dying. I'll try to figure it out and post results here.

[Spot]

Happy to read this... before, I've though that my windows settings were bad.

I've noticed this issue by the way that "asus gateway device icon" disappear from the list of upnp devices in winxp!

But I've also noticed that the icon shows up again after a while, and so on...
so I guess wl500g auto-restart the process when killed.

This seems to happend with all fw versions that I've tried since 1.6.x.x

[tomilius]

I've set up crond to run a preservation script every minute in order to make sure important processes are running. "watchdog" is supposed to do this but I'm not sure it always does... Maybe it just takes longer. Anyway, here's what my preservation script put out:
05/03/05 12:06:01PM upnp: restarting
05/03/05 12:19:02PM upnp: restarting
05/03/05 12:23:02PM upnp: restarting
05/03/05 12:30:01PM upnp: restarting
05/03/05 12:37:01PM upnp: restarting
05/03/05 12:47:01PM upnp: restarting
05/03/05 1:00:02PM upnp: restarting
05/03/05 1:07:02PM upnp: restarting
05/03/05 1:14:01PM upnp: restarting
05/03/05 1:21:01PM upnp: restarting
05/03/05 1:28:01PM upnp: restarting
...
05/03/05 3:13:01PM upnp: restarting
05/03/05 3:20:01PM upnp: restarting

A lot of that, of course, looks like it's happening every 7 minutes. It may be crashing due to the request of some application for me, though it should never crash like that anyway. It's annoying. I'm actually using the latest version of upnp too now (the one from 1.9.4.0 beta). So no solution there.

[tomilius]

Well, I ran upnp with strace...
Here's how it ends:

...
sendto(4, "NOTIFY * HTTP/1.1 \r\nHOST: 239.25"..., 329, 0, {sa_family=AF_INET, sin_port=htons(1900), sin_addr=inet_addr("239.255.255.250")}, 16) = 329
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
--- SIGUSR1 (Stack fault) @ 0 (0) ---
write(1, "upnp reinitialize.\n", 19upnp reinitialize.
) = 19
close(4) = 0
close(3) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
ioctl(3, 0x8915, 0x7fff79e8) = 0
close(3) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(3, {sa_family=AF_INET, sin_port=htons(5431), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
listen(3, 10) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 4
ioctl(4, 0x8913, 0x7fff7980) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(4, {sa_family=AF_INET, sin_port=htons(1900), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
ioctl(4, 0x8933, {6, "br0"}) = 0
setsockopt(4, SOL_IP, IP_ADD_MEMBERSHIP, "\357\377\377\372\0\0\0\0\6\0\0\0", 12) = 0
setsockopt(4, SOL_IP, IP_MULTICAST_IF, [16885952], 4) = 0
setsockopt(4, SOL_IP, IP_MULTICAST_TTL, "\4", 1) = 0
rt_sigaction(SIGUSR1, {0x10000000, [], SA_SIGINFO|0x403104}, {0x10000000, [], SA_SIGINFO|0x403104}, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 940000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 940000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 940000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 940000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 940000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 930000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
close(4) = 0
close(3) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 910000}}) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 90000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 70000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
exit(0) = ?

Related source code:
upnp/igd/igd.c:

void sigusr1_handler(int i)
{
extern void reinit_lan_interface(struct iface *pif);
extern struct iface *global_lans;
struct iface *pif;

printf("upnp reinitialize.\n");
bump_generation();

for (pif = global_lans; pif; pif = pif->next)
reinit_lan_interface(pif);

/* re-install a signal handler for SIGUSR1 */
signal(SIGUSR1, sigusr1_handler);
}

Hmm. I'm not sure if this could be considered ironic, but it appears that perhaps watchdog itself is doing the killing of upnp. After all, it did die when my IP address was being renewed recently, despite the 7-minute deaths from before...

MORE:
rc/network.c:

void
wan_up(char *wan_ifname)
{
...
stop_upnp();
start_upnp();
...
}

rc/watchdog.c:

int ntp_timesync(void)
{
...
if (tm.tm_year>100) // More than 2000
{
sync_interval = (atoi(nvram_safe_get("ntp_interval_x")) ? : 2) * 360;
logmessage("ntp client", "Synchronizing time with %s...", nvram_safe_get("ntp_servers"));

stop_upnp();
start_upnp();
}
...
}
Apparently from what it says there (and through other stuff I've omitted), if the time has been synchronized once before and it's time to sync the time again, upnp will be stopped and started. So this means upnp stops and starts every 2 hours? Uh, ooh, ouch. Is that really necessary?

Also, I tried (with it running with strace) killing it using killall -USR1 upnp through another terminal...


...
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f0) = 0
close(6) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff7990) = 0
close(6) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f8) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 40000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 40000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)

That's what happened up to the next "SIGALRM" -- no exit.

[Oleg]

Who is sending SIGALRM to it?

[tomilius]

Well, itself, isn't it? I know very little about this stuff, but I'm guessing SIGALRM has something to do with timers... and it uses timers... (see upnp.c)

All this occurred over and over:

--- SIGALRM (Alarm clock) @ 0 (0) ---

rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f0) = 0
close(6) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff7990) = 0
close(6) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f8) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={2, 0}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={2, 0}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f0) = 0
close(6) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff7990) = 0
close(6) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f8) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 60000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 60000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8946, 0x7fff7998) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 110000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 110000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
time(NULL) = 1115260616
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 20000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 20000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
time(NULL) = 1115260616
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 810000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 810000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f0) = 0
close(6) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff7990) = 0
close(6) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f8) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 60000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 60000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8946, 0x7fff7998) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 940000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 930000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f0) = 0
close(6) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff7990) = 0
close(6) = 0
read(5, "\32\0\0\0", 13) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "J\0\0\0", 11) = 4
read(5, "\32\0\0\0", 13) = 4
read(5, "\303\0\0\0", 12) = 4
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, 0x8915, 0x7fff78f8) = 0
close(6) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={2, 0}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={2, 0}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(5, [3 4], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)

[Oleg]

check SIGALRM handler then, to check why it's bailing out.

[tomilius]

Well, it bails out if it receives an interrupt...


void interrupt_handler(int i)
{
// signal(SIGINT, SIG_DFL);
send_advertisements(SSDP_BYEBYE);
global_exit_now = TRUE;
}

... Most of the time, I think, it goes away because the DHCP lease has expired and is being renewed or the time is updating (code confirms, afaik, that it restarts under these circumstances). This might be a cheap and simple way to avoid having to rebuild firewall rules, but I probably don't know what I'm talking about here. I mean, maybe that's what it does to rebuild them.

[Oleg]

it appears, that this code handles SIGINT only...

[tomilius]

Uh, well, like I said, I know very little about this (I pretty much figured out that this "SIG" stuff existed a few weeks ago and haven't done anything involving it again until today). Here's everything related to SIGALRM in all of upnp:


static void block_alarm()
{
sigset_t set;

sigemptyset(&set);
sigaddset(&set, SIGALRM);
sigprocmask(SIG_BLOCK, &set, NULL);
}

static void unblock_alarm()
{
sigset_t set;

sigemptyset(&set);
sigaddset(&set, SIGALRM);
sigprocmask(SIG_UNBLOCK, &set, NULL);
}

Isn't SIGALRM a timer? That's just what I'd guess.

In int upnp_main:

memset(&timer, 0, sizeof(timer));
timer.it_interval.tv_sec = 30;
timer.it_value.tv_sec = 30;
td1 = enqueue_event(&timer, (event_callback_t)connection_reaper, NULL);

memset(&timer, 0, sizeof(timer));
timer.it_interval.tv_sec = 30;
timer.it_value.tv_sec = 30;
td2 = enqueue_event(&timer, (event_callback_t)gena_subscription_reaper, NULL);

memset(&timer, 0, sizeof(timer));
timer.it_interval.tv_sec = UPNP_REFRESH;
timer.it_value.tv_sec = UPNP_REFRESH;
td3 = enqueue_event(&timer, (event_callback_t)periodic_advertiser, (void *) SSDP_ALIVE);

The functions:
in upnp.c

static void connection_reaper(timer_t t, void *arg)
{
struct net_connection **pnet, *net;
time_t now;
int i = 0;

now = time(NULL);
pnet = &net_connections;
while (*pnet) {
i++;
if ((*pnet)->expires && (*pnet)->expires < now) {
net = *pnet;
*pnet = (*pnet)->next;
assert(net->func);
(*(net->func))(CONNECTION_DELETE, net, net->arg);
continue;
}
pnet = &((*pnet)->next);
}
}

in gena.c:


void gena_subscription_reaper(timer_t t, void *arg)
{
PDevice pdev;
PService psvc;
time_t now;

now = time(NULL);

forall_devices(pdev) {
forall_services(pdev, psvc) {
reap_service_subscriptions(psvc, now);
}
}
}


static void reap_service_subscriptions(PService psvc, time_t now)
{
PSubscription *ppsr, sr;
int i = 0;

ppsr = &(psvc->subscriptions);
while (*ppsr) {
i++;
if ((*ppsr)->expires && (*ppsr)->expires < now) {
UPNP_SUBSCRIBE(("Reaping subscription for %s.\n", psvc->template->name));
sr = *ppsr;
*ppsr = (*ppsr)->next;

free(sr->cb_host);
free(sr->cb_path);
free(sr);
continue;
}
ppsr = &((*ppsr)->next);
}
}

in ssdp.c

/* Should really call this twice to give the UDP packets a better chance of reaching their destination.
*/
static void advertise_device(PDevice pdev, ssdp_t sstype, struct iface *pif, struct sockaddr *addr, int addrlen)
{
UFILE *upkt;
PService psvc;
char tmpbuf[100], svctype[100];
const char *loc = location(pdev, pif);

// create a growable string UFILE.
if ((upkt = usopen(NULL, 0))) {

if (ISROOT(pdev)) {
snprintf(tmpbuf, sizeof(tmpbuf), "%s::upnp:rootdevice", pdev->udn);
ssdp_packet(
upkt, sstype, "upnp:rootdevice", tmpbuf,
loc, SSDP_REFRESH);
if (sendto(pif->ssdp_connection->fd, ubuffer(upkt), utell(upkt), 0, addr, addrlen) < 0)
UPNP_ERROR(("sendto failed at %s:%d - err %d\n", __FILE__, __LINE__, errno));
uflush(upkt); // reset the packet buffer before we build another.
}

// advertise device by UDN
ssdp_packet( upkt, sstype, pdev->udn, pdev->udn,
loc, SSDP_REFRESH);
if (sendto(pif->ssdp_connection->fd, ubuffer(upkt), utell(upkt), 0, addr, addrlen) < 0)
UPNP_ERROR(("sendto failed at %s:%d - err %d\n", __FILE__, __LINE__, errno));
uflush(upkt); // reset the packet buffer before we build another.

// advertise device by combination of UDN and type
snprintf(tmpbuf, sizeof(tmpbuf), "%s::%s", pdev->udn, pdev->template->type);
ssdp_packet( upkt, sstype, pdev->template->type, tmpbuf,
loc, SSDP_REFRESH);
if (sendto(pif->ssdp_connection->fd, ubuffer(upkt), utell(upkt), 0, addr, addrlen) < 0)
UPNP_ERROR(("sendto failed at %s:%d - err %d\n", __FILE__, __LINE__, errno));
uflush(upkt); // reset the packet buffer before we build another.

// advertise the services...
for (psvc = pdev->services; psvc; psvc = psvc->next) {
snprintf(svctype, sizeof(svctype), "urn:%s:service:%s", psvc->template->schema, psvc->template->name);
snprintf(tmpbuf, sizeof(tmpbuf), "%s::%s", pdev->udn, svctype);

ssdp_packet( upkt, sstype, svctype, tmpbuf,
loc, SSDP_REFRESH);

if (sendto(pif->ssdp_connection->fd, ubuffer(upkt), utell(upkt), 0, addr, addrlen) == -1)
UPNP_ERROR(("sendto failed at %s:%d - err %d\n", __FILE__, __LINE__, errno));
uflush(upkt); // reset the packet buffer before we build another.
}

// release the growable string UFILE.
uclose(upkt);
}

}

void periodic_advertiser(timer_t t, ssdp_t sstype)
{
send_advertisements(sstype);
}

/* Construct the multicast address and send out the appropriate device advertisement packets. */
void send_advertisements(ssdp_t sstype)
{
struct sockaddr_in addr;
struct iface *pif;
PDevice pdev;

addr.sin_family = AF_INET;
addr.sin_addr.s_addr = inet_addr(SSDP_IP);
addr.sin_port = htons(SSDP_PORT);

for (pif = global_lans; pif; pif = pif->next) {
forall_devices(pdev) {
advertise_device(pdev, sstype, pif, (struct sockaddr *)&addr, sizeof(addr));
}
}
}

That's about everything I can find even slightly related, and all I'm looking for is some kind of "dropping out." I don't completely understand the strace result differences from it dropping out after SIGUSR1 and it not dropping out, but I think it's all related to the internal stop/start commands in network.c of rc and the other places... (resets on time update, resets on wan change).

See, I don't exactly understand why under these circumstances I'd ever see anything in my logs (about upnp not being found running and having to be started by my crond script) or why it would ever not be running since it's reset, not stopped... at least, that's the way it's supposed to be... but, eh.

[tomilius]

I think I was wrong. I've acquired new information, and I believe the strace logs I've placed previously were not the results of the crashing, just of the harmless resetting. However, it does crash as well.


...
) = -1 ETIMEDOUT (Connection timed out)
close(9) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 700000}}, NULL) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 700000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
sigreturn() = ? (mask now [RT_37 RT_38 RT_39 RT_41 RT_45 RT_50 RT_61])
read(6, "SUBSCRIBE /uuid:0011d81b-f83e-00"..., 399) = 354
time(NULL) = 1115528116
read(5, "\312\3\0\0", 11) = 4
read(5, "\312\3\0\0", 11) = 4
time(NULL) = 1115528116
write(6, "HTTP/1.1 200 OK\r\nServer: LINUX/2"..., 129) = -1 ECONNRESET (Connection reset by peer)
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
getitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 650000}}) = 0
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
recvfrom(4, "NOTIFY * HTTP/1.1 \r\nHOST: 239.25"..., 2500, 0, {sa_family=AF_INET, sin_port=htons(1900), sin_addr=inet_addr("192.168.1.1")}, [16]) = 351
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(9, [3 4 6 8], NULL, NULL, NULL) = 4 (in [3 4 6 8])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(8, "UNSUBSCRIBE /uuid:0011d81b-f83e-"..., 399) = 304
time(NULL) = 1115528116
time(NULL) = 1115528116
time(NULL) = 1115528116
open("/etc/TZ", O_RDONLY) = 9
read(9, "PST8PDT\n", 68) = 8
read(9, "", 60) = 0
close(9) = 0
write(8, "HTTP/1.1 200 OK\r\nDATE: Sun, 08 M"..., 186) = -1 ECONNRESET (Connection reset by peer)
write(8, "", 0) = 0
read(6, "", 399) = 0
close(6) = 0
close(6) = -1 EBADF (Bad file descriptor)
recvfrom(4, "NOTIFY * HTTP/1.1 \r\nHOST: 239.25"..., 2500, 0, {sa_family=AF_INET, sin_port=htons(1900), sin_addr=inet_addr("192.168.1.1")}, [16]) = 383
accept(3, {sa_family=AF_INET, sin_port=htons(3772), sin_addr=inet_addr("192.168.1.12")}, [16]) = 6
time(NULL) = 1115528116
fcntl(6, F_GETFL) = 0x2 (flags O_RDWR)
ioctl(6, TIOCNXCL, 0x7fff7be0) = -1 EINVAL (Invalid argument)
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(9, [3 4 6 8], NULL, NULL, NULL) = 4 (in [3 4 6 8])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(6, "UNSUBSCRIBE /uuid:0011d81b-f83e-"..., 399) = 312
time(NULL) = 1115528116
time(NULL) = 1115528116
time(NULL) = 1115528116
open("/etc/TZ", O_RDONLY) = 9
read(9, "PST8PDT\n", 68) = 8
read(9, "", 60) = 0
close(9) = 0
write(6, "HTTP/1.1 200 OK\r\nDATE: Sun, 08 M"..., 186) = -1 ECONNRESET (Connection reset by peer)
write(6, "", 0) = 0
read(8, "", 399) = 0
close(8) = 0
close(8) = -1 EBADF (Bad file descriptor)
recvfrom(4, "NOTIFY * HTTP/1.1 \r\nHOST: 239.25"..., 2500, 0, {sa_family=AF_INET, sin_port=htons(1900), sin_addr=inet_addr("192.168.1.1")}, [16]) = 312
accept(3, {sa_family=AF_INET, sin_port=htons(3259), sin_addr=inet_addr("192.168.1.11")}, [16]) = 8
time(NULL) = 1115528116
fcntl(8, F_GETFL) = 0x2 (flags O_RDWR)
ioctl(8, TIOCNXCL, 0x7fff7be0) = -1 EINVAL (Invalid argument)
rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 16) = 0
_newselect(9, [3 4 6 8], NULL, NULL, NULL) = 3 (in [4 6 8])
rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 16) = 0
read(8, "GET /dynsvc/WANCommonInterfaceCo"..., 399) = 245
time(NULL) = 1115528116
open("/dev/null", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 9
ioctl(9, TIOCNXCL, 0x7fff7950) = -1 ENOTTY (Inappropriate ioctl for device)
write(9, "<?xml version=\"1.0\"?>\r\n<scpd xml"..., 256) = 256
write(9, "essType</name>\r\n<relatedStateVar"..., 256) = 256
write(9, "</direction>\r\n</argument>\r\n<argu"..., 256) = 256
write(9, "teVariable>PhysicalLinkStatus</r"..., 256) = 256
write(9, "sSent</relatedStateVariable>\r\n<d"..., 256) = 256
write(9, "edStateVariable>\r\n<direction>out"..., 256) = 256
write(9, "eVariable>\r\n<direction>out</dire"..., 256) = 256
write(9, "tion>out</direction>\r\n</argument"..., 256) = 256
write(9, "\n <allowedValue>POTS</allow"..., 256) = 256
write(9, "ayer1UpstreamMaxBitRate</name>\r\n"..., 256) = 256
write(9, "atus</name>\r\n <dataType>string<"..., 256) = 256
write(9, "edValueList>\r\n</stateVariable>\r\n"..., 256) = 256
write(9, "le>\r\n<stateVariable sendEvents=\""..., 256) = 256
write(9, "=\"no\">\r\n <name>TotalPacketsRece"..., 122) = 122
close(9) = 0
time(NULL) = 1115528116
open("/etc/TZ", O_RDONLY) = 9
read(9, "PST8PDT\n", 68) = 8
read(9, "", 60) = 0
close(9) = 0
write(8, "HTTP/1.0 200 OK\r\nSERVER: LINUX/2"..., 199) = -1 ECONNRESET (Connection reset by peer)
write(8, "HTTP/1.0 200 OK\r\nSERVER: LINUX/2"..., 256) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
+++ killed by SIGPIPE +++

That's all I have from that, though, since I set up some script stuff to delete the log every minute but back up the log if upnp is found closed.

Here's a helpful Google result:

Signal: Pipe

This signal is raised when a program writes to a socket or fifo that has no readers. The default action of this signal is to cause the program to terminate.

You might see this message if you have a series of commands in a shell pipe line and one of the processes quits. Eg:

$ cat somefile | head

After "head" has printed out the first 10 lines and quits, "cat" will get a pipe error. However, cat catches the signal and quits gracefully. If you pipe the output of some cvs(1) commands into less(1) and quit, then you might see the shell print out a message as cvs doesn't handle this signal gracefully.

Another example, using strace(1) to show system calls:

$ strace ls /etc | echo
execve("/bin/ls", ["ls", "/etc"], [/* 52 vars */]) = 0
...
write(1, "a2ps\nadjtime\napache2\napm\nasound."..., 1593) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
+++ killed by SIGPIPE +++
$

If you get this message when writing to a socket, it can be avoided by passing MSG_NOSIGNAL as a flag to send() or ignoring the signal by using signal(SIGPIPE,SIG_IGN);

I added signal(SIGPIPE,SIG_IGN) to upnp_main with the others. I'll see how it goes.

[tomilius]

Actually, upnp hasn't worked at all for me lately... I'm not sure if that's because of 1.9.2.7-5 or what, but it's not working and won't work. It might be Windows XP. I don't know what's causing this, but it's annoying.

UPDATE: Can't blame it on the computer... it's not working on any of the others either (they're not detecting it in Network Connections and UPnPTest fails). Hmm :(. Still, it's probably an obvious error on my part... maybe...

OK. So UPnP is definitely broken for me. Hmm.

Oh, but now it works again. Ugh. How problematic and disgusting. UPnP really needs some source tweaking...

[tomilius]

UPnP hasn't crashed since I made the aforementioned modification. Other than that, I had some Windows settings to tweak, and I lowered the UPNP_REFRESH value along with some of the related variables (lowered the SSDP one too). I think to 15 and 20, respectively... but that probably was unnecessary.

[tomilius]

Just for clarification, adding:


signal(SIGPIPE,SIG_IGN);

to upnp_main in upnp.c with the other calls to the signal function solved the crashing for me. UPnP still annoyingly restarts in the circumstances I've mentioned here (like ntp time updates), but this stops it from crashing for me.

[DocSnyder]

Is there a firmware available where the Upnp doesn't crash up to 10 times a day. Azureus states that it lost connection to device. But the download goes on. With my other router this does not happen. Is this a known bug or is my device faulty ?

[DocSnyder]

Nobody with the same problem?

[Oleg]

This is a known bug, fixed in the 1.9.2.7-6 custom firmware.

[Styno]

Another option is to disable uPnP (which is a security risk anyway) and use the Virtual Server function instead.

[DocSnyder]

Ok, that might be right. But I just wanted to be sure that it works. Now it seems to. Thanx

[Surfer_D]

Hi People,

I tried to connect my Nokia n95 to WL500 via upnp, but it can't find any media server from n95.

Did anyone already try this? Any hints maybe?

Thanks

[c20h25n3o]

Hi all,

For the last couple of days I've been going completely crazy.
UPNP just doesn't work under Vista Ultimate X64..
I've tried disabling ipv6, didn't work.
Tried original Asus firmware, didn't work.
Tried disabling and enabling a lot of services, didn't work.
I also did the Internet Connectivity Evaluation Tool (http://www.microsoft.com/windows/using/tools/igd/default.mspx) The strange thing is, sometime it passes the upnp test (it doesn't work though). Sometimes it doesn't pass the test. It never passes the NAT test though (Is this normal for WL-500g deluxe routers?). Even in XP it doesn't pass this part of the test...?
UPNP works perfect in XP btw. But in Vista it just doesn't seem to work.
I have upnptester.exe. It shows all details of the router in XP, but in Vista it says no upnp device found.
MSN the same.. In XP it says "connected through a UPNP port restricted NAT" , in Vista it says "connected through a non-UPNP restricted NAT"

I've been searching on Google for days and I just couldn't find a solution.

Is the WL-500g Deluxe not compatible with Vista x64, or is it a setting on the router? (Did the factory reset)

Is there anyone that has upnp working under Vista Ultimate x64? Could you please let me know how you did that before I throw my PC out the window? :P.

[c20h25n3o]

The "network map" is not working as well btw.

[dholliday]

Hi Oleg

I'm running 9.2.5 now. I have a problem with UPnP. Sometimes doesn't even load, sometimes load but it crashes when I try to open a port or some application is trying to open or close ports (emule, utorrent…). In system log is nothing that mention upnp. How would I check, what's causing these crashes? All settings were set manually (not loaded with configuration file). Router was reset to default settings before new firmware was putted on. After configuration it was unplugged from electricity.
In 1.9.2.7-6b firmware, upnp was working very well and it didn't crash. In later firmwares were problems. I would like to use the last firmware, because it has some other features that I like. Is it possible to recompile 9.2.5 with upnp from 1.9.2.7-6b or it’s not so simple because there were changes in other parts of firmware which are related to upnp? :confused:

Has anyone else had similar problems with upnp in 1.9.2.7-9 or other releases?

Thanks for your time

[jimmy_cr]

so what now? which firmware is the latest for WL500g recommended?

[fgomes]

I'm running 1.9.2.7-6b version, and recently found that when some application on my network opens a port on the Asus router using uPnP this port remains mapped, even after stopping the application and even reseting the router. Is there a easy way to close these ports opened through uPnP? I try to disable uPnP (the ports were closed), but enabling uPnP open those pots again even with no application asking. I only managed to keep the ports closed restoring the factory defaults. I need uPnP active because some 'devices' in my house need to use uPnP and they aren't configurable, but I don't want to have uPnP mappings permanent, specially for some mappings created by ad-hoc applications that destroy the statically configured mappings (i have a static port forwarding for the port 80 and some application is creating another mapping through uPnP also for the port 80 and the statically configured mapping stopped working).

Thanks for your help!

Fernando