Backlog/v12 forwarder collector fixes - #2507
Merged
Merged
Conversation
The HTTP/HTTPS collector lived in a top-level listeners package while the syslog, netflow and file collectors lived under collector/. It implements the same Collector interface and already depended on collector/configwatcher and collector/schema, so it belongs beside its siblings. The package name also claimed more than it held: it contained one collector, while syslog and netflow have listeners too. No behavior change. Only the package clause and the two import sites move; the redundant import alias in collector.go and config.go is gone as a result.
…eld reads Disabling an integration logged a bogus error: error closing tcp listener: close tcp [::]:1470: use of closed network connection disableTCP closes the listener and the accept goroutine's defer closed it a second time. The owner's close had already succeeded, so the message was a lie about a failure that never happened. The deferred close is removed and ownership is now explicit: enableTCP and disableTCP open and close, the goroutine only accepts. The panic path is the one exception and calls disableTCP, because a listener nobody is accepting on must go down too; leaving it open would keep accepting peers whose logs are never read, losing data silently instead of failing loudly. The more dangerous defect was the goroutine reading inst.TCPListener.Listener, .CTX and .TLSEnabled with no mutex while enableTCP writes them under one. On the port-change path (disable, 200ms sleep, enable) a delayed goroutine could close the newly installed listener, leaving IsEnabled true on a dead socket with nothing in the log. The goroutine now captures those values as locals while the mutex is still held, so it can only ever touch its own listener. Connections receive that context as a parameter instead of re-reading the field, so a connection accepted by a retired listener can no longer latch onto the context of its replacement and keep forwarding after the change. Verified against a live backend: enable/disable on TCP and UDP now log only the listening and closed lines, with the port released and the process alive.
Disabling an integration with traffic in flight leaked a goroutine and a file descriptor per connection, permanently and with nothing in the log. msgChannel is unbuffered and its only reader, handleMessage, returns as soon as the context is cancelled. An unguarded send therefore parked readLoop forever on any message still in flight, so it never reached its ctx.Done check, handleConnectionTCP never returned, and its deferred Close never ran. The connection stayed established from the peer's side and the descriptor stayed counted against the process. The send now selects on ctx.Done, the same idiom handleMessage already used for its own send to the queue. That covers a reader parked on the send. A reader parked on the read had the same outcome: the plain-TCP path clears its read deadline after the TLS probe, so cancellation could not wake it and it waited until the peer spoke or hung up. A watchdog bounded by the handler's own lifetime now moves the read deadline into the past on cancellation, which makes the in-flight read fail immediately so the handler returns and its defer closes the connection. It only moves the deadline: the handler's defer remains the sole owner of Close. The TLS path is deliberately left without a watchdog. readLoop resets a 30s deadline at the top of every iteration there, so a watchdog would be best-effort rather than a guarantee; a TLS connection parked on a read is already bounded to 30s. Making it a guarantee means reworking that idle timeout, which is observable behavior and belongs in its own change.
…errors Every normal client disconnect produced two ERROR lines. On a forwarder whose clients reconnect routinely this was the dominant source of error volume, and it hid the failures that mattered. Two causes. framing.go both logged and returned at every failure point, so the caller logged the same event again. And it wrapped its cause with %w, which defeats the caller's classification: a direct == comparison against io.EOF and a type assertion to net.Error never match a wrapped error, so both Info branches in readLoop were unreachable and every disconnect fell through to ErrorF. framing.go is a parsing helper and no longer logs at all; it returns the wrapped error and readLoop decides the level, which is the only place that knows the peer and whether the context is cancelled. Classification now uses errors.Is and errors.As, which walk the wrap chain. readLoop also checks ctx.Err() before classifying. A read that fails because we are shutting down is an orderly release, not a transport fault, and checking it first keeps it out of the error branch. io.ErrUnexpectedEOF deliberately stays at ERROR. A peer that announced N octets, sent fewer and vanished broke its own framing and the partial message is discarded; on a SIEM that is data loss and the operator needs to see it. Malformed frames, invalid lengths and unknown framing bytes keep ERROR and lose only the duplicate. Verified against a live backend: three clean disconnects produced three Info lines where the previous build produced six errors.
…asing the mutex enablePort wrote nc.listener, nc.ctx and nc.cancel under the mutex and the read goroutine then read those same fields with no lock at all, which is a data race the race detector flags. The window is reachable through the port-change path, which disables, sleeps 200ms and enables again. A delayed goroutine reads the newly installed listener and the new, uncancelled context, so its return path becomes unreachable and two goroutines end up reading the same UDP socket with datagrams split nondeterministically between them. It is less severe than the equivalent defect in syslog because nothing closes the new listener, so there is no dead socket, and the next disable cancels the new context and stops both. It is the same mistake all the same. The goroutine now uses locals captured while the mutex is held. The fields are still assigned because disablePort needs them to cancel and close. Note for anyone searching production logs: disablePort discards the error from Close, so netflow never emitted a close error either way. Absence of error lines here was never evidence of health.
…s file handle The file handle lived in a shared struct field that four places closed: Stop, reconcile and stopWatchersForDataType under fc.mu, and tailFile with no lock, so the mutex protected nothing. tailFile also had no deferred close, so both of its returns abandoned the handle. A reconcile that observed w.file as nil, because tailFile sat between nilling it and reopening it, deleted the watcher from the map and left the goroutine to open a descriptor nothing could ever reach again. That handle is not leaked forever: os.newFile installs a runtime finalizer, so the runtime closes it once it becomes unreachable. The real defect is a close that depends on the garbage collector with no bound on when it happens. A mostly idle forwarder allocates almost nothing, so the descriptor and the unlinked inode behind it stay pinned, and under descriptor pressure os.Open fails long before any sweep. The handle and the offset are now locals of tailFile with a deferred close, so there is exactly one owner and every exit path releases it, panic included. The external closers only cancel the context now. Cancellation alone is sufficient: the loop never blocks in a read, and it checks ctx.Done at the top of the outer loop and before every ReadString. The old external close never accelerated anything, it only made the next Stat fail. Worst-case release moves from immediate to one pollInterval, one second. Tailing, rotation detection and truncation detection are unchanged.
…g collectors StopAll called Stop on every collector and returned without waiting for anything. A reconcile already in flight could therefore reopen a socket after Stop had passed, and the process exited with the port still bound, which surfaces on the next start as "address already in use". Shutdown is now three strictly ordered phases: cancel the watch context, wait for every collector to report that its Start returned, and only then call Stop. The wait is what makes the ordering hold, and it is meaningful because every collector's Start ends in configwatcher.Watch, which blocks while it watches. The return of Start is therefore the signal that no reconcile is still running. That contract is now documented on Watch, since the shutdown path depends on it from another package. The wait is bounded at 10s for the whole phase, shared across collectors rather than per collector, so several wedged collectors cost one timeout instead of several. It covers the slowest legitimate reconcile: netflow's 200ms sleep, syslog's 200ms per protocol, and http's 5s graceful shutdown. On expiry the collectors are stopped anyway, because leaving one alive is worse than the race, and the final log line says the shutdown was degraded instead of reporting it as clean. A collector that already returned is checked without blocking first, so it can never be reported as late; select picks at random when several cases are ready, and the timer being ready must not misattribute the delay. Watch also checks for cancellation before its initial reconcile. That reconcile opens sockets, and a collector whose goroutine had not been scheduled yet when StopAll ran would otherwise open them after shutdown had already passed. Verified against a live backend: four collectors quiesced in 0.35ms, every port released, and an immediate restart rebound with no error.
…ration paths reconcile keyed only on name and protocol and restarted an instance only when the key was absent. Changing port, path, bind or auth on an integration that stayed enabled produced the same key, so the freshly built config was silently discarded and the old server kept serving with the old settings, with nothing in the log. The workaround was to disable and re-enable the integration. The config fields now live in a separate comparable struct embedded in the instance, so a plain == covers all of them and adding a field to that struct is picked up for free. On a difference the instance is restarted and the transition is logged so an operator can see the edit was applied. Everything that must change goes down before anything comes up. Restarting one key at a time cannot handle two integrations swapping ports: whichever is processed first fails to bind because the other still holds the port, and stays down until the next reconcile, up to the five minute fallback interval. mux.Handle panics on a malformed pattern, and the path comes straight from operator config with no validation. A trailing space, a missing leading slash or a stray brace killed the whole HTTP collector: the panic unwound out of reconcile and Watch, so it never reconciled again and no later config change was applied. Which integrations had already started when it fired depended on Go's random map iteration order, so the same configuration produced different outcomes on different boots. Paths are now validated before use. Whitespace and a missing leading slash are repaired and logged, since intent is unambiguous there and it also fixes a trailing newline silently producing an unreachable route. Anything else is rejected with the reason, that integration alone is skipped, and the collector keeps reconciling. Validation trial-registers the pattern on a throwaway mux under recover, so it matches what ServeMux accepts by construction instead of duplicating its grammar. shutdownInstance now force-closes after a failed graceful shutdown, so a request still in flight cannot keep being served under the previous auth settings for the remainder of its read timeout. Verified against a live backend: an in-place path change moved the endpoint without disabling the integration, and a malformed path was rejected by name with no panic while the collector applied the next change normally.
✅ AI review — CleanNo issues detected in this diff. ✅
|
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.
Started from one bogus error on disable and ended up fixing the pattern behind it.
What it fixes
error closing tcp listener: use of closed network connectionaddress already in useRoot cause
A long-running goroutine read shared struct fields without the mutex the reconcile
path writes under, and no one owned the socket. Same mistake in four files.
Validation
Built and installed against a live backend. TCP, UDP and HTTP: enable, send logs,
disable. Logs arrived, ports released, immediate restart clean.