dpgk --configure -a trava a configuração de arquivos base, aparentemente em systemd-tty-ask-password-agent

dpgk --configure -a trava a configuração de arquivos base, aparentemente em systemd-tty-ask-password-agent

dpkg --configure -aestá pendurado durante a configuração base-files. Do diagnóstico até agora aparece dpkg --configure -aruns /var/lib/dpkg/info/base-files.postinst, que executa deb-systemd-invoke start motd-news.timer, que executa systemd-tty-ask-password-agent --watch, que espera eternamente (sem pedir senha no terminal). Diagnóstico detalhado:

$ sudo strace -o /tmp/dpkg-strace -tt -ff dpkg --debug=222 --configure -a
Setting up base-files (11ubuntu5.4) ...
D000002: fork/exec /var/lib/dpkg/info/base-files.postinst ( configure 11ubuntu5.3 )

Executando este postinstscript manualmente com bash -xvtravamentos durante a execução deb-systemd-invoke start motd-news.timer, algo também revelado por pstree(para um caso executado sem strace):

bash───sudo───dpkg───base-files.post───systemctl───systemd-tty-ask

Strace gera cerca de 10 mil linhas. Um dos arquivos de saída do strace, que parece corresponder ao comando deb-systemd-invoke start motd-news.timer, termina com um ppoll, aparentemente aguardando um soquete. Seleção de deb-systemd-invoke start motd-news.timer(PID 51072):

10:50:46.673278 close(10)               = 0
10:50:46.673319 execve("/usr/bin/deb-systemd-invoke", ["deb-systemd-invoke", "start", "motd-news.timer"], 0x56297d000c88 /* 37 vars */) = 0
10:50:46.673511 brk(NULL)               = 0x55fff0539000
10:50:46.673534 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd593b7540) = -1 EINVAL (Invalid argument)
10:50:46.673574 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
10:50:46.673613 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.673641 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.673663 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f3bdfb5e000
10:50:46.673686 close(3)                = 0
10:50:46.673713 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
[...]
10:50:46.708457 socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
[...]
10:50:46.710298 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\4\1\24\0\0\0\2\0\0\0\227\0\0\0\1\1o\0\31\0\0\0/org/fre"..., iov_len=168}, {iov_base="\17\0\0\0motd-news.timer\0", iov_len=20}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 188
10:50:46.710350 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\2\1\0017\0\0\0\3\0\0\0007\0\0\0\5\1u\0\2\0\0\0", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24
10:50:46.710422 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\7\1s\0\30\0\0\0org.freedesktop.systemd1"..., iov_len=103}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 103
10:50:46.710472 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\4\19\0\0\0\3\0\0\0\250\0\0\0\1\1o\0002\0\0\0/org/fre"..., iov_len=184}, {iov_base="\35\0\0\0org.freedesktop.systemd1.Uni"..., iov_len=57}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 241
10:50:46.710522 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
10:50:46.710565 ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=24, tv_nsec=999957000}, NULL, 8) = 1 ([{fd=3, revents=POLLIN}], left {tv_sec=24, tv_nsec=999940266})
10:50:46.710626 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\2\1\1\10\0\0\0\4\0\0\0007\0\0\0\5\1u\0\3\0\0\0", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24
10:50:46.710676 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\7\1s\0\30\0\0\0org.freedesktop.systemd1"..., iov_len=56}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 56
10:50:46.710745 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
10:50:46.710794 ppoll([{fd=3, events=POLLIN}], 1, NULL, NULL, 8

Outro, systemd-tty-ask-password-agent --watch, termina com poll, aparentemente aguardando um evento de soquete ou inotify para que uma senha apareça. Seleção para 51076:

10:50:46.709061 set_robust_list(0x7fb46e4f98e0, 24) = 0
10:50:46.709158 prctl(PR_SET_NAME, "(sd-askpwagent)"...) = 0
10:50:46.709242 geteuid()               = 0
10:50:46.709322 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb46e9cd000
10:50:46.709349 prctl(PR_SET_MM, PR_SET_MM_ARG_START, 0x7fb46e9cd000, 0, 0) = 0
10:50:46.709371 prctl(PR_SET_MM, PR_SET_MM_ARG_END, 0x7fb46e9cd010, 0, 0) = 0
10:50:46.709393 prctl(PR_SET_PDEATHSIG, SIGTERM) = 0
10:50:46.709416 rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
10:50:46.709439 rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
10:50:46.709459 rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fb46e808210}, NULL, 8) = 0
[...]
10:50:46.711627 prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=512*1024, rlim_max=512*1024}) = 0
10:50:46.711660 prlimit64(0, RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=512*1024}, NULL) = 0
10:50:46.711690 execve("/bin/systemd-tty-ask-password-agent", ["/bin/systemd-tty-ask-password-ag"..., "--watch"], 0x7ffce60ac808 /* 37 vars */) = 0
10:50:46.711926 brk(NULL)               = 0x55abfc744000
10:50:46.711956 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffe7027e8f0) = -1 EINVAL (Invalid argument)
[...]
10:50:46.722618 read(3, "", 1024)       = 0
10:50:46.722637 close(3)                = 0
10:50:46.722659 stat("/run/systemd/ask-password-block", {st_mode=S_IFDIR|0700, st_size=160, ...}) = 0
10:50:46.722683 mknod("/run/systemd/ask-password-block/136:6", S_IFIFO|0600) = -1 EEXIST (File exists)
10:50:46.722706 openat(AT_FDCWD, "/run/systemd/ask-password-block/136:6", O_RDONLY|O_NOCTTY|O_NONBLOCK|O_CLOEXEC) = 3
10:50:46.722728 stat("/run/systemd", {st_mode=S_IFDIR|0755, st_size=520, ...}) = 0
10:50:46.722751 mkdir("/run/systemd/ask-password", 0755) = -1 EEXIST (File exists)
10:50:46.722779 stat("/run/systemd/ask-password", {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
10:50:46.722803 rt_sigprocmask(SIG_SETMASK, [TERM], NULL, 8) = 0
10:50:46.722823 signalfd4(-1, [TERM], 8, SFD_CLOEXEC|SFD_NONBLOCK) = 4
10:50:46.722845 inotify_init1(IN_CLOEXEC) = 5
10:50:46.722865 inotify_add_watch(5, "/run/systemd/ask-password", IN_CLOSE_WRITE|IN_MOVED_TO) = 1
10:50:46.722891 openat(AT_FDCWD, "/run/systemd/ask-password", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6
10:50:46.722913 fstat(6, {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
10:50:46.722937 getdents64(6, /* 2 entries */, 32768) = 48
10:50:46.722959 getdents64(6, /* 0 entries */, 32768) = 0
10:50:46.722977 close(6)                = 0
10:50:46.722995 poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1

O processo principal e o script base-files.postinst parecem estar aguardando wait4a conclusão de outros processos:

10:50:46.017699 execve("/usr/bin/dpkg", ["dpkg", "--configure", "-a"], 0x7fffb1462800 /* 27 vars */) = 0
10:50:46.018044 brk(NULL)               = 0x5636a8783000
10:50:46.018135 arch_prctl(0x3001 /* ARCH_??? */, 0x7fffa60dac50) = -1 EINVAL (Invalid argument)
10:50:46.018208 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
10:50:46.018264 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.018307 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.018343 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fa02ba19000
10:50:46.018377 close(3)                = 0
10:50:46.018416 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
10:50:46.018450 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@p\0\0\0\0\0\0"..., 832) = 832
[...]
10:50:46.163945 fcntl(5, F_SETFD, FD_CLOEXEC) = 0
10:50:46.164043 fstat(5, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
10:50:46.164180 write(5, "#padding\n#padding\n#padding\n#padd"..., 4096) = 4096
10:50:46.164354 write(5, "padding\n#padding\n#padding\n#paddi"..., 512) = 512
10:50:46.164486 lseek(5, 0, SEEK_SET)   = 0
10:50:46.164598 stat("/var/lib/dpkg/info/base-files.postinst", {st_mode=S_IFREG|0755, st_size=5664, ...}) = 0
10:50:46.164718 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fa02b7406d0) = 51032
10:50:46.165711 rt_sigaction(SIGQUIT, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7fa02b840210}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
10:50:46.165855 rt_sigaction(SIGINT, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7fa02b840210}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
10:50:46.166017 wait4(51032,

e

10:50:46.165943 set_robust_list(0x7fa02b7406e0, 24) = 0
10:50:46.166455 chdir("/")              = 0
10:50:46.166748 execve("/var/lib/dpkg/info/base-files.postinst", ["/var/lib/dpkg/info/base-files.po"..., "configure", "11ubuntu5.3"], 0x5636a87c4840 /* 36 vars */) = 0
10:50:46.168230 brk(NULL)               = 0x56297cffd000
10:50:46.168542 arch_prctl(0x3001 /* ARCH_??? */, 0x7fffc0915d90) = -1 EINVAL (Invalid argument)
10:50:46.168877 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
10:50:46.169322 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
10:50:46.169734 fstat(3, {st_mode=S_IFREG|0644, st_size=160254, ...}) = 0
10:50:46.169951 mmap(NULL, 160254, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f5c7351e000
10:50:46.170127 close(3)                = 0
[...]
10:50:46.673001 close(1)                = 0
10:50:46.673018 fcntl(11, F_SETFD, FD_CLOEXEC) = 0
10:50:46.673035 dup2(3, 1)              = 1
10:50:46.673051 close(3)                = 0
10:50:46.673068 stat("/usr/local/sbin/deb-systemd-invoke", 0x7fffc09159a0) = -1 ENOENT (No such file or directory)
10:50:46.673093 stat("/usr/local/bin/deb-systemd-invoke", 0x7fffc09159a0) = -1 ENOENT (No such file or directory)
10:50:46.673113 stat("/usr/sbin/deb-systemd-invoke", 0x7fffc09159a0) = -1 ENOENT (No such file or directory)
10:50:46.673132 stat("/usr/bin/deb-systemd-invoke", {st_mode=S_IFREG|0755, st_size=4430, ...}) = 0
10:50:46.673156 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f5c7351d850) = 51072
10:50:46.673267 wait4(-1,

A maioria dos outros termina com "+++ encerrado com 0 +++" e/ou não vejo nada suspeito.

Parece que deb-systemd-invoke start motd-news.timerdeb-systemd-invoke start motd-news.timerestamos esperando uma eternidade por uma senha, mas nenhuma solicitação está visível na interface do usuário. De acordo comesta nota do blog, a reinicialização deve resolver este problema:

É bastante irritante quando systemd-tty-ask ou /bin/systemd-tty-ask-password-agent –watch trava durante a instalação de um pacote, início de serviço ou operação de interrupção.

Embora reiniciar o sistema resolva o problema, felizmente basta reiniciar apenas o gerenciador do systemd:

sudo systemctl daemon-reexec

Eu suspeito que este seja um bug do systemd, já que o daemon-reexec disse não estar fazendo nada de especial além de reiniciar o daemon com a releitura da configuração.

No entanto, nem executar sudo systemctl daemon-reexecnem reinicializar o sistema resolveu o problema. Só depois de fazer esta pergunta é que descobriesta questão intimamente relacionadamas nenhuma solução satisfatória é proposta (gostaria de acreditar que não há necessidade de reinstalar o sistema).

Parece queeste bug no launchpad está relacionado, talvez causando diretamente o problema.

Como posso superar o dpkg --configure -aenforcamento base-files? Existe alguma solução alternativa conhecida antes de reinstalar o sistema?

Responder1

Isto parece ser devido a um bug no systemd comorelatado na barra de lançamento aqui. O bug resulta em systemctl start ...suspensão durante a execução systemd-tty-ask-password-agent. Alguns scripts de pós-instalação são executados systemctl start(ou melhor, seus irmãos deb-systemd-invoke start), mas não sei por que isso trava em alguns sistemas, mas não em outros.

É possível completar dpkg --configure -a(ou melhor, permanecer incompleto) editando /var/lib/dpkg/base-files.postinste descomentando a linha deb-systemd-invoke start 'motd-news.timer' >/dev/null || true. Feito isso, dpkg --configure -aé aprovado o base-filesscript de pós-instalação. No entanto, esta não é uma solução satisfatória. Em primeiro lugar, não iniciar o serviço no script pós-instalação provavelmente terá efeitos colaterais no sistema. Em segundo lugar, no próximo apt upgrade, dpkgestava pendurado outro script de pós-instalação (neste caso apt.postinst), então pode ser necessário configurar uma solução alternativa para alguns pacotes, em cada caso com efeitos colaterais a serem determinados.

A alternativa proposta em um comentário sobre o bug da barra de lançamento, para executar systemctl start --no-ask-password, não fez diferença no meu caso.

informação relacionada