PESDLC-1113 Copy logs from agent and RP pods #17772

savex · 2024-04-10T21:21:20Z

Take advantage of call to logs property and simulate DT log copy using streaming approach to eliminate huge memory consumptions.

Backports Required

Release Notes

none

savex · 2024-04-22T22:57:22Z

EC2 test run:

ubuntu@ip-172-31-4-5:~/tests$  cd /home/ubuntu/tests ; /usr/bin/env /opt/.ducktape-venv/bin/python3 /home/ubuntu/.vscode-server/extensions/ms-python.debugpy-2024.5.11001012-linux-x64/bundled/libs/debugpy/adapter/../../debugpy/launcher 48537 -- -m ducktape --compress --cluster=ducktape.cluster.json.JsonCluster --cluster-file=cluster.json --globals=globals.json --max-parallel=1 --repeat=1 --test-runner-timeout=86400000 rptest/redpanda_cloud_tests/cloud_self_test.py::SelfRedpandaCloudTest.test_healthy 
[INFO:2024-04-22 22:40:13,692]: starting test run with session id 2024-04-22--006...
[INFO:2024-04-22 22:40:13,692]: running 1 tests...
[INFO:2024-04-22 22:40:13,693]: Triggering test 1 of 1...
[INFO:2024-04-22 22:40:14,642]: RunnerClient: Loading test {'directory': '/home/ubuntu/redpanda/tests/rptest/redpanda_cloud_tests', 'file_name': 'cloud_self_test.py', 'cls_name': 'SelfRedpandaCloudTest', 'method_name': 'test_healthy', 'injected_args': None}
[INFO:2024-04-22 22:40:14,646]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: on run 1/1
[INFO:2024-04-22 22:40:14,968]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: Setting up...
[WARNING - 2024-04-22 22:40:18,650 - redpanda_cloud - create - lineno:899]: will not create cluster; already have cluster_id cojcnl1ai2dm17j4nqng
WARN [TBOT]      CLI parameters are overriding onboarding config from  config/config.go:472
INFO [TBOT]      Created directory "/tmp/tbot-data" config/destination_directory.go:132
INFO [TBOT]      Anonymous telemetry is not enabled. Find out more about Machine ID's anonymous telemetry at https://goteleport.com/docs/machine-id/reference/telemetry/ tbot/anonymous_telemetry.go:83
INFO [TBOT]      Attempting to generate new identity from token tbot/renew.go:510
INFO [AUTH]      Attempting registration via proxy server. auth/register.go:283
INFO [AUTH]      Attempting to register Bot with IAM method using regional STS endpoint auth/register.go:629
INFO [AUTH]      Successfully registered Bot with IAM method using regional STS endpoint auth/register.go:662
INFO [AUTH]      Successfully registered via proxy server. auth/register.go:290
INFO [TBOT]      Successfully generated new bot identity, valid: after=2024-04-22T22:39:20Z, before=2024-04-23T04:40:19Z, duration=6h0m59s | kind=tls, renewable=false, disallow-reissue=false, roles=[bot-buildkite-robot], principals=[-teleport-internal-join], generation=0 tbot/tbot.go:446
INFO [TBOT]      Beginning renewal loop: ttl=6h0m0s interval=6h0m0s tbot/renew.go:726
INFO [TBOT]      Started watching for CA rotations tbot/ca_rotation.go:173
INFO [TBOT]      Attempting to generate new identity from token tbot/renew.go:510
INFO [AUTH]      Attempting registration via proxy server. auth/register.go:283
INFO [AUTH]      Attempting to register Bot with IAM method using regional STS endpoint auth/register.go:629
INFO [AUTH]      Successfully registered Bot with IAM method using regional STS endpoint auth/register.go:662
INFO [AUTH]      Successfully registered via proxy server. auth/register.go:290
INFO [TBOT]      Successfully renewed bot certificates, valid: after=2024-04-22T22:39:22Z, before=2024-04-23T04:40:21Z, duration=6h0m59s | kind=tls, renewable=false, disallow-reissue=false, roles=[bot-buildkite-robot], principals=[-teleport-internal-join], generation=0 tbot/renew.go:634
INFO [TBOT]      Successfully renewed impersonated certificates for directory /tmp/machine-id, valid: after=2024-04-22T22:39:23Z, before=2024-04-23T04:40:23Z, duration=6h1m0s | kind=tls, renewable=false, disallow-reissue=true, roles=[teleport-admin], principals=[root redpanda {{internal.logins}} -teleport-internal-join], generation=0 tbot/renew.go:697
INFO [TBOT]      Persisted certificates successfully. One-shot mode enabled so exiting. tbot/renew.go:780
WARN [TBOT]      Context canceled during backoff for CA rotation watcher. Aborting. tbot/ca_rotation.go:139
=== kubectl already installed
=== k alias already created
=== k9s already installed
=== AWS VM detected. Running AWS specific configurations
=== k8s context already configured
=== grpcurl already installed
=== unzip already installed
=== rpk already installed
=== stern already installed
[INFO:2024-04-22 22:40:39,041]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: Running...
[WARNING - 2024-04-22 22:42:55,050 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[WARNING - 2024-04-22 22:42:55,050 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[WARNING - 2024-04-22 22:43:19,950 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[WARNING - 2024-04-22 22:43:19,950 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[WARNING - 2024-04-22 22:43:43,433 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[WARNING - 2024-04-22 22:43:43,434 - utils - _check_oversized_allocations - lineno:120]: Ignoring oversized allocation, 217088 is less than the max allowable allocation size of 409600 bytes
[INFO:2024-04-22 22:43:43,435]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: Tearing down...
[INFO:2024-04-22 22:43:43,437]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: PASS
[INFO:2024-04-22 22:43:43,438]: RunnerClient: rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy: Data: None
test_id:    rptest.redpanda_cloud_tests.cloud_self_test.SelfRedpandaCloudTest.test_healthy
status:     PASS
run time:   3 minutes 28.791 seconds
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
========================================================================================================================================================================================================================================================================================
SESSION REPORT (ALL TESTS)
ducktape version: 0.8.18
session_id:       2024-04-22--006
run time:         3 minutes 30.361 seconds
tests run:        1
passed:           1
flaky:            0
failed:           0
ignored:          0
opassed:          0
ofailed:          0
opassedfips:      0
ofailedfips:      0
========================================================================================================================================================================================================================================================================================
ubuntu@ip-172-31-4-5:~/tests$

savex · 2024-04-22T22:57:41Z

/ci-repeat 1

vbotbuildovich · 2024-04-23T01:23:47Z

new failures in https://buildkite.com/redpanda/redpanda/builds/48123#018f085c-7474-4b3e-b2ac-9d1bd0d8dae4:

"rptest.tests.full_disk_test.FullDiskReclaimTest.test_full_disk_triggers_gc"

new failures in https://buildkite.com/redpanda/redpanda/builds/48230#018f119a-6ef6-4e46-8a17-b7cbef6e856e:

"rptest.tests.rbac_upgrade_test.UpgradeMigrationCreatingDefaultRole.test_rbac_migration"

savex · 2024-04-24T18:30:57Z

/ci-repeat 1

vbotbuildovich · 2024-04-24T21:23:57Z

ducktape was retried in https://buildkite.com/redpanda/redpanda/builds/48230#018f11b9-e027-4032-843c-412a6f75cd07

ducktape was retried in https://buildkite.com/redpanda/redpanda/builds/48709#018f40f3-a1d2-4340-9aaa-98448686dddb

ducktape was retried in https://buildkite.com/redpanda/redpanda/builds/48709#018f40e3-aea2-40b8-8a37-2b638952338f

ducktape was retried in https://buildkite.com/redpanda/redpanda/builds/48856#018f5aa3-ebf1-4884-951e-bd3e87bc614b

ducktape was retried in https://buildkite.com/redpanda/redpanda/builds/48856#018f5df0-c8dd-447e-906a-0e826719a6a4

savex · 2024-04-25T22:56:32Z

/ci-repeat 1

savex · 2024-04-25T23:02:11Z

Linter error are from separate module and not related to this change

Run shfmt -i 2 -ci -s -d .
--- tests/docker/ducktape-deps/tinygo-wasi-transforms.orig
+++ tests/docker/ducktape-deps/tinygo-wasi-transforms
@@ -10,7 +10,7 @@
   local count=0
   until "$@"; do
     exit=$?
-    count=$(($count + 1))
+    count=$((count + 1))
     if [ $count -lt $retries ]; then
       echo "Retry $count/$retries exited $exit, retrying..."
     else
Error: Process completed with exit code 1.

savex · 2024-04-25T23:02:27Z

/ci-repeat 1

tests/rptest/clients/kubectl.py

travisdowns · 2024-04-29T14:37:09Z

tests/rptest/clients/kubectl.py

+            for line in process.stdout:  # type: ignore
+                yield line
+        except Exception as e:
+            raise RuntimeError(f'Failed to capture output') from e


What value does this exception chaining add? Actually I find the error confusing because it's not really the capture that failed in almost all cases but the process itself.

This is a way to show some helpful errors if a process failed with something meaningful.

Alas, there should be separate ticket/task to update this to return actual error from shell. Right now underlying error masks it under "return code 1" exception and this is useful when something wrong with the environment

tests/rptest/clients/kubectl.py

tests/rptest/services/utils.py

Implement simple class to track time and log milestones with ease.

Implement simple script that extracts specific log lines from rp log based on broker name and time.

To eliminate additional function call, just implement fake account class inside Cloud broker with similar functionality

To unify calls to node shell, put it inside CloudBroker class. This way actual shell pod could be left intact and not being created/deleted for each activity

Enable KubeNodeShell to be initialized in demand and clean when needed

Use CloudBroker initialization to inject script onto broker node

Copy agent logs first Then use ThreadPoolExecutor to copy logs from brokers Use stopwatch to track time

savex · 2024-05-03T20:00:10Z

Rebased with latest changes from @travisdowns on capture errors from cmd output

Also refactor capture cmd to support latest updates to cmd

tests/rptest/clients/kubectl.py

tests/rptest/remote_scripts/cloud/pod_log_extract.sh

jackietung-redpanda · 2024-05-08T16:30:19Z

tests/rptest/services/cloud_broker.py

@@ -16,6 +25,10 @@ def __init__(self, pod, kubectl, logger) -> None:
        self._meta = pod['metadata']
        self.name = self._meta['name']

+        # Backward compatibility
+        # Various classes will use this to hash and compare nodes
+        self.account(pod)


Why does this account need to be a class, that we instantiate?

Actually I don't really understand what is happening here at all :).

After this line, the CloudBroker object is unchanged right?

Looking further down, may be the intent is something like self.account = account(pod)?

No this is a mimic of ducktape mechanism that is defined here.

Ducktape uses separate class to define sophisticated way to do SSH to node and run commands: Linux_RemoteAccount. Since we need to be consistent with normal logs extraction when searching for errors inside them in raise_on_badlogs, we just defining fake class with one needed attribute: hostname which is consumed in multiple places as if it is duck-tape's node.account. class

Primary cause for this dance is here.

Class BafLogLines used in separate module and there was a discussion couple of weeks back not to overcomplicate it with inheritance (which was original solution)

tests/rptest/services/utils.py

savex requested review from travisdowns and rpdevmp April 10, 2024 21:21

savex marked this pull request as ready for review April 22, 2024 22:55

savex marked this pull request as draft April 23, 2024 17:16

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from 97ac409 to 5eaa5ef Compare April 24, 2024 14:25

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch 3 times, most recently from c72decb to 39550ff Compare April 25, 2024 22:51

savex marked this pull request as ready for review April 25, 2024 22:56

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from 21bdc15 to 53314a2 Compare April 26, 2024 14:34

savex requested a review from a team as a code owner April 26, 2024 14:34

travisdowns reviewed Apr 29, 2024

View reviewed changes

tests/rptest/clients/kubectl.py Outdated Show resolved Hide resolved

travisdowns reviewed Apr 29, 2024

View reviewed changes

tests/rptest/clients/kubectl.py Show resolved Hide resolved

travisdowns reviewed Apr 29, 2024

View reviewed changes

tests/rptest/services/utils.py Show resolved Hide resolved

savex requested a review from travisdowns April 29, 2024 21:51

savex added 6 commits May 3, 2024 14:38

PESDLC-1113 Add simple stopwatch class

a283869

Implement simple class to track time and log milestones with ease.

PESDLC-1113 Add log extraction script

bdbde60

Implement simple script that extracts specific log lines from rp log based on broker name and time.

PESDLC-1113 Mimic account class inside CloudBroker

fd3291e

To eliminate additional function call, just implement fake account class inside Cloud broker with similar functionality

PESDLC-1113 Move nodeshell inside Cloud Broker

95170ae

To unify calls to node shell, put it inside CloudBroker class. This way actual shell pod could be left intact and not being created/deleted for each activity

PESDLC-1113 Update KubeNodeShell with clean flag

c98dcf4

Enable KubeNodeShell to be initialized in demand and clean when needed

PESDLC-1113 Inject log extraction script on Broker init

ef6f810

Use CloudBroker initialization to inject script onto broker node

savex added 3 commits May 3, 2024 14:56

PESDLC-1113 Implement capture mode when running kubectl cmd

8e1d8bf

PESDLC-1113 Implement log copying

8af45d5

Copy agent logs first Then use ThreadPoolExecutor to copy logs from brokers Use stopwatch to track time

PESDLC-1113 Fix bash liter errors

b2e31f0

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from f0e51fc to 91d418b Compare May 3, 2024 19:59

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from 91d418b to 0cb51c8 Compare May 3, 2024 22:28

PESDLC-1113 Updated kubectl docstrings and Stopwatch logic.

97928f5

Also refactor capture cmd to support latest updates to cmd

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from 0cb51c8 to 97928f5 Compare May 3, 2024 22:44

jackietung-redpanda reviewed May 8, 2024

View reviewed changes

savex requested a review from jackietung-redpanda May 8, 2024 21:15

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from c074747 to 5ef6f10 Compare May 8, 2024 22:24

PESDLC-1113 Code review updates

a8909aa

savex force-pushed the PESDLC-1113-add-htt-logs-copy branch from 5ef6f10 to a8909aa Compare May 8, 2024 22:25

jackietung-redpanda approved these changes May 8, 2024

View reviewed changes

savex merged commit 1acaf9d into dev May 9, 2024
17 checks passed

savex deleted the PESDLC-1113-add-htt-logs-copy branch May 9, 2024 18:15

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PESDLC-1113 Copy logs from agent and RP pods #17772

PESDLC-1113 Copy logs from agent and RP pods #17772

savex commented Apr 10, 2024

savex commented Apr 22, 2024

savex commented Apr 22, 2024

vbotbuildovich commented Apr 23, 2024 •

edited

Loading

savex commented Apr 24, 2024

vbotbuildovich commented Apr 24, 2024 •

edited

Loading

savex commented Apr 25, 2024

savex commented Apr 25, 2024

savex commented Apr 25, 2024

travisdowns Apr 29, 2024

savex Apr 29, 2024

savex Apr 29, 2024

savex commented May 3, 2024

jackietung-redpanda May 8, 2024

savex May 8, 2024

savex May 8, 2024

PESDLC-1113 Copy logs from agent and RP pods #17772

PESDLC-1113 Copy logs from agent and RP pods #17772

Conversation

savex commented Apr 10, 2024

Backports Required

Release Notes

savex commented Apr 22, 2024

savex commented Apr 22, 2024

vbotbuildovich commented Apr 23, 2024 • edited Loading

savex commented Apr 24, 2024

vbotbuildovich commented Apr 24, 2024 • edited Loading

savex commented Apr 25, 2024

savex commented Apr 25, 2024

savex commented Apr 25, 2024

travisdowns Apr 29, 2024

Choose a reason for hiding this comment

savex Apr 29, 2024

Choose a reason for hiding this comment

savex Apr 29, 2024

Choose a reason for hiding this comment

savex commented May 3, 2024

jackietung-redpanda May 8, 2024

Choose a reason for hiding this comment

savex May 8, 2024

Choose a reason for hiding this comment

savex May 8, 2024

Choose a reason for hiding this comment

vbotbuildovich commented Apr 23, 2024 •

edited

Loading

vbotbuildovich commented Apr 24, 2024 •

edited

Loading