Unverified Commit fa3eda52 authored by Minseong Choi's avatar Minseong Choi 💬
Browse files

fix(nano): quote and cap the request log line

felis nano logged every request with the raw RequestURI and %s. That
text is the caller's: a right-to-left override reordered the line as
displayed, an invalid UTF-8 byte made journald store the entry as a
binary blob that journalctl -f shows as "[N blob data]", and a query
near net/http's one-megabyte limit became a one-megabyte log line.

The URI is now capped at 256 bytes, several times a real hasJoined
query, and printed with %q, so control, bidi and invalid bytes appear
escaped. The handler assembly moved into nanoHandler so the logged
handler can be tested on its own; cmdNano serves it unchanged.

The new test sends a query carrying U+202E, a 0x9b byte and 4 KiB of
padding, and expects a valid UTF-8 line with the override escaped and
no more than twice the cap. Restoring the old unquoted line fails it.
parent 1905cac9
Loading
Loading
Loading
Loading
+24 −9
Changes for cmd/felis/nano.go: 24 added lines, 9 removed lines.
Original line number Diff line number Diff line
@@ -43,6 +43,10 @@ type nanoStubRepo struct{ api.Repo }

func (nanoStubRepo) IsUsernameBlacklisted(context.Context, string) (bool, error) { return false, nil }

// nanoLogURIMax is room for a real hasJoined query (a 16-character name, a 41-character
// serverId, an address) several times over.
const nanoLogURIMax = 256

func cmdNano(args []string, stdout, stderr io.Writer) int {
	fs := flag.NewFlagSet("nano", flag.ContinueOnError)
	fs.SetOutput(stderr)
@@ -62,23 +66,34 @@ func cmdNano(args []string, stdout, stderr io.Writer) int {
		return 1
	}

	handler := api.HasJoinedHandler(authSourcesFromConfig(cfg.AuthSources), nanoStubRepo{})
	fmt.Fprintf(stderr, "felis nano: hasJoined multiplexer on %s — Mojang + %d third-party source(s)\n", *listen, len(cfg.AuthSources))
	for i, s := range cfg.AuthSources {
		fmt.Fprintf(stderr, "  [%d] %s -> %s\n", i+1, s.Tag, s.URL)
	}

	// Log each request so a live login attempt is visible while testing against a real
	// Velocity — "is authlib even reaching me?" is the first question during verification.
	logged := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprintf(stderr, "felis nano: %s %s\n", r.Method, r.RequestURI)
		handler.ServeHTTP(w, r)
	})

	srv := newAPIServer(*listen, logged)
	srv := newAPIServer(*listen, nanoHandler(cfg.AuthSources, stderr))
	if err := srv.ListenAndServe(); err != nil {
		fmt.Fprintln(stderr, "felis nano:", err)
		return 1
	}
	return 0
}

// nanoHandler is what felis nano serves: the shared hasJoined handler, Mojang first, behind
// a request log.
func nanoHandler(sources []config.AuthSourceConfig, stderr io.Writer) http.Handler {
	handler := api.HasJoinedHandler(authSourcesFromConfig(sources), nanoStubRepo{})
	// Log each request so a live login attempt is visible while testing against a real
	// Velocity — "is Velocity even reaching me?" is the first question during verification.
	// The URI is the caller's text: quoted so a control or bidi character cannot rewrite the
	// line and invalid UTF-8 cannot turn the journal entry into a blob, and capped so one
	// request cannot write a megabyte of log.
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		uri := r.RequestURI
		if len(uri) > nanoLogURIMax {
			uri = uri[:nanoLogURIMax] + "..."
		}
		fmt.Fprintf(stderr, "felis nano: %s %q\n", r.Method, uri)
		handler.ServeHTTP(w, r)
	})
}

cmd/felis/nano_test.go

0 → 100644
+35 −0
Changes for cmd/felis/nano_test.go: 35 added lines, 0 removed lines.
Original line number Diff line number Diff line
package main

import (
	"bytes"
	"net/http"
	"net/http/httptest"
	"strconv"
	"strings"
	"testing"
	"unicode/utf8"
)

// The request log prints text the caller chose. A bidi override must not reorder the line,
// an invalid byte must not make journald store the entry as a blob, and a huge query must
// not become a huge log line. serverId is left out so the handler answers without asking
// any source.
func TestNanoRequestLogIsQuotedAndCapped(t *testing.T) {
	const rlo = rune(0x202e) // RIGHT-TO-LEFT OVERRIDE
	var log bytes.Buffer
	h := nanoHandler(nil, &log)
	target := "/session/minecraft/hasJoined?username=" + string(rlo) + "evil" + string([]byte{0x9b}) + "31m" + strings.Repeat("a", 4096)
	w := httptest.NewRecorder()
	h.ServeHTTP(w, httptest.NewRequest(http.MethodGet, target, nil))

	line := log.String()
	if strings.ContainsRune(line, rlo) || !utf8.ValidString(line) {
		t.Fatalf("raw caller bytes reached the log: %q", line)
	}
	if escaped := strings.Trim(strconv.QuoteRune(rlo), "'"); !strings.Contains(line, escaped) {
		t.Fatalf("log line %q should show the override escaped as %s", line, escaped)
	}
	if len(line) > 2*nanoLogURIMax {
		t.Fatalf("log line is %d bytes for a %d-byte URI; want it capped", len(line), len(target))
	}
}