7 min de leitura ·

Como uma edição de título de PR quebrou minha pipeline por algumas horas

Se liga nessa situação que rolou comigo há algum tempo... dia tranquilo até que a pipeline caiu "do nada" (sempre assim né? xD). O erro apontava para a VM, mas a causa real estava escondida em três mudanças de uma PR que ninguém tinha percebido.

O problema

Um dev me pingou: "Tá dando erro estranho na pipe, olha aí?" Parei o que eu estava fazendo e fui investigar.

Acessei o build e de primeira já verifiquei que falhou na etapa de instalação do Angular. Isso já me deu o palpite de que podia ser um problema na VM, pois essa pipeline usava um agente self-hosted (para contexto, nessa situação estamos falando de Azure DevOps e Bitbucket).

A investigação

Abri a task de instalação do Angular e a primeira mensagem que vi foi: ENOTEMPTY: directory not empty, rename '.../cli' -> '.../cli-Xuqet0PR'

Exatamente desse jeito, inclusive vou deixar o output aqui para ficar mais fácil de entender:

2000-00-00T13:00:57Z [command] npm install -g @angular/cli@XX.X.1
2000-00-00T13:01:15Z npm error code ENOTEMPTY
2000-00-00T13:01:15Z npm error syscall rename
2000-00-00T13:01:15Z npm error path   .../node_modules/@angular/cli
2000-00-00T13:01:15Z npm error dest   .../node_modules/@angular/.cli-Xuqet0PR
2000-00-00T13:01:15Z npm error errno  -39
2000-00-00T13:01:15Z npm error ENOTEMPTY: directory not empty, rename '.../cli' -> '.../cli-Xuqet0PR'
2000-00-00T13:01:16Z ##[error]Error: Npm failed with return code: 217

De primeira dá para notar que o npm tentou renomear uma pasta e não conseguiu... como eu não sabia a fundo como funcionava o processo de instalação, dei uma pesquisada rápida e descobri que ao instalar o Angular, o npm tenta renomear o diretório atual (cli) para um nome temporário (.cli-Xuqet0PR) e se der certo esse rename, ele faz a instalação do Angular na pasta /cli, esse processo é basicamente para liberar o caminho no diretório antes de escrever a nova versão. O problema é que de alguma forma já existia um temporário lá e já estava com conteúdo, então o rename falhou, o processo morreu, o build foi junto.

Agora a grande pergunta não era o que quebrou. Era o porquê esse diretório temporário estava ali.

Aqui começa a investigação de verdade... Fui na lista de builds no Azure DevOps, procurei o último lote de builds com sucesso e identifiquei o momento exato em que as falhas começaram. Abri o build correspondente, acessei a PR em andamento e encontrei uma alteração no YAML da pipeline: o dev tinha removido a etapa de instalação do Angular.

# trecho removido da pipeline pelo dev
- task: Npm@1
  inputs:
    command: 'custom'
    customCommand: 'install -g @angular/cli@XX.X.1'
  displayName: 'Install Angular CLI'

Esse tipo de mudança é estranho, mas como o dev é novato e está começando, eu relevei e entendi que talvez ele não soube como resolver o problema do ENOTEMPTY, e usou IA para resolver mas não passou contexto suficiente.

Antes de continuar investigando, preciso liberar o fluxo...

Pipeline parada é prioridade máxima. Como DevOps, minha função é acelerar o ciclo de entrega do time, e build travado é o oposto disso.

Dei um change request na PR, chamei o dev no privado para avisar sobre a alteração do YAML e comuniquei ao time no grupo que eu já estava verificando o problema com a pipeline. Com isso feito, ativei a VPN e acessei a VM via SSH.

Tava lá. O diretório temporário abandonado, exatamente como o erro dizia.

Como eu falei anteriormente, o fluxo do npm é renomear a pasta /cli para um nome temporário e processar o pacote. Se o processo é interrompido no meio, o diretório temporário fica para trás. Na próxima execução, quando o npm tenta renomear de novo, encontra um diretório não vazio e explode com ENOTEMPTY.

Para resolver eu simplesmente apaguei as pastas...

Rodei a pipeline de novo e passou. Problema resolvido, avisei o time no grupo que a pipe estava liberada. Agora preciso entender a causa raiz.

Quem interrompeu o processo?

Um princípio que carrego na minha carreira é: nada acontece do nada.

De cara, minha dedução foi que o problema estava na alteração do YAML que o novato fez. Mas fui checar o histórico da PR e notei que ele só removeu a instalação do Angular no terceiro commit. O erro já estava quebrando a pipeline antes disso.

Fui ver nos logs do agente na VM (aqui aprendi na marra algo que eu não tinha prestado atenção antes: a VM estava em UTC e eu estava em UTC-3) e os builds que via no Azure DevOps como falho às 08:53 correspondia a 11:53 na VM. Isso importa na hora de correlacionar logs, demorei uns minutos para lembrar disso xD

$ cat /home/vm-admin/myagent/_diag/Agent_*.log | grep "Running job"

[2000-00-00 01:00:39Z] Running job: Build Frontend
[2000-00-00 01:03:25Z] Running job: Build Frontend
[2000-00-00 01:05:58Z] Running job: Build Frontend
[2000-00-00 02:00:20Z] Running job: Job
[2000-00-00 02:10:37Z] Running job: Job
[2000-00-00 02:20:45Z] Running job: Job
[2000-00-00 11:49:37Z] Running job: Job  ← suspeito
[2000-00-00 11:50:35Z] Running job: Job  ← suspeito
[2000-00-00 11:53:12Z] Running job: Job  ← falhou

Ao ler o log, fui por eliminação... como eu sabia que tinha pipe que rodou de madrugada por schedule e o build que eu procurava era das 11:53, sobraram dois jobs que não apareciam na interface do Azure DevOps. Foi só nesse momento que notei o número do build que havia falhado: #20000000.3. Tava na minha cara o tempo todo. O sufixo (3) já indicava que era a terceira execução do dia. Não vi antes... mas acontece xD.

Lendo os logs dos Workers

Bom, agora que eu sei que tem dois builds que foram apagados e não aparecem na interface, e tenho informações de horário, vou até os logs de Workers. Lá é um arquivo por build, e o melhor, com o horário de início em UTC no próprio nome do arquivo.

$ ls /home/vm-admin/myagent/_diag/
Worker_20000000-114938-utc.log
Worker_20000000-115038-utc.log

Achei esses dois logs, e os minutos batem com o log que analisei anteriormente... Só podiam ser esses.

Log era enorme, então copiei, joguei para a IA e perguntei: "o que aconteceu com esse build? Foi deletado, cancelado, crashou?"

A IA respondeu:

Pipeline:     [empresa] - Dashboard (Staging)
Build:        20000000.1 | Motivo: PullRequest
Resultado:    Canceled
Momento:      durante o passo Cache npm
Consequência: todos os passos seguintes foram skipped

Nesse log não aparece quem cancelou.
O log mostra apenas que o agente recebeu um sinal de cancelamento.

Opa, agora sei que os dois builds foram cancelados. Não foi crash, não foi a VM. Receberam um sinal externo. Mas de quem?

O culpado

Builds cancelados podem não aparecer na interface gráfica do Azure DevOps, mas da API não tem como, ela expõe isso. Montei a URL com ajuda de IA, já autenticado no portal, e o JSON retornou:

"deletedBy": "Microsoft.VisualStudio.Services.TFS",
"deletedReason": "The build was manually deleted.",
"pr.autoCancel": "true"

Aí o culpado... Não foi o dev. Não foi ninguém do time. Foi o próprio Azure DevOps, pelo pr.autoCancel que cancela automaticamente qualquer build em andamento toda vez que a PR é atualizada.

Fui até a PR no Bitbucket para tirar a prova real, e reconstruí a sequência, olha que dahora:

Dev abriu a PR → build 20000000.1 inicia
Dev marcou como DRAFT → auto-cancel derruba o build .1 → build 20000000.2 inicia
Dev editou o título da PR → auto-cancel derruba o build .2 durante o npm install → .cli-Xuqet0PR fica incompleto na VM → build 20000000.3 inicia → ENOTEMPTY → todos os builds seguintes quebram.

Insight: Olha que massa, eu realmente não sabia que editar o título de uma PR também disparava um novo build. E na verdade qualquer atualização na PR com um build em andamento aciona o pr.autoCancel. Se o cancelamento ocorre no meio de um processo com estado em disco, como o npm install, o rastro fica na VM e quebra todos os builds seguintes até alguém limpar manualmente.

Caraca, fiquei de cara quando entendi o problema pela raiz... e qual foi o aprendizado? Só crie a PR quando ela estiver 100% pronta. xD

Obviamente que esse problema não podemos colocar na conta do novato... nem eu sabia que podia dar problema... mas uma boa prática é você abrir a PR tendo a certeza que ela está pronta... ou já abrir ela como draft.

E é isso, basicamente essas 3 mudanças rápidas que o dev fez (literalmente uma em seguida da outra) foi matando os builds com o autocancel e na última alteração deu ruim.

Bom, isso ocorreu há um tempo atrás... mas conhecimento nunca ocupa espaço, então ficou de aprendizado haha

Já tinha visto esse B.O antes? Conta aí

Ficou em aberto

Por que o npm não faz cleanup ao receber o sinal de cancelamento? Dependendo de como o sinal é entregue e em que ponto do rename o processo estava, o cleanup pode não acontecer. Não investiguei a fundo.

O pr.autoCancel tem configuração granular? Não verifiquei se é possível desativar por pipeline específica ou se é global.

Dá para tornar o step idempotente? Uma limpeza antes do npm install -g eliminaria o problema independentemente de cancelamentos futuros:

- script: |
    rm -rf $(node_modules_path)/@angular/cli
    rm -rf $(node_modules_path)/@angular/.cli-*
  displayName: 'Clean Angular'

Não implementei ainda. Não sei se gera efeito colateral em builds paralelos no mesmo agente.

Referências

Vinicius Aguilar — DevOps Engineer

Fonte: https://aguillarops.dev/enotempty-npm-pipeline-pr-autocancelamento

clovisdanielss

12 dias atrás

Bem legal a investigação, parabéns. Eu só discordo em falar que a culpa era do dev novato. Ele teve culpa por ter editado um yaml que não deveria (E isso ainda é passível de questionamento, pois onde tava a review do PR ?), mas no geral a culpa foi do pipeline. Já que exitem pontos não mapeados sobre as ações que fazem o pipeline executar, então o agente deveria verificar resíduos antes da instalação do angular. Na minha opinião, penso que a pipeline deveria ser revisada, pois não faz sentido qualquer cancelamento da execução provocar um erro que causa problema nos próximos builds.

No mais, entendo que processos se distinguem de um local para outro, mas o PR é um ponto de revisão e mudanças. Não acredito ter sentido o dev ter que garantir que esteja tudo ok no PR, pois tudo ali é passível de alterações.

aguillarops

Autor

12 dias atrás

Fala, clovisdanielss! Cara, excelente ponto.

Concordo 100% com você, e refletindo sobre seu comentário vi que posso ter me expressado mal no final... Quando eu disse que a 'culpa' não era dele, foi justamente nesse sentido: o comportamento de atualizar uma PR é esperado e legítimo (até por que se não fosse não teria essa possibilidade né? haha). O sistema é que foi frágil ao não lidar com o estado residual no disco. O bug é sistêmico, não humano.

O aprendizado real foi que a pipeline precisa ser resiliente (inclusive deixei isso em aberto no final do artigo... aquele step de limpeza antes do npm install acredito que resolve exatamente isso). E o melhor, esse caso foi um dos gatilhos para eu mudar a estratégia: hoje rodamos tudo em Kubernetes com pods efêmeros. Cada build roda num container limpo, então resíduos de builds anteriores nem existem mais. Problema eliminado pela raiz xD

Valeu demais pelo feedback, agrega muito na discussão de como tornar o CI mais resiliente!

marlon

12 dias atrás

Caraaaca, acho que descobri o problema desses dias hahaha. Tive um problema parecido que decorreu dos triggers de update do PR. No meu caso só rodei denovo e passou.

aguillarops

Autor

12 dias atrás

Haha, sério?? Que massa, marlon! Fico feliz demais que o post te deu esse insight. Às vezes a gente roda de novo e passa... mas sempre fica aquela pulga atrás da orelha, né?

E agora já fica o alerta pra quando der ruim "do nada" de novo xD

Valeu pelo comentário!

abnercoolman

12 dias atrás

É exatamente dessa forma que o caba vai pegando senioridade kkk

É sempre bom ter um problema. Pode demorar pra resolver? Com toda a certeza

Mas vc se bate e resolve kk

Rapaz no fim das contas, que bom que vc resolveu seu problema e meu muito obrigado por compartilhar sua experiência com a gente

aguillarops

Autor

12 dias atrás

Exatamente isso! Senioridade é repertório de problema resolvido haha. E o melhor é que depois de apanhar bastante, quando aparece algo parecido você já sabe onde olhar primeiro...

Valeu pelo comentário, abnercoolman! 🤝

lzocateli

12 dias atrás

Já passei por coisas parecidas. Perdi madrugadas com mudanças que "não deveriam ter quebrado nada". Dois casos que me marcaram:

Renomear Utils para utils: No Windows são a mesma pasta. No Linux (runner do CI), não são. O git mv no Windows nem registra a mudança de case. O build no CI falha com file not found e você gasta 2 horas achando que é cache. A solução é forçar em dois passos:

git mv Utils temp && git mv temp utils

Emoji no nome da branch: Um dev criou fix/🐛-null-ref. O Azure DevOps aceitou. O GitHub Actions aceitou. O script de deploy que usava o nome da branch como tag do Docker container... não aceitou. O registry rejeitou a tag silenciosamente. Deploy não aconteceu. Sem erro — simplesmente não fez nada.

O padrão que conecta esses casos: a pipeline assume que o input é "normal" e não valida na entrada. Hoje eu coloco um step de sanity check antes de tudo:

Validar nome da branch com regex
dotnet format --verify-no-changes (pega formatação alterada por acidente)
Flag quando o diff tem mais de X arquivos (review manual obrigatório)

Pipeline resiliente não é a que nunca quebra — é a que te diz exatamente o que quebrou em menos de 30 segundos.

aguillarops

Autor

12 dias atrás

Pô, que dahora! O do case sensitivity já passei por igual, é osso. Mas o emoji na branch é nova pra mim... e é a cara de IA colocar emoji em branch hehe xD

Valeu por compartilhar! 🤝

juniorsantana

10 dias atrás

Fazia tempo que não lia um artigo descrevendo um problema, a investigação e conclusão.
Isso representa bem melhor o dia a dia do nosso trabalho e traz uma visão interessante pra quem está no começo da carreira.

É bacana acompanhar a "história" até chegar na soluçãodo problema, principalmentequando não somos nós fazendoa investigação kkk.

Eu só tenho algumas ressalvas sobre as conclusões.

Na seção "culpado" vc coloca que não foi o dev ou alguém do time mas sim o Azure De opa que cancelou o job na alteração do PR. Na minha visão, o Azure fez exatamente o que lhe foi pedido de acordo com a configuração de autocancel. Poderia alterar o texto pra explicar que essa foi a causa da pasta temporária.
Mais pra frente é dito que o aprendizado foi "Só crie a PR quando ela estiver 100% pronta". Isso está incorreto, PR serve justamente pra revisão, e alterações são esperadas e bem-vindas. O real aprendizado é que é dito na seção "em aberto", ou seja, o job precisa ser idempotente e investigação de jobs cancelados tem alguns obstáculos no Azure.
Podia tbm finalizar com mais alternativas para a solução (como o uso de containers que vc mencionou em outro comentário)

aguillarops

Autor

10 dias atrás

Eae, juniorsantana! Valeu demais pelo feedback, irmão... isso agrega muito pra mim 🙏

Você foi cirúrgico. O Azure fez exatamente o que a config mandava e PR é, de fato, lugar de iterar... Aquele meu fechamento sobre a PR estar "100% pronta" ficou simplificado demais no calor do momento xD. O real aprendizado é o que você pescou: jobs idempotentes para sobreviver a cancelamentos + a dificuldade de investigar o que some da UI do Azure.

E para falar a verdade, eu pensei várias vezes em editar o texto, mas decidi manter a versão original. O motivo é que esse artigo é um log do meu raciocínio ao vivo enquanto eu apagava o incêndio. Ele documenta meus erros, minhas conclusões precipitadas e como meu cérebro operou sob pressão, detalhe por detalhe, erro por erro.

Editar agora tiraria o valor educacional de ver o processo de investigação "nu e cru". Na prática, o post registrou meu "eu" daquele momento, com uma conclusão que hoje, com a cabeça fria e o seu feedback, eu formularia melhor.

Fiquei animado pra caramba com os comentários, porque a discussão aqui acabou virando a "parte 2" necessária do artigo, deixando o aprendizado muito mais rico que o texto sozinho...

Ah, e sobre os containers (K8s + KEDA + pods efêmeros), o post já está no forno! Spoiler: é a solução definitiva para esse tipo de dor de cabeça. Em breve solto aqui! xD

Valeu DEMAIS pela contribuição, brother! 🤝