Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DHCP Issue again. #3053

Closed
Black8all opened this issue May 1, 2021 · 45 comments
Closed

DHCP Issue again. #3053

Black8all opened this issue May 1, 2021 · 45 comments
Assignees
Milestone

Comments

@Black8all
Copy link

Hi, after few test, I have some trouble again with the DHCP. Some of my devices can't obtain an IP and I need to set a static lease if I want it to work.

I also encounter some of disconnection with few other. In the end, my log file are flooded by message about normalisation error.

I run now the 1.0.6.1 b1

Best regards

AdGuard.log

Originally posted by @Black8all in #2978 (comment)

@zhangguanzhang
Copy link

same issue

@ainar-g
Copy link
Contributor

ainar-g commented May 4, 2021

Hi, and thank you for the thorough report. From the logs, it seems like your installation's leases.db has a lot of duplicated IP addresses. Do you have a lot of static leases? Could you add the IP range that is used in the DHCP server as well as the IPs of the static leases? Thanks!

@ainar-g ainar-g added the waiting for data Waiting for users to provide more data. label May 4, 2021
@Black8all
Copy link
Author

No I haven't a lot of static leases. Instead of the two last in the list (those who don't work with dynamic DHCP) I usually only have 4 static.

Screenshot_20210504-180829_Firefox.jpg
Screenshot_20210504-180934_Firefox.jpg

@ainar-g
Copy link
Contributor

ainar-g commented May 4, 2021

I see, thanks. This may be the same issue as #3056. We're planning a patch in the next few days for it.

@ainar-g ainar-g added bug P3: Medium and removed waiting for data Waiting for users to provide more data. labels May 4, 2021
@ainar-g ainar-g self-assigned this May 4, 2021
@ainar-g ainar-g added this to the v0.106.2 milestone May 4, 2021
@ainar-g
Copy link
Contributor

ainar-g commented May 6, 2021

We've pushed a possible fix to the edge channel. Could you please check if our solution makes the DHCP server work better?

@Black8all
Copy link
Author

Black8all commented May 6, 2021 via email

@Black8all
Copy link
Author

I updated to version 0.106.2 b1 and it seems to work. I deleted all the static leases that I had to set up manually and at the moment all of my devices got an IP quickly. I'll juste wait until all my dynamics leases renew.

@Black8all
Copy link
Author

Finally I withdraw what I just said. Some of my devices still don't have internet access, despite having an IP assigned by DHCP. I'll post the log soon.

@Black8all
Copy link
Author

The log is pretty similar as before :

2021/05/06 21:10:23 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:23 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:26 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:26 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:29 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:30 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:33 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:33 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:36 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:36 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:39 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:39 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:43 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:43 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:46 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:46 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:49 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:49 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:52 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:53 [info] dhcp: stored 31 leases in DB
2021/05/06 21:10:56 [info] dhcpv4: normalized hostname "TOSHIBA-TV" into "toshiba-tv"
2021/05/06 21:10:56 [info] dhcp: stored 31 leases in DB

It's this device that can't get internet access --^

2021/05/07 07:09:52 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:52 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:52 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:52 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:52 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:53 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:53 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:53 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:55 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:55 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:56 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:56 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:56 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:56 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:57 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:57 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:57 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:58 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:58 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:58 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:59 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:59 [info] dhcp: stored 31 leases in DB
2021/05/07 07:09:59 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:09:59 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:00 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:00 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:00 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:00 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:00 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:00 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:00 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:00 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:00 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:00 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:01 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"
2021/05/07 07:10:01 [info] dhcp: stored 31 leases in DB
2021/05/07 07:10:01 [info] dhcpv4: normalized hostname "ESP_839FAC" into "esp-839fac"

And it's the same for all my leases, I have this two message in loop.

@ameshkov
Copy link
Member

ameshkov commented May 7, 2021

Weird, we need verbose-level log to see what's happening.

  1. Configure AdGuard Home to write verbose-level log.
  2. Reproduce the issue.
  3. Post the log file here.

@Black8all
Copy link
Author

Ok, I'll do that. Strangely, I had already activated the verbose mode, but apparently it was not saved after the update.

@ameshkov
Copy link
Member

ameshkov commented May 7, 2021

@Black8all you need to stop AGH before changing verbose flag.

@Black8all
Copy link
Author

I reproduce the issue with verbose mode on, I have posted below the log file only from the moment I removed the static lease to let DHCP assign an IP to my device. Despite getting an IP, the device has no access to the internet (it's a toshiba smart TV) and I guess that for a period of 45min the logs are huge.

AdGuard.log

@Black8all
Copy link
Author

Screenshot_20210508-023837_Settings.jpg

If it can help, this is the message on my Galaxy S20 when it obtain an IP from the DHCP without static lease set.

@Black8all
Copy link
Author

Today it's worst than ever, few of my devices can't obtain an IP, or if it obtain it, they don't have internet access. I need to set lot of statics lease for temporary solve the issue.

@ainar-g ainar-g modified the milestones: v0.106.2, v0.106.3 May 11, 2021
@ainar-g
Copy link
Contributor

ainar-g commented May 11, 2021

Thank you for the log. We're still investigating the issue. It's really weird that the clients seem to be sending the same requests over and over. Do you use any additional options in dhcp.dhcpv4.options field in your config?

@Black8all
Copy link
Author

No, I don't use any option. The only thing that I was configure is the IP range on the web GUI. There is no mysterious config. If you need more info or my complete log file, just ask me.

@ainar-g
Copy link
Contributor

ainar-g commented May 13, 2021

We've pushed some DHCP changes to the edge revision c890f5c. Could you please check if it makes the problem better?

Also, if you don't have a lot of static leases, and you don't mind adding them manually, you could also remove the leases.db file in AGH's workdir to make sure that old corrupted data isn't interfering with the new server logic.

Thanks.

@Black8all
Copy link
Author

Okay, I'll test this right away. Normally when DHCP is working normally I only have 4 static leases, so it's not a big deal if I have to set them up again by hand. I have a lot more right now because of the problem with DHCP.

Thanks for your work.

@Black8all
Copy link
Author

It's ok, I done the update and removed my leases.db.

Here is the log file from when I did the update and apparently I still have the same problem. For the moment only a few of my devices have tried to get an IP but the same messages keep coming up. On the other hand, those one get an IP (with difficulty) and internet connection but some others still don't.

AdGuard - Copie.log

@ainar-g
Copy link
Contributor

ainar-g commented May 13, 2021

Thank you for the log. We will research it further.

@Black8all
Copy link
Author

Black8all commented May 13, 2021

It was previously set to 1000, I increased it to 3000.
AdGuard - Copie.log
This is the log since the change.

image
This time it seem to obtain his IP.

image
But still no host-name.

I'll wait for all my leases to be renewed.

@ainar-g
Copy link
Contributor

ainar-g commented May 13, 2021

Thank you very much! I think that we have a couple of ways of improving the situation now. You should probably keep the new timeout value at least for now.

@Black8all
Copy link
Author

Unfortunately always the same thing, all this log is only for one device.
AdGuard - Copie (2).log

@ainar-g
Copy link
Contributor

ainar-g commented May 14, 2021

Is this a manually filtered log? If so, have you noticed any requests from that machine with the DECLINE message type? An unfiltered log would be more helpful.

Also, just to be safe, there are no other DHCP servers in that network, correct?

@Black8all
Copy link
Author

This is not a filtered log, I just selected the logs from when one of my hosts tried to get an IP, to the end of the file. The whole log file is over 90MB and not all of it is relevant.
I don't know if there were any DECLINE messages, I didn't have time to read everything yesterday.

Because of my ISP, I had to configure two DHCP, because my TV set-top box only wants an IP from the ISP box. The DHCP range of the ISP box is 192.168.1.2 to 192.168.1.3. and I have set up two static leases on the ISP box. One for the decoder .2 and one for my NAS .3 (which hosts AGH).

Then the DHCP of AGH takes over on a range from 192.168.1.5 to 192.168.1.150.

I know it's not very clean but it's the only way I can use AGH and my IPTV. And as far as I remember it worked well with version 0.105.2.

@ainar-g
Copy link
Contributor

ainar-g commented May 14, 2021

I see. Unfortunately, configurations with two DHCP servers in one network aren't really supported by AGH, sorry. We'll try to make a few more fixes in v0.106.3, but we cannot guarantee that they will fix the issue, as again, such configurations aren't currently supported.

@Black8all
Copy link
Author

OK, it's a shame, I really appreciate AGH 😢, I'll try to rollback to 0.105.2 for see if it worked. If so I would stay on this version 😅.

adguard pushed a commit that referenced this issue May 14, 2021
Updates #3053.

Squashed commit of the following:

commit eb68a21
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:58:15 2021 +0300

    dhcpd: do not panic

commit 4236789
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:18:49 2021 +0300

    dhcpd: support decline and release msgs
@ainar-g
Copy link
Contributor

ainar-g commented May 17, 2021

The latest edge build contains some enhancements that should make the DHCP server behave better.

@Black8all
Copy link
Author

Nice 👍I'll test this this evening.

@Black8all
Copy link
Author

I just updated to the v0.107.0-a.29+5acae6e2, I'll see if it's better.

@Black8all
Copy link
Author

Apparently nothing has changed for me with this update.
AdGuard - Copie (2).log

@ainar-g
Copy link
Contributor

ainar-g commented May 18, 2021

@Black8all, we've improved logging a bit in the most recent edge build (b2e3e4d). Could you please provide a full log after:

  1. Updating.
  2. Restarting AGH.
  3. Keeping it working for about five minutes.

The restart and the full log are very important. If you would like to make it more private, you could sent it to devteam@adguard.com with the subject line “AdGuard Home Issue 3053”.

We still don't see why the DHCP clients would behave the way they behave and which changes in v0.106 branch caused it, but we're looking into it further.

@Black8all
Copy link
Author

Thanks you very much for your hard work. I'll do that as soon as I get back to home.

adguard pushed a commit that referenced this issue May 19, 2021
Updates #3053.

Squashed commit of the following:

commit eb68a21
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:58:15 2021 +0300

    dhcpd: do not panic

commit 4236789
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:18:49 2021 +0300

    dhcpd: support decline and release msgs
@ainar-g ainar-g modified the milestones: v0.106.3, v0.107.0 May 19, 2021
@ainar-g
Copy link
Contributor

ainar-g commented May 19, 2021

We have received the logs, thanks. We will inspect them and see if we can improve something more in the nearest days.

@ainar-g
Copy link
Contributor

ainar-g commented May 20, 2021

@Black8all, I remember I proposed that you increase dhcp.dhcpv4.icmp_timeout_msec. Can you please reset it to 1000 or perhaps set it even lower, to 500? Perhaps the client has a very low DHCP timeout, and now that DECLINE messages are processed, the risk of IP conflicts should become lower.

@MarsWarrior
Copy link

MarsWarrior commented Jun 12, 2021

I see. Unfortunately, configurations with two DHCP servers in one network aren't really supported by AGH, sorry. We'll try to make a few more fixes in v0.106.3, but we cannot guarantee that they will fix the issue, as again, such configurations aren't currently supported.

But this is a completely valid configuration: two DHCP servers with different ranges (split scope) as you can read in this stackexchange question/answer Can I have multiple DHCP servers on one network?

I have the same. My ISP's modem can't disable the DHCP server, so this server is only handling some non existent mac address, meaning it doesn't do anything on my network!

On the other hand I'm using redundant AGH docker containers using bakito's adguardhome-sync to fully (config, dns, dhcp) sync the instances.

So I have 3 DHCP servers running on my network using static leases, where the AGH containers are servicing the exact same DHCP range, which is - again - a valid DHCP configuration!

@zhangguanzhang
Copy link

could add option for it in the configuration.

@anbraten
Copy link

@Black8all I can't get IPs for my ESPs and some other IoT stuff as well. It seem to me that this issue is coming from the fact that ESPs etc. expect a Unicast response from the DHCP server, but currently the ADH DHCP is only responding with Broadcasts. After I changed some code in #3458, it worked was able to receive IPs with my ESPs etc.

@ainar-g
Copy link
Contributor

ainar-g commented Sep 21, 2021

@Black8all, hello. We've made several improvements to the DHCP server during the v0.107 cycle. Could you please check one of our latest betas to see if there are still issues?

@anbraten
Copy link

@ainar-g Checked it as well. Seems to fixed my problem.

@ainar-g
Copy link
Contributor

ainar-g commented Sep 30, 2021

@Black8all, hello. We've made another round of improvements to the DHCP server. We'll close this issue for now, but if you find any new issues with the latest edge builds, please report them.

@ainar-g ainar-g closed this as completed Sep 30, 2021
@Black8all
Copy link
Author

Black8all commented Sep 30, 2021 via email

heyxkhoa pushed a commit to heyxkhoa/AdGuardHome that referenced this issue Mar 20, 2023
Updates AdguardTeam#3053.

Squashed commit of the following:

commit eb68a21
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:58:15 2021 +0300

    dhcpd: do not panic

commit 4236789
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri May 14 18:18:49 2021 +0300

    dhcpd: support decline and release msgs
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants