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 Server not run at first start #2304

Closed
3 tasks done
TooYoungTooSimp opened this issue Nov 12, 2020 · 26 comments
Closed
3 tasks done

DHCP Server not run at first start #2304

TooYoungTooSimp opened this issue Nov 12, 2020 · 26 comments
Assignees
Milestone

Comments

@TooYoungTooSimp
Copy link

Prerequisites

Please answer the following questions for yourself before submitting an issue. YOU MAY DELETE THE PREREQUISITES SECTION.

  • I am running the latest version
  • I checked the documentation and found no answer
  • I checked to make sure that this issue has not already been filed

Issue Details

  • Version of AdGuard Home server:
    • 0.104.1
  • How did you setup DNS configuration:
    • System
  • If it's a router or IoT, please write device model:
  • Operating system and version:
    • Archlinux

Expected Behavior

dhcp listen at :67 after boot

Actual Behavior

dhcp doesn't listen 67. Unless I restart adguardhome

Screenshots

Screenshot:

Additional Information

I think maybe it's because it can not bind to specific nic at very early time.
So if there's a solution to let adguard home waiting the nic goes up to bind, it should be solved.

@ameshkov
Copy link
Member

The problem is that we cannot solve this on our own as it's not caused by us.

AdGuard Home needs to be started when the network is available, and this is specified in the service configuration.

The question is why in your case the order is wrong.

@TooYoungTooSimp
Copy link
Author

I've rechecked the boot sequence.
image
image
Seems agh boots AFTER nic link up.(I've set After=basic.target in agh .service file)
So in conclusion, I believe my order is correct.

@ameshkov
Copy link
Member

@TooYoungTooSimp I guess the temporary solution would be to postpone the service startup so that the iface was actually initialized.

@ainar-g this is not the first time we're facing this issue. We could implement something simple, like waiting a couple more seconds if the interface is not found on the DHCP server startup.

@TooYoungTooSimp
Copy link
Author

I added a ExecStartPre=sleep 3, as a temporary solution. It does work now. Thanks for your kindly advice.

@nhmarujo
Copy link

nhmarujo commented Nov 13, 2020

I think I'm facing the same issue. When I boot the system, the DHCP Server doesn't work properly. Devices are able to connect to the network, but hang obtaining an IP address.

If I restart the service (sudo service AdGuardHome restart) then everything starts working normally.

I'm running AdGuardHome on the following setup:

  • RPi 1 Model B
  • Raspbian GNU/Linux 10 (buster)
  • AdguardHome v0.104.1

I have checked the service configuration file (/etc/systemd/system/AdGuardHome.service) and I can see the proper configuration to wait for the network: After=syslog.target network-online.target

I also tried to add the instruction ExecStartPre=sleep 3, like suggested by @TooYoungTooSimp as a workaround, but it doesn't seem to solve the issue (I still need to restart AdGuardHome after each boot).

@TooYoungTooSimp
Copy link
Author

I think I'm facing the same issue. When I boot the system, the DHCP Server doesn't work properly. Devices are able to connect to the network, but hang obtaining an IP address.

If I restart the service (sudo service AdGuardHome restart) then everything starts working normally.

I'm running AdGuardHome on the following setup:

  • RPi 1 Model B
  • Raspbian GNU/Linux 10 (buster)
  • AdguardHome v0.104.1

I have checked the service configuration file (/etc/systemd/system/AdGuardHome.service) and I can see the proper configuration to wait for the network: After=syslog.target network-online.target

I also tried to add the instruction ExecStartPre=sleep 3, like suggested by @TooYoungTooSimp as a workaround, but it doesn't seem to solve the issue (I still need to restart AdGuardHome after each boot).

well, you should type the full path of sleep, like /usr/bin/sleep (use which sleep to figure out). Maybe you could give it another try.

@nhmarujo
Copy link

Actually no, just like that was fine. I just had to increase the sleep a bit in order to make it work.

Here is the service definition (/etc/systemd/system/AdGuardHome.service):

[Unit]
Description=AdGuard Home: Network-level blocker
ConditionFileIsExecutable=/home/pi/AdGuardHome/AdGuardHome
After=syslog.target network-online.target

[Service]
StartLimitInterval=5
StartLimitBurst=10
ExecStartPre=sleep 5
ExecStart=/home/pi/AdGuardHome/AdGuardHome "-s" "run"

WorkingDirectory=/home/pi/AdGuardHome

StandardOutput=file:/var/log/AdGuardHome.out
StandardError=file:/var/log/AdGuardHome.err
Restart=always
RestartSec=10
EnvironmentFile=-/etc/sysconfig/AdGuardHome

[Install]
WantedBy=multi-user.target

If I try to put the full path it actually fail to start.

Right now, I got it booting up fine with this. My issue now is that the DHCP server stops working sometimes and I need to restart the service 😞

@ainar-g
Copy link
Contributor

ainar-g commented Nov 25, 2020

@TooYoungTooSimp, thanks for your report! Can you set verbose: true in your config and post the log (preferably in text, but a screenshot is fine too) of AGH starting up? Thanks again!

@TooYoungTooSimp
Copy link
Author

log.txt
@ainar-g Here's my verbose log. Hope it is helpful for you!

@TooYoungTooSimp
Copy link
Author

I can see a line likes not finding ip address of interface ens34, my nics are managed by systemd-networkd and have static ip configuration. Is there's a way just bind on specific interface regardless it's ipaddr (a whimsical suggestion)?

@ainar-g
Copy link
Contributor

ainar-g commented Nov 27, 2020

@TooYoungTooSimp, thanks for the logs, they're very helpful! We need to know the IP address of the interface we're binding to, because that's the address that we send to the DHCP clients as the address of the DNS server that they should use. We're currently thinking of ways to somehow wait for the interface to get an IP.

adguard pushed a commit that referenced this issue Nov 27, 2020
Merge in DNS/adguard-home from 2304-dncp-backoff to master

Updates #2304.

Squashed commit of the following:

commit c9bff8b
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri Nov 27 14:08:03 2020 +0300

    dhcpd: try for 5s instead of 10s

commit 983cf47
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Wed Nov 25 19:58:41 2020 +0300

    dhcpd: wait for interfaces' ip addresses to appear
@ainar-g
Copy link
Contributor

ainar-g commented Nov 27, 2020

Should be fixed as of snapshot 60d72fb. Can you please check if our solution fixes the issue for you?

adguard pushed a commit that referenced this issue Dec 2, 2020
Merge in DNS/adguard-home from 2304-fix-panic to master

Updates #2304.

Squashed commit of the following:

commit bd7742e
Merge: 2631392 7d1d87d
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:29:37 2020 +0300

    Merge branch 'master' into 2304-fix-panic

commit 2631392
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:09:16 2020 +0300

    all: add gitignore rule

commit 5a8521b
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:03:26 2020 +0300

    dhcpd: fix zero-length ip addresses list bug
@ainar-g
Copy link
Contributor

ainar-g commented Dec 4, 2020

I'll close this issue for now. Please feel free to reopen with more details if you think it should be reopened.

@ainar-g ainar-g closed this as completed Dec 4, 2020
adguard pushed a commit that referenced this issue Dec 10, 2020
Merge in DNS/adguard-home from 2304-dncp-backoff to master

Updates #2304.

Squashed commit of the following:

commit c9bff8b
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Fri Nov 27 14:08:03 2020 +0300

    dhcpd: try for 5s instead of 10s

commit 983cf47
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Wed Nov 25 19:58:41 2020 +0300

    dhcpd: wait for interfaces' ip addresses to appear
adguard pushed a commit that referenced this issue Dec 10, 2020
Merge in DNS/adguard-home from 2304-fix-panic to master

Updates #2304.

Squashed commit of the following:

commit bd7742e
Merge: 2631392 7d1d87d
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:29:37 2020 +0300

    Merge branch 'master' into 2304-fix-panic

commit 2631392
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:09:16 2020 +0300

    all: add gitignore rule

commit 5a8521b
Author: Eugene Burkov <e.burkov@adguard.com>
Date:   Wed Dec 2 14:03:26 2020 +0300

    dhcpd: fix zero-length ip addresses list bug
@TooYoungTooSimp
Copy link
Author

fix confirmed in v0.105.0-beta.1. Sorry for late response and thank for your hard work!

@zadigre
Copy link

zadigre commented Jan 24, 2021

I have this issue on 0.105 beta 2.
I have to restart AdGuard home to get a working dhcp server...
I have a script in crontab running after reboot... sleep 15 and then restart AdGuard home.
it works fine with this command.

running on raspberry OS 64 bits.
I installed AdGuard home service with the -s install command.

Please let me know if you need logs to see what’s going on.

@ameshkov
Copy link
Member

@zadigre

To troubleshoot this issue we need to see AdGuard Home logs.

  1. Configure AdGuard Home to collect logs:
    • Specify log_file
    • Set verbose to True
  2. Restart AdGuard Home and reproduce the issue
  3. Post the log file here.

@zadigre
Copy link

zadigre commented Jan 25, 2021

here's the relevant parts... dhcpv4 cannot find IP address:
`
2021/01/25 09:19:35 470#49 [info] AdGuard Home, version 0.105.0-beta.2, channel beta, arch linux arm64
2021/01/25 09:19:35 470#49 [debug] Current working directory is /home/pi/AdGuardHome
2021/01/25 09:19:35 470#49 [info] AdGuard Home is running as a service
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.upgradeConfig(): got schema version 7
2021/01/25 09:19:35 470#49 [debug] Reading config file: /home/pi/AdGuardHome/AdGuardHome.yaml
2021/01/25 09:19:35 470#49 [debug] dhcpv4: added lease x.x.x.x <-> XX:XX:XX:XX:XX:XX

[... bunch of leases removed ...]

2021/01/25 09:19:35 470#49 [debug] dhcpv4: added lease x.x.x.x <-> XX:XX:XX:XX:XX:XX
2021/01/25 09:19:35 470#49 [info] DHCP: loaded leases v4:76 v6:0 total-read:76 from DB
2021/01/25 09:19:35 470#49 [debug] AutoHosts: loading hosts from file /etc/hosts
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added 127.0.0.1 -> localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address 127.0.0.1 -> localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added ::1 -> localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address ::1 -> localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added ::1 -> ip6-localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address ::1 -> ip6-localhost
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added ::1 -> ip6-loopback
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address ::1 -> ip6-loopback
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added ff02::1 -> ip6-allnodes
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address ff02::1 -> ip6-allnodes
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added ff02::2 -> ip6-allrouters
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address ff02::2 -> ip6-allrouters
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added 127.0.1.1 -> raspberrypi
2021/01/25 09:19:35 470#49 [debug] AutoHosts: added reverse-address 127.0.1.1 -> raspberrypi
2021/01/25 09:19:35 470#49 [debug] clients: removed 0 client aliases
2021/01/25 09:19:35 470#49 [debug] clients: added "x.x.x.x" -> "XXXXX" [1]

[... bunch of clients removed ...]

2021/01/25 09:19:35 470#49 [debug] clients: added "x.x.x.x" -> "XXXXX" [13]
2021/01/25 09:19:35 470#49 [debug] Clients: added 67 client aliases from DHCP
2021/01/25 09:19:35 470#49 [debug] Writing YAML file: /home/pi/AdGuardHome/AdGuardHome.yaml
2021/01/25 09:19:35 470#49 [info] Initializing auth module: /home/pi/AdGuardHome/data/sessions.db
2021/01/25 09:19:35 470#49 [debug] Auth: loaded 6 sessions from DB (removed 0 expired)
2021/01/25 09:19:35 470#49 [info] Auth: initialized. users:1 sessions:6
2021/01/25 09:19:35 470#49 [info] Initialize web module
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).dbOpen(): db.Open...
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).dbOpen(): db.Open
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin...
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.createObject(): Deleting old units...
2021/01/25 09:19:35 470#49 [debug] Stats: initialized
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname blink_sync_module from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: skipping invalid hostname Meross Smart Switch from DHCP
2021/01/25 09:19:35 470#49 [debug] DNS: added 59 A/PTR entries from DHCP
2021/01/25 09:19:35 470#49 [debug] IPSET: added 0 hosts
2021/01/25 09:19:35 470#49 [debug] Bootstraps: [9.9.9.11 149.112.112.11 2620:fe::11 2620:fe::fe:11]
2021/01/25 09:19:35 470#49 [debug] Upstream 0: 207.164.234.129:53
2021/01/25 09:19:35 470#49 [debug] Upstream 1: 207.164.234.193:53
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*Filtering).load(): Loading filter 1609598775 contents to: /home/pi/AdGuardHome/data/filters/1609598775.txt
2021/01/25 09:19:35 470#49 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*Filtering).load(): File /home/pi/AdGuardHome/data/filters/1609598775.txt, id 1609598775, length 10780572
2021/01/25 09:19:35 470#49 [debug] Web: applying new TLS configuration
2021/01/25 09:19:35 470#49 [debug] Start AutoHosts module
2021/01/25 09:19:35 470#27 [debug] AutoHosts: loading hosts from file /etc/hosts
2021/01/25 09:19:35 470#27 [debug] AutoHosts: loading hosts from file /etc/hosts
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added 127.0.0.1 -> localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address 127.0.0.1 -> localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added ::1 -> localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address ::1 -> localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added ::1 -> ip6-localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address ::1 -> ip6-localhost
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added ::1 -> ip6-loopback
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address ::1 -> ip6-loopback
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added ff02::1 -> ip6-allnodes
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address ff02::1 -> ip6-allnodes
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added ff02::2 -> ip6-allrouters
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address ff02::2 -> ip6-allrouters
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added 127.0.1.1 -> raspberrypi
2021/01/25 09:19:35 470#27 [debug] AutoHosts: added reverse-address 127.0.1.1 -> raspberrypi
2021/01/25 09:19:35 470#27 [debug] clients: removed 0 client aliases
2021/01/25 09:19:35 470#27 [debug] clients: added "ff02::1" -> "ip6-allnodes" [68]
2021/01/25 09:19:35 470#27 [debug] clients: added "ff02::2" -> "ip6-allrouters" [69]
2021/01/25 09:19:35 470#27 [debug] clients: added "127.0.1.1" -> "raspberrypi" [70]
2021/01/25 09:19:35 470#27 [debug] clients: added "127.0.0.1" -> "localhost" [71]
2021/01/25 09:19:35 470#27 [debug] clients: added "::1" -> "localhost" [72]
2021/01/25 09:19:35 470#27 [debug] clients: added "::1" -> "ip6-localhost" [72]
2021/01/25 09:19:35 470#27 [debug] clients: added "::1" -> "ip6-loopback" [72]
2021/01/25 09:19:35 470#27 [debug] Clients: added 7 client aliases from system hosts-file
2021/01/25 09:19:35 470#49 [debug] dhcpv4: starting...
2021/01/25 09:19:35 470#49 [debug] dhcpv4: attempt 1: no ip addresses
2021/01/25 09:19:36 470#49 [debug] dhcpv4: attempt 2: no ip addresses
2021/01/25 09:19:36 470#49 [debug] dhcpv4: attempt 3: no ip addresses
2021/01/25 09:19:37 470#49 [debug] dhcpv4: attempt 4: no ip addresses
2021/01/25 09:19:37 470#49 [debug] dhcpv4: attempt 5: no ip addresses
2021/01/25 09:19:38 470#49 [debug] dhcpv4: attempt 6: no ip addresses
2021/01/25 09:19:38 470#49 [debug] dhcpv4: attempt 7: no ip addresses
2021/01/25 09:19:39 470#49 [debug] dhcpv4: attempt 8: no ip addresses
2021/01/25 09:19:39 470#49 [debug] dhcpv4: attempt 9: no ip addresses
2021/01/25 09:19:40 470#49 [debug] dhcpv4: attempt 10: no ip addresses
2021/01/25 09:19:40 470#49 [error] dhcpv4: no ip address for interface after 11 attempts and 5.5s
2021/01/25 09:19:40 470#49 [info] AdGuard Home is available on the following addresses:
2021/01/25 09:19:40 470#49 [info] Go to http://127.0.0.1:80
2021/01/25 09:19:40 470#49 [info] Go to http://[::1]:80
2021/01/25 09:19:44 470#29 [debug] initialized filtering engine
2021/01/25 09:19:44 470#29 [info] Starting the DNS proxy server
2021/01/25 09:19:44 470#29 [info] Cache TTL override is enabled. Min=300, Max=86400
2021/01/25 09:19:44 470#29 [info] Ratelimit is enabled and set to 100 rps
2021/01/25 09:19:44 470#29 [info] The server is configured to refuse ANY requests
2021/01/25 09:19:44 470#29 [info] DNS cache is enabled
2021/01/25 09:19:44 470#29 [info] MaxGoroutines is set to 300
2021/01/25 09:19:44 470#29 [info] Creating the UDP server socket
2021/01/25 09:19:44 470#29 [info] Listening to udp://[::]:53
2021/01/25 09:19:44 470#29 [info] Creating a TCP server socket
2021/01/25 09:19:44 470#29 [info] Listening to tcp://[::]:53
2021/01/25 09:19:44 470#31 [info] Entering the UDP listener loop on [::]:53
2021/01/25 09:19:44 470#30 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*clientsContainer).addFromSystemARP(): executing /usr/sbin/arp [arp -a]
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin...
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin
2021/01/25 09:19:44 470#66 [debug] Filters: updating...
2021/01/25 09:19:44 470#66 [debug] Filters: update finished
2021/01/25 09:19:44 470#32 [info] Entering the tcp listener loop on [::]:53
2021/01/25 09:19:44 470#30 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*clientsContainer).addFromSystemARP(): executing /usr/sbin/arp [arp -a]
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin...
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.(*statsCtx).beginTxn(): db.Begin
2021/01/25 09:19:44 470#66 [debug] Filters: updating...
2021/01/25 09:19:44 470#66 [debug] Filters: update finished
2021/01/25 09:19:44 470#32 [info] Entering the tcp listener loop on [::]:53
2021/01/25 09:19:44 470#68 [debug] querylog: the oldest log entry: 2021-01-24T09:32:52.766932726-05:00
2021/01/25 09:19:44 470#30 [debug] clients: removed 0 client aliases
2021/01/25 09:19:44 470#30 [debug] Clients: added 0 client aliases from 'arp -a' command output
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.71
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.49
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.72
2021/01/25 09:19:44 470#25 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).resolve(): Resolving host for 192.168.25.71
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.3
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.13
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 192.168.25.69
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 169.254.115.200
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 169.254.96.195
2021/01/25 09:19:44 470#29 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.(*RDNS).Begin(): rDNS: adding 169.254.216.143
2021/01/25 09:19:44 470#25 [debug] 207.164.234.129:53: sending request PTR 71.25.168.192.in-addr.arpa.
2021/01/25 09:19:46 470#9 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:41656
2021/01/25 09:19:46 470#8 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:41656
`

DNS works fine.
DHCP works fine as soon as I restart AdGuardHome (either in crontab 15 secs after reboot or manually on the command line).

IP address is static... configured through the dhcpcd.conf file.
I have two interface (ethernet and wireless) connected to the same network.
wireless IP address also static.
DHCP in AdGuardHome is configured to listen to the ethernet interface.

@zadigre
Copy link

zadigre commented Jan 27, 2021

FYI... adguard is installed on Raspberry OS 64 bits (which you see with arm64 on the first line of the log).
besides DHCP server that doesn't come online on boot, everything else works fine.
please let me know if you need me to do other tests.

@ameshkov
Copy link
Member

Well, it seems something is really off with the startup order and I am not sure what we can do on our side to address this.

You need to figure out why the network is not initialized by the time AGH starts up.

@zadigre
Copy link

zadigre commented Jan 31, 2021

I'm not sure either what could be the problem...
I'm no expert in these little things.
I tried to put different services in the After= line... and nothing helped.
I put the ExecStartPre=sleep 5 line ... and this fixed the problem... I no longer have to restart the service after boot to have a working dhcp server.

I'm ok to leave this line as is...
is there a risk this line will be overwritten when AdGuardHome is upgraded?

@ameshkov
Copy link
Member

ameshkov commented Jan 31, 2021

is there a risk this line will be overwritten when AdGuardHome is upgraded?

Nope, AGH does not touch it's service after the installation

@zadigre
Copy link

zadigre commented Feb 2, 2021

could you add an option in the config file to tell the DHCP server to wait a little bit longer... currently I believe with beta 2, it waits 5 seconds... if we could adjust this to lets say 10 seconds, it should work fine (at least for me).

@ameshkov
Copy link
Member

ameshkov commented Feb 3, 2021

It's just there's not much difference between exposing it via the config file or changing the service file, you'll anyway need to make some changes.

I guess as a temporary solution we could just increase the default limit from 5 to 10 seconds and hope that this would solve this issue for most of the users. But we're yet to figure out a better solution. @ainar-g what do you think?

@bunkobugsy
Copy link

actually it's all up to systemd version
https://serverfault.com/questions/736624/systemd-service-automatic-restart-after-startlimitinterval

https://github.com/systemd/systemd/blob/main/NEWS
"CHANGES WITH 229:
The settings StartLimitBurst=, StartLimitInterval=, StartLimitAction= and RebootArgument= have been moved from the [Service] section of unit files to [Unit]"

https://itecnotes.com/server/systemd-service-automatic-restart-after-startlimitinterval/
"Before systemd-230 it was called just StartLimitInterval" so after it's called StartLimitIntervalSec
"StartLimitIntervalSec must be greater than RestartSec * StartLimitBurst otherwise the service will be restarted indefinitely"

myself on systemd 247.3-7+rpi1+deb11u1

@bunkobugsy
Copy link

It's just there's not much difference between exposing it via the config file or changing the service file, you'll anyway need to make some changes.

I guess as a temporary solution we could just increase the default limit from 5 to 10 seconds and hope that this would solve this issue for most of the users. But we're yet to figure out a better solution. @ainar-g what do you think?

No matter what I changed in service file I got this error on boot: [error] dhcpv4: no ip for iface after 10 attempts and 5s
I think the service file only controls AGH service (and it doesn't fail) and not the internal dhcp server restart parameters.
10 attempts and 5 seconds limit are somehow passed by AGH to the internal dhcpd, so yes, maybe increase it to 10 seconds.

@bunkobugsy
Copy link

bunkobugsy commented Jan 11, 2023

Nevermind, found the missing 5 seconds, it was ARP probing:

Jan 11 23:42:05 raspberrypi dhcpcd[314]: eth0: IAID eb:69:64:1a
Jan 11 23:42:05 raspberrypi dhcpcd[314]: eth0: adding address fe80::39ef:9716:f>
Jan 11 23:42:05 raspberrypi dhcpcd[314]: eth0: probing address 192.168.0.2/24
Jan 11 23:42:06 raspberrypi dhcpcd[314]: eth0: soliciting an IPv6 router
Jan 11 23:42:10 raspberrypi dhcpcd[314]: eth0: using static address 192.168.0.2>
Jan 11 23:42:10 raspberrypi dhcpcd[314]: eth0: adding route to 192.168.0.0/24
Jan 11 23:42:10 raspberrypi dhcpcd[314]: eth0: adding default route via 192.168>
Jan 11 23:42:10 raspberrypi dhcpcd[314]: forked to background, child pid 445
Jan 11 23:42:10 raspberrypi systemd[1]: Started DHCP Client Daemon.

Adding noarp to interface in /etc/dhcpcd.conf fixes the problem:
interface eth0
noarp
static ip_address=192.168.0.2/24
static routers=192.168.0.1
static domain_name_servers=8.8.8.8

Jan 12 01:12:51 raspberrypi dhcpcd[314]: DUID 00:01:00:01:2a:be:6d:d5:b8:27:eb:>
Jan 12 01:12:51 raspberrypi dhcpcd[314]: eth0: IAID eb:69:64:1a
Jan 12 01:12:51 raspberrypi dhcpcd[314]: eth0: adding address fe80::39ef:9716:f>
Jan 12 01:12:51 raspberrypi dhcpcd[314]: eth0: using static address 192.168.0.2>
Jan 12 01:12:51 raspberrypi dhcpcd[314]: eth0: adding route to 192.168.0.0/24
Jan 12 01:12:51 raspberrypi dhcpcd[314]: eth0: adding default route via 192.168>
Jan 12 01:12:51 raspberrypi dhcpcd[314]: forked to background, child pid 445
Jan 12 01:12:51 raspberrypi systemd[1]: Started DHCP Client Daemon.
Jan 12 01:12:51 raspberrypi dhcpcd[445]: eth0: soliciting an IPv6 router

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants