No one really cares. Its cost outweighs its usefulness.
name old time/op new time/op delta
HandleBootstrapDNS-10 105ns ± 4% 65ns ± 2% -37.68% (p=0.000 n=15+14)
name old alloc/op new alloc/op delta
HandleBootstrapDNS-10 416B ± 0% 0B -100.00% (p=0.000 n=15+15)
name old allocs/op new allocs/op delta
HandleBootstrapDNS-10 3.00 ± 0% 0.00 -100.00% (p=0.000 n=15+15)
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Do json formatting once, rather than on every request.
Use an atomic.Value.
name old time/op new time/op delta
HandleBootstrapDNS-10 6.35µs ± 0% 0.10µs ± 4% -98.35% (p=0.000 n=14+15)
name old alloc/op new alloc/op delta
HandleBootstrapDNS-10 3.20kB ± 0% 0.42kB ± 0% -86.99% (p=0.000 n=12+15)
name old allocs/op new allocs/op delta
HandleBootstrapDNS-10 41.0 ± 0% 3.0 ± 0% -92.68% (p=0.000 n=15+15)
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This fixes a deadlock on shutdown.
One goroutine is waiting to send on c.derpRecvCh before unlocking c.mu.
The other goroutine is waiting to lock c.mu before receiving from c.derpRecvCh.
#3736 has a more detailed explanation of the sequence of events.
Fixes#3736
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This test set the bar too high.
Just a couple of missed timers was enough to fail.
Change the test to more of a sanity check.
While we're here, run it for just 1s instead of 5s.
Prior to this change, on a 13" M1 MPB, with
stress -p 512 ./rate.test -test.run=QPS
I saw 90%+ failures.
After this change, I'm at 30k runs with no failures yet.
Fixes#3733
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This started as an attempt to placate GitHub's code scanner,
but it's also probably generally a good idea.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The GitHub code scanner flagged this as a security vulnerability.
I don't believe it was, but I couldn't convince myself of it 100%.
Err on the safe side and use html/template to generate the HTML,
with all necessary escaping.
Fixestailscale/corp#2698
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The rest of our workflows use v2.1.4.
For reasons I do not understand, we must set GOPATH here.
Maybe the GitHub Action builds come with GOPATH already set?
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Make shrinkDefaultRoute a pure function.
Instead of calling interfaceRoutes, accept that information as parameters.
Hard-code those parameters in TestShrinkDefaultRoute.
Fixes#3580
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
testNodes have a reference to a testing.TB via their env.
Use it instead of making the caller pass theirs.
We did this in some methods but not others; finish the job.
This simplifies the call sites.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
magicsock was hanging onto its netmap on logout,
which caused tailscale status to display partial
information about a bunch of zombie peers.
After logout, there should be no peers.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
If you're using -verbose-tailscaled, you're doing in-the-weeds debugging,
so you probably want the verbose output.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The existing code relied on the Go build cache to avoid
needless work when obtaining the tailscale binaries.
For non-obvious reasons, the binaries were getting re-linked
every time, which added 600ms or so on my machine to every test.
Instead, build the binaries exactly once, on demand.
This reduces the time to run 'go test -count=5' from 34s to 10s
on my machine.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
fee2d9fad added support for cmd/tailscale to connect to IPNExtension.
It came in two parts: If no socket was provided, dial IPNExtension first,
and also, if dialing the socket failed, fall back to IPNExtension.
The second half of that support caused the integration tests to fail
when run on a machine that was also running IPNExtension.
The integration tests want to wait until the tailscaled instances
that they spun up are listening. They do that by dialing the new
instance. But when that dial failed, it was falling back to IPNExtension,
so it appeared (incorrectly) that tailscaled was running.
Hilarity predictably ensued.
If a user (or a test) explicitly provides a socket to dial,
it is a reasonable assumption that they have a specific tailscaled
in mind and don't want to fall back to IPNExtension.
It is certainly true of the integration tests.
Instead of adding a bool to Connect, split out the notion of a
connection strategy. For now, the implementation remains the same,
but with the details hidden a bit. Later, we can improve that.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Before:
failed to connect to local tailscaled (which appears to be running). Got error: Get "http://local-tailscaled.sock/localapi/v0/status": EOF
After:
failed to connect to local tailscaled (which appears to be running as IPNExtension, pid 2118). Got error: Get "http://local-tailscaled.sock/localapi/v0/status": EOF
This was useful just now, as it made it clear that tailscaled I thought
I was connecting to might not in fact be running; there was
a second tailscaled running that made the error message slightly misleading.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
We often need both a log function and a context.
We can do this by adding the log function as a context value.
This commit adds helper glue to make that easy.
It is designed to allow incremental adoption.
Updates tailscale/corp#3138
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The block-write and block-read tests are both flaky,
because each assumes it can get a normal read/write
completed within 10ms. This isn’t always true.
We can’t increase the timeouts, because that slows down the test.
However, we don’t need to issue a regular read/write for this test.
The immediately preceding tests already test this code,
using a far more generous timeout.
Remove the extraneous read/write.
This drops the failure rate from 1 per 20,000 to undetectable
on my machine.
While we’re here, fix a typo in a debug print statement.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Without the continue, we might overwrite our current meta
with a zero meta.
Log the error, so that we can check for anything unexpected.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Currently, comments in resolv.conf cause our parser to fail,
with error messages like:
ParseIP("192.168.0.100 # comment"): unexpected character (at " # comment")
Fix that.
Noticed while looking through logs.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
We were missing an argument here.
Also, switch to %q, in case anything weird
is happening with these strings.
Updates tailscale/corp#461
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
When this happens, it is incredibly noisy in the logs.
It accounts for about a third of all remaining
"unexpected" log lines from a recent investigation.
It's not clear that we know how to fix this,
we have a functioning workaround,
and we now have a (cheap and efficient) metric for this
that we can use for measurements.
So reduce the logging to approximately once per minute.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This limits the output to a single IP address.
RELNOTE=tailscale ip now has a -1 flag (TODO: update docs to use it)
Fixes#1921
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
One of the most common "unexpected" log lines is:
"network state changed, but stringification didn't"
One way that this can occur is if an interesting interface
(non-Tailscale, has interesting IP address)
gains or loses an uninteresting IP address (link local or loopback).
The fact that the interface is interesting is enough for EqualFiltered
to inspect it. The fact that an IP address changed is enough for
EqualFiltered to declare that the interfaces are not equal.
But the State.String method reasonably declines to print any
uninteresting IP addresses. As a result, the network state appears
to have changed, but the stringification did not.
The String method is correct; nothing interesting happened.
This change fixes this by adding an IP address filter to EqualFiltered
in addition to the interface filter. This lets the network monitor
ignore the addition/removal of uninteresting IP addresses.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Linux-only for now, to avoid having to figure out why
powershell doesn't like my shell scripting. (Not that I blame it.)
That'll be enough to catch most regressions.
Fixes#1083
Co-authored-by: Aaron Klotz <aaron@tailscale.com>
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The Windows BOOL type is an int32. We were using a bool,
which is a one byte wide. This could be responsible for the
ERROR_INVALID_PARAMETER errors we were seeing for calls to
WinHttpGetProxyForUrl.
We manually checked all other existing Windows syscalls
for similar mistakes and did not find any.
Updates #879
Co-authored-by: Aaron Klotz <aaron@tailscale.com>
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
There are lots of lines in the logs of the form:
portmapper: unexpected PMP probe response: {OpCode:128 ResultCode:3
SecondsSinceEpoch:NNN MappingValidSeconds:0 InternalPort:0
ExternalPort:0 PublicAddr:0.0.0.0}
ResultCode 3 here means a network failure, e.g. the NAT box itself has
not obtained a DHCP lease. This is not an indication that something
is wrong in the Tailscale client, so use different wording here
to reflect that. Keep logging, so that we can analyze and debug
the reasons that PMP probes fail.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
In rare circumstances (tailscale/corp#3016), the PublicKey
and Endpoints can diverge.
This by itself doesn't cause any harm, but our early exit
in response did, because it prevented us from recovering from it.
Remove the early exit.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
endpoint.discoKey is protected by endpoint.mu.
endpoint.sendDiscoMessage was reading it without holding the lock.
This showed up in a CI failure and is readily reproducible locally.
The fix is in two parts.
First, for Conn.enqueueCallMeMaybe, eliminate the one-line helper method endpoint.sendDiscoMessage; call Conn.sendDiscoMessage directly.
This makes it more natural to read endpoint.discoKey in a context
in which endpoint.mu is already held.
Second, for endpoint.sendDiscoPing, explicitly pass the disco key
as an argument. Again, this makes it easier to read endpoint.discoKey
in a context in which endpoint.mu is already held.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
I believe that this should eliminate the flakiness.
If GitHub CI manages to be even slower that can be believed
(and I can believe a lot at this point),
then we should roll this back and make some more invasive changes.
Updates #654Fixes#3247 (I hope)
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
We can do the "maybe delete" check unilaterally:
In the case of an insert, both oldDiscoKey
and ep.discoKey will be the zero value.
And since we don't use pi again, we can skip
giving it a name, which makes scoping clearer.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
In DeviceConfig, we did not close r after calling FromUAPI.
If FromUAPI returned early due to an error, then it might
not have read all the data that IpcGetOperation wanted to write.
As a result, IpcGetOperation could hang, as in #3220.
We were also closing the wrong end of the pipe after IpcSetOperation
in ReconfigDevice.
To ensure that we get all available information to diagnose
such a situation, include all errors anytime something goes wrong.
This should fix the immediate crashing problem in #3220.
We'll then need to figure out why IpcGetOperation was failing.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
github.com/go-multierror/multierror served us well.
But we need a few feature from it (implement Is),
and it's not worth maintaining a fork of such a small module.
Instead, I did a clean room implementation inspired by its API.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
There are a few remaining uses of testing.AllocsPerRun:
Two in which we only log the number of allocations,
and one in which dynamically calculate the allocations
target based on a different AllocsPerRun run.
This also allows us to tighten the "no allocs"
test in wgengine/filter.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
testing.AllocsPerRun measures the total allocations performed
by the entire program while repeatedly executing a function f.
If some unrelated part of the rest of the program happens to
allocate a lot during that period, you end up with a test failure.
Ideally, the rest of the program would be silent while
testing.AllocsPerRun executes.
Realistically, that is often unachievable.
AllocsPerRun attempts to mitigate this by setting GOMAXPROCS to 1,
but that doesn't prevent other code from running;
it only makes it less likely.
You can also mitigate this by passing a large iteration count to
AllocsPerRun, but that is unreliable and needlessly expensive.
Unlike most of package testing, AllocsPerRun doesn't use any
toolchain magic, so we can just write a replacement.
One wild idea is to change how we count mallocs.
Instead of using runtime.MemStats, turn on memory profiling with a
memprofilerate of 1. Discard all samples from the profile whose stack
does not contain testing.AllocsPerRun. Count the remaining samples to
determine the number of mallocs.
That's fun, but overkill.
Instead, this change adds a simple API that attempts to get f to
run at least once with a target number of allocations.
This is useful when you know that f should allocate consistently.
We can then assume that any iterations with too many allocations
are probably due to one-time costs or background noise.
This suits most uses of AllocsPerRun.
Ratcheting tests tend to be significantly less flaky,
because they are biased towards success.
They can also be faster, because they can exit early,
once success has been reached.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The fully qualified name of the type is thisPkg.tname,
so write the args like that too.
Suggested-by: Joe Tsai <joetsai@digital-static.net>
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
And in the process, fix a bug:
The fmt formatting was being applied by writef,
not fmt.Sprintf, thus emitting a MISSING string.
And there's no guarantee that fmt will be imported
in the generated code.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Change from a single-case type switch to a type assertion
with an early return.
That exposes that the name arg to gen is unneeded.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This is a package for shared utilities used in doing codegen programs.
The inaugural API is for writing gofmt'd code to a file.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
LocalBackend.Shutdown's docs say:
> The backend can no longer be used after Shutdown returns.
Nevertheless, TestStateMachine blithely calls Shutdown, talks some smack,
and continues on, expecting things to work. Other uses of Shutdown
in the codebase are as intended.
Things mostly kinda work anyway, except that the wgengine.Engine has been
shut down, so calls to Reconfig fail. Those get logged:
> local.go:603: wgengine status error: engine closing; no status
but otherwise ignored.
However, the Reconfig failure caused one fewer call to pause/unpause
than normal. Now the assertCalls lines match the equivalent ones
earlier in the test.
I don't see an obvious correct replacement for Shutdown in the context
of this test; I'm not sure entirely what it is trying to accomplish.
It is possible that many of the tests remaining after the prior call
to Shutdown are now extraneous. They don't harm anything, though,
so err on the side of safety and leave them for now.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Use helpers and variadic functions to make the call sites
a lot easier to read, since they occur a lot.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Concurrent calls to LocalBackend.setWgengineStatus
could result in some of the status updates being dropped.
This was exacerbated by 92077ae78c,
which increases the probability of concurrent status updates,
causing test failures (tailscale/corp#2579).
It's going to take a bit of work to fix this test.
The ipnlocal state machine is difficult to reason about,
particularly in the face of concurrency.
We could fix the test trivially by throwing a new mutex around
setWgengineStatus to serialize calls to it,
but I'd like to at least try to do better than cosmetics.
In the meantime, commit the test.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
We don't want to force ourselves to update the DERP list
every time we want to cut a new release.
Having an outdated DERP list on release branches is OK.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Spelling out the command to run for every type
means that changing the command makes for a large, repetitive diff.
Stop doing that.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
These "weird" port lines show up in logs frequently.
They're the result of uninteresting races,
and they're not actionable. Remove the noise.
Remove the isLoopbackAddr case to placate staticcheck.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
On about 1 out of 500 runs, TestSendFreeze failed:
derp_test.go:416: bob: unexpected message type derp.PeerGoneMessage
Closing alice before bob created a race.
If bob closed promptly, the test passed.
If bob closed slowly, and alice's disappearance caused
bob to receive a PeerGoneMessage before closing, the test failed.
Deflake the test by closing bob first.
With this fix, the test passed 12,000 times locally.
Fixes#2668
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This is useful for manual performance testing
of networks with many nodes.
I imagine it'll grow more knobs over time.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The number of peers we have will be pretty stable across time.
Allocate roughly the right slice size.
This reduces memory usage when there are many peers.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Two optimizations.
Use values instead of pointers.
We were using pointers to make track the "peer in progress" easier.
It's not too hard to do it manually, though.
Make two passes through the data, so that we can size our
return value accurately from the beginning.
This is cheap enough compared to the allocation,
which grows linearly in the number of peers,
that it is worth doing.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The netmaps can get really large.
Printing, processing, and uploading them is expensive.
Only print the header on an ongoing basis.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The number of packet filters can grow very large,
so this log entry can be very large.
We can get the packet filter server-side,
so reduce verbosity here to just the number of filters present.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
The code goes to some effort to send a single JSON object
when there's only a single line and a JSON array when there
are multiple lines.
It makes the code more complex and more expensive;
when we add a second line, we have to use a second buffer
to duplicate the first one after adding a leading square brackets.
The savings come to two bytes. Instead, always send an array.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Scanning log lines is a frequent source of allocations.
Pre-allocate a re-usable buffer.
This still doesn't help when there are giant log lines.
Those will still be problematic from an iOS memory perspective.
For more on that, see https://github.com/tailscale/corp/issues/2423.
(For those who cannot follow that link, it is a discussion
of particular problematic types of log lines for
particular categories of customers. The "categories of customers"
part is the reason that it is a private issue.)
There is also a latent bug here. If we ever encounter
a log line longer than bufio.MaxScanTokenSize,
then bufio.Scan will return an error,
and we'll truncate the file and discard the rest of the log.
That's not good, but bufio.MaxScanTokenSize is really big,
so it probably doesn't matter much in practice now.
Unfortunately, it does prevent us from easily capping the potential
memory usage here, on pain of losing log entries.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
Prior to Go 1.16, iOS used GOOS=darwin,
so we had to distinguish macOS from iOS during GOARCH.
We now require Go 1.16 in our go.mod, so we can simplify.
Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
