Skip to content

Debug apt get timeout #1257

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

Draft
adombeck wants to merge 14 commits into
base: main
Choose a base branch
from
Draft

Debug apt get timeout #1257

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
14 commits
Select commit Hold shift + click to select a range
5a33b48
Split update && upgrade apt calls to avoid timeout
denisonbarbosa Apr 23, 2025
dccd884
XXX: Set log level debug
adombeck May 16, 2025
7b0a1ee
Add DEBIAN_FRONTEND=noninteractive
adombeck May 16, 2025
27dff0d
Use dpkg options to never ask questions
adombeck May 16, 2025
e4b2b09
Print stdout bytes without waiting for newline
adombeck May 16, 2025
7d0197a
fixup
adombeck May 16, 2025
faa356a
wip
adombeck May 16, 2025
33478d0
WIP: Make apt print progress (hopefully)
adombeck Jun 3, 2025
ca2dce2
Use -oDebug::pkgAcquire::Worker=1
adombeck Jun 3, 2025
cb1757c
Request pseudo terminal
adombeck Jun 3, 2025
f975aaa
XXX: Simpler stdout/stderr piping (just for debugging)
adombeck Jun 3, 2025
3385fcd
XXX: Set GODEBUG=ssh=2 in e2e-tests
adombeck Jun 3, 2025
19d13ec
Revert "XXX: Simpler stdout/stderr piping (just for debugging)"
adombeck Jun 3, 2025
9309a04
Try running commands via `ssh` command
adombeck Jun 3, 2025
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
1 change: 1 addition & 0 deletions .github/workflows/e2e-tests.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -87,6 +87,7 @@ jobs:
env:
AD_PASSWORD: ${{ secrets.AD_PASSWORD }}
ADSYS_PRO_TOKEN: ${{ secrets.ADSYS_PRO_TOKEN }}
GODEBUG: "ssh=2"
steps:
- name: Install required dependencies
run: |
Expand Down
29 changes: 21 additions & 8 deletions e2e/cmd/build_base_image/01_prepare_base_vm/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -140,21 +140,34 @@ func action(ctx context.Context, cmd *command.Command) error {

// Install required dependencies
log.Infof("Installing eatmydata to speed up package installation...")
if _, err := client.Run(ctx, `echo force-unsafe-io | sudo tee /etc/dpkg/dpkg.cfg.d/force-unsafe-io && \
sudo apt-get update && sudo DEBIAN_FRONTEND=noninteractive apt-get install -y eatmydata`); err != nil {
if _, err := client.Run(ctx, "echo force-unsafe-io | sudo tee /etc/dpkg/dpkg.cfg.d/force-unsafe-io"); err != nil {
return fmt.Errorf("failed to install required packages: %w", err)
}

if _, err := client.Run(ctx, "sudo apt-get update"); err != nil {
return fmt.Errorf("failed to update packages: %w", err)
}

if _, err := client.Run(ctx, "sudo DEBIAN_FRONTEND=noninteractive apt-get install -y eatmydata"); err != nil {
return fmt.Errorf("failed to set up eatmydata: %w", err)
}

log.Infof("Installing required packages on VM...")
if _, err := client.Run(ctx, `echo force-unsafe-io | sudo tee /etc/dpkg/dpkg.cfg.d/force-unsafe-io && \
sudo eatmydata apt-get update && sudo DEBIAN_FRONTEND=noninteractive eatmydata apt-get upgrade -y && \
sudo DEBIAN_FRONTEND=noninteractive eatmydata apt-get install -y ubuntu-desktop realmd nfs-common cifs-utils && \
sudo sync && \
sudo rm -f /etc/dpkg/dpkg.cfg.d/force-unsafe-io
`); err != nil {
_, err = client.Run(ctx, "sudo DEBIAN_FRONTEND=noninteractive eatmydata apt-get upgrade -y")
if err != nil {
return fmt.Errorf("failed to update packages: %w", err)
}

_, err = client.Run(ctx, "sudo DEBIAN_FRONTEND=noninteractive eatmydata apt-get install -y ubuntu-desktop realmd nfs-common cifs-utils")
if err != nil {
return fmt.Errorf("failed to install required packages: %w", err)
}

_, err = client.Run(ctx, "sudo sync && sudo rm -f /etc/dpkg/dpkg.cfg.d/force-unsafe-io")
if err != nil {
return fmt.Errorf("failed to clean up eatmydata: %w", err)
}

scriptsDir, err := scripts.Dir()
if err != nil {
return fmt.Errorf("failed to get scripts directory: %w", err)
Expand Down
13 changes: 9 additions & 4 deletions e2e/cmd/run_tests/01_provision_client/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -176,22 +176,27 @@ func action(ctx context.Context, cmd *command.Command) error {
}
}

log.Infof("Upgrading packages...")
_, err = client.Run(ctx, "apt-get -y update && DEBIAN_FRONTEND=noninteractive apt-get -y upgrade")
log.Infof("Updating and upgrading packages...")
_, err = client.Run(ctx, "apt-get update -oDebug::pkgAcquire::Worker=1")
if err != nil {
return fmt.Errorf("failed to update package list: %w", err)
}

_, err = client.Run(ctx, "DEBIAN_FRONTEND=noninteractive DEBCONF_NONINTERACTIVE_SEEN=true apt-get upgrade -y -o Dpkg::Options::=\"--force-confdef\" -o Dpkg::Options::=\"--force-confold\" -o Dpkg::Progress-Fancy=\"1\" -oDebug::pkgAcquire::Worker=1")
if err != nil {
return fmt.Errorf("failed to upgrade packages: %w", err)
}

log.Infof("Installing adsys package...")
_, err = client.Run(ctx, "DEBIAN_FRONTEND=noninteractive apt-get install -y /debs/*.deb")
_, err = client.Run(ctx, "DEBIAN_FRONTEND=noninteractive DEBCONF_NONINTERACTIVE_SEEN=true apt-get install /debs/*.deb -y -o Dpkg::Progress-Fancy=\"1\" -oDebug::pkgAcquire::Worker=1")
if err != nil {
return fmt.Errorf("failed to install adsys package: %w", err)
}

// TODO: remove this once the packages installed below are MIRed and installed by default with adsys
// Allow errors here on account on packages not being available on the tested Ubuntu version
log.Infof("Installing universe packages required for some policy managers...")
if _, err := client.Run(ctx, "DEBIAN_FRONTEND=noninteractive apt-get install -y ubuntu-proxy-manager python3-cepces"); err != nil {
if _, err := client.Run(ctx, "DEBIAN_FRONTEND=noninteractive DEBCONF_NONINTERACTIVE_SEEN=true apt-get install ubuntu-proxy-manager python3-cepces -y -o Dpkg::Progress-Fancy=\"1\" -oDebug::pkgAcquire::Worker=1"); err != nil {
log.Warningf("Some packages failed to install: %v", err)
}

Expand Down
183 changes: 101 additions & 82 deletions e2e/internal/remote/remote.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,12 @@
package remote

import (
"bufio"
"context"
"errors"
"fmt"
"os"
"os/exec"
"path/filepath"
"strings"
"sync"
"time"

"github.com/pkg/sftp"
Expand Down Expand Up @@ -94,91 +92,112 @@

// Run runs the given command on the remote host and returns the combined output
// while also printing the command output as it occurs.
func (c Client) Run(ctx context.Context, cmd string) ([]byte, error) {
func (c Client) Run(ctx context.Context, cmdStr string) ([]byte, error) {
ctx, cancel := context.WithTimeout(ctx, commandTimeout)
defer cancel()

// Create a session
session, err := c.client.NewSession()
// Run the command via `ssh` directly
cmd := exec.CommandContext(ctx, "ssh", "-vv", c.client.User()+"@"+c.host, cmdStr)

Check failure on line 100 in e2e/internal/remote/remote.go

View workflow job for this annotation

GitHub Actions / Code sanity 

G204: Subprocess launched with a potential tainted input or cmd arguments (gosec)
cmd.Stderr = os.Stderr
cmd.Stdout = os.Stdout
err := cmd.Run()
if err != nil {
return nil, fmt.Errorf("failed to create session: %w", err)
}
defer session.Close()

// Create pipes for stdout and stderr
stdout, err := session.StdoutPipe()
if err != nil {
return nil, fmt.Errorf("failed to create stdout pipe: %w", err)
}
stderr, err := session.StderrPipe()
if err != nil {
return nil, fmt.Errorf("failed to create stderr pipe: %w", err)
}

log.Infof("Running command %q on remote host %q", cmd, c.client.RemoteAddr().String())

// Start the remote command
startTime := time.Now()
if err := session.Start(cmd); err != nil {
return nil, fmt.Errorf("failed to start command: %w", err)
}

// Create scanners to read stdout and stderr line by line
stdoutScanner := bufio.NewScanner(stdout)
stderrScanner := bufio.NewScanner(stderr)
var combinedOutput []string
var mu sync.Mutex
var wg sync.WaitGroup

// Use goroutines to read and print both stdout and stderr concurrently
wg.Add(2)
go func() {
for stdoutScanner.Scan() {
line := stdoutScanner.Text()
log.Debug("\t", line)
mu.Lock()
combinedOutput = append(combinedOutput, line)
mu.Unlock()
}
wg.Done()
}()
go func() {
for stderrScanner.Scan() {
line := stderrScanner.Text()
log.Warning("\t", line)
mu.Lock()
combinedOutput = append(combinedOutput, line)
mu.Unlock()
if errors.Is(err, context.DeadlineExceeded) {
return nil, fmt.Errorf("command timed out after %s: %w", commandTimeout, err)
}
wg.Done()
}()

waitDone := make(chan error, 1)
go func() {
waitDone <- session.Wait()
}()

select {
case <-ctx.Done():
if errors.Is(ctx.Err(), context.DeadlineExceeded) {
return nil, fmt.Errorf("command timed out after %s", commandTimeout)
}
return nil, fmt.Errorf("command cancelled: %w", ctx.Err())
case err := <-waitDone:
elapsedTime := time.Since(startTime)
wg.Wait() // wait for scanners to finish
mu.Lock()
defer mu.Unlock()

out := []byte(strings.Join(combinedOutput, "\n"))
if err != nil {
log.Warningf("Command %q failed in %s", cmd, elapsedTime)
return out, fmt.Errorf("command failed: %w", err)
}
log.Infof("Command %q finished in %s", cmd, elapsedTime)

return out, nil
return nil, fmt.Errorf("failed to run command %q on host %q: %w", cmdStr, c.host, err)
}
return nil, nil

//// Create a session
//session, err := c.client.NewSession()
//if err != nil {
// return nil, fmt.Errorf("failed to create session: %w", err)
//}
//defer session.Close()
//
//err = session.RequestPty("xterm", 80, 40, ssh.TerminalModes{})
//if err != nil {
// log.Fatalf("Request for pseudo terminal failed: %v", err)
//}
//
//// Create pipes for stdout and stderr
//stdout, err := session.StdoutPipe()
//if err != nil {
// return nil, fmt.Errorf("failed to create stdout pipe: %w", err)
//}
//stderr, err := session.StderrPipe()
//if err != nil {
// return nil, fmt.Errorf("failed to create stderr pipe: %w", err)
//}
//
//log.Infof("Running command %q on remote host %q", cmdStr, c.client.RemoteAddr().String())
//
//// Start the remote command
//startTime := time.Now()
//if err := session.Start(cmdStr); err != nil {
// return nil, fmt.Errorf("failed to start command: %w", err)
//}
//
//// Create scanners to read stdout and stderr line by line
//stdoutScanner := bufio.NewScanner(stdout)
//stderrScanner := bufio.NewScanner(stderr)
////stdoutScanner.Split(bufio.ScanWords)
//var combinedOutput []string
//var mu sync.Mutex
//var wg sync.WaitGroup
//
//log.SetLevel(log.DebugLevel)
//
//// Use goroutines to read and print both stdout and stderr concurrently
//wg.Add(2)
//go func() {
// for stdoutScanner.Scan() {
// line := stdoutScanner.Text()
// log.Debug("\t", line)
// mu.Lock()
// combinedOutput = append(combinedOutput, line)
// mu.Unlock()
// }
// wg.Done()
//}()
//go func() {
// for stderrScanner.Scan() {
// line := stderrScanner.Text()
// log.Warning("\t", line)
// mu.Lock()
// combinedOutput = append(combinedOutput, line)
// mu.Unlock()
// }
// wg.Done()
//}()
//
//waitDone := make(chan error, 1)
//go func() {
// waitDone <- session.Wait()
//}()
//
//select {
//case <-ctx.Done():
// if errors.Is(ctx.Err(), context.DeadlineExceeded) {
// return nil, fmt.Errorf("command timed out after %s", commandTimeout)
// }
// return nil, fmt.Errorf("command cancelled: %w", ctx.Err())
//case err := <-waitDone:
// elapsedTime := time.Since(startTime)
// wg.Wait() // wait for scanners to finish
// mu.Lock()
// defer mu.Unlock()
//
// out := []byte(strings.Join(combinedOutput, "\n"))
// if err != nil {
// log.Warningf("Command %q failed in %s", cmdStr, elapsedTime)
// return out, fmt.Errorf("command failed: %w", err)
// }
// log.Infof("Command %q finished in %s", cmdStr, elapsedTime)
//
// return out, nil
//}
}

// Upload uploads the given local file to the remote host.
Expand Down
Loading