DNS over TLS not working

Fri May 25 10:12:07 UTC 2018

Yesssssssss!!!

Now fixed! Wokring log attached.

Great work, Wouter!

25.05.2018 16:04, W.C.A. Wijngaards пишет:
> Hi Yuri,
>
> Yes in these traces, cloudflare and 9.9.9.9 work once, but not all the
> time.  Something must be wrong in the calls that unbound makes.
>
> It seems that unbound does not reset the events for closed file
> descriptors, this makes the first one work, but others try to write when
> the fd is not connected yet and this causes a failure, which causes
> libssl to close the file descriptor which fails the connection.
>
> open.nlnetlabs.nl/~wouter/unbound_rc45_fixclose.exe
> (replacements for unbound.exe, rename as unbound.exe for use).
>
> Best regards, Wouter
>
> On 25/05/18 11:10, Yuri wrote:
>> Hmmmmmmm.
>>
>> Same issue.
>>
>> I do not think, this issue related to blocking somewhere, because of in
>> the same network UNIX Unbound with DoT works perfectly.
>> Also, simplest availability checks says ok:
>>
>> root @ khorne / # ping 1.1.1.1
>> 1.1.1.1 is alive
>> root @ khorne / # telnet 1.1.1.1 853
>> Trying 1.1.1.1...
>> Connected to 1.1.1.1.
>> Escape character is '^]'.
>> ^CConnection to 1.1.1.1 closed by foreign host.
>>
>> I.e., DNS servers available, sockets on 853 port opens.
>>
>> Latest log for this version attached.
>>
>> 25.05.2018 12:30, W.C.A. Wijngaards пишет:
>>> Hi Yuri,
>>>
>>> And here is the same executable but with counting that will exclude
>>> addresses for which the connection doesn't establish.  That would
>>> exclude all (except one), looking at the logs.
>>>
>>> open.nlnetlabs.nl/~wouter/unbound_rc45_fixnonestablishedtcp.exe
>>> (This is again unbound.exe, rename it to unbound.exe for use)
>>>
>>> I made it because it will likely work better.  The fix is also in the
>>> public code repository.  What it does is keep track of connection
>>> failures and then when server selection happens, it should omit the
>>> failing servers from the server selection.
>>>
>>> This may not actually be the bug you originally tried to report, but it
>>> should be an improvement.
>>>
>>> Best regards, Wouter
>>>
>>> On 25/05/18 08:05, W.C.A. Wijngaards via Unbound-users wrote:
>>>> 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 *
>>>>>>>>>>>>>>>> *****************************
>>>>>>>>>>>>>>>>
>

-- 
"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: unbound.zip
Type: application/x-zip-compressed
Size: 131420 bytes
Desc: not available
URL: <http://lists.nlnetlabs.nl/pipermail/unbound-users/attachments/20180525/7f95b4d2/attachment.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 659 bytes
Desc: OpenPGP digital signature
URL: <http://lists.nlnetlabs.nl/pipermail/unbound-users/attachments/20180525/7f95b4d2/attachment-0001.bin>