k8s.io/kubernetes@v1.31.0-alpha.0.0.20240520171757-56147500dadc/test/e2e_node/container_lifecycle_pod_construction.go (about)

     1  /*
     2  Copyright 2023 The Kubernetes Authors.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package e2enode
    18  
    19  import (
    20  	"bufio"
    21  	"bytes"
    22  	"context"
    23  	"fmt"
    24  	"sort"
    25  	"strings"
    26  	"time"
    27  
    28  	v1 "k8s.io/api/core/v1"
    29  	"k8s.io/apimachinery/pkg/api/resource"
    30  
    31  	"k8s.io/kubernetes/test/e2e/framework"
    32  	e2epod "k8s.io/kubernetes/test/e2e/framework/pod"
    33  )
    34  
    35  type execCommand struct {
    36  	// ExitCode is the exit status of the container
    37  	ExitCode int
    38  	// StartDelay is how long the container should delay before starting
    39  	StartDelay int
    40  	// Delay is how long the container should delay before exiting
    41  	Delay int
    42  	// LoopForever if set will cause the command to log once per second in a loop until
    43  	// terminated
    44  	LoopForever bool
    45  	// TerminationSeconds is the time it takes for the container before
    46  	// terminating if it catches SIGTERM.
    47  	TerminationSeconds int
    48  	// ContainerName is the name of the container to append the log. If empty,
    49  	// the name specified in ExecCommand will be used.
    50  	ContainerName string
    51  }
    52  
    53  // ExecCommand returns the command to execute in the container that implements
    54  // execCommand and logs activities to a container specific log that persists
    55  // across container restarts. The final log is written to container log so it
    56  // can be retrieved by the test harness during the container execution.
    57  // Log to /proc/1/fd/1 so that the lifecycle hook handler logs are captured as
    58  // well.
    59  func ExecCommand(name string, c execCommand) []string {
    60  	var cmd bytes.Buffer
    61  	// all outputs are in the format of:
    62  	// time-since-boot timestamp container-name message
    63  
    64  	// The busybox time command doesn't support sub-second display.
    65  	// We have to use nmeter to get the milliseconds part.
    66  	timeCmd := "`date -u +%FT$(nmeter -d0 '%3t' | head -n1)Z`"
    67  	containerName := name
    68  	if c.ContainerName != "" {
    69  		containerName = c.ContainerName
    70  	}
    71  	containerLog := fmt.Sprintf("/persistent/%s.log", containerName)
    72  
    73  	fmt.Fprintf(&cmd, "touch %s; ", containerLog)
    74  	if c.ContainerName == "" {
    75  		fmt.Fprintf(&cmd, "cat %s >> /proc/1/fd/1; ", containerLog)
    76  	}
    77  
    78  	fmt.Fprintf(&cmd, "echo %s '%s Starting %d' | tee -a %s >> /proc/1/fd/1; ", timeCmd, name, c.StartDelay, containerLog)
    79  	fmt.Fprintf(&cmd, "_term() { sleep %d; echo %s '%s Exiting' | tee -a %s >> /proc/1/fd/1; exit %d; }; ", c.TerminationSeconds, timeCmd, name, containerLog, c.ExitCode)
    80  	fmt.Fprintf(&cmd, "trap _term TERM; ")
    81  	if c.StartDelay != 0 {
    82  		fmt.Fprint(&cmd, sleepCommand(c.StartDelay))
    83  	}
    84  	// You can check started file to see if the container has started
    85  	fmt.Fprintf(&cmd, "touch started; ")
    86  	fmt.Fprintf(&cmd, "echo %s '%s Started' | tee -a %s >> /proc/1/fd/1; ", timeCmd, name, containerLog)
    87  	fmt.Fprintf(&cmd, "echo %s '%s Delaying %d' | tee -a %s >> /proc/1/fd/1; ", timeCmd, name, c.Delay, containerLog)
    88  	if c.Delay != 0 {
    89  		fmt.Fprint(&cmd, sleepCommand(c.Delay))
    90  	}
    91  	if c.LoopForever {
    92  		fmt.Fprintf(&cmd, "while true; do echo %s '%s Looping' | tee -a %s >> /proc/1/fd/1 ; sleep 1 ; done; ", timeCmd, name, containerLog)
    93  	}
    94  	fmt.Fprintf(&cmd, "echo %s '%s Exiting'  | tee -a %s >> /proc/1/fd/1; ", timeCmd, name, containerLog)
    95  	fmt.Fprintf(&cmd, "exit %d", c.ExitCode)
    96  	return []string{"sh", "-c", cmd.String()}
    97  }
    98  
    99  // sleepCommand returns a command that sleeps for the given number of seconds
   100  // in background and waits for it to finish so that the parent process can
   101  // handle signals.
   102  func sleepCommand(seconds int) string {
   103  	return fmt.Sprintf("exec sleep %d & wait $!; ", seconds)
   104  }
   105  
   106  type containerOutput struct {
   107  	// time the message was seen to the nearest second
   108  	timestamp     time.Time
   109  	containerName string
   110  	command       string
   111  }
   112  type containerOutputList []containerOutput
   113  
   114  func (o containerOutputList) String() string {
   115  	var b bytes.Buffer
   116  	for i, v := range o {
   117  		fmt.Fprintf(&b, "%d) %s %s %s\n", i, v.timestamp, v.containerName, v.command)
   118  	}
   119  	return b.String()
   120  }
   121  
   122  // RunTogether returns an error the lhs and rhs run together
   123  func (o containerOutputList) RunTogether(lhs, rhs string) error {
   124  	lhsStart := o.findIndex(lhs, "Started", 0)
   125  	if lhsStart == -1 {
   126  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", lhs, o)
   127  	}
   128  
   129  	rhsStart := o.findIndex(rhs, "Started", lhsStart+1)
   130  	if rhsStart == -1 {
   131  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", rhs, o)
   132  	}
   133  
   134  	lhsExit := o.findIndex(lhs, "Exiting", lhsStart+1)
   135  	if lhsExit == -1 {
   136  		return fmt.Errorf("couldn't find that %s ever exited, got\n%v", lhs, o)
   137  	}
   138  
   139  	if rhsStart > lhsExit {
   140  		return fmt.Errorf("expected %s to start before exiting %s, got\n%v", rhs, lhs, o)
   141  	}
   142  
   143  	rhsExit := o.findIndex(rhs, "Exiting", rhsStart+1)
   144  	if rhsExit == -1 {
   145  		return fmt.Errorf("couldn't find that %s ever exited, got\n%v", rhs, o)
   146  	}
   147  
   148  	if lhsStart > rhsExit {
   149  		return fmt.Errorf("expected %s to start before exiting %s, got\n%v", lhs, rhs, o)
   150  	}
   151  
   152  	return nil
   153  }
   154  
   155  // StartsBefore returns an error if lhs did not start before rhs
   156  func (o containerOutputList) StartsBefore(lhs, rhs string) error {
   157  	lhsStart := o.findIndex(lhs, "Started", 0)
   158  
   159  	if lhsStart == -1 {
   160  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", lhs, o)
   161  	}
   162  
   163  	// this works even for the same names (restart case)
   164  	rhsStart := o.findIndex(rhs, "Starting", lhsStart+1)
   165  
   166  	if rhsStart == -1 {
   167  		return fmt.Errorf("couldn't find that %s started after %s, got\n%v", rhs, lhs, o)
   168  	}
   169  	return nil
   170  }
   171  
   172  // DoesntStartAfter returns an error if lhs started after rhs
   173  func (o containerOutputList) DoesntStartAfter(lhs, rhs string) error {
   174  	rhsStart := o.findIndex(rhs, "Starting", 0)
   175  
   176  	if rhsStart == -1 {
   177  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", rhs, o)
   178  	}
   179  
   180  	// this works even for the same names (restart case)
   181  	lhsStart := o.findIndex(lhs, "Started", rhsStart+1)
   182  
   183  	if lhsStart != -1 {
   184  		return fmt.Errorf("expected %s to not start after %s, got\n%v", lhs, rhs, o)
   185  	}
   186  
   187  	return nil
   188  }
   189  
   190  // ExitsBefore returns an error if lhs did not end before rhs
   191  func (o containerOutputList) ExitsBefore(lhs, rhs string) error {
   192  	lhsExit := o.findIndex(lhs, "Exiting", 0)
   193  
   194  	if lhsExit == -1 {
   195  		return fmt.Errorf("couldn't find that %s ever exited, got\n%v", lhs, o)
   196  	}
   197  
   198  	// this works even for the same names (restart case)
   199  	rhsExit := o.findIndex(rhs, "Exiting", lhsExit+1)
   200  
   201  	if rhsExit == -1 {
   202  		return fmt.Errorf("couldn't find that %s starting before %s exited (starting at idx %d), got\n%v", rhs, lhs, lhsExit+1, o)
   203  	}
   204  	return nil
   205  }
   206  
   207  // Starts returns an error if the container was not found to have started
   208  func (o containerOutputList) Starts(name string) error {
   209  	if idx := o.findIndex(name, "Started", 0); idx == -1 {
   210  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", name, o)
   211  	}
   212  	return nil
   213  }
   214  
   215  // DoesntStart returns an error if the container was found to have started
   216  func (o containerOutputList) DoesntStart(name string) error {
   217  	if idx := o.findIndex(name, "Started", 0); idx != -1 {
   218  		return fmt.Errorf("find %s started, but didn't expect to, got\n%v", name, o)
   219  	}
   220  	return nil
   221  }
   222  
   223  // Exits returns an error if the container was not found to have exited
   224  func (o containerOutputList) Exits(name string) error {
   225  	if idx := o.findIndex(name, "Exiting", 0); idx == -1 {
   226  		return fmt.Errorf("couldn't find that %s ever exited, got\n%v", name, o)
   227  	}
   228  	return nil
   229  }
   230  
   231  // HasRestarted returns an error if the container was not found to have restarted
   232  func (o containerOutputList) HasRestarted(name string) error {
   233  	idx := o.findIndex(name, "Starting", 0)
   234  	if idx == -1 {
   235  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", name, o)
   236  	}
   237  
   238  	idx = o.findIndex(name, "Starting", idx+1)
   239  
   240  	if idx == -1 {
   241  		return fmt.Errorf("couldn't find that %s ever restarted, got\n%v", name, o)
   242  	}
   243  
   244  	return nil
   245  }
   246  
   247  // HasNotRestarted returns an error if the container was found to have restarted
   248  func (o containerOutputList) HasNotRestarted(name string) error {
   249  	idx := o.findIndex(name, "Starting", 0)
   250  	if idx == -1 {
   251  		return fmt.Errorf("couldn't find that %s ever started, got\n%v", name, o)
   252  	}
   253  
   254  	idx = o.findIndex(name, "Starting", idx+1)
   255  
   256  	if idx != -1 {
   257  		return fmt.Errorf("found that %s restarted but wasn't expected to, got\n%v", name, o)
   258  	}
   259  
   260  	return nil
   261  }
   262  
   263  type containerOutputIndex int
   264  
   265  func (i containerOutputIndex) IsBefore(other containerOutputIndex) error {
   266  	if i >= other {
   267  		return fmt.Errorf("%d should be before %d", i, other)
   268  	}
   269  	return nil
   270  }
   271  
   272  func (o containerOutputList) FindIndex(name string, command string, startIdx containerOutputIndex) (containerOutputIndex, error) {
   273  	idx := o.findIndex(name, command, int(startIdx))
   274  	if idx == -1 {
   275  		return -1, fmt.Errorf("couldn't find %s %s, got\n%v", name, command, o)
   276  	}
   277  	return containerOutputIndex(idx), nil
   278  }
   279  
   280  func (o containerOutputList) findIndex(name string, command string, startIdx int) int {
   281  	for i, v := range o {
   282  		if i < startIdx {
   283  			continue
   284  		}
   285  		if v.containerName == name && v.command == command {
   286  			return i
   287  		}
   288  	}
   289  	return -1
   290  }
   291  func (o containerOutputList) findLastIndex(name string, command string) int {
   292  	found := -1
   293  	for i, v := range o {
   294  		if v.containerName == name && v.command == command {
   295  			found = i
   296  		}
   297  	}
   298  	return found
   299  }
   300  
   301  // TimeOfStart returns the UNIX time in milliseconds when the specified container started.
   302  func (o containerOutputList) TimeOfStart(name string) (int64, error) {
   303  	idx := o.findIndex(name, "Starting", 0)
   304  	if idx == -1 {
   305  		return 0, fmt.Errorf("couldn't find that %s ever started, got\n%v", name, o)
   306  	}
   307  	return o[idx].timestamp.UnixMilli(), nil
   308  }
   309  
   310  // TimeOfLastLoop returns the UNIX time in milliseconds when the specified container last looped.
   311  func (o containerOutputList) TimeOfLastLoop(name string) (int64, error) {
   312  	idx := o.findLastIndex(name, "Looping")
   313  	if idx == -1 {
   314  		return 0, fmt.Errorf("couldn't find that %s ever looped, got\n%v", name, o)
   315  	}
   316  	return o[idx].timestamp.UnixMilli(), nil
   317  }
   318  
   319  // parseOutput combines the container log from all of the init and regular
   320  // containers and parses/sorts the outputs to produce an execution log
   321  func parseOutput(ctx context.Context, f *framework.Framework, pod *v1.Pod) containerOutputList {
   322  	// accumulate all of our statuses
   323  	var statuses []v1.ContainerStatus
   324  	statuses = append(statuses, pod.Status.InitContainerStatuses...)
   325  	statuses = append(statuses, pod.Status.ContainerStatuses...)
   326  
   327  	var buf bytes.Buffer
   328  	for _, cs := range statuses {
   329  		log, err := e2epod.GetPodLogs(ctx, f.ClientSet, f.Namespace.Name, pod.Name, cs.Name)
   330  		if err != nil {
   331  			framework.Logf("error getting logs for %s: %v", cs.Name, err)
   332  			log, err = e2epod.GetPreviousPodLogs(ctx, f.ClientSet, f.Namespace.Name, pod.Name, cs.Name)
   333  			if err != nil {
   334  				framework.Logf("error getting previous logs for %s: %v", cs.Name, err)
   335  			}
   336  		}
   337  		buf.WriteString(log)
   338  	}
   339  
   340  	// parse
   341  	sc := bufio.NewScanner(&buf)
   342  	var res containerOutputList
   343  	for sc.Scan() {
   344  		fields := strings.Fields(sc.Text())
   345  		if len(fields) < 3 {
   346  			framework.ExpectNoError(fmt.Errorf("%v should have at least length 3", fields))
   347  		}
   348  		timestamp, err := time.Parse(time.RFC3339, fields[0])
   349  		framework.ExpectNoError(err)
   350  		res = append(res, containerOutput{
   351  			timestamp:     timestamp,
   352  			containerName: fields[1],
   353  			command:       fields[2],
   354  		})
   355  	}
   356  
   357  	// sort using the timeSinceBoot since it has more precision
   358  	sort.Slice(res, func(i, j int) bool {
   359  		return res[i].timestamp.Before(res[j].timestamp)
   360  	})
   361  	return res
   362  }
   363  
   364  // preparePod adds an empty dir volume and mounts it to each container at /persistent
   365  func preparePod(pod *v1.Pod) {
   366  	var defaultResourceRequirements = v1.ResourceRequirements{
   367  		Requests: v1.ResourceList{
   368  			v1.ResourceMemory: resource.MustParse("15Mi"),
   369  		},
   370  		Limits: v1.ResourceList{
   371  			v1.ResourceMemory: resource.MustParse("15Mi"),
   372  		},
   373  	}
   374  
   375  	for i := range pod.Spec.Containers {
   376  		c := &pod.Spec.Containers[i]
   377  		c.Resources = defaultResourceRequirements
   378  		c.VolumeMounts = []v1.VolumeMount{
   379  			{
   380  				Name:      "persistent",
   381  				MountPath: "/persistent",
   382  			},
   383  		}
   384  	}
   385  	for i := range pod.Spec.InitContainers {
   386  		c := &pod.Spec.InitContainers[i]
   387  		c.Resources = defaultResourceRequirements
   388  		c.VolumeMounts = []v1.VolumeMount{
   389  			{
   390  				Name:      "persistent",
   391  				MountPath: "/persistent",
   392  			},
   393  		}
   394  	}
   395  
   396  	pod.Spec.Volumes = []v1.Volume{
   397  		{
   398  			Name: "persistent",
   399  			VolumeSource: v1.VolumeSource{
   400  				EmptyDir: &v1.EmptyDirVolumeSource{},
   401  			},
   402  		},
   403  	}
   404  }