fix(executors): surface env var decode failures in the job log - #282
Closed
adbatista wants to merge 12 commits into
Closed
fix(executors): surface env var decode failures in the job log#282adbatista wants to merge 12 commits into
adbatista wants to merge 12 commits into
Conversation
Env var and file decode errors carried only a base64 byte offset, so a job that died in ExportEnvVars gave no clue which value was malformed (renderedtext/tasks#10631). Wrapping the error in EnvVar.Decode() and File.Decode() names the offender at every call site at once, including the file injection paths that logged no path at all. The wrapped message also describes the value's shape - length, url-safe alphabet, padding, whitespace - which distinguishes a truncated value from one encoded with the wrong alphabet. The value itself is never logged. ValidateEncoding() decodes all env vars and files up front for callers that want to check a payload before running a job.
The shell executor swallowed the CreateEnvironment error entirely, so a job killed by an undecodable env var showed nothing but a bare exit code 1 in the job log - the only log customers can read (renderedtext/tasks#10631). Both the shell and docker executors now write the named error to the job log, the way the kubernetes executor already does for the same failure in Prepare().
An env var that is not valid base64 kills the job before checkout, and the job payload might have been corrupted in transit, so the agent now re-fetches it up to 3 times before giving up (renderedtext/tasks#10631). A payload that stays invalid is used anyway: the job then fails in the executor, which names the offending variable in the job log. Reporting the job as failed here instead would happen before the job logger exists, leaving no job log at all for whoever needs to debug it. Also fixes the hub mock serving a body after writing a 500 header, and adds AssignBadJobFor() so tests can serve a corrupt payload for the first N attempts only.
describeBase64Value flagged any value containing '-' or '_' as url-safe base64, so ordinary plaintext - a branch name, a date - was reported as "url-safe alphabet". That points whoever reads the log at a producer using the wrong encoder, when the truth is that the value is not base64 at all. The claim is now made only when the standard encoding rejects the value and the url-safe one accepts it, which is the combination that actually implicates the encoder. Also corrects the ValidateEncoding comment: SSH public keys are a known gap, not a safe omission - a key that fails to decode does fail the job on the docker-compose executor. They are excluded because PublicKey has no name to report. The test case name said "conditionally decoded", which read as if the gap were intended behaviour.
…code The executors captured the error from File.Decode() and then logged a fixed "Failed to decode the content of the file." - no path, no shape, nothing to act on. Since InjectFiles runs on every job, that made the named error from File.Decode() dead code for the whole Files half of a job request. The decode branch also returned instead of breaking, unlike every sibling error path in the same loop, so LogCommandFinished never ran and the job log was left with an unterminated "Injecting Files" directive and no exit code. Also drops the now-redundant path from the kubernetes error wrapper, which printed it twice once File.Decode() started naming it.
An undecodable SSH public key fails the job in Prepare(), and both executors logged the failure only to the agent log - so the job log ended up empty, which is the exact symptom that made renderedtext/tasks#10631 impossible to diagnose. On the docker-compose executor this path runs on every job. PublicKey has no name to report, so DecodeAt() identifies the key by its position in the job request and describes the value's shape. The key material is never logged: these keys authorize SSH access into the job.
ValidateEncoding built a "; "-separated string, which threw away the individual errors. errors.Join keeps every offender reachable through errors.Is/errors.As and returns nil for an empty slice, so the len check goes away too. The decode wrappers now use %w for the same reason: base64.CorruptInputError survives the wrapping and can be matched by callers.
…op-job Two defects in the job-payload path. The re-fetch loop validated a payload, fetched a new one, and then let the retry budget run out - so the job ran on a request that was never validated while the agent log blamed the previous one. It now returns the payload it just validated, and only claims the payload is invalid when that is what it is handing to the job. Attempts and delay became fields so tests do not pay real sleeps, and the delay is jittered: an invalid payload is invalid for every agent on that endpoint, so a fixed delay makes a fleet re-fetch in synchronized waves against a hub that is already misbehaving. A stop-job arriving while the payload was still being fetched dereferenced a nil job and panicked the whole agent process. StopJob now reports the job as stopped, and RunJob checks for that before running anything, so a stopped job does not start after the fact. The state those two coordinate through was read by the sync loop without holding the mutex, which is what made the guard unsound on its own, so State, CurrentJobID, CurrentJobResult, InterruptedAt and StopSync are now accessed under it - Sync snapshots them rather than holding the lock across the request. The hub mock had no synchronization at all, so exact attempt-count assertions raced with the HTTP handlers. Its shared state is now guarded, with accessors for the fields tests read.
The value was encoded with RawStdEncoding, which omits padding, while api.EnvVar.Decode uses the standard padded encoding. The two only agreed because "passed" and "failed" are 6 bytes long, which needs no padding. Any result whose length is not a multiple of 3 breaks the export: "stopped" encodes to 10 characters and fails with "illegal base64 data at input byte 8". Today no such result reaches handleEpilogues, since epilogues are skipped for stopped jobs, but adding a result string or running epilogues on stop would trip it - and the epilogue commands still run afterwards, just without SEMAPHORE_JOB_RESULT set, so an epilogue branching on it takes the wrong path. The encoding now lives in jobResultEnvVar, and the test round-trips every job result constant so a future result cannot reintroduce this.
The test hard-coded /tmp/repro-10631 and expected it verbatim in the job log, but InjectFiles logs the normalized destination path - on Windows that is C:\Users\runneradmin\tmp\repro-10631, so unit-testing failed there. The expectation is now built from the same api.File the executor is given, through the same NormalizePath call, and the path comes from os.TempDir() like the neighbouring InjectFiles test.
Making Sync() snapshot its state under the mutex deadlocked the agent against JobFinished, which sent on the unbuffered forceSyncCh while holding that same mutex. SyncLoop only drains the channel between syncs, so it blocked acquiring the mutex for the next sync and never took the nudge. A stopped job left the agent reporting stopping-job forever, which is what hung the job_stopping E2E test until the pipeline timed out. The channel is buffered and the send is non-blocking now, so a nudge can never wait for the sync loop, and JobFinished releases the mutex before nudging. A nudge that cannot be queued is one that is already queued.
Test__OutputBuffer__FlushIgnoresCharactersThatAreNotUtf8Valid appended 100 bytes, waited a fixed 10ms and asserted on everything flushed so far. The flush loop backs off up to a second while the buffer is empty, so on a loaded machine it had not woken up yet and the assertion saw nothing - it failed on one CI run and passed on the other for the same commit. Waiting longer would not fix it either: the broken byte is flushed on its own once it has sat in the buffer for 100ms, so "everything flushed so far" is only equal to the input inside a narrow window. The assertion is now about the first chunk, which is what the test is actually claiming - that the broken byte is not part of it. The consumer runs on the buffer's goroutine, so every test in the file collected its chunks through an unsynchronized slice. They now share a guarded collector, which takes the file from 6 data races under -race to none. While confirming that, two unsynchronized accesses turned up in the buffer itself: IsEmpty() read the byte slice without the mutex, and Close() wrote the done flag that the flush loop reads. Both are now guarded. chunkSize() keeps reading the flag directly, since flush() already holds the lock.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
No description provided.