From db9908f6da0f7da3590c25f4d0b24964d1f885ef Mon Sep 17 00:00:00 2001 From: ambarve <57150885+ambarve@users.noreply.github.com> Date: Fri, 12 Nov 2021 12:03:34 -0800 Subject: [PATCH] Time synchronization inside LCOW UVM (#1119) Start time synchronization service in opengcs Changes to the opengcs to start the chronyd service after UVM boots. Signed-off-by: Amit Barve * Signed-off-by: Amit Barve * TimeSync service inside LCOW UVM. Add test to verify both chronyd running & disabled cases. Minor fixes in chronyd startup code. Signed-off-by: Amit Barve * Run Chronyd with restart monitor Signed-off-by: Amit Barve * Force chronyd to step update time if difference is big Signed-off-by: Amit Barve * Fixes after rebase Signed-off-by: Amit Barve * go mod vendor & tidy Signed-off-by: Amit Barve * Use backoff package instead of manually calculating backoffs Signed-off-by: Amit Barve * Rename gcs cmdline params, use io.ReadFull instead of io.Read Minor other fixes. Signed-off-by: Amit Barve * go mod vendor Signed-off-by: Amit Barve * Ignore err if file doesn't exist Signed-off-by: Amit Barve * Use ioutil.ReadFile to read clock_name file Signed-off-by: Amit Barve * minor fix Signed-off-by: Amit Barve * Remove incorrect usage of backoff.MaxElapsedTime Signed-off-by: Amit Barve --- cmd/gcs/main.go | 91 +++++++++++++++ internal/oci/uvm.go | 1 + internal/uvm/create_lcow.go | 6 + pkg/annotations/annotations.go | 4 + test/cri-containerd/runpodsandbox_test.go | 105 +++++++++++++++++- .../Microsoft/hcsshim/internal/oci/uvm.go | 1 + .../hcsshim/internal/uvm/create_lcow.go | 6 + .../hcsshim/pkg/annotations/annotations.go | 4 + 8 files changed, 217 insertions(+), 1 deletion(-) diff --git a/cmd/gcs/main.go b/cmd/gcs/main.go index 7dacf5d5b8..eb6081ef1f 100644 --- a/cmd/gcs/main.go +++ b/cmd/gcs/main.go @@ -8,6 +8,8 @@ import ( "io" "io/ioutil" "os" + "os/exec" + "path/filepath" "syscall" "time" @@ -17,9 +19,11 @@ import ( "github.com/Microsoft/hcsshim/internal/guest/runtime/runc" "github.com/Microsoft/hcsshim/internal/guest/transport" "github.com/Microsoft/hcsshim/internal/oc" + "github.com/cenkalti/backoff/v4" "github.com/containerd/cgroups" cgroupstats "github.com/containerd/cgroups/stats/v1" oci "github.com/opencontainers/runtime-spec/specs-go" + "github.com/pkg/errors" "github.com/sirupsen/logrus" "go.opencensus.io/trace" ) @@ -81,6 +85,84 @@ func readMemoryEvents(startTime time.Time, efdFile *os.File, cgName string, thre } } +// runWithRestartMonitor starts a command with given args and waits for it to exit. If the +// command exit code is non-zero the command is restarted with with some back off delay. +// Any stdout or stderr of the command will be split into lines and written as a log with +// logrus standard logger. This function must be called in a separate goroutine. +func runWithRestartMonitor(arg0 string, args ...string) { + backoffSettings := backoff.NewExponentialBackOff() + // After we hit 10 min retry interval keep retrying after every 10 mins instead of + // continuing to increase retry interval. + backoffSettings.MaxInterval = time.Minute * 10 + for { + command := exec.Command(arg0, args...) + if err := command.Run(); err != nil { + logrus.WithFields(logrus.Fields{ + "error": err, + "command": command.Args, + }).Warn("restart monitor: run command returns error") + } + backOffTime := backoffSettings.NextBackOff() + // since backoffSettings.MaxElapsedTime is set to 0 we will never receive backoff.Stop. + time.Sleep(backOffTime) + } + +} + +// startTimeSyncService starts the `chronyd` deamon to keep the UVM time synchronized. We +// use a PTP device provided by the hypervisor as a source of correct time (instead of +// using a network server). We need to create a configuration file that configures chronyd +// to use the PTP device. The system can have multiple PTP devices so we identify the +// correct PTP device by verifying that the `clock_name` of that device is `hyperv`. +func startTimeSyncService() error { + ptpClassDir, err := os.Open("/sys/class/ptp") + if err != nil { + return errors.Wrap(err, "failed to open PTP class directory") + } + + ptpDirList, err := ptpClassDir.Readdirnames(-1) + if err != nil { + return errors.Wrap(err, "failed to list PTP class directory") + } + + var ptpDirPath string + found := false + // The file ends with a new line + expectedClockName := "hyperv\n" + for _, ptpDirPath = range ptpDirList { + clockNameFilePath := filepath.Join(ptpClassDir.Name(), ptpDirPath, "clock_name") + buf, err := ioutil.ReadFile(clockNameFilePath) + if err != nil && !os.IsNotExist(err) { + return errors.Wrapf(err, "failed to read clock name file at %s", clockNameFilePath) + } + + if string(buf) == expectedClockName { + found = true + break + } + } + + if !found { + return errors.Errorf("no PTP device found with name \"%s\"", expectedClockName) + } + + // create chronyd config file + ptpDevPath := filepath.Join("/dev", filepath.Base(ptpDirPath)) + // chronyd config file take from: https://docs.microsoft.com/en-us/azure/virtual-machines/linux/time-sync + chronydConfigString := fmt.Sprintf("refclock PHC %s poll 3 dpoll -2 offset 0 stratum 2\nmakestep 0.1 -1\n", ptpDevPath) + chronydConfPath := "/tmp/chronyd.conf" + err = ioutil.WriteFile(chronydConfPath, []byte(chronydConfigString), 0644) + if err != nil { + return errors.Wrapf(err, "failed to create chronyd conf file %s", chronydConfPath) + } + + // start chronyd. Do NOT start chronyd as daemon because creating a daemon + // involves double forking the restart monitor will attempt to restart chornyd + // after the first fork child exits. + go runWithRestartMonitor("chronyd", "-n", "-f", chronydConfPath) + return nil +} + func main() { startTime := time.Now() logLevel := flag.String("loglevel", "debug", "Logging Level: debug, info, warning, error, fatal, panic.") @@ -92,6 +174,7 @@ func main() { v4 := flag.Bool("v4", false, "enable the v4 protocol support and v2 schema") rootMemReserveBytes := flag.Uint64("root-mem-reserve-bytes", 75*1024*1024, "the amount of memory reserved for the orchestration, the rest will be assigned to containers") gcsMemLimitBytes := flag.Uint64("gcs-mem-limit-bytes", 50*1024*1024, "the maximum amount of memory the gcs can use") + disableTimeSync := flag.Bool("disable-time-sync", false, "If true do not run chronyd time synchronization service inside the UVM") flag.Usage = func() { fmt.Fprintf(os.Stderr, "\nUsage of %s:\n", os.Args[0]) @@ -248,6 +331,13 @@ func main() { oomFile := os.NewFile(oom, "cefd") defer oomFile.Close() + // time synchronization service + if !(*disableTimeSync) { + if err = startTimeSyncService(); err != nil { + logrus.WithError(err).Fatal("failed to start time synchronization service") + } + } + go readMemoryEvents(startTime, gefdFile, "/gcs", int64(*gcsMemLimitBytes), gcsControl) go readMemoryEvents(startTime, oomFile, "/containers", containersLimit, containersControl) err = b.ListenAndServe(bridgeIn, bridgeOut) @@ -256,4 +346,5 @@ func main() { logrus.ErrorKey: err, }).Fatal("failed to serve gcs service") } + } diff --git a/internal/oci/uvm.go b/internal/oci/uvm.go index 82f7ed810b..0782a9cf5c 100644 --- a/internal/oci/uvm.go +++ b/internal/oci/uvm.go @@ -358,6 +358,7 @@ func SpecToUVMCreateOpts(ctx context.Context, s *specs.Spec, id, owner string) ( lopts.SecurityPolicy = parseAnnotationsString(s.Annotations, annotations.SecurityPolicy, lopts.SecurityPolicy) lopts.KernelBootOptions = parseAnnotationsString(s.Annotations, annotations.KernelBootOptions, lopts.KernelBootOptions) lopts.ProcessDumpLocation = parseAnnotationsString(s.Annotations, annotations.ContainerProcessDumpLocation, lopts.ProcessDumpLocation) + lopts.DisableTimeSyncService = parseAnnotationsBool(ctx, s.Annotations, annotations.DisableLCOWTimeSyncService, lopts.DisableTimeSyncService) handleAnnotationPreferredRootFSType(ctx, s.Annotations, lopts) handleAnnotationKernelDirectBoot(ctx, s.Annotations, lopts) diff --git a/internal/uvm/create_lcow.go b/internal/uvm/create_lcow.go index dd8b68c3f5..a8ff8c7742 100644 --- a/internal/uvm/create_lcow.go +++ b/internal/uvm/create_lcow.go @@ -103,6 +103,7 @@ type OptionsLCOW struct { SecurityPolicyEnabled bool // Set when there is a security policy to apply on actual SNP hardware, use this rathen than checking the string length UseGuestStateFile bool // Use a vmgs file that contains a kernel and initrd, required for SNP GuestStateFile string // The vmgs file to load + DisableTimeSyncService bool // Disables the time synchronization service } // defaultLCOWOSBootFilesPath returns the default path used to locate the LCOW @@ -152,6 +153,7 @@ func NewDefaultOptionsLCOW(id, owner string) *OptionsLCOW { SecurityPolicyEnabled: false, SecurityPolicy: "", GuestStateFile: "", + DisableTimeSyncService: false, } if _, err := os.Stat(filepath.Join(opts.BootFilesPath, VhdFile)); err == nil { @@ -651,6 +653,10 @@ func makeLCOWDoc(ctx context.Context, opts *OptionsLCOW, uvm *UtilityVM) (_ *hcs initArgs += fmt.Sprintf(" -e %d", linuxLogVsockPort) } + if opts.DisableTimeSyncService { + opts.ExecCommandLine = fmt.Sprintf("%s --disable-time-sync", opts.ExecCommandLine) + } + initArgs += " " + opts.ExecCommandLine if opts.ProcessDumpLocation != "" { diff --git a/pkg/annotations/annotations.go b/pkg/annotations/annotations.go index 420243937c..4202c56aba 100644 --- a/pkg/annotations/annotations.go +++ b/pkg/annotations/annotations.go @@ -257,4 +257,8 @@ const ( // GuestStateFile specifies the path of the vmgs file to use if required. Only applies in SNP mode. GuestStateFile = "io.microsoft.virtualmachine.lcow.gueststatefile" + + // AnnotationDisableLCOWTimeSyncService is used to disable the chronyd time + // synchronization service inside the LCOW UVM. + DisableLCOWTimeSyncService = "io.microsoft.virtualmachine.lcow.timesync.disable" ) diff --git a/test/cri-containerd/runpodsandbox_test.go b/test/cri-containerd/runpodsandbox_test.go index d549f02592..4c96710545 100644 --- a/test/cri-containerd/runpodsandbox_test.go +++ b/test/cri-containerd/runpodsandbox_test.go @@ -4,9 +4,10 @@ package cri_containerd import ( "bufio" + "bytes" "context" "fmt" - "github.com/Microsoft/hcsshim/pkg/annotations" + "io" "io/ioutil" "os" "path/filepath" @@ -19,8 +20,11 @@ import ( "github.com/Microsoft/hcsshim/internal/hcs" "github.com/Microsoft/hcsshim/internal/lcow" "github.com/Microsoft/hcsshim/internal/processorinfo" + "github.com/Microsoft/hcsshim/internal/shimdiag" "github.com/Microsoft/hcsshim/osversion" + "github.com/Microsoft/hcsshim/pkg/annotations" testutilities "github.com/Microsoft/hcsshim/test/functional/utilities" + "github.com/containerd/containerd/log" runtime "k8s.io/cri-api/pkg/apis/runtime/v1alpha2" ) @@ -1050,6 +1054,14 @@ func Test_RunPodSandbox_CPUGroup(t *testing.T) { } func createExt4VHD(ctx context.Context, t *testing.T, path string) { + // UVM related functions called below produce a lot debug logs. Set the logger + // output to Discard if verbose flag is not set. This way we can still capture + // these logs in a wpr session. + if !testing.Verbose() { + origLogOut := log.L.Logger.Out + log.L.Logger.SetOutput(io.Discard) + defer log.L.Logger.SetOutput(origLogOut) + } uvm := testutilities.CreateLCOWUVM(ctx, t, t.Name()+"-createExt4VHD") defer uvm.Close() @@ -1708,3 +1720,94 @@ func Test_RunPodSandbox_KernelOptions_LCOW(t *testing.T) { t.Fatalf("Expected number of hugepages to be 10. Got output instead: %d", numOfHugePages) } } + +func Test_RunPodSandbox_TimeSyncService(t *testing.T) { + requireFeatures(t, featureLCOW) + + client := newTestRuntimeClient(t) + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + + pullRequiredLCOWImages(t, []string{imageLcowK8sPause}) + + request := getRunPodSandboxRequest( + t, + lcowRuntimeHandler) + + podID := runPodSandbox(t, client, ctx, request) + defer removePodSandbox(t, client, ctx, podID) + defer stopPodSandbox(t, client, ctx, podID) + + shimName := fmt.Sprintf("k8s.io-%s", podID) + + shim, err := shimdiag.GetShim(shimName) + if err != nil { + t.Fatalf("failed to find shim %s: %s", shimName, err) + } + + psCmd := []string{"ps"} + shimClient := shimdiag.NewShimDiagClient(shim) + outBuf := bytes.Buffer{} + outw := bufio.NewWriter(&outBuf) + errBuf := bytes.Buffer{} + errw := bufio.NewWriter(&errBuf) + exitCode, err := execInHost(ctx, shimClient, psCmd, nil, outw, errw) + if err != nil { + t.Fatalf("failed to exec `%s` in the uvm with %s", psCmd[0], err) + } + if exitCode != 0 { + t.Fatalf("exec `%s` in the uvm failed with exit code: %d, std error: %s", psCmd[0], exitCode, errBuf.String()) + } + if !strings.Contains(outBuf.String(), "chronyd") { + t.Logf("standard output of exec %s is: %s\n", psCmd[0], outBuf.String()) + t.Fatalf("chronyd is not running inside the uvm") + } +} + +func Test_RunPodSandbox_DisableTimeSyncService(t *testing.T) { + requireFeatures(t, featureLCOW) + + client := newTestRuntimeClient(t) + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + + pullRequiredLCOWImages(t, []string{imageLcowK8sPause}) + + request := getRunPodSandboxRequest( + t, + lcowRuntimeHandler, + WithSandboxAnnotations( + map[string]string{ + annotations.DisableLCOWTimeSyncService: "true", + }), + ) + + podID := runPodSandbox(t, client, ctx, request) + defer removePodSandbox(t, client, ctx, podID) + defer stopPodSandbox(t, client, ctx, podID) + + shimName := fmt.Sprintf("k8s.io-%s", podID) + + shim, err := shimdiag.GetShim(shimName) + if err != nil { + t.Fatalf("failed to find shim %s: %s", shimName, err) + } + + psCmd := []string{"ps"} + shimClient := shimdiag.NewShimDiagClient(shim) + outBuf := bytes.Buffer{} + outw := bufio.NewWriter(&outBuf) + errBuf := bytes.Buffer{} + errw := bufio.NewWriter(&errBuf) + exitCode, err := execInHost(ctx, shimClient, psCmd, nil, outw, errw) + if err != nil { + t.Fatalf("failed to exec `%s` in the uvm with %s", psCmd[0], err) + } + if exitCode != 0 { + t.Fatalf("exec `%s` in the uvm failed with exit code: %d, std error: %s", psCmd[0], exitCode, errBuf.String()) + } + if strings.Contains(outBuf.String(), "chronyd") { + t.Logf("standard output of exec %s is: %s\n", psCmd[0], outBuf.String()) + t.Fatalf("chronyd should not be running inside the uvm") + } +} diff --git a/test/vendor/github.com/Microsoft/hcsshim/internal/oci/uvm.go b/test/vendor/github.com/Microsoft/hcsshim/internal/oci/uvm.go index 82f7ed810b..0782a9cf5c 100644 --- a/test/vendor/github.com/Microsoft/hcsshim/internal/oci/uvm.go +++ b/test/vendor/github.com/Microsoft/hcsshim/internal/oci/uvm.go @@ -358,6 +358,7 @@ func SpecToUVMCreateOpts(ctx context.Context, s *specs.Spec, id, owner string) ( lopts.SecurityPolicy = parseAnnotationsString(s.Annotations, annotations.SecurityPolicy, lopts.SecurityPolicy) lopts.KernelBootOptions = parseAnnotationsString(s.Annotations, annotations.KernelBootOptions, lopts.KernelBootOptions) lopts.ProcessDumpLocation = parseAnnotationsString(s.Annotations, annotations.ContainerProcessDumpLocation, lopts.ProcessDumpLocation) + lopts.DisableTimeSyncService = parseAnnotationsBool(ctx, s.Annotations, annotations.DisableLCOWTimeSyncService, lopts.DisableTimeSyncService) handleAnnotationPreferredRootFSType(ctx, s.Annotations, lopts) handleAnnotationKernelDirectBoot(ctx, s.Annotations, lopts) diff --git a/test/vendor/github.com/Microsoft/hcsshim/internal/uvm/create_lcow.go b/test/vendor/github.com/Microsoft/hcsshim/internal/uvm/create_lcow.go index dd8b68c3f5..a8ff8c7742 100644 --- a/test/vendor/github.com/Microsoft/hcsshim/internal/uvm/create_lcow.go +++ b/test/vendor/github.com/Microsoft/hcsshim/internal/uvm/create_lcow.go @@ -103,6 +103,7 @@ type OptionsLCOW struct { SecurityPolicyEnabled bool // Set when there is a security policy to apply on actual SNP hardware, use this rathen than checking the string length UseGuestStateFile bool // Use a vmgs file that contains a kernel and initrd, required for SNP GuestStateFile string // The vmgs file to load + DisableTimeSyncService bool // Disables the time synchronization service } // defaultLCOWOSBootFilesPath returns the default path used to locate the LCOW @@ -152,6 +153,7 @@ func NewDefaultOptionsLCOW(id, owner string) *OptionsLCOW { SecurityPolicyEnabled: false, SecurityPolicy: "", GuestStateFile: "", + DisableTimeSyncService: false, } if _, err := os.Stat(filepath.Join(opts.BootFilesPath, VhdFile)); err == nil { @@ -651,6 +653,10 @@ func makeLCOWDoc(ctx context.Context, opts *OptionsLCOW, uvm *UtilityVM) (_ *hcs initArgs += fmt.Sprintf(" -e %d", linuxLogVsockPort) } + if opts.DisableTimeSyncService { + opts.ExecCommandLine = fmt.Sprintf("%s --disable-time-sync", opts.ExecCommandLine) + } + initArgs += " " + opts.ExecCommandLine if opts.ProcessDumpLocation != "" { diff --git a/test/vendor/github.com/Microsoft/hcsshim/pkg/annotations/annotations.go b/test/vendor/github.com/Microsoft/hcsshim/pkg/annotations/annotations.go index 420243937c..4202c56aba 100644 --- a/test/vendor/github.com/Microsoft/hcsshim/pkg/annotations/annotations.go +++ b/test/vendor/github.com/Microsoft/hcsshim/pkg/annotations/annotations.go @@ -257,4 +257,8 @@ const ( // GuestStateFile specifies the path of the vmgs file to use if required. Only applies in SNP mode. GuestStateFile = "io.microsoft.virtualmachine.lcow.gueststatefile" + + // AnnotationDisableLCOWTimeSyncService is used to disable the chronyd time + // synchronization service inside the LCOW UVM. + DisableLCOWTimeSyncService = "io.microsoft.virtualmachine.lcow.timesync.disable" )