feat: add wal write system call metrics observation (main)

[Akiqqqqqqq]

xref. #17615

add new metrics: wal_write_duration_seconds

wal_write_duration_seconds represent total delay of:

syscall.write(padding_info + record_data_with_padding)

• delay of fsync is not included in wal_write_duration_seconds
• data: the raft log to write to the WAL on disk at one single raftNode loop

[k8s-ci-robot]

Hi @Akiqqqqqqq. Thanks for your PR.

I'm waiting for a etcd-io member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

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/test-infra repository.

[jmhbnz]

/ok-to-test

[Akiqqqqqqq]

/retest

[jmhbnz]

LGTM - Thanks @Akiqqqqqqq

[Akiqqqqqqq]

@fuweid master, can help approve merge this PR?

[ahrtr]

Also update the metrics in writeUint64, just as what we already do for walWriteBytes?

etcd/server/storage/wal/encoder.go

Lines 119 to 120 in 1348062

	nv, err := w.Write(buf)
	walWriteBytes.Add(float64(nv))

[Akiqqqqqqq]

Also update the metrics in writeUint64, just as what we already do for walWriteBytes?

etcd/server/storage/wal/encoder.go

Lines 119 to 120 in 1348062

	nv, err := w.Write(buf)
	walWriteBytes.Add(float64(nv))

will do

[ahrtr]

lgtm

Thanks

[ahrtr]

cc @serathius

Want to ask question

[serathius]

Should there be two separate calls to Observe? I think those are part of a single write. I think it would be better to have single call with time measured before writeUint64.

	start := time.Now()
	if err = writeUint64(e.bw, lenField, e.uint64buf); err != nil {
		return err
	}
	if padBytes != 0 {
		data = append(data, make([]byte, padBytes)...)
	}
	n, err = e.bw.Write(data)
	walWriteSec.Observe(time.Since(start).Seconds())

[serathius]

I see you followed the same flow as for walWriteBytes, however the difference is that number of calls to cumulative .Add doesn't matter while .Observe on histogram does.

[serathius]

Observing a write of writeUint64 as separate call would skew the histogram, as it's expected to write much smaller than size of data, then your 50%ile would be just writeUint64.

[Akiqqqqqqq]

I see, that make sense, will fix later

[serathius]

Please fix measurement of write so there is only 1 call to .Observe.

[fuweid]

LGTM

Fixed

[ahrtr]

Please also add a changelog for 3.6 if you don't backport the fix to 3.5; otherwise add a changelog for 3.5 after backporting.

[Akiqqqqqqq]

Please also add a changelog for 3.6 if you don't backport the fix to 3.5; otherwise add a changelog for 3.5 after backporting.

will do later

[Akiqqqqqqq]

I backported to 3.5 and raised a changelog: #17728
plz check