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 }