diff --git a/sshd/sshd.go b/sshd/sshd.go index 59d315d..3508718 100644 --- a/sshd/sshd.go +++ b/sshd/sshd.go @@ -18,6 +18,7 @@ import ( "os" "path/filepath" "sync" + "sync/atomic" "time" "golang.org/x/crypto/ssh" @@ -143,9 +144,14 @@ func (s *Server) Serve(ctx context.Context, ln net.Listener) error { func (s *Server) handle(ctx context.Context, nc net.Conn) { defer nc.Close() nc.SetDeadline(time.Now().Add(handshakeTimeout)) - conn, chans, reqs, err := ssh.NewServerConn(nc, s.conf) + rc := &readCounter{Conn: nc} + conn, chans, reqs, err := ssh.NewServerConn(rc, s.conf) if err != nil { - s.cfg.Logf("ssh: sign-in from %s failed: %v", nc.RemoteAddr(), err) + // A client that connects and never says anything is a port probe or a health check (Hammerhead + // checks every TCP resource this way), not a failed sign-in, so it is not worth a log line each time. + if rc.n.Load() > 0 { + s.cfg.Logf("ssh: sign-in from %s failed: %v", nc.RemoteAddr(), err) + } return } nc.SetDeadline(time.Time{}) @@ -172,6 +178,18 @@ func (s *Server) handle(ctx context.Context, nc net.Conn) { wg.Wait() } +// readCounter counts the bytes a client has sent. +type readCounter struct { + net.Conn + n atomic.Int64 +} + +func (r *readCounter) Read(p []byte) (int, error) { + n, err := r.Conn.Read(p) + r.n.Add(int64(n)) + return n, err +} + type ptyReq struct { term string cols, rows uint32 diff --git a/sshd/sshd_test.go b/sshd/sshd_test.go index cca3aca..77758d9 100644 --- a/sshd/sshd_test.go +++ b/sshd/sshd_test.go @@ -4,9 +4,12 @@ import ( "context" "crypto/ed25519" "crypto/rand" + "fmt" "net" "os" "path/filepath" + "strings" + "sync" "testing" "time" @@ -148,3 +151,50 @@ func TestNoForwarding(t *testing.T) { t.Fatal("port forwarding was allowed") } } + +// Hammerhead health-checks a TCP resource by connecting and hanging up; that must not look like +// a failed sign-in in the log, while a real failure still does. +func TestProbesAreNotLogged(t *testing.T) { + good := newSigner(t) + dir := t.TempDir() + keys := filepath.Join(dir, "authorized_keys") + if err := os.WriteFile(keys, []byte(authLine(good)), 0o600); err != nil { + t.Fatal(err) + } + var mu sync.Mutex + var logs []string + srv, err := New(Config{AuthorizedKeys: keys, HostKey: filepath.Join(dir, "host_key"), Logf: func(f string, a ...any) { + mu.Lock() + logs = append(logs, fmt.Sprintf(f, a...)) + mu.Unlock() + }}) + if err != nil { + t.Fatal(err) + } + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + ctx, cancel := context.WithCancel(context.Background()) + done := make(chan struct{}) + go func() { srv.Serve(ctx, ln); close(done) }() + t.Cleanup(func() { cancel(); <-done }) + + for i := 0; i < 3; i++ { + c, err := net.Dial("tcp", ln.Addr().String()) + if err != nil { + t.Fatal(err) + } + c.Close() + } + time.Sleep(200 * time.Millisecond) + if _, err := dial(ln.Addr().String(), ssh.PublicKeys(newSigner(t))); err == nil { + t.Fatal("an unknown key signed in") + } + time.Sleep(200 * time.Millisecond) + mu.Lock() + defer mu.Unlock() + if len(logs) != 1 || !strings.Contains(logs[0], "failed") { + t.Fatalf("want exactly the one real failure logged, got %q", logs) + } +}