Strange log entry for WAN lease renew

Im using a self compiled version of openwrt on my wrt1900ac.
BUILD: OpenWrt SNAPSHOT r6874-02225f5

I notice the following log entry in the system log. Just wondering what is that IP address:10.23.113.6 ? it doesnt seem to be for my ISP as my ISP IPs are 24.200.x.x. Unless the ISP DHCP server is in fact really that?

In any case it seems unreachable at which point there is another renew request to 0.0.0.0 and thats when i get my WAN IP. Does this look normal?

Thu Jun 14 10:12:54 2018 daemon.notice netifd: wan (2103): udhcpc: sending renew to 10.23.113.6
Thu Jun 14 10:12:54 2018 daemon.notice netifd: wan (2103): udhcpc: send: Network unreachable
Thu Jun 14 10:12:54 2018 daemon.notice netifd: wan (2103): udhcpc: sending renew to 0.0.0.0
Thu Jun 14 10:12:54 2018 daemon.notice netifd: wan (2103): udhcpc: lease of X.X.X.X obtained, lease time 86400

See

Likely udhcpc commit has something to do with this:
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=e4259bed3f20f8f132555ae8aef379e3d2ffb938

Many renew retries. Sometimes ending failing with request to 0.0.0.0

Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:45:42 2018 daemon.notice netifd: wan (1066): udhcpc: lease of x.x.x.y obtained, lease time 1800
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 17:32:34 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to x.x.x.x
Thu Jun 14 18:14:46 2018 daemon.notice netifd: wan (1066): udhcpc: sending renew to 0.0.0.0
Thu Jun 14 18:14:46 2018 daemon.notice netifd: wan (1066): udhcpc: lease of x.x.x.y obtained, lease time 1800
1 Like

Good find! Will post on the referenced thread as well.

@h8red OP is using 02225f5, made on May 12th. The commit you referenced (which I authored) was committed on June 6th. So unless there are some time travel shenanigans, I don't think the commit you linked has anything to do with OP's issue.

@alirz1 I believe that my commit (linked by @h8red) is actually the solution for your problem. I've been having the same one. Please check this PR for more info https://github.com/openwrt/openwrt/pull/1017

Ok. Thanks all. I will compile a new build today and test that out.

Sorry, didn`t check that out. Thanks. Will check this out on forum to fish out the problem.

Thanks again

ok i installed a new compiled image.
Build: OpenWrt SNAPSHOT r6874-02225f5

So far i'm only see the wan dhcp renew at router reboot. Im not seeing any subsequent renew requests. Will monitor and report.

Thu Jun 14 16:42:09 2018 daemon.notice netifd: wan (2018): udhcpc: started, v1.28.3
Thu Jun 14 16:42:09 2018 daemon.err odhcp6c[2025]: Failed to send RS (Address not available)
Thu Jun 14 16:42:09 2018 daemon.notice netifd: wan (2018): udhcpc: sending discover
Thu Jun 14 16:42:09 2018 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Thu Jun 14 16:42:09 2018 daemon.notice netifd: wan (2018): udhcpc: sending select for X.X.X.X
Thu Jun 14 16:42:10 2018 daemon.notice netifd: wan (2018): udhcpc: lease of X.X.X.X obtained, lease time 62303

EDIT: non related. Strange that the firmware build number is same as before, even though my previous build was over a month old. I thought that would have updated...not sure what to make of that.

@adiov how do you determine that my build was from May based on the firmware version "02225f5" ?

lede_source$ git log -1 02225f5
commit 02225f576360d60963af3de7da7f0299a0b4f52a
Author: Rafał Miłecki <rafal@milecki.pl>
Date:   Sat May 12 15:38:53 2018 +0200

    bcm53xx: backport the first bunch of 4.18 BCM5301X patches
    
    Signed-off-by: Rafał Miłecki <rafal@milecki.pl>

Thanks Jeff. Instead of starting a new thread i'll just ask here.
Would you know why a firmware that i compiled today ended with build of 02225f5?

im not an expert at git, but I did the usual:
./scripts/feeds update -a
./scripts/feeds install -a
make menuconfig
make -j 8

Should i have done a git pull before? i though that was a one time thing when setting the dev environment?

You need to get the new source with a git pull

Edit: maybe some useful bits

1 Like

Thank you.

For the longest time i thought that running: scripts/feeds update -a , followed by scripts/feeds install -a
would update the code of the kernel and all my select packages etc in the firmware that i was about to build.

Now i realize that i need to do a git pull as the first step.

My habit is to git pull first (well, actually git fetch and then rebase my local work onto the new head), then update the feeds, then

make -j5 clean download world

(4-core build box) which makes sure that things are tidy, as well as that all the needed sources are available before the compile starts.

You can also use git tag some-name-that-means-something-to-you to mark points in your local copy. Before I started capturing everything with a script, I'd use build-2018-06-14 or the like for my tags.

What does adding "world" in the make command do?

ok i have installed a new build (OpenWrt SNAPSHOT r7194-5e9470a) and now there seem to be less chatter from the udhcp for the WAN lease. However im curious though. Does the firewall reload message below also indicate the WAN interface was reset? i.e would i have internet when this happened?

Sat Jun 16 03:21:23 2018 daemon.notice netifd: wan (2042): udhcpc: sending renew to 10.23.113.6
Sat Jun 16 03:21:23 2018 daemon.notice netifd: wan (2042): udhcpc: lease of X.X.X.X obtained, lease time 82531
Sat Jun 16 03:21:23 2018 user.notice firewall: Reloading firewall due to ifupdate of wan (eth1.2)

"world" is the generic target for make, so it makes "everything" after clean and download. Sort of shorthand for

make -j5 clean ; make -j5 download ; make -j5

Thanks again.

This is good news! Not only there's less chatter, but your lease is actually being renewed the first time by a direct request to your DHCP server which is on a deeper network in your ISP's infra.

AFAIK, this is an event fired by netifd when there's a change in your interface. This happens when your DHCP server responds with a DHCPACK containing different IP from the one you had before x.x.x.x a different IP from the one you had earlier. I'm not sure if this is possible according to RFC2131, but if it is then I can imagine that the firewall needs to be reloaded when that happens. According to RFC2131, the DHCP server can also send you other "configuration changes" .

The firewall reload in this case happens by calling the FW Hotplug script here https://github.com/openwrt/openwrt/blob/master/package/network/config/firewall/files/firewall.hotplug I'm not really a Linux networking guy, so I cannot answer for sure if you lose connectivity during a fw reload, but I strongly suspect that you don't.

You can actually verify if this is what's happening by taking a tcpdump -n port 67 and port 68 from your WAN when initial lease happens and when renewal happens to see what kind of differences there are.

Well whatever its worth. Note that my ISP rarely changes my WAN IP. I also dont think that my wan connection is being reset. About two years ago though, there was a build i was using where my wan would reset at lease renew time causing loss of internet. I havent noticed that so far but again this is hard to capture.
if i notice issues, ill look into running a trace on the router.
Thanks for your help.