k8s.io/kubernetes@v1.29.3/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 "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 }