net/tshttpproxy: aggressively rate-limit error logs in Transport.Proxy path

Otherwise log upload HTTP requests generate proxy errrors which
generate logs which generate HTTP requests which generate proxy
errors which generate more logs, etc.

Fixes #879
This commit is contained in:
Brad Fitzpatrick 2020-11-03 08:53:01 -08:00
parent 07b6ffd55c
commit 1036f51a56

View File

@ -19,6 +19,7 @@
"github.com/alexbrainman/sspi/negotiate" "github.com/alexbrainman/sspi/negotiate"
"golang.org/x/sys/windows" "golang.org/x/sys/windows"
"tailscale.com/types/logger"
) )
var ( var (
@ -38,6 +39,13 @@ func init() {
val *url.URL val *url.URL
} }
// proxyErrorf is a rate-limited logger specifically for errors asking
// WinHTTP for the proxy information. We don't want to log about
// errors often, otherwise the log message itself will generate a new
// HTTP request which ultimately will call back into us to log again,
// forever. So for errors, we only log a bit.
var proxyErrorf = logger.RateLimitedFn(log.Printf, 10*time.Minute, 2 /* burst*/, 10 /* maxCache */)
func proxyFromWinHTTPOrCache(req *http.Request) (*url.URL, error) { func proxyFromWinHTTPOrCache(req *http.Request) (*url.URL, error) {
if req.URL == nil { if req.URL == nil {
return nil, nil return nil, nil
@ -79,7 +87,14 @@ type result struct {
setNoProxyUntil(10 * time.Second) setNoProxyUntil(10 * time.Second)
return nil, nil return nil, nil
} }
log.Printf("tshttpproxy: winhttp: GetProxyForURL(%q): %v/%#v", urlStr, err, err) if err == windows.ERROR_INVALID_PARAMETER {
// Seen on Windows 8.1. (https://github.com/tailscale/tailscale/issues/879)
// TODO(bradfitz): figure this out.
setNoProxyUntil(time.Hour)
proxyErrorf("tshttpproxy: winhttp: GetProxyForURL(%q): ERROR_INVALID_PARAMETER [unexpected]", urlStr)
return nil, nil
}
proxyErrorf("tshttpproxy: winhttp: GetProxyForURL(%q): %v/%#v", urlStr, err, err)
if err == syscall.Errno(ERROR_WINHTTP_UNABLE_TO_DOWNLOAD_SCRIPT) { if err == syscall.Errno(ERROR_WINHTTP_UNABLE_TO_DOWNLOAD_SCRIPT) {
setNoProxyUntil(10 * time.Second) setNoProxyUntil(10 * time.Second)
return nil, nil return nil, nil
@ -88,7 +103,7 @@ type result struct {
case <-ctx.Done(): case <-ctx.Done():
cachedProxy.Lock() cachedProxy.Lock()
defer cachedProxy.Unlock() defer cachedProxy.Unlock()
log.Printf("tshttpproxy: winhttp: GetProxyForURL(%q): timeout; using cached proxy %v", urlStr, cachedProxy.val) proxyErrorf("tshttpproxy: winhttp: GetProxyForURL(%q): timeout; using cached proxy %v", urlStr, cachedProxy.val)
return cachedProxy.val, nil return cachedProxy.val, nil
} }
} }
@ -96,7 +111,7 @@ type result struct {
func proxyFromWinHTTP(ctx context.Context, urlStr string) (proxy *url.URL, err error) { func proxyFromWinHTTP(ctx context.Context, urlStr string) (proxy *url.URL, err error) {
whi, err := winHTTPOpen() whi, err := winHTTPOpen()
if err != nil { if err != nil {
log.Printf("winhttp: Open: %v", err) proxyErrorf("winhttp: Open: %v", err)
return nil, err return nil, err
} }
defer whi.Close() defer whi.Close()