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

DNSSEC broken with dnsmasq 2.80 #163

Closed
BugReporter-ilKY opened this issue Apr 26, 2019 · 28 comments · Fixed by #164
Closed

DNSSEC broken with dnsmasq 2.80 #163

BugReporter-ilKY opened this issue Apr 26, 2019 · 28 comments · Fixed by #164

Comments

@BugReporter-ilKY
Copy link
Contributor

BugReporter-ilKY commented Apr 26, 2019

I'm running dnsmasq as DHCP and DNS server with DNSSEC enabled. A recent upgrade of Freetz also upgrades dnsmasq which broke DNS. After each reboot any DNS query would fail with reply <TLD> is BOGUS DS. Disabling DNSSEC for a short time fixed the problem permanently (until the next reboot that is) and also DNSSEC worked fine again.

After looking into the issue I figured out the problem and a found a similar bug report for Pihole:

  • --dnssec-check-unsigned is the default now, which is actually good
  • The Fritz box starts up with a bogus time and date (Jan 1 01:01:14 fritz syslog.info syslogd started: BusyBox v1.27.2). I was surprised to find the Fritz box does not have an RTC.
  • DNSSEC checks require proper time and date and thus fail
  • NTP requires resolution of the time server's DNS name and thus fails

Disabling DNSSEC resolves the deadlock by allowing NTP to set the correct time which in turn allows DNSSEC validation. The current state is just plain bad: DNSSEC fails without any obvious reason. The obvious “solution” is to disable DNSSEC, but that's not good. One real option would be not to use Dnsmasq as the local resolver. That also means not to have DNSSEC for the box. Not too nice either. Probably the best choice is to only do this until NTP updated the clock. Any idea how to handle this properly?

[edit] The bug is generic, but for completeness: I have a FritzBox 7360SL running on freetz-devel-15014.[/edit]

@PeterPawn
Copy link
Contributor

Defer DNSMASQ startup until a valid time was set - a possible solution: https://github.com/PeterPawn/YourFritz/blob/master/tools/waittimeset ... but this doesn't work for x86 systems on Puma devices, because the timer value isn't always initialized with an epoch value of zero there (you need a bigger value in line 4 for this models).

Add your own attempt to set a valid time at startup - I personally use a local time server according to RFC 868 and the rdate applet from BusyBox:

root@FB7490:~ $ cat /etc/init.d/S50-rdate
#! /bin/false
# avoid to be called without explicit shell invocation
# vim: set syntax=sh tabstop=2 shiftwidth=2 highlight=on
#################################################################################
#                                                                               #
# S50-rdate                                                                     #
#                                                                               #
# try to set our RTC from a local network source, this may lead to a faster     #
# boot process, because any process waiting for a valid local time may continue #
# to run after this script sets the correct date and time                       #
#                                                                               #
#################################################################################
#                                                                               #
# our configuration                                                             #
#                                                                               #
#################################################################################
CFG=$YF_CONFIG_CFGDIR/rdate.conf
#################################################################################
#                                                                               #
# try to find our configuration file, the YF_CONFIG values are set by caller    #
#                                                                               #
#################################################################################
if [ -f $CFG ]; then
        if [ -s $CFG ]; then
                SERVER=$(sed -n -e "s|^SERVER=\(.*\)\$|\1|p" $CFG)
                if [ ${#SERVER} -gt 0 ]; then
                        SERVER="${SERVER//\"/}"
                fi
                /bin/busybox logger "Setting date/time from server $SERVER"
                /bin/busybox rdate $SERVER
        fi
fi
#################################################################################
#                                                                               #
# end of script                                                                 #
#                                                                               #
#################################################################################

An alternative approach is a simple HTTP GET request to any (at its best also a local) host, which has (for sure) a valid date/time value. If you use nc for this request and try to get data from an invalid URL, you'll get (in most cases) an answer containing the current date/time and the only remaining task is to parse it and use the value in a call of date with the --set option.

There are some programs, that offer this function (reading date/time via HTTP) - but this task is sooo simple, that I would never use one of these offers and implement it with the "basic applets" from BusyBox.
There's nearly always a local source for date/time values - and you may implement it with an additional check (for a valid value) and a (sequential) list of possible sources, if one of these devices may not available at a time.

Waiting for a valid value from an internet source is not always a good idea - but you have to wait, until the local network of your FRITZ!OS device is up and running. Therefore I've used this (late) hook with S50 - the local network gets re-initialized during dsld startup at stage 4 of init process. Do not try to use the (more obvious looking) script S09-rtc for your own additions - the local network may be unusable at this time.

A broken internet connection (no matter, what's the reason for) would render your local infrastructure unusable, if you restart the router (with the hope, a previous problem would vanish now), but it can't get a new internet connection immediately and nevertheless the startup of your local DNS server would be deferred, until a new internet connection gets available (if the DNSMASQ instance isn't only the forwarder for requests of external addresses) - as a result, your local devices would be unable to communicate with others (using their names).

If there's a small deviation from the time, that gets set later by AVM's chronyc, it's no problem ... as long as this difference is small enough.

And if you have a 24/7 running, local NTP server anyway (from a local Linux server with a RTC (RasPi?) or a NAS device or somewhere else), you may set its local address as NTP server for FRITZ!OS, too - then there's no need for a single line of additional script code.

@feedzapper
Copy link

feedzapper commented Apr 26, 2019

There is no bug in dnsmasq and dnssec. himself
The issue is in the "default config " from freetz with dnsmasq + dnssec.
It NEEDS to set "dnssec-no-timecheck" for boot at the first time until the correct time in the router is received by NTP.
if you use dnssec with wrong time parameters (booting with activated timecheck) can results in HUGE
reactions of dnsmasq as you mentioned !
Is the "correct" time given by the router, a SIGINT "killall -INT dnsmasq" command sent to the dnsmasq process, enables timecheck for ddnssec from now.

Refer also here these links to understand the mechanism :
https://www.linksysinfo.org/index.php?threads/fork-freshtomato-arm.74117/page-24#post-304474

https://www.linksysinfo.org/index.php?threads/fork-freshtomato-arm.74117/page-24#post-304535

i forgot - short workaround / solution in the default freetz config :
add "dnssec-no-timecheck" to the Freetz -> dnsmasq -> extra config

Note : from this point timecheck for dnssec would NOT not be automatically activated by Freetz !

You need to sent SIGINT to dnsmasq for doing this by commandline or by a script that not (yet)
exists....

@BugReporter-ilKY
Copy link
Contributor Author

[PeterPawn]

There's nearly always a local source for date/time values

Not a reliable/always-up one in my case. The reason I use Freetz is that I want to have “the essentials” (DHCP, DNS, NTP, VPN/SSH, VoIP, tiny NAS) directly on the router.

[feedzapper]

short workaround / solution in the default freetz config :
add "dnssec-no-timecheck" to the Freetz -> dnsmasq -> extra config

Thanks. I considered combining this with the script approach PeterPawn suggested. But the dnsmasq manual (which I should have read more carefully in the first place) offers an even more convenient option, dnssec-timestamp:

Enables an alternative way of checking the validity of the system time
for DNSSEC (see --dnssec-no-timecheck). In this case, the system time
is considered to be valid once it becomes later than the timestamp on
the specified file. The file is created and its timestamp set auto‐
matically by dnsmasq. The file must be stored on a persistent filesystem,
so that it and its mtime are carried over system restarts. The timestamp
file is created after dnsmasq has dropped root, so it must be in a
location writable by the unprivileged user that dnsmasq runs as.

I could not find writable permanent storage, but dnsmasq merely relies on the file's mtime. So I set the extra options to --dnssec-timestamp=/bin/busybox and that seems to work nicely.

@PeterPawn
Copy link
Contributor

that seems to work nicely.

Would you provide a patch for dnsmasq_conf?

@feedzapper
Copy link

feedzapper commented Apr 27, 2019

I could not find writable permanent storage, but dnsmasq merely relies on the file's mtime. So I set the extra options to --dnssec-timestamp=/bin/busybox and that seems to work nicely

A lot of boxes have a minimum of internal NAS space 7360SL does not ?
Also you can store "mtime" in /tmp/flash directory from the Box, but it needs to make a "modsave" command that makes this file permanent in the flash. Maybe a solution ? - each time dnsmasq would be started, it updates the dnssec-timestamp file in /tmp/flash. Also this needs each time a "modsave"
to keep the mtime file up-to-date in the flash ....

dnssec-timestamp=/tmp/flash/mtime
user=root

Also it is possible to create a EMTPY file e.g. with nano "mtime" in /tmp/flash directory. this file got a FIXED system time. Doing a "modsave" to make this permanent in the flash.
dnsmasq-timestamp using this file eachtime after boot - point to /tmp/flash/mtime
Also this is a real "writetable path"
But i am not sure about the FIXED timestamp is a problem with dnsmasq dnssec.
I think dnsmasq checks only for a newer system time than the file "mtime" does had.
if this is given dnssec timecheck would be activated.

@PeterPawn
Copy link
Contributor

In my opinion, the solution using a file from the SquashFS image is absolutely sufficient, if it works as expected and looking into the source code (http://thekelleys.org.uk/gitweb/?p=dnsmasq.git;a=blob;f=src/dnssec.c;h=9bf43a2e1b70792bd769ac37e10d62ad1a46b30a;hb=HEAD), it should solve the problem, because only the modification time of the specified file is used instead of the fixed value "2015-01-01" (if the file does not exist). There's no need to invent any new file for this check.

There's no later obvious attempt visible to write or change the file, beside the one in line 170 and this one is only executed, if the file did not exist (ENOENT).

But I would suggest to use another file for this timestamp ... simply due to the fact, that AVM itself uses the date/time of /etc/version in another place already (look into /etc/version for the --date option).

Therefore this value should always be valid, the file will always exist and it's a "fixed" reference for all Freetz images built from the same AVM version.

Using "/bin/busybox" as source leads to a varying time source and in worst case, when things are going really badly, the build system doesn't have a valid time set while creating the image (OK, that's only a theoretical problem).

But because the time of the original file is preserved while modifying the firmware, a valid (and common) timestamp is ensured while using this file.

@BugReporter-ilKY
Copy link
Contributor Author

[PeterPawn]

Would you provide a patch for dnsmasq_conf?

Sure. I didn't rebuild my firmware yet but following the other parts of that file, this should do the trick.

[feedzapper]

A lot of boxes have a minimum of internal NAS space 7360SL does not ?

You are right. There is writable storage in /data

$ df -h
Filesystem Size Used Available Use% Mounted on
/dev/root 13.1M 13.1M 0 100% /
/dev/mtdblock5 1.0M 452.0K 572.0K 44% /data
/dev/loop0 274.0K 253.0K 7.0K 97% /var/media/ftp

It just looked weird to me that there are supposedly 452KB of data there, but I can find no files. So I didn't want to use that filesystem. And a firmware file (now /etc/version) solves the problem as well and avoids writing to flash.

@PeterPawn
Copy link
Contributor

this should do the trick.

I agree - and thanks for the (smart) solution and the patch.

But it seems, my question was too vague.

The best (and easiest) manner to incorporate the change(s) to Freetz master is a "pull request" and lastly I wanted to know, whether you will provide this PR yourself or if someone else should create one and refer to this issue.

BugReporter-ilKY added a commit to BugReporter-ilKY/freetz that referenced this issue Apr 27, 2019
When DNSSEC is enabled, disable its time checks until NTP set the
system time properly. Reuse /etc/version as reference file.

Closes Freetz#163
@er13 er13 closed this as completed in #164 Apr 28, 2019
er13 pushed a commit that referenced this issue Apr 28, 2019
When DNSSEC is enabled, disable its time checks until NTP set the
system time properly. Reuse /etc/version as reference file.

Closes #163
@er13
Copy link
Member

er13 commented May 5, 2019

Btw. cuma's solution for the same problem: https://trac.boxmatrix.info/freetz-ng/changeset/15335/freetz-ng

@PeterPawn
Copy link
Contributor

Fortsetzung von #187 (comment):

Der Fehler dürfte auch nur bei einem Neustart des Daemons auftreten, wenn die Box bereits eine gültige Uhrzeit hat. Dann muß man allerdings tatsächlich noch etwas unternehmen, wenn man diesen Fehler (der ansonsten aber keinerlei Auswirkungen haben dürfte) nicht haben möchte.

Auswirkungen hat er (neben der erwähnten Fehlermeldung) deshalb nicht, weil trotzdem die nachfolgenden Zeilen

 159           if (utimes(daemon->timestamp_file, NULL) == -1)
 160             my_syslog(LOG_ERR, _("failed to update mtime on %s: %s"), daemon->timestamp_file, strerror(errno));
 161           daemon->back_to_the_future = 1;
 162           return 0;

ausgeführt werden und der Daemon mit der Signaturprüfung beginnt.

Entweder man patcht die Fehlermeldung generell weg oder man baut vor dem "utimes"-Aufruf noch einen Test ein, ob das Dateisystem mit dieser Datei generell änderbar ist oder nicht.

Ich wäre für einen einfachen "utimes()"-Aufruf mit Ignorieren eines Fehlers ... zwar kommt der Daemon da auch nur einmal beim Start vorbei, aber solange die Meldung zu erwarten ist (das ist nun mal bei einem r/o-Filesystem so) und ohnehin nur auftritt, wenn man bereits eine Uhrzeit hat (woher auch immer), wenn der Daemon gestartet wird UND wenn außer der Meldung nichts weiter geschieht, braucht es diese Meldung auch nicht. Ich würde deshalb jedenfalls nicht in Erwägung ziehen, eine andere Datei an einer anderen Stelle zu verwenden.

@er13 er13 reopened this May 29, 2019
@WileC
Copy link
Contributor

WileC commented May 30, 2019

Spricht was dagegen, die /etc/version nach /var/tmp zu verschieben und per symlink zu referenzieren?! Dann wäre sie beschreibbar.

@er13
Copy link
Member

er13 commented May 30, 2019

Handelt es sich bei Deinem Vorschlag um Deinen eigenen? Bitte, sofern es sich nicht um Deinen eigenen Vorschlag handelt, immer explizit und ohne explizite Aufforderung die Quelle bzw. den Author angeben. Dein Vorschlag entspricht dem in freetz-ng umgesetzten.

Ansonsten habe ich mir noch keine Meinung bilden können. Denn, Stand jetzt, verstehe ich noch nicht mal, wozu man überhaupt mtimes von der dnssec-timestamp-Datei updaten muss (habe den Quellcode von dsnmasq allerdings noch nicht gelesen). Und da ich es nicht verstehe, tendiere ich zum Rauspatchen der Log-Meldung bzw. sogar des utimes-Aufrufs.

@PeterPawn
Copy link
Contributor

Ich verstehe ohnehin nicht, warum der dnsmasq da die Angabe aktualisieren will.

Schaut man sich die dnsmasq-Quellen an, arbeitet die ganze Logik in check_date_range() ohnehin nur auf der Basis von daemon->back_to_the_future (also einer boolschen Variablen), auch wenn es in dnssec.c (Zeile 203) erst mal anders erscheint.

Zwar wird dort dann mittels utimes() das Dateidatum auch noch einmal versucht zu ändern, wenn eine Uhrzeit erreicht/eingestellt wurde, die jenseits der bisher in timestamp_time gespeicherten liegt. Nur wird der zum Vergleich herangezogene Wert in timestamp_time dabei nicht aktualisiert und so ist die Tatsache, daß ab diesem Zeitpunkt das Protokoll nicht mit den Meldungen:

 208           my_syslog(LOG_INFO, _("system time considered valid, now checking DNSSEC signature timestamps."));

geflutet wird, nur der Tatsache zuzuschreiben, daß parallel noch daemon->back_to_the_future auf 1 gesetzt wird und der Code in den Zeilen 205 bis 211 deshalb nicht erneut ausgeführt wird.

Das Setzen von timestamp_time erfolgt in setup_timestamp() (da findet sich auch noch einmal das Setzen der Zeit, wenn es beim Start schon später ist als im Dateidatum) und dieses wird exakt ein einziges Mal aus dnsmasq.c heraus aufgerufen (in main und sonst nirgends).

Wenn ich da nichts Fundamentales übersehe, interessiert sich dnsmasq bis zum nächsten Start gar nicht mehr für das Änderungsdatum dieser Datei ... und da es dann garantiert beim nächsten Start auch wieder später sein wird, als im Änderungsdatum dieser Datei vermerkt, läuft exakt wieder derselbe Vorgang ab, weil es gar keine Rolle spielt, WIE GROSS die Differenz zwischen dem Dateidatum und der aktuellen Zeit ist - nur die Relation an sich spielt hier eine Rolle.

Da ist eine Datei im r/o-Speicher sogar noch ein Schutz gegen das "Abschalten" der Signaturprüfung ... denn wenn es einem Angreifer gelingt, das Datum dieser Datei weit genug in die Zukunft zu verschieben (wenn sie an einer beschreibbaren Stelle liegt), wird die Signaturprüfung solange ausgesetzt, bis es wieder später ist, als das Dateidatum es vorgibt. Solche Angriffe sind auch nicht nur graue Theorie, hierfür reicht wieder ein manipulierter NTP-Server, wenn der Client nur einen einzigen befragt (m.W. macht das FRITZ!OS genau das).

@WileC
Copy link
Contributor

WileC commented May 30, 2019

@er13 Es war mein eigener Gedanke!!! Weil in meinem LOG eben der Hinweis auf "read only filesystem" auftaucht... Daher liegt's einfach nahe, per Symlink die Datei auf ein beschreibbares FS auszulagern!

er13 added a commit that referenced this issue Jun 19, 2019
@er13
Copy link
Member

er13 commented Jun 19, 2019

395b25c is compile-tested only. Könnte bitte jemand, der dnsmasq auf der Box hat (@WileC vielleicht Du), es testen? Danke!

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

@er13 erledigt, anbei das LOG beim Startup meiner 3490 mit DNSMasq:

Jan  1 01:02:13 fritz user.notice ONLINECHANGED[4172]: [online] approved
Jan  1 01:02:13 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] waiting
Jan  1 01:02:13 fritz user.notice ONLINECHANGED[4172]: [online] executing /etc/onlinechanged/00-get_ip
Jan  1 01:02:13 fritz user.notice ONLINECHANGED[4172]: [online] executing /etc/onlinechanged/webdav_net
Jan  1 01:02:13 fritz user.notice ONLINECHANGED[4172]: [online]  * webdav_net online status_onlinev4
Jan  1 01:02:13 fritz kern.info kernel: [  133.910000][1]kdsld: flushing internet sessions
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4172]: [online] executing /tmp/flash/onlinechanged/onlinechanged-cgi
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4172]: [online] finished
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] approved
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] executing /etc/onlinechanged/00-get_ip
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] executing /etc/onlinechanged/webdav_net
Jan  1 01:02:14 fritz user.notice ONLINECHANGED[4176]: [onlineipv6]  * webdav_net onlineipv6 status_onlinev4v6
Jan  1 01:02:15 fritz kern.err kernel: [  135.130000][1][ppe_setup_qos_write] avmwanqueuesetrate 1 1000000
Jan  1 01:02:15 fritz kern.warn kernel: [  135.260000][1][1]system-load 100% loadavg 0.75 0.41 0.16 - 112 tasks:2 % curr:webdavcfginfo(0 %) max:avmike(1 %, pid:4166) pgstat: sum=63613 free=25810 slab=4646 alloc=51/s fault=155/s ai_sys:15.18/min 0x805b5d60 pndisc_const
Jan  1 01:00:30 fritz daemon.info dnsmasq[2936]: started, version 2.80 cachesize 150
Jan  1 01:00:30 fritz daemon.info dnsmasq[2936]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: DNSSEC validation enabled
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: DNSSEC signature timestamps not checked until system time valid
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: configured with trust anchor for <root> keytag 20326
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: configured with trust anchor for <root> keytag 19036
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: asynchronous logging enabled, queue limit is 10 messages
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.251.1#53 for domain 251.168.192.in-addr.arpa (no DNSSEC)
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.251.1#53 for domain rmk-hotspot.lan (no DNSSEC)
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.10.1#53 for domain 10.168.192.in-addr.arpa (no DNSSEC)
Jun 20 09:52:33 fritz daemon.warn dnsmasq[2936]: overflow: 17 log entries lost
Jun 20 09:52:33 fritz daemon.info dnsmasq[2936]: read /etc/hosts - 33 addresses
Jun 20 09:52:34 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] executing /tmp/flash/onlinechanged/onlinechanged-cgi
Jun 20 09:52:34 fritz user.notice ONLINECHANGED[4176]: [onlineipv6] finished
Jun 20 09:52:34 fritz user.err telefon[3208]: set initial telefon time from linux time to 9:52:34 20.06 2019!
Jun 20 09:52:47 fritz kern.info kernel: [  149.390000][0]kdsld: IPv6: internet: gu 2003:c1:37ff:164c:ca0e:14ff:fe18:1f10 remote ::
Jun 20 09:52:49 fritz kern.info kernel: [  151.310000][0]/proc/tffs: info request: success

@PeterPawn
Copy link
Contributor

PeterPawn commented Jun 20, 2019

Da fehlt jetzt aber der Eintrag

system time considered valid, now checking DNSSEC signature timestamps.

im Protokoll.

Dem Patch nach zu urteilen, sollte die Nachricht aber trotzdem erscheinen, bevor back_to_the_future auf 1 gesetzt wird.

Der Ausschnitt aus dem Protokoll reicht also nicht aus, um die Funktion des Patches nachzuweisen - ob die Fehlernachricht wg. des Patches unterbleibt oder weil der Daemon die Änderung der Uhrzeit gar nicht geschnallt hat, kann man nicht sagen ... wobei die Wahrscheinlichkeit für letzteres deutlich höher liegt.

Es kann aber auch am Puffern der Log-Einträge im "dnsmasq"-Daemon liegen, daß die noch nicht ausgegeben wurden bis zu diesem Punkt.

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Das ist alles, was mein Log bei einem Boot der 3490 bzgl. DNSMasq hergibt:

Jan  1 01:00:30 fritz daemon.info dnsmasq[2936]: started, version 2.80 cachesize 150
Jan  1 01:00:30 fritz daemon.info dnsmasq[2936]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: DNSSEC validation enabled
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: DNSSEC signature timestamps not checked until system time valid
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: configured with trust anchor for <root> keytag 20326
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: configured with trust anchor for <root> keytag 19036
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: asynchronous logging enabled, queue limit is 10 messages
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.251.1#53 for domain 251.168.192.in-addr.arpa (no DNSSEC)
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.251.1#53 for domain rmk-hotspot.lan (no DNSSEC)
Jan  1 01:00:31 fritz daemon.info dnsmasq[2936]: using nameserver 192.168.10.1#53 for domain 10.168.192.in-addr.arpa (no DNSSEC)
Jun 20 09:52:33 fritz daemon.warn dnsmasq[2936]: overflow: 17 log entries lost
Jun 20 09:52:33 fritz daemon.info dnsmasq[2936]: read /etc/hosts - 33 addresses
Jun 20 09:55:47 fritz daemon.warn dnsmasq[2936]: Insecure DS reply received, do upstream DNS servers support DNSSEC?
Jun 20 09:55:47 fritz daemon.warn dnsmasq[2936]: Insecure DS reply received, do upstream DNS servers support DNSSEC?

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Nach einem restart des DNSMasq:

Jun 20 10:38:30 fritz daemon.info dnsmasq[2936]: exiting on receipt of SIGTERM
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: started, version 2.80 cachesize 150
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: DNSSEC validation enabled
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: configured with trust anchor for <root> keytag 20326
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: configured with trust anchor for <root> keytag 19036
Jun 20 10:38:32 fritz daemon.warn dnsmasq[6485]: warning: using interface lan instead
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: asynchronous logging enabled, queue limit is 10 messages
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.251.1#53 for domain 251.168.192.in-addr.arpa (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.251.1#53 for domain rmk-hotspot.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.10.1#53 for domain 10.168.192.in-addr.arpa (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.10.1#53 for domain rmkurek.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.250.1#53 for domain 250.168.192.in-addr.arpa (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.250.1#53 for domain kh-hotspot.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.20.1#53 for domain 20.168.192.in-addr.arpa (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.20.1#53 for domain hhofmeier.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.1.10#53 for domain 1.168.192.in-addr.arpa (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.1.10#53 for domain tmk-audio.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.1.10#53 for domain kurekhome.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 192.168.1.10#53 for domain d-jay.lan (no DNSSEC)
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using local addresses only for domain powerline
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using local addresses only for domain box
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 2606:4700:4700::1001#53
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 2606:4700:4700::1111#53
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 1.0.0.1#53
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: using nameserver 1.1.1.1#53
Jun 20 10:38:32 fritz daemon.info dnsmasq[6485]: read /etc/hosts - 33 addresses

@PeterPawn
Copy link
Contributor

PeterPawn commented Jun 20, 2019

Das wäre wieder normal nach dem Restart, weil hier ja jetzt nicht die Signaturprüfung zurückgestellt wurde, bis die Uhrzeit gültig ist, wie das beim ersten Start noch der Fall war:

DNSSEC signature timestamps not checked until system time valid

Es wäre ja nur wichtig zu klären, ob das beim ersten Startversuch noch irgendwo anders wieder auf "Prüfung ein" gesetzt wurde (und nur die Message fehlt), weil ansonsten halt die Signaturprüfung (genauer: die Prüfung der Zeitstempel) die gesamte Zeit deaktiviert ist.

Es könnte auch eine Race-Condition sein, wenn die Zeit zwischen zwei Tests dann doch noch gesetzt wird und die Prüfung damit - trotz der anderslautenden Meldung - gar nicht wirklich zurückgestellt wird, bis die Zeit gesetzt wurde.

Nur sollte man das dann auch mit passenden Messages protokollieren ... es ist schon "schwierig", wenn man eigentlich der Ansicht ist, die Signatur von DNSSEC-Antworten würde (in vollem Umfang) geprüft, obwohl das am Ende gar nicht der Fall ist.

@er13
Copy link
Member

er13 commented Jun 20, 2019

@WileC:
Test-Case 1: dnsmasq wird zu einem Zeitpunkt gestartet, zu dem die Zeit noch nicht valide ist, z.B. unmittelbar beim Booten.

In diesem Fall reicht es nicht aus, die Log-Datei unmittelbar nach dem Starten zu posten. Denn die Prüfung (und damit die entsprechende Log-Meldung), ob die Zeit nun valide geworden ist, wird postponed bis zu dem Zeitpunkt, zu dem einer der konfigurierten DNS-Server die erste mit DNSSEC versehene Antwort schickt. Oder andersrum, Du musst ein DNS-Request für eine Adresse absenden, bei der Du weist, dass die DNS-Responses für diese mit DNSSEC versehen sind. Erst dann ist

system time considered valid, now checking DNSSEC signature timestamps

in den Log-Ausgaben zu erwarten.

Test-Case 2: dnsmasq wird zu einem Zeitpunkt gestartet, zu dem die Zeit bereits valide ist.
Für diesen Fall ist vom Author von dnsmasq keine (positive) Log-Ausgabe vorgesehen. Dies habe ich in c30bd6f nachgeholt.

Ansonsten gehe ich davon aus, dass in Deiner dnsmasq-extra-Konfiguration die Option dnssec-no-timecheck nicht gesetzt ist, denn diese schaltet ja die Timestamp-Prüfung gänzlich aus.

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Also so sieht nun das Log vom DNSMasq mit dem aktuellen commit aus:

Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: started, version 2.80 cachesize 150
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: DNSSEC validation enabled
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: DNSSEC signature timestamps not checked until system time valid
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: configured with trust anchor for <root> keytag 20326
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: configured with trust anchor for <root> keytag 19036
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: asynchronous logging enabled, queue limit is 10 messages
Jan  1 01:00:30 fritz daemon.info dnsmasq-dhcp[2886]: DHCP, IP range 192.168.10.200 -- 192.168.10.239, lease time 12h
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: using nameserver 192.168.251.1#53 for domain 251.168.192.in-addr.arpa (no DNSSEC)
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: using nameserver 192.168.251.1#53 for domain rmk-hotspot.lan (no DNSSEC)
Jan  1 01:00:58 fritz daemon.warn dnsmasq[2886]: overflow: 143 log entries lost
Jan  1 01:00:58 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:00:58 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:00:58 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:00:58 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._udp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:00 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:03 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._udp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:03 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:03 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:03 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:03 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:06 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._udp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:06 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:06 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:06 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:06 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:09 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._udp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:09 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:09 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:09 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:09 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:12 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._tcp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:12 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:12 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:12 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:12 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:14 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jan  1 01:01:14 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:01:14 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:01:14 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:01:14 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:15 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._tcp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:15 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:15 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:15 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:15 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:16 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jan  1 01:01:16 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:01:16 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:01:16 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:01:16 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:18 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._tcp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:18 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:18 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:18 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:18 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:19 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jan  1 01:01:19 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:01:19 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:01:19 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:01:19 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:21 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._tcp.tel.t-online.de from 192.168.10.16
Jan  1 01:01:21 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:21 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:21 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.0.0.1
Jan  1 01:01:21 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 1.1.1.1
Jan  1 01:01:22 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jan  1 01:01:22 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jan  1 01:01:22 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1111
Jan  1 01:01:22 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.0.0.1
Jan  1 01:01:22 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 1.1.1.1
Jan  1 01:01:24 fritz daemon.info dnsmasq[2886]: query[A] tel.t-online.de from 192.168.10.16
Jan  1 01:01:24 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:24 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:24 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.0.0.1
Jan  1 01:01:24 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.1.1.1
Jan  1 01:01:28 fritz daemon.info dnsmasq[2886]: query[A] tel.t-online.de from 192.168.10.16
Jan  1 01:01:28 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:28 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:28 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.0.0.1
Jan  1 01:01:28 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.1.1.1
Jan  1 01:01:31 fritz daemon.info dnsmasq[2886]: query[A] tel.t-online.de from 192.168.10.16
Jan  1 01:01:31 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:31 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:31 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.0.0.1
Jan  1 01:01:31 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.1.1.1
Jan  1 01:01:34 fritz daemon.info dnsmasq[2886]: query[A] tel.t-online.de from 192.168.10.16
Jan  1 01:01:34 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1001
Jan  1 01:01:34 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1111
Jan  1 01:01:34 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.0.0.1
Jan  1 01:01:34 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.1.1.1
Jan  1 01:01:41 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] de to 1.1.1.1
Jan  1 01:01:41 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] . to 1.1.1.1
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 20326, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 59944, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 25266, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply de is DS keytag 39227, algo 8, digest 2
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] t-online.de to 1.1.1.1
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] de to 1.1.1.1
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 39227, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 22771, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply t-online.de is no DS
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply tel.t-online.de is 217.0.128.133
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: query[A] cmrelay.avm.de from 127.0.0.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 2606:4700:4700::1111
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 1.0.0.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 1.1.1.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: system time considered valid, now checking DNSSEC signature timestamps.
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] . to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: read /etc/hosts - 19 addresses
Jun 20 18:33:26 fritz daemon.info dnsmasq-dhcp[2886]: read /etc/ethers - 13 addresses
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 59944, algo 8
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 25266, algo 8
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply . is DNSKEY keytag 20326, algo 8
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply de is DS keytag 39227, algo 8, digest 2
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] avm.de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 22771, algo 8
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 39227, algo 8
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply avm.de is no DS
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: reply cmrelay.avm.de is 212.42.244.85
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: query[AAAA] sslout.df.eu from 127.0.0.1
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: forwarded sslout.df.eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: query[A] sslout.df.eu from 127.0.0.1
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: forwarded sslout.df.eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DS keytag 59479, algo 8, digest 2
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] df.eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DS keytag 59479, algo 8, digest 2
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] df.eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] eu to 2606:4700:4700::1001
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 62025, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 59479, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 9315, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply df.eu is no DS
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply sslout.df.eu is 134.119.18.24
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 9315, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 62025, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply eu is DNSKEY keytag 59479, algo 8
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: reply df.eu is no DS
Jun 20 18:33:27 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: query[A] dynreg.gigaset.net from 192.168.10.16
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: forwarded dynreg.gigaset.net to 2606:4700:4700::1001
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] net to 2606:4700:4700::1001
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: reply net is DS keytag 35886, algo 8, digest 2
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] gigaset.net to 2606:4700:4700::1001
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] net to 2606:4700:4700::1001
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: reply net is DNSKEY keytag 2129, algo 8
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: reply net is DNSKEY keytag 35886, algo 8
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: reply gigaset.net is no DS
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:31 fritz daemon.info dnsmasq[2886]: reply dynreg.gigaset.net is 148.251.243.133
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[NAPTR] tel.t-online.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 2606:4700:4700::1111
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.0.0.1
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded tel.t-online.de to 1.1.1.1
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] t-online.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: reply t-online.de is no DS
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._udp.tel.t-online.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded _sip._udp.tel.t-online.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] hh-epp-110.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded hh-epp-110.edns.t-ipnet.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] t-ipnet.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: reply t-ipnet.de is no DS
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: reply hh-epp-110.edns.t-ipnet.de is 217.0.25.33
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] d-epp-100.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded d-epp-100.edns.t-ipnet.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: reply d-epp-100.edns.t-ipnet.de is 217.0.28.32
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] h2-epp-100.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded h2-epp-100.edns.t-ipnet.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: reply h2-epp-100.edns.t-ipnet.de is 217.0.29.32
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[SRV] _sip._tcp.tel.t-online.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: forwarded _sip._tcp.tel.t-online.de to 2606:4700:4700::1001
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] hh-epp-110.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: cached hh-epp-110.edns.t-ipnet.de is 217.0.25.33
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] d-epp-100.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: cached d-epp-100.edns.t-ipnet.de is 217.0.28.32
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: query[A] h2-epp-100.edns.t-ipnet.de from 192.168.10.16
Jun 20 18:33:53 fritz daemon.info dnsmasq[2886]: cached h2-epp-100.edns.t-ipnet.de is 217.0.29.32
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: query[A] info.gigaset.net from 192.168.10.16
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: forwarded info.gigaset.net to 2606:4700:4700::1001
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: reply info.gigaset.net is 148.251.246.100
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: reply info.gigaset.net is 148.251.246.101
Jun 20 18:33:55 fritz daemon.info dnsmasq[2886]: reply info.gigaset.net is 148.251.246.99

hier noch die dnsmasq.conf, erstellt aus dem Optionen des WebIFs

domain-needed
log-async=10
no-resolv
dhcp-range=192.168.10.200,192.168.10.239,12h
domain=rmkurek.lan
expand-hosts
read-ethers
stop-dns-rebind
log-queries
conf-file=/mod/etc/default.dnsmasq/trust-anchors.conf
dnssec
dnssec-timestamp=/etc/version
### content of /tmp/flash/dnsmasq/dnsmasq.extra

@er13
Copy link
Member

er13 commented Jun 20, 2019

Also so sieht nun das Log vom DNSMasq mit dem aktuellen commit aus:

Das ist wohl das Log für den Test-Case 1. Sieht gut aus: system time considered valid, now checking DNSSEC signature timestamps ist erwartungsgemäß da, failed to update mtime on /etc/version: Read-only file system ist dagegen nicht da, ebenso erwartungsgemäß.

Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: started, version 2.80 cachesize 150
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: DNSSEC validation enabled
Jan  1 01:00:30 fritz daemon.info dnsmasq[2886]: DNSSEC signature timestamps not checked until system time valid
...
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] t-online.de to 1.1.1.1
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] de to 1.1.1.1
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 39227, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply de is DNSKEY keytag 22771, algo 8
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply t-online.de is no DS
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: validation result is INSECURE
Jan  1 01:01:42 fritz daemon.info dnsmasq[2886]: reply tel.t-online.de is 217.0.128.133
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: query[A] cmrelay.avm.de from 127.0.0.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 2606:4700:4700::1111
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 1.0.0.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: forwarded cmrelay.avm.de to 1.1.1.1
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DS] de to 2606:4700:4700::1001
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: system time considered valid, now checking DNSSEC signature timestamps.
Jun 20 18:33:26 fritz daemon.info dnsmasq[2886]: dnssec-query[DNSKEY] . to 2606:4700:4700::1001
...

Jetzt fehlt nur noch das Log für den Test-Case 2. Wenn in diesem dann unmittelbar beim Starten von dnsmasq sowas

daemon.info dnsmasq[XYZ]: DNSSEC validation enabled
daemon.info dnsmasq[XYZ]: system time considered valid, checking DNSSEC signature timestamps.

auftauchen würde, dann kann man sagen, alle Patches greifen und das Ticket kann geschlossen werden.

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Also muss ich nur den DNSMasq neu starten?

@er13
Copy link
Member

er13 commented Jun 20, 2019

Also muss ich nur den DNSMasq neu starten?

Ja.

@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Jun 20 22:19:50 fritz daemon.info dnsmasq[2886]: exiting on receipt of SIGTERM
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: started, version 2.80 cachesize 150
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect no-inotify dumpfile
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: DNSSEC validation enabled
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: system time considered valid, checking DNSSEC signature timestamps.
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: configured with trust anchor for <root> keytag 20326
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: configured with trust anchor for <root> keytag 19036
Jun 20 22:19:52 fritz daemon.warn dnsmasq[5109]: warning: using interface lan instead
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: asynchronous logging enabled, queue limit is 10 messages
Jun 20 22:19:52 fritz daemon.info dnsmasq-dhcp[5109]: DHCP, IP range 192.168.10.200 -- 192.168.10.239, lease time 12h
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.251.1#53 for domain 251.168.192.in-addr.arpa (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.251.1#53 for domain rmk-hotspot.lan (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.250.1#53 for domain 250.168.192.in-addr.arpa (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.250.1#53 for domain kh-hotspot.lan (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.1.1#53 for domain 1.168.192.in-addr.arpa (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.1.1#53 for domain tmk-audio.lan (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.1.1#53 for domain kurekhome.lan (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 192.168.1.1#53 for domain d-jay.lan (no DNSSEC)
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using local addresses only for domain 10.168.192.in-addr.arpa
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using local addresses only for domain rmkurek.lan
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using local addresses only for domain powerline
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using local addresses only for domain box
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 2606:4700:4700::1001#53
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 2606:4700:4700::1111#53
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 1.0.0.1#53
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: using nameserver 1.1.1.1#53
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: read /etc/hosts - 19 addresses
Jun 20 22:19:52 fritz daemon.info dnsmasq-dhcp[5109]: read /etc/ethers - 13 addresses
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: query[A] router.rmkurek.lan from 192.168.1.10
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: /etc/hosts router.rmkurek.lan is 192.168.10.1
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: query[AAAA] router.rmkurek.lan from 192.168.1.10
Jun 20 22:19:52 fritz daemon.info dnsmasq[5109]: config router.rmkurek.lan is NODATA-IPv6

@er13
Copy link
Member

er13 commented Jun 20, 2019

@WileC: Danke fürs Testen!

@er13 er13 closed this as completed Jun 20, 2019
@WileC
Copy link
Contributor

WileC commented Jun 20, 2019

Gerne

fda77 referenced this issue in Freetz-NG/freetz-ng Sep 30, 2019
When DNSSEC is enabled, disable its time checks until NTP set the
system time properly. Reuse /etc/version as reference file.

Closes #163

(cherry picked from commit c616c7b)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants