ipn/ipnlocal: add verbose Taildrive logging on client side

This allows logging the following Taildrive behavior from the client's perspective
when --verbose=1:

- Initialization of Taildrive remotes for every peer
- Peer availability checks
- All HTTP requests to peers (not just GET and PUT)

Updates tailscale/corp#29702

Signed-off-by: Percy Wegmann <percy@tailscale.com>
This commit is contained in:
Percy Wegmann
2025-06-30 13:43:16 -05:00
committed by Percy Wegmann
parent 47e77565c6
commit 6a9bf9172b
2 changed files with 27 additions and 14 deletions

View File

@@ -306,10 +306,12 @@ func (b *LocalBackend) updateDrivePeersLocked(nm *netmap.NetworkMap) {
}
func (b *LocalBackend) driveRemotesFromPeers(nm *netmap.NetworkMap) []*drive.Remote {
b.logf("[v1] taildrive: setting up drive remotes from peers")
driveRemotes := make([]*drive.Remote, 0, len(nm.Peers))
for _, p := range nm.Peers {
peerID := p.ID()
url := fmt.Sprintf("%s/%s", peerAPIBase(nm, p), taildrivePrefix[1:])
b.logf("[v1] taildrive: appending remote for peer %d: %s", peerID, url)
driveRemotes = append(driveRemotes, &drive.Remote{
Name: p.DisplayName(false),
URL: url,
@@ -320,6 +322,7 @@ func (b *LocalBackend) driveRemotesFromPeers(nm *netmap.NetworkMap) []*drive.Rem
cn := b.currentNode()
peer, ok := cn.NodeByID(peerID)
if !ok {
b.logf("[v1] taildrive: Available(): peer %d not found", peerID)
return false
}
@@ -332,14 +335,17 @@ func (b *LocalBackend) driveRemotesFromPeers(nm *netmap.NetworkMap) []*drive.Rem
// The netmap.Peers slice is not updated in all cases.
// It should be fixed now that we use PeerByIDOk.
if !peer.Online().Get() {
b.logf("[v1] taildrive: Available(): peer %d offline", peerID)
return false
}
// Check that the peer is allowed to share with us.
if cn.PeerHasCap(peer, tailcfg.PeerCapabilityTaildriveSharer) {
b.logf("[v1] taildrive: Available(): peer %d available", peerID)
return true
}
b.logf("[v1] taildrive: Available(): peer %d not allowed to share", peerID)
return false
},
})

View File

@@ -1459,7 +1459,7 @@ func (b *LocalBackend) WhoIs(proto string, ipp netip.AddrPort) (n tailcfg.NodeVi
}
n, ok = cn.NodeByID(nid)
if !ok {
return zero, u, false
return zero, u, false
}
up, ok := cn.UserByID(n.User())
if !ok {
@@ -5960,6 +5960,7 @@ func (b *LocalBackend) setNetMapLocked(nm *netmap.NetworkMap) {
// the number of bytesRead.
type responseBodyWrapper struct {
io.ReadCloser
logVerbose bool
bytesRx int64
bytesTx int64
log logger.Logf
@@ -5981,8 +5982,22 @@ func (rbw *responseBodyWrapper) logAccess(err string) {
// Some operating systems create and copy lots of 0 length hidden files for
// tracking various states. Omit these to keep logs from being too verbose.
if rbw.contentLength > 0 {
rbw.log("taildrive: access: %s from %s to %s: status-code=%d ext=%q content-type=%q content-length=%.f tx=%.f rx=%.f err=%q", rbw.method, rbw.selfNodeKey, rbw.shareNodeKey, rbw.statusCode, rbw.fileExtension, rbw.contentType, roundTraffic(rbw.contentLength), roundTraffic(rbw.bytesTx), roundTraffic(rbw.bytesRx), err)
if rbw.logVerbose || rbw.contentLength > 0 {
levelPrefix := ""
if rbw.logVerbose {
levelPrefix = "[v1] "
}
rbw.log(
"%staildrive: access: %s from %s to %s: status-code=%d ext=%q content-type=%q content-length=%.f tx=%.f rx=%.f err=%q",
levelPrefix,
rbw.method,
rbw.selfNodeKey,
rbw.shareNodeKey,
rbw.statusCode,
rbw.fileExtension,
rbw.contentType,
roundTraffic(rbw.contentLength),
roundTraffic(rbw.bytesTx), roundTraffic(rbw.bytesRx), err)
}
}
@@ -6037,17 +6052,8 @@ func (dt *driveTransport) RoundTrip(req *http.Request) (resp *http.Response, err
defer func() {
contentType := "unknown"
switch req.Method {
case httpm.PUT:
if ct := req.Header.Get("Content-Type"); ct != "" {
contentType = ct
}
case httpm.GET:
if ct := resp.Header.Get("Content-Type"); ct != "" {
contentType = ct
}
default:
return
if ct := req.Header.Get("Content-Type"); ct != "" {
contentType = ct
}
dt.b.mu.Lock()
@@ -6061,6 +6067,7 @@ func (dt *driveTransport) RoundTrip(req *http.Request) (resp *http.Response, err
rbw := responseBodyWrapper{
log: dt.b.logf,
logVerbose: req.Method != httpm.GET && req.Method != httpm.PUT, // other requests like PROPFIND are quite chatty, so we log those at verbose level
method: req.Method,
bytesTx: int64(bw.bytesRead),
selfNodeKey: selfNodeKey,