“apt-get -y upgrade” na execução da tarefa Cron, mas não atualiza o sistema

Question

Este servidor roda o Debian 7 e eu estou enfrentando um grande mistério.

Aqui estão minhas tarefas do cron:

$ sudo crontab -e

42 15 * * * apt-get -y update >> /var/log/my-apt-update.txt
52 15 * * * apt-get -y upgrade >> /var/log/my-apt-upgrade.txt

Adicionei a parte ">> /var/log/my-apt-upgrade.txt" porque tento entender por que meu sistema nunca é atualizado.

As tarefas do cron são executadas. Todos os dias eu tenho essas linhas em / var / log / syslog:

Nov 14 15:42:01 myhostname /USR/SBIN/CRON[3374]: (root) CMD (apt-get -y update >> /var/log/my-apt-update.txt)
Nov 14 15:52:01 myhostname /USR/SBIN/CRON[3394]: (root) CMD (apt-get -y upgrade >> /var/log/my-apt-upgrade.txt)

E /var/log/my-apt-upgrade.txt tem parágrafos como este (eu só mostro os últimos dois dias):

Reading package lists...
Building dependency tree...
Reading state information...
The following packages will be upgraded:
  file libmagic1
2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Need to get 0 B/256 kB of archives.
After this operation, 110 kB disk space will be freed.
Reading package lists...
Building dependency tree...
Reading state information...
The following packages will be upgraded:
  file libmagic1
2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Need to get 0 B/256 kB of archives.
After this operation, 110 kB disk space will be freed.

Como você pode ver, os pacotes "file" e "libmagic1" devem ter sido atualizados no primeiro dia. Mas eles não eram. Então, no segundo dia, eles são mencionados novamente. Mas não atualizado.

E hoje, se eu correr

$ sudo apt-get -y upgrade

os pacotes "file" e "libmagic1" são mencionados novamente e são atualizados (finalmente).

Então, como você pode ver, posso atualizar manualmente. Mas esses pacotes deveriam ter sido atualizados anteriormente quando a tarefa do cron foi executada.

Alguma pista sobre esse mistério?

Adição sab 15 de nov. 11:48:

aqui está o que aparece no meu /var/log/apt/history.log na hora das tarefas do cron.

Start-Date: 2014-11-13  15:52:03
Commandline: apt-get -y upgrade
Upgrade: file:amd64 (5.11-2+deb7u5, 5.11-2+deb7u6), libmagic1:amd64 (5.11-2+deb7u5, 5.11-2+deb7u6)
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2014-11-13  15:52:03

Start-Date: 2014-11-14  15:52:03
Commandline: apt-get -y upgrade
Upgrade: file:amd64 (5.11-2+deb7u5, 5.11-2+deb7u6), libmagic1:amd64 (5.11-2+deb7u5, 5.11-2+deb7u6)
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2014-11-14  15:52:03

O mesmo tipo de mensagem ocorre no /var/log/apt/history.log para pacotes diferentes. Por exemplo, no início deste mês, o pacote "wget" precisou de alguma atualização (eu tentei com a opção -qq desta vez, mas esta opção não parece fazer nenhuma diferença).

Start-Date: 2014-11-03  15:52:02
Commandline: apt-get -y -qq upgrade
Upgrade: wget:amd64 (1.13.4-3+deb7u1, 1.13.4-3+deb7u2)
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2014-11-03  15:52:02

Start-Date: 2014-11-04  15:52:02
Commandline: apt-get -y -qq upgrade
Upgrade: wget:amd64 (1.13.4-3+deb7u1, 1.13.4-3+deb7u2)
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2014-11-04  15:52:03

Start-Date: 2014-11-05  15:52:03
Commandline: apt-get -y -qq upgrade
Upgrade: wget:amd64 (1.13.4-3+deb7u1, 1.13.4-3+deb7u2)
Error: Sub-process /usr/bin/dpkg returned an error code (2)
End-Date: 2014-11-05  15:52:03

    

Answer 1

Parece que encontrei a causa do problema.

Para detectar o erro, eu tive que pegar stderr no meu log personalizado. Aconteceu que era útil fazer isso porque alguns erros não foram enviados para o root e não foram escritos em outros logs.

Para pegar o stderr no meu log, eu primeiro mudei a tarefa do cron para:

52 15 * * * apt-get -y upgrade >> /var/log/my-apt-upgrade.txt 2>&1

Hoje o pacote "wlibgcrypt11" deve ser atualizado. Desta vez, meu log detectou um erro. Foi mais explícito do que a vaga mensagem de erro que apareceu anteriormente em /var/log/apt/history.log.

Em /var/log/my-apt-upgrade.txt hoje:

Reading package lists...
Building dependency tree...
Reading state information...
The following packages will be upgraded:
  libgcrypt11
debconf: unable to initialize frontend: Dialog
debconf: (TERM is not set, so the dialog frontend is not usable.)
debconf: falling back to frontend: Readline
debconf: unable to initialize frontend: Readline
debconf: (This frontend requires a controlling tty.)
debconf: falling back to frontend: Teletype
dpkg-preconfigure: unable to re-open stdin: 
1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Need to get 0 B/300 kB of archives.
After this operation, 35.8 kB of additional disk space will be used.
dpkg: warning: 'ldconfig' not found in PATH or not executable
dpkg: warning: 'start-stop-daemon' not found in PATH or not executable
dpkg: error: 2 expected programs not found in PATH or not executable
Note: root's PATH should usually contain /usr/local/sbin, /usr/sbin and /sbin
E: Sub-process /usr/bin/dpkg returned an error code (2)

Então, foi um erro PATH.

O PATH da raiz no meu sistema contém todos os diretórios necessários. O mesmo acontece com a variável secure_path no visudo. É por isso que tudo funciona quando eu executo o sudo apt-get manualmente.

Mas o cron não define as variáveis de ambiente. Então, adicionei uma variável de ambiente PATH para cada uma das tarefas do cron.

$ sudo crontab -e

22 16 * * * PATH='/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin' apt-get -y update >> /var/log/my-new-apt-update.txt 2>&1
32 16 * * * PATH='/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin' apt-get -y upgrade >> /var/log/my-new-apt-upgrade.txt 2>&1

E funcionou! O pacote foi atualizado com sucesso pela tarefa Cron.