531b36924c
- job stop: real systemctl stop via SSH (was DB-only soft stop) resolves node from alloc_history or --peer flag - doctor db-retention: row count check for jobs/tasks/audit_log warns at 100k rows, suggests backup + cleanup - logs --lines: cap at 50000 (default 1000); --since upper bound 7d prevents OOM from unbounded journalctl - cache DB mode 0600 (was 0644; matches store.Open) - upgrade cutover: backup file + atomic rename (was sed -i) rollback restores from backup on failure Tests: job stop SSH, DB retention warning, logs lines cap, cache mode, cutover backup-restore + atomic rename. ---ci--- project: orca phase: 9 milestone: v0.13 status: complete requirements: covered: [158] ---/ci---
515 lines
14 KiB
Go
515 lines
14 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
|
|
}
|
|
|
|
func (m *mockLogsExec) callsFor(match string) []logsMockCall {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
var out []logsMockCall
|
|
for _, c := range m.calls {
|
|
if strings.Contains(c.cmd, match) {
|
|
out = append(out, c)
|
|
}
|
|
}
|
|
return out
|
|
}
|
|
|
|
// 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), "", 1000) {
|
|
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")
|
|
}
|
|
}
|
|
|
|
|
|
// TestLogsLinesFlag verifies that --lines is passed through to the
|
|
// journalctl command as --lines=N (REQ-158, P09 T8).
|
|
func TestLogsLinesFlag(t *testing.T) {
|
|
_, cleanup := initTestEnv(t)
|
|
defer cleanup()
|
|
|
|
logsNodeForTest(t, "linesnode", "linesnode: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", "line test", "6") + "\n"},
|
|
}
|
|
|
|
_, err := runLogsCmd(t, []string{"logs", "--node", "linesnode", "--since", "1m", "--lines", "500"})
|
|
if err != nil {
|
|
t.Fatalf("logs: %v", err)
|
|
}
|
|
calls := mx.callsFor("journalctl")
|
|
if len(calls) == 0 {
|
|
t.Fatal("expected journalctl call")
|
|
}
|
|
if !strings.Contains(calls[0].cmd, "--lines 500") {
|
|
t.Errorf("expected '--lines 500' in cmd, got: %s", calls[0].cmd)
|
|
}
|
|
}
|
|
|
|
// TestLogsLinesDefault verifies that the default --lines value (1000)
|
|
// is passed to journalctl when --lines is not specified (REQ-158).
|
|
func TestLogsLinesDefault(t *testing.T) {
|
|
_, cleanup := initTestEnv(t)
|
|
defer cleanup()
|
|
|
|
logsNodeForTest(t, "defnode", "defnode: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", "default lines", "6") + "\n"},
|
|
}
|
|
|
|
_, err := runLogsCmd(t, []string{"logs", "--node", "defnode", "--since", "1m"})
|
|
if err != nil {
|
|
t.Fatalf("logs: %v", err)
|
|
}
|
|
calls := mx.callsFor("journalctl")
|
|
if len(calls) == 0 {
|
|
t.Fatal("expected journalctl call")
|
|
}
|
|
if !strings.Contains(calls[0].cmd, "--lines 1000") {
|
|
t.Errorf("expected default '--lines 1000' in cmd, got: %s", calls[0].cmd)
|
|
}
|
|
}
|
|
|
|
// TestLogsLinesClamp verifies that --lines exceeding the max (50000) is
|
|
// clamped (REQ-158, P09 T8).
|
|
func TestLogsLinesClamp(t *testing.T) {
|
|
_, cleanup := initTestEnv(t)
|
|
defer cleanup()
|
|
|
|
logsNodeForTest(t, "clampnode", "clampnode: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", "clamp test", "6") + "\n"},
|
|
}
|
|
|
|
_, err := runLogsCmd(t, []string{"logs", "--node", "clampnode", "--since", "1m", "--lines", "999999"})
|
|
if err != nil {
|
|
t.Fatalf("logs: %v", err)
|
|
}
|
|
calls := mx.callsFor("journalctl")
|
|
if len(calls) == 0 {
|
|
t.Fatal("expected journalctl call")
|
|
}
|
|
if !strings.Contains(calls[0].cmd, "--lines 50000") {
|
|
t.Errorf("expected clamped '--lines 50000' in cmd, got: %s", calls[0].cmd)
|
|
}
|
|
}
|
|
|
|
// TestLogsSinceClamp verifies that --since exceeding 7 days is
|
|
// clamped and a warning is printed (REQ-158, P09 T8).
|
|
func TestLogsSinceClamp(t *testing.T) {
|
|
_, cleanup := initTestEnv(t)
|
|
defer cleanup()
|
|
|
|
logsNodeForTest(t, "sincenode", "sincenode: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", "since test", "6") + "\n"},
|
|
}
|
|
|
|
var buf bytes.Buffer
|
|
rootCmd.SetOut(&buf)
|
|
rootCmd.SetErr(&buf)
|
|
resetRootFlags(t)
|
|
rootCmd.SetOut(&buf)
|
|
rootCmd.SetErr(&buf)
|
|
rootCmd.SetArgs([]string{"logs", "--node", "sincenode", "--since", "720h"})
|
|
err := rootCmd.Execute()
|
|
if err != nil {
|
|
t.Fatalf("logs: %v", err)
|
|
}
|
|
out := buf.String()
|
|
if !strings.Contains(out, "clamping to 7d") {
|
|
t.Errorf("expected warning about clamping --since to 7d, got: %s", out)
|
|
}
|
|
calls := mx.callsFor("journalctl")
|
|
if len(calls) == 0 {
|
|
t.Fatal("expected journalctl call")
|
|
}
|
|
}
|
|
|
|
// TestLogsLinesFlagJSON verifies --lines is passed through in JSON mode.
|
|
func TestLogsLinesFlagJSON(t *testing.T) {
|
|
_, cleanup := initTestEnv(t)
|
|
defer cleanup()
|
|
|
|
logsNodeForTest(t, "jsonlines", "jsonlines: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 lines test", "6") + "\n"},
|
|
}
|
|
|
|
_, err := runLogsCmd(t, []string{"logs", "--node", "jsonlines", "--since", "1m", "--lines", "200", "--json"})
|
|
if err != nil {
|
|
t.Fatalf("logs: %v", err)
|
|
}
|
|
calls := mx.callsFor("journalctl")
|
|
if len(calls) == 0 {
|
|
t.Fatal("expected journalctl call")
|
|
}
|
|
if !strings.Contains(calls[0].cmd, "--lines 200") {
|
|
t.Errorf("expected '--lines 200' in cmd, got: %s", calls[0].cmd)
|
|
}
|
|
}
|