all: remove unnecessary trailing newlines in format patterns for consistency

And document on logger.Logf that it's unnecessary.
pull/296/head
Brad Fitzpatrick 5 years ago
parent a7e7c7b548
commit 45f2b53aca

@ -45,7 +45,7 @@ func main() {
err := fixconsole.FixConsoleIfNeeded() err := fixconsole.FixConsoleIfNeeded()
if err != nil { if err != nil {
logf("fixConsoleOutput: %v\n", err) logf("fixConsoleOutput: %v", err)
} }
pol := logpolicy.New("tailnode.log.tailscale.io") pol := logpolicy.New("tailnode.log.tailscale.io")
@ -75,7 +75,7 @@ func main() {
e, err = wgengine.NewUserspaceEngine(logf, *tunname, *listenport) e, err = wgengine.NewUserspaceEngine(logf, *tunname, *listenport)
} }
if err != nil { if err != nil {
log.Fatalf("wgengine.New: %v\n", err) log.Fatalf("wgengine.New: %v", err)
} }
e = wgengine.NewWatchdog(e) e = wgengine.NewWatchdog(e)
@ -90,7 +90,7 @@ func main() {
} }
err = ipnserver.Run(context.Background(), logf, pol.PublicID.String(), opts, e) err = ipnserver.Run(context.Background(), logf, pol.PublicID.String(), opts, e)
if err != nil { if err != nil {
log.Fatalf("tailscaled: %v\n", err) log.Fatalf("tailscaled: %v", err)
} }
// TODO(crawshaw): It would be nice to start a timeout context the moment a signal // TODO(crawshaw): It would be nice to start a timeout context the moment a signal

@ -202,7 +202,7 @@ func (c *Client) cancelMapSafely() {
c.mu.Lock() c.mu.Lock()
defer c.mu.Unlock() defer c.mu.Unlock()
c.logf("cancelMapSafely: synced=%v\n", c.synced) c.logf("cancelMapSafely: synced=%v", c.synced)
if c.inPollNetMap { if c.inPollNetMap {
// received at least one netmap since the last // received at least one netmap since the last
@ -224,12 +224,12 @@ func (c *Client) cancelMapSafely() {
// request. // request.
select { select {
case c.newMapCh <- struct{}{}: case c.newMapCh <- struct{}{}:
c.logf("cancelMapSafely: wrote to channel\n") c.logf("cancelMapSafely: wrote to channel")
default: default:
// if channel write failed, then there was already // if channel write failed, then there was already
// an outstanding newMapCh request. One is enough, // an outstanding newMapCh request. One is enough,
// since it'll always use the latest endpoints. // since it'll always use the latest endpoints.
c.logf("cancelMapSafely: channel was full\n") c.logf("cancelMapSafely: channel was full")
} }
} }
} }
@ -240,7 +240,7 @@ func (c *Client) authRoutine() {
for { for {
c.mu.Lock() c.mu.Lock()
c.logf("authRoutine: %s\n", c.state) c.logf("authRoutine: %s", c.state)
expiry := c.expiry expiry := c.expiry
goal := c.loginGoal goal := c.loginGoal
ctx := c.authCtx ctx := c.authCtx
@ -249,13 +249,13 @@ func (c *Client) authRoutine() {
select { select {
case <-c.quit: case <-c.quit:
c.logf("authRoutine: quit\n") c.logf("authRoutine: quit")
return return
default: default:
} }
report := func(err error, msg string) { report := func(err error, msg string) {
c.logf("%s: %v\n", msg, err) c.logf("%s: %v", msg, err)
err = fmt.Errorf("%s: %v", msg, err) err = fmt.Errorf("%s: %v", msg, err)
// don't send status updates for context errors, // don't send status updates for context errors,
// since context cancelation is always on purpose. // since context cancelation is always on purpose.
@ -284,14 +284,14 @@ func (c *Client) authRoutine() {
} }
select { select {
case <-ctx.Done(): case <-ctx.Done():
c.logf("authRoutine: context done.\n") c.logf("authRoutine: context done.")
case <-exp: case <-exp:
// Unfortunately the key expiry isn't provided // Unfortunately the key expiry isn't provided
// by the control server until mapRequest. // by the control server until mapRequest.
// So we have to do some hackery with c.expiry // So we have to do some hackery with c.expiry
// in here. // in here.
// TODO(apenwarr): add a key expiry field in RegisterResponse. // TODO(apenwarr): add a key expiry field in RegisterResponse.
c.logf("authRoutine: key expiration check.\n") c.logf("authRoutine: key expiration check.")
if synced && expiry != nil && !expiry.IsZero() && expiry.Before(c.timeNow()) { if synced && expiry != nil && !expiry.IsZero() && expiry.Before(c.timeNow()) {
c.logf("Key expired; setting loggedIn=false.") c.logf("Key expired; setting loggedIn=false.")
@ -385,20 +385,20 @@ func (c *Client) mapRoutine() {
for { for {
c.mu.Lock() c.mu.Lock()
c.logf("mapRoutine: %s\n", c.state) c.logf("mapRoutine: %s", c.state)
loggedIn := c.loggedIn loggedIn := c.loggedIn
ctx := c.mapCtx ctx := c.mapCtx
c.mu.Unlock() c.mu.Unlock()
select { select {
case <-c.quit: case <-c.quit:
c.logf("mapRoutine: quit\n") c.logf("mapRoutine: quit")
return return
default: default:
} }
report := func(err error, msg string) { report := func(err error, msg string) {
c.logf("%s: %v\n", msg, err) c.logf("%s: %v", msg, err)
err = fmt.Errorf("%s: %v", msg, err) err = fmt.Errorf("%s: %v", msg, err)
// don't send status updates for context errors, // don't send status updates for context errors,
// since context cancelation is always on purpose. // since context cancelation is always on purpose.
@ -416,9 +416,9 @@ func (c *Client) mapRoutine() {
select { select {
case <-ctx.Done(): case <-ctx.Done():
c.logf("mapRoutine: context done.\n") c.logf("mapRoutine: context done.")
case <-c.newMapCh: case <-c.newMapCh:
c.logf("mapRoutine: new map needed while idle.\n") c.logf("mapRoutine: new map needed while idle.")
} }
} else { } else {
// Be sure this is false when we're not inside // Be sure this is false when we're not inside
@ -433,7 +433,7 @@ func (c *Client) mapRoutine() {
select { select {
case <-c.newMapCh: case <-c.newMapCh:
c.logf("mapRoutine: new map request during PollNetMap. canceling.\n") c.logf("mapRoutine: new map request during PollNetMap. canceling.")
c.cancelMapLocked() c.cancelMapLocked()
// Don't emit this netmap; we're // Don't emit this netmap; we're
@ -455,7 +455,7 @@ func (c *Client) mapRoutine() {
c.mu.Unlock() c.mu.Unlock()
c.logf("mapRoutine: netmap received: %s\n", state) c.logf("mapRoutine: netmap received: %s", state)
if stillAuthed { if stillAuthed {
c.sendStatus("mapRoutine2", nil, "", nm) c.sendStatus("mapRoutine2", nil, "", nm)
} }
@ -530,7 +530,7 @@ func (c *Client) sendStatus(who string, err error, url string, nm *NetworkMap) {
c.inSendStatus++ c.inSendStatus++
c.mu.Unlock() c.mu.Unlock()
c.logf("sendStatus: %s: %v\n", who, state) c.logf("sendStatus: %s: %v", who, state)
var p *Persist var p *Persist
var fin *empty.Message var fin *empty.Message
@ -566,7 +566,7 @@ func (c *Client) sendStatus(who string, err error, url string, nm *NetworkMap) {
} }
func (c *Client) Login(t *oauth2.Token, flags LoginFlags) { func (c *Client) Login(t *oauth2.Token, flags LoginFlags) {
c.logf("client.Login(%v, %v)\n", t != nil, flags) c.logf("client.Login(%v, %v)", t != nil, flags)
c.mu.Lock() c.mu.Lock()
c.loginGoal = &LoginGoal{ c.loginGoal = &LoginGoal{
@ -580,7 +580,7 @@ func (c *Client) Login(t *oauth2.Token, flags LoginFlags) {
} }
func (c *Client) Logout() { func (c *Client) Logout() {
c.logf("client.Logout()\n") c.logf("client.Logout()")
c.mu.Lock() c.mu.Lock()
c.loginGoal = &LoginGoal{ c.loginGoal = &LoginGoal{
@ -599,7 +599,7 @@ func (c *Client) UpdateEndpoints(localPort uint16, endpoints []string) {
} }
func (c *Client) Shutdown() { func (c *Client) Shutdown() {
c.logf("client.Shutdown()\n") c.logf("client.Shutdown()")
c.mu.Lock() c.mu.Lock()
inSendStatus := c.inSendStatus inSendStatus := c.inSendStatus
@ -610,13 +610,13 @@ func (c *Client) Shutdown() {
} }
c.mu.Unlock() c.mu.Unlock()
c.logf("client.Shutdown: inSendStatus=%v\n", inSendStatus) c.logf("client.Shutdown: inSendStatus=%v", inSendStatus)
if !closed { if !closed {
close(c.quit) close(c.quit)
c.cancelAuth() c.cancelAuth()
<-c.authDone <-c.authDone
c.cancelMapUnsafely() c.cancelMapUnsafely()
<-c.mapDone <-c.mapDone
c.logf("Client.Shutdown done.\n") c.logf("Client.Shutdown done.")
} }
} }

@ -202,7 +202,7 @@ const (
) )
func (c *Direct) TryLogout(ctx context.Context) error { func (c *Direct) TryLogout(ctx context.Context) error {
c.logf("direct.TryLogout()\n") c.logf("direct.TryLogout()")
c.mu.Lock() c.mu.Lock()
defer c.mu.Unlock() defer c.mu.Unlock()
@ -218,12 +218,12 @@ func (c *Direct) TryLogout(ctx context.Context) error {
} }
func (c *Direct) TryLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags) (url string, err error) { func (c *Direct) TryLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags) (url string, err error) {
c.logf("direct.TryLogin(%v, %v)\n", t != nil, flags) c.logf("direct.TryLogin(%v, %v)", t != nil, flags)
return c.doLoginOrRegen(ctx, t, flags, false, "") return c.doLoginOrRegen(ctx, t, flags, false, "")
} }
func (c *Direct) WaitLoginURL(ctx context.Context, url string) (newUrl string, err error) { func (c *Direct) WaitLoginURL(ctx context.Context, url string) (newUrl string, err error) {
c.logf("direct.WaitLoginURL\n") c.logf("direct.WaitLoginURL")
return c.doLoginOrRegen(ctx, nil, LoginDefault, false, url) return c.doLoginOrRegen(ctx, nil, LoginDefault, false, url)
} }
@ -247,7 +247,7 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
c.mu.Unlock() c.mu.Unlock()
if persist.PrivateMachineKey == (wgcfg.PrivateKey{}) { if persist.PrivateMachineKey == (wgcfg.PrivateKey{}) {
c.logf("Generating a new machinekey.\n") c.logf("Generating a new machinekey.")
mkey, err := wgcfg.NewPrivateKey() mkey, err := wgcfg.NewPrivateKey()
if err != nil { if err != nil {
log.Fatal(err) log.Fatal(err)
@ -256,15 +256,15 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
} }
if expired { if expired {
c.logf("Old key expired -> regen=true\n") c.logf("Old key expired -> regen=true")
regen = true regen = true
} }
if (flags & LoginInteractive) != 0 { if (flags & LoginInteractive) != 0 {
c.logf("LoginInteractive -> regen=true\n") c.logf("LoginInteractive -> regen=true")
regen = true regen = true
} }
c.logf("doLogin(regen=%v, hasUrl=%v)\n", regen, url != "") c.logf("doLogin(regen=%v, hasUrl=%v)", regen, url != "")
if serverKey == (wgcfg.Key{}) { if serverKey == (wgcfg.Key{}) {
var err error var err error
serverKey, err = loadServerKey(ctx, c.httpc, c.serverURL) serverKey, err = loadServerKey(ctx, c.httpc, c.serverURL)
@ -280,7 +280,7 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
var oldNodeKey wgcfg.Key var oldNodeKey wgcfg.Key
if url != "" { if url != "" {
} else if regen || persist.PrivateNodeKey == (wgcfg.PrivateKey{}) { } else if regen || persist.PrivateNodeKey == (wgcfg.PrivateKey{}) {
c.logf("Generating a new nodekey.\n") c.logf("Generating a new nodekey.")
persist.OldPrivateNodeKey = persist.PrivateNodeKey persist.OldPrivateNodeKey = persist.PrivateNodeKey
key, err := wgcfg.NewPrivateKey() key, err := wgcfg.NewPrivateKey()
if err != nil { if err != nil {
@ -297,7 +297,7 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
} }
if tryingNewKey == (wgcfg.PrivateKey{}) { if tryingNewKey == (wgcfg.PrivateKey{}) {
log.Fatalf("tryingNewKey is empty, give up\n") log.Fatalf("tryingNewKey is empty, give up")
} }
if c.hostinfo.BackendLogID == "" { if c.hostinfo.BackendLogID == "" {
err = errors.New("hostinfo: BackendLogID missing") err = errors.New("hostinfo: BackendLogID missing")
@ -310,7 +310,7 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
Hostinfo: c.hostinfo, Hostinfo: c.hostinfo,
Followup: url, Followup: url,
} }
c.logf("RegisterReq: onode=%v node=%v fup=%v\n", c.logf("RegisterReq: onode=%v node=%v fup=%v",
request.OldNodeKey.ShortString(), request.OldNodeKey.ShortString(),
request.NodeKey.ShortString(), url != "") request.NodeKey.ShortString(), url != "")
request.Auth.Oauth2Token = t request.Auth.Oauth2Token = t
@ -334,7 +334,7 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
if err != nil { if err != nil {
return regen, url, fmt.Errorf("register request: %v", err) return regen, url, fmt.Errorf("register request: %v", err)
} }
c.logf("RegisterReq: returned.\n") c.logf("RegisterReq: returned.")
resp := tailcfg.RegisterResponse{} resp := tailcfg.RegisterResponse{}
if err := decode(res, &resp, &serverKey, &persist.PrivateMachineKey); err != nil { if err := decode(res, &resp, &serverKey, &persist.PrivateMachineKey); err != nil {
return regen, url, fmt.Errorf("register request: %v", err) return regen, url, fmt.Errorf("register request: %v", err)
@ -362,9 +362,9 @@ func (c *Direct) doLogin(ctx context.Context, t *oauth2.Token, flags LoginFlags,
// - user is disabled // - user is disabled
if resp.AuthURL != "" { if resp.AuthURL != "" {
c.logf("AuthURL is %.20v...\n", resp.AuthURL) c.logf("AuthURL is %.20v...", resp.AuthURL)
} else { } else {
c.logf("No AuthURL\n") c.logf("No AuthURL")
} }
c.mu.Lock() c.mu.Lock()
@ -411,7 +411,7 @@ func (c *Direct) newEndpoints(localPort uint16, endpoints []string) (changed boo
if c.localPort == localPort && sameStrings(c.endpoints, endpoints) { if c.localPort == localPort && sameStrings(c.endpoints, endpoints) {
return false // unchanged return false // unchanged
} }
c.logf("client.newEndpoints(%v, %v)\n", localPort, endpoints) c.logf("client.newEndpoints(%v, %v)", localPort, endpoints)
c.localPort = localPort c.localPort = localPort
c.endpoints = append(c.endpoints[:0], endpoints...) c.endpoints = append(c.endpoints[:0], endpoints...)
return true // changed return true // changed
@ -441,7 +441,7 @@ func (c *Direct) PollNetMap(ctx context.Context, maxPolls int, cb func(*NetworkM
} }
allowStream := maxPolls != 1 allowStream := maxPolls != 1
c.logf("PollNetMap: stream=%v :%v %v\n", maxPolls, localPort, ep) c.logf("PollNetMap: stream=%v :%v %v", maxPolls, localPort, ep)
request := tailcfg.MapRequest{ request := tailcfg.MapRequest{
Version: 4, Version: 4,

@ -62,7 +62,7 @@ func (h *Handle) Reset() {
func (h *Handle) notify(n Notify) { func (h *Handle) notify(n Notify) {
h.mu.Lock() h.mu.Lock()
if n.BackendLogID != nil { if n.BackendLogID != nil {
h.logf("Handle: logs: be:%v fe:%v\n", h.logf("Handle: logs: be:%v fe:%v",
*n.BackendLogID, h.frontendLogID) *n.BackendLogID, h.frontendLogID)
} }
if n.State != nil { if n.State != nil {

@ -14,7 +14,6 @@ import (
"os" "os"
"os/exec" "os/exec"
"os/signal" "os/signal"
"strings"
"sync" "sync"
"syscall" "syscall"
"time" "time"
@ -64,17 +63,17 @@ type Options struct {
} }
func pump(logf logger.Logf, ctx context.Context, bs *ipn.BackendServer, s net.Conn) { func pump(logf logger.Logf, ctx context.Context, bs *ipn.BackendServer, s net.Conn) {
defer logf("Control connection done.\n") defer logf("Control connection done.")
for ctx.Err() == nil && !bs.GotQuit { for ctx.Err() == nil && !bs.GotQuit {
msg, err := ipn.ReadMsg(s) msg, err := ipn.ReadMsg(s)
if err != nil { if err != nil {
logf("ReadMsg: %v\n", err) logf("ReadMsg: %v", err)
break break
} }
err = bs.GotCommandMsg(msg) err = bs.GotCommandMsg(msg)
if err != nil { if err != nil {
logf("GotCommandMsg: %v\n", err) logf("GotCommandMsg: %v", err)
break break
} }
} }
@ -97,7 +96,7 @@ func Run(rctx context.Context, logf logger.Logf, logid string, opts Options, e w
} }
listen.Close() listen.Close()
}() }()
logf("Listening on %v\n", listen.Addr()) logf("Listening on %v", listen.Addr())
var store ipn.StateStore var store ipn.StateStore
if opts.StatePath != "" { if opts.StatePath != "" {
@ -170,11 +169,11 @@ func Run(rctx context.Context, logf logger.Logf, logid string, opts Options, e w
for i := 1; rctx.Err() == nil; i++ { for i := 1; rctx.Err() == nil; i++ {
s, err = listen.Accept() s, err = listen.Accept()
if err != nil { if err != nil {
logf("%d: Accept: %v\n", i, err) logf("%d: Accept: %v", i, err)
bo.BackOff(rctx, err) bo.BackOff(rctx, err)
continue continue
} }
logf("%d: Incoming control connection.\n", i) logf("%d: Incoming control connection.", i)
stopAll() stopAll()
ctx, cancel = context.WithCancel(rctx) ctx, cancel = context.WithCancel(rctx)
@ -217,10 +216,10 @@ func BabysitProc(ctx context.Context, args []string, logf logger.Logf) {
var sig os.Signal var sig os.Signal
select { select {
case sig = <-interrupt: case sig = <-interrupt:
logf("BabysitProc: got signal: %v\n", sig) logf("BabysitProc: got signal: %v", sig)
close(done) close(done)
case <-ctx.Done(): case <-ctx.Done():
logf("BabysitProc: context done\n") logf("BabysitProc: context done")
sig = os.Kill sig = os.Kill
close(done) close(done)
} }
@ -234,7 +233,7 @@ func BabysitProc(ctx context.Context, args []string, logf logger.Logf) {
for { for {
startTime := time.Now() startTime := time.Now()
log.Printf("exec: %#v %v\n", executable, args) log.Printf("exec: %#v %v", executable, args)
cmd := exec.Command(executable, args...) cmd := exec.Command(executable, args...)
// Create a pipe object to use as the subproc's stdin. // Create a pipe object to use as the subproc's stdin.
@ -245,7 +244,7 @@ func BabysitProc(ctx context.Context, args []string, logf logger.Logf) {
// We never need to actually write to wStdin. // We never need to actually write to wStdin.
rStdin, wStdin, err := os.Pipe() rStdin, wStdin, err := os.Pipe()
if err != nil { if err != nil {
log.Printf("os.Pipe 1: %v\n", err) log.Printf("os.Pipe 1: %v", err)
return return
} }
@ -257,7 +256,7 @@ func BabysitProc(ctx context.Context, args []string, logf logger.Logf) {
// logf() calls. bufio is more appropriate. // logf() calls. bufio is more appropriate.
rStdout, wStdout, err := os.Pipe() rStdout, wStdout, err := os.Pipe()
if err != nil { if err != nil {
log.Printf("os.Pipe 2: %v\n", err) log.Printf("os.Pipe 2: %v", err)
} }
go func(r *os.File) { go func(r *os.File) {
defer r.Close() defer r.Close()
@ -265,7 +264,7 @@ func BabysitProc(ctx context.Context, args []string, logf logger.Logf) {
for { for {
s, err := rb.ReadString('\n') s, err := rb.ReadString('\n')
if s != "" { if s != "" {
logf("%s\n", strings.TrimSuffix(s, "\n")) logf("%s", s)
} }
if err != nil { if err != nil {
break break

@ -76,7 +76,7 @@ func NewLocalBackend(logf logger.Logf, logid string, store StateStore, e wgengin
ctx, cancel := context.WithCancel(context.Background()) ctx, cancel := context.WithCancel(context.Background())
portpoll, err := portlist.NewPoller() portpoll, err := portlist.NewPoller()
if err != nil { if err != nil {
logf("skipping portlist: %s\n", err) logf("skipping portlist: %s", err)
} }
b := &LocalBackend{ b := &LocalBackend{
@ -165,9 +165,9 @@ func (b *LocalBackend) Start(opts Options) error {
} }
if opts.Prefs != nil { if opts.Prefs != nil {
b.logf("Start: %v\n", opts.Prefs.Pretty()) b.logf("Start: %v", opts.Prefs.Pretty())
} else { } else {
b.logf("Start\n") b.logf("Start")
} }
hi := controlclient.NewHostinfo() hi := controlclient.NewHostinfo()
@ -268,7 +268,7 @@ func (b *LocalBackend) Start(opts Options) error {
if strings.TrimSpace(diff) == "" { if strings.TrimSpace(diff) == "" {
b.logf("netmap diff: (none)") b.logf("netmap diff: (none)")
} else { } else {
b.logf("netmap diff:\n%v\n", diff) b.logf("netmap diff:\n%v", diff)
} }
} }
b.netMapCache = newSt.NetMap b.netMapCache = newSt.NetMap
@ -278,7 +278,7 @@ func (b *LocalBackend) Start(opts Options) error {
b.updateFilter(newSt.NetMap) b.updateFilter(newSt.NetMap)
} }
if newSt.URL != "" { if newSt.URL != "" {
b.logf("Received auth URL: %.20v...\n", newSt.URL) b.logf("Received auth URL: %.20v...", newSt.URL)
b.mu.Lock() b.mu.Lock()
interact := b.interact interact := b.interact
@ -313,7 +313,7 @@ func (b *LocalBackend) Start(opts Options) error {
return return
} }
if s == nil { if s == nil {
log.Fatalf("weird: non-error wgengine update with status=nil\n") log.Fatalf("weird: non-error wgengine update with status=nil")
} }
es := b.parseWgStatus(s) es := b.parseWgStatus(s)
@ -343,7 +343,7 @@ func (b *LocalBackend) Start(opts Options) error {
b.mu.Unlock() b.mu.Unlock()
blid := b.backendLogID blid := b.backendLogID
b.logf("Backend: logs: be:%v fe:%v\n", blid, opts.FrontendLogID) b.logf("Backend: logs: be:%v fe:%v", blid, opts.FrontendLogID)
b.send(Notify{BackendLogID: &blid}) b.send(Notify{BackendLogID: &blid})
b.send(Notify{Prefs: prefs}) b.send(Notify{Prefs: prefs})
@ -362,10 +362,10 @@ func (b *LocalBackend) updateFilter(netMap *controlclient.NetworkMap) {
// TODO(apenwarr): print a diff instead of full filter. // TODO(apenwarr): print a diff instead of full filter.
now := time.Now() now := time.Now()
if now.Sub(b.lastFilterPrint) > 1*time.Minute { if now.Sub(b.lastFilterPrint) > 1*time.Minute {
b.logf("netmap packet filter: %v\n", b.netMapCache.PacketFilter) b.logf("netmap packet filter: %v", b.netMapCache.PacketFilter)
b.lastFilterPrint = now b.lastFilterPrint = now
} else { } else {
b.logf("netmap packet filter: (suppressed)\n") b.logf("netmap packet filter: (suppressed)")
} }
b.e.SetFilter(filter.New(netMap.PacketFilter, b.e.GetFilter())) b.e.SetFilter(filter.New(netMap.PacketFilter, b.e.GetFilter()))
} }
@ -426,7 +426,7 @@ func (b *LocalBackend) popBrowserAuthNow() {
b.authURL = "" b.authURL = ""
b.mu.Unlock() b.mu.Unlock()
b.logf("popBrowserAuthNow: url=%v\n", url != "") b.logf("popBrowserAuthNow: url=%v", url != "")
b.blockEngineUpdates(true) b.blockEngineUpdates(true)
b.stopEngineAndWait() b.stopEngineAndWait()
@ -515,7 +515,7 @@ func (b *LocalBackend) StartLoginInteractive() {
url := b.authURL url := b.authURL
c := b.c c := b.c
b.mu.Unlock() b.mu.Unlock()
b.logf("StartLoginInteractive: url=%v\n", url != "") b.logf("StartLoginInteractive: url=%v", url != "")
if url != "" { if url != "" {
b.popBrowserAuthNow() b.popBrowserAuthNow()
@ -525,7 +525,7 @@ func (b *LocalBackend) StartLoginInteractive() {
} }
func (b *LocalBackend) FakeExpireAfter(x time.Duration) { func (b *LocalBackend) FakeExpireAfter(x time.Duration) {
b.logf("FakeExpireAfter: %v\n", x) b.logf("FakeExpireAfter: %v", x)
if b.netMapCache != nil { if b.netMapCache != nil {
e := b.netMapCache.Expiry e := b.netMapCache.Expiry
if e.IsZero() || time.Until(e) > x { if e.IsZero() || time.Until(e) > x {
@ -568,7 +568,7 @@ func (b *LocalBackend) parseWgStatus(s *wgengine.Status) EngineStatus {
rx += p.RxBytes rx += p.RxBytes
tx += p.TxBytes tx += p.TxBytes
} }
b.logf("v%v peers: %v\n", version.LONG, strings.Join(ss, " ")) b.logf("v%v peers: %v", version.LONG, strings.Join(ss, " "))
return EngineStatus{ return EngineStatus{
RBytes: rx, RBytes: rx,
WBytes: tx, WBytes: tx,
@ -610,7 +610,7 @@ func (b *LocalBackend) SetPrefs(new *Prefs) {
cli := b.c cli := b.c
b.mu.Unlock() b.mu.Unlock()
b.logf("SetPrefs: %v\n", new.Pretty()) b.logf("SetPrefs: %v", new.Pretty())
if cli != nil && !oldHi.Equal(newHi) { if cli != nil && !oldHi.Equal(newHi) {
cli.SetHostinfo(newHi) cli.SetHostinfo(newHi)
@ -632,7 +632,7 @@ func (b *LocalBackend) NetMap() *controlclient.NetworkMap {
func (b *LocalBackend) blockEngineUpdates(block bool) { func (b *LocalBackend) blockEngineUpdates(block bool) {
// TODO(apenwarr): probably need mutex here (and several other places) // TODO(apenwarr): probably need mutex here (and several other places)
b.logf("blockEngineUpdates(%v)\n", block) b.logf("blockEngineUpdates(%v)", block)
b.mu.Lock() b.mu.Lock()
b.blocked = block b.blocked = block
@ -647,15 +647,15 @@ func (b *LocalBackend) authReconfig() {
b.mu.Unlock() b.mu.Unlock()
if blocked { if blocked {
b.logf("authReconfig: blocked, skipping.\n") b.logf("authReconfig: blocked, skipping.")
return return
} }
if nm == nil { if nm == nil {
b.logf("authReconfig: netmap not yet valid. Skipping.\n") b.logf("authReconfig: netmap not yet valid. Skipping.")
return return
} }
if !uc.WantRunning { if !uc.WantRunning {
b.logf("authReconfig: skipping because !WantRunning.\n") b.logf("authReconfig: skipping because !WantRunning.")
return return
} }
@ -683,14 +683,14 @@ func (b *LocalBackend) authReconfig() {
} }
cfg, err := nm.WGCfg(uflags, dns) cfg, err := nm.WGCfg(uflags, dns)
if err != nil { if err != nil {
log.Fatalf("WGCfg: %v\n", err) log.Fatalf("WGCfg: %v", err)
} }
err = b.e.Reconfig(cfg, dom) err = b.e.Reconfig(cfg, dom)
if err == wgengine.ErrNoChanges { if err == wgengine.ErrNoChanges {
return return
} }
b.logf("authReconfig: ra=%v dns=%v 0x%02x: %v\n", uc.RouteAll, uc.CorpDNS, uflags, err) b.logf("authReconfig: ra=%v dns=%v 0x%02x: %v", uc.RouteAll, uc.CorpDNS, uflags, err)
} }
func (b *LocalBackend) enterState(newState State) { func (b *LocalBackend) enterState(newState State) {
@ -703,7 +703,7 @@ func (b *LocalBackend) enterState(newState State) {
if state == newState { if state == newState {
return return
} }
b.logf("Switching ipn state %v -> %v (WantRunning=%v)\n", b.logf("Switching ipn state %v -> %v (WantRunning=%v)",
state, newState, prefs.WantRunning) state, newState, prefs.WantRunning)
if notify != nil { if notify != nil {
b.send(Notify{State: &newState}) b.send(Notify{State: &newState})
@ -717,7 +717,7 @@ func (b *LocalBackend) enterState(newState State) {
case Stopped: case Stopped:
err := b.e.Reconfig(&wgcfg.Config{}, nil) err := b.e.Reconfig(&wgcfg.Config{}, nil)
if err != nil { if err != nil {
b.logf("Reconfig(down): %v\n", err) b.logf("Reconfig(down): %v", err)
} }
case Starting, NeedsMachineAuth: case Starting, NeedsMachineAuth:
b.authReconfig() b.authReconfig()
@ -726,7 +726,7 @@ func (b *LocalBackend) enterState(newState State) {
case Running: case Running:
break break
default: default:
b.logf("Weird: unknown newState %#v\n", newState) b.logf("[unexpected] unknown newState %#v", newState)
} }
} }
@ -790,22 +790,22 @@ func (b *LocalBackend) stateMachine() {
} }
func (b *LocalBackend) stopEngineAndWait() { func (b *LocalBackend) stopEngineAndWait() {
b.logf("stopEngineAndWait...\n") b.logf("stopEngineAndWait...")
b.e.Reconfig(&wgcfg.Config{}, nil) b.e.Reconfig(&wgcfg.Config{}, nil)
b.requestEngineStatusAndWait() b.requestEngineStatusAndWait()
b.logf("stopEngineAndWait: done.\n") b.logf("stopEngineAndWait: done.")
} }
// Requests the wgengine status, and does not return until the status // Requests the wgengine status, and does not return until the status
// was delivered (to the usual callback). // was delivered (to the usual callback).
func (b *LocalBackend) requestEngineStatusAndWait() { func (b *LocalBackend) requestEngineStatusAndWait() {
b.logf("requestEngineStatusAndWait\n") b.logf("requestEngineStatusAndWait")
b.statusLock.Lock() b.statusLock.Lock()
go b.e.RequestStatus() go b.e.RequestStatus()
b.logf("requestEngineStatusAndWait: waiting...\n") b.logf("requestEngineStatusAndWait: waiting...")
b.statusChanged.Wait() // temporarily releases lock while waiting b.statusChanged.Wait() // temporarily releases lock while waiting
b.logf("requestEngineStatusAndWait: got status update.\n") b.logf("requestEngineStatusAndWait: got status update.")
b.statusLock.Unlock() b.statusLock.Unlock()
} }

@ -66,7 +66,7 @@ func (bs *BackendServer) send(n Notify) {
n.Version = version.LONG n.Version = version.LONG
b, err := json.Marshal(n) b, err := json.Marshal(n)
if err != nil { if err != nil {
log.Fatalf("Failed json.Marshal(notify): %v\n%#v\n", err, n) log.Fatalf("Failed json.Marshal(notify): %v\n%#v", err, n)
} }
bs.sendNotifyMsg(b) bs.sendNotifyMsg(b)
} }
@ -83,9 +83,9 @@ func (bs *BackendServer) GotCommandMsg(b []byte) error {
func (bs *BackendServer) GotCommand(cmd *Command) error { func (bs *BackendServer) GotCommand(cmd *Command) error {
if cmd.Version != version.LONG { if cmd.Version != version.LONG {
vs := fmt.Sprintf("Version mismatch! frontend=%#v backend=%#v\n", vs := fmt.Sprintf("Version mismatch! frontend=%#v backend=%#v",
cmd.Version, version.LONG) cmd.Version, version.LONG)
bs.logf("%s\n", vs) bs.logf("%s", vs)
// ignore the command, but send a message back to the // ignore the command, but send a message back to the
// caller so it can realize the version mismatch too. // caller so it can realize the version mismatch too.
// We don't want to exit because it might cause a crash // We don't want to exit because it might cause a crash
@ -154,7 +154,7 @@ func (bc *BackendClient) GotNotifyMsg(b []byte) {
if n.Version != version.LONG { if n.Version != version.LONG {
vs := fmt.Sprintf("Version mismatch! frontend=%#v backend=%#v", vs := fmt.Sprintf("Version mismatch! frontend=%#v backend=%#v",
version.LONG, n.Version) version.LONG, n.Version)
bc.logf("%s\n", vs) bc.logf("%s", vs)
// delete anything in the notification except the version, // delete anything in the notification except the version,
// to prevent incorrect operation. // to prevent incorrect operation.
n = Notify{ n = Notify{

@ -13,6 +13,7 @@ import (
) )
// Logf is the basic Tailscale logger type: a printf-like func. // Logf is the basic Tailscale logger type: a printf-like func.
// Like log.Printf, the format need not end in a newline.
type Logf func(format string, args ...interface{}) type Logf func(format string, args ...interface{})
// WithPrefix wraps f, prefixing each format with the provided prefix. // WithPrefix wraps f, prefixing each format with the provided prefix.

@ -21,16 +21,16 @@ type fakeRouter struct {
} }
func (r fakeRouter) Up() error { func (r fakeRouter) Up() error {
r.logf("Warning: fakeRouter.Up: not implemented.\n") r.logf("Warning: fakeRouter.Up: not implemented.")
return nil return nil
} }
func (r fakeRouter) SetRoutes(rs RouteSettings) error { func (r fakeRouter) SetRoutes(rs RouteSettings) error {
r.logf("Warning: fakeRouter.SetRoutes: not implemented.\n") r.logf("Warning: fakeRouter.SetRoutes: not implemented.")
return nil return nil
} }
func (r fakeRouter) Close() error { func (r fakeRouter) Close() error {
r.logf("Warning: fakeRouter.Close: not implemented.\n") r.logf("Warning: fakeRouter.Close: not implemented.")
return nil return nil
} }

@ -87,14 +87,14 @@ func NewUserspaceEngine(logf logger.Logf, tunname string, listenPort uint16) (En
tundev, err := tun.CreateTUN(tunname, device.DefaultMTU) tundev, err := tun.CreateTUN(tunname, device.DefaultMTU)
if err != nil { if err != nil {
diagnoseTUNFailure(logf) diagnoseTUNFailure(logf)
logf("CreateTUN: %v\n", err) logf("CreateTUN: %v", err)
return nil, err return nil, err
} }
logf("CreateTUN ok.\n") logf("CreateTUN ok.")
e, err := NewUserspaceEngineAdvanced(logf, tundev, newUserspaceRouter, listenPort) e, err := NewUserspaceEngineAdvanced(logf, tundev, newUserspaceRouter, listenPort)
if err != nil { if err != nil {
logf("NewUserspaceEngineAdv: %v\n", err) logf("NewUserspaceEngineAdv: %v", err)
tundev.Close() tundev.Close()
return nil, err return nil, err
} }
@ -149,7 +149,7 @@ func newUserspaceEngineAdvanced(logf logger.Logf, tundev tun.Device, routerGen R
} }
nofilter := func(b []byte) device.FilterResult { nofilter := func(b []byte) device.FilterResult {
// for safety, default to dropping all packets // for safety, default to dropping all packets
logf("Warning: you forgot to use wgengine.SetFilterInOut()! Packet dropped.\n") logf("Warning: you forgot to use wgengine.SetFilterInOut()! Packet dropped.")
return device.FilterDrop return device.FilterDrop
} }
@ -344,11 +344,11 @@ func (e *userspaceEngine) Reconfig(cfg *wgcfg.Config, dnsDomains []string) error
// will start trying to handshake, which we want to be able to // will start trying to handshake, which we want to be able to
// go over DERP. // go over DERP.
if err := e.magicConn.SetPrivateKey(cfg.PrivateKey); err != nil { if err := e.magicConn.SetPrivateKey(cfg.PrivateKey); err != nil {
e.logf("magicsock: %v\n", err) e.logf("wgengine: Reconfig: SetPrivateKey: %v", err)
} }
if err := e.wgdev.Reconfig(cfg); err != nil { if err := e.wgdev.Reconfig(cfg); err != nil {
e.logf("wgdev.Reconfig: %v\n", err) e.logf("wgdev.Reconfig: %v", err)
return err return err
} }
@ -399,7 +399,7 @@ func (e *userspaceEngine) GetFilter() *filter.Filter {
func (e *userspaceEngine) SetFilter(filt *filter.Filter) { func (e *userspaceEngine) SetFilter(filt *filter.Filter) {
var filtin, filtout func(b []byte) device.FilterResult var filtin, filtout func(b []byte) device.FilterResult
if filt == nil { if filt == nil {
e.logf("wgengine: nil filter provided; no access restrictions.\n") e.logf("wgengine: nil filter provided; no access restrictions.")
} else { } else {
ft, ft_ok := e.tundev.(*fakeTun) ft, ft_ok := e.tundev.(*fakeTun)
filtin = func(b []byte) device.FilterResult { filtin = func(b []byte) device.FilterResult {
@ -508,7 +508,7 @@ func (e *userspaceEngine) getStatus() (*Status, error) {
case "public_key": case "public_key":
pk, err := key.NewPublicFromHexMem(v) pk, err := key.NewPublicFromHexMem(v)
if err != nil { if err != nil {
log.Fatalf("IpcGetOperation: invalid key %#v\n", v) log.Fatalf("IpcGetOperation: invalid key %#v", v)
} }
p = &PeerStatus{} p = &PeerStatus{}
pp[wgcfg.Key(pk)] = p pp[wgcfg.Key(pk)] = p
@ -519,23 +519,23 @@ func (e *userspaceEngine) getStatus() (*Status, error) {
n, err = v.ParseInt(10, 64) n, err = v.ParseInt(10, 64)
p.RxBytes = ByteCount(n) p.RxBytes = ByteCount(n)
if err != nil { if err != nil {
log.Fatalf("IpcGetOperation: rx_bytes invalid: %#v\n", line) log.Fatalf("IpcGetOperation: rx_bytes invalid: %#v", line)
} }
case "tx_bytes": case "tx_bytes":
n, err = v.ParseInt(10, 64) n, err = v.ParseInt(10, 64)
p.TxBytes = ByteCount(n) p.TxBytes = ByteCount(n)
if err != nil { if err != nil {
log.Fatalf("IpcGetOperation: tx_bytes invalid: %#v\n", line) log.Fatalf("IpcGetOperation: tx_bytes invalid: %#v", line)
} }
case "last_handshake_time_sec": case "last_handshake_time_sec":
hst1, err = v.ParseInt(10, 64) hst1, err = v.ParseInt(10, 64)
if err != nil { if err != nil {
log.Fatalf("IpcGetOperation: hst1 invalid: %#v\n", line) log.Fatalf("IpcGetOperation: hst1 invalid: %#v", line)
} }
case "last_handshake_time_nsec": case "last_handshake_time_nsec":
hst2, err = v.ParseInt(10, 64) hst2, err = v.ParseInt(10, 64)
if err != nil { if err != nil {
log.Fatalf("IpcGetOperation: hst2 invalid: %#v\n", line) log.Fatalf("IpcGetOperation: hst2 invalid: %#v", line)
} }
if hst1 != 0 || hst2 != 0 { if hst1 != 0 || hst2 != 0 {
p.LastHandshake = time.Unix(hst1, hst2) p.LastHandshake = time.Unix(hst1, hst2)
@ -562,7 +562,7 @@ func (e *userspaceEngine) getStatus() (*Status, error) {
} }
if len(pp) != len(e.peerSequence) { if len(pp) != len(e.peerSequence) {
e.logf("wg status returned %v peers, expected %v\n", len(pp), len(e.peerSequence)) e.logf("wg status returned %v peers, expected %v", len(pp), len(e.peerSequence))
} }
return &Status{ return &Status{
@ -596,7 +596,7 @@ func (e *userspaceEngine) RequestStatus() {
case <-e.reqCh: case <-e.reqCh:
s, err := e.getStatus() s, err := e.getStatus()
if s == nil && err == nil { if s == nil && err == nil {
e.logf("RequestStatus: weird: both s and err are nil\n") e.logf("RequestStatus: weird: both s and err are nil")
return return
} }
if cb := e.getStatusCallback(); cb != nil { if cb := e.getStatusCallback(); cb != nil {

Loading…
Cancel
Save