diff --git a/.gitignore b/.gitignore index a1c44a1f..8800f09f 100644 --- a/.gitignore +++ b/.gitignore @@ -83,3 +83,7 @@ tags .history # End of https://www.gitignore.io/api/go,vim,emacs,visualstudiocode *.iml + + +docker/zu/.gradle +docker/zu/build diff --git a/docker/bin/zookeeperStart.sh b/docker/bin/zookeeperStart.sh index 5813b024..0e3d2592 100755 --- a/docker/bin/zookeeperStart.sh +++ b/docker/bin/zookeeperStart.sh @@ -181,6 +181,8 @@ else fi cp -f /conf/log4j.properties $ZOOCFGDIR cp -f /conf/log4j-quiet.properties $ZOOCFGDIR +cp -f /conf/logback.xml $ZOOCFGDIR +cp -f /conf/logback-quiet.xml $ZOOCFGDIR cp -f /conf/env.sh $ZOOCFGDIR if [ -f $DYNCONFIG ]; then diff --git a/go.mod b/go.mod index d0522f71..a8d10917 100644 --- a/go.mod +++ b/go.mod @@ -46,10 +46,13 @@ require ( github.com/google/gnostic-models v0.7.0 // indirect github.com/google/go-cmp v0.7.0 // indirect github.com/google/uuid v1.6.0 // indirect + github.com/gorilla/websocket v1.5.4-0.20250319132907-e064f32e3674 // indirect github.com/json-iterator/go v1.1.12 // indirect + github.com/moby/spdystream v0.5.0 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.3-0.20250322232337-35a7c28c31ee // indirect github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect + github.com/mxk/go-flowrate v0.0.0-20140419014527-cca7078d478f // indirect github.com/nxadm/tail v1.4.11 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect github.com/prometheus/client_golang v1.23.2 // indirect diff --git a/go.sum b/go.sum index 693bee80..0f7d26ca 100644 --- a/go.sum +++ b/go.sum @@ -1,5 +1,7 @@ github.com/Masterminds/semver/v3 v3.4.0 h1:Zog+i5UMtVoCU8oKka5P7i9q9HgrJeGzI9SA1Xbatp0= github.com/Masterminds/semver/v3 v3.4.0/go.mod h1:4V+yj/TJE1HU9XfppCwVMZq3I84lprf4nC11bSS5beM= +github.com/armon/go-socks5 v0.0.0-20160902184237-e75332964ef5 h1:0CwZNZbxp69SHPdPJAN/hZIm0C4OItdklCFmMRWYpio= +github.com/armon/go-socks5 v0.0.0-20160902184237-e75332964ef5/go.mod h1:wHh0iHkYZB8zMSxRWpUBQtwG5a7fFgvEO+odwuTv2gs= github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM= github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw= github.com/cespare/xxhash/v2 v2.3.0 h1:UL815xU9SqsFlibzuggzjXhog7bL6oX9BbNZnL2UFvs= @@ -85,6 +87,8 @@ github.com/google/pprof v0.0.0-20250403155104-27863c87afa6 h1:BHT72Gu3keYf3ZEu2J github.com/google/pprof v0.0.0-20250403155104-27863c87afa6/go.mod h1:boTsfXsheKC2y+lKOCMpSfarhxDeIzfZG1jqGcPl3cA= github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/gorilla/websocket v1.5.4-0.20250319132907-e064f32e3674 h1:JeSE6pjso5THxAzdVpqr6/geYxZytqFMBCOtn/ujyeo= +github.com/gorilla/websocket v1.5.4-0.20250319132907-e064f32e3674/go.mod h1:r4w70xmWCQKmi1ONH4KIaBptdivuRPyosB9RmPlGEwA= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/json-iterator/go v1.1.12 h1:PV8peI4a0ysnczrg+LtxykD8LfKY9ML6u2jnxaEnrnM= github.com/json-iterator/go v1.1.12/go.mod h1:e30LSqwooZae/UwlEbR2852Gd8hjQvJoHmT4TnhNGBo= @@ -98,6 +102,8 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/kylelemons/godebug v1.1.0 h1:RPNrshWIDI6G2gRW9EHilWtl7Z6Sb1BR0xunSBf0SNc= github.com/kylelemons/godebug v1.1.0/go.mod h1:9/0rRGxNHcop5bhtWyNeEfOS8JIWk580+fNqagV/RAw= +github.com/moby/spdystream v0.5.0 h1:7r0J1Si3QO/kjRitvSLVVFUjxMEb/YLj6S9FF62JBCU= +github.com/moby/spdystream v0.5.0/go.mod h1:xBAYlnt/ay+11ShkdFKNAG7LsyK/tmNBVvVOwrfMgdI= github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd h1:TRLaZ9cD/w8PVh93nsPXa1VrQ6jlwL5oN8l14QlcNfg= github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= @@ -106,6 +112,8 @@ github.com/modern-go/reflect2 v1.0.3-0.20250322232337-35a7c28c31ee h1:W5t00kpgFd github.com/modern-go/reflect2 v1.0.3-0.20250322232337-35a7c28c31ee/go.mod h1:yWuevngMOJpCy52FWWMvUC8ws7m/LJsjYzDa0/r8luk= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq1c1nUAm88MOHcQC9l5mIlSMApZMrHA= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822/go.mod h1:+n7T8mK8HuQTcFwEeznm/DIxMOiR9yIdICNftLE1DvQ= +github.com/mxk/go-flowrate v0.0.0-20140419014527-cca7078d478f h1:y5//uYreIhSUg3J1GEMiLbxo1LJaP8RfCpH6pymGZus= +github.com/mxk/go-flowrate v0.0.0-20140419014527-cca7078d478f/go.mod h1:ZdcZmHo+o7JKHSa8/e818NopupXU1YMK5fe1lsApnBw= github.com/nxadm/tail v1.4.4/go.mod h1:kenIhsEOeOJmVchQTgglprH7qJGnHDVpk1VPCcaMI8A= github.com/nxadm/tail v1.4.8/go.mod h1:+ncqLTQzXmGhMZNUePPaPqPvBxHAIsmXswZKocGu+AU= github.com/nxadm/tail v1.4.11 h1:8feyoE3OzPrcshW5/MJ4sGESc5cqmGkGCWlco4l0bqY= diff --git a/openspec/changes/zookeeper-logback-info/.openspec.yaml b/openspec/changes/zookeeper-logback-info/.openspec.yaml new file mode 100644 index 00000000..eac8ef7a --- /dev/null +++ b/openspec/changes/zookeeper-logback-info/.openspec.yaml @@ -0,0 +1,2 @@ +schema: spec-driven +created: 2026-02-23 diff --git a/openspec/changes/zookeeper-logback-info/design.md b/openspec/changes/zookeeper-logback-info/design.md new file mode 100644 index 00000000..61ff287c --- /dev/null +++ b/openspec/changes/zookeeper-logback-info/design.md @@ -0,0 +1,69 @@ +# Design: Add Logback config so ZooKeeper logs at INFO + +## Context + +The operator generates a ConfigMap per ZookeeperCluster containing `zoo.cfg`, `env.sh`, `log4j.properties`, and `log4j-quiet.properties`. The ConfigMap is mounted at `/conf` and the pod’s startup script copies its contents to a writable config dir (e.g. `/data/conf`) before running `zkServer.sh --config /data/conf start-foreground`. The ZooKeeper server image uses **Logback** (logback-classic, logback-core) as the SLF4J backend; there is no Log4j on the classpath, so the existing log4j config files are never read. Logback discovers configuration by looking for `logback.xml` (or `logback.groovy` / `logback-test.xml`) on the classpath; `ZOOCFGDIR` is prepended to the classpath in `zkEnv.sh`, so a `logback.xml` placed in the config dir will be picked up when the JVM starts. The goal is to add operator-generated Logback config so that runtime logging is at INFO (or optionally ERROR for a quiet profile) instead of DEBUG. + +## Goals / Non-Goals + +**Goals:** + +- Generate `logback.xml` with root and key loggers at INFO, and `logback-quiet.xml` with root and key loggers at ERROR. +- Include both files in the existing ZookeeperCluster ConfigMap; no new volume or mount. +- Use a CONSOLE appender with the same pattern as upstream ZooKeeper (`%d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n`) for consistency. +- Explicitly set logger level for `org.apache.zookeeper` and `org.eclipse.jetty` so DEBUG from those packages is suppressed regardless of any default or bundled config. + +**Non-Goals:** + +- No CRD field or API to select log level (INFO vs ERROR); both configs are present and the default is `logback.xml` (INFO) via Logback’s default discovery. Optional future: env or CRD to point to the quiet file via `-Dlogback.configurationFile`. +- No removal of existing log4j config files (kept for any image that might use Log4j). The **startup script is updated** so that Logback configs are copied and take effect (see Decision 5). + +## Decisions + +### 1. Generate Logback XML in Go as raw strings + +**Decision:** Implement two functions (e.g. `makeZkLogbackConfigString()`, `makeZkLogbackQuietConfigString()`) that return the full XML as Go raw string literals. + +**Rationale:** The content is static and small; no user or cluster-specific substitution is required. Using a raw string avoids escaping and keeps the XML readable in code. Alternatives (embedding a file, or using text/template with a tiny template) add indirection without benefit for this size. + +### 2. Two separate files (logback.xml and logback-quiet.xml) + +**Decision:** Emit two files: `logback.xml` (INFO) and `logback-quiet.xml` (ERROR). Logback’s default lookup uses `logback.xml`, so the default behavior is INFO without any startup-script or env change. + +**Rationale:** Matches the existing pattern (log4j.properties vs logback-quiet.properties). A single parameterized file would require the image to pass `-Dlogback.configurationFile` or similar, which is out of scope. Keeping the default as INFO satisfies the main use case (reduce DEBUG); the quiet file is available for future use (e.g. script or env pointing to it). + +### 3. Keep existing log4j files unchanged + +**Decision:** Do not remove or alter `log4j.properties` or `log4j-quiet.properties` in the ConfigMap. + +**Rationale:** Some images or environments might still use Log4j; removing those files could break them. The change is purely additive. + +### 4. CONSOLE appender only; explicit loggers for ZooKeeper and Jetty + +**Decision:** Each Logback config has one CONSOLE appender with a ThresholdFilter at the chosen level, plus `` and ``, and `` with that appender. + +**Rationale:** CONSOLE-only matches current operator behavior (no file appenders). Explicit loggers ensure that even if another config or a jar’s default sets DEBUG for those packages, our config takes precedence when our file is loaded first on the classpath. + +### 5. Startup script copies Logback configs to writable config dir + +**Decision:** The ZooKeeper startup script (e.g. `zookeeperStart.sh`) SHALL copy `logback.xml` and `logback-quiet.xml` from the mounted config source (e.g. `/conf`) to the writable config directory (e.g. `/data/conf`, i.e. `ZOOCFGDIR`) before invoking `zkServer.sh --config $ZOOCFGDIR start-foreground`, in the same way it already copies `log4j.properties`, `log4j-quiet.properties`, and `env.sh`. + +**Rationale:** The ConfigMap is mounted read-only at `/conf`. The server runs with `ZOOCFGDIR=/data/conf` on the classpath; that directory is writable and is populated by the script. If the script does not copy the Logback files, they never appear in `/data/conf`, so Logback does not find them and falls back to default (DEBUG). Copying them ensures they are present when the JVM starts. + +## Risks / Trade-offs + +| Risk | Mitigation | +|------|------------| +| Another `logback.xml` (e.g. inside a JAR) is found before the config dir on the classpath | ZOOCFGDIR is prepended in zkEnv.sh; as long as the pod uses that script and the same config dir, our file is first. Explicit logger levels still help if both configs are merged in some scenarios. | +| Startup script does not copy Logback files to writable config dir | The startup script in the repo (`docker/bin/zookeeperStart.sh`) is updated to copy `logback.xml` and `logback-quiet.xml` from `/conf` to `$ZOOCFGDIR` alongside the existing log4j and env.sh copies. Rebuilding the image that includes this script is required for the fix to take effect. | +| Need to switch to ERROR at runtime without redeploy | Not supported in this change; would require env/CRD and `-Dlogback.configurationFile` in the image. Document as a possible future improvement. | + +## Migration Plan + +- **Deployment:** No migration steps for the operator. New ConfigMap entries are additive; existing keys and mounts unchanged. The **image** that runs the ZooKeeper container must include the updated startup script (copying logback.xml and logback-quiet.xml); rebuild and push the image, then roll out the new image to the StatefulSet. +- **Rollout:** On next rollout with the updated image, pods will copy `logback.xml` and `logback-quiet.xml` to the config dir and the JVM will load `logback.xml` from that dir. No data or API migration. +- **Rollback:** Revert the operator change and the startup script change; redeploy the previous image. ConfigMap will no longer contain the Logback keys; script will no longer copy them. Logback will fall back to default or another config on the classpath (e.g. from a JAR); behavior returns to whatever it was before (e.g. DEBUG). + +## Open Questions + +- **Optional:** Add a ZookeeperCluster field (e.g. `spec.logging.level: Info | Error`) and set `LOG_BACK_CONFIG_FILE` or JVM `-Dlogback.configurationFile` in env so the image can choose the quiet file without changing the image. Defer until someone needs it. diff --git a/openspec/changes/zookeeper-logback-info/proposal.md b/openspec/changes/zookeeper-logback-info/proposal.md new file mode 100644 index 00000000..1fd60be3 --- /dev/null +++ b/openspec/changes/zookeeper-logback-info/proposal.md @@ -0,0 +1,29 @@ +# Proposal: Add Logback config so ZooKeeper logs at INFO + +## Why + +ZooKeeper pods managed by the operator log at DEBUG level, producing very high log volume from `org.apache.zookeeper` and `org.eclipse.jetty` (CommitProcessor, DataTree, NettyServerCnxn, Jetty lifecycle, etc.). This makes logs hard to use in production and can impact performance and log storage. The operator already generates `log4j.properties` and `log4j-quiet.properties`, but the ZooKeeper server image uses **Logback** as its SLF4J backend (logback-classic, logback-core in `lib/`), not Log4j, so those files are never read. To reduce log level to INFO we must provide a Logback configuration that is actually used at runtime. + +## What Changes + +- **Operator ConfigMap**: Generate and include `logback.xml` (root and key loggers at INFO) and `logback-quiet.xml` (root and key loggers at ERROR) in the ZookeeperCluster ConfigMap, alongside existing log4j files. +- **Logback content**: Both files use a CONSOLE appender with the same pattern as upstream ZooKeeper (`%d{ISO8601} [myid:%X{myid}] - %-5p ...`). Explicit `` entries for `org.apache.zookeeper` and `org.eclipse.jetty` at the chosen level so DEBUG from those packages is suppressed regardless of any default config. +- **No removal**: Existing `log4j.properties` and `log4j-quiet.properties` remain for images or setups that use Log4j; no breaking change to the ConfigMap shape or mount paths. +- **Runtime behavior**: When the pod’s config dir (e.g. `/data/conf` or `/conf`) is on the classpath before other resources, Logback will load `logback.xml` from that dir and apply INFO (or ERROR when using the quiet variant), reducing log volume to a manageable level. + +## Capabilities + +### New Capabilities + +- **zookeeper-logback-config**: The operator supplies Logback configuration (logback.xml and an optional quiet variant) so that ZooKeeper servers using Logback at runtime log at INFO by default, with an option for a quieter (ERROR) profile. Covers generation of the XML configs, inclusion in the ConfigMap, and the contract that the chosen file is on the server classpath so Logback picks it up. + +### Modified Capabilities + +- _(None. No existing specs in `openspec/specs/`; this is a new capability only.)_ + +## Impact + +- **Code**: `pkg/zk/generators.go` — new helpers to generate logback.xml and logback-quiet.xml strings; ConfigMap `Data` extended with `logback.xml` and `logback-quiet.xml`. +- **APIs**: No change to ZookeeperCluster CRD or public API. +- **Dependencies**: None; no new libraries. +- **Systems**: Pods that use the operator’s ConfigMap and a ZooKeeper image with Logback on the classpath will start using the new config on next rollout; config dir must be on the classpath (already true for the current startup flow). Images that use Log4j continue to rely on existing log4j.* properties. diff --git a/openspec/changes/zookeeper-logback-info/specs/zookeeper-logback-config/spec.md b/openspec/changes/zookeeper-logback-info/specs/zookeeper-logback-config/spec.md new file mode 100644 index 00000000..487d1107 --- /dev/null +++ b/openspec/changes/zookeeper-logback-info/specs/zookeeper-logback-config/spec.md @@ -0,0 +1,55 @@ +# Spec: zookeeper-logback-config + +The operator supplies Logback configuration so that ZooKeeper servers using Logback at runtime log at INFO by default, with an optional quieter (ERROR) profile. + +## ADDED Requirements + +### Requirement: Operator generates default Logback config at INFO + +The operator SHALL generate a Logback configuration file named `logback.xml` with root logger and CONSOLE appender at INFO level. The configuration SHALL set explicit logger level to INFO for the packages `org.apache.zookeeper` and `org.eclipse.jetty` so that DEBUG output from those packages is not emitted. + +#### Scenario: Default config caps ZooKeeper and Jetty at INFO + +- **WHEN** a ZookeeperCluster is reconciled and the ConfigMap is generated +- **THEN** the ConfigMap SHALL contain a key `logback.xml` whose value is valid Logback XML with `` and `` and `` + +#### Scenario: Default config uses CONSOLE appender with ZooKeeper pattern + +- **WHEN** the generated `logback.xml` is inspected +- **THEN** it SHALL contain a CONSOLE appender with a pattern that includes `%d{ISO8601}`, `[myid:%X{myid}]`, and `%-5p` so that log format is consistent with upstream ZooKeeper + +### Requirement: Operator generates quiet Logback config at ERROR + +The operator SHALL generate a Logback configuration file named `logback-quiet.xml` with root logger and CONSOLE appender at ERROR level. The configuration SHALL set explicit logger level to ERROR for `org.apache.zookeeper` and `org.eclipse.jetty`. + +#### Scenario: Quiet config caps all at ERROR + +- **WHEN** a ZookeeperCluster is reconciled and the ConfigMap is generated +- **THEN** the ConfigMap SHALL contain a key `logback-quiet.xml` whose value is valid Logback XML with `` and `` and `` + +### Requirement: Logback configs are in the cluster ConfigMap + +The operator SHALL include both `logback.xml` and `logback-quiet.xml` in the same ConfigMap that is used for the ZookeeperCluster (the one mounted at the config directory). No separate volume or mount SHALL be required. + +#### Scenario: ConfigMap contains both Logback files + +- **WHEN** the ZookeeperCluster ConfigMap is listed +- **THEN** its `data` SHALL include the keys `logback.xml` and `logback-quiet.xml` in addition to existing keys (e.g. `zoo.cfg`, `env.sh`, `log4j.properties`, `log4j-quiet.properties`) + +### Requirement: Config directory is on server classpath + +For the Logback configuration to take effect, the ZooKeeper server process SHALL have the config directory (the directory where `logback.xml` is placed, e.g. `/data/conf` or `/conf`) on its Java classpath before any JAR or resource that might contain another `logback.xml`. The startup script SHALL copy `logback.xml` and `logback-quiet.xml` from the mounted config source into that directory before starting the server, so that Logback discovers them. + +#### Scenario: Logback discovers operator config when config dir is first on classpath + +- **WHEN** the ZooKeeper server starts with the operator’s ConfigMap mounted and the config directory is the first element on the classpath +- **THEN** Logback SHALL load `logback.xml` from that directory and the effective log level for `org.apache.zookeeper` and `org.eclipse.jetty` SHALL be INFO (or ERROR if the process is configured to use `logback-quiet.xml`) + +### Requirement: Startup script copies Logback configs to writable config directory + +The ZooKeeper startup script (e.g. `zookeeperStart.sh`) SHALL copy `logback.xml` and `logback-quiet.xml` from the mounted config source (e.g. `/conf`) to the writable config directory used at runtime (e.g. `/data/conf`, i.e. `ZOOCFGDIR`) before invoking the ZooKeeper server, in the same way it copies `log4j.properties`, `log4j-quiet.properties`, and `env.sh`. This ensures the files are present on the classpath when the JVM starts. + +#### Scenario: Script copies Logback files alongside other config files + +- **WHEN** the pod starts and the startup script runs before `zkServer.sh --config $ZOOCFGDIR start-foreground` +- **THEN** the script SHALL copy `/conf/logback.xml` and `/conf/logback-quiet.xml` to `$ZOOCFGDIR` (e.g. `/data/conf`), so that both files exist in the same directory as `zoo.cfg`, `log4j.properties`, `log4j-quiet.properties`, and `env.sh` diff --git a/openspec/changes/zookeeper-logback-info/tasks.md b/openspec/changes/zookeeper-logback-info/tasks.md new file mode 100644 index 00000000..1f9aa8bc --- /dev/null +++ b/openspec/changes/zookeeper-logback-info/tasks.md @@ -0,0 +1,21 @@ +## 1. Logback config generation + +- [x] 1.1 Add `makeZkLogbackConfigString()` in `pkg/zk/generators.go` returning valid Logback XML with root and CONSOLE appender at INFO, explicit `` for `org.apache.zookeeper` and `org.eclipse.jetty` at INFO, and pattern `%d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n` +- [x] 1.2 Add `makeZkLogbackQuietConfigString()` in `pkg/zk/generators.go` returning valid Logback XML with root and CONSOLE appender at ERROR and explicit loggers for `org.apache.zookeeper` and `org.eclipse.jetty` at ERROR, same pattern + +## 2. ConfigMap integration + +- [x] 2.1 In `MakeConfigMap()`, add `"logback.xml": makeZkLogbackConfigString()` and `"logback-quiet.xml": makeZkLogbackQuietConfigString()` to the ConfigMap `Data` map alongside existing keys (`zoo.cfg`, `log4j.properties`, `log4j-quiet.properties`, `env.sh`) + +## 3. Verification + +- [x] 3.1 Confirm generated ConfigMap contains both `logback.xml` and `logback-quiet.xml` (e.g. unit test or manual check after deploy) + +## 4. Startup script + +- [x] 4.1 In the ZooKeeper startup script (e.g. `docker/bin/zookeeperStart.sh`), add copy of `logback.xml` and `logback-quiet.xml` from `/conf` to `$ZOOCFGDIR` (e.g. `/data/conf`) alongside the existing copies of `log4j.properties`, `log4j-quiet.properties`, and `env.sh`, so that Logback finds the config when the JVM starts + +## 5. E2E test + +- [x] 5.1 Add e2eutil helpers in `pkg/test/e2e/e2eutil/pod_util.go`: `GetPodLogs` (stream pod logs with optional `PodLogOptions`) and `PodExec` (run a command in a pod container and return stdout/stderr) +- [x] 5.2 Add e2e test in `test/e2e/logback_config_test.go` that creates a Zookeeper cluster, waits for ready, then (a) execs `ls /data/conf` in a running pod and asserts output contains `logback.xml` and `logback-quiet.xml`, and (b) fetches recent pod logs and asserts no DEBUG lines from `org.apache.zookeeper` or `org.eclipse.jetty` (so desired level INFO is applied), then deletes the cluster diff --git a/pkg/test/e2e/e2eutil/pod_util.go b/pkg/test/e2e/e2eutil/pod_util.go new file mode 100644 index 00000000..e8bc7f3e --- /dev/null +++ b/pkg/test/e2e/e2eutil/pod_util.go @@ -0,0 +1,82 @@ +/** + * Copyright (c) 2018 Dell Inc., or its subsidiaries. All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + */ + +package e2eutil + +import ( + "bytes" + "context" + "fmt" + "io" + + corev1 "k8s.io/api/core/v1" + "k8s.io/client-go/kubernetes" + "k8s.io/client-go/kubernetes/scheme" + restclient "k8s.io/client-go/rest" + "k8s.io/client-go/tools/remotecommand" +) + +// GetPodLogs returns recent logs from a pod's container. +// If opts is nil, default options (no tail limit) are used. +func GetPodLogs(ctx context.Context, config *restclient.Config, namespace, podName, containerName string, opts *corev1.PodLogOptions) (string, error) { + clientset, err := kubernetes.NewForConfig(config) + if err != nil { + return "", fmt.Errorf("create clientset: %w", err) + } + if opts == nil { + opts = &corev1.PodLogOptions{} + } + if containerName != "" { + opts.Container = containerName + } + req := clientset.CoreV1().Pods(namespace).GetLogs(podName, opts) + logStream, err := req.Stream(ctx) + if err != nil { + return "", fmt.Errorf("stream logs: %w", err) + } + defer logStream.Close() + var buf bytes.Buffer + _, err = io.Copy(&buf, logStream) + if err != nil { + return "", fmt.Errorf("read logs: %w", err) + } + return buf.String(), nil +} + +// PodExec runs a command in a pod container and returns stdout and stderr. +func PodExec(ctx context.Context, config *restclient.Config, namespace, podName, containerName string, command []string) (stdout, stderr string, err error) { + clientset, err := kubernetes.NewForConfig(config) + if err != nil { + return "", "", fmt.Errorf("create clientset: %w", err) + } + opts := &corev1.PodExecOptions{ + Container: containerName, + Command: command, + Stdout: true, + Stderr: true, + } + req := clientset.CoreV1().RESTClient().Post(). + Resource("pods").Namespace(namespace).Name(podName). + SubResource("exec"). + VersionedParams(opts, scheme.ParameterCodec) + exec, err := remotecommand.NewSPDYExecutor(config, "POST", req.URL()) + if err != nil { + return "", "", fmt.Errorf("create executor: %w", err) + } + var outBuf, errBuf bytes.Buffer + err = exec.StreamWithContext(ctx, remotecommand.StreamOptions{ + Stdout: &outBuf, + Stderr: &errBuf, + }) + if err != nil { + return outBuf.String(), errBuf.String(), fmt.Errorf("stream exec: %w", err) + } + return outBuf.String(), errBuf.String(), nil +} diff --git a/pkg/zk/generators.go b/pkg/zk/generators.go index f13ae37b..314a8776 100644 --- a/pkg/zk/generators.go +++ b/pkg/zk/generators.go @@ -229,6 +229,8 @@ func MakeConfigMap(z *v1beta1.ZookeeperCluster) *v1.ConfigMap { "zoo.cfg": makeZkConfigString(z), "log4j.properties": makeZkLog4JConfigString(), "log4j-quiet.properties": makeZkLog4JQuietConfigString(), + "logback.xml": makeZkLogbackConfigString(), + "logback-quiet.xml": makeZkLogbackQuietConfigString(), "env.sh": makeZkEnvConfigString(z), }, } @@ -300,6 +302,49 @@ func makeZkLog4JConfigString() string { "log4j.appender.CONSOLE.layout.ConversionPattern=%d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n\n" } +// makeZkLogbackConfigString returns logback.xml with root and key loggers at INFO +// so that ZooKeeper (which uses Logback at runtime) does not emit DEBUG. +func makeZkLogbackConfigString() string { + return ` + + + + %d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n + + + INFO + + + + + + + + +` +} + +// makeZkLogbackQuietConfigString returns logback-quiet.xml with root and key loggers at ERROR. +func makeZkLogbackQuietConfigString() string { + return ` + + + + %d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n + + + ERROR + + + + + + + + +` +} + func makeZkEnvConfigString(z *v1beta1.ZookeeperCluster) string { ports := z.ZookeeperPorts() return "#!/usr/bin/env bash\n\n" + diff --git a/pkg/zk/generators_test.go b/pkg/zk/generators_test.go index f545ddb5..290648de 100644 --- a/pkg/zk/generators_test.go +++ b/pkg/zk/generators_test.go @@ -144,6 +144,27 @@ var _ = Describe("Generators Spec", func() { }) }) + + Context("Logback config", func() { + It("should contain logback.xml and logback-quiet.xml in ConfigMap Data", func() { + Ω(cm.Data).To(HaveKey("logback.xml")) + Ω(cm.Data).To(HaveKey("logback-quiet.xml")) + }) + + It("should have logback.xml with root and loggers at INFO", func() { + cfg := cm.Data["logback.xml"] + Ω(cfg).To(ContainSubstring("")) + Ω(cfg).To(ContainSubstring("")) + Ω(cfg).To(ContainSubstring("")) + }) + + It("should have logback-quiet.xml with root and loggers at ERROR", func() { + cfg := cm.Data["logback-quiet.xml"] + Ω(cfg).To(ContainSubstring("")) + Ω(cfg).To(ContainSubstring("")) + Ω(cfg).To(ContainSubstring("")) + }) + }) }) Context("with overridden kubernetes cluster domain", func() { var cfg string diff --git a/test/e2e/logback_config_test.go b/test/e2e/logback_config_test.go new file mode 100644 index 00000000..2cf4aa3d --- /dev/null +++ b/test/e2e/logback_config_test.go @@ -0,0 +1,91 @@ +/** + * Copyright (c) 2018 Dell Inc., or its subsidiaries. All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + */ + +package e2e + +import ( + "strings" + + corev1 "k8s.io/api/core/v1" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" + zk_e2eutil "github.com/pravega/zookeeper-operator/pkg/test/e2e/e2eutil" +) + +// E2E test for Logback config: script copies operator-generated logback files to +// the runtime config dir, and the desired log level (INFO by default) is applied. +var _ = Describe("Logback config", func() { + Context("Script copies Logback files and desired log level is applied", func() { + It("should have logback files in runtime config dir and no DEBUG from ZooKeeper/Jetty when INFO is desired", func() { + By("creating Zookeeper cluster") + cluster := zk_e2eutil.NewDefaultCluster(testNamespace) + cluster.WithDefaults() + cluster.Status.Init() + cluster.Spec.Persistence.VolumeReclaimPolicy = "Delete" + + zk, err := zk_e2eutil.CreateCluster(logger, k8sClient, cluster) + Expect(err).NotTo(HaveOccurred()) + + podSize := 3 + Expect(zk_e2eutil.WaitForClusterToBecomeReady(logger, k8sClient, cluster, podSize)).NotTo(HaveOccurred()) + + By("fetching a running pod") + podList, err := zk_e2eutil.GetPods(k8sClient, zk) + Expect(err).NotTo(HaveOccurred()) + Expect(podList.Items).NotTo(BeEmpty()) + var pod *corev1.Pod + for i := range podList.Items { + p := &podList.Items[i] + if p.Status.Phase == corev1.PodRunning { + pod = p + break + } + } + Expect(pod).NotTo(BeNil(), "at least one pod should be Running") + + By("verifying startup script copied Logback files to runtime config dir") + stdout, stderr, err := zk_e2eutil.PodExec(ctx, cfg, zk.Namespace, pod.Name, "zookeeper", []string{"ls", "/data/conf"}) + Expect(err).NotTo(HaveOccurred(), "exec ls /data/conf: stdout=%q stderr=%q", stdout, stderr) + Expect(stdout).To(ContainSubstring("logback.xml"), "runtime config dir should contain logback.xml") + Expect(stdout).To(ContainSubstring("logback-quiet.xml"), "runtime config dir should contain logback-quiet.xml") + + By("verifying desired log level is applied (no DEBUG from ZooKeeper/Jetty when we expect INFO)") + logs, err := zk_e2eutil.GetPodLogs(ctx, cfg, zk.Namespace, pod.Name, "zookeeper", &corev1.PodLogOptions{TailLines: intPtr(200)}) + Expect(err).NotTo(HaveOccurred()) + // The main regression: when operator config asks for INFO, we must not see DEBUG from these packages. + // If DEBUG appears, Logback config was not discovered or not applied. + lines := strings.Split(logs, "\n") + var debugLines []string + for _, line := range lines { + if strings.Contains(line, " DEBUG ") && (strings.Contains(line, "org.apache.zookeeper") || strings.Contains(line, "org.eclipse.jetty")) { + debugLines = append(debugLines, strings.TrimSpace(line)) + } + } + Expect(debugLines).To(BeEmpty(), "desired level is INFO but found DEBUG from ZooKeeper/Jetty (config not applied): %v; logs (excerpt): %s", debugLines, truncate(logs, 1500)) + + By("deleting Zookeeper cluster") + Expect(k8sClient.Delete(ctx, zk)).Should(Succeed()) + Expect(zk_e2eutil.WaitForClusterToTerminate(logger, k8sClient, zk)).NotTo(HaveOccurred()) + }) + }) +}) + +func intPtr(n int) *int64 { + v := int64(n) + return &v +} + +func truncate(s string, max int) string { + if len(s) <= max { + return s + } + return s[:max] + "..." +}