I test erano verdi, ma le notifiche non erano mai partite

Un alert 500 è comparso su Slack. Il messaggio d'errore era insolito: Error: Custom Id cannot contain :. L'API con cui gli amministratori registrano le risposte alle domande degli utenti stava morendo, e lo stack trace puntava a Job.validateOptions di BullMQ.

Fin qui, un bug report qualunque. Il punto in cui questa storia smette di essere ordinaria arriva dopo aver trovato la causa. Il codice che lanciava quell'errore non era stato toccato dal deploy di quel giorno. Falliva ogni volta, al 100%, dal giorno in cui la funzionalità era entrata in produzione. Il che significa che le notifiche push che quella coda avrebbe dovuto inviare non erano mai partite, nemmeno una volta. E per tutto quel tempo i test erano rimasti verdi.

La causa: un solo carattere

Il codice incriminato era questo. È il punto in cui, quando una domanda riceve una risposta, si accoda il job che invia la push all'utente.

await this.queue.add(ANSWER_NOTIFY_JOB_NAME, data, {
  jobId: `answer-notify:${data.questionId}`, // ← questo due punti
});

L'idea era assegnare un jobId personalizzato per evitare che lo stesso job entrasse due volte per la stessa domanda, ma come separatore era stato usato il due punti. BullMQ assembla le chiavi Redis con i due punti, quindi li vieta nei jobId personalizzati. In v5 la condizione esatta è questa: se il jobId contiene un due punti e i segmenti risultanti dalla divisione non sono tre, lancia l'errore. L'eccezione dei tre segmenti è un carve-out per il formato legacy dei job repeatable, quindi un jobId a due segmenti come answer-notify:123 produce sempre Custom Id cannot contain :. Per inciso, anche un jobId di soli numeri viene rifiutato con Custom Id cannot be integers, quindi nemmeno togliere il prefisso è una soluzione.

Le decine di altre code nel codebase usavano tutte il trattino. Solo questo file usava i due punti.

Il bug c'era dal primo giorno, allora perché è esploso oggi

La correzione è una riga: sostituire i due punti con un trattino. La domanda interessante è un'altra. Perché un codice che falliva sempre è rimasto zitto per tutto questo tempo ed è diventato un 500 proprio oggi?

Quando la funzionalità fu deployata la prima volta, l'enqueue era avvolto così.

try {
  await this.queue.add(/* ... */);
  return true;
} catch (err) {
  this.logger.error("enqueue failed", err);
  return false; // ← il fallimento sparisce qui
}

Registra il fallimento nel log e restituisce false. Il chiamante non controlla il valore di ritorno. Così l'eccezione lanciata ogni volta veniva inghiottita ogni volta, l'API restituiva 200 e la notifica evaporava in silenzio.

Poi un commit mergiato quello stesso giorno ha cambiato questo contratto. L'intenzione era che un enqueue fallito non venisse più inghiottito ma lanciasse l'eccezione, così da annullare il flag "risposta data" scritto nella transazione e permettere il retry. Un cambiamento nella direzione giusta. In quel momento, l'enqueue che falliva da sempre ha fatto rumore per la prima volta. Il 500 non era un bug introdotto da quel commit: era il primo urlo di un bug che c'era già.

Questo è il costo del codice che inghiotte gli errori. Il segnale sparisce, e il bug resta lì e si porta via un'intera funzionalità.

Perché i test erano verdi

Questa coda aveva dei test. Uno spec nella forma più comune: chiami l'enqueue e verifichi che queue.add venga invocato con gli argomenti giusti. E il queue.add di quel test era un mock che riusciva sempre.

Il vero add di BullMQ valida il jobId e rifiuta i due punti. L'add del mock accetta qualsiasi cosa. Nella misura in cui il mock è più permissivo del contratto reale, il test faceva passare in verde input che nella realtà non potevano passare mai. Quando il mock diverge dal contratto reale, un test verde non certifica codice vivo: certifica codice morto.

Nel correggere, ho tappato prima questo buco. Ho fatto in modo che l'add del mock della coda eseguisse il vero Job.validateOptions di BullMQ. È una validazione pura che gira senza Redis, quindi si può montare direttamente nei test. Poi ho verificato con un test di mutazione che la guardia fosse una vera guardia: ho rimesso i due punti, ho visto il test diventare rosso esattamente in quel punto, e solo dopo ho committato. Se reintroduci il bug e il test resta verde, quel test è come se non esistesse.

Non era un caso isolato

Fermarsi qui avrebbe significato correggere solo metà. Se lo stesso errore sta in un punto, è probabile che stia anche altrove. Ho definito la "classe" del difetto - jobId personalizzati contenenti due punti - ho passato al setaccio l'intero codebase e ho messo più agenti di review a fare verifica incrociata. Sono usciti altri due casi.

Uno era la coda che trascrive in testo gli audio caricati dagli utenti. jobId: "stt:${id}". Qui l'errore veniva ancora inghiottito, quindi non usciva nemmeno un 500. Controllando, è saltato fuori che da 12 giorni nessun job di trascrizione entrava in coda. I file audio venivano salvati regolarmente, il fallimento restava solo nei log, e sullo schermo dell'utente il testo rimaneva vuoto per sempre. Completamente asintomatico.

L'altro era la coda delle email informative per gli eventi programmati. Il jobId aveva quattro segmenti separati da due punti, quindi né i promemoria né gli avvisi di cancellazione entravano mai in coda.

Ho unificato i producer delle tre code in un unico builder condiviso di jobId: una funzione che unisce con i trattini, sostituisce eventuali due punti e rifiuta i valori puramente numerici. Come prevenzione ho aggiunto anche una regola di lint che intercetta esattamente il pattern del due punti letterale dentro un jobId. Non ho migrato a forza al nuovo builder la cinquantina di jobId con trattino già esistenti: se il jobId di un job repeatable cambia, c'è il rischio che il cron venga registrato in doppio, quindi ho scelto di colpire solo la classe del difetto.

La seconda trappola: un jobId fisso uccide in silenzio i retry

Sarebbe stato bello se la storia finisse qui, ma durante la verifica in review è emerso un problema più profondo. Una volta corretti i due punti, un jobId fisso come answer-notify-123 torna in vita, e proprio quel jobId fisso era in contraddizione con il contratto di retry stabilito lo stesso giorno.

Se l'hash di un job con lo stesso jobId è ancora in Redis, BullMQ ignora il nuovo add senza alcun errore e restituisce il jobId esistente. È un comportamento che il verificatore ha confermato arrivando a leggere gli script Lua di BullMQ. Ma questa coda usa removeOnComplete: { count: 100 }, quindi anche l'hash di un job appena completato resta lì. Combinando le due cose, lo scenario è questo. Il job di notifica fallisce una volta. Come da contratto, il flag "risposta data" viene annullato e l'amministratore riprova. Il nuovo enqueue inciampa nell'hash del job rimasto, non fa nulla e ritorna come se avesse avuto successo. La notifica non parte mai, e stavolta non ci sono né errori né DLQ.

Eliminato il catch che inghiottiva i fallimenti, è la dedupe della libreria a prenderne il posto. Alla fine da questa coda ho tolto del tutto il jobId personalizzato. La prevenzione dei duplicati si è spostata sul lato consumer: il processor si appropria in modo atomico del flag "notifica inviata" con un aggiornamento condizionale. Anche se il job entra due volte, solo il lato che prende il flag per primo manda la push.

Se nel vostro design un jobId personalizzato previene i duplicati e allo stesso tempo, in caso di fallimento, si fa un nuovo enqueue, vale la pena verificare che i due meccanismi non si uccidano a vicenda. Potrebbe essere la stessa combinazione nostra, quella in cui il retry diventa silenziosamente un no-op.

A quanto ammontava il danno

Una funzionalità morta per 12 giorni fa pensare a un danno enorme, ma la misurazione ha detto altro. Per le notifiche di risposta, la funzionalità non era ancora in uso reale in produzione, quindi zero perdite. Anche la coda email riguardava solo eventi già passati, quindi non c'era nulla da rispedire. Il recupero vero e proprio: 2 audio non trascritti. Li ho ritrascritti dai file audio rimasti e il danno è stato recuperato.

È andata bene. E questa fortuna non si ripete. Se fosse stata una funzionalità in uso reale, 12 giorni di notifiche e trascrizioni sarebbero andati persi, e siccome i job non erano mai stati creati in coda, il deploy da solo non avrebbe recuperato nulla. Scrivere uno script di backfill era secondario. Il punto essenziale, ho giudicato, era correggere il fatto che nessuno sapesse che una funzionalità morta era morta da 12 giorni. Così ora i fallimenti di trascrizione non restano più solo nei log ma salgono su un canale di alert, e il percorso delle notifiche di risposta è passato a un outbox committato insieme alla transazione, eliminando alla radice lo stato "nel DB risulta il successo, ma il job non esiste".

Cosa resta

Tre cose di questa vicenda che dureranno più del codice.

Primo: un catch che si limita a loggare e a ritornare normalmente fa sì che nessuno si accorga nemmeno di un percorso che fallisce al 100%. Se proprio si vuole inghiottire, devono esserci almeno una metrica che conta i fallimenti o un alert; se non ci sono, è meglio lanciare. Un errore lanciato fa rumore ma viene corretto; un errore inghiottito vive 12 giorni.

Secondo: un mock deve essere rigoroso quanto il contratto reale. Sopra un mock che riesce sempre, nessun input viene validato. Se la libreria offre una funzione di validazione pura, montatela nel mock, e verificate che il test diventi rosso quando reintroducete il bug: solo allora è una guardia.

Terzo: i difetti si catturano per classi. Nello stesso codebase, lo stesso errore non capita una volta sola. Trovatone uno, definite la classe, setacciate tutto e arrivate fino a impedire che quella classe possa rientrare - con una regola di lint o un builder condiviso. Solo così una singola scoperta vale davvero il suo prezzo.