diff --git a/cmd/tailscaled/tailscaled.go b/cmd/tailscaled/tailscaled.go index 95193f1e7..45f2afc3e 100644 --- a/cmd/tailscaled/tailscaled.go +++ b/cmd/tailscaled/tailscaled.go @@ -342,7 +342,7 @@ func run() error { } sys.Set(netMon) - pol := logpolicy.New(logtail.CollectionNode, netMon) + pol := logpolicy.New(logtail.CollectionNode, netMon, nil /* use log.Printf */) pol.SetVerbosityLevel(args.verbose) logPol = pol defer func() { diff --git a/ipn/ipnserver/proxyconnect.go b/ipn/ipnserver/proxyconnect.go index 5ac7e89db..0a515350d 100644 --- a/ipn/ipnserver/proxyconnect.go +++ b/ipn/ipnserver/proxyconnect.go @@ -37,7 +37,7 @@ func (s *Server) handleProxyConnectConn(w http.ResponseWriter, r *http.Request) return } - dialContext := logpolicy.MakeDialFunc(s.netMon) + dialContext := logpolicy.MakeDialFunc(s.netMon, s.logf) back, err := dialContext(ctx, "tcp", hostPort) if err != nil { s.logf("error CONNECT dialing %v: %v", hostPort, err) diff --git a/log/sockstatlog/logger.go b/log/sockstatlog/logger.go index 4f522f17d..c1f96e8cc 100644 --- a/log/sockstatlog/logger.go +++ b/log/sockstatlog/logger.go @@ -114,7 +114,7 @@ func NewLogger(logdir string, logf logger.Logf, logID logid.PublicID, netMon *ne logger := &Logger{ logf: logf, filch: filch, - tr: logpolicy.NewLogtailTransport(logtail.DefaultHost, netMon), + tr: logpolicy.NewLogtailTransport(logtail.DefaultHost, netMon, logf), } logger.logger = logtail.NewLogger(logtail.Config{ BaseURL: logpolicy.LogURL(), diff --git a/logpolicy/logpolicy.go b/logpolicy/logpolicy.go index 7becc934f..41d111455 100644 --- a/logpolicy/logpolicy.go +++ b/logpolicy/logpolicy.go @@ -110,6 +110,8 @@ type Policy struct { Logtail *logtail.Logger // PublicID is the logger's instance identifier. PublicID logid.PublicID + // Logf is where to write informational messages about this Logger. + Logf logger.Logf } // NewConfig creates a Config with collection and a newly generated PrivateID. @@ -310,7 +312,7 @@ func winProgramDataAccessible(dir string) bool { // log state for that command exists in dir, then the log state is // moved from wherever it does exist, into dir. Leftover logs state // in / and $CACHE_DIRECTORY is deleted. -func tryFixLogStateLocation(dir, cmdname string) { +func tryFixLogStateLocation(dir, cmdname string, logf logger.Logf) { switch runtime.GOOS { case "linux", "freebsd", "openbsd": // These are the OSes where we might have written stuff into @@ -320,13 +322,13 @@ func tryFixLogStateLocation(dir, cmdname string) { return } if cmdname == "" { - log.Printf("[unexpected] no cmdname given to tryFixLogStateLocation, please file a bug at https://github.com/tailscale/tailscale") + logf("[unexpected] no cmdname given to tryFixLogStateLocation, please file a bug at https://github.com/tailscale/tailscale") return } if dir == "/" { // Trying to store things in / still. That's a bug, but don't // abort hard. - log.Printf("[unexpected] storing logging config in /, please file a bug at https://github.com/tailscale/tailscale") + logf("[unexpected] storing logging config in /, please file a bug at https://github.com/tailscale/tailscale") return } if os.Getuid() != 0 { @@ -383,7 +385,7 @@ func tryFixLogStateLocation(dir, cmdname string) { existsInRoot, err := checkExists("/") if err != nil { - log.Printf("checking for configs in /: %v", err) + logf("checking for configs in /: %v", err) return } existsInCache := false @@ -391,12 +393,12 @@ func tryFixLogStateLocation(dir, cmdname string) { if cacheDir != "" { existsInCache, err = checkExists("/var/cache/tailscale") if err != nil { - log.Printf("checking for configs in %s: %v", cacheDir, err) + logf("checking for configs in %s: %v", cacheDir, err) } } existsInDest, err := checkExists(dir) if err != nil { - log.Printf("checking for configs in %s: %v", dir, err) + logf("checking for configs in %s: %v", dir, err) return } @@ -411,13 +413,13 @@ func tryFixLogStateLocation(dir, cmdname string) { // CACHE_DIRECTORY takes precedence over /, move files from // there. if err := moveFiles(cacheDir); err != nil { - log.Print(err) + logf("%v", err) return } case existsInRoot: // Files from root is better than nothing. if err := moveFiles("/"); err != nil { - log.Print(err) + logf("%v", err) return } } @@ -439,27 +441,32 @@ func tryFixLogStateLocation(dir, cmdname string) { if os.IsNotExist(err) { continue } else if err != nil { - log.Printf("stat %q: %v", p, err) + logf("stat %q: %v", p, err) return } if err := os.Remove(p); err != nil { - log.Printf("rm %q: %v", p, err) + logf("rm %q: %v", p, err) } } } } -// New returns a new log policy (a logger and its instance ID) for a -// given collection name. -// The netMon parameter is optional; if non-nil it's used to do faster interface lookups. -func New(collection string, netMon *netmon.Monitor) *Policy { - return NewWithConfigPath(collection, "", "", netMon) +// New returns a new log policy (a logger and its instance ID) for a given +// collection name. +// +// The netMon parameter is optional; if non-nil it's used to do faster +// interface lookups. +// +// The logf parameter is optional; if non-nil, information logs (e.g. when +// migrating state) are sent to that logger, and global changes to the log +// package are avoided. If nil, logs will be printed using log.Printf. +func New(collection string, netMon *netmon.Monitor, logf logger.Logf) *Policy { + return NewWithConfigPath(collection, "", "", netMon, logf) } -// NewWithConfigPath is identical to New, -// but uses the specified directory and command name. -// If either is empty, it derives them automatically. -func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) *Policy { +// NewWithConfigPath is identical to New, but uses the specified directory and +// command name. If either is empty, it derives them automatically. +func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor, logf logger.Logf) *Policy { var lflags int if term.IsTerminal(2) || runtime.GOOS == "windows" { lflags = 0 @@ -488,7 +495,12 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) if cmdName == "" { cmdName = version.CmdName() } - tryFixLogStateLocation(dir, cmdName) + + useStdLogger := logf == nil + if useStdLogger { + logf = log.Printf + } + tryFixLogStateLocation(dir, cmdName, logf) cfgPath := filepath.Join(dir, fmt.Sprintf("%s.log.conf", cmdName)) @@ -556,7 +568,7 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) } return w }, - HTTPC: &http.Client{Transport: NewLogtailTransport(logtail.DefaultHost, netMon)}, + HTTPC: &http.Client{Transport: NewLogtailTransport(logtail.DefaultHost, netMon, logf)}, } if collection == logtail.CollectionNode { conf.MetricsDelta = clientmetric.EncodeLogTailMetricsDelta @@ -565,13 +577,13 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) } if envknob.NoLogsNoSupport() || inTest() { - log.Println("You have disabled logging. Tailscale will not be able to provide support.") + logf("You have disabled logging. Tailscale will not be able to provide support.") conf.HTTPC = &http.Client{Transport: noopPretendSuccessTransport{}} } else if val := getLogTarget(); val != "" { - log.Println("You have enabled a non-default log target. Doing without being told to by Tailscale staff or your network administrator will make getting support difficult.") + logf("You have enabled a non-default log target. Doing without being told to by Tailscale staff or your network administrator will make getting support difficult.") conf.BaseURL = val u, _ := url.Parse(val) - conf.HTTPC = &http.Client{Transport: NewLogtailTransport(u.Host, netMon)} + conf.HTTPC = &http.Client{Transport: NewLogtailTransport(u.Host, netMon, logf)} } filchOptions := filch.Options{ @@ -588,7 +600,7 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) filchOptions.MaxFileSize = 1 << 20 } else { // not a fatal error, we can leave the log files on the spinning disk - log.Printf("Unable to create /tmp directory for log storage: %v\n", err) + logf("Unable to create /tmp directory for log storage: %v\n", err) } } @@ -599,7 +611,7 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) conf.Stderr = filchBuf.OrigStderr } } - lw := logtail.NewLogger(conf, log.Printf) + lw := logtail.NewLogger(conf, logf) var logOutput io.Writer = lw @@ -612,24 +624,27 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor) } } - log.SetFlags(0) // other log flags are set on console, not here - log.SetOutput(logOutput) + if useStdLogger { + log.SetFlags(0) // other log flags are set on console, not here + log.SetOutput(logOutput) + } - log.Printf("Program starting: v%v, Go %v: %#v", + logf("Program starting: v%v, Go %v: %#v", version.Long(), goVersion(), os.Args) - log.Printf("LogID: %v", newc.PublicID) + logf("LogID: %v", newc.PublicID) if filchErr != nil { - log.Printf("filch failed: %v", filchErr) + logf("filch failed: %v", filchErr) } if earlyErrBuf.Len() != 0 { - log.Printf("%s", earlyErrBuf.Bytes()) + logf("%s", earlyErrBuf.Bytes()) } return &Policy{ Logtail: lw, PublicID: newc.PublicID, + Logf: logf, } } @@ -666,7 +681,7 @@ func (p *Policy) Close() { // log upload if it can be done before ctx is canceled. func (p *Policy) Shutdown(ctx context.Context) error { if p.Logtail != nil { - log.Printf("flushing log.") + p.Logf("flushing log.") return p.Logtail.Shutdown(ctx) } return nil @@ -680,14 +695,14 @@ func (p *Policy) Shutdown(ctx context.Context) error { // for the benefit of older OS platforms which might not include it. // // The netMon parameter is optional; if non-nil it's used to do faster interface lookups. -func MakeDialFunc(netMon *netmon.Monitor) func(ctx context.Context, netw, addr string) (net.Conn, error) { +func MakeDialFunc(netMon *netmon.Monitor, logf logger.Logf) func(ctx context.Context, netw, addr string) (net.Conn, error) { return func(ctx context.Context, netw, addr string) (net.Conn, error) { - return dialContext(ctx, netw, addr, netMon) + return dialContext(ctx, netw, addr, netMon, logf) } } -func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor) (net.Conn, error) { - nd := netns.FromDialer(log.Printf, netMon, &net.Dialer{ +func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor, logf logger.Logf) (net.Conn, error) { + nd := netns.FromDialer(logf, netMon, &net.Dialer{ Timeout: 30 * time.Second, KeepAlive: netknob.PlatformTCPKeepAlive(), }) @@ -708,7 +723,7 @@ func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor) err = errors.New(res.Status) } if err != nil { - log.Printf("logtail: CONNECT response error from tailscaled: %v", err) + logf("logtail: CONNECT response error from tailscaled: %v", err) c.Close() } else { dialLog.Printf("connected via tailscaled") @@ -718,25 +733,29 @@ func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor) } // If we failed to dial, try again with bootstrap DNS. - log.Printf("logtail: dial %q failed: %v (in %v), trying bootstrap...", addr, err, d) + logf("logtail: dial %q failed: %v (in %v), trying bootstrap...", addr, err, d) dnsCache := &dnscache.Resolver{ Forward: dnscache.Get().Forward, // use default cache's forwarder UseLastGood: true, - LookupIPFallback: dnsfallback.MakeLookupFunc(log.Printf, netMon), + LookupIPFallback: dnsfallback.MakeLookupFunc(logf, netMon), NetMon: netMon, } dialer := dnscache.Dialer(nd.DialContext, dnsCache) c, err = dialer(ctx, netw, addr) if err == nil { - log.Printf("logtail: bootstrap dial succeeded") + logf("logtail: bootstrap dial succeeded") } return c, err } // NewLogtailTransport returns an HTTP Transport particularly suited to uploading // logs to the given host name. See DialContext for details on how it works. +// // The netMon parameter is optional; if non-nil it's used to do faster interface lookups. -func NewLogtailTransport(host string, netMon *netmon.Monitor) http.RoundTripper { +// +// The logf parameter is optional; if non-nil, logs are printed using the +// provided function; if nil, log.Printf will be used instead. +func NewLogtailTransport(host string, netMon *netmon.Monitor, logf logger.Logf) http.RoundTripper { if inTest() { return noopPretendSuccessTransport{} } @@ -752,7 +771,10 @@ func NewLogtailTransport(host string, netMon *netmon.Monitor) http.RoundTripper tr.DisableCompression = true // Log whenever we dial: - tr.DialContext = MakeDialFunc(netMon) + if logf == nil { + logf = log.Printf + } + tr.DialContext = MakeDialFunc(netMon, logf) // We're contacting exactly 1 hostname, so the default's 100 // max idle conns is very high for our needs. Even 2 is diff --git a/tsnet/tsnet.go b/tsnet/tsnet.go index a0430857a..d819e5a79 100644 --- a/tsnet/tsnet.go +++ b/tsnet/tsnet.go @@ -641,7 +641,7 @@ func (s *Server) startLogger(closePool *closeOnErrorPool) error { } return w }, - HTTPC: &http.Client{Transport: logpolicy.NewLogtailTransport(logtail.DefaultHost, s.netMon)}, + HTTPC: &http.Client{Transport: logpolicy.NewLogtailTransport(logtail.DefaultHost, s.netMon, s.logf)}, } s.logtail = logtail.NewLogger(c, s.logf) closePool.addFunc(func() { s.logtail.Shutdown(context.Background()) }) diff --git a/wgengine/netlog/logger.go b/wgengine/netlog/logger.go index a694308e6..68a873052 100644 --- a/wgengine/netlog/logger.go +++ b/wgengine/netlog/logger.go @@ -101,7 +101,7 @@ func (nl *Logger) Startup(nodeID tailcfg.StableNodeID, nodeLogID, domainLogID lo } // Startup a log stream to Tailscale's logging service. - httpc := &http.Client{Transport: logpolicy.NewLogtailTransport(logtail.DefaultHost, netMon)} + httpc := &http.Client{Transport: logpolicy.NewLogtailTransport(logtail.DefaultHost, netMon, nl.logger.Logf)} if testClient != nil { httpc = testClient }