Issues with DNS over TLS

IPfire 183 running at RPI. Connectivity to the internet is a LTE modem. I use Brave as my primary web browser and I noticed that I have often issue when I try to search, Brave uses their search engine at search.brave.com. Sometimes this search works but in most cases it doesn’t work and I have to switch to google.com

IPfire forwards DNS queries to DNS server 9.9.9.9, in TLS mode.

I just captured such event, and I see at RPI that there is an issue, with DNS resolver:

[root@rpifire ~]# host search.brave.com
Host search.brave.com not found: 2(SERVFAIL)

[root@rpifire ~]# host search.brave.com 9.9.9.9
Using domain server:
Name: 9.9.9.9
Address: 9.9.9.9#53
Aliases: 

search.brave.com has address 18.239.36.97
search.brave.com has address 18.239.36.14
search.brave.com has address 18.239.36.81
search.brave.com has address 18.239.36.74
search.brave.com has IPv6 address 2600:9000:20a0:c000:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:2600:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:200:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:8000:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:2800:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:8200:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:5a00:5:a6ac:6100:93a1
search.brave.com has IPv6 address 2600:9000:20a0:a800:5:a6ac:6100:93a1

[root@rpifire ~]# host search.brave.com
Host search.brave.com not found: 2(SERVFAIL)

[root@rpifire ~]# host search.brave.com
Host search.brave.com not found: 2(SERVFAIL)

I will switch from Quad9 to CloudFlare and update this post if the issue was fixed or or not…


My RPI has wrong time! It is interesting I have issue only with search.brave.com, other sites were working just fine…

These errors are in /var/log/messages:

Mar  3 04:21:20 rpifire unbound: [1660:0] info: validation failure <search.brave.com. A IN>: signature before inception date from 9.9.9.9 for key search.brave.com. while building chain of trust

Mar  3 04:32:30 rpifire unbound: [1660:0] info: validation failure <search.brave.com. HTTPS IN>: key for validation search.brave.com. is marked as invalid because of a previous

Time at my notebook:

$ date -u
Sun  3 Mar 18:56:17 UTC 2024

RPI with IPfire, time is wrong:

[root@rpifire ~]# date -u
Sun Mar  3 03:38:17 AM UTC 2024

[root@rpifire ~]# ntpdate -q pool.ntp.org
server 162.159.200.123, stratum 3, offset +55094.768532, delay 0.07501
server 147.251.48.140, stratum 2, offset +55094.767734, delay 0.06151
server 77.48.28.248, stratum 2, offset +55094.770576, delay 0.07130
server 162.159.200.1, stratum 3, offset +55094.762263, delay 0.06383
 3 Mar 04:42:44 ntpdate[5712]: step time server 147.251.48.140 offset +55094.767734 sec

[root@rpifire ~]# uptime
 04:46:15 up 2 days, 21:52,  1 user,  load average: 0.07, 0.10, 0.09

My RPI has no RTC module, time is fetched from internet:

[root@rpifire ~]# hwclock 
hwclock: Cannot access the Hardware Clock via any known method.
hwclock: Use the --verbose option to see the details of our search for an access method.

IPfire reports time in the format 12 AM/PM. Locale is set to LC_TIME="en_US.UTF-8". I do not remember if that is a default or if this is configured during setup process. I would like to have time in format 24H but I cannot find an option to change locale in setup script. I assume I have to change locale to en_GB.UTF-8

[root@rpifire ~]# LC_ALL=en_GB.UTF-8 date -u
Sun  3 Mar 04:32:58 UTC 2024

NOTE, it took me several years to find how to switch time format from 12 to 24H at Amazon Kindle ebook reader. It is easy, device language has to be switched from American English to British English… :wink:

This is my current time setting, note a red message Waiting to synchronize clock...:

Option provide time to local network is active but no NTP is running at IPfire, an evidence, ntpdate from notebook to IPfire:

$ ntpdate -q 192.168.111.1
 3 Mar 20:29:50 ntpdate[243310]: no server suitable for synchronization found

Other interesting point is that I cannot find local time of IPfire at WUI, it is not at time server page, it is not at home/status page. No easy way to note an issue with time at IPfire…

From what I seem to remember about NTP…

you have to be somewhat close for NTP to update. If it is off by a large amount of time then NTP may not work as hoped.

this might help with a manual setting of time to help NTP get started:

https://www.ipfire.org/docs/configuration/services/ntp#manual-setting

Is this valid point? I do not think so…

  1. RPI has no RTC clock, time has to be fetched from the internet after power off
  2. ntpdate during boot should update clock to be with sync with NTP time, after that ntp daemon slowly adjusts local time to be in sync with the network of NTP servers with high precision.

So, RPI has some time but is off by several hours. That is an evidence that initial time synchronization was executed. Uptime of RPI is about 2 days, so it happend 2 days ago. I cannot explain why local clock was delayed by such huge offset in just 2 days. It is a mystery I cannot explain. Maybe RPI was busy, maybe other issue. I assume there is an issue here…

Time server setup has option to configure how frequently time is synchronized with NTP network (see screenshot). It looks like there is no NTP server running but cron regularly starts ntpdate to sync time from NTP network; in my case once a day. Maybe that form is not correct… IPcop synced time from crontab, it is possible that IPfire evolved but this form was not updated… I just cannot find any ntpdate call from crontab

UPDATE: script /usr/local/bin/timecheck is called from crontab each 5 minutes, it can be checked with fcrontab -l:

[root@rpifire ~]# fcrontab -l | grep timecheck
2024-03-04 08:56:04  INFO listing root's fcrontab
*/5 * * * *	/usr/local/bin/timecheck > /dev/null 2>&1

File settime.conf is empty, that could be the source of the issue:

[root@rpifire ~]# ll /var/ipfire/time/settime.conf
-rw-r--r-- 2 nobody nobody 0 Mar  3 15:55 /var/ipfire/time/settime.conf

I pressed “Save” button at “Time Server” page and the file was updated with NTP servers (from the form):

[root@rpifire ~]# cat /var/ipfire/time/settime.conf 
162.159.200.1 0.ipfire.pool.ntp.org

Time at IPfire was synced, the red message Waiting to synchronize clock... is gone, I see that ntpd process is running and ntpdate started at notebook can get time from IPfire gateway. It looks great!

[root@rpifire ~]# ntpq -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 LOCAL(0)        .LOCL.          10 l  103   64   36    0.000   +0.000   0.000
*time.cloudflare 10.31.8.128      3 u   33   64   37   71.624   +1.952  12.673
+pyrrha.fi.muni. 63.173.124.164   2 u   37   64   37   73.088   +5.121  10.138

I cannot explain why file settime.conf was empty; that was source of this issue.

I assume that RPI was able to fetch time from internet after power on. Maybe that is not correct and time was set from the last known time before power off, from some file on filesystem.

1 Like

You are right. On boot up time is set, using an IP at ipfire.org if no DNS resolution is possible.
In a running system the defined time servers are used.

settime.conf was empty because you didn’t press ‘save’.
See explanation of standard config behaviour in wiki.

File settime.conf is empty again! Who is the troublemaker??

The last check I did, it was OK:

[root@rpifire ~]# ll /var/ipfire/time/settime.conf 
-rw-r--r-- 2 nobody nobody 36 Mar  4 08:07 /var/ipfire/time/settime.conf

Fresh check, file is empty:

[root@rpifire time]# ll /var/ipfire/time/settime.conf 
-rw-r--r-- 2 nobody nobody 0 Mar  4 08:48 /var/ipfire/time/settime.conf

I modified page “Time Server”, I changed “synchronisation”, from “Daily” to “Manual”, I think it is not needed when NTP server is up and running… I did that change several minutes ago. Was a side affect, that values from settime.conf were erased?? Probably not, because when I press “Save” button, file is updated with NTP servers…

[root@rpifire time]# ll /var/ipfire/time/settime.conf 
-rw-r--r-- 2 nobody nobody 36 Mar  4 09:11 /var/ipfire/time/settime.conf

And just a minute later, it is empty again:

[root@rpifire time]# ll /var/ipfire/time/settime.conf 
-rw-r--r-- 2 nobody nobody 0 Mar  4 09:18 /var/ipfire/time/settime.conf

I fixed file with “save” button:

-rw-r--r-- 2 nobody nobody 36 Mar  4 09:39 /var/ipfire/time/settime.conf

And it is empty again:

-rw-r--r-- 2 nobody nobody 0 Mar  4 09:48 /var/ipfire/time/settime.conf

And again:

-rw-r--r-- 2 nobody nobody 0 Mar  4 10:18 /var/ipfire/time/settime.conf

It looks like some task from cron empties the file. I cannot find script that is responsible for it. The only script that modifies settime.conf is /srv/web/ipfire/cgi-bin/time.cgi but I do not see it is the source of this trouble… It is interesting that timestamp of empty file is ending with 18 and 48 (every 30 minutes), like 08:48, 09:18, 09:48, 10:18, 10:48…

File was touched again at 11:18, I monitored it closely and it happened at 11:18:15.

Could you look ( and post ) at contents of /var/ipfire/time/settings ?

[root@rpifire time]# ll /var/ipfire/time/settings
-rw-r--r-- 1 nobody nobody 173 Mar  4 09:39 /var/ipfire/time/settings

[root@rpifire time]# cat /var/ipfire/time/settings
ENABLESETONBOOT=on
UPDATE_METHOD=manually
ENABLECLNTP=on
VALID=yes
NTP_ADDR_2=0.ipfire.pool.ntp.org
NTP_ADDR_1=162.159.200.1
UPDATE_VALUE=1
UPDATE_PERIOD=daily
ENABLENTP=on

Looks ok.
Are there any messages in /var/log/messages like

ntpdate[31982]: adjust time server 178.215.228.24 offset +0.002419 sec
ipfire: NTP Synchronisierung

The last message from ntpd in /var/log/messages is this, it is related to time when I used Save button to fix the settime.conf:

Mar  4 09:39:08 rpifire ntpdate[6848]: adjust time server 78.80.172.133 offset -0.000238 sec
Mar  4 09:39:08 rpifire ipfire: NTP synchronisation event
Mar  4 09:39:08 rpifire ipfire: NTP synchronization enabled
Mar  4 09:39:08 rpifire ipfire: ntpd restarted
Mar  4 09:39:09 rpifire ntpd[4062]: ntpd exiting on signal 15 (Terminated)
Mar  4 09:39:09 rpifire ntpd[4062]: 127.127.1.0 local addr 127.0.0.1 -> <null>
Mar  4 09:39:09 rpifire ntpd[4062]: 162.159.200.1 local addr 192.168.100.137 -> <null>
Mar  4 09:39:09 rpifire ntpd[4062]: 213.192.54.227 local addr 192.168.100.137 -> <null>
Mar  4 09:39:18 rpifire ntpdate[6928]: adjust time server 78.80.172.133 offset -0.003391 sec
Mar  4 09:39:18 rpifire ipfire: NTP synchronisation event
Mar  4 09:39:18 rpifire ntpd[6948]: ntpd 4.2.8p17@1.4004-o Fri Aug  4 12:02:34 UTC 2023 (1): Starting
Mar  4 09:39:18 rpifire ntpd[6948]: Command line: /usr/bin/ntpd -Ap /var/run/ntpd.pid
Mar  4 09:39:18 rpifire ntpd[6948]: ----------------------------------------------------
Mar  4 09:39:18 rpifire ntpd[6948]: ntp-4 is maintained by Network Time Foundation,
Mar  4 09:39:18 rpifire ntpd[6948]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
Mar  4 09:39:18 rpifire ntpd[6948]: corporation.  Support and training for ntp-4 are
Mar  4 09:39:18 rpifire ntpd[6948]: available at https://www.nwtime.org/support
Mar  4 09:39:18 rpifire ntpd[6948]: ----------------------------------------------------
Mar  4 09:39:18 rpifire ntpd[6948]: DEBUG behavior is enabled - a violation of any
Mar  4 09:39:18 rpifire ntpd[6948]: diagnostic assertion will cause ntpd to abort
Mar  4 09:39:18 rpifire ntpd[6950]: proto: precision = 0.625 usec (-21)
Mar  4 09:39:18 rpifire ntpd[6950]: basedate set to 2023-07-23
Mar  4 09:39:18 rpifire ntpd[6950]: gps base set to 2023-07-23 (week 2272)
Mar  4 09:39:18 rpifire ntpd[6950]: initial drift restored to -6.054000
Mar  4 09:39:18 rpifire ntpd[6950]: Listen and drop on 0 v6wildcard [::]:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listen normally on 2 lo 127.0.0.1:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listen normally on 3 green0 192.168.111.1:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listen normally on 4 red0 192.168.100.137:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listen normally on 5 blue0 192.168.112.1:123
Mar  4 09:39:18 rpifire ntpd[6950]: Listening on routing socket on fd #22 for interface updates
Mar  4 09:39:18 rpifire ntpd[6950]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
Mar  4 09:39:18 rpifire ntpd[6950]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized

That’s nearly identical to my system.
Only difference is the drift value -6.054 ( yours ) vs. 24.139 ( mine ).

BTW: your primary IP isn’t a NTP server. Without DNS the second server name cannot be resolved.
Just try the command from unbound start code
/usr/local/bin/settime 81.3.27.46
81.3.27.46 is ntp.ipfire.org

Why do you think that my primary IP address is not NTP server? Maybe it is geolocated IP address. It is OK from my point of view:

[root@rpifire time]# host 162.159.200.1
1.200.159.162.in-addr.arpa domain name pointer time.cloudflare.com.

[root@rpifire time]# host time.cloudflare.com
time.cloudflare.com has address 162.159.200.1
time.cloudflare.com has address 162.159.200.123
time.cloudflare.com has IPv6 address 2606:4700:f1::123
time.cloudflare.com has IPv6 address 2606:4700:f1::1

[root@rpifire time]# ntpdate -q 162.159.200.1
server 162.159.200.1, stratum 3, offset +0.019678, delay 0.10831
 4 Mar 11:21:36 ntpdate[14216]: adjust time server 162.159.200.1 offset +0.019678 sec

[root@rpifire time]# ntpdate -u 162.159.200.1
 4 Mar 11:27:35 ntpdate[14553]: adjust time server 162.159.200.1 offset -0.002745 sec
[root@rpifire time]# settime 162.159.200.1
hwclock: Cannot access the Hardware Clock via any known method.
hwclock: Use the --verbose option to see the details of our search for an access method.

CloudFlare NTP time service, global anycast network

I do not claim it is source of my issue but I do not like that PERL function flock has magic number as a parameter. An example:

[root@rpifire time]# grep flock /srv/web/ipfire/cgi-bin/time.cgi
		flock(FILE, 2);
		flock(FILE, 2);
			flock(FILE, 2);

I assume that magic number 2 means LOCK_EX as documented in flock doc.

More such “bad” usage could be found with command find /srv/web/ipfire/cgi-bin/ -type f -exec grep flock {} +

I suggest to fix it, to replace all flock(FILE, 2); with flock(FILE, LOCK_EX);

Sorry, I’ve checked with an typo. :frowning:

Guys,
Not diving into the issue above let me share 2 ideas:

  1. Let DNS system resolve your closest NTP server by using a server name like “server 0.COUNTRY_CODE.pool.ntp.org”. You will get fastest and reliable results.
  2. Do not use a loaded huge public DNS servers like 8.8.8.8 for production. Give a try to a little tool I used to use for years to find a real fast and close public DNS server around you:
    GRC's | DNS Nameserver Performance Benchmark  

Have a good day!

None of these ideas address the main issue that file settime.conf is erased every 30 minutes…

2 Likes

I missed one important detail for long time. File settime.conf is hardlinked, it is visible in the output from ls -l:

[root@rpifire tmp]# ll /var/ipfire/time/settime.conf 
-rw-r--r-- 2 nobody nobody 0 Mar  4 13:18 /var/ipfire/time/settime.conf

[root@rpifire tmp]# find / -samefile /var/ipfire/time/settime.conf 2>/dev/null
/var/spool/cron/root.tmp
/var/ipfire/time/settime.conf

[root@rpifire tmp]# ll /var/spool/cron/root.tmp
-rw-r--r-- 2 nobody nobody 0 Mar  4 13:18 /var/spool/cron/root.tmp

The key question is why /var/spool/cron/root.tmp is hardlinked to /var/ipfire/time/settime.conf. Is it only at my IPfire? Is it in every IPfire??

It is not in my IPFire system. I have no /var/spool/cron/root.tmp file.

1 Like

I installed fresh IPfire to virtual machine (VirtualBox 7.0), I started with core 181 and upgraded it to core 183. There is no file /var/spool/cron/root.tmp. I observed situation for a while, I played with IPfire configuration. Then I decided to create that file, this is the command:

ln /var/ipfire/time/settime.conf /var/spool/cron/root.tmp

After a while, I see that size of the file changed to 0, it happened at 15:09. This part can be replicated. I still do not know what process touches that file, I assume it is fcron but I do not have an evidence.

Other question is why these files were linked. It could be my (human) error, that I executed some command that linked file; it is hard to believe I did it but I cannot say for sure. Other explanation could be that this is a result of some filesystem corruption; filesystem is at microSDHC card, RPI is randomly powered off, without proper shutdown. I do not know how I found that file name should be root.tmp. When I rename file root.tmp to root.tmp-0, it is not touched anymore. This is my indirect evidence that the file root.tmp was created by some process, probably fcron. And there is still a possibility that the link was created by some script…


I see other issue, I assume it is a minor issue. Permission of file /var/spool/cron/root is too open, the file can be read by “others”. I see this issue only on newly installed IPcop in Virtual machine, and I cannot see it at IPfire running at RPI. File root has permission 644, it should be 640 or only 600 (600 is permission at RPI):

[root@testfire cron]# pwd; ll
/var/spool/cron
total 12
-rw-r--r-- 1 root root 5353 Mar  4 15:39 root
-rw------- 1 root cron 3472 Nov 21 17:18 root.orig

And I just found how dangerous is command fcrontab -r, it should not be there. I lost crontab of root, I have to reinstall IPfire in virtual machine! When I try to delete a file, I get a polite prompt “are you sure you want to delete regular file?” Crontab is removed without any warning, that is not good… :frowning: DANGEROUS, do not run it:

[root@testfire cron]# fcrontab -r
2024-03-04 16:35:47  INFO removing root's fcrontab
Modifications will be taken into account right now.

[root@testfire cron]# fcrontab -V
fcrontab 3.2.1 - user interface to daemon fcron
Copyright 2000-2016 Thibault Godouet <fcron@free.fr>
This program is free software distributed WITHOUT ANY WARRANTY.
See the GNU General Public License for more details.