Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Streams deployment task logs if there is only one task #436

Merged
merged 1 commit into from
Mar 15, 2019
Merged

Streams deployment task logs if there is only one task #436

merged 1 commit into from
Mar 15, 2019

Conversation

benlangfeld
Copy link
Contributor

@benlangfeld benlangfeld commented Mar 1, 2019 •
edited
Loading

Closes #346

I have not attempted any sort of implementation for the case where multiple tasks exist in a deployment, but even with the simple case of a single task, I'm unsure how this would be tested. I'd appreciate it if someone would point me in the right direction.

The best idea I've had so far is to use a fixture where the pod prints some output over several seconds, and assert that the logs reflect this in the timestamps at the beginning of each line. Indeed, if I do this and run the test with PRINT_LOGS=1, I can see that it works. Anyone have a better idea?

dturn
dturn reviewed Mar 1, 2019
View reviewed changes
Copy link
Contributor

@dturn dturn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for working on this! This is a feature I'm excited about. So looking at some outputs:
(without this change)

 > PRINT_LOGS=1 rt test/integration/kubernetes_deploy_test.rb -n /test_service_account_predeployed_before_unmanaged_pod/

...
[INFO][2019-03-01 09:50:47 -0800]	------------------------------Phase 3: Predeploying priority resources------------------------------
[INFO][2019-03-01 09:50:47 -0800]	Deploying ConfigMap/hello-cloud-configmap-data (timeout: 30s)
[INFO][2019-03-01 09:50:48 -0800]	Successfully deployed in 0.3s: ConfigMap/hello-cloud-configmap-data
[INFO][2019-03-01 09:50:48 -0800]	
[INFO][2019-03-01 09:50:48 -0800]	Deploying ServiceAccount/build-robot (timeout: 30s)
[INFO][2019-03-01 09:50:48 -0800]	Successfully deployed in 0.3s: ServiceAccount/build-robot
[INFO][2019-03-01 09:50:48 -0800]	
[INFO][2019-03-01 09:50:48 -0800]	Deploying Pod/unmanaged-pod-k52d1dce-58bb206e (timeout: 60s)
[INFO][2019-03-01 09:50:51 -0800]	Logs from Pod/unmanaged-pod-k52d1dce-58bb206e container 'hello-cloud':
[INFO][2019-03-01 09:50:51 -0800]		Hello from the command runner!
[INFO][2019-03-01 09:50:51 -0800]	
[INFO][2019-03-01 09:50:51 -0800]	Successfully deployed in 3.4s: Pod/unmanaged-pod-k52d1dce-58bb206e
...

vs
(with this change)

 > PRINT_LOGS=1 rt test/integration/kubernetes_deploy_test.rb -n /test_service_account_predeployed_before_unmanaged_pod/

...
[INFO][2019-03-01 09:57:44 -0800]	------------------------------Phase 3: Predeploying priority resources------------------------------
[INFO][2019-03-01 09:57:44 -0800]	Deploying ConfigMap/hello-cloud-configmap-data (timeout: 30s)
[INFO][2019-03-01 09:57:44 -0800]	Successfully deployed in 0.3s: ConfigMap/hello-cloud-configmap-data
[INFO][2019-03-01 09:57:44 -0800]	
[INFO][2019-03-01 09:57:44 -0800]	Deploying ServiceAccount/build-robot (timeout: 30s)
[INFO][2019-03-01 09:57:45 -0800]	Successfully deployed in 0.3s: ServiceAccount/build-robot
[INFO][2019-03-01 09:57:45 -0800]	
[INFO][2019-03-01 09:57:45 -0800]	Deploying Pod/unmanaged-pod-k51f10ac-43e7e9e6 (timeout: 60s)
[INFO][2019-03-01 09:57:48 -0800]	Hello from the command runner!
[INFO][2019-03-01 09:57:48 -0800]	Successfully deployed in 3.4s: Pod/unmanaged-pod-k51f10ac-43e7e9e6
[INFO][2019-03-01 09:57:48 -0800]	

...

There is a line Logs from Pod/unmanaged-pod-k52d1dce-58bb206e container 'hello-cloud': that gets lost in the streaming version. It's from RemoteLogs#print_all. Once idea to look at if is if we could have the first call to RemoteLogs#print_latest emit something similar but like: Streaming logs from Pod/unmanaged-pod-k52d1dce-58bb206e container 'hello-cloud': . Then we could test for that line. Now its not exactly that simple since we'd need to make sure the output from the task runner (see PRINT_LOGS=1 rt test/integration/runner_task_test.rb -n /test_run_with_verify_result_success/ ) is still reasonable.

lib/kubernetes-deploy/deploy_task.rb Outdated Show resolved Hide resolved
@benlangfeld
Copy link
Contributor Author 

[INFO][2019-03-01 16:31:21 -0300]       ------------------------------------Phase 1: Initializing deploy------------------------------------
[INFO][2019-03-01 16:31:22 -0300]       Context minikube found
[INFO][2019-03-01 16:31:22 -0300]       Namespace k8sdeploy-test-service-account-predeployed-bef-5bda741b20f5ae34 found
[INFO][2019-03-01 16:31:22 -0300]       All required parameters and files are present
[INFO][2019-03-01 16:31:22 -0300]       Discovering templates:
[INFO][2019-03-01 16:31:22 -0300]         - Pod/unmanaged-pod-k995a259-fbc8980b
[INFO][2019-03-01 16:31:22 -0300]         - ServiceAccount/build-robot
[INFO][2019-03-01 16:31:22 -0300]         - ConfigMap/hello-cloud-configmap-data
[INFO][2019-03-01 16:31:23 -0300]
[INFO][2019-03-01 16:31:23 -0300]       ----------------------------Phase 2: Checking initial resource statuses-----------------------------
[INFO][2019-03-01 16:31:23 -0300]       Pod/unmanaged-pod-k995a259-fbc8980b               Unknown
[INFO][2019-03-01 16:31:23 -0300]       ServiceAccount/build-robot                        Not Found
[INFO][2019-03-01 16:31:23 -0300]       ConfigMap/hello-cloud-configmap-data              Not Found
[INFO][2019-03-01 16:31:23 -0300]
[INFO][2019-03-01 16:31:23 -0300]       ------------------------------Phase 3: Predeploying priority resources------------------------------
[INFO][2019-03-01 16:31:23 -0300]       Deploying ConfigMap/hello-cloud-configmap-data (timeout: 30s)
[INFO][2019-03-01 16:31:23 -0300]       Successfully deployed in 0.4s: ConfigMap/hello-cloud-configmap-data
[INFO][2019-03-01 16:31:23 -0300]
[INFO][2019-03-01 16:31:23 -0300]       Deploying ServiceAccount/build-robot (timeout: 30s)
[INFO][2019-03-01 16:31:24 -0300]       Successfully deployed in 0.4s: ServiceAccount/build-robot
[INFO][2019-03-01 16:31:24 -0300]
[INFO][2019-03-01 16:31:24 -0300]       Deploying Pod/unmanaged-pod-k995a259-fbc8980b (timeout: 60s)
[INFO][2019-03-01 16:31:24 -0300]       Streaming logs from Pod/unmanaged-pod-k995a259-fbc8980b container 'hello-cloud':
[INFO][2019-03-01 16:31:27 -0300]       Hello from the command runner!
[INFO][2019-03-01 16:31:27 -0300]       Successfully deployed in 3.6s: Pod/unmanaged-pod-k995a259-fbc8980b
[INFO][2019-03-01 16:31:27 -0300]
[INFO][2019-03-01 16:31:27 -0300]
[INFO][2019-03-01 16:31:27 -0300]       ----------------------------------Phase 4: Deploying all resources----------------------------------
[INFO][2019-03-01 16:31:27 -0300]       Deploying resources:
[INFO][2019-03-01 16:31:27 -0300]       - Pod/unmanaged-pod-k995a259-fbc8980b (timeout: 60s)
[INFO][2019-03-01 16:31:27 -0300]       - ServiceAccount/build-robot (timeout: 30s)
[INFO][2019-03-01 16:31:27 -0300]       - ConfigMap/hello-cloud-configmap-data (timeout: 30s)
[INFO][2019-03-01 16:31:28 -0300]       Successfully deployed in 0.7s: Pod/unmanaged-pod-k995a259-fbc8980b, ServiceAccount/build-robot, ConfigMap/hello-cloud-configmap-data
[INFO][2019-03-01 16:31:28 -0300]
[INFO][2019-03-01 16:31:28 -0300]       ------------------------------------------Result: SUCCESS-------------------------------------------
[INFO][2019-03-01 16:31:28 -0300]       Successfully deployed 3 resources
[INFO][2019-03-01 16:31:28 -0300]
[INFO][2019-03-01 16:31:28 -0300]       Successful resources
[INFO][2019-03-01 16:31:28 -0300]       Pod/unmanaged-pod-k995a259-fbc8980b               Succeeded
[INFO][2019-03-01 16:31:28 -0300]       ServiceAccount/build-robot                        Created
[INFO][2019-03-01 16:31:28 -0300]       ConfigMap/hello-cloud-configmap-data              Available

[INFO][2019-03-01 16:30:55 -0300]       -------------------------------------Phase 1: Initializing task-------------------------------------
[INFO][2019-03-01 16:30:55 -0300]       Validating configuration
[INFO][2019-03-01 16:30:55 -0300]       Using namespace 'k8sdeploy-test-run-with-verify-result-success-b05621642456a99b' in context 'minikube'
[INFO][2019-03-01 16:30:55 -0300]       Using template 'hello-cloud-template-runner'
[INFO][2019-03-01 16:30:55 -0300]
[INFO][2019-03-01 16:30:55 -0300]       ----------------------------------------Phase 2: Running pod----------------------------------------
[INFO][2019-03-01 16:30:55 -0300]       Creating pod 'task-runner-224354af870c884c'
[INFO][2019-03-01 16:30:55 -0300]       Pod creation succeeded
[INFO][2019-03-01 16:30:55 -0300]
[INFO][2019-03-01 16:30:55 -0300]       --------------------------------------Phase 3: Streaming logs---------------------------------------
[INFO][2019-03-01 16:30:56 -0300]       Streaming logs from Pod/task-runner-224354af870c884c container 'task-runner':
[INFO][2019-03-01 16:30:59 -0300]       Line 1
[INFO][2019-03-01 16:30:59 -0300]       Line 2
[INFO][2019-03-01 16:30:59 -0300]       Line 3
[INFO][2019-03-01 16:30:59 -0300]       Line 4
[INFO][2019-03-01 16:30:59 -0300]       Line 5
[INFO][2019-03-01 16:30:59 -0300]       Line 6
[INFO][2019-03-01 16:30:59 -0300]       Line 7
[INFO][2019-03-01 16:30:59 -0300]       Line 8
[INFO][2019-03-01 16:31:01 -0300]       Successfully ran in 5.3s: Pod/task-runner-224354af870c884c
[INFO][2019-03-01 16:31:01 -0300]
[INFO][2019-03-01 16:31:01 -0300]       ------------------------------------------Result: SUCCESS-------------------------------------------
[INFO][2019-03-01 16:31:01 -0300]       Successfully ran 1 resource
[INFO][2019-03-01 16:31:01 -0300]
[INFO][2019-03-01 16:31:01 -0300]       Successful resources
[INFO][2019-03-01 16:31:01 -0300]       Pod/task-runner-224354af870c884c                  Succeeded

dturn
dturn reviewed Mar 1, 2019
View reviewed changes
Copy link
Contributor

@dturn dturn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this looks solid

lib/kubernetes-deploy/container_logs.rb Outdated Show resolved Hide resolved
lib/kubernetes-deploy/deploy_task.rb Show resolved Hide resolved
dturn
dturn reviewed Mar 6, 2019
View reviewed changes
Copy link
Contributor

@dturn dturn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just about done. Thanks for sticking with this.

test/integration/kubernetes_deploy_test.rb Show resolved Hide resolved
test/integration/kubernetes_deploy_test.rb Show resolved Hide resolved
@benlangfeld benlangfeld force-pushed the stream-pod-logs branch 4 times, most recently from 66476f2 to d4b8524 Compare March 14, 2019 20:00
dturn
dturn approved these changes Mar 14, 2019
View reviewed changes
Copy link
Contributor

@dturn dturn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's a bit hard to read due to the rebsae. But looks good

@benlangfeld
Copy link
Contributor Author

Rebased for the last time since #441 was merged. Should be good to go.

timothysmith0609
timothysmith0609 approved these changes Mar 15, 2019
View reviewed changes
Copy link
Contributor

@timothysmith0609 timothysmith0609 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Testing this locally is working as expected and nothing is jumping out at me for comment

@dturn dturn merged commit e0f4aeb into Shopify:master Mar 15, 2019
@benlangfeld benlangfeld deleted the stream-pod-logs branch March 18, 2019 12:38
@timothysmith0609 timothysmith0609 temporarily deployed to rubygems March 27, 2019 16:53 Inactive
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@KnVerey KnVerey KnVerey left review comments

@timothysmith0609 timothysmith0609 timothysmith0609 approved these changes

@dturn dturn dturn approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

Stream task runner pods during deploys
4 participants
@benlangfeld @KnVerey @dturn @timothysmith0609