Skip to content

Fix for console and file explorer timeout #1065

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

Merged
javuto merged 1 commit into from
Sep 25, 2026
Merged

Fix for console and file explorer timeout #1065

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
75 changes: 24 additions & 51 deletions cmd/api/handlers/console.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ func (h *HandlersApi) ConsoleSessionCreateHandler(w http.ResponseWriter, r *http
// node's next QueryRead can also switch to fast polling before the
// operator types their first command. A priming failure is non-fatal.
var priming *console.Command
if primingCmd, primingErr := h.Console.SubmitPrimingCommand(session.ID, h.consolePrimingTimeout(env, node)); primingErr == nil {
if primingCmd, primingErr := h.Console.SubmitPrimingCommand(session.ID, h.consolePrimingTimeout(env)); primingErr == nil {
priming = &primingCmd
}
h.auditConsoleVisit(ctx[ctxUser], r, env.ID)
Expand Down Expand Up @@ -146,11 +146,7 @@ func (h *HandlersApi) ConsoleCommandCreateHandler(w http.ResponseWriter, r *http
apiErrorResponse(w, "no access", http.StatusForbidden, fmt.Errorf("attempt to use console get by user %s", ctx[ctxUser]))
return
}
node, ok := h.sessionNode(w, env, session.NodeUUID)
if !ok {
return
}
command, parsed, err := h.Console.SubmitCommandWithTimeout(session.ID, body.Input, h.consoleCommandTimeout(env, node, preview), body.OsqueryMode)
command, parsed, err := h.Console.SubmitCommandWithTimeout(session.ID, body.Input, h.consoleCommandTimeout(env, preview), body.OsqueryMode)
if err != nil {
apiErrorResponse(w, err.Error(), http.StatusBadRequest, err)
return
Expand Down Expand Up @@ -257,55 +253,50 @@ func (h *HandlersApi) acceleratedQueryReadSeconds() int64 {
// distributed interval (--distributed_interval = env.QueryInterval), not
// at the accelerated interval. A query expiring before the node's next
// scheduled read is never delivered, which is what forced operators to
// click refresh repeatedly until acceleration happened to kick in. The
// last query read recorded for the node makes the next read predictable:
// last read + configured interval. The wait is whatever remains of that
// window, capped by maxWarmupWait. Once acceleration is active the last
// read is fresh, the wait collapses to zero, and the base timeout alone
// covers delivery on the (now fast) polling cadence.
func warmupQueryWait(env environments.TLSEnvironment, node nodes.OsqueryNode) time.Duration {
// click refresh repeatedly until acceleration happened to kick in.
//
// The node's recorded last read is deliberately not used to shrink this
// window. osctrl-tls stamps last_query_read through a batch writer that
// coalesces check-ins and flushes on --writer-timeout (60s by default),
// so the stamp can lag the node's real poll by roughly one interval —
// the same magnitude as the window being predicted. Trusting it made
// mid-cycle reads look overdue, granted no extra wait, and expired
// warmup commands undelivered. Reserving the full interval keeps
// delivery certain for live nodes; once acceleration is active the
// command completes on the first fast poll and the extra expiration
// only bounds how long a dead node's command stays pending.
func warmupQueryWait(env environments.TLSEnvironment) time.Duration {
interval := env.QueryInterval
if interval <= 0 {
interval = environments.DefaultQueryInterval
}
if node.LastQueryRead.IsZero() {
// No read recorded yet (new node or rows predating the column):
// assume the next read can be a full interval away.
return min(time.Duration(interval)*time.Second, maxWarmupWait)
}
wait := time.Duration(interval)*time.Second - time.Since(node.LastQueryRead)
if wait <= 0 {
// The scheduled read is overdue — the node is offline or asleep.
// Keep the base timeout so dead nodes still fail fast.
return 0
}
return min(wait, maxWarmupWait)
return min(time.Duration(interval)*time.Second, maxWarmupWait)
}

func (h *HandlersApi) consoleCommandTimeout(env environments.TLSEnvironment, node nodes.OsqueryNode, parsed console.ParsedCommand) time.Duration {
func (h *HandlersApi) consoleCommandTimeout(env environments.TLSEnvironment, parsed console.ParsedCommand) time.Duration {
seconds := h.acceleratedQueryReadSeconds()
if parsed.Kind == console.CommandRemote && parsed.Command == "sql" {
timeout := time.Duration(seconds*12) * time.Second
if timeout < time.Minute {
timeout = time.Minute
}
return timeout + warmupQueryWait(env, node)
return timeout + warmupQueryWait(env)
}
return time.Duration(seconds*2)*time.Second + warmupQueryWait(env, node)
return time.Duration(seconds*2)*time.Second + warmupQueryWait(env)
}

// consolePrimingTimeout is the expiration given to the priming metadata
// query. The base is intentionally generous (the accelerated interval
// doubled plus a minute floor) so the priming query stays pending long
// enough for the next accelerated QueryRead to deliver it, and the warmup
// wait extends it further while the node is still on its regular polling
// interval.
func (h *HandlersApi) consolePrimingTimeout(env environments.TLSEnvironment, node nodes.OsqueryNode) time.Duration {
// enough for the next accelerated QueryRead to deliver it, and the
// warmup wait extends it further while the node is still polling at its
// regular interval.
func (h *HandlersApi) consolePrimingTimeout(env environments.TLSEnvironment) time.Duration {
timeout := time.Duration(h.acceleratedQueryReadSeconds()*2) * time.Second
if timeout < time.Minute {
timeout = time.Minute
}
return timeout + warmupQueryWait(env, node)
return timeout + warmupQueryWait(env)
}

func osqueryTableSupportsPlatform(table types.OsqueryTable, platform string) bool {
Expand Down Expand Up @@ -416,24 +407,6 @@ func (h *HandlersApi) consoleSessionContext(w http.ResponseWriter, r *http.Reque
return env, ctx, session, true
}

// sessionNode resolves the node an interactive session (console or file
// explorer) belongs to, so submit paths can size the distributed query
// expiration from the node's polling state. The session was created
// against this node; if it no longer resolves, nothing submitted to it
// can ever be delivered.
func (h *HandlersApi) sessionNode(w http.ResponseWriter, env environments.TLSEnvironment, nodeUUID string) (nodes.OsqueryNode, bool) {
node, err := h.Nodes.GetByUUIDEnv(nodeUUID, env.ID)
if err != nil {
if errors.Is(err, gorm.ErrRecordNotFound) {
apiErrorResponse(w, "node not found", http.StatusNotFound, err)
return nodes.OsqueryNode{}, false
}
apiErrorResponse(w, "error getting node", http.StatusInternalServerError, err)
return nodes.OsqueryNode{}, false
}
return node, true
}

func consolePathUint(w http.ResponseWriter, r *http.Request, name string) (uint, bool) {
value := r.PathValue(name)
id, err := strconv.ParseUint(value, 10, strconv.IntSize)
Expand Down
71 changes: 33 additions & 38 deletions cmd/api/handlers/console_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,32 +112,26 @@ func TestConsoleSessionCreateDispatchesPrimingCommand(t *testing.T) {
require.True(t, distributed.Hidden)
}

func TestWarmupQueryWaitSizedToNodePollingState(t *testing.T) {
env := environments.TLSEnvironment{QueryInterval: 60}
// Fresh read: nearly the whole interval remains until the next read.
wait := warmupQueryWait(env, nodes.OsqueryNode{LastQueryRead: time.Now()})
require.Greater(t, wait, 55*time.Second)
require.LessOrEqual(t, wait, 60*time.Second)
// Read 30s ago on a 60s interval: about 30s remain.
wait = warmupQueryWait(env, nodes.OsqueryNode{LastQueryRead: time.Now().Add(-30 * time.Second)})
require.Greater(t, wait, 25*time.Second)
require.LessOrEqual(t, wait, 35*time.Second)
// Overdue read: no extra wait, so dead nodes still fail fast.
require.Zero(t, warmupQueryWait(env, nodes.OsqueryNode{LastQueryRead: time.Now().Add(-2 * time.Minute)}))
// No read recorded yet: assume the next read can be a full interval away.
require.Equal(t, 60*time.Second, warmupQueryWait(env, nodes.OsqueryNode{}))
func TestWarmupQueryWaitCoversFullPollInterval(t *testing.T) {
// last_query_read is stamped by osctrl-tls's batch writer and can lag
// the node's real poll by up to a flush window, so it must not shrink
// the warmup window: every warming-up command reserves a full interval
// regardless of how fresh or stale the recorded read looks.
require.Equal(t, 60*time.Second, warmupQueryWait(environments.TLSEnvironment{QueryInterval: 60}))
// A recorded read (fresh or stale) must not change the reservation.
require.Equal(t, 60*time.Second, warmupQueryWait(environments.TLSEnvironment{QueryInterval: 60}))
// Unset interval falls back to the environment default.
require.Equal(t, 60*time.Second, warmupQueryWait(environments.TLSEnvironment{}, nodes.OsqueryNode{}))
require.Equal(t, 60*time.Second, warmupQueryWait(environments.TLSEnvironment{}))
// Very long intervals are capped so requests cannot pend unbounded.
require.Equal(t, maxWarmupWait, warmupQueryWait(environments.TLSEnvironment{QueryInterval: 3600}, nodes.OsqueryNode{LastQueryRead: time.Now()}))
require.Equal(t, maxWarmupWait, warmupQueryWait(environments.TLSEnvironment{QueryInterval: 3600}))
}

func TestConsoleSessionCreatePrimingSurvivesNodePollInterval(t *testing.T) {
db, h, env, node := setupConsoleHandlers(t)
require.NoError(t, db.Model(&env).UpdateColumn("query_interval", 60).Error)
// The node is mid-cycle on its regular distributed interval; the
// priming query must still be pending when its next read arrives.
require.NoError(t, db.Model(&node).UpdateColumn("last_query_read", time.Now().Add(-30*time.Second)).Error)
// The node's recorded read is mid-cycle on its regular distributed
// interval; the priming query must still be pending when its next
// read arrives.
before := time.Now()

req := consoleRequest(http.MethodPost, "/console", nil, "alice")
Expand All @@ -154,8 +148,9 @@ func TestConsoleSessionCreatePrimingSurvivesNodePollInterval(t *testing.T) {

var distributed queries.DistributedQuery
require.NoError(t, db.Where("name = ?", resp.Priming.DistributedQueryName).First(&distributed).Error)
require.True(t, distributed.Expiration.After(before.Add(85*time.Second)), "priming must cover the node's next scheduled read")
require.True(t, distributed.Expiration.Before(before.Add(97*time.Second)))
// Base is the minute floor plus the full warmup wait (60s interval).
require.True(t, distributed.Expiration.After(before.Add(115*time.Second)), "priming must cover the node's next scheduled read")
require.True(t, distributed.Expiration.Before(before.Add(125*time.Second)))
}

func TestConsoleSessionCreateReturnsNodeInfo(t *testing.T) {
Expand Down Expand Up @@ -283,9 +278,8 @@ func TestConsoleCommandRejectsSecondInFlightCommand(t *testing.T) {
func TestConsoleCommandExpirationUsesDoubleAcceleratedQueryReadInterval(t *testing.T) {
db, h, env, node := setupConsoleHandlers(t)
require.NoError(t, h.Settings.NewIntegerValue(config.ServiceTLS, settings.AcceleratedSeconds, 7, settings.NoEnvironmentID))
// The node's scheduled read is overdue, so no warmup wait is added:
// the expiration is the doubled accelerated interval alone.
require.NoError(t, db.Model(&node).UpdateColumn("last_query_read", time.Now().Add(-2*time.Minute)).Error)
// The expiration is the doubled accelerated interval plus the full
// warmup wait (60s default interval).
session, err := h.Console.CreateSession(env, node, "alice")
require.NoError(t, err)
before := time.Now()
Expand All @@ -302,19 +296,20 @@ func TestConsoleCommandExpirationUsesDoubleAcceleratedQueryReadInterval(t *testi
require.NoError(t, json.Unmarshal(rr.Body.Bytes(), &resp))
var distributed queries.DistributedQuery
require.NoError(t, db.Where("name = ?", resp.Command.DistributedQueryName).First(&distributed).Error)
require.True(t, distributed.Expiration.After(before.Add(13*time.Second)))
require.True(t, distributed.Expiration.Before(before.Add(15*time.Second)))
require.True(t, distributed.Expiration.After(before.Add(73*time.Second)))
require.True(t, distributed.Expiration.Before(before.Add(76*time.Second)))
}

func TestConsoleCommandExpirationSurvivesNodePollIntervalWhileWarmingUp(t *testing.T) {
db, h, env, node := setupConsoleHandlers(t)
require.NoError(t, h.Settings.NewIntegerValue(config.ServiceTLS, settings.AcceleratedSeconds, 7, settings.NoEnvironmentID))
require.NoError(t, db.Model(&env).UpdateColumn("query_interval", 60).Error)
// The node's last query read was 30s ago on a 60s interval: its next
// read is up to 30s away. The query must stay pending at least that
// long, or warmup commands expire undelivered and the operator has to
// keep clicking refresh until acceleration happens to kick in.
require.NoError(t, db.Model(&node).UpdateColumn("last_query_read", time.Now().Add(-30*time.Second)).Error)
// The node's last recorded read looks overdue, but the batch writer
// lag means its next real read can still be a full interval away. The
// query must stay pending at least that long, or warmup commands
// expire undelivered and the operator has to keep clicking refresh
// until acceleration happens to kick in.
require.NoError(t, db.Model(&node).UpdateColumn("last_query_read", time.Now().Add(-2*time.Minute)).Error)
session, err := h.Console.CreateSession(env, node, "alice")
require.NoError(t, err)
before := time.Now()
Expand All @@ -332,16 +327,16 @@ func TestConsoleCommandExpirationSurvivesNodePollIntervalWhileWarmingUp(t *testi
require.NotNil(t, resp.Command.ExpiresAt, "the response must expose the deadline so clients can wait it out")
var distributed queries.DistributedQuery
require.NoError(t, db.Where("name = ?", resp.Command.DistributedQueryName).First(&distributed).Error)
require.True(t, distributed.Expiration.After(before.Add(40*time.Second)), "expiration must cover the node's next scheduled read")
require.True(t, distributed.Expiration.Before(before.Add(47*time.Second)))
require.True(t, distributed.Expiration.After(before.Add(73*time.Second)), "expiration must cover the node's next scheduled read despite stale check-in data")
require.True(t, distributed.Expiration.Before(before.Add(76*time.Second)))
}

func TestConsoleOsqueryModeSQLUsesLongerExpiration(t *testing.T) {
db, h, env, node := setupConsoleHandlers(t)
require.NoError(t, h.Settings.NewIntegerValue(config.ServiceTLS, settings.AcceleratedSeconds, 5, settings.NoEnvironmentID))
// Overdue read: no warmup wait, so the expiration is the long sql
// timeout alone.
require.NoError(t, db.Model(&node).UpdateColumn("last_query_read", time.Now().Add(-2*time.Minute)).Error)
require.NoError(t, db.Model(&env).UpdateColumn("query_interval", 60).Error)
// The sql timeout floor is a minute; the full warmup wait (60s) is
// added on top so delivery is covered while still warming up.
session, _ := h.Console.CreateSession(env, node, "alice")
before := time.Now()

Expand All @@ -357,8 +352,8 @@ func TestConsoleOsqueryModeSQLUsesLongerExpiration(t *testing.T) {
require.NoError(t, json.Unmarshal(rr.Body.Bytes(), &resp))
var distributed queries.DistributedQuery
require.NoError(t, db.Where("name = ?", resp.Command.DistributedQueryName).First(&distributed).Error)
require.True(t, distributed.Expiration.After(before.Add(59*time.Second)))
require.True(t, distributed.Expiration.Before(before.Add(61*time.Second)))
require.True(t, distributed.Expiration.After(before.Add(119*time.Second)))
require.True(t, distributed.Expiration.Before(before.Add(122*time.Second)))
}

func TestConsoleCommandRejectsNonAdminSessionOwner(t *testing.T) {
Expand Down
19 changes: 5 additions & 14 deletions cmd/api/handlers/file_explorer.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,6 @@ import (

"github.com/jmpsec/osctrl/pkg/environments"
"github.com/jmpsec/osctrl/pkg/fileexplorer"
"github.com/jmpsec/osctrl/pkg/nodes"
"github.com/jmpsec/osctrl/pkg/types"
"github.com/jmpsec/osctrl/pkg/utils"
"gorm.io/gorm"
Expand Down Expand Up @@ -61,7 +60,7 @@ func (h *HandlersApi) FileExplorerSessionCreateHandler(w http.ResponseWriter, r
// before the operator expands the first directory. Non-fatal on
// failure.
var priming *fileexplorer.Request
if primingReq, primingErr := h.FileExplorer.SubmitPrimingRequest(session.ID, h.fileExplorerRequestTimeout(env, node)); primingErr == nil {
if primingReq, primingErr := h.FileExplorer.SubmitPrimingRequest(session.ID, h.fileExplorerRequestTimeout(env)); primingErr == nil {
priming = &primingReq
}
h.auditFileExplorerAction(ctx[ctxUser], "file explorer session", r, env.ID)
Expand Down Expand Up @@ -107,11 +106,7 @@ func (h *HandlersApi) FileExplorerListHandler(w http.ResponseWriter, r *http.Req
if !ok {
return
}
node, ok := h.sessionNode(w, env, session.NodeUUID)
if !ok {
return
}
request, err := h.FileExplorer.ListDirectory(session.ID, path, h.fileExplorerRequestTimeout(env, node))
request, err := h.FileExplorer.ListDirectory(session.ID, path, h.fileExplorerRequestTimeout(env))
if err != nil {
apiErrorResponse(w, err.Error(), http.StatusBadRequest, err)
return
Expand All @@ -129,11 +124,7 @@ func (h *HandlersApi) FileExplorerStatHandler(w http.ResponseWriter, r *http.Req
if !ok {
return
}
node, ok := h.sessionNode(w, env, session.NodeUUID)
if !ok {
return
}
request, err := h.FileExplorer.StatPath(session.ID, path, h.fileExplorerRequestTimeout(env, node))
request, err := h.FileExplorer.StatPath(session.ID, path, h.fileExplorerRequestTimeout(env))
if err != nil {
apiErrorResponse(w, err.Error(), http.StatusBadRequest, err)
return
Expand Down Expand Up @@ -260,8 +251,8 @@ func fileExplorerRequestPath(w http.ResponseWriter, r *http.Request) (string, bo
// once the node polls at the accelerated interval; the warmup wait keeps
// the query alive until the node's next regularly scheduled read while
// acceleration has not kicked in yet.
func (h *HandlersApi) fileExplorerRequestTimeout(env environments.TLSEnvironment, node nodes.OsqueryNode) time.Duration {
return time.Duration(h.acceleratedQueryReadSeconds()*2)*time.Second + warmupQueryWait(env, node)
func (h *HandlersApi) fileExplorerRequestTimeout(env environments.TLSEnvironment) time.Duration {
return time.Duration(h.acceleratedQueryReadSeconds()*2)*time.Second + warmupQueryWait(env)
}

func (h *HandlersApi) auditFileExplorerAction(user, action string, r *http.Request, envID uint) {
Expand Down
Loading
Loading