Source file src/k8s.io/kubernetes/test/e2e_node/container_lifecycle_pod_construction.go

Documentation: k8s.io/kubernetes/test/e2e_node

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

View as plain text