DNS over TLS not working

Fri May 25 06:05:40 UTC 2018

Hi Yuri,

From the logs, it looks like the connections to quad9 and cloudflare all
end, very quickly, with a tcperror.  Some connections succeed, to quad9
at the 112.  If you search for 'peer certificate' in the logs, you find
those cases, and also that it works and returns an answer.

It looks like the other addresses are somehow filtered?  There might not
be a bug in the windows code of unbound too; by the way, thank you for
the logs.

Best regards, Wouter

On 24/05/18 19:22, Yuri wrote:
> Yup. Log included.
> 
> 
> 24.05.2018 18:54, W.C.A. Wijngaards пишет:
>> Hi Yuri,
>>
>> Could you try this unbound.exe with extra debug printouts?  So I can see
>> what SSL calls are called.
>>
>> open.nlnetlabs.nl/~wouter/unbound_1.7.2rc45_debug.exe
>> rename it to unbound.exe and use it, it is rc45 with some debug
>> printouts about what part of the SSL sequence is enabled.
>>
>> (slightly differently exe size due to 32bit compile).
>>
>> Best regards, Wouter
>>
>> On 24/05/18 14:25, Yuri wrote:
>>> Sure.
>>>
>>>     tls-cert-bundle: "C:\Squid\etc\squid\ca-bundle.crt"
>>>
>>> Mozilla CA's bundle.
>>>
>>> 24.05.2018 17:17, W.C.A. Wijngaards пишет:
>>>> Hi Yuri,
>>>>
>>>>
>>>> On 24/05/18 13:08, Yuri wrote:
>>>>> Still get tcp error:
>>>> Do you have a ca-cert bundle loaded?
>>>> server:
>>>>         tls-cert-bundle: "ca-bundle.pem"
>>>>
>>>> From, on Linux: /etc/pki/tls/certs/ca-bundle.crt
>>>>
>>>> Best regards, Wouter
>>>>
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] info:
>>>>> 0RDd mod1 rep nasa.gov. A IN
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> cache memory msg=66446 rrset=66533 infra=6220 val=66288
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> svcd callbacks end
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> event_del 0000000003F0CF50 added=1 fd=-1 tv=1527159695184  EV_TIMEOUT
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> winsock 504 got sticky EV_READEV_WRITE
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> winsock 504 pass sticky EV_READEV_WRITE
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> winsock 504 store sticky EV_READEV_WRITE
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> winsock event callback 0000000003E97210 fd=504  ;  EV_READ EV_WRITE
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 6, before read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 134, return read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 3, before read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 131, return read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 6, before read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 134, return read
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> bio_cb 1, before write
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> event_del 0000000003E97210 added=1 fd=504 tv=-1  EV_WRITE
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> close fd 504
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> outnettcp cb
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> outnettcp got tcp error -1
>>>>> 24.05.2018 17:01:35 C:\Program Files\Unbound\unbound.exe[18264:1] debug:
>>>>> tcp error for address ip4 1.1.1.1 port 853 (len 16)
>>>>>
>>>>> and no resolve.
>>>>>
>>>>>
>>>>>
>>>>> 24.05.2018 15:57, W.C.A. Wijngaards пишет:
>>>>>> Hi Yuri,
>>>>>>
>>>>>> On 09/05/18 16:51, Yuri wrote:
>>>>>>> 09.05.2018 11:51, W.C.A. Wijngaards via Unbound-users пишет:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> No idea what is going on anymore, here is two new sets of binaries.
>>>>>>>>
>>>>>>>> These are made with openssl 1.0.2j.  The code in unbound that does
>>>>>>>> tls-upstream:yes is basically almost the same as previous releases, and
>>>>>>>> with the same version of openssl, shouldn't that work like it did in the
>>>>>>>> previous release?
>>>>>>>>
>>>>>>>> Note that the 1.0.2 openssl does not have the set verify name function
>>>>>>>> that is used to verify the tls authentication name, so it won't check that.
>>>>>>>>
>>>>>>>> open.nlnetlabs.nl/~wouter/unbound-1.7.1_20180509.zip
>>>>>>>> open.nlnetlabs.nl/~wouter/unbound-1.7.2_20180509.zip
>>>>>>> Same shame, Wouter.:-(
>>>>>>>
>>>>>>> Both does not work with DoT.
>>>>>> I have a bugfix for windows DNS-over-TLS.  There was missing
>>>>>> initialisation.  The version with bugfixes is available here
>>>>>> open.nlnetlabs.nl/~wouter/unbound-1.7.2rc45.zip
>>>>>> and unbound_setup_1.7.2rc45.exe and .asc gpg sigs.
>>>>>>
>>>>>> Best regards, Wouter
>>>>>>
>>>>>>>> pgp sigs in .asc files.
>>>>>>>>
>>>>>>>> The 1.7.1 zipfile is the 1.7.1 release with the different openssl library.
>>>>>>>>
>>>>>>>> The 1.7.2 has a different windows event handling for SSL upstream, that
>>>>>>>> should result in fewer cycles used to handle the SSL connection.  It
>>>>>>>> should however, not otherwise change the SSL connection calls to OpenSSL.
>>>>>>>>
>>>>>>>> Best regards, Wouter
>>>>>>>>
>>>>>>>> On 08/05/18 18:25, Yuri via Unbound-users wrote:
>>>>>>>>> Still not, Raymond.
>>>>>>>>>
>>>>>>>>> Digging.
>>>>>>>>>
>>>>>>>>> 08.05.2018 21:45, Raymond Bannan via Unbound-users пишет:
>>>>>>>>>> I downloaded the updated binary and tried on my system as well -
>>>>>>>>>> unbound is still attempting to resolve without first negotiating TLS.
>>>>>>>>>>
>>>>>>>>>> It correctly reaches out to 1.1.1.1:853, but it doesn't negotiate a
>>>>>>>>>> TLS connection.  Is there anything I could do to help fix this?
>>>>>>>>>>
>>>>>>>>>> -Ray
>>>>>>>>>>
>>>>>>>>>> On 5/7/2018 8:25 AM, W.C.A. Wijngaards via Unbound-users wrote:
>>>>>>>>>>> Hi Yuri,
>>>>>>>>>>>
>>>>>>>>>>> On 07/05/18 16:16, Yuri via Unbound-users wrote:
>>>>>>>>>>>> Just checked. Unfortunately, patch does not fix issue.
>>>>>>>>>>>>
>>>>>>>>>>>> Same sympthom. Timeout, then no resolve.
>>>>>>>>>>>  From your previous logs, what unbound does is connect, then write. 
>>>>>>>>>>> Then
>>>>>>>>>>> it gets nothing to read.  Until the timeout happens.  The connection
>>>>>>>>>>> closes, there was no data received.
>>>>>>>>>>>
>>>>>>>>>>> Is there a firewall of some sort preventing data from leaving or
>>>>>>>>>>> entering the system?
>>>>>>>>>>>
>>>>>>>>>>> Best regards, Wouter
>>>>>>>>>>>
>>>>>>>>>>>> http://open.nlnetlabs.nl/~wouter/unbound-1.7.2_20180507.zip (16Mb)
>>>>>>>>>>>> http://open.nlnetlabs.nl/~wouter/unbound-1.7.2_20180507.zip.asc (pgp
>>>>>>>>>>>> sig)
>>>>>>>>>>>>
>>>>>>>>>>>> -- 
>>>>>>>>>>>> "C++ seems like a language suitable for firing other people's legs."
>>>>>>>>>>>>
>>>>>>>>>>>> *****************************
>>>>>>>>>>>> * C++20 : Bug to the future *
>>>>>>>>>>>> *****************************
>>>>>>>>>>>>
>>
> 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <http://lists.nlnetlabs.nl/pipermail/unbound-users/attachments/20180525/bf7de64d/attachment.bin>