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

Add NTP-server/client implementation #1977

Merged
merged 51 commits into from
Jun 29, 2024
Merged

Add NTP-server/client implementation #1977

merged 51 commits into from
Jun 29, 2024

Conversation

DL6ER
Copy link
Member

@DL6ER DL6ER commented May 28, 2024

What does this implement/fix?

Pi-hole's FTL features a full-blown DHCP server that may be used in cases where changing the DNS server of router's internal DHCP servers isn't possible or where greater flexibility is required. The DHCP server is primarily responsible for assigning IP addresses to devices on a network. It can also provide additional configuration information to these devices, such as the addresses of NTP (Network Time Protocol) servers.

NTP is used to synchronize the clocks of computers over a network. Accurate timekeeping is crucial for most modern features.

Why should FTL also offer NTP service:

  1. Simplicity: By providing both DHCP and NTP services, FTL can handle both IP address allocation and time synchronization. This resembles the functionality found in many routers that offer DHCP service.

  2. Efficiency: When a device connects to the network, it can query the Pi-hole for time synchronization making this a very fast (sub-millisecond) synchronization compared to each device individually using online services which are several milliseconds away.

  3. Consistency: By providing NTP services, the DHCP server can ensure that all devices on the network are using the same time source. This can help to prevent inconsistencies. (even when this shouldn't be an issue, usually)


Related issue or feature (if applicable): N/A

Pull request in docs with documentation (if applicable): N/A


By submitting this pull request, I confirm the following:

  1. I have read and understood the contributors guide, as well as this entire template. I understand which branch to base my commits and Pull Requests against.
  2. I have commented my proposed changes within the code.
  3. I am willing to help maintain this change if there are issues with it later.
  4. It is compatible with the EUPL 1.2 license
  5. I have squashed any insignificant commits. (git rebase)

Checklist:

  • The code change is tested and works locally.
  • I based my code and PRs against the repositories developmental branch.
  • I signed off all commits. Pi-hole enforces the DCO for all contributions
  • I signed all my commits. Pi-hole requires signatures to verify authorship
  • I have read the above and my PR is ready for review.

@DL6ER DL6ER requested a review from a team May 28, 2024 19:24
@DL6ER
Copy link
Member Author

DL6ER commented May 28, 2024

Note that the failed spellcheck will be fixed by #1962

Copy link

github-actions bot commented Jun 1, 2024

This pull request has conflicts, please resolve those before we can evaluate the pull request.

1 similar comment
Copy link

github-actions bot commented Jun 1, 2024

This pull request has conflicts, please resolve those before we can evaluate the pull request.

Copy link

github-actions bot commented Jun 1, 2024

Conflicts have been resolved.

@DL6ER DL6ER marked this pull request as draft June 1, 2024 15:20
@DL6ER
Copy link
Member Author

DL6ER commented Jun 1, 2024

Planning to add actual clock setting capability, converting to draft

@DL6ER DL6ER removed the request for review from a team June 1, 2024 15:21
DL6ER added 3 commits June 2, 2024 07:17
…gned 64 bit and double computations as mandated by RFC 5905 (page 28)

Signed-off-by: DL6ER <[email protected]>
@DL6ER DL6ER marked this pull request as ready for review June 2, 2024 08:24
@DL6ER DL6ER requested a review from a team June 2, 2024 08:24
@DL6ER
Copy link
Member Author

DL6ER commented Jun 2, 2024

Ready for review

Copy link
Member

@yubiuser yubiuser left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did not read the whole code yet, just two questions: is the NTP function only enabled when FTL's DHCP server is enabled or is it independent?

In case FTL is the DHCP server do you think it should announce itself as NTP server via DHCP option 42?

@DL6ER
Copy link
Member Author

DL6ER commented Jun 3, 2024

is the NTP function only enabled when FTL's DHCP server is enabled or is it independent?

NTP service is always offered given no other NTP server is running on the same host (and port 123 is already taken)

In case FTL is the DHCP server do you think it should announce itself as NTP server via DHCP option 42?

Absolutely, this is implemented in this PR as well 🙂

image

Copy link
Member

@yubiuser yubiuser left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I played with this PR and while trying to figure out why ntpdate is complaining here from a client, I noticed there are no logs of ntp queries in FTL.log. Maybe you should add some log_debug() that can help identifying issues.

chrko@ThinkPad-X230:~$ ntpdate -vdq 10.0.1.24
 3 Jun 21:42:19 ntpdate[32031]: ntpdate [email protected] Wed Feb 16 17:13:02 UTC 2022 (1)
Looking for host 10.0.1.24 and service ntp
10.0.1.24 reversed to pi.hole
host found : pi.hole
transmit(10.0.1.24)
receive(10.0.1.24)
10.0.1.24: Server dropped: server has gone too long without sync

server 10.0.1.24, port 123
stratum 2, precision -20, leap 00, trust 000
refid [76.79.67.76], root delay 0.000000, root dispersion 0.000000
reference time:      (no time)
originate timestamp: ea089b1b.87cc1871  Mon, Jun  3 2024 21:42:19.530
transmit timestamp:  ea089b1b.847b2f76  Mon, Jun  3 2024 21:42:19.517
delay 0.02666, dispersion 0.00000, offset -0.001330

 3 Jun 21:42:19 ntpdate[32031]: no server suitable for synchronization found

@yubiuser
Copy link
Member

yubiuser commented Jun 3, 2024

Where does the server part get its time from? Is it just using the hosts current time? I did not find a trace where FTL is querying a public NTP server.

@yubiuser
Copy link
Member

When using pihole-FTL ntp there is only partially logging to FTL.log (even with debug ntp). With no additional argument the individual queries are logged, but not the summary. When using a different upstream (with pihole-FTL ntp server) nothing is loggend at all (might be desired).

Additionally with the --update flag, opening and setting the RTC is not logged at all (with and without [server])

@DL6ER
Copy link
Member Author

DL6ER commented Jun 16, 2024

Not exactly sure what you mean, let me try a few things here:

$ sudo pihole-FTL --config debug.ntp false &&  pihole-FTL ntp
false
........
Received 8/8 valid NTP replies from 127.0.0.1
Average time offset: (-2.264977e-06 +/- 3.150939e-05 s)
Average round-trip delay: (3.192425e-04 +/- 1.041611e-04 s)
Trimmed mean time offset: 7.969993e-06 s (excluded 1 outliers)
Trimmed mean round-trip delay: 2.851486e-04 s (excluded 1 outliers)

-> no logging to FTL.log

$ sudo pihole-FTL --config debug.ntp true && pihole-FTL ntp
true
Server reference time: ea18efb7.eae8aa90 = 2024-06-16 06:59:35.917612 CEST
Current time at client: ea18f04d.48c1ca3a = 2024-06-16 07:02:05.284206 CEST
Current time at server: ea18f04d.48b9ecf6 = 2024-06-16 07:02:05.284086 CEST
Time offset: 6.771088e-05 s
Round-trip delay: 3.747940e-04 s
Root delay: 1.429901e-01 s
Root dispersion: 1.373291e-04 s
[...]
.
Received 7/8 valid NTP replies from 127.0.0.1
Average time offset: (6.675720e-06 +/- 2.751231e-05 s)
Average round-trip delay: (2.598081e-04 +/- 6.134486e-05 s)
Trimmed mean time offset: -3.496806e-06 s (excluded 2 outliers)
Trimmed mean round-trip delay: 2.406438e-04 s (excluded 2 outliers)

-> everything that is logged to FTL.log is the server thread's debug messages, the client shouldn't log anything. That's also why there's no summary in the log (the server does not see a summary):

2024-06-16 07:02:06.287 CEST [3690425/T3690430] DEBUG_NTP: Received NTP request from 127.0.0.1:47308
2024-06-16 07:02:06.290 CEST [3691281/F3690425] DEBUG_NTP: Reference Timestamp: ea18efb7.eae8aa90 = 2024-06-16 06:59:35.917612 CEST
2024-06-16 07:02:06.291 CEST [3691281/F3690425] DEBUG_NTP: Origin Timestamp: ea18f04e.49a3c211 = 2024-06-16 07:02:06.287654 CEST
2024-06-16 07:02:06.291 CEST [3691281/F3690425] DEBUG_NTP: Receive Timestamp: ea18f04e.49a9da59 = 2024-06-16 07:02:06.287747 CEST
2024-06-16 07:02:06.291 CEST [3691281/F3690425] DEBUG_NTP: Transmit Timestamp: ea18f04e.4a88effe = 2024-06-16 07:02:06.291151 CEST
[...]

Mind that the shown PID differs from the usual FTL process as NTP workers fork to achieve parallelism and avoid blocking if multiple queries arrive at the same time.

The reason that everything that is being logged is the server also explains why you haven't seen any RTC setting. When the client is run from within your FTL process (to automatically sync the clock in the background), everything will be logged to FTL.log as there is no terminal to print stuff onto.

@DL6ER
Copy link
Member Author

DL6ER commented Jun 16, 2024

NB: I was now running three days without new/ntp and the first sync after switching back already had to correct my local time (incl. RTC) by two seconds underlining the usefulness of this change for Pi-hole matters.

…ng the internal NTP synchronization method. This ensures FTL can import the real most recent 24 hours data of history after a restart on a system lacking a real hardware clock

Signed-off-by: DL6ER <[email protected]>
Copy link

This pull request has conflicts, please resolve those before we can evaluate the pull request.

Copy link

Conflicts have been resolved.

@yubiuser
Copy link
Member

everything that is logged to FTL.log is the server thread's debug messages, the client shouldn't log anything. That's also why there's no summary in the log (the server does not see a summary):

Ok, this explains my questions about the logging.

Copy link
Member

@yubiuser yubiuser left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nanopi@nanopi:~$ pihole-FTL ntp --update
....
Gradually adjusting system time by -135 us
Error NTP client: Failed to adjust time during NTP sync: Insufficient permissions
add_message(type=13, message=Failed to adjust time during NTP sync: Insufficient permissions) - SQL error step DELETE: attempt to write a readonly database
Error while trying to close database: database is locked
log_ntp_message(): Failed to add message to database

We should check for sufficient permissions early and fail gracefully.

@yubiuser
Copy link
Member

Regarding your last commit: should we change the startup order to check first for the correct time and then import the queries - this could maybe avoid a restart if the time was off to far.


024-06-25 22:54:07.826 CEST [349294M] INFO: Imported 8102 queries from the long-term database
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Total DNS queries: 8102
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Cached DNS queries: 3983
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Forwarded DNS queries: 2601
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Blocked DNS queries: 1406
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Unknown DNS queries: 31
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Unique domains: 959
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> Unique clients: 11
2024-06-25 22:54:07.826 CEST [349294M] INFO:  -> DNS cache records: 1886
2024-06-25 22:54:07.827 CEST [349294M] INFO:  -> Known forward destinations: 6
2024-06-25 22:54:07.827 CEST [349294/T349296] INFO: NTP server listening on 0.0.0.0:123 (IPv4)
2024-06-25 22:54:07.827 CEST [349294/T349297] INFO: NTP server listening on :::123 (IPv6)
2024-06-25 22:54:07.828 CEST [349294M] INFO: FTL is running as user pihole (UID 999)
2024-06-25 22:54:07.828 CEST [349294M] INFO: Reading certificate from /etc/pihole/tls.pem ...
2024-06-25 22:54:07.829 CEST [349294M] INFO: Using SSL/TLS certificate file /etc/pihole/tls.pem
2024-06-25 22:54:07.831 CEST [349294M] INFO: Restored 1 API session from the database
2024-06-25 22:54:07.836 CEST [349294M] INFO: Blocking status is enabled
2024-06-25 22:54:08.000 CEST [349294/T349299] INFO: Compiled 6 allow and 1 deny regex for 11 clients in 68.6 msec
2024-06-25 22:54:12.450 CEST [349294/T349298] INFO: Received 8/8 valid NTP replies from de.pool.ntp.org
2024-06-25 22:54:12.451 CEST [349294/T349298] INFO: Time offset: 1.657626e+01 ms (excluded 0 outliers)
2024-06-25 22:54:12.451 CEST [349294/T349298] INFO: Round-trip delay: 5.545336e+01 ms (excluded 0 outliers)
2024-06-25 22:54:13.000 CEST [349294/T349298] INFO: Current RTC time is 2024-06-25 20:54:13


@DL6ER
Copy link
Member Author

DL6ER commented Jun 26, 2024

We should check for sufficient permissions early and fail gracefully.

Ah, you mean concerning the database, yes. The most recent commits made this:

$ pihole-FTL ntp de.pool.ntp.org --update
........
Received 8/8 valid NTP replies from de.pool.ntp.org
Time offset: 9.241263e+00 ms (excluded 2 outliers)
Round-trip delay: 5.255381e+00 ms (excluded 2 outliers)
Error NTP client: Failed to adjust time during NTP sync: Insufficient permissions
Cannot open database in read-write mode

Regarding your last commit: should we change the startup order to check first for the correct time and then import the queries - this could maybe avoid a restart if the time was off to far.

The idea proposed here is to start the resolver and import queries only once the first NTP synchronization finished. NTP synchronization can take everything between 4 seconds (minimum when everything works) to 40 seconds (when all eight attempts time out after five seconds each). I implemented this now.

Before NTP synchronization finished, the web interface will look like
before NTP sync
and thereafter
after NTP sync
and then (a long time afterwards!)
image

The reason is that all the main graphs aren't updated very often. We need to make a change to the web interface to force reloading the large graphs if the total queries number jumps significantly. My suggestions would be a jump of a factor 2 but at least 100 in absolute numbers. To avoid reloading often once we go from 2 to 4 to 8, ... queries.

Signed-off-by: DL6ER <[email protected]>
@yubiuser
Copy link
Member

Ah, you mean concerning the database, yes. The most recent commits made this:

My idea was more about check_capability(CAP_SYS_TIME) and do not perform any NTP queries if the permission are not granted at all.


Can you add the detail log of what queries are imported after the import again? Currently it is not much of a use to see details of zero imported queries and no details after the import.

2024-06-26 22:23:31.412 CEST [362251M] INFO: Database successfully initialized
2024-06-26 22:23:31.446 CEST [362251M] INFO:  -> Total DNS queries: 0
2024-06-26 22:23:31.446 CEST [362251M] INFO:  -> Cached DNS queries: 0
2024-06-26 22:23:31.446 CEST [362251M] INFO:  -> Forwarded DNS queries: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> Blocked DNS queries: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> Unknown DNS queries: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> Unique domains: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> Unique clients: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> DNS cache records: 0
2024-06-26 22:23:31.447 CEST [362251M] INFO:  -> Known forward destinations: 0
2024-06-26 22:23:31.448 CEST [362251/T362252] INFO: NTP server listening on 0.0.0.0:123 (IPv4)
2024-06-26 22:23:31.448 CEST [362251/T362253] INFO: NTP server listening on :::123 (IPv6)
.....
2024-06-26 22:23:35.676 CEST [362251/T362254] INFO: Received 8/8 valid NTP replies from de.pool.ntp.org
2024-06-26 22:23:35.677 CEST [362251/T362254] INFO: Time offset: 3.415857e-01 ms (excluded 1 outliers)
2024-06-26 22:23:35.677 CEST [362251/T362254] INFO: Round-trip delay: 2.570173e+01 ms (excluded 1 outliers)
2024-06-26 22:23:36.000 CEST [362251/T362254] INFO: Current RTC time is 2024-06-26 20:23:36
2024-06-26 22:23:36.756 CEST [362251/T362254] INFO: Imported 6918 queries from the on-disk database (it has 1242488 rows)
2024-06-26 22:23:36.756 CEST [362251/T362254] INFO: Parsing queries in database
2024-06-26 22:23:37.221 CEST [362251/T362254] INFO: Imported 6918 queries from the long-term database
2024-06-26 22:24:00.735 CEST [362251/T362255] INFO: Size of /etc/pihole/pihole-FTL.db is 83.38 MB, deleted 151 rows

@DL6ER DL6ER merged commit fbae3b9 into development-v6 Jun 29, 2024
17 checks passed
@DL6ER DL6ER deleted the new/ntp branch June 29, 2024 19:48
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants