Skip to content

Commit ecc294c

Browse files
feat: Collect the containerdebug logs (#1106)
* feat: Collect the containerdebug logs * chore: Apply findings from other operators * chore: Upgrade serde-saphyr * chore: Revert downgrade of base64
1 parent d1154dc commit ecc294c

10 files changed

Lines changed: 637 additions & 22 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,8 @@ All notable changes to this project will be documented in this file.
1010
([#1086]).
1111
- BREAKING: Enable auto-purge feature for data directory cleanup ([#1068]).
1212
- Add `/ready` endpoint to the operator Deployment, which reports the CRD installation status ([#1090]).
13+
- The logs of the `containerdebug` process are now collected by the Vector agent and forwarded to
14+
the Vector aggregator ([#1106]).
1315

1416
### Changed
1517

@@ -49,6 +51,10 @@ All notable changes to this project will be documented in this file.
4951
See [our internal issue](https://github.com/stackabletech/hdfs-operator/issues/626) and [the fix](https://github.com/kube-rs/kube/pull/2042) for details ([#1070]).
5052
- The operator now watches all resources that it creates and early-exits the reconcile action when the
5153
cluster is marked for deletion ([#1079]).
54+
- The `containerdebug` process writes its log file again. The operator set
55+
`CONTAINERDEBUG_LOG_DIRECTORY`, which containerdebug stopped reading in its version 0.2.0 when it
56+
moved to `stackable-telemetry`; the directory is now set via `FILE_LOG_DIRECTORY`. The file is
57+
rotated hourly and at most two files are kept, because rotation is opt-in ([#1106]).
5258

5359
[#1053]: https://github.com/stackabletech/zookeeper-operator/pull/1053
5460
[#1060]: https://github.com/stackabletech/zookeeper-operator/pull/1060
@@ -68,6 +74,7 @@ All notable changes to this project will be documented in this file.
6874
[#1100]: https://github.com/stackabletech/zookeeper-operator/pull/1100
6975
[#1101]: https://github.com/stackabletech/zookeeper-operator/pull/1101
7076
[#1102]: https://github.com/stackabletech/zookeeper-operator/pull/1102
77+
[#1106]: https://github.com/stackabletech/zookeeper-operator/pull/1106
7178

7279
## [26.7.0] - 2026-07-21
7380

‎Cargo.lock‎

Lines changed: 2 additions & 2 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎Cargo.nix‎

Lines changed: 2 additions & 2 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎docs/modules/zookeeper/pages/usage_guide/log_aggregation.adoc‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,4 +26,12 @@ spec:
2626
replicas: 1
2727
----
2828

29+
NOTE: The logs of the xref:concepts:observability/containerdebug.adoc[`containerdebug` process] are collected as well.
30+
They are labelled `container: containerdebug`, although no such Kubernetes container exists.
31+
The process runs in the background of the `zookeeper` container.
32+
The label comes from `/stackable/log/containerdebug`, the directory which the operator sets with the `FILE_LOG_DIRECTORY` environment variable and from which the Vector agent derives the container name.
33+
Overriding `FILE_LOG_DIRECTORY` with `envOverrides` therefore changes how these logs are aggregated.
34+
The agent only collects files one level below `/stackable/log`, so a sibling directory such as `/stackable/log/zookeeper` relabels the events instead of dropping them, while any deeper or shallower path stops the aggregation.
35+
A path outside `/stackable/log` also leaves the size-capped log volume.
36+
2937
Further information on how to configure logging, can be found in xref:concepts:logging.adoc[].

‎rust/operator-binary/src/zk_controller/build/properties/product_logging/mod.rs‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,5 +80,7 @@ mod tests {
8080
// ZooKeeper's logback writes log4j-format XML to `*.log4j.xml`, so the `files_log4j`
8181
// source matches it.
8282
assert!(content.contains("files_log4j"));
83+
assert!(content.contains("files_tracing_rs"));
84+
assert!(content.contains("*.tracing-rs.json"));
8385
}
8486
}

‎rust/operator-binary/src/zk_controller/build/properties/product_logging/vector-test.yaml‎

Lines changed: 279 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -137,6 +137,285 @@ tests:
137137
"timestamp": t'2025-10-02T09:27:28.582Z'
138138
}
139139
140+
assert_eq!(expected_log_event, .)
141+
- name: Test tracing-rs log
142+
inputs:
143+
- type: log
144+
insert_at: processed_files_tracing_rs
145+
log_fields:
146+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
147+
message: '{"timestamp":"2026-11-02T14:49:28.028922Z","level":"INFO","fields":{"message":"found disk","disk.name":"overlay"},"target":"containerdebug::system_information::disk"}'
148+
pod: test-zk-server-default-0
149+
source_type: file
150+
timestamp: 2026-11-02T14:49:29.473487331Z
151+
outputs:
152+
- extract_from: extended_logs
153+
expected_event_count: 1
154+
conditions:
155+
- type: vrl
156+
source: |
157+
expected_log_event = {
158+
"cluster": "test-zk",
159+
"container": "containerdebug",
160+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
161+
"level": "INFO",
162+
"logger": "containerdebug::system_information::disk",
163+
"message": "found disk\n\ndisk.name=overlay",
164+
"timestamp": t'2026-11-02T14:49:28.028922Z',
165+
"namespace": "default",
166+
"pod": "test-zk-server-default-0",
167+
"role": "server",
168+
"roleGroup": "default"
169+
}
170+
171+
assert_eq!(expected_log_event, .)
172+
- name: Test unparsable tracing-rs log
173+
inputs:
174+
- type: log
175+
insert_at: processed_files_tracing_rs
176+
log_fields:
177+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
178+
message: '{ unparsable'
179+
pod: test-zk-server-default-0
180+
source_type: file
181+
timestamp: 2026-11-02T14:49:29.473487331Z
182+
outputs:
183+
- extract_from: extended_logs
184+
expected_event_count: 1
185+
conditions:
186+
- type: vrl
187+
source: |
188+
expected_log_event = {
189+
"cluster": "test-zk",
190+
"container": "containerdebug",
191+
"errors": [
192+
.errors[0]
193+
],
194+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
195+
"level": "INFO",
196+
"logger": "",
197+
"message": "{ unparsable",
198+
"timestamp": .timestamp,
199+
"namespace": "default",
200+
"pod": "test-zk-server-default-0",
201+
"role": "server",
202+
"roleGroup": "default"
203+
}
204+
205+
assert_eq!(expected_log_event, .)
206+
207+
# The remainder of the message contains character offsets into
208+
# the VRL source, so only the stable prefix is asserted.
209+
assert!(starts_with!(.errors[0], "JSON not parsable: "))
210+
- name: Test tracing-rs log which is not a JSON object
211+
inputs:
212+
- type: log
213+
insert_at: processed_files_tracing_rs
214+
log_fields:
215+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
216+
message: 'false'
217+
pod: test-zk-server-default-0
218+
source_type: file
219+
timestamp: 2026-11-02T14:49:29.473487331Z
220+
outputs:
221+
- extract_from: extended_logs
222+
expected_event_count: 1
223+
conditions:
224+
- type: vrl
225+
source: |
226+
expected_log_event = {
227+
"cluster": "test-zk",
228+
"container": "containerdebug",
229+
"errors": [
230+
"Parsed event is not a JSON object."
231+
],
232+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
233+
"level": "INFO",
234+
"logger": "",
235+
"message": "false",
236+
"timestamp": .timestamp,
237+
"namespace": "default",
238+
"pod": "test-zk-server-default-0",
239+
"role": "server",
240+
"roleGroup": "default"
241+
}
242+
243+
assert_eq!(expected_log_event, .)
244+
- name: Test tracing-rs log with invalid fields
245+
inputs:
246+
- type: log
247+
insert_at: processed_files_tracing_rs
248+
log_fields:
249+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
250+
message: '{"timestamp":"unparsable","level":"INVALID","fields":"none","target":null}'
251+
pod: test-zk-server-default-0
252+
source_type: file
253+
timestamp: 2026-11-02T14:49:29.473487331Z
254+
outputs:
255+
- extract_from: extended_logs
256+
expected_event_count: 1
257+
conditions:
258+
- type: vrl
259+
source: |
260+
expected_log_event = {
261+
"cluster": "test-zk",
262+
"container": "containerdebug",
263+
"errors": [
264+
.errors[0],
265+
"Logger/target not found.",
266+
"Level \"INVALID\" unknown, using \"INFO\" instead.",
267+
"Fields are not an object."
268+
],
269+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
270+
"level": "INFO",
271+
"logger": "",
272+
"message": "{\"timestamp\":\"unparsable\",\"level\":\"INVALID\",\"fields\":\"none\",\"target\":null}",
273+
"timestamp": .timestamp,
274+
"namespace": "default",
275+
"pod": "test-zk-server-default-0",
276+
"role": "server",
277+
"roleGroup": "default"
278+
}
279+
280+
assert_eq!(expected_log_event, .)
281+
282+
# The remainder of the message contains character offsets into
283+
# the VRL source, so only the stable prefix is asserted.
284+
assert!(starts_with!(.errors[0], "Timestamp not parsable, using current time instead: "))
285+
- name: Test tracing-rs log without a timestamp
286+
inputs:
287+
- type: log
288+
insert_at: processed_files_tracing_rs
289+
log_fields:
290+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
291+
message: '{"level":"INFO","fields":{"message":"found disk"},"target":"containerdebug::system_information::disk"}'
292+
pod: test-zk-server-default-0
293+
source_type: file
294+
timestamp: 2026-11-02T14:49:29.473487331Z
295+
outputs:
296+
- extract_from: extended_logs
297+
expected_event_count: 1
298+
conditions:
299+
- type: vrl
300+
source: |
301+
expected_log_event = {
302+
"cluster": "test-zk",
303+
"container": "containerdebug",
304+
"errors": [
305+
"Timestamp not found, using current time instead."
306+
],
307+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
308+
"level": "INFO",
309+
"logger": "containerdebug::system_information::disk",
310+
"message": "found disk",
311+
"timestamp": .timestamp,
312+
"namespace": "default",
313+
"pod": "test-zk-server-default-0",
314+
"role": "server",
315+
"roleGroup": "default"
316+
}
317+
318+
assert_eq!(expected_log_event, .)
319+
320+
# The current time is used and not the timestamp which the file
321+
# source attached to the event. The latter reaches the transform
322+
# as a string, whereas now() yields a timestamp.
323+
assert!(is_timestamp(.timestamp))
324+
- name: Test tracing-rs log without a message but with other fields
325+
inputs:
326+
- type: log
327+
insert_at: processed_files_tracing_rs
328+
log_fields:
329+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
330+
message: '{"timestamp":"2026-11-02T14:49:28.028922Z","level":"INFO","fields":{"disk.name":"overlay"},"target":"containerdebug::system_information::disk"}'
331+
pod: test-zk-server-default-0
332+
source_type: file
333+
timestamp: 2026-11-02T14:49:29.473487331Z
334+
outputs:
335+
- extract_from: extended_logs
336+
expected_event_count: 1
337+
conditions:
338+
- type: vrl
339+
source: |
340+
expected_log_event = {
341+
"cluster": "test-zk",
342+
"container": "containerdebug",
343+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
344+
"level": "INFO",
345+
"logger": "containerdebug::system_information::disk",
346+
"message": "disk.name=overlay",
347+
"timestamp": t'2026-11-02T14:49:28.028922Z',
348+
"namespace": "default",
349+
"pod": "test-zk-server-default-0",
350+
"role": "server",
351+
"roleGroup": "default"
352+
}
353+
354+
assert_eq!(expected_log_event, .)
355+
- name: Test tracing-rs log with a message which is not a string
356+
inputs:
357+
- type: log
358+
insert_at: processed_files_tracing_rs
359+
log_fields:
360+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
361+
message: '{"timestamp":"2026-11-02T14:49:28.028922Z","level":"INFO","fields":{"message":42,"disk.name":"overlay"},"target":"containerdebug::system_information::disk"}'
362+
pod: test-zk-server-default-0
363+
source_type: file
364+
timestamp: 2026-11-02T14:49:29.473487331Z
365+
outputs:
366+
- extract_from: extended_logs
367+
expected_event_count: 1
368+
conditions:
369+
- type: vrl
370+
source: |
371+
expected_log_event = {
372+
"cluster": "test-zk",
373+
"container": "containerdebug",
374+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
375+
"level": "INFO",
376+
"logger": "containerdebug::system_information::disk",
377+
"message": "disk.name=overlay\nmessage=42",
378+
"timestamp": t'2026-11-02T14:49:28.028922Z',
379+
"namespace": "default",
380+
"pod": "test-zk-server-default-0",
381+
"role": "server",
382+
"roleGroup": "default"
383+
}
384+
385+
assert_eq!(expected_log_event, .)
386+
- name: Test tracing-rs log without any fields
387+
inputs:
388+
- type: log
389+
insert_at: processed_files_tracing_rs
390+
log_fields:
391+
file: /stackable/log/containerdebug/containerdebug.2026-11-02-14.tracing-rs.json
392+
message: '{"timestamp":"2026-11-02T14:49:28.028922Z","level":"INFO","fields":{},"target":"containerdebug::system_information::disk"}'
393+
pod: test-zk-server-default-0
394+
source_type: file
395+
timestamp: 2026-11-02T14:49:29.473487331Z
396+
outputs:
397+
- extract_from: extended_logs
398+
expected_event_count: 1
399+
conditions:
400+
- type: vrl
401+
source: |
402+
expected_log_event = {
403+
"cluster": "test-zk",
404+
"container": "containerdebug",
405+
"errors": [
406+
"Message not found."
407+
],
408+
"file": "containerdebug.2026-11-02-14.tracing-rs.json",
409+
"level": "INFO",
410+
"logger": "containerdebug::system_information::disk",
411+
"message": "",
412+
"timestamp": t'2026-11-02T14:49:28.028922Z',
413+
"namespace": "default",
414+
"pod": "test-zk-server-default-0",
415+
"role": "server",
416+
"roleGroup": "default"
417+
}
418+
140419
assert_eq!(expected_log_event, .)
141420
- name: Test Vector internal logs
142421
inputs:

0 commit comments

Comments
 (0)