Skip to content

Commit

Permalink
SQUASH with tests/tests utilities
Browse files Browse the repository at this point in the history 
Signed-off-by: Gabriel Mougard <[email protected]>
  • Loading branch information
@gabrielmougard
gabrielmougard committed Feb 28, 2025
1 parent 15a3595 commit 21aaf3f
Show file tree
Hide file tree
Showing 7 changed files with 228 additions and 239 deletions.
60 changes: 41 additions & 19 deletions lxd/daemon.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ import (
liblxc "github.com/lxc/go-lxc"
"golang.org/x/sys/unix"

"github.com/canonical/lxd/client"
lxd "github.com/canonical/lxd/client"
"github.com/canonical/lxd/lxd/acme"
"github.com/canonical/lxd/lxd/apparmor"
"github.com/canonical/lxd/lxd/auth"
Expand Down Expand Up @@ -2063,10 +2063,30 @@ func (d *Daemon) Stop(ctx context.Context, sig os.Signal) error {
if err == nil {
instancesLoaded = true
}
}

ctx, cancel := context.WithTimeout(ctx, s.GlobalConfig.ShutdownTimeout())
defer cancel()
// Load cluster configuration.
var cancel context.CancelFunc
err = d.db.Cluster.Transaction(ctx, func(ctx context.Context, tx *db.ClusterTx) error {
config, err := clusterConfig.Load(ctx, tx)
if err != nil {
return err
}

d.globalConfigMu.Lock()
d.globalConfig = config
d.globalConfigMu.Unlock()

return nil
})
if err != nil {
logger.Warn("Failed loading cluster configuration", logger.Ctx{"err": err})
ctx, cancel = context.WithTimeout(ctx, 5*time.Minute)
} else {
ctx, cancel = context.WithTimeout(ctx, d.globalConfig.ShutdownTimeout())
}

defer cancel()
}

// Handle shutdown (unix.SIGPWR) and reload (unix.SIGTERM) signals.
if sig == unix.SIGPWR || sig == unix.SIGTERM {
Expand Down Expand Up @@ -2134,6 +2154,23 @@ func (d *Daemon) Stop(ctx context.Context, sig os.Signal) error {
}
}
}

if d.db.Cluster != nil {
// Remove remaining operations before closing the database.
err := s.DB.Cluster.Transaction(context.TODO(), func(ctx context.Context, tx *db.ClusterTx) error {
err := dbCluster.DeleteOperations(ctx, tx.Tx(), s.DB.Cluster.GetNodeID())
if err != nil {
logger.Error("Failed cleaning up operations")
}

return nil
})
if err != nil {
logger.Error("Failed cleaning up operations", logger.Ctx{"err": err})
} else {
logger.Debug("Operations deleted from the database")
}
}
}

if d.gateway != nil {
Expand All @@ -2154,21 +2191,6 @@ func (d *Daemon) Stop(ctx context.Context, sig os.Signal) error {
shouldUnmount := instancesLoaded && n <= 0

if d.db.Cluster != nil {
// Remove remaining operations before closing the database.
err = s.DB.Cluster.Transaction(context.TODO(), func(ctx context.Context, tx *db.ClusterTx) error {
err := dbCluster.DeleteOperations(ctx, tx.Tx(), s.DB.Cluster.GetNodeID())
if err != nil {
logger.Error("Failed cleaning up operations")
}

return nil
})
if err != nil {
logger.Error("Failed cleaning up operations", logger.Ctx{"err": err})
} else {
logger.Debug("Operations deleted from the database")
}

logger.Info("Closing the database")
err := d.db.Cluster.Close()
if err != nil {
Expand Down
6 changes: 3 additions & 3 deletions lxd/instances.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -532,7 +532,7 @@ func instancesShutdown(ctx context.Context, instances []instance.Instance, opsTr
go func(instShutdownCh <-chan instance.Instance) {
for inst := range instShutdownCh {
// Determine how long to wait for the instance to shutdown cleanly.
logger.Debug("Instance received for shutdown", logger.Ctx{"project": inst.Project().Name, "instance": inst.Name()})
logger.Debug("Instance received for shutdown", logger.Ctx{"project": inst.Project().Name, "instance": inst.Name(), "timestamp": time.Now().UnixNano()})
timeoutSeconds := 30
value, ok := inst.ExpandedConfig()["boot.host_shutdown_timeout"]
if ok {
Expand All @@ -556,7 +556,7 @@ func instancesShutdown(ctx context.Context, instances []instance.Instance, opsTr
}

wg.Done()
logger.Debug("Instance shutdown complete", logger.Ctx{"project": inst.Project().Name, "instance": inst.Name()})
logger.Debug("Instance shutdown complete", logger.Ctx{"project": inst.Project().Name, "instance": inst.Name(), "timestamp": time.Now().UnixNano()})
}
}(instShutdownCh)
}
Expand Down Expand Up @@ -612,7 +612,7 @@ func instancesShutdown(ctx context.Context, instances []instance.Instance, opsTr
}

currentBatchPriority = priority
logger.Info("Stopping instances", logger.Ctx{"stopPriority": currentBatchPriority})
logger.Info("Stopping instances", logger.Ctx{"stopPriority": currentBatchPriority, "timestamp": time.Now().UnixNano()})
}

if instancesTracker != nil && isInstanceBusy(instancesTracker, inst) {
Expand Down
90 changes: 83 additions & 7 deletions test/includes/check.sh
View file
Original file line number Diff line number Diff line change
Expand Up @@ -70,37 +70,113 @@ check_log_presence() {
}

# check_log_order checks for specific messages in a log file and validates their order.
# * The matching priorities are in the following order:
# 1. Unix nano timestamps (timestamp=<unix_nano>)
# 2. Standard log timestamps (time="2025-02-27T10:07:50+01:00")
# 3. Line position (fallback)
# * If a message is missing, it is reported as an error.
# * If a message is out of order, it is reported as an error.
check_log_order() {
local logfile="$1"
local expected_messages=("${@:2}")
local prev_line_num=0
local prev_timestamp=""
local prev_unix_timestamp=0
local all_in_order=true

for message in "${expected_messages[@]}"; do
line_num=$(grep -n "$message" "$logfile" | cut -d':' -f1)
local grep_output=$(grep -n "$message" "$logfile")

if [[ -z "$line_num" ]]; then
if [[ -z "$grep_output" ]]; then
echo "ERROR: Missing expected message: '$message'"
echo " (Looking for: '$message')"
all_in_order=false
continue
fi

if (( line_num > prev_line_num )); then
echo "Found expected message: '$message' on line $line_num (Order OK)"
# If multiple matches, take the first one
local first_match=$(echo "$grep_output" | head -n1)
local line_num=$(echo "$first_match" | cut -d':' -f1)
local full_line=$(echo "$first_match" | cut -d':' -f2-)

# Extract timestamp=<unix_nano> with proper pattern for long integers (high priority)
local current_unix_timestamp=$(echo "$full_line" | grep -o 'timestamp=[0-9]\+' | cut -d'=' -f2)

# Extract standard timestamp (format: time="2025-02-27T10:07:50+01:00")
local current_timestamp=$(echo "$full_line" | grep -o 'time="[^"]*"' | cut -d'"' -f2)

echo "DEBUG: Message: '$message'"
echo "DEBUG: Line Number: $line_num"
if [[ -n "$current_unix_timestamp" ]]; then
echo "DEBUG: Unix Timestamp: $current_unix_timestamp"
fi
if [[ -n "$current_timestamp" ]]; then
echo "DEBUG: Time: $current_timestamp"
fi

# First message is always in order
if [[ -z "$prev_unix_timestamp" && -z "$prev_timestamp" ]]; then
echo "Found first expected message: '$message' on line $line_num"
prev_line_num=$line_num
prev_timestamp=$current_timestamp
prev_unix_timestamp=$current_unix_timestamp
continue
fi

# Check order based on priority
local in_order=false
local order_method=""

# Priority 1: Check unix nano timestamps if available for both messages
if [[ -n "$current_unix_timestamp" && -n "$prev_unix_timestamp" ]]; then
# Compare as numbers, not strings
if (( 10#$current_unix_timestamp >= 10#$prev_unix_timestamp )); then
in_order=true
order_method="Unix timestamp (nanoseconds)"
fi
# Priority 2: Use line standard log timestamps
elif [[ -n "$current_timestamp" && -n "$prev_timestamp" ]]; then
# Compare timestamps as strings
if [[ "$current_timestamp" == "$prev_timestamp" || "$current_timestamp" > "$prev_timestamp" ]]; then
in_order=true
order_method="Standard timestamp"
fi
# Priority 3: Fall back to line position.
elif (( line_num > prev_line_num )); then
in_order=true
order_method="Line position"
fi

if $in_order; then
echo "✓ OK: Message '$message' is in order (by $order_method)"
else
echo "ERROR: Expected message '$message' is out of order!"
echo " (Found on line: $line_num, Previous message on line: $prev_line_num)"
echo " Found on line: $line_num, Previous message on line: $prev_line_num"
if [[ -n "$current_unix_timestamp" && -n "$prev_unix_timestamp" ]]; then
echo " Current unix timestamp: $current_unix_timestamp"
echo " Previous unix timestamp: $prev_unix_timestamp"
fi

if [[ -n "$current_timestamp" && -n "$prev_timestamp" ]]; then
echo " Current standard timestamp: $current_timestamp"
echo " Previous standard timestamp: $prev_timestamp"
fi

all_in_order=false
fi

# Update tracking variables
prev_line_num=$line_num
prev_timestamp=$current_timestamp
prev_unix_timestamp=$current_unix_timestamp
done

echo "----------------------------------------"
if "$all_in_order"; then
echo "Log file check (order) completed. All messages in correct order."
echo "✓ Log file check PASSED: All messages found in correct order."
return 0
else
echo "Log file check (order) completed with errors. Messages are out of order or missing."
echo "✗ Log file check FAILED: Messages are out of order or missing."
return 1
fi
}
Loading

0 comments on commit 21aaf3f

Please sign in to comment.