diff --git a/.dockerignore b/.dockerignore index 4d248e6d..ffa14334 100644 --- a/.dockerignore +++ b/.dockerignore @@ -2,6 +2,7 @@ docs examples scripts +!scripts/ci/verify-image.sh test libjq @@ -10,4 +11,4 @@ libjq Dockerfile LICENSE *.md -*.png \ No newline at end of file +*.png diff --git a/.github/workflows/images.yaml b/.github/workflows/images.yaml new file mode 100644 index 00000000..1752a8a5 --- /dev/null +++ b/.github/workflows/images.yaml @@ -0,0 +1,78 @@ +# - Detect base-image changes in Dockerfile FROM instructions. +# - Build amd64, arm64 and arm/v7 only when bases change or on manual runs. +# - Check base-image and binary architectures and run smoke tests without publishing images. +name: Base image architecture checks +on: + pull_request: + types: [opened, synchronize] + workflow_dispatch: + +permissions: + contents: read + +jobs: + changes: + name: Detect base image changes + runs-on: ubuntu-latest + outputs: + build: ${{ steps.check.outputs.build }} + steps: + - name: Check out shell-operator code + if: github.event_name == 'pull_request' + uses: actions/checkout@v7 + - name: Decide whether to build images + id: check + shell: bash + env: + EVENT_NAME: ${{ github.event_name }} + BEFORE_SHA: ${{ github.event.before || github.event.pull_request.base.sha }} + AFTER_SHA: ${{ github.event.pull_request.head.sha }} + run: | + if [ "$EVENT_NAME" = workflow_dispatch ]; then + echo "▶️ Manual run requested: building and checking all platforms." + echo "build=true" >> "$GITHUB_OUTPUT" + exit 0 + fi + + # Compare this push so unrelated commits do not repeat the full build. + git fetch --no-tags --depth=1 origin "$BEFORE_SHA" "$AFTER_SHA" + git show "$BEFORE_SHA:Dockerfile" | awk 'toupper($1) == "FROM" { $1=$1; print }' > "$RUNNER_TEMP/base-images-before" + git show "$AFTER_SHA:Dockerfile" | awk 'toupper($1) == "FROM" { $1=$1; print }' > "$RUNNER_TEMP/base-images-after" + + if cmp -s "$RUNNER_TEMP/base-images-before" "$RUNNER_TEMP/base-images-after"; then + echo "⏭️ Base images unchanged. Skipping architecture checks." + echo "build=false" >> "$GITHUB_OUTPUT" + else + echo "🔄 Base image changes detected." + echo "🚀 Full build and architecture checks requested for all platforms." + echo "build=true" >> "$GITHUB_OUTPUT" + fi + + build: + needs: changes + if: needs.changes.outputs.build == 'true' + name: Build and verify (${{ matrix.platform }}) + runs-on: ubuntu-latest + strategy: + fail-fast: false + matrix: + platform: [linux/amd64, linux/arm64, linux/arm/v7] + steps: + - name: Check out shell-operator code + uses: actions/checkout@v7 + - name: Set up QEMU + uses: docker/setup-qemu-action@v4.2.0 + with: + platforms: arm64,arm + - name: Set up Docker Buildx + uses: docker/setup-buildx-action@v4 + - name: Build and verify image + env: + PLATFORM: ${{ matrix.platform }} + run: | + echo "🏗️ Building $PLATFORM image with architecture verification enabled." + docker buildx build \ + --platform "$PLATFORM" \ + --build-arg appVersion=ci \ + --output type=cacheonly \ + . diff --git a/.github/workflows/lint.yaml b/.github/workflows/lint.yaml index d223799e..29dca004 100644 --- a/.github/workflows/lint.yaml +++ b/.github/workflows/lint.yaml @@ -39,7 +39,7 @@ jobs: steps: - uses: actions/setup-python@v6 with: - python-version: 3.8 + python-version: "3.12" - name: Check out addon-operator code uses: actions/checkout@v6 - name: Run codespell diff --git a/Dockerfile b/Dockerfile index 77739655..6b2cb2fd 100644 --- a/Dockerfile +++ b/Dockerfile @@ -1,8 +1,4 @@ -# Prebuilt jq from deckhouse base images (v1.0.40). -FROM --platform=${TARGETPLATFORM:-linux/amd64} registry.deckhouse.io/container-factory@sha256:4b36dcf53c35b50e0afbc445232713aff15f788a61b832cd720bf9e88fc9fba8 AS libjq - -# Go builder stage (builder/golang-alpine, Go 1.26.4 on alpine 3.22). -FROM --platform=${TARGETPLATFORM:-linux/amd64} registry.deckhouse.io/container-factory@sha256:193e8ed6cd7fc19015ab615ccf92d0fe02471e66e3e5abf560b3a87fb05bdb62 AS builder +FROM --platform=${TARGETPLATFORM:-linux/amd64} golang:1.26.4-alpine3.23@sha256:18b460dd17542c2ba43299a633cf6ebfc1115101509531471d7cfce1019af083 AS builder ARG appVersion=latest @@ -32,8 +28,7 @@ RUN GOOS=linux \ -o shell-operator \ ./cmd/shell-operator -# Final runtime image (builder/alpine 3.22 from deckhouse base images v1.0.40). -FROM --platform=${TARGETPLATFORM:-linux/amd64} registry.deckhouse.io/container-factory@sha256:8fa8cf713bf8cfc9038901e5b2fbc97d0403794d834dc4a619e9e81312a6feef +FROM --platform=${TARGETPLATFORM:-linux/amd64} alpine:3.23@sha256:ff7f0c727dd796aa36787bfcd9a64bf35a6ce72a73451b3359fde849b6703d63 ARG TARGETPLATFORM ARG kubectlVersion=v1.34.8 @@ -44,6 +39,7 @@ RUN apk --no-cache add \ bash \ sed \ tini \ + jq \ curl # Determine kubectl architecture and download @@ -58,9 +54,14 @@ RUN mkdir /hooks # Copy necessary files ADD frameworks/shell /frameworks/shell ADD shell_lib.sh / -COPY --from=libjq /usr/bin/jq /usr/bin/jq COPY --from=builder /app/shell-operator / +# Reject incorrect architectures before the image can be published. +RUN --mount=type=bind,source=scripts/ci/verify-image.sh,target=/tmp/verify-image.sh \ + apk add --no-cache --virtual .image-verification file && \ + sh /tmp/verify-image.sh "${TARGETPLATFORM:-linux/amd64}" && \ + apk del .image-verification + # Set working directory WORKDIR / diff --git a/pkg/executor/executor.go b/pkg/executor/executor.go index e192d0d2..b6502b09 100644 --- a/pkg/executor/executor.go +++ b/pkg/executor/executor.go @@ -4,6 +4,7 @@ import ( "bufio" "bytes" "context" + stdjson "encoding/json" "errors" "fmt" "io" @@ -196,6 +197,8 @@ func (e *Executor) RunAndLogLines(ctx context.Context, logLabels map[string]stri defer unregisterPID(e.cmd.Process.Pid) err := e.cmd.Wait() + plo.flush() + ple.flush() if err != nil { if len(stdErr.Bytes()) > 0 { return nil, &StderrError{Message: stdErr.String()} @@ -229,105 +232,109 @@ type proxyLogger struct { proxyJsonLogKey string logger *log.Logger buf []byte + jsonBuf []byte } func (pl *proxyLogger) Write(p []byte) (int, error) { - if !pl.logProxyHookJSON { - pl.writerScanner(p) - - return len(p), nil - } - - // join all parts of json pl.buf = append(pl.buf, p...) - var line interface{} - err := json.Unmarshal(pl.buf, &line) - if err != nil { - if err.Error() == "unexpected end of JSON input" { - return len(p), nil + for len(pl.buf) > 0 { + lineSize := bytes.IndexByte(pl.buf, '\n') + 1 + if !pl.hasPendingJSON() && len(pl.buf) >= bufio.MaxScanTokenSize && (lineSize == 0 || lineSize > bufio.MaxScanTokenSize) { + lineSize = bufio.MaxScanTokenSize + } + if lineSize == 0 { + break } - pl.logger.Debug("output is not json", log.Err(err)) - pl.writerScanner(p) - - return len(p), nil + pl.logLine(pl.buf[:lineSize]) + pl.buf = pl.buf[lineSize:] } - - logMap, ok := line.(map[string]interface{}) - defer func() { - pl.buf = pl.buf[:0] - }() - - if !ok { - pl.logger.Debug("json log line not map[string]interface{}", slog.Any(pkg.LogKeyLine, line)) - - // fall back to using the logger - pl.logger.Info(string(p)) - - return len(p), nil + if len(pl.buf) == 0 { + pl.buf = nil } - pl.mergeAndLogInputLog(pl.ctx, logMap, "hook") - return len(p), nil } -func (pl *proxyLogger) writerScanner(p []byte) { - scanner := bufio.NewScanner(bytes.NewReader(p)) - scanner.Buffer(make([]byte, bufio.MaxScanTokenSize), bufio.MaxScanTokenSize) +func (pl *proxyLogger) hasPendingJSON() bool { + if len(pl.jsonBuf) > 0 { + return true + } + line := bytes.TrimLeft(pl.buf, " \t\r\n") + return bytes.HasPrefix(line, []byte("{")) || (pl.logProxyHookJSON && (bytes.HasPrefix(line, []byte("[")) || bytes.HasPrefix(line, []byte("\"")))) +} - var jsonBuf []string - // Split large entries into chunks - chunkSize := bufio.MaxScanTokenSize // 64KB - splitFunc := func(data []byte, atEOF bool) (int, []byte, error) { - if len(data) >= chunkSize { - return chunkSize, data[:chunkSize], nil - } - return bufio.ScanLines(data, atEOF) +// flush logs the final unterminated record after the output stream ends. +func (pl *proxyLogger) flush() { + if len(pl.buf) > 0 { + pl.logLine(pl.buf) + pl.buf = nil } - scanner.Split(splitFunc) - // Scan the input and write it to the logger using the specified print function - for scanner.Scan() { - // Prevent empty logging - line := strings.TrimSpace(scanner.Text()) - if line == "" { - continue - } + if len(pl.jsonBuf) > 0 { + pl.logText(string(pl.jsonBuf)) + pl.jsonBuf = nil + } +} - if len(jsonBuf) > 0 || strings.HasPrefix(line, "{") { - jsonBuf = append(jsonBuf, line) - joined := strings.Join(jsonBuf, "\n") - if err := pl.tryLogJSON(joined); err == nil { - jsonBuf = nil - } - continue - } +func (pl *proxyLogger) logLine(raw []byte) { + line := strings.TrimSpace(string(raw)) + if line == "" && len(pl.jsonBuf) == 0 { + return + } - if len(line) > 10000 { - line = fmt.Sprintf("%s:truncated", line[:10000]) + // JSON records can span both physical lines and separate Write calls. + if len(pl.jsonBuf) > 0 || strings.HasPrefix(line, "{") || (pl.logProxyHookJSON && (strings.HasPrefix(line, "[") || strings.HasPrefix(line, "\""))) { + pl.jsonBuf = append(pl.jsonBuf, raw...) + err := pl.tryLogJSON(string(pl.jsonBuf)) + if errors.Is(err, io.ErrUnexpectedEOF) { + return } - - if err := pl.tryLogJSON(line); err == nil { - continue + if err != nil { + pl.logText(string(pl.jsonBuf)) } - pl.logger.Info(line) + pl.jsonBuf = nil + return + } + + if err := pl.tryLogJSON(string(raw)); err == nil { + return } - // If there was an error while scanning the input, log an error - if err := scanner.Err(); err != nil { - pl.logger.Error("reading from scanner", log.Err(err)) + pl.logText(line) +} + +func (pl *proxyLogger) logText(line string) { + line = strings.TrimSpace(line) + if len(line) > 10000 { + line = fmt.Sprintf("%s:truncated", line[:10000]) } + pl.logger.Info(line) } -// tryLogJSON tries to parse the string as JSON and log it if it succeeds +// tryLogJSON logs a complete JSON record with the hook's structured fields. func (pl *proxyLogger) tryLogJSON(s string) error { - var m map[string]interface{} - err := json.Unmarshal([]byte(s), &m) - if err == nil { - pl.mergeAndLogInputLog(pl.ctx, m, "hook") + var value interface{} + if err := json.Unmarshal([]byte(s), &value); err != nil { + // go-json reports some incomplete documents as syntax errors. + var raw stdjson.RawMessage + if decodeErr := stdjson.NewDecoder(strings.NewReader(s)).Decode(&raw); errors.Is(decodeErr, io.ErrUnexpectedEOF) { + return io.ErrUnexpectedEOF + } + return err + } + + logMap, ok := value.(map[string]interface{}) + if ok || (value == nil && !pl.logProxyHookJSON) { + pl.mergeAndLogInputLog(pl.ctx, logMap, "hook") return nil } - return fmt.Errorf("failed to parse json: %w", err) + if !pl.logProxyHookJSON { + return errors.New("json log line is not an object") + } + + pl.logger.Debug("json log line not map[string]interface{}", slog.Any(pkg.LogKeyLine, value)) + pl.logger.Info(s) + return nil } // level = level diff --git a/pkg/executor/proxy_logger_test.go b/pkg/executor/proxy_logger_test.go new file mode 100644 index 00000000..b0111771 --- /dev/null +++ b/pkg/executor/proxy_logger_test.go @@ -0,0 +1,190 @@ +package executor + +import ( + "bytes" + "context" + "fmt" + "strings" + "testing" + "time" + + "github.com/deckhouse/deckhouse/pkg/log" + "github.com/stretchr/testify/require" + + json "github.com/flant/shell-operator/pkg/utils/json" +) + +func TestProxyLoggerWriteBoundaries(t *testing.T) { + cases := []struct { + name string + proxy bool + input string + expected []map[string]any + }{ + { + name: "mixed JSON and text", + proxy: true, + input: "{\"level\":\"error\",\"msg\":\"quoted \\\"{value}\\\"\",\"value\":\"Привет\"}\r\n" + + "plain text\r\n" + "{\r\n\"a\":\"b\",\r\n\"c\":\"d\"\r\n}", + expected: []map[string]any{ + {"level": "error", "msg": `quoted "{value}"`, "hook_value": "Привет", "output": "stdout", "proxyJsonLog": true}, + {"level": "info", "msg": "plain text", "output": "stdout"}, + {"level": "info", "msg": "hook result", "hook_a": "b", "hook_c": "d", "output": "stdout", "proxyJsonLog": true}, + }, + }, + { + name: "plain text without JSON proxy", + input: "first line\r\n\nПривет\nlast line", + expected: []map[string]any{ + {"level": "info", "msg": "first line", "output": "stdout"}, + {"level": "info", "msg": "Привет", "output": "stdout"}, + {"level": "info", "msg": "last line", "output": "stdout"}, + }, + }, + } + + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + t.Run("whole", func(t *testing.T) { + require.Equal(t, tc.expected, proxyLoggerRecords(t, tc.proxy, tc.input)) + }) + for split := 1; split < len(tc.input); split++ { + t.Run(fmt.Sprintf("split_%d", split), func(t *testing.T) { + require.Equal(t, tc.expected, proxyLoggerRecords(t, tc.proxy, tc.input[:split], tc.input[split:])) + }) + } + t.Run("bytewise", func(t *testing.T) { + chunks := make([]string, len(tc.input)) + for i := range chunks { + chunks[i] = tc.input[i : i+1] + } + require.Equal(t, tc.expected, proxyLoggerRecords(t, tc.proxy, chunks...)) + }) + }) + } +} + +func TestProxyLoggerFlushIncompleteJSON(t *testing.T) { + require.Equal(t, []map[string]any{ + {"level": "info", "msg": `{"unfinished":`, "output": "stdout"}, + }, proxyLoggerRecords(t, true, `{"unfin`, `ished":`)) +} + +func TestProxyLoggerMalformedJSON(t *testing.T) { + require.Equal(t, []map[string]any{ + {"level": "info", "msg": `{"value": broken}`, "output": "stdout"}, + {"level": "info", "msg": "hook result", "hook_value": "next", "output": "stdout", "proxyJsonLog": true}, + }, proxyLoggerRecords(t, true, "{\"value\": broken}\n{\"value\":\"next\"}\n")) +} + +func TestProxyLoggerMultilineArray(t *testing.T) { + input := "[\n\n\"first\",\n\"second\"\n]\n" + require.Equal(t, []map[string]any{ + {"level": "info", "msg": input, "output": "stdout"}, + }, proxyLoggerRecords(t, true, input[:4], input[4:])) +} + +func TestProxyLoggerLongRecords(t *testing.T) { + t.Run("plain text is truncated across writes", func(t *testing.T) { + line := "result " + strings.Repeat("x", 20000) + records := proxyLoggerRecords(t, false, line[:4096], line[4096:]+"\nafter\n") + require.Equal(t, []map[string]any{ + {"level": "info", "msg": line[:10000] + ":truncated", "output": "stdout"}, + {"level": "info", "msg": "after", "output": "stdout"}, + }, records) + }) + + t.Run("JSON fields are truncated across writes", func(t *testing.T) { + input := `{"payload":"` + strings.Repeat("x", 70000) + `"}` + records := proxyLoggerRecords(t, true, input[:32768], input[32768:]+"\n") + require.Equal(t, []map[string]any{ + { + "level": "info", "msg": "hook result", "output": "stdout", "proxyJsonLog": true, + "hook": map[string]any{"truncated": input[:10000] + ":truncated"}, + }, + }, records) + }) + + t.Run("non-object JSON remains raw text", func(t *testing.T) { + input := `"` + strings.Repeat("x", 70000) + "\"\n" + require.Equal(t, []map[string]any{ + {"level": "info", "msg": input, "output": "stdout"}, + }, proxyLoggerRecords(t, true, input[:32768], input[32768:])) + }) +} + +func TestRunAndLogLinesFlushesBothStreams(t *testing.T) { + for _, failed := range []bool{false, true} { + t.Run(fmt.Sprintf("failed_%t", failed), func(t *testing.T) { + logger, output := newProxyLoggerTestLogger() + exitCode := 0 + if failed { + exitCode = 1 + } + script := fmt.Sprintf(`printf '%%s' '{"value":"out"}'; printf '%%s' 'stderr tail' >&2; exit %d`, exitCode) + ex := NewExecutor("", "sh", []string{"-c", script}, nil). + WithLogProxyHookJSON(true). + WithLogger(logger) + + _, err := ex.RunAndLogLines(context.Background(), nil) + if failed { + var stderrErr *StderrError + require.ErrorAs(t, err, &stderrErr) + require.Equal(t, "stderr tail", stderrErr.Message) + } else { + require.NoError(t, err) + } + require.Equal(t, []map[string]any{ + {"level": "info", "msg": "hook result", "hook_value": "out", "output": "stdout", "proxyJsonLog": true}, + {"level": "info", "msg": "stderr tail", "output": "stderr"}, + }, decodeProxyLoggerRecords(t, output.String())) + }) + } +} + +func proxyLoggerRecords(t *testing.T, proxy bool, chunks ...string) []map[string]any { + t.Helper() + logger, output := newProxyLoggerTestLogger() + pl := &proxyLogger{ + ctx: context.Background(), + logProxyHookJSON: proxy, + proxyJsonLogKey: "proxyJsonLog", + logger: logger.With("output", "stdout"), + } + for _, chunk := range chunks { + n, err := pl.Write([]byte(chunk)) + require.NoError(t, err) + require.Equal(t, len(chunk), n) + } + pl.flush() + result := output.String() + pl.flush() + require.Equal(t, result, output.String(), "flushing again must not duplicate records") + return decodeProxyLoggerRecords(t, result) +} + +func newProxyLoggerTestLogger() (*log.Logger, *bytes.Buffer) { + logger := log.NewLogger(log.WithTimeFunc(func(time.Time) time.Time { + return time.Date(2006, time.January, 2, 15, 4, 5, 0, time.UTC) + })) + logger.SetLevel(log.LevelInfo) + output := new(bytes.Buffer) + logger.SetOutput(output) + return logger, output +} + +func decodeProxyLoggerRecords(t *testing.T, output string) []map[string]any { + t.Helper() + var records []map[string]any + for _, line := range strings.Split(strings.TrimSpace(output), "\n") { + if line == "" { + continue + } + var record map[string]any + require.NoError(t, json.Unmarshal([]byte(line), &record)) + require.Equal(t, "2006-01-02T15:04:05Z", record["time"]) + delete(record, "time") + records = append(records, record) + } + return records +} diff --git a/scripts/ci/verify-image.sh b/scripts/ci/verify-image.sh new file mode 100644 index 00000000..0fb27d94 --- /dev/null +++ b/scripts/ci/verify-image.sh @@ -0,0 +1,79 @@ +#!/bin/sh +set -eu + +report_architecture_error() { + cat >&2 <&2 + exit 1 + ;; +esac + +printf '🔍 %s: starting architecture consistency checks for the base image and built binaries.\n' "$platform" + +actual_arch=$(apk --print-arch) +if [ "$actual_arch" != "$apk_arch" ]; then + report_architecture_error "Alpine base image" \ + "$(describe_architecture "$apk_arch")" "$(describe_architecture "$actual_arch")" +fi + +# Emulation can run a binary for the wrong platform, so inspect its ELF header. +for binary in /shell-operator /usr/bin/jq /bin/busybox /sbin/tini /bin/kubectl; do + description=$(file -bL "$binary") + echo "$binary: $description" + if ! printf '%s\n' "$description" | grep -Eq "$elf_pattern"; then + report_architecture_error "$binary" "$expected_cpu" "$(describe_architecture "$description")" + fi +done + +/sbin/tini -- /shell-operator version +/bin/kubectl version --client + +context_file=$(mktemp) +trap 'rm -f "$context_file"' EXIT +printf '%s\n' '[{"binding":"image-verification"}]' > "$context_file" +export BINDING_CONTEXT_PATH="$context_file" +export BINDING_CONTEXT_CURRENT_INDEX=0 +bash -ec 'source /shell_lib.sh; test "$(context::get --required binding)" = image-verification' + +printf '✅ %s: Alpine and all 5 checked binaries have the expected CPU architecture.\n' "$platform"