[GH-ISSUE #1132] ResolverConfig and ResolverOpts loaded by read_system_conf should be updated automatically when system's conf is changed #609

Open
opened 2026-03-15 23:26:33 +03:00 by kerem · 9 comments
Owner

Originally created by @zonyitoo on GitHub (Jun 10, 2020).
Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/1132

Describe the bug
After recover from hibernate on OS X, AsyncResolver::lookup_ip will not return even if network is fine (all the other applications works fine).

To Reproduce
Steps to reproduce the behavior:

  1. Run a server (tokio, multi-thread scheduler) on OS X
  2. Let system go into hibernate state
  3. (optional) Go to another place, connect to another Wi-Fi
  4. Recover from hibernate

Nearly 100% reproduciable.

Expected behavior

AsyncResolver::lookup_ip should work after recover from hibernate like all the other applications.

System:

  • OS: macOS
  • Architecture: x86_64
  • Version: 10.15.5
  • rustc version: 1.46.0-nightly (feb3536eb 2020-06-09)

Version:
Crate: resolver
Version: 0.19.5

Originally created by @zonyitoo on GitHub (Jun 10, 2020). Original GitHub issue: https://github.com/hickory-dns/hickory-dns/issues/1132 **Describe the bug** After recover from hibernate on OS X, `AsyncResolver::lookup_ip` will not return even if network is fine (all the other applications works fine). **To Reproduce** Steps to reproduce the behavior: 1. Run a server (tokio, multi-thread scheduler) on OS X 2. Let system go into hibernate state 3. (optional) Go to another place, connect to another Wi-Fi 4. Recover from hibernate Nearly 100% reproduciable. **Expected behavior** `AsyncResolver::lookup_ip` should work after recover from hibernate like all the other applications. **System:** - OS: macOS - Architecture: x86_64 - Version: 10.15.5 - rustc version: 1.46.0-nightly (feb3536eb 2020-06-09) **Version:** Crate: resolver Version: 0.19.5
Author
Owner

@zonyitoo commented on GitHub (Jun 10, 2020):

Not sure if it is related to: https://github.com/bluejekyll/trust-dns/issues/1073

<!-- gh-comment-id:642038770 --> @zonyitoo commented on GitHub (Jun 10, 2020): Not sure if it is related to: https://github.com/bluejekyll/trust-dns/issues/1073
Author
Owner

@bluejekyll commented on GitHub (Jun 10, 2020):

This is potentially much better context and yes possibly related.

Any chance you could attach a debugger and grab a stack dump of the the threads? Might see the spot where we’re stuck.

<!-- gh-comment-id:642043048 --> @bluejekyll commented on GitHub (Jun 10, 2020): This is potentially much better context and yes possibly related. Any chance you could attach a debugger and grab a stack dump of the the threads? Might see the spot where we’re stuck.
Author
Owner

@zonyitoo commented on GitHub (Jun 10, 2020):

I can sure that if the address is already in cache, everything works correctly.

I will try to gdb it tomorrow, when the problem shows up again.

<!-- gh-comment-id:642048792 --> @zonyitoo commented on GitHub (Jun 10, 2020): I can sure that if the address is already in cache, everything works correctly. I will try to gdb it tomorrow, when the problem shows up again.
Author
Owner

@zonyitoo commented on GitHub (Jun 11, 2020):

2020-06-11T10:25:38.866+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving www.baidu.com:80 with trust-dns
2020-06-11T10:25:38.866+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: www.baidu.com A
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }]
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(211.148.192.141:53), protocol: Udp, tls_dns_name: None }
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }]
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(211.148.192.151:53), protocol: Udp, tls_dns_name: None }
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }]
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully

Some related logs. Still don't know where it actually being blocked. I will try to reproduce it next day (I forgot to save the stack dump).

<!-- gh-comment-id:642367535 --> @zonyitoo commented on GitHub (Jun 11, 2020): ``` 2020-06-11T10:25:38.866+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving www.baidu.com:80 with trust-dns 2020-06-11T10:25:38.866+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: www.baidu.com A 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }] 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(211.148.192.141:53), protocol: Udp, tls_dns_name: None } 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }] 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(211.148.192.151:53), protocol: Udp, tls_dns_name: None } 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [www, baidu, com] }, query_type: A, query_class: IN }] 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T10:25:38.867+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully ``` Some related logs. Still don't know where it actually being blocked. I will try to reproduce it next day (I forgot to save the stack dump).
Author
Owner

@zonyitoo commented on GitHub (Jun 11, 2020):

2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:25.933+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [cds, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:30.814+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes
2020-06-11T22:52:30.814+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:32.992+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes
2020-06-11T22:52:32.992+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed
2020-06-11T22:52:32.992+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:32.993+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:37.999+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:37.999+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:38.000+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:38.000+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:38.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:40.942+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:40.942+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::io] read 1037 bytes
2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::io] parsed 5 headers
2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::conn] incoming body is content-length (837 bytes)
2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::conn] incoming body completed
2020-06-11T22:52:42.808+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] request 127.0.0.1:62795 Request { method: POST, uri: https://vortex.data.microsoft.com/collect/v1, version: HTTP/1.1, headers: {"content-type": "application/x-json-stream", "content-encoding": "gzip", "content-length": "837", "host": "vortex.data.microsoft.com", "connection": "close"}, body: Body(Streaming) }
2020-06-11T22:52:42.809+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] HTTP POST vortex.data.microsoft.com:443 HTTP/1.1
2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: guzzoni.apple.com AAAA
2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:43.050+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving vortex.data.microsoft.com:443 with trust-dns
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: vortex.data.microsoft.com A
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:43.052+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:43.052+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:45.947+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:48.057+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:48.057+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::context] DNS resolved guzzoni.apple.com:443 elapsed: 197.905s, Err(Custom { kind: Other, error: "dns resolve guzzoni.apple.com:443 error: request timed out" })
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::context] check bypassing guzzoni.apple.com:443 elapsed 197.967s, result: proxied
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::relay::tcprelay::proxy_stream] connect to guzzoni.apple.com:443 via hk.chliny.me:920 (127.0.0.1:64559) (proxied)
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:53.008+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] connecting to proxy hk.chliny.me:920 (127.0.0.1:64559), timeout: Some(90s)
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:53.009+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:53.009+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] connected proxy hk.chliny.me:920 (127.0.0.1:64559)
2020-06-11T22:52:53.009+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:53.009+08:00 TRACE [shadowsocks::relay::tcprelay::crypto_io] generated AEAD cipher salt b"v2\x8b#\xd6i')\x84(\x82\xe2\x94\xb8o\x8d\x14\xcc\x90T\xbc\xb3\xeaV\xa3d\x8b@\xec\x91w\xb4h\x8a\xabe\xa7!\x90\x87\xe1RJ\xc3\x03\xed\xe8\x16(\xde\x9e\xe2*Y\xdc\x1bZ\xdd\xd2f\x07j\xa6\xf9"
2020-06-11T22:52:53.010+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay connected 127.0.0.1:62147 <-> guzzoni.apple.com:443
2020-06-11T22:52:53.010+08:00 DEBUG [hyper::proto::h1::io] flushed 56 bytes
2020-06-11T22:52:53.011+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT tunnel upgrade success, 127.0.0.1:62147 <-> guzzoni.apple.com:443
2020-06-11T22:52:53.011+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay established 127.0.0.1:62147 <-> guzzoni.apple.com:443
2020-06-11T22:52:53.012+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] sending handshake address guzzoni.apple.com:443 with data 517 bytes
2020-06-11T22:52:53.013+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] sent handshake address guzzoni.apple.com:443 with 517 bytes of data, data len 517 bytes
2020-06-11T22:52:53.054+08:00 TRACE [shadowsocks::relay::tcprelay::crypto_io] got AEAD cipher salt b"4\xfe0\x08\x90\xbc\x99\xafwI(\xeb\xe0\x9f\xcc\x16\xa1#\xb5F\r\xcf\xd0\x94s\x0e\x98\x0e\x88}q\xa3\xd9\xc5\xac\x1f\xd3\xac\x81\x0f\xd3\x01j\xbd\x17\t\xae\x9c\xb9\x9c \x7f\x02m\x92\xb4\xb63T\xa4\x00\x85Hi"
2020-06-11T22:52:53.059+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:52:53.059+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:53.178+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62147 -> guzzoni.apple.com:443 closed
2020-06-11T22:52:53.178+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62147 <-> guzzoni.apple.com:443 closed
2020-06-11T22:52:54.007+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes
2020-06-11T22:52:54.007+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed
2020-06-11T22:52:58.013+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:58.013+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: vortex.data.microsoft.com AAAA
2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:58.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:58.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::io] read 164 bytes
2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::io] parsed 3 headers
2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::conn] incoming body is empty
2020-06-11T22:52:58.412+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] request 127.0.0.1:62833 Request { method: CONNECT, uri: mesu.apple.com:443, version: HTTP/1.1, headers: {"host": "mesu.apple.com", "user-agent": "mobileassetd (unknown version) CFNetwork/1125.2 Darwin/19.4.0 (x86_64)", "connection": "close"}, body: Body(Empty) }
2020-06-11T22:52:58.412+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] HTTP CONNECT mesu.apple.com:443
2020-06-11T22:52:58.472+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving mesu.apple.com:443 with trust-dns
2020-06-11T22:52:58.472+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: mesu.apple.com A
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:52:58.823+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62557 <- mtalk.google.com:5228 closed with error timed out
2020-06-11T22:52:58.823+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62557 <-> mtalk.google.com:5228 closed
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:03.017+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }]
2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:08.482+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:08.648+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62347 <- mail.google.com:443 closed with error timed out
2020-06-11T22:53:08.648+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62347 <-> mail.google.com:443 closed
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }]
2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:14.081+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62602 <- safebrowsing.google.com:443 closed with error timed out
2020-06-11T22:53:14.081+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62602 <-> safebrowsing.google.com:443 closed
2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:18.513+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62624 <- safebrowsing.googleapis.com:443 closed with error timed out
2020-06-11T22:53:18.513+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62624 <-> safebrowsing.googleapis.com:443 closed
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }]
2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down
2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None }
2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully
2020-06-11T22:53:28.034+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out

Lots of name_server connection failure: request timed out.

<!-- gh-comment-id:642712256 --> @zonyitoo commented on GitHub (Jun 11, 2020): ``` 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:25.931+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:25.932+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:25.933+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [cds, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:26.019+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:30.814+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes 2020-06-11T22:52:30.814+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:30.934+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:30.935+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:32.992+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes 2020-06-11T22:52:32.992+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed 2020-06-11T22:52:32.992+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:32.993+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:35.936+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:35.937+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:37.999+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:37.999+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:38.000+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:38.000+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:38.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:40.941+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:40.942+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:40.942+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::io] read 1037 bytes 2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::io] parsed 5 headers 2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::conn] incoming body is content-length (837 bytes) 2020-06-11T22:52:42.808+08:00 DEBUG [hyper::proto::h1::conn] incoming body completed 2020-06-11T22:52:42.808+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] request 127.0.0.1:62795 Request { method: POST, uri: https://vortex.data.microsoft.com/collect/v1, version: HTTP/1.1, headers: {"content-type": "application/x-json-stream", "content-encoding": "gzip", "content-length": "837", "host": "vortex.data.microsoft.com", "connection": "close"}, body: Body(Streaming) } 2020-06-11T22:52:42.809+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] HTTP POST vortex.data.microsoft.com:443 HTTP/1.1 2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: guzzoni.apple.com AAAA 2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:43.001+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:43.002+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:43.050+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving vortex.data.microsoft.com:443 with trust-dns 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: vortex.data.microsoft.com A 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:43.051+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:43.052+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:43.052+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:45.947+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:48.004+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:48.005+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:48.057+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:48.057+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:48.058+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::context] DNS resolved guzzoni.apple.com:443 elapsed: 197.905s, Err(Custom { kind: Other, error: "dns resolve guzzoni.apple.com:443 error: request timed out" }) 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::context] check bypassing guzzoni.apple.com:443 elapsed 197.967s, result: proxied 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:53.008+08:00 DEBUG [shadowsocks::relay::tcprelay::proxy_stream] connect to guzzoni.apple.com:443 via hk.chliny.me:920 (127.0.0.1:64559) (proxied) 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:53.008+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] connecting to proxy hk.chliny.me:920 (127.0.0.1:64559), timeout: Some(90s) 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:53.008+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:53.009+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:53.009+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] connected proxy hk.chliny.me:920 (127.0.0.1:64559) 2020-06-11T22:52:53.009+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:53.009+08:00 TRACE [shadowsocks::relay::tcprelay::crypto_io] generated AEAD cipher salt b"v2\x8b#\xd6i')\x84(\x82\xe2\x94\xb8o\x8d\x14\xcc\x90T\xbc\xb3\xeaV\xa3d\x8b@\xec\x91w\xb4h\x8a\xabe\xa7!\x90\x87\xe1RJ\xc3\x03\xed\xe8\x16(\xde\x9e\xe2*Y\xdc\x1bZ\xdd\xd2f\x07j\xa6\xf9" 2020-06-11T22:52:53.010+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay connected 127.0.0.1:62147 <-> guzzoni.apple.com:443 2020-06-11T22:52:53.010+08:00 DEBUG [hyper::proto::h1::io] flushed 56 bytes 2020-06-11T22:52:53.011+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT tunnel upgrade success, 127.0.0.1:62147 <-> guzzoni.apple.com:443 2020-06-11T22:52:53.011+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay established 127.0.0.1:62147 <-> guzzoni.apple.com:443 2020-06-11T22:52:53.012+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] sending handshake address guzzoni.apple.com:443 with data 517 bytes 2020-06-11T22:52:53.013+08:00 TRACE [shadowsocks::relay::tcprelay::proxy_stream] sent handshake address guzzoni.apple.com:443 with 517 bytes of data, data len 517 bytes 2020-06-11T22:52:53.054+08:00 TRACE [shadowsocks::relay::tcprelay::crypto_io] got AEAD cipher salt b"4\xfe0\x08\x90\xbc\x99\xafwI(\xeb\xe0\x9f\xcc\x16\xa1#\xb5F\r\xcf\xd0\x94s\x0e\x98\x0e\x88}q\xa3\xd9\xc5\xac\x1f\xd3\xac\x81\x0f\xd3\x01j\xbd\x17\t\xae\x9c\xb9\x9c \x7f\x02m\x92\xb4\xb63T\xa4\x00\x85Hi" 2020-06-11T22:52:53.059+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:52:53.059+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:53.178+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62147 -> guzzoni.apple.com:443 closed 2020-06-11T22:52:53.178+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62147 <-> guzzoni.apple.com:443 closed 2020-06-11T22:52:54.007+08:00 DEBUG [hyper::proto::h1::io] read 0 bytes 2020-06-11T22:52:54.007+08:00 DEBUG [hyper::server::conn::spawn_all] connection error: connection closed before message completed 2020-06-11T22:52:58.013+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:58.013+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: vortex.data.microsoft.com AAAA 2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:58.014+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:52:58.015+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:58.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:58.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::io] read 164 bytes 2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::io] parsed 3 headers 2020-06-11T22:52:58.412+08:00 DEBUG [hyper::proto::h1::conn] incoming body is empty 2020-06-11T22:52:58.412+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] request 127.0.0.1:62833 Request { method: CONNECT, uri: mesu.apple.com:443, version: HTTP/1.1, headers: {"host": "mesu.apple.com", "user-agent": "mobileassetd (unknown version) CFNetwork/1125.2 Darwin/19.4.0 (x86_64)", "connection": "close"}, body: Body(Empty) } 2020-06-11T22:52:58.412+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] HTTP CONNECT mesu.apple.com:443 2020-06-11T22:52:58.472+08:00 TRACE [shadowsocks::relay::dns_resolver::trust_dns_resolver] DNS resolving mesu.apple.com:443 with trust-dns 2020-06-11T22:52:58.472+08:00 DEBUG [trust_dns_proto::xfer::dns_handle] querying: mesu.apple.com A 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:58.473+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:52:58.823+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62557 <- mtalk.google.com:5228 closed with error timed out 2020-06-11T22:52:58.823+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62557 <-> mtalk.google.com:5228 closed 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:03.016+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:03.017+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [mesu, apple, com] }, query_type: A, query_class: IN }] 2020-06-11T22:53:03.478+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:08.022+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_resolver::name_server::name_server] existing connection: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:08.023+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:08.024+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:08.482+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:08.648+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62347 <- mail.google.com:443 closed with error timed out 2020-06-11T22:53:08.648+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62347 <-> mail.google.com:443 closed 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:13.025+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: A, query_class: IN }] 2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:13.026+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:14.081+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62602 <- safebrowsing.google.com:443 closed with error timed out 2020-06-11T22:53:14.081+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62602 <-> safebrowsing.google.com:443 closed 2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:18.027+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:18.028+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:18.029+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:18.513+08:00 TRACE [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62624 <- safebrowsing.googleapis.com:443 closed with error timed out 2020-06-11T22:53:18.513+08:00 DEBUG [shadowsocks::relay::tcprelay::http_local] CONNECT relay 127.0.0.1:62624 <-> safebrowsing.googleapis.com:443 closed 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] stream errored while connecting: ProtoError { kind: Timeout, backtrack: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server_pool] sending request: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.25:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [vortex, data, microsoft, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Udp, tls_dns_name: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.210:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::xfer] enqueueing message: [Query { name: Name { is_fqdn: false, labels: [guzzoni, apple, com] }, query_type: AAAA, query_class: IN }] 2020-06-11T22:53:23.031+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::xfer::dns_exchange] io_stream is done, shutting down 2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_resolver::name_server::name_server] reconnecting: NameServerConfig { socket_addr: V4(10.28.0.211:53), protocol: Tcp, tls_dns_name: None } 2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:23.051+08:00 DEBUG [trust_dns_proto::udp::udp_stream] created socket successfully 2020-06-11T22:53:28.034+08:00 DEBUG [trust_dns_resolver::name_server::name_server] name_server connection failure: request timed out ``` Lots of `name_server connection failure: request timed out`.
Author
Owner

@zonyitoo commented on GitHub (Jun 11, 2020):

I see.. It is all about trust_dns_resolver::system_conf::read_system_conf.

read_system_conf is called when server starts, but when I switch Wi-Fi, name servers are changed!! But trust_dns_resolver still tried to use the old name servers.

read_system_conf may need to reload if /etc/resolv.conf changed.

<!-- gh-comment-id:642716588 --> @zonyitoo commented on GitHub (Jun 11, 2020): I see.. It is all about `trust_dns_resolver::system_conf::read_system_conf`. `read_system_conf` is called when server starts, but when I switch Wi-Fi, name servers are changed!! But `trust_dns_resolver` still tried to use the old name servers. `read_system_conf` may need to reload if `/etc/resolv.conf` changed.
Author
Owner

@bluejekyll commented on GitHub (Jun 11, 2020):

Ah, so it's hanging on network configuration changes. I think we have an open story for how to support that. It would be interesting to come up with a good model for that. I've been hesitant to support it because of the dynamicity of it and recreating futures, etc, but maybe we should revisit that.

<!-- gh-comment-id:642723878 --> @bluejekyll commented on GitHub (Jun 11, 2020): Ah, so it's hanging on network configuration changes. I think we have an open story for how to support that. It would be interesting to come up with a good model for that. I've been hesitant to support it because of the dynamicity of it and recreating futures, etc, but maybe we should revisit that.
Author
Owner

@zonyitoo commented on GitHub (Jun 11, 2020):

My solution is to add a script to watch /etc/resolv.conf and restart my servers when DNS configuration is changed.

<!-- gh-comment-id:642741594 --> @zonyitoo commented on GitHub (Jun 11, 2020): My solution is to add a script to watch `/etc/resolv.conf` and restart my servers when DNS configuration is changed.
Author
Owner

@zonyitoo commented on GitHub (Nov 17, 2020):

I found an issue https://github.com/c-ares/c-ares/issues/324 , it seems that we can call functions from libresolv on BSD-like systems, specifically in this case, macOS.

There are resolv, resolv-sys wrappers on crates.io.

<!-- gh-comment-id:728893503 --> @zonyitoo commented on GitHub (Nov 17, 2020): I found an issue https://github.com/c-ares/c-ares/issues/324 , it seems that we can call functions from `libresolv` on BSD-like systems, specifically in this case, macOS. There are [resolv](https://crates.io/crates/resolv), [resolv-sys](https://crates.io/crates/libresolv-sys) wrappers on crates.io.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/hickory-dns#609
No description provided.