Fix/gearman reconnect - #1
Merged
Merged
Conversation
…althy A dropped connection to the job server stopped the worker consuming, for good. gearman-go's agent.work hands a *WorkerDisconnectError to the ErrorHandler on EOF and then returns, so nothing sends on worker.in any more - and Work() is a plain range over that channel, which only Close() ends. The worker stayed up, kept emitting its 30-second stats line and processed nothing: twelve error=EOF WARN lines and then processed=12836 repeating unchanged until someone restarted the process by hand. superviseReconnects is one goroutine per queue that closes the dead generation and rebuilds the worker (New/AddServer/AddFunc/Ready/Work), retrying every reconnectDelay until it succeeds or Stop is called. Twelve queues dropped by one job-server restart come back in parallel. Deliberately not the library's WorkerDisconnectError.Reconnect(): agent.disconnect_error calls the ErrorHandler while holding the agent's mutex and reconnect() takes that same mutex, so reconnecting where the disconnect is reported is a self-deadlock. reconnect() also reuses the dead agent in place - overwriting a.conn without closing the old socket, taking the agent mutex before the worker mutex, calling agentWG.Add on a WaitGroup Close may be waiting on. Rebuilding touches none of that. Two properties are load-bearing. The ErrorHandler's send onto queueWorker.lost is non-blocking, because it runs under that agent mutex. And Stop closes c.stopping under c.mu, which is the whole serialisation against a reconnect landing mid-shutdown: either the new worker gets into Stop's snapshot, or the supervisor sees the shutdown and never starts its Work loop - without that, a fresh connection outlives Stop and feeds BulkInserters that have already been flushed. Also adds queue_connected (gauge) and queue_reconnects_total, on both backends. queue_connected is the metric to alert on and the reason this was invisible: a queue that has stopped consuming and one that is merely idle both leave messages_received_total flat and jobs_in_flight at 0. It is the one per-queue series deliberately kept out of InitQueue - a pre-created gauge sits at 0, which here reads as the outage it exists to detect, so each consumer sets it once a connection is genuinely up. The stale comment above reconnectDelay claimed the opposite about Gearman - that the library handled reconnects and only shutdown needed care. That assumption is why this survived. Measured, worker binary against a real gearmand with the connection severed through a proxy: queue_connected 12 -> 0 -> 12, twelve "reconnected" lines, and 500 statusngin_hostchecks published *after* the drop reaching MySQL as 500 rows. Before the fix the same test waits out its 30s timeout at reconnects=0. SIGTERM during an active retry loop returns in 4ms with failed=0 on the flush, well under TimeoutStopSec. Jobs in flight at the drop lose their acknowledgement and are handed out again after the reconnect - rule 6's upserts are what make that a non-event. TestGearmanConsumerReconnectsAfterConnectionDrop severs the connection with a TCP proxy, because gearman-go keeps its socket in an unexported field of an unexported agent and a test must not restart the shared dev gearmand. TestGearmanConsumerStopsWhileReconnecting pins that an unbounded retry loop never outlasts a shutdown. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
A downtime arrives as up to four separate jobs - ADD, START, STOP, DELETE - and only ADD is an UPSERT. START and STOP are bare UPDATE ... WHERE <PK> against the row ADD created, and STOP/DELETE are DELETE FROM scheduleddowntimes. Every one of those is a silent no-op when it runs before the message it depends on, and execDowntimeAction ignored RowsAffected, so nothing failed and nothing was logged. The Gearman consumer dispatches eight handlers per queue, so that ordering held only by luck - and live traffic supplies the luck, since a downtime's events are minutes apart. A backlog does not. After a two-hour job-server outage was drained in one burst, 6 of ~14 downtimes came out wrong, each one explainable by the order its jobs happened to run in: START before ADD left was_started=0 and actual_start_time=0 on a row whose actual_end_time was correct, and STOP before START left a scheduleddowntimes row behind for good because STOP deleted it and START's UPSERT put it back. It was found by cmd/db_verifier diffing against the legacy PHP worker, which is the only reason it was found at all. RequiresInOrderProcessing caps that queue at gearman.New(1) regardless of -gearman-max-concurrent-jobs-per-queue. Reproduced end to end both ways against a real gearmand and MySQL, eight lifecycles published in one burst: with the cap 8/8 rows correct and no leftover scheduled rows, without it the production signature returns - one row at was_started=0/actual_start_time=0 with actual_end_time set, and three leftover scheduled rows. The cap costs nothing; that queue sees a handful of messages an hour, and per-queue concurrency buys no throughput anyway (CLAUDE.md rule 2 - the bottleneck is the single Run goroutine per table). The legacy PHP worker forks one process per queue and the RabbitMQ consumer calls its Handler synchronously from a plain for range, so both were already in order. Only the Gearman path was not, and never deliberately. queue_downtime_updates_unmatched_total is the backstop for the case serialization cannot cover: an ADD that never arrives at all. Deliberately not a plain RowsAffected check - MySQL counts rows changed rather than matched, so a redelivered START rewriting its own values reports zero exactly like a START whose row is missing, and redelivery is normal here (rule 6). A zero therefore costs one follow-up SELECT to tell the two apart, on a path that should never be taken. DELETE is excluded: STOP already removed the scheduled row, so a zero-row DELETE happens on every ordinary downtime and counting it would bury the signal. That check has a measured limit worth stating: a writer landing between the UPDATE and the lookup makes a real loss read as a redelivery. Run against a deliberately unserialized queue, the corruption appeared in MySQL while the counter stayed at 0. It backstops a missing ADD, not a broken ordering guarantee - TestDowntimeQueueIsHandledOneAtATime covers the latter, and fails at "8 downtime handlers ran at once" without the cap. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
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.