I'm wondering if the original intention of the code was:

That would mean if the status is not found in the status manager AND the pod is running, record the metric, which makes sense. But it looks to me like there was perhaps a mistake made in thinking through the logic / precedence of the operators.

I think this the preferable way to fix the issue. With the change this PR has now, it would not record the metric until the second sync loop iteration, which is less ideal.

I think this the preferable way to fix the issue. With the change this PR has now, it would not record the metric until the second sync loop iteration, which is less ideal.

Hmm. After looking at the statusManager again, I think your suggested code is the intended logic. There can be a case that the pod isn't present in the manager, but it is running. My fix wouldn't handle this case.

I'll push the corrected version soon.

It doesn't look like you are adding this status to the kubelet's statusManager, so this test covers the !ok && apiPodStatus.Phase == v1.PodRunning case that was previously failing, which is great as regression coverage.

For completion, I think we should also have tests covering the cases of existingStatus == v1.PodPending and existingStatus == v1.PodRunning. This would be cleaner to do if you can convert this to table-driven tests.

As you mentioned, we already cover these cases:

• ok is false and apiPodStatus.Phase == v1.PodPending
• ok is true, existingStatus.Phase == v1.PodPending, and apiPodStatus.Phase == v1.PodRunning

I think the only case that remains is when existingStatus.Phase == v1.PodRunning, which means that we should have already observed the pod startup, and duplication shouldn't happen in the metric count. We can add this case by simply adding another SyncPod to ensure that it won't observe the pod again. The added SyncPod call would be something like this:

// Syncing the running pod for the second time.
_, err = kubelet.SyncPod(context.Background(), kubetypes.SyncPodUpdate, pod, nil, podStatus) // podStatus is as the previous call with one running container
if err != nil {
	t.Errorf("Unexpected err: %v", err)
}

// The metric should not consider the running pod again.
testutil.AssertHistogramTotalCount(t, "kubelet_pod_start_duration_seconds", map[string]string{}, 1)

I'm not sure whether table-driven testing is needed here. What I understand is that we want to test the behavior of SyncPod over changes in the pod's status and statusManager keys. If we used table-driven testing, cases would be dependent on each other, which doesn't seem really clean to me.

It's fine with me if you prefer to do it not table-driven as long as we have the coverage. Please make sure we also cover ok is false and apiPodStatus.Phase == v1.PodRunning

Thanks for your comment. I changed the unit test to cover both !ok && apiPodStatus.Phase == v1.PodRunning and existingStatus.Phase == v1.PodRunning cases.

I also tried table-driven testing, but since the counter of the histogram cannot be reset easily, the results of some cases would be dependent on their previous cases. So, I didn't use it.

I also tried table-driven testing, but since the counter of the histogram cannot be reset easily, the results of some cases would be dependent on their previous cases. So, I didn't use it.

We have other table driven tests that have this behavior where some cases are affected by previous cases. If that's the only reason you decided not to use it, we should still go with a table-driven structure. It will be easier to read and see that we are covering all the cases.

Something like:

	tests := []struct {
		name                  string
		pod                   *v1.Pod
                expectedHistogramBump bool
	}{
        ...

I also tried table-driven testing, but since the counter of the histogram cannot be reset easily, the results of some cases would be dependent on their previous cases. So, I didn't use it.

We have other table driven tests that have this behavior where some cases are affected by previous cases. If that's the only reason you decided not to use it, we should still go with a table-driven structure. It will be easier to read and see that we are covering all the cases.

Something like:

	tests := []struct {
		name                  string
		pod                   *v1.Pod
                expectedHistogramBump bool
	}{
        ...

why does the container status here need to be populated? Can we instead just pass in &kubecontainer.PodStatus{ID: pod.UID} directly into the SyncPod call?

Yes, we can pass nothing to state if the container is not running. I just wanted to be explicit here.

It looks to me like you are relying on this SyncPod call to populate the status manager so that we cover the ok && existingStatus.Phase == v1.PodPending case later. I think this is more confusing than it needs to be. Instead, each case in the table driven test should have a different pod, and whenever we need to test the case where ok is true, we populate the status manager directly using kl.statusManager.SetPodStatus. This will also reduce how much each test case depends on the previous one.

Hmm. It is not just populating the status manager. It is also testing the case that ok is false. This call is exactly the call that would fail without the fix. But as I said in my other comment, I tried to follow your style in my latest commit.

super nit: someone just reading this test won't necessarily know what ok means without context, let's be more explicit:

This also applies to your other test names that refer to ok

optional nit: is it possible to set histogramCount to the current total histogram count here? (you can disregard this comment if it would be challenging or complex to do; just thinking if it would be a simple change then we might as well)

I looked at it again. The only way I can think of is to do it like AssertHistogramTotalCount. We can probably add another function in testutil and remove duplicated code between the new function and AssertHistogramTotalCount, but I'm not sure whether it is needed. I haven't implemented it, but if you think it seems fine, we can try it out.

Apologies, I've been caught up with other things and haven't had time to properly review this PR until now.

I understand the changes made here: we record the pod_start_duration_seconds metric when either the podStatus doesn't exist in statusManager, or when the status transitions from pending to running.

This works well in most scenarios, and checking for non-existent podStatus in statusManager is good defensive programming (since it's nearly impossible to have apiPodStatus as running while podStatus is missing in statusManager).

But what happens during a kubelet restart?

If there are already running pods on the node, the statusManager won't have their podStatus. Since their apiPodStatus is already running, we'd record pod_start_duration_seconds for these pods.

However, because kubelet restarted, the firstSeenTime would be approximately equal to kubelet's startup time. This would make all recorded existing pod startup durations appear extremely short.

Does this recorded metric still hold meaning for these existing pods? It no longer represents the actual pod startup interval and would undoubtedly create confusion.

I'm uncertain about the exact behavior here. In my opinion, it might be better to either:

• Apply the following code changes:

	existingStatus, ok := kl.statusManager.GetPodStatus(pod.UID)
	if ok {
		if existingStatus.Phase == v1.PodPending && apiPodStatus.Phase == v1.PodRunning &&
			!firstSeenTime.IsZero() {
			fmt.Printf("pod %s firstSeenTime: %v", pod.Name, firstSeenTime)
			metrics.PodStartDuration.Observe(metrics.SinceInSeconds(firstSeenTime))
		}
	}

• Introduce a separate metric specifically for pods that already existed on the node when kubelet restarted.

/cc @dashpole I'd appreciate broader and more accurate input from sig-Instrumentation on this matter.

I believe this confusion stems from the changes introduced in PR: #105829

It's my understanding that the pod_start_duration_seconds metric was originally intended to measure the duration from pending → running state. However, we messed up in the implementation of the pod_start_duration_seconds metric functionality, it doesn't work as intended.

While we updated the metric's description to match its actual (incorrect) behavior in PR: #105829, making the documentation temporarily consistent with the implementation, this created a fundamental disconnect between the metric's name and its documented purpose.

Apply the following code changes:

existingStatus, ok := kl.statusManager.GetPodStatus(pod.UID)
if ok {
	if existingStatus.Phase == v1.PodPending && apiPodStatus.Phase == v1.PodRunning &&
		!firstSeenTime.IsZero() {
		fmt.Printf("pod %s firstSeenTime: %v", pod.Name, firstSeenTime)
		metrics.PodStartDuration.Observe(metrics.SinceInSeconds(firstSeenTime))
	}
}

This implementation is what I wrote first, but as per talk with @natasha41575, it misses the case the pod is running right away in the first call to SyncPod. In that case, we would calculate the wrong duration :?

However, because kubelet restarted, the firstSeenTime would be approximately equal to kubelet's startup time. This would make all recorded pod startup durations appear extremely short.

Based on the current metric's description, isn't it what we want? The current description (whether right or wrong) says:

Duration in seconds from kubelet seeing a pod for the first time to the pod starting to run

If pods keep running and kubelet restarts, the difference between the time kubelet seeing a pod and the time the pod starts running should be almost zero as the pod is already running.

I agree that the name of this metric is really misleading, but this implementation aligns with its description. I think the fix to the name or introducing a new metric can be done in another dedicated PR.

Based on the current metric's description, isn't it what we want? The current description (whether right or wrong) says:

Duration in seconds from kubelet seeing a pod for the first time to the pod starting to run

This is exactly what I mentioned in #132278.

Our original expectation was: the pod_start_duration_seconds metric should record the time taken for a pod to transition from the Pending to the Running state.

Both the name pod_start_duration_seconds and its previous description confirm that this is what we intended.

However, we messed up in the implementation of the pod_start_duration_seconds metric functionality, it doesn't work as intended.

Subsequently, in #105829, we revised the description of the pod_start_duration_seconds metric based on this incorrect logic. This does not justify our change to the description, especially since the description now severely contradicts the metric's name.

I agree that the name of this metric is really misleading, but this implementation aligns with its description. I think the fix to the name or introducing a new metric can be done in another dedicated PR.

Perhaps we need to clarify the responsibility of the pod_start_duration_seconds metric, revise its description again to align with the metric name, and make it function correctly.

Let's cc the sig-node maintainers, @SergeyKanzhelev @tallclair @haircommander to get broader perspectives.

Ah thanks @HirazawaUi for the context, I misunderstood the expectation of this metric. Based on the metric description I had assumed that re-recording the metric upon kubelet restart was intentional, but from your description I see that this was not the original desired behavior.

I agree that the name of this metric is really misleading, but this implementation aligns with its description. I think the fix to the name or introducing a new metric can be done in another dedicated PR.

I'm inclined to agree with this comment that this PR is a net fix for the duplicate recording issue currently described by #132268, and is an incremental improvement despite not fixing the fundamental issue of the metric description and implementation not matching the original intention.

I'm inclined to agree with this comment that this PR is a net fix for the duplicate recording issue currently described by #132268, and is an incremental improvement despite not fixing the fundamental issue of the metric description and implementation not matching the original intention.

I agree to merge this PR to temporarily resolve the duplicate metrics reporting issue.

However, considering we may have handled things incorrectly before, we need to exercise extra caution when fixing this problem. We likely need further discussion to determine what we should do now :)