Este problema parece trivial a princípio, mas não é, e provavelmente não é totalmente específico do Postfix/Dovecot. Seria ótimo se alguém pudesse me dar uma dica...
A configuração é a seguinte: Tenho um servidor de nomes (BIND) e um combo Postfix/Dovecot rodando na mesma máquina. Ele tem 1 endereço IPv4 (esses são escassos...) e vários endereços IPv6. No começo, todos os servidores estavam rodando em todas as interfaces, ou seja, escutando em 0.0.0.0
e [::]
, mas então decidi dar a eles IPv6 separados ("porque podemos..."). Na v4 eles permanecem no mesmo IP.
Durante a configuração inicial e os testes, tudo funcionou bem. No final, decidi reiniciar a máquina só para ter certeza de que não há nenhuma configuração obsoleta/temporária à espreita e que tudo funciona como esperado após uma inicialização limpa.
E então aconteceu o seguinte (registro reduzido às partes relevantes):
...
Nov 30 22:49:52 systemd[1]: Finished networking.service - Raise network interfaces.
Nov 30 22:49:52 systemd[1]: Reached target network.target - Network.
Nov 30 22:49:52 systemd[1]: Reached target network-online.target - Network is Online.
Nov 30 22:49:52 systemd[1]: Starting dovecot.service - Dovecot IMAP/POP3 email server...
Nov 30 22:49:52 systemd[1]: Starting named.service - BIND Domain Name Server...
Nov 30 22:49:52 systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Nov 30 22:49:52 named[984]: starting BIND 9.20.2-1-Debian (Stable Release) <id:>
Nov 30 22:49:52 named[984]: running on Linux x86_64 6.11.5-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.11.5-1 (2024-10-27)
...
Nov 30 22:49:52 named[984]: listening on IPv4 interface lo, 127.0.0.6#53
Nov 30 22:49:52 named[984]: listening on IPv4 interface enp5s0, 88.198.70.58#53
Nov 30 22:49:52 named[984]: listening on IPv6 interface enp5s0, 2a01:4f8:140:501a::b00d#53
...
Nov 30 22:49:52 dovecot[983]: Error: bind(2a01:4f8:140:501a::d19c, 587) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Error: service(submission-login): listen(2a01:4f8:140:501a::d19c, 587) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Error: bind(2a01:4f8:140:501a::d19c, 143) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Error: service(imap-login): listen(2a01:4f8:140:501a::d19c, 143) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Error: bind(2a01:4f8:140:501a::d19c, 993) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Error: service(imap-login): listen(2a01:4f8:140:501a::d19c, 993) failed: Cannot assign requested address
Nov 30 22:49:52 dovecot[983]: Fatal: Failed to start listeners
Nov 30 22:49:52 systemd[1]: dovecot.service: Main process exited, code=exited, status=89/n/a
Nov 30 22:49:52 systemd[1]: dovecot.service: Failed with result 'exit-code'.
Nov 30 22:49:52 systemd[1]: Failed to start dovecot.service - Dovecot IMAP/POP3 email server.
...
Nov 30 22:49:52 systemd[1]: Started named.service - BIND Domain Name Server.
Nov 30 22:49:52 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups.
Nov 30 22:49:52 systemd[1]: Starting [email protected] - Postfix Mail Transport Agent (instance -)...
Nov 30 22:49:52 postmulti[1141]: postfix/postlog: starting the Postfix mail system
Nov 30 22:49:52 postfix/master[1143]: fatal: bind 2a01:4f8:140:501a::d19c port 25: Cannot assign requested address
Nov 30 22:49:54 postmulti[1145]: postfix/postlog: fatal: mail system startup failed
Nov 30 22:49:55 systemd[1]: [email protected]: Control process exited, code=exited, status=1/FAILURE
Nov 30 22:49:55 systemd[1]: [email protected]: Failed with result 'exit-code'.
Nov 30 22:49:55 systemd[1]: Failed to start [email protected] - Postfix Mail Transport Agent (instance -).
Note que o BIND inicia com sucesso em todas as interfaces. O Dovecot inicia em paralelo e gera um erro ao tentar escutar em um IPv6 separado. (O log não diz nada sobre IPv4 e localhost, então ou funciona, ou o erro IPv6 vem primeiro.) O Postfix encontra o mesmo erro ao tentar escutar no mesmo IPv6.
Agora, a questão é que, quando eu inicio esses serviços manualmente após a inicialização via systemctl start
, ambos inicializam sem problemas. E eles realmente funcionam em todas as interfaces.
Então meu pensamento inicial foi que há algum tipo de condição de corrida durante o processo de inicialização, de modo que nem todas as interfaces IPv6 são realmente ativadas, antes do início do Dovecot/Postfix. O que não deveria ser possível, já que todas elas dependem de network-online.target
, que de acordo com o systemd é totalmente concluído antes do BIND iniciar a inicialização.
Então eu troquei o Dovecot para rodar no mesmo IPv6 (:b00d) que o BIND, já que ele inicializa com sucesso naquele IP. O Postfix ainda está no IP original (:d19c). Ao mesmo tempo, eu também criei um "serviço" fictício que apenas exibe a configuração de rede durante o processo de inicialização, para que eu possa ver o que o Dovecot e o Postfix estão vendo durante a inicialização. Eu fiz esse serviço rodar duas vezes - uma antes do BIND/Postfix/Dovecot, e uma depois.
O resultado final é: a) O Dovecot ainda falha mesmo quando se usa o mesmo IP do BIND . b) de acordo com ifconfig
todos os IPv6s que estão realmente configurados e ativos antes do início dos serviços (como deveria ser)
Dec 01 19:52:16 systemd[1]: Finished networking.service - Raise network interfaces.
Dec 01 19:52:16 systemd[1]: Reached target network.target - Network.
Dec 01 19:52:16 systemd[1]: Reached target network-online.target - Network is Online.
Dec 01 19:52:16 systemd[1]: Starting named.service - BIND Domain Name Server...
Dec 01 19:52:16 systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Dec 01 19:52:16 systemd[1]: Reached target getty.target - Login Prompts.
Dec 01 19:52:16 named[981]: starting BIND 9.20.2-1-Debian (Stable Release) <id:>
Dec 01 19:52:16 named[981]: running on Linux x86_64 6.11.5-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.11.5-1 (2024-10-27)
...
Dec 01 19:52:16 named[981]: listening on IPv4 interface lo, 127.0.0.6#53
Dec 01 19:52:16 named[981]: listening on IPv4 interface enp5s0, 88.198.70.58#53
Dec 01 19:52:16 named[981]: listening on IPv6 interface enp5s0, 2a01:4f8:140:501a::b00d#53
...
Dec 01 19:52:16 systemd[1]: Started named.service - BIND Domain Name Server.
Dec 01 19:52:16 systemd[1]: Reached target nss-lookup.target - Host and Network Name Lookups.
Dec 01 19:52:16 systemd[1]: Starting dovecot.service - Dovecot IMAP/POP3 email server...
Dec 01 19:52:16 systemd[1]: Starting test-networking.service - ###################### Test Network Configuration ###########################...
Dec 01 19:52:16 ip[992]: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
Dec 01 19:52:16 ip[992]: link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
Dec 01 19:52:16 ip[992]: inet 127.0.0.1/8 scope host lo
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet 127.0.0.3/8 brd 127.0.0.0 scope host secondary lo
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet 127.0.0.6/8 brd 127.0.0.0 scope host secondary lo
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet6 ::1/128 scope host noprefixroute
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: 2: enp5s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel state DOWN group default qlen 1000
Dec 01 19:52:16 ip[992]: link/ether a8:a1:59:08:49:5d brd ff:ff:ff:ff:ff:ff
Dec 01 19:52:16 ip[992]: inet 88.198.70.58/27 brd 88.198.70.63 scope global enp5s0
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet6 2a01:4f8:140:501a::d19c/64 scope global tentative
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet6 2a01:4f8:140:501a::b00d/64 scope global tentative
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[992]: inet6 2a01:4f8:140:501a::2/64 scope global tentative
Dec 01 19:52:16 ip[992]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 systemd[1]: test-networking.service: Deactivated successfully.
Dec 01 19:52:16 systemd[1]: Finished test-networking.service - ###################### Test Network Configuration ###########################.
Dec 01 19:52:16 dovecot[991]: Error: bind(2a01:4f8:140:501a::d19c, 587) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Error: service(submission-login): listen(2a01:4f8:140:501a::d19c, 587) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Error: bind(2a01:4f8:140:501a::d19c, 143) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Error: service(imap-login): listen(2a01:4f8:140:501a::d19c, 143) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Error: bind(2a01:4f8:140:501a::d19c, 993) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Error: service(imap-login): listen(2a01:4f8:140:501a::d19c, 993) failed: Cannot assign requested address
Dec 01 19:52:16 dovecot[991]: Fatal: Failed to start listeners
Dec 01 19:52:16 systemd[1]: dovecot.service: Main process exited, code=exited, status=89/n/a
Dec 01 19:52:16 systemd[1]: dovecot.service: Failed with result 'exit-code'.
Dec 01 19:52:16 systemd[1]: Failed to start dovecot.service - Dovecot IMAP/POP3 email server.
Dec 01 19:52:16 systemd[1]: Reached target multi-user.target - Multi-User System.
Dec 01 19:52:16 systemd[1]: Reached target graphical.target - Graphical Interface.
Dec 01 19:52:16 systemd[1]: Starting [email protected] - Postfix Mail Transport Agent (instance -)...
Dec 01 19:52:16 systemd[1]: Starting test-networking2.service - ********************** Second Test Network Configuration ****************************...
Dec 01 19:52:16 ip[998]: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
Dec 01 19:52:16 ip[998]: link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
Dec 01 19:52:16 ip[998]: inet 127.0.0.1/8 scope host lo
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet 127.0.0.3/8 brd 127.0.0.0 scope host secondary lo
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet 127.0.0.6/8 brd 127.0.0.0 scope host secondary lo
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet6 ::1/128 scope host noprefixroute
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: 2: enp5s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel state DOWN group default qlen 1000
Dec 01 19:52:16 ip[998]: link/ether a8:a1:59:08:49:5d brd ff:ff:ff:ff:ff:ff
Dec 01 19:52:16 ip[998]: inet 88.198.70.58/27 brd 88.198.70.63 scope global enp5s0
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet6 2a01:4f8:140:501a::d19c/64 scope global tentative
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet6 2a01:4f8:140:501a::b00d/64 scope global tentative
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 ip[998]: inet6 2a01:4f8:140:501a::2/64 scope global tentative
Dec 01 19:52:16 ip[998]: valid_lft forever preferred_lft forever
Dec 01 19:52:16 systemd[1]: test-networking2.service: Deactivated successfully.
Dec 01 19:52:16 systemd[1]: Finished test-networking2.service - ********************** Second Test Network Configuration ****************************.
Dec 01 19:52:17 postmulti[1143]: postfix/postlog: starting the Postfix mail system
Dec 01 19:52:17 postfix/master[1145]: fatal: bind 2a01:4f8:140:501a::d19c port 25: Cannot assign requested address
Dec 01 19:52:19 kernel: r8169 0000:05:00.0 enp5s0: Link is Up - 1Gbps/Full - flow control rx/tx
Dec 01 19:52:19 postmulti[1146]: postfix/postlog: fatal: mail system startup failed
Dec 01 19:52:20 systemd[1]: [email protected]: Control process exited, code=exited, status=1/FAILURE
Dec 01 19:52:20 systemd[1]: [email protected]: Failed with result 'exit-code'.
Dec 01 19:52:20 systemd[1]: Failed to start [email protected] - Postfix Mail Transport Agent (instance -).
Dec 01 19:52:20 systemd[1]: Startup finished in 3.180s (kernel) + 6.272s (userspace) = 9.453s.
...
Dec 01 19:54:04 systemd[1]: Starting dovecot.service - Dovecot IMAP/POP3 email server...
Dec 01 19:54:04 systemd[1]: Started dovecot.service - Dovecot IMAP/POP3 email server.
Dec 01 19:54:10 systemd[1]: Starting [email protected] - Postfix Mail Transport Agent (instance -)...
Dec 01 19:54:10 postmulti[1341]: postfix/postlog: warning: symlink leaves directory: /etc/postfix/./postfix-files
Dec 01 19:54:10 postmulti[1375]: postfix/postlog: starting the Postfix mail system
Dec 01 19:54:10 systemd[1]: Started [email protected] - Postfix Mail Transport Agent (instance -).
Dec 01 19:54:10 systemd[1]: Starting postfix.service - Postfix Mail Transport Agent...
Dec 01 19:54:10 systemd[1]: Finished postfix.service - Postfix Mail Transport Agent.
Novamente, após a inicialização, posso iniciar ambos os serviços manualmente - sem erros.
Alguém tem alguma ideia do que está acontecendo? Encontrei alguns relatos semelhantes na internet, mas todos eles têm causas que podem ser descartadas no meu caso.
Obrigado por qualquer feedback!
EDIT : Substitua o segundo log onde ip addr
é usado em vez de ifconfig
para mostrar a configuração de rede atual durante o tempo de inicialização. Também incluí as linhas que mostram o início manual do Dovecot/Postfix 2 minutos após a inicialização - sem erros.
EDIT2: Os IPs adicionais são configurados por meio de um arquivo sob /etc/network/interfaces.d/
o qual no Debian é originado por /etc/network/interfaces
. Ambos os arquivos são processados em uma etapa durante a inicialização quando networking.service
é iniciado. Este é o snippet:
iface enp5s0 inet6 static
address 2a01:4f8:140:501a::b00d/64
iface enp5s0 inet6 static
address 2a01:4f8:140:501a::d19c/64
Tradicionalmente, essas seriam interfaces com alias (enp5s0:1, :2, etc.), mas elas parecem estar obsoletas agora, então a maneira acima é aparentemente a preferida para configurar IPs adicionais atualmente.