Retain process logs on robustness tests #16077

tjungblu · 2023-06-14T08:24:42Z

Adding a new flag to retain e2e etcd process logs after stop and saving next to the visualized model.

Spun out of #16018 where I used it for easier local debugging on model violations.

Please read https://github.com/etcd-io/etcd/blob/main/CONTRIBUTING.md#contribution-flow.

serathius · 2023-06-14T09:55:56Z

Etcd logs are available the same way as e2e logs. By passing EXPECT_DEBUG=true flag to the test run.

tjungblu · 2023-06-14T10:23:59Z

Etcd logs are available the same way as e2e logs. By passing EXPECT_DEBUG=true flag to the test run.

If you feel like browsing the logs is convenient enough already I'm happy to close. For me it makes more sense to have the member debug logs next to the history.html in the artifacts zip.

tests/framework/e2e/etcd_process.go

serathius · 2023-06-14T10:34:02Z

If you feel like browsing the logs is convenient enough already I'm happy to close. For me it makes more sense to have the member debug logs next to the history.html in the artifacts zip.

It's not #15079

tests/framework/e2e/etcd_process.go

serathius · 2023-06-14T11:45:58Z

FYI main challenge here is to merge logs from between server restarts.

tjungblu · 2023-06-14T14:18:13Z

@serathius created an aggregation of LogExpects to merge the logs. Let me know if the implemented behavior works for you, too (mostly on the expect side of things).

serathius · 2023-06-14T20:13:59Z

tests/framework/e2e/etcd_process.go

@@ -230,7 +233,7 @@ func (ep *EtcdServerProcess) Config() *EtcdServerProcessConfig { return ep.cfg }

 func (ep *EtcdServerProcess) Logs() LogsExpect {


Code looks nice, but changing func (ep *EtcdServerProcess) Logs() LogsExpect semantic behavior is risky. When I expect most people will assume member.Logs().ExpectWithContext() will analyse logs emitted from the current run and might stumble on problem that log they are expecting was already emitted before restart.

Proposal:

Have func (ep *EtcdServerProcess) Logs() LogsExpect return logsExpect from the latest run ep.logs.procLogs[len(ep.logs.procLogs)-1]

Have a separate method like allLogLines or aggregatedLogLines etcd that will return appended results of all runs.

What do you think?

Agreed with the incremental changes to be safe.

func (ep *EtcdServerProcess) Logs() LogsExpect was using ep.proc in happy case and most of the cases.

The PR is intended to retain all the previous runs logs after all the runs of the process are stopped.

Seems only func (m *multiLogsExpect) Lines() is needed.

Have func (ep *EtcdServerProcess) Logs() LogsExpect return logsExpect from the latest run ep.logs.procLogs[len(ep.logs.procLogs)-1]

Sounds like a good proposal to me. Is that also acceptable for you @chaochn47?

Seems only func (m *multiLogsExpect) Lines() is needed.

Currently yes, I'm surprised we don't have expect tests across stop/restart scenarios.

I pushed a slight alternative as a new commit, while the process is running it will return the running LogsExpect, otherwise the last one from the multiLogsExpect.

Looking into the dependencies of the Lines method we could also split the interface in two, one for the Lines+Count and one for the expect to leave the current code paths untouched. There's only a zap test depending on the lines of a given process.

Currently yes, I'm surprised we don't have expect tests across stop/restart scenarios.

We want to explicitly avoid that because it not natural. Imagine that you want to check that etcd member has started using one of the starting logs. It's natural to call member.Logs().Expect("etcd started"), but it needs to only consider the logs from the last restart to make sense. Otherwise it might always return true when member was already restarted.

tldr. Don't want to change the semantics of func (ep *EtcdServerProcess) Logs() LogsExpect.

Cool, pushed another by just moving up the Lines and Count via interface, so the current LogsExpect stays entirely untouched.

Adding a set of functions which retain e2e etcd process logs after stop and saving next to the visualized model during robustness tests. Spun out of etcd-io#16018 where I used it for easier local debugging on model violations. Fixes etcd-io#15079 partially. Signed-off-by: Thomas Jungblut <tjungblu@redhat.com>

serathius · 2023-06-15T12:52:31Z

tests/framework/e2e/etcd_process.go

+	return ep.logs.Lines()
+}
+
+func (ep *EtcdServerProcess) LineCount() int {


Doesn't looks like it's used by anyone. Remove?

just two places ultimately: https://github.com/search?q=repo%3Aetcd-io%2Fetcd%20LineCount&type=code

but looks like it could be removed

I mean it's not needed for EtcdServerProcess.

serathius · 2023-06-15T12:56:12Z

tests/framework/e2e/etcd_process.go

@@ -235,6 +242,14 @@ func (ep *EtcdServerProcess) Logs() LogsExpect {
 	return ep.proc
 }

+func (ep *EtcdServerProcess) Lines() []string {


Proposed interface member.Logs() and member.Lines() seems unnatural. Recommendation:

Rename member.Logs() to member.ProcessLogs() to inform that those logs come only from the started process.

Rename member.Lines() to member.DumpLogs().

serathius · 2023-06-15T12:56:31Z

tests/framework/e2e/etcd_process.go

@@ -72,6 +77,7 @@ type EtcdServerProcess struct {
 	proxy      proxy.Server
 	failpoints *BinaryFailpoints
 	donec      chan struct{} // closed when Interact() terminates
+	logs       *procLogs


Suggested change

logs *procLogs

logs procLogs

It doesn't need to be a pointer.

serathius · 2023-06-15T12:57:42Z

tests/framework/e2e/etcd_process.go

@@ -235,6 +242,14 @@ func (ep *EtcdServerProcess) Logs() LogsExpect {
 	return ep.proc
 }

+func (ep *EtcdServerProcess) Lines() []string {
+	return ep.logs.Lines()


I find it pretty unnatural that calling member.Lines() will not return me any log lines until the process has exited.

serathius · 2023-06-15T12:59:31Z

tests/framework/e2e/etcd_process.go

@@ -378,3 +393,20 @@ func GetVersionFromBinary(binaryPath string) (*semver.Version, error) {

 	return nil, fmt.Errorf("could not find version in binary output of %s, lines outputted were %v", binaryPath, lines)
 }
+
+type procLogs struct {


Don't think the name makes sense. Does "proc" refer to process or something else? As this merges log lines from multiple process lines it's definitely not processLogs.

serathius · 2023-06-15T12:59:50Z

tests/framework/e2e/etcd_process.go

@@ -378,3 +393,20 @@ func GetVersionFromBinary(binaryPath string) (*semver.Version, error) {

 	return nil, fmt.Errorf("could not find version in binary output of %s, lines outputted were %v", binaryPath, lines)
 }
+
+type procLogs struct {
+	procLogs []string


You know you don't need to create struct just have type logs []string ?

serathius · 2023-06-15T15:10:49Z

Also, please remove environment EXPECT_DEBUG from the Robustness tests github workflow.

stale · 2023-09-17T01:16:30Z

This issue has been automatically marked as stale because it has not had recent activity. It will be closed after 21 days if no further activity occurs. Thank you for your contributions.

k8s-ci-robot · 2024-08-05T22:49:16Z

@tjungblu: The following tests failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name	Commit	Details	Required	Rerun command
pull-etcd-verify	`b5cdfc0`	link	true	`/test pull-etcd-verify`
pull-etcd-unit-test-amd64	`b5cdfc0`	link	true	`/test pull-etcd-unit-test-amd64`
pull-etcd-unit-test-arm64	`b5cdfc0`	link	true	`/test pull-etcd-unit-test-arm64`

Full PR test history. Your PR dashboard. Please help us cut down on flakes by linking to an open issue when you hit one in your PR.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository. I understand the commands that are listed here.

tjungblu force-pushed the etcdprocess_logs branch from ca95eef to b599235 Compare June 14, 2023 08:35

serathius reviewed Jun 14, 2023

View reviewed changes

tests/framework/e2e/etcd_process.go Outdated Show resolved Hide resolved

serathius reviewed Jun 14, 2023

View reviewed changes

tests/framework/e2e/etcd_process.go Outdated Show resolved Hide resolved

tjungblu force-pushed the etcdprocess_logs branch 2 times, most recently from 9359aa9 to ab50d80 Compare June 14, 2023 14:16

serathius reviewed Jun 14, 2023

View reviewed changes

tjungblu force-pushed the etcdprocess_logs branch from 4d2a097 to b5cdfc0 Compare June 15, 2023 12:33

serathius reviewed Jun 15, 2023

View reviewed changes

stale bot added the stale label Sep 17, 2023

stale bot removed the stale label Jan 16, 2024

k8s-ci-robot added the needs-rebase label Jun 10, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Retain process logs on robustness tests #16077

Retain process logs on robustness tests #16077

tjungblu commented Jun 14, 2023

serathius commented Jun 14, 2023

tjungblu commented Jun 14, 2023

serathius commented Jun 14, 2023

serathius commented Jun 14, 2023 •

edited

Loading

tjungblu commented Jun 14, 2023

serathius Jun 14, 2023

chaochn47 Jun 14, 2023

tjungblu Jun 15, 2023

tjungblu Jun 15, 2023 •

edited

Loading

serathius Jun 15, 2023

tjungblu Jun 15, 2023

serathius Jun 15, 2023

tjungblu Jun 15, 2023

serathius Jun 15, 2023

serathius Jun 15, 2023

serathius Jun 15, 2023 •

edited

Loading

serathius Jun 15, 2023

serathius Jun 15, 2023

serathius Jun 15, 2023

serathius commented Jun 15, 2023

stale bot commented Sep 17, 2023

k8s-ci-robot commented Aug 5, 2024

		@@ -230,7 +233,7 @@ func (ep EtcdServerProcess) Config() EtcdServerProcessConfig { return ep.cfg }

		func (ep *EtcdServerProcess) Logs() LogsExpect {

Retain process logs on robustness tests #16077

Are you sure you want to change the base?

Retain process logs on robustness tests #16077

Conversation

tjungblu commented Jun 14, 2023

serathius commented Jun 14, 2023

tjungblu commented Jun 14, 2023

serathius commented Jun 14, 2023

serathius commented Jun 14, 2023 • edited Loading

tjungblu commented Jun 14, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tjungblu Jun 15, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

serathius Jun 15, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

serathius commented Jun 15, 2023

stale bot commented Sep 17, 2023

k8s-ci-robot commented Aug 5, 2024

serathius commented Jun 14, 2023 •

edited

Loading

tjungblu Jun 15, 2023 •

edited

Loading

serathius Jun 15, 2023 •

edited

Loading