derp: add a debug option to verbosely log drops to a destination.
"fmt"
"io"
"io/ioutil"
+ "log"
"math/big"
"os"
"runtime"
"sync"
"time"
+ "go4.org/mem"
"golang.org/x/crypto/nacl/box"
"golang.org/x/sync/errgroup"
"tailscale.com/disco"
var debug, _ = strconv.ParseBool(os.Getenv("DERP_DEBUG_LOGS"))
+// verboseDropKeys is the set of destination public keys that should
+// verbosely log whenever DERP drops a packet.
+var verboseDropKeys = map[key.Public]bool{}
+
+func init() {
+ keys := os.Getenv("TS_DEBUG_VERBOSE_DROPS")
+ if keys == "" {
+ return
+ }
+ for _, keyStr := range strings.Split(keys, ",") {
+ k, err := key.NewPublicFromHexMem(mem.S(keyStr))
+ if err != nil {
+ log.Printf("ignoring invalid debug key %q: %v", keyStr, err)
+ } else {
+ verboseDropKeys[k] = true
+ }
+ }
+}
+
const (
perClientSendQueueDepth = 32 // packets buffered for sending
writeTimeout = 2 * time.Second
@@ -58,9 +79,9 @@ type Server struct {
logf logger.Logf
memSys0 uint64 // runtime.MemStats.Sys at start (or early-ish)
meshKey string
+ limitedLogf logger.Logf
// Counters:
- _ [pad32bit]byte
packetsSent, bytesSent expvar.Int
packetsRecv, bytesRecv expvar.Int
packetsRecvByKind metrics.LabelMap
@@ -141,6 +162,7 @@ func NewServer(privateKey key.Private, logf logger.Logf) *Server {
privateKey: privateKey,
publicKey: privateKey.Public(),
logf: logf,
+ limitedLogf: logger.RateLimitedFn(logf, 30*time.Second, 5, 100),
packetsRecvByKind: metrics.LabelMap{Label: "kind"},
packetsDroppedReason: metrics.LabelMap{Label: "reason"},
clients: map[key.Public]*sclient{},
@@ -624,6 +646,12 @@ func (c *sclient) sendPkt(dst *sclient, p pkt) error {
case <-dst.sendQueue:
s.packetsDropped.Add(1)
s.packetsDroppedQueueHead.Add(1)
+ if verboseDropKeys[dstKey] {
+ // Generate a full string including src and dst, so
+ // the limiter kicks in once per src.
+ msg := fmt.Sprintf("tail drop %s -> %s", p.src.ShortString(), dstKey.ShortString())
+ c.s.limitedLogf(msg)
+ }
if debug {
c.logf("dropping packet from client %x queue head", dstKey)
}
@@ -635,6 +663,12 @@ func (c *sclient) sendPkt(dst *sclient, p pkt) error {
// this case to keep reader unblocked.
s.packetsDropped.Add(1)
s.packetsDroppedQueueTail.Add(1)
+ if verboseDropKeys[dstKey] {
+ // Generate a full string including src and dst, so
+ // the limiter kicks in once per src.
+ msg := fmt.Sprintf("head drop %s -> %s", p.src.ShortString(), dstKey.ShortString())
+ c.s.limitedLogf(msg)
+ }
if debug {
c.logf("dropping packet from client %x queue tail", dstKey)
}
