Files
orca/internal/cli/logs_test.go
T
Jon Chery c8cf2e41e5 feat(P06): alloc history (REQ-071) + logs --all-nodes (REQ-117)
internal/store/alloc_history.go: AllocHistoryRepo (Record/List/Evict)
in orca_cache.db with 7-day TTL eviction goroutine. internal/cli/logs.go:
orca logs --all-nodes --since 5m with iter.Seq streaming, SSH fanout,
journalctl JSON parsing, signal.NotifyContext cancellation, --json output.

---ci---
project: orca
phase: 06
milestone: v0.11
status: execute
---/ci---
2026-08-07 05:36:30 +00:00

360 lines
9.7 KiB
Go

package cli
import (
"bytes"
"context"
"strconv"
"strings"
"sync"
"testing"
"time"
"git.cloudinit.dev/coreci/orca/internal/certpaths"
"git.cloudinit.dev/coreci/orca/internal/model"
"git.cloudinit.dev/coreci/orca/internal/store"
)
// mockLogsExec is a record-and-replay execer for `orca logs` tests
// (same pattern as internal/stepca mockExec / drain_test mockDrainExec).
// It matches each incoming command against a list of (substring,
// output) responses; the first match wins. An entry with an empty
// substring matches any command.
type mockLogsExec struct {
mu sync.Mutex
responses []logsMockResp
calls []logsMockCall
}
type logsMockResp struct {
match string
peer string // if set, must match the peer too
out string
}
type logsMockCall struct {
peer string
cmd string
}
func (m *mockLogsExec) Exec(_ context.Context, peer, cmd string) ([]byte, error) {
m.mu.Lock()
defer m.mu.Unlock()
m.calls = append(m.calls, logsMockCall{peer: peer, cmd: cmd})
for _, r := range m.responses {
if r.peer != "" && !strings.Contains(peer, r.peer) {
continue
}
if r.match == "" || strings.Contains(cmd, r.match) {
return []byte(r.out), nil
}
}
return nil, nil
}
func (m *mockLogsExec) countCalls(match string) int {
m.mu.Lock()
defer m.mu.Unlock()
n := 0
for _, c := range m.calls {
if strings.Contains(c.cmd, match) {
n++
}
}
return n
}
// logsTestEnv wires a mockLogsExec into logsExecOverride and returns
// the mock + a cleanup func. Tests MUST defer the cleanup.
func logsTestEnv(t *testing.T) *mockLogsExec {
t.Helper()
prev := logsExecOverride
mx := &mockLogsExec{}
logsExecOverride = mx
t.Cleanup(func() { logsExecOverride = prev })
return mx
}
// logsNodeForTest inserts a node with a fixed name and returns it so
// logs commands can target it by name. Uses the test ORCA_HOME db.
func logsNodeForTest(t *testing.T, name, addr string) *model.Node {
t.Helper()
db, err := store.Open(certpaths.DBPath())
if err != nil {
t.Fatalf("open db: %v", err)
}
defer db.Close()
n := &model.Node{
ID: "node-" + name,
Name: name,
Address: addr,
State: model.NodeStateReady,
JoinedAt: time.Now().UTC(),
LastSeen: time.Now().UTC(),
Kind: string(model.NodeKindLinux),
}
if err := store.NewNodeRepo(db).Insert(context.Background(), n); err != nil {
t.Fatalf("insert node: %v", err)
}
return n
}
// journalJSONLine renders a single journalctl --output json line.
func journalJSONLine(ts time.Time, unit, msg, prio string) string {
return `{"__REALTIME_TIMESTAMP":` + strconv.FormatInt(ts.UnixNano(), 10) +
`,"_SYSTEMD_UNIT":"` + unit + `.service","MESSAGE":"` + msg + `","PRIORITY":"` + prio + `"}`
}
// runLogsCmd executes logsCmd with the given args against a buffered
// stdout, returning the captured output and any error.
func runLogsCmd(t *testing.T, args []string) (string, error) {
t.Helper()
resetRootFlags(t)
var buf bytes.Buffer
rootCmd.SetOut(&buf)
rootCmd.SetErr(&buf)
rootCmd.SetArgs(args)
err := rootCmd.Execute()
return buf.String(), err
}
func TestLogsCommandRegistered(t *testing.T) {
found := false
for _, cmd := range rootCmd.Commands() {
if cmd.Name() == "logs" {
found = true
break
}
}
if !found {
t.Fatal("logs command not registered on rootCmd")
}
}
func TestLogsRequiresAllNodesOrNode(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
resetRootFlags(t)
_, err := runLogsCmd(t, []string{"logs"})
if err == nil {
t.Fatal("expected error when neither --all-nodes nor --node is set")
}
if !strings.Contains(err.Error(), "--all-nodes") && !strings.Contains(err.Error(), "--node") {
t.Errorf("error = %q, want mention of --all-nodes/--node", err)
}
}
func TestLogsAllNodesAndNodeMutuallyExclusive(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
resetRootFlags(t)
_, err := runLogsCmd(t, []string{"logs", "--all-nodes", "--node", "x"})
if err == nil {
t.Fatal("expected error for --all-nodes + --node together")
}
}
func TestLogsSinceParsing(t *testing.T) {
cases := []struct {
in string
wantErr bool
}{
{"5m", false},
{"1h30m", false},
{"500ms", false},
{"", false}, // defaults to 5m
{"notaduration", true},
{"-5m", true},
{"0s", true},
}
for _, c := range cases {
_, err := parseSince(c.in)
if c.wantErr && err == nil {
t.Errorf("parseSince(%q): expected error, got nil", c.in)
}
if !c.wantErr && err != nil {
t.Errorf("parseSince(%q): unexpected error: %v", c.in, err)
}
}
}
func TestLogsSinceDefaultIs5m(t *testing.T) {
before := time.Now().UTC()
got, err := parseSince("")
if err != nil {
t.Fatalf("parseSince(empty): %v", err)
}
after := time.Now().UTC()
// got should be ~5m ago. The call's "now" is in [before, after],
// so got = now-5m is in [before-5m, after-5m].
lo := before.Add(-5 * time.Minute)
hi := after.Add(-5 * time.Minute)
if got.Before(lo) || got.After(hi) {
t.Errorf("parseSince(empty) = %v, want ~5m ago (between %v and %v)", got, lo, hi)
}
}
func TestLogsAllNodes_FansOutAndStreams(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
logsNodeForTest(t, "web-1", "web-1:8443")
logsNodeForTest(t, "web-2", "web-2:8443")
mx := logsTestEnv(t)
ts := time.Date(2026, 1, 1, 12, 0, 0, 0, time.UTC)
// Two nodes, each returns one journal line.
mx.responses = []logsMockResp{
{peer: "web-1", match: "journalctl", out: journalJSONLine(ts, "orca-alloc-web-0", "hello from web-1", "6") + "\n"},
{peer: "web-2", match: "journalctl", out: journalJSONLine(ts, "orca-alloc-web-0", "hello from web-2", "6") + "\n"},
}
out, err := runLogsCmd(t, []string{"logs", "--all-nodes", "--since", "5m"})
if err != nil {
t.Fatalf("logs: %v", err)
}
if mx.countCalls("journalctl") != 2 {
t.Errorf("expected 2 journalctl calls, got %d", mx.countCalls("journalctl"))
}
if !strings.Contains(out, "hello from web-1") {
t.Errorf("output missing web-1 line:\n%s", out)
}
if !strings.Contains(out, "hello from web-2") {
t.Errorf("output missing web-2 line:\n%s", out)
}
if !strings.Contains(out, "[web-1]") || !strings.Contains(out, "[web-2]") {
t.Errorf("output missing [host] prefix for multi-node:\n%s", out)
}
}
func TestLogsSingleNode_NoHostPrefix(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
logsNodeForTest(t, "solo", "solo:8443")
mx := logsTestEnv(t)
ts := time.Date(2026, 1, 1, 12, 0, 0, 0, time.UTC)
mx.responses = []logsMockResp{
{match: "journalctl", out: journalJSONLine(ts, "orca-alloc-web-0", "single node msg", "6") + "\n"},
}
out, err := runLogsCmd(t, []string{"logs", "--node", "solo", "--since", "1h"})
if err != nil {
t.Fatalf("logs: %v", err)
}
if !strings.Contains(out, "single node msg") {
t.Errorf("output missing message:\n%s", out)
}
if strings.Contains(out, "[solo]") {
t.Errorf("single-node output should NOT have [host] prefix:\n%s", out)
}
if mx.countCalls("journalctl") != 1 {
t.Errorf("expected 1 journalctl call, got %d", mx.countCalls("journalctl"))
}
}
func TestLogsJSONOutput(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
logsNodeForTest(t, "jsonnode", "jsonnode:8443")
mx := logsTestEnv(t)
ts := time.Date(2026, 1, 1, 12, 0, 0, 0, time.UTC)
mx.responses = []logsMockResp{
{match: "journalctl", out: journalJSONLine(ts, "orca-alloc-web-0", "json line", "6") + "\n"},
}
out, err := runLogsCmd(t, []string{"logs", "--node", "jsonnode", "--since", "1m", "--json"})
if err != nil {
t.Fatalf("logs: %v", err)
}
if !strings.Contains(out, `"message":"json line"`) {
t.Errorf("json output missing message field:\n%s", out)
}
if !strings.Contains(out, `"host":"jsonnode"`) {
t.Errorf("json output missing host field:\n%s", out)
}
}
func TestLogsJobFilterAffectsUnitPattern(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
logsNodeForTest(t, "jobnode", "jobnode:8443")
mx := logsTestEnv(t)
mx.responses = []logsMockResp{
{match: "orca-alloc-web-*", out: ""},
}
_, err := runLogsCmd(t, []string{"logs", "--node", "jobnode", "--job", "web", "--since", "1m"})
if err != nil {
t.Fatalf("logs: %v", err)
}
if mx.countCalls("orca-alloc-web-*") != 1 {
t.Errorf("expected unit pattern orca-alloc-web-* in cmd, calls=%v", mx.calls)
}
if mx.countCalls("orca-alloc-*") != 1 {
// The job-specific pattern is a subset of the bare pattern;
// substring match counts both. Ensure the job pattern was used.
}
}
func TestLogsCancelStopsStream(t *testing.T) {
_, cleanup := initTestEnv(t)
defer cleanup()
logsNodeForTest(t, "cancelnode", "cancelnode:8443")
mx := logsTestEnv(t)
mx.responses = []logsMockResp{
{match: "journalctl", out: journalJSONLine(time.Now().UTC(), "orca-alloc-x", "msg", "6") + "\n"},
}
ctx, cancel := context.WithCancel(context.Background())
cancel() // already-cancelled context: streamLogs should return immediately
ex, err := logsExecFromCtx(ctx)
if err != nil {
t.Fatalf("exec: %v", err)
}
nodes := []*model.Node{
{ID: "n1", Name: "cancelnode", Address: "cancelnode:8443"},
}
consumed := 0
for range streamLogs(ctx, ex, nodes, time.Now().UTC().Add(-1*time.Minute), "") {
consumed++
}
if consumed > 1 {
t.Errorf("cancelled stream yielded %d lines, want <= 1", consumed)
}
}
func TestLogsParseJournalLine(t *testing.T) {
ts := time.Date(2026, 1, 1, 12, 0, 0, 123456789, time.UTC)
raw := journalJSONLine(ts, "orca-alloc-web-0", "hello world", "6")
ll, err := parseJournalLine(raw)
if err != nil {
t.Fatalf("parseJournalLine: %v", err)
}
if ll.Message != "hello world" {
t.Errorf("message = %q, want hello world", ll.Message)
}
if ll.Unit != "orca-alloc-web-0" {
t.Errorf("unit = %q, want orca-alloc-web-0", ll.Unit)
}
if ll.Priority != "6" {
t.Errorf("priority = %q, want 6", ll.Priority)
}
}
func TestLogsParseJournalLine_InvalidJSON(t *testing.T) {
_, err := parseJournalLine("not json")
if err == nil {
t.Error("expected error for invalid json, got nil")
}
}