Repository: kubernetes/kubernetes (language: go)

Issue:
kubelet GetBootTime() could drift backward for 1s
### What happened?

There are a few places in kubelet that calls `pkg/kubelet/util`.`GetBootTime()`. One such place is the kubelet `/stats/summary` endpoint where it's getting the node startTime: [ref](https://github.com/kubernetes/kubernetes/blob/v1.30.0/pkg/kubelet/server/stats/summary.go#L56)

And there's an issue in the [Linux implementation of `GetBootTime`](https://github.com/kubernetes/kubernetes/blob/v1.31.0/pkg/kubelet/util/boottime_util_linux.go#L30) that the result is not consistent: sometimes it could drift backwards for 1s. This caused problem in certain monitoring systems where the time series database expect timestamps to be monotonically increasing.****

### What did you expect to happen?

`GetBootTime()` to return consistent result everytime it runs, more specifically the kubelet `/stats/summary` endpoint returns a consistent node startTime when kubelet restarts.

### How can we reproduce it (as minimally and precisely as possible)?

do the following steps multiple times:

- restart kubelet
- do a http get on kubelet /stats/summary endpoint
- observe the `node`.`startTime` field in the response

you will see the node startTime could shift backwards for 1s in some cases.

You can also reproduce the issue by simply running the same `GetBootTime` logic multiple times:

```
cat get-boot-time.go 
package main

import (
	"fmt"
	"time"
	"golang.org/x/sys/unix"
)

func main() {
	// This is the same logic as `pkg/kubelet/util/boottime_util_linux.go`
	currentTime := time.Now()
	var info unix.Sysinfo_t
	if err := unix.Sysinfo(&info); err != nil {
		fmt.Errorf("error getting system uptime: %s", err)
		return
	}
	bootTime := currentTime.Add(-time.Duration(info.Uptime) * time.Second).Truncate(time.Second)
	fmt.Printf("bootTime: %s\n", bootTime)
	return
}

$ for i in {1..100} ; do go run get-boot-time.go ; done
bootTime: 2024-09-09 01:04:18 +0000 UTC
bootTime: 2024-09-09 01:04:18 +0000 UTC
bootTime: 2024-09-09 01:04:17 +0000 UTC    <--------- 1s backward drift
bootTime: 2024-09-09 01:04:18 +0000 UTC
 bootTime: 2024-09-09 01:04:18 +0000 UTC
bootTime: 2024-09-09 01:04:18 +0000 UTC
bootTime: 2024-09-09 01:04:18 +0000 UTC
```

### Anything else we need to know?

I think the cause is a combination of multiple factors:

(a) `currentTime := time.Now()` is represented in a sub-second unit
(b) `unix.Sysinfo.Uptime` has a unit in second
(c) GetBootTime() subtracts uptime from current time and then round to the earlier second with the `time`.`Truncate()` method

so the following situation could happen:

1. system actually starts at 0,
2. when kubelet calls GetBootTime(), currentTIme returns 10s 999ms 999us 999ns
3. then 1us later, sysInfo reports Uptime 11s
4. at the end GetBootTime would round (10.999999 - 11) and return -1s instead of the actual 0s

### One possible solution:

The drift always happen when Sysinfo.upTime increased by one second, so we could avoid it by: call the same GetBootTime() logic 3 times in a row, assuming each call finishes < 1s, then there will be for sure at least 2 times where Sysinfo.upTime agrees with each other. Then out of the 2 times, we use the GetBootTime() result from first one.

### Kubernetes version

all existing kubernetes versions

### Cloud provider

<details>

</details>


### OS version

<details>

```console
# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here

# On Windows:
C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture
# paste output here
```

</details>


### Install tools

<details>

</details>


### Container runtime (CRI) and version (if applicable)

<details>

</details>


### Related plugins (CNI, CSI, ...) and versions (if applicable)

<details>

</details>



Discussion / hints:
This issue is currently awaiting triage.

If a SIG or subproject determines this is a relevant issue, they will accept it by applying the `triage/accepted` label and provide further guidance.

The `triage/accepted` label can be added by org members by writing `/triage accepted` in a comment.


<details>

Instructions for interacting with me using PR comments are available [here](https://git.k8s.io/community/contributors/guide/pull-requests.md).  If you have questions or suggestions related to my behavior, please file an issue against the [kubernetes-sigs/prow](https://github.com/kubernetes-sigs/prow/issues/new?title=Prow%20issue:) repository.
</details>
/sig instrumentation

Fix patch:
diff --git a/pkg/kubelet/util/boottime_util_linux.go b/pkg/kubelet/util/boottime_util_linux.go
index b48ef392eeb05..935b3d80341b6 100644
--- a/pkg/kubelet/util/boottime_util_linux.go
+++ b/pkg/kubelet/util/boottime_util_linux.go
@@ -21,17 +21,54 @@ package util
 
 import (
 	"fmt"
+	"os"
+	"strconv"
+	"strings"
 	"time"
 
 	"golang.org/x/sys/unix"
+	"k8s.io/klog/v2"
 )
 
-// GetBootTime returns the time at which the machine was started, truncated to the nearest second
+// GetBootTime returns the time at which the machine was started, truncated to the nearest second.
+// It uses /proc/stat first, which is more accurate, and falls back to the less accurate
+// unix.Sysinfo if /proc/stat failed.
 func GetBootTime() (time.Time, error) {
+	bootTime, err := getBootTimeWithProcStat()
+	if err != nil {
+		klog.InfoS("Failed to get boot time from /proc/uptime. Will retry with unix.Sysinfo.", "error", err)
+		return getBootTimeWithSysinfo()
+	}
+	return bootTime, nil
+}
+
+func getBootTimeWithProcStat() (time.Time, error) {
+	raw, err := os.ReadFile("/proc/stat")
+	if err != nil {
+		return time.Time{}, fmt.Errorf("error getting boot time: %w", err)
+	}
+	rawFields := strings.Fields(string(raw))
+	for i, v := range rawFields {
+		if v == "btime" {
+			if len(rawFields) > i+1 {
+				sec, err := strconv.ParseInt(rawFields[i+1], 10, 64)
+				if err != nil {
+					return time.Time{}, fmt.Errorf("error parsing boot time %s: %w", rawFields[i+1], err)
+				}
+				return time.Unix(sec, 0), nil
+			}
+			break
+		}
+	}
+
+	return time.Time{}, fmt.Errorf("can not find btime from /proc/stat: %s", raw)
+}
+
+func getBootTimeWithSysinfo() (time.Time, error) {
 	currentTime := time.Now()
 	var info unix.Sysinfo_t
 	if err := unix.Sysinfo(&info); err != nil {
-		return time.Time{}, fmt.Errorf("error getting system uptime: %s", err)
+		return time.Time{}, fmt.Errorf("error getting system uptime: %w", err)
 	}
 	return currentTime.Add(-time.Duration(info.Uptime) * time.Second).Truncate(time.Second), nil
 }


Test patch:
diff --git a/pkg/kubelet/util/boottime_util_linux_test.go b/pkg/kubelet/util/boottime_util_linux_test.go
index 4fce0acdeb30a..9f77dfd0287ba 100644
--- a/pkg/kubelet/util/boottime_util_linux_test.go
+++ b/pkg/kubelet/util/boottime_util_linux_test.go
@@ -35,3 +35,18 @@ func TestGetBootTime(t *testing.T) {
 		t.Errorf("Invalid system uptime")
 	}
 }
+
+func TestVariationBetweenGetBootTimeMethods(t *testing.T) {
+	boottime1, err := getBootTimeWithProcStat()
+	if err != nil {
+		t.Errorf("Unable to get boot time from /proc/uptime")
+	}
+	boottime2, err := getBootTimeWithSysinfo()
+	if err != nil {
+		t.Errorf("Unable to get boot time from unix.Sysinfo")
+	}
+	diff := boottime1.Sub(boottime2)
+	if diff > time.Second || diff < -time.Second {
+		t.Errorf("boot time produced by 2 methods should not vary more than a second")
+	}
+}