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 *
>>>>>>>>>>>>>>> *****************************
>>>>>>>>>>>>>>>
>>>
>>
> 


Attachment: signature.asc
Description: OpenPGP digital signature

Reply via email to