Fix scripts that block execution of subsequent scripts when timing out on Windows (#19485)

This commit is contained in:
Martin Angers
2024-06-11 09:21:57 -04:00
committed by GitHub
parent dec9bc53e3
commit 6dd365f266
6 changed files with 51 additions and 10 deletions
@@ -0,0 +1 @@
* Fixed scripts that were blocking execution of other scripts after timing out on Windows.
+9 -1
View File
@@ -6,6 +6,7 @@ import (
"context"
"os/exec"
"path/filepath"
"time"
)
func ExecCmd(ctx context.Context, scriptPath string, env []string) (output []byte, exitCode int, err error) {
@@ -16,8 +17,15 @@ func ExecCmd(ctx context.Context, scriptPath string, env []string) (output []byt
cmd := exec.CommandContext(ctx, "powershell", "-MTA", "-ExecutionPolicy", "Bypass", "-File", scriptPath)
cmd.Env = env
cmd.Dir = filepath.Dir(scriptPath)
cmd.WaitDelay = time.Second
output, err = cmd.CombinedOutput()
if cmd.ProcessState != nil {
// we still check if the context was cancelled before setting an exitCode !=
// -1, as killing a process on Windows is not straightforward (see the
// WaitDelay documentation) and may have timed out even if exit code is
// reported as 1, so keep it to -1 in that case so that all user messages are
// as expected.
if cmd.ProcessState != nil && ctx.Err() == nil {
// The windows exit code is a 32-bit unsigned integer, but the
// interpreter treats it like a signed integer. When a process
// is killed, it returns 0xFFFFFFFF (interpreted as -1). We
+4
View File
@@ -15,6 +15,7 @@ import (
"github.com/fleetdm/fleet/v4/orbit/pkg/constant"
"github.com/fleetdm/fleet/v4/pkg/scripts"
"github.com/fleetdm/fleet/v4/server/fleet"
"github.com/rs/zerolog/log"
)
// Client defines the methods required for the API requests to the server. The
@@ -65,6 +66,7 @@ func (r *Runner) Run(execIDs []string) error {
break
}
log.Debug().Msgf("running script %v", execID)
if err := r.runOne(script); err != nil {
errs = append(errs, err)
}
@@ -120,7 +122,9 @@ func (r *Runner) runOne(script *fleet.HostScriptResult) (finalErr error) {
execCmdFn = ExecCmd
}
start := time.Now()
log.Debug().Msgf("starting script execution of %v", script.ExecutionID)
output, exitCode, execErr := execCmdFn(ctx, scriptFile, nil)
log.Debug().Msgf("after script execution of %v", script.ExecutionID)
duration := time.Since(start)
// report the output or the error
+22 -5
View File
@@ -231,14 +231,31 @@ func (ds *Datastore) MarkActivitiesAsStreamed(ctx context.Context, activityIDs [
// software to install, etc.) and provides a unified view of those upcoming
// tasks.
func (ds *Datastore) ListHostUpcomingActivities(ctx context.Context, hostID uint, opt fleet.ListOptions) ([]*fleet.Activity, *fleet.PaginationMetadata, error) {
// NOTE: Be sure to update both the count (here) and list statements (below)
// if the query condition is modified.
countStmts := []string{
`SELECT COUNT(*) c FROM host_script_results WHERE host_id = :host_id AND exit_code IS NULL`,
`SELECT COUNT(*) c FROM host_software_installs WHERE host_id = :host_id AND pre_install_query_output IS NULL AND install_script_exit_code IS NULL`,
`SELECT
COUNT(*) c
FROM host_script_results
WHERE host_id = :host_id AND
exit_code IS NULL AND
(sync_request = 0 OR created_at >= DATE_SUB(NOW(), INTERVAL :max_wait_time SECOND))`,
`SELECT
COUNT(*) c
FROM host_software_installs
WHERE host_id = :host_id AND
pre_install_query_output IS NULL AND
install_script_exit_code IS NULL`,
}
var count uint
countStmt := `SELECT SUM(c) FROM ( ` + strings.Join(countStmts, " UNION ALL ") + ` ) AS counts`
countStmt, args, err := sqlx.Named(countStmt, map[string]any{"host_id": hostID})
seconds := int(scripts.MaxServerWaitTime.Seconds())
countStmt, args, err := sqlx.Named(countStmt, map[string]any{
"host_id": hostID,
"max_wait_time": seconds,
})
if err != nil {
return nil, nil, ctxerr.Wrap(ctx, err, "build count query from named args")
}
@@ -249,7 +266,8 @@ func (ds *Datastore) ListHostUpcomingActivities(ctx context.Context, hostID uint
return []*fleet.Activity{}, &fleet.PaginationMetadata{}, nil
}
// NOTE: Be sure to update both the count and list statements if the list query is modified
// NOTE: Be sure to update both the count (above) and list statements (below)
// if the query condition is modified.
listStmts := []string{
// list pending scripts
`SELECT
@@ -318,7 +336,6 @@ func (ds *Datastore) ListHostUpcomingActivities(ctx context.Context, hostID uint
`, softwareInstallerHostStatusNamedQuery("hsi", "")),
}
seconds := int(scripts.MaxServerWaitTime.Seconds())
listStmt := `
SELECT
uuid,
+11 -1
View File
@@ -10,6 +10,7 @@ import (
"testing"
"time"
"github.com/fleetdm/fleet/v4/pkg/scripts"
"github.com/fleetdm/fleet/v4/server/contexts/viewer"
"github.com/fleetdm/fleet/v4/server/fleet"
"github.com/fleetdm/fleet/v4/server/ptr"
@@ -414,8 +415,17 @@ func testListHostUpcomingActivities(t *testing.T, ds *Datastore) {
sw2Meta, err := ds.GetSoftwareInstallerMetadataByID(ctx, sw2)
require.NoError(t, err)
// create a sync script request for h1 that has been pending for > MaxWaitTime, will not show up
hsr, err := ds.NewHostScriptExecutionRequest(ctx, &fleet.HostScriptRequestPayload{HostID: h1.ID, ScriptContents: "sync", UserID: &u.ID, SyncRequest: true})
require.NoError(t, err)
hSyncExpired := hsr.ExecutionID
ExecAdhocSQL(t, ds, func(q sqlx.ExtContext) error {
_, err := q.ExecContext(ctx, "UPDATE host_script_results SET created_at = ? WHERE execution_id = ?", time.Now().Add(-(scripts.MaxServerWaitTime + time.Minute)), hSyncExpired)
return err
})
// create some script requests for h1
hsr, err := ds.NewHostScriptExecutionRequest(ctx, &fleet.HostScriptRequestPayload{HostID: h1.ID, ScriptID: &scr1.ID, ScriptContents: scr1.ScriptContents, UserID: &u.ID})
hsr, err = ds.NewHostScriptExecutionRequest(ctx, &fleet.HostScriptRequestPayload{HostID: h1.ID, ScriptID: &scr1.ID, ScriptContents: scr1.ScriptContents, UserID: &u.ID})
require.NoError(t, err)
h1A := hsr.ExecutionID
hsr, err = ds.NewHostScriptExecutionRequest(ctx, &fleet.HostScriptRequestPayload{HostID: h1.ID, ScriptID: &scr2.ID, ScriptContents: scr2.ScriptContents, UserID: &u.ID})
+4 -3
View File
@@ -11265,8 +11265,9 @@ func (s *integrationTestSuite) TestListHostUpcomingActivities() {
endTime = mysql.SetOrderedCreatedAtTimestamps(t, s.ds, endTime, "host_software_installs", "execution_id", h1Foo)
mysql.SetOrderedCreatedAtTimestamps(t, s.ds, endTime, "host_script_results", "execution_id", h1C, h1D, h1E)
// modify the timestamp h1A and h1B to simulate an script that has
// been pending for a long time
// modify the timestamp h1A and h1B to simulate an script that has been
// pending for a long time (h1A is a sync request, so it will be ignored for
// upcoming activities)
mysql.ExecAdhocSQL(t, s.ds, func(tx sqlx.ExtContext) error {
_, err := tx.ExecContext(ctx, "UPDATE host_script_results SET created_at = ? WHERE execution_id IN (?, ?)", time.Now().Add(-24*time.Hour), h1A, h1B)
return err
@@ -11323,7 +11324,7 @@ func (s *integrationTestSuite) TestListHostUpcomingActivities() {
queryArgs := c.queries
s.DoJSON("GET", fmt.Sprintf("/api/latest/fleet/hosts/%d/activities/upcoming", host1.ID), nil, http.StatusOK, &listResp, queryArgs...)
require.Equal(t, uint(6), listResp.Count)
require.Equal(t, uint(5), listResp.Count)
require.Equal(t, len(c.wantExecs), len(listResp.Activities))
require.Equal(t, c.wantMeta, listResp.Meta)