optimize: DNS获取到的IP，如果测速未通过，则不使用该IP，直接使用域名发起请求。 (#333)

packages/mitmproxy/src/lib/proxy/mitmproxy/createConnectHandler.js

@@ -3,9 +3,8 @@ const url = require('url')
 const log = require('../../../utils/util.log')
 const DnsUtil = require('../../dns/index')
 const localIP = '127.0.0.1'
-const defaultDns = require('dns')
+const dnsLookup = require('./dnsLookup')
-// const matchUtil = require('../../../utils/util.match')
+
-const speedTest = require('../../speed/index.js')
 function isSslConnect (sslConnectInterceptors, req, cltSocket, head) {
   for (const intercept of sslConnectInterceptors) {
     const ret = intercept(req, cltSocket, head)
@@ -36,10 +35,10 @@ module.exports = function createConnectHandler (sslConnectInterceptor, middlewar
     if (isSslConnect(sslConnectInterceptors, req, cltSocket, head)) {
       // 需要拦截，代替目标服务器，让客户端连接DS在本地启动的代理服务
       fakeServerCenter.getServerPromise(hostname, port).then((serverObj) => {
-        log.info('--- fakeServer connect', hostname)
+        log.info(`----- fakeServer connect: ${localIP}:${serverObj.port} ➜ ${req.url} -----`)
         connect(req, cltSocket, head, localIP, serverObj.port)
       }, (e) => {
-        log.error('getServerPromise', e)
+        log.error(`----- fakeServer getServerPromise error: ${hostname}:${port}, error:`, e)
       })
     } else {
       log.info(`未匹配到任何 sslConnectInterceptors，不拦截请求，直接连接目标服务器: ${hostname}:${port}`)
@@ -52,7 +51,7 @@ function connect (req, cltSocket, head, hostname, port, dnsConfig/* , sniRegexpM
   // tunneling https
   // log.info('connect:', hostname, port)
   const start = new Date()
-  let isDnsIntercept = null
+  const isDnsIntercept = {}
   const hostport = `${hostname}:${port}`
   // const replaceSni = matchUtil.matchHostname(sniRegexpMap, hostname, 'sni')
   try {
@@ -61,30 +60,10 @@ function connect (req, cltSocket, head, hostname, port, dnsConfig/* , sniRegexpM
       host: hostname,
       connectTimeout: 10000
     }
-    if (dnsConfig) {
+    if (dnsConfig && dnsConfig.providers) {
       const dns = DnsUtil.hasDnsLookup(dnsConfig, hostname)
       if (dns) {
-        options.lookup = (hostname, options, callback) => {
+        options.lookup = dnsLookup.createLookupFunc(dns, 'connect', hostport, isDnsIntercept)
-          const tester = speedTest.getSpeedTester(hostname)
-          if (tester) {
-            const aliveIpObj = tester.pickFastAliveIpObj()
-            if (aliveIpObj) {
-              log.info(`----- connect: ${hostport}, use alive ip from dns '${aliveIpObj.dns}': ${aliveIpObj.host} -----`)
-              callback(null, aliveIpObj.host, 4)
-              return
-            }
-          }
-          dns.lookup(hostname).then(ip => {
-            isDnsIntercept = { dns, hostname, ip }
-            if (ip !== hostname) {
-              log.info(`---- connect: ${hostport}, use ip from dns '${dns.name}': ${ip} ----`)
-              callback(null, ip, 4)
-            } else {
-              log.info(`----- connect: ${hostport}, use hostname: ${hostname} -----`)
-              defaultDns.lookup(hostname, options, callback)
-            }
-          })
-        }
       }
     }
     const proxySocket = net.connect(options, () => {
@@ -105,17 +84,29 @@ function connect (req, cltSocket, head, hostname, port, dnsConfig/* , sniRegexpM
     })
     proxySocket.on('timeout', () => {
       const cost = new Date() - start
-      log.info('代理socket timeout：', hostname, port, cost + 'ms')
+      const errorMsg = `代理连接超时: ${hostport}, cost: ${cost} ms`
+      log.error(errorMsg)
+
+      cltSocket.destroy()
+
+      if (isDnsIntercept && isDnsIntercept.dns && isDnsIntercept.ip !== isDnsIntercept.hostname) {
+        const { dns, ip, hostname } = isDnsIntercept
+        dns.count(hostname, ip, true)
+        log.error(`记录ip失败次数，用于优选ip！ hostname: ${hostname}, ip: ${ip}, reason: ${errorMsg}, dns: ${dns.name}`)
+      }
     })
     proxySocket.on('error', (e) => {
       // 连接失败，可能被GFW拦截，或者服务端拥挤
       const cost = new Date() - start
-      log.error('代理连接失败：', e.message, hostname, port, cost + 'ms')
+      const errorMsg = `代理连接失败: ${hostport}, cost: ${cost} ms, errorMsg: ${e.message}`
+      log.error(errorMsg)
+
       cltSocket.destroy()
-      if (isDnsIntercept) {
+
+      if (isDnsIntercept && isDnsIntercept.dns && isDnsIntercept.ip !== isDnsIntercept.hostname) {
         const { dns, ip, hostname } = isDnsIntercept
         dns.count(hostname, ip, true)
-        log.error('记录ip失败次数,用于优选ip：', hostname, ip)
+        log.error(`记录ip失败次数，用于优选ip！ hostname: ${hostname}, ip: ${ip}, reason: ${errorMsg}, dns: ${dns.name}`)
       }
     })
     return proxySocket

packages/mitmproxy/src/lib/proxy/mitmproxy/createRequestHandler.js

@@ -6,9 +6,9 @@ const DnsUtil = require('../../dns/index')
 const log = require('../../../utils/util.log')
 const RequestCounter = require('../../choice/RequestCounter')
 const InsertScriptMiddleware = require('../middleware/InsertScriptMiddleware')
-const speedTest = require('../../speed/index.js')
+const dnsLookup = require('./dnsLookup')
-const defaultDns = require('dns')
 const MAX_SLOW_TIME = 8000 // 超过此时间 则认为太慢了
+
 // create requestHandler function
 module.exports = function createRequestHandler (createIntercepts, middlewares, externalProxy, dnsConfig, setting) {
   // return
@@ -81,15 +81,15 @@ module.exports = function createRequestHandler (createIntercepts, middlewares, e
     }
 
     function countSlow (isDnsIntercept, reason) {
-      if (isDnsIntercept) {
+      if (isDnsIntercept && isDnsIntercept.dns && isDnsIntercept.ip !== isDnsIntercept.hostname) {
         const { dns, ip, hostname } = isDnsIntercept
         dns.count(hostname, ip, true)
-        log.error('记录ip失败次数,用于优选ip：', hostname, ip, reason)
+        log.error(`记录ip失败次数，用于优选ip！ hostname: ${hostname}, ip: ${ip}, reason: ${reason}, dns: ${dns.name}`)
       }
       const counter = context.requestCount
       if (counter != null) {
         counter.count.doCount(counter.value, true)
-        log.error('记录proxy失败次数：', counter.value, reason)
+        log.error(`记录Proxy请求失败次数，用于切换备选域名！ hostname: ${counter.value}, reason: ${reason}, counter.count:`, counter.count)
       }
     }
 
@@ -108,34 +108,21 @@ module.exports = function createRequestHandler (createIntercepts, middlewares, e
         onFree()
 
         function onFree () {
-          const url = `${rOptions.protocol}//${rOptions.hostname}:${rOptions.port}${rOptions.path}`
+          const url = `${rOptions.method} ➜ ${rOptions.protocol}//${rOptions.hostname}:${rOptions.port}${rOptions.path}`
           const start = new Date()
-          log.info('代理请求:', url, rOptions.method, rOptions.servername ? ', sni: ' + rOptions.servername : '')
+          log.info('发起代理请求:', url, (rOptions.servername ? ', sni: ' + rOptions.servername : ''))
-          let isDnsIntercept
+
-          if (dnsConfig) {
+          const isDnsIntercept = {}
-            const dns = DnsUtil.hasDnsLookup(dnsConfig, rOptions.hostname)
+          if (dnsConfig && dnsConfig.providers) {
+            let dns = DnsUtil.hasDnsLookup(dnsConfig, rOptions.hostname)
+            if (!dns && rOptions.servername) {
+              dns = dnsConfig.providers.quad9
               if (dns) {
-              rOptions.lookup = (hostname, options, callback) => {
+                log.info(`域名 ${rOptions.hostname} 在dns中未配置，但使用了 sni: ${rOptions.servername}, 必须使用dns，现默认使用 'quad9' DNS.`)
-                const tester = speedTest.getSpeedTester(hostname)
-                if (tester) {
-                  const aliveIpObj = tester.pickFastAliveIpObj()
-                  if (aliveIpObj) {
-                    log.info(`----- request url: ${url}, use alive ip from dns '${aliveIpObj.dns}': ${aliveIpObj.host} -----`)
-                    callback(null, aliveIpObj.host, 4)
-                    return
               }
             }
-                dns.lookup(hostname).then(ip => {
+            if (dns) {
-                  isDnsIntercept = { dns, hostname, ip }
+              rOptions.lookup = dnsLookup.createLookupFunc(dns, 'request url', url, isDnsIntercept)
-                  if (ip !== hostname) {
-                    log.info(`---- request url: ${url}, use ip from dns '${dns.name}': ${ip} ----`)
-                    callback(null, ip, 4)
-                  } else {
-                    log.info(`---- request url: ${url}, use hostname: ${hostname} ----`)
-                    defaultDns.lookup(hostname, options, callback)
-                  }
-                })
-              }
             }
           }
 
@@ -149,62 +136,73 @@ module.exports = function createRequestHandler (createIntercepts, middlewares, e
           proxyReq = (rOptions.protocol === 'https:' ? https : http).request(rOptions, (proxyRes) => {
             const cost = new Date() - start
             if (rOptions.protocol === 'https:') {
-              log.info('代理请求返回:', url, cost + 'ms')
+              log.info(`代理请求返回: ${url}, cost: ${cost} ms`)
+            } else {
+              log.info(`请求返回: ${url}, cost: ${cost} ms`)
             }
             // console.log('request:', proxyReq, proxyReq.socket)
+
             if (cost > MAX_SLOW_TIME) {
-              countSlow(isDnsIntercept, 'to slow  ' + cost + 'ms')
+              countSlow(isDnsIntercept, `代理请求成功但太慢, cost: ${cost} ms > ${MAX_SLOW_TIME} ms`)
             }
+
             resolve(proxyRes)
           })
 
           // 代理请求的事件监听
           proxyReq.on('timeout', () => {
             const cost = new Date() - start
-            log.error('代理请求超时', rOptions.protocol, rOptions.hostname, rOptions.path, cost + 'ms')
+            const errorMsg = `代理请求超时: ${url}, cost: ${cost} ms`
-            countSlow(isDnsIntercept, 'to slow  ' + cost + 'ms')
+            log.error(errorMsg)
+            countSlow(isDnsIntercept, `代理请求超时, cost: ${cost} ms`)
             proxyReq.end()
             proxyReq.destroy()
-            const error = new Error(`${rOptions.host}:${rOptions.port}, 代理请求超时`)
+            const error = new Error(errorMsg)
             error.status = 408
             reject(error)
           })
           proxyReq.on('error', (e) => {
             const cost = new Date() - start
-            log.error('代理请求错误', e.code, e.message, rOptions.hostname, rOptions.path, cost + 'ms')
+            log.error(`代理请求错误: ${url}, cost: ${cost} ms, error:`, e)
-            countSlow(isDnsIntercept, 'error:' + e.message)
+            countSlow(isDnsIntercept, '代理请求错误: ' + e.message)
             reject(e)
           })
           proxyReq.on('aborted', () => {
             const cost = new Date() - start
-            log.error('代理请求被取消', rOptions.hostname, rOptions.path, cost + 'ms')
+            const errorMsg = `代理请求被取消: ${url}, cost: ${cost} ms`
+            log.error(errorMsg)
 
             if (cost > MAX_SLOW_TIME) {
-              countSlow(isDnsIntercept, 'to slow  ' + cost + 'ms')
+              countSlow(isDnsIntercept, `代理请求被取消，且请求太慢, cost: ${cost} ms > ${MAX_SLOW_TIME} ms`)
             }
 
             if (res.writableEnded) {
               return
             }
-            reject(new Error('代理请求被取消'))
+            reject(new Error(errorMsg))
           })
 
           // 原始请求的事件监听
           req.on('aborted', function () {
-            log.error('请求被取消', rOptions.hostname, rOptions.path)
+            const cost = new Date() - start
+            const errorMsg = `请求被取消: ${url}, cost: ${cost} ms`
+            log.error(errorMsg)
             proxyReq.abort()
             if (res.writableEnded) {
               return
             }
-            reject(new Error('请求被取消'))
+            reject(new Error(errorMsg))
           })
           req.on('error', function (e, req, res) {
-            log.error('请求错误：', e.errno, rOptions.hostname, rOptions.path)
+            const cost = new Date() - start
+            log.error(`请求错误: ${url}, cost: ${cost} ms, error:`, e)
             reject(e)
           })
           req.on('timeout', () => {
-            log.error('请求超时', rOptions.hostname, rOptions.path)
+            const cost = new Date() - start
-            reject(new Error(`${rOptions.hostname}:${rOptions.port}, 请求超时`))
+            const errorMsg = `请求超时: ${url}, cost: ${cost} ms`
+            log.error(errorMsg)
+            reject(new Error(errorMsg))
           })
           req.pipe(proxyReq)
         }
@@ -318,6 +316,21 @@ module.exports = function createRequestHandler (createIntercepts, middlewares, e
           // do nothing
         }
 
+        // region 忽略部分已经打印过ERROR日志的错误
+        if (e.message) {
+          const ignoreErrors = [
+            '代理请求错误: ',
+            '代理请求超时: ',
+            '代理请求被取消: '
+          ]
+          for (const ignoreError of ignoreErrors) {
+            if (e.message.startsWith(ignoreError)) {
+              return
+            }
+          }
+        }
+        // endregion
+
         log.error('Request error:', e)
       }
     })

packages/mitmproxy/src/lib/proxy/mitmproxy/dnsLookup.js

@@ -0,0 +1,56 @@
+const speedTest = require('../../speed')
+const log = require('../../../utils/util.log')
+const defaultDns = require('dns')
+
+module.exports = {
+  createLookupFunc: function (dns, action, target, isDnsIntercept) {
+    return (hostname, options, callback) => {
+      const tester = speedTest.getSpeedTester(hostname)
+      if (tester && tester.ready) {
+        const aliveIpObj = tester.pickFastAliveIpObj()
+        if (aliveIpObj) {
+          log.info(`----- ${action}: ${target}, use alive ip from dns '${aliveIpObj.dns}': ${aliveIpObj.host} -----`)
+          callback(null, aliveIpObj.host, 4)
+          return
+        } else {
+          log.info(`----- ${action}: ${target}, no alive ip, tester:`, tester)
+        }
+      }
+      dns.lookup(hostname).then(ip => {
+        if (isDnsIntercept) {
+          isDnsIntercept.dns = dns
+          isDnsIntercept.hostname = hostname
+          isDnsIntercept.ip = ip
+        }
+
+        if (ip !== hostname) {
+          // 判断是否为测速失败的IP，如果是，则不使用当前IP
+          let isTestFailedIp = false
+          if (tester && tester.ready && tester.backupList && tester.backupList.length > 0) {
+            for (let i = 0; i < tester.backupList.length; i++) {
+              const item = tester.backupList[i]
+              if (item.host === ip) {
+                if (item.time == null) {
+                  isTestFailedIp = true
+                }
+                break
+              }
+            }
+          }
+          if (isTestFailedIp === false) {
+            log.info(`----- ${action}: ${target}, use ip from dns '${dns.name}': ${ip} -----`)
+            callback(null, ip, 4)
+            return
+          } else {
+            // 使用默认dns
+            log.info(`----- ${action}: ${target}, use hostname by default DNS: ${hostname}, skip test failed ip from dns '${dns.name}: ${ip}', options:`, options)
+          }
+        } else {
+          // 使用默认dns
+          log.info(`----- ${action}: ${target}, use hostname by default DNS: ${hostname}, options:`, options, ', dns:', dns)
+        }
+        defaultDns.lookup(hostname, options, callback)
+      })
+    }
+  }
+}