Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore: write updater logs to host file [BE-10984] (Experiment) #28

Closed
wants to merge 3 commits into from
Closed

chore: write updater logs to host file [BE-10984] (Experiment) #28

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
e851910
chore: log to file
oscarzhou-portainer Jul 23, 2024
5519fff
chore: add more debug logs
oscarzhou-portainer Jul 29, 2024
b757e81
chore: simulate long-time pulling image
oscarzhou-portainer Aug 3, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
69 changes: 65 additions & 4 deletions dockerstandalone/update.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"encoding/json"
"fmt"
"io"
"math/rand"
"os"
"strings"
"time"
Expand All @@ -29,7 +30,7 @@ func Update(ctx context.Context, dockerCli *client.Client, oldContainerId string
Str("image", imageName).
Msg("Starting update process")

// We look for the existing container to copy its configuration
// We look for the existing container to copy its configuration
log.Debug().
Str("containerId", oldContainerId).
Msg("Looking for container")
Expand Down Expand Up @@ -67,18 +68,28 @@ func Update(ctx context.Context, dockerCli *client.Client, oldContainerId string
}

oldContainerName := strings.TrimPrefix(oldContainer.Name, "/")
log.Info().Str("old_container_name", oldContainerName).Msg("retrieving old container name")

// We create the new container
tempContainerName := buildContainerName(oldContainerName)
log.Info().Str("temporary_container_name", tempContainerName).Msg("creating new container")

newContainerID, err := createContainer(ctx, dockerCli, imageName, tempContainerName, oldContainer, updateConfig)
if err != nil {
log.Err(err).
Str("image_name", imageName).
Str("tempory_container_name", tempContainerName).
Str("old_container", oldContainerId).
Str("new_container_id", newContainerID).
Str("context", "UpdaterCreatesNewAgentContainer").
Msg("Unable to create container")

return cleanupContainerAndError(ctx, dockerCli, oldContainerId, newContainerID)
}

log.Info().Str("old_container_id", oldContainer.ID).
Str("new_container_id", newContainerID).
Msg("will start container")
err = startContainer(ctx, dockerCli, oldContainer.ID, newContainerID)
if err != nil {
log.Err(err).
Expand All @@ -87,22 +98,38 @@ func Update(ctx context.Context, dockerCli *client.Client, oldContainerId string
return cleanupContainerAndError(ctx, dockerCli, oldContainerId, newContainerID)
}

log.Info().
Str("new_container_id", newContainerID).
Str("old_container_id", oldContainerId).
Msg("will monitor container health")
healthy, err := monitorHealth(ctx, dockerCli, newContainerID)
if err != nil {
log.Err(err).
Str("new_container_id", newContainerID).
Str("old_container_id", oldContainerId).
Str("context", "UpdateInProgress").
Msg("Unable to monitor container health")
return cleanupContainerAndError(ctx, dockerCli, oldContainerId, newContainerID)
}

if !healthy {
log.Debug().
Str("new_container_id", newContainerID).
Str("old_container_id", oldContainerId).
Str("context", "UpdateInProgress").
Msg("The container is not healthy. Return")
return cleanupContainerAndError(ctx, dockerCli, oldContainerId, newContainerID)
}

log.Info().
Msg("New container is healthy. The old will be removed.")
Msg("New container is healthy. The old will be removed.")

tryRemoveOldContainer(ctx, dockerCli, oldContainer.ID)

log.Debug().
Str("old_container_id", oldContainer.ID).
Msg("Old container is removed")

// rename new container to old container name
err = dockerCli.ContainerRename(ctx, newContainerID, oldContainerName)
if err != nil {
Expand All @@ -124,6 +151,7 @@ func cleanupContainerAndError(ctx context.Context, dockerCli *client.Client, old
log.Debug().
Msg("An error occurred during the update process - removing newly created container")

log.Debug().Msg("skip to restart old container")
// should restart old container
err := dockerCli.ContainerStart(ctx, oldContainerId, container.StartOptions{})
if err != nil {
Expand All @@ -135,8 +163,8 @@ func cleanupContainerAndError(ctx context.Context, dockerCli *client.Client, old
if newContainerID != "" {
printLogsToStdout(ctx, dockerCli, newContainerID)

err = dockerCli.ContainerRemove(ctx, newContainerID, container.RemoveOptions{Force: true})
if err != nil {
log.Debug().Msg("skip to remove the new container")
if err := dockerCli.ContainerRemove(ctx, newContainerID, container.RemoveOptions{Force: true}); err != nil {
log.Err(err).
Msg("Unable to remove temporary container, please remove it manually")
}
Expand All @@ -155,6 +183,7 @@ func buildContainerName(containerName string) string {

func pullImage(ctx context.Context, dockerCli *client.Client, imageName string) (bool, error) {
if os.Getenv("SKIP_PULL") != "" {
simPullImageSleep()
return false, nil
}

Expand Down Expand Up @@ -272,6 +301,10 @@ func monitorHealth(ctx context.Context, dockerCli *client.Client, containerId st

if container.State.Health == nil {
if container.State.Status == "exited" {
log.Info().
Str("containerId", containerId).
Str("status", container.State.Status).
Msg("monitorHealth found container exited unexpectedly")
return false, errors.New("Container exited unexpectedly")
}

Expand All @@ -285,6 +318,10 @@ func monitorHealth(ctx context.Context, dockerCli *client.Client, containerId st

tries := 5
for i := 0; i < tries; i++ {
log.Debug().Int("retry_time", i+1).
Str("container_state_health_status", container.State.Health.Status).
Str("context", "MonitorHealthStatus").
Msg("Updater monitors health status")

if container.State.Health.Status == "healthy" {
return true, nil
Expand Down Expand Up @@ -349,6 +386,12 @@ func createContainer(ctx context.Context, dockerCli *client.Client, imageName, t

updateConfig(containerConfigCopy)

log.Debug().
Str("update_id", containerConfigCopy.Labels["io.portainer.update.scheduleId"]).
Strs("cmds", containerConfigCopy.Cmd).
Str("temporary_container_name", tempContainerName).
Msg("Copied container config")

newContainer, err := dockerCli.ContainerCreate(ctx,
containerConfigCopy,
oldContainer.HostConfig,
Expand Down Expand Up @@ -387,3 +430,21 @@ func printLogsToStdout(ctx context.Context, dockerCli *client.Client, containerI
}

}

func simPullImageSleep() {
rand.Seed(time.Now().UnixNano())

// Define the minimum and maximum durations in seconds
minDuration := 2*60 + 50 // 2 minutes 50 seconds in seconds
maxDuration := 4 * 60 // 4 minutes in seconds

// Generate a random duration within the range
randomDuration := time.Duration(rand.Intn(maxDuration-minDuration+1)+minDuration) * time.Second

// Print the random duration for reference
log.Info().Dur("simulate_pull_image_sleep", randomDuration).
Msg("simulate sleep")

// Sleep for the random duration
time.Sleep(randomDuration)
}
13 changes: 7 additions & 6 deletions log/log.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,19 +24,20 @@ const (
)

// ConfigureLogger configures the logger
func ConfigureLogger(pretty bool) {
func ConfigureLogger(pretty bool, file *os.File) {
zerolog.ErrorStackFieldName = "stack_trace"
zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack
zerolog.TimeFieldFormat = zerolog.TimeFormatUnix

stdlog.SetFlags(0)
stdlog.SetOutput(log.Logger)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is the reason for removing this?


log.Logger = log.Logger.With().Caller().Stack().Logger()
log.Logger = zerolog.New(file).With().Caller().Stack().Logger()

if pretty {
log.Logger = log.Logger.Output(zerolog.ConsoleWriter{Out: os.Stderr})
}
// log.Logger = log.Logger.With().Caller().Stack().Logger()

// if pretty {
// log.Logger = log.Logger.Output(zerolog.ConsoleWriter{Out: os.Stderr})
// }
}

// SetLoggingLevel sets the logging level
Expand Down
14 changes: 11 additions & 3 deletions main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,11 +19,19 @@ func main() {
Summary: true,
}))

log.ConfigureLogger(cli.CLI.PrettyLog)
file, err := os.OpenFile("/tmp/updater.log",
os.O_APPEND|os.O_CREATE|os.O_WRONLY,
0664,
)
if err != nil {
panic(err)
}
defer file.Close()

log.ConfigureLogger(cli.CLI.PrettyLog, file)
log.SetLoggingLevel(log.Level(cli.CLI.LogLevel))

err := cliCtx.Run()
if err != nil {
if err := cliCtx.Run(); err != nil {
cliCtx.FatalIfErrorf(err)
}
os.Exit(0)
Expand Down
Loading