Getting a new IP several times a day.

[eldaria]

Since I changed to the Almond+ i been having a problem that my WAN IP keep on changing several times per day.
I have for a about a week had another router (Original Almond) connected to another port on the fiber converter from my ISP, and this one has had the same IP since it booted. (I can connect up to 5 devices that get their own public IP from the ISP)

Since the Almond+ is not keeping logs, it was difficult to identify what was going on, so I have set up Rsyslog to capture what was happening.
And this is the logs when the IP change.

Code: [Select]

Date,Facility,Severity,Host,Syslogtag,ProcessID,Messagetype,Message
"Today 18:11:08","3","2","admin.lan","dnsmasq[26958]:","","1"," FAILED to start up"
"Today 18:11:08","3","2","admin.lan","dnsmasq[26958]:","","1"," failed to bind DHCP server socket: Address already in use"
"Today 18:11:06","3","6","admin.lan","dnsmasq[12878]:","","1"," using local addresses only for domain lan"
"Today 18:11:06","3","6","admin.lan","dnsmasq[12878]:","","1"," using nameserver 213.80.98.2#53"
"Today 18:11:06","3","6","admin.lan","dnsmasq[12878]:","","1"," using nameserver 213.80.101.3#53"
"Today 18:11:06","3","6","admin.lan","dnsmasq[12878]:","","1"," reading /tmp/resolv.conf.auto"
"Today 18:11:06","1","5","admin.lan","miniupnpd:","","1"," adding firewall rules for eth0 to zone wan"
"Today 18:11:05","1","5","admin.lan","dnsmasq:","","1"," Allowing 127.0.0.0/8 responses"
"Today 18:11:05","1","5","admin.lan","dnsmasq:","","1"," DNS rebinding protection is active, will discard upstream RFC1918 responses!"
"Today 18:11:05","1","5","admin.lan","root:","","1"," starting ntpclient"
"Today 18:11:05","1","6","admin.lan","firewall:","","1"," adding wan (eth0) to zone wan"
"Today 18:11:04","1","5","admin.lan","ifup:","","1"," Enabling Router Solicitations on wan (eth0)"
"Today 18:11:03","1","6","admin.lan","sysinit:","","1"," ping: sendto: Network is unreachable"
"Today 18:11:01","1","6","admin.lan","sysinit:","","1"," ping: sendto: Network is unreachable"
"Today 18:11:00","1","5","admin.lan","root:","","1"," stopping ntpclient"

Honestly i'm not sure what to make of it.
All those messages come in burst, there is not so much happening before or after, I see some upnp stuff going on, but they are minutes apart from this.

My network:

[jjoepaulines]

can you please share the complete log file because even i don't have any clue either.

if you see that Udhcpc option , -R denotes releasing the IP on exit ... may be any service which may restart this udhcpc daemon.. Not sure about this .. but i will do investigate on this ...

Code: [Select]

udhcpc -t 3 -T 3 -A 40 -i eth0 -b -p /var/run/dhcp-eth0.pid -O rootpath -R

mean while you can try the below things

kill the udhcpc and

run udhcpc with out that option -R

[eldaria]

Hello Joe,

Thanks for replying, I did some testing based on your advice, so much that I ended up without an Internet connection since I used up all the available addresses I can get.
So have to wait until the ISP DHCP server releases them again.

I did find some other bugs during the troubleshooting I will create some separate posts about this.

Anyway when running the command without -R I get the same IP every time.
When running the command once with -R I get the same IP the first time i run it again, but when running it a second time with or without the -R I get a new IP.

So it certainly seems that it is the reason for the problems that I get a new IP all the time.

So my next questions should then be, how do I make it so that this change of parameters survive a reboot?

However looking at what that parameter does.
"-R,--release      Release IP on exit"

That implies that the udhcpc process terminates and sends a release to the DHCP server and then starts up again?
Why does the process terminate in the first place?

I have reset the router now to factory defaults, and I killed the udhcpc process, and launched it again without the -R and added -S in the hopes that I will capture the logs if it get's terminated again.
Right now however my Almond+ is not connected straight to the Fiberbox, since I do not get an IP from them at the moment, Instead I have now connected it to the Almond that was luckily still connected so for now it is the Almond that is giving me an IP.

[eldaria]

So today I tried to connect the Almond+ back to the Fiber Box again. Before doing this I check that the process I had started was still using the same parameters:

Code: [Select]

root@AlmondWhite:/etc/ppp# ps w | grep udhcpc
 9026 root      1328 S    udhcpc -t 3 -T 3 -A 40 -i eth0 -x hostname almondplus -b -p /var/run/dhcp-eth0.pid -S -O rootpath

I then went on to move the cable over from the Original Almond to the Fiber Box.
And now I got the "wrong" parameters again.

Code: [Select]

root@AlmondWhite:/etc/ppp# ps w | grep udhcpc
 4415 root      1324 S    udhcpc -t 3 -T 3 -A 40 -i eth0 -H almondplus -b -p /var/run/dhcp-eth0.pid -O rootpath -R

So I killed the process and ran the correct one.

Code: [Select]

root@AlmondWhite:/etc/ppp# xargs kill < /var/run/dhcp-eth0.pid
root@AlmondWhite:/etc/ppp# udhcpc -t 3 -T 3 -A 40 -i eth0 -x hostname:almondplus -b -p /var/run/dhcp-eth0.pid -S -O rootpath | grep lease
Lease of 46.59.XX.XX obtained, lease time 14400

dnsmasq: failed to bind DHCP server socket: Address already in use
root@AlmondWhite:/etc/ppp# ps w | grep udhcpc
 5308 root      1328 S    udhcpc -t 3 -T 3 -A 40 -i eth0 -x hostname almondplus -b -p /var/run/dhcp-eth0.pid -S -O rootpath

I now also get DHCP log in syslog so should be able to see if anything happens.

It still gives that Failed to bind error from dnsmasq, not sure what where it comes from, but it is working now and I will monitor.

But Joe if you could tell how I can change the parameters so it does not reset and I have to manually fix it again?

[eldaria]

Well unfortunately it seems that it at some point reset back to the original setting.
And now i'm again not getting an IP from my ISP since I used up all the IP's so I really need to know how I can modify the default parameters.

[eldaria]

Ok after a lot of digging through config files and searching internet I found out how to fix the parameters.

So for anyone who might have the same trouble as me.

Code: [Select]

vi /lib/network/config.sh

You can scroll, but the fastest is to just use the built in search by typing a foward slash ' / '.
Now type rootpath and hit enter, you should end up with something like this:

Code: [Select]

                        # don't stay running in background if dhcp is not the main proto on the interface (e.g. when using pptp)
                        [ "$proto1" != "$proto" ] && append dhcpopts "-n -q" || append dhcpopts "-O rootpath -R &"
                        [ "$broadcast" = 1 ] && broadcast="-B -C" || broadcast=
                                             
                        $DEBUG eval udhcpc -t 3 -T 3 -A 40 -i "$iface" \
                                ${ipaddr:+-r $ipaddr} \           
                                ${hostname:+-H $hostname} \
                                ${clientid:+-c $clientid} \
                                ${vendorid:+-V $vendorid} \
                                -b -p "$pidfile" $broadcast \
                                ${dhcpopts}

Modify this line (push i for insert editing)

Code: [Select]

[ "$proto1" != "$proto" ] && append dhcpopts "-n -q" || append dhcpopts "-O rootpath -R &"
I changed it to:

Code: [Select]

[ "$proto1" != "$proto" ] && append dhcpopts "-n -q" || append dhcpopts "-S -O rootpath &"
I removed -R This prevents it from releasing the lease, and I added -S to get syslog to log DHCP.

While you are in here you can also fix the hostname parameter.

Modfiy this line:

Code: [Select]

${hostname:+-H $hostname} \
Change it to:

Code: [Select]

${hostname:+-x hostname\:$hostname} \
Now all you need to do is disconnect your wan cable and insert it again and it will use the new parameters.

[mparadis]

I am also experiencing the same phenomenon of a new IP address several times a day, often times the almond does not get a new ip after disconnecting the old but cannot confirm its got the same cause as I don't have the technical knowledge to view the logs etc.

[jjoepaulines]

I checked this again .. looks like

${hostname:+-H $hostname} \

is adding the Hostname in to DHCP discover header....

So we don't have to replace above option

${hostname:+-x hostname\:$hostname} \

Any update on this  ?

[eldaria]

Hi Joe, I responded to you in the thread where I reported the specific problem with the hostname parameter.

For a update on the new IP, I can say that after modifying the file, I have kept the same IP the whole time now.
So it seems my modifications worked, thanks for the tip on what to look for. ;-)

[eldaria]

By the way.
It still seems that the router keeps on restarting the udhcpc daemon, and renews the IP, however since I change the parameter I no longer get a new IP from the ISP.
And when it does I briefly loose connectivity, I notice this for example when i'm on Google hangouts calls.

So I looked through the log for clues, and I did notice something interesting in the log history.
When the Almond+ is connected directly to the my ISP's fiber converter it keeps killing and restarting the Daemon.
If I filter out udhcpc events this is what comes up:

Code: [Select]

Date,Facility,Severity,Host,Syslogtag,ProcessID,Messagetype,Message
"Today 09:47:47","3","6","192.168.1.1","udhcpc[16992]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 09:47:47","3","6","192.168.1.1","udhcpc[16992]:","","1"," Sending select for XX.XX.44.39..."
"Today 09:47:46","3","6","192.168.1.1","udhcpc[16992]:","","1"," Sending discover..."
"Today 09:47:45","3","6","192.168.1.1","udhcpc[16992]:","","1"," udhcpc (v1.22.1) started"
"Today 09:47:45","3","6","192.168.1.1","udhcpc[15903]:","","1"," Received SIGTERM"
"Today 09:37:56","3","6","192.168.1.1","udhcpc[15406]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 09:37:56","3","6","192.168.1.1","udhcpc[15406]:","","1"," Sending select for XX.XX.44.39..."
"Today 09:37:55","3","6","192.168.1.1","udhcpc[15406]:","","1"," Sending discover..."
"Today 09:37:54","3","6","192.168.1.1","udhcpc[15406]:","","1"," udhcpc (v1.22.1) started"
"Today 09:37:53","3","6","192.168.1.1","udhcpc[30787]:","","1"," Received SIGTERM"
"Today 09:06:14","3","6","192.168.1.1","udhcpc[30787]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 09:06:14","3","6","192.168.1.1","udhcpc[30787]:","","1"," Sending renew..."
"Today 07:06:09","3","6","192.168.1.1","udhcpc[30297]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 07:06:09","3","6","192.168.1.1","udhcpc[30297]:","","1"," Sending select for XX.XX.44.39..."
"Today 07:06:08","3","6","192.168.1.1","udhcpc[30297]:","","1"," Sending discover..."
"Today 07:06:07","3","6","192.168.1.1","udhcpc[30297]:","","1"," udhcpc (v1.22.1) started"
"Today 07:06:06","3","6","192.168.1.1","udhcpc[18475]:","","1"," Received SIGTERM"
"Today 05:18:39","3","6","192.168.1.1","udhcpc[17989]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 05:18:38","3","6","192.168.1.1","udhcpc[17989]:","","1"," Sending select for XX.XX.44.39..."
"Today 05:18:37","3","6","192.168.1.1","udhcpc[17989]:","","1"," Sending discover..."
"Today 05:18:36","3","6","192.168.1.1","udhcpc[17989]:","","1"," udhcpc (v1.22.1) started"
"Today 05:18:36","3","6","192.168.1.1","udhcpc[11158]:","","1"," Received SIGTERM"
"Today 04:16:14","3","6","192.168.1.1","udhcpc[10646]:","","1"," Lease of XX.XX.44.39 obtained, lease time 14400"
"Today 04:16:14","3","6","192.168.1.1","udhcpc[10646]:","","1"," Sending select for XX.XX.44.39..."
"Today 04:16:13","3","6","192.168.1.1","udhcpc[10646]:","","1"," Sending discover..."
"Today 04:16:12","3","6","192.168.1.1","udhcpc[10646]:","","1"," udhcpc (v1.22.1) started"
"Today 04:16:11","3","6","192.168.1.1","udhcpc[7175]:","","1"," Received SIGTERM"

This goes on for the last 5 days when it was connected directly.
But before then I was connecting my Almond+ through the original Almond that that configured with full DMZ, and this is how the log looks when connected in this way:

Code: [Select]

"2014-10-25 02:47:59","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease of XX.XX.44.211 obtained, lease time 86400"
"2014-10-25 02:47:59","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending select for XX.XX.44.211..."
"2014-10-25 02:47:58","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease lost, entering init state"
"2014-10-25 02:47:58","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:47:57","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:47:54","3","6","192.168.1.1","udhcpc[21151]:","","1"," message repeated 2 times: [ Sending renew...]"
"2014-10-25 02:47:39","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:47:18","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:46:36","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:45:11","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:42:23","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:36:46","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:25:31","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 02:03:01","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-25 01:18:01","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 23:48:01","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 20:48:02","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 14:48:02","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:55","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease of XX.XX.44.211 obtained, lease time 86400"
"2014-10-24 02:47:55","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending select for XX.XX.44.211..."
"2014-10-24 02:47:55","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending discover..."
"2014-10-24 02:47:54","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease lost, entering init state"
"2014-10-24 02:47:53","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:52","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:50","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:45","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:34","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:47:13","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:46:31","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:45:07","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:42:19","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:36:42","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:25:27","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 02:02:57","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-24 01:17:57","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-23 23:47:57","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-23 20:47:57","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-23 14:47:58","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-23 02:47:44","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease of XX.XX.44.211 obtained, lease time 86400"
"2014-10-23 02:47:44","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending select for XX.XX.44.211..."
"2014-10-23 02:47:44","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending discover..."
"2014-10-23 02:47:43","3","6","192.168.1.1","udhcpc[21151]:","","1"," Lease lost, entering init state"
"2014-10-23 02:47:43","3","6","192.168.1.1","udhcpc[21151]:","","1"," message repeated 3 times: [ Sending renew...]"
"2014-10-23 02:47:34","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."
"2014-10-23 02:47:24","3","6","192.168.1.1","udhcpc[21151]:","","1"," Sending renew..."

If you need the full log with not only udhcpc let me know. I'm not keen on posting the whole log public on the forum, but if you want I can PM you a link to the file if you are interested in it.
Let me know also if you need me to enable additional logs.