1. SH Avatar SH
  2. Untitled project
  3. MailServer
  4. Issues

No more STARTTLS on 2.4.7

Issue #1089 resolved
Arthur Trouillet created an issue

Since 2.4.7 i have no more STARTTLS connection.

This does not seems to come from a Firewall, as in the docker i have nothing listening to port 587: 

arthur  /etc/poste.io  docker exec -it poste.io netstat -tulnp | grep 587
arthur  /etc/poste.io  echo $?
1

As my understanting, the SMTP should be handled by Haraka, the process seems to be running in the container : 

arthur  /etc/poste.io  docker exec poste.io ps -aux | grep haraka
root         679  0.0  0.0    200     0 pts/0    S+   20:01   0:00 s6-supervise haraka-submission/log
root         680  0.0  0.0    200     0 pts/0    S+   20:01   0:00 s6-supervise haraka-submission
root         695  0.0  0.0    200     0 pts/0    S+   20:01   0:00 s6-supervise haraka-smtp/log
root         696  0.0  0.0    200     0 pts/0    S+   20:01   0:00 s6-supervise haraka-smtp
nobody       706  0.0  0.0    264     0 ?        Ss   20:01   0:00 s6-log -bp -- n20 s1000000 T /data/log/s6/haraka-smtp
nobody       738  3.7  0.0    284     0 ?        Ss   20:01   0:49 s6-log -bp -- n20 s1000000 T /data/log/s6/haraka-submission
delivery    3169  0.6  0.7 11825700 112616 ?     Ssl  20:04   0:07 /usr/bin/node --tls-min-v1.0 --tls-cipher-list=DEFAULT@SECLEVEL=0 --no-deprecation --trace-warnings /usr/lib/node_modules/Haraka/bin/haraka -c /opt/haraka-smtp/
root       15771  0.0  0.3 1000740 49664 ?       Rsl  20:22   0:00 /usr/bin/node --tls-min-v1.0 --tls-cipher-list=DEFAULT@SECLEVEL=0 --no-deprecation --trace-warnings /usr/lib/node_modules/Haraka/bin/haraka -c /opt/haraka-submission/

This is the logs from Haraka SMTP : 

2024-08-16 20:18:11.502490500  [DEBUG] [-] [watch]  msg="220 [REDACTED] ESMTP Haraka ready"
2024-08-16 20:18:11.945889500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] tarpit connect end
2024-08-16 20:18:11.945973500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=connect plugin=karma function=hook_connect params="" retval=CONT msg=""
2024-08-16 20:18:11.946025500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running connect hook in dns-list plugin
2024-08-16 20:18:12.373690500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] tarpit connect end
2024-08-16 20:18:12.373754500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=connect plugin=karma function=hook_connect params="" retval=CONT msg=""
2024-08-16 20:18:12.373793500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running connect hook in dns-list plugin
2024-08-16 20:18:14.110493500  [INFO] [AE726B94-C145-42B1-95B4-5B2EB607F135] [dns-list] pass:psbl.surriel.com, bl.spamcop.net, dnsbl-1.uceprotect.net, dnsbl.justspam.org, dnsbl.sorbs.net, truncate.gbudb.net, b.barracudacentral.org
2024-08-16 20:18:14.110573500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=connect plugin=dns-list function=onConnect params="" retval=CONT msg=""
2024-08-16 20:18:14.110625500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running connect hook in relay plugin
2024-08-16 20:18:14.110689500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=connect plugin=relay function=pass_relaying params="" retval=CONT msg=""
2024-08-16 20:18:14.110733500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running connect hook in geoip plugin
2024-08-16 20:18:14.110981500  [INFO] [AE726B94-C145-42B1-95B4-5B2EB607F135] [geoip] CZ
2024-08-16 20:18:14.111039500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=connect plugin=geoip function=lookup_maxmind params="" retval=CONT msg=""
2024-08-16 20:18:14.111177500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 220 [REDACTED] ESMTP Haraka ready
2024-08-16 20:18:14.178092500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] C: EHLO 185.13.36.60 state=1
2024-08-16 20:18:14.178284500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hooks
2024-08-16 20:18:14.178339500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in hello_block plugin
2024-08-16 20:18:14.178408500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=hello_block function=check_ymlf params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:14.178453500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in karma plugin
2024-08-16 20:18:14.178524500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] static tarpit
2024-08-16 20:18:14.178564500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] tarpitting ehlo for 1s
2024-08-16 20:18:15.179015500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] tarpit ehlo end
2024-08-16 20:18:15.179096500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=karma function=hook_ehlo params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179147500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.179276500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=proto_mismatch_esmtp params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179320500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.179406500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=init params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179449500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.179635500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=match_re params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179706500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.179822500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=bare_ip params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179854500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.179951500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=dynamic params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.179982500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180076500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=big_company params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180104500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180321500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=valid_hostname params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180352500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180477500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=rdns_match params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180505500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180599500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=forward_dns params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180627500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180703500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=host_mismatch params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180732500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180819500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=literal_mismatch params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.180847500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in helo.checks plugin
2024-08-16 20:18:15.180881500  [INFO] [AE726B94-C145-42B1-95B4-5B2EB607F135] [helo.checks] helo_host: 185.13.36.60, pass:match_re, big_co(not), host_mismatch, literal_mismatch, fail:bare_ip(invalid literal), valid_hostname, rdns_match, forward_dns(invalid_hostname), skip:dynamic(literal)
2024-08-16 20:18:15.180916500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=helo.checks function=emit_log params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.181393500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in mailauth/verify plugin
2024-08-16 20:18:15.181463500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=mailauth/verify function=mailauth_helo params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.181496500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running ehlo hook in uribl plugin
2024-08-16 20:18:15.181558500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [uribl] (helo) found 1 items for lookup
2024-08-16 20:18:15.181586500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [uribl] (helo) checking: 185.13.36.60
2024-08-16 20:18:15.181760500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=ehlo plugin=uribl function=lookup_ehlo params=185.13.36.60 retval=CONT msg=""
2024-08-16 20:18:15.181798500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running capabilities hooks
2024-08-16 20:18:15.181831500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running capabilities hook in auth/poste plugin
2024-08-16 20:18:15.181870500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=capabilities plugin=auth/poste function=hook_capabilities params="" retval=CONT msg=""
2024-08-16 20:18:15.181898500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running capabilities hook in status_http plugin
2024-08-16 20:18:15.181935500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=capabilities plugin=status_http function=hook_capabilities params="" retval=CONT msg=""
2024-08-16 20:18:15.181964500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running capabilities hook in tls plugin
2024-08-16 20:18:15.182544500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=capabilities plugin=tls function=advertise_starttls params="" retval=CONT msg=""
2024-08-16 20:18:15.182594500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250-[REDACTED] Hello mail.poste.io [178.248.62.3], , Poste.io is at your service
2024-08-16 20:18:15.182619500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250-PIPELINING
2024-08-16 20:18:15.182643500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250-8BITMIME
2024-08-16 20:18:15.182667500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250-SMTPUTF8
2024-08-16 20:18:15.182698500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250-SIZE 26214400
2024-08-16 20:18:15.182721500  [PROTOCOL] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] S: 250 STARTTLS
2024-08-16 20:18:15.182917500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.182933500  [DEBUG] [-] [watch]  _skip_hooks=proto_mismatch
2024-08-16 20:18:15.183009500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183028500  [DEBUG] [-] [watch]  _skip_hooks=match_re
2024-08-16 20:18:15.183085500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183105500  [DEBUG] [-] [watch]  _skip_hooks=bare_ip
2024-08-16 20:18:15.183165500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183184500  [DEBUG] [-] [watch]  _skip_hooks=dynamic
2024-08-16 20:18:15.183237500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183257500  [DEBUG] [-] [watch]  _skip_hooks=big_company
2024-08-16 20:18:15.183309500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183328500  [DEBUG] [-] [watch]  _skip_hooks=valid_hostname
2024-08-16 20:18:15.183386500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183406500  [DEBUG] [-] [watch]  _skip_hooks=rdns_match
2024-08-16 20:18:15.183463500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183482500  [DEBUG] [-] [watch]  _skip_hooks=forward_dns
2024-08-16 20:18:15.183538500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183559500  [DEBUG] [-] [watch]  _skip_hooks=host_mismatch
2024-08-16 20:18:15.183609500  [DEBUG] [-] [watch] helo.checks
2024-08-16 20:18:15.183629500  [DEBUG] [-] [watch]  _skip_hooks=literal_mismatch
2024-08-16 20:18:15.249694500  [INFO] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client half closed connection ip=178.248.62.3
2024-08-16 20:18:15.249940500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.249984500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hooks
2024-08-16 20:18:15.250030500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.250086500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hook in stats plugin
2024-08-16 20:18:15.251678500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.251764500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=disconnect plugin=stats function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:15.251806500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.251870500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hook in block_bad_connections plugin
2024-08-16 20:18:15.252683500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [block_bad_connections] Invalid connections: 12/100
2024-08-16 20:18:15.252730500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.252802500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=disconnect plugin=block_bad_connections function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:15.252846500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.252919500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hook in karma plugin
2024-08-16 20:18:15.253380500  [INFO] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] score: -4, bad: 8, connections: 11, history: -8, awards: 004,005,130,133, asn_score: -8, asn_connections: 17, asn_bad: 8, fail:asn:history
2024-08-16 20:18:15.253426500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.253535500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=disconnect plugin=karma function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:15.253561500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.253613500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hook in log plugin
2024-08-16 20:18:15.253913500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.253998500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=disconnect plugin=log function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:15.254016500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.254090500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] running disconnect hook in tls plugin
2024-08-16 20:18:15.254120500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] client has disconnected
2024-08-16 20:18:15.254169500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core]  hook=disconnect plugin=tls function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:15.254386500  [NOTICE] [AE726B94-C145-42B1-95B4-5B2EB607F135] [core] disconnect ip=178.248.62.3 rdns=mail.poste.io helo=185.13.36.60 relay=N early=N esmtp=Y tls=N pipe=N errors=0 txns=0 rcpts=0/0/0 msgs=0/0/0 bytes=0 lr="" time=7.325
2024-08-16 20:18:15.255431500  [DEBUG] [AE726B94-C145-42B1-95B4-5B2EB607F135] [karma] unsubsubscribed from result-AE726B94-C145-42B1-95B4-5B2EB607F135*
2024-08-16 20:18:15.256691500  [DEBUG] [-] [watch] important_response
2024-08-16 20:18:15.256745500  [DEBUG] [-] [watch]  msg="250-[REDACTED] Hello mail.poste.io [178.248.62.3], , Poste.io is at your service\r\\n250-PIPELINING\r\\n250-8BITMIME\r\\n250-SMTPUTF8\r\\n250-SIZE 26214400\r\\n250 STARTTLS"
2024-08-16 20:18:18.369963500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] [early_talker] state=4 esmtp=false line="EHLO 2a03:75c0:1f:a81b::"
2024-08-16 20:18:23.314689500  [INFO] [6692838E-5510-4277-B73C-91E53EE12A76] [dns-list] pass:bl.spamcop.net, dnsbl.justspam.org, dnsbl.sorbs.net, truncate.gbudb.net, dnsbl-1.uceprotect.net, psbl.surriel.com, b.barracudacentral.org
2024-08-16 20:18:23.314769500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=connect plugin=dns-list function=onConnect params="" retval=CONT msg=""
2024-08-16 20:18:23.314822500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running connect hook in relay plugin
2024-08-16 20:18:23.314883500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=connect plugin=relay function=pass_relaying params="" retval=CONT msg=""
2024-08-16 20:18:23.314927500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running connect hook in geoip plugin
2024-08-16 20:18:23.315101500  [INFO] [6692838E-5510-4277-B73C-91E53EE12A76] [geoip] CZ
2024-08-16 20:18:23.315154500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=connect plugin=geoip function=lookup_maxmind params="" retval=CONT msg=""
2024-08-16 20:18:23.315301500  [PROTOCOL] [6692838E-5510-4277-B73C-91E53EE12A76] [core] S: 220 [REDACTED] ESMTP Haraka ready
2024-08-16 20:18:23.315415500  [PROTOCOL] [6692838E-5510-4277-B73C-91E53EE12A76] [core] C: EHLO 2a03:75c0:1f:a81b:: state=1
2024-08-16 20:18:23.315535500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running ehlo hooks
2024-08-16 20:18:23.315583500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running ehlo hook in hello_block plugin
2024-08-16 20:18:23.315641500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=ehlo plugin=hello_block function=check_ymlf params=2a03:75c0:1f:a81b:: retval=CONT msg=""
2024-08-16 20:18:23.315683500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running ehlo hook in karma plugin
2024-08-16 20:18:23.315918500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] applied early_talker:-3
2024-08-16 20:18:23.316005500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] static tarpit
2024-08-16 20:18:23.316043500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] tarpitting ehlo for 1s
2024-08-16 20:18:23.339649500  [INFO] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client half closed connection ip=2a03:ab00:10:113::1
2024-08-16 20:18:23.339794500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.339833500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hooks
2024-08-16 20:18:23.341423500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.341555500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hook in stats plugin
2024-08-16 20:18:23.343020500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.343171500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=disconnect plugin=stats function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:23.343255500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.343313500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hook in block_bad_connections plugin
2024-08-16 20:18:23.344038500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [block_bad_connections] Invalid connections: 6/100
2024-08-16 20:18:23.344094500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.344167500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=disconnect plugin=block_bad_connections function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:23.344214500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.344268500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hook in karma plugin
2024-08-16 20:18:23.344516500  [INFO] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] score: -5, bad: 5, connections: 5, history: -5, awards: 004,005, fail:early_talker
2024-08-16 20:18:23.344563500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.344625500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=disconnect plugin=karma function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:23.344667500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.344715500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hook in log plugin
2024-08-16 20:18:23.345016500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.345070500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=disconnect plugin=log function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:23.345130500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.345178500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] running disconnect hook in tls plugin
2024-08-16 20:18:23.345227500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core] client has disconnected
2024-08-16 20:18:23.345281500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [core]  hook=disconnect plugin=tls function=hook_disconnect params="" retval=CONT msg=""
2024-08-16 20:18:23.345459500  [NOTICE] [6692838E-5510-4277-B73C-91E53EE12A76] [core] disconnect ip=2a03:ab00:10:113::1 rdns=mail.poste.io helo=2a03:75c0:1f:a81b:: relay=N early=Y esmtp=N tls=N pipe=N errors=0 txns=0 rcpts=0/0/0 msgs=0/0/0 bytes=0 lr="" time=14.986
2024-08-16 20:18:23.346084500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] unsubsubscribed from result-6692838E-5510-4277-B73C-91E53EE12A76*
2024-08-16 20:18:23.346633500  [DEBUG] [-] [watch] important_response
2024-08-16 20:18:23.346667500  [DEBUG] [-] [watch]  msg="220 [REDACTED] ESMTP Haraka ready"
2024-08-16 20:18:24.315892500  [DEBUG] [6692838E-5510-4277-B73C-91E53EE12A76] [karma] tarpit ehlo end

And of course, i can’t telnet on port 587 inside the container : 

arthur  /etc/poste.io/log/s6  docker exec poste.io telnet localhost 587
Trying ::1...
Trying 127.0.0.1...
telnet: Unable to connect to remote host: Connection refused

‌

Comments (2)

  1. Arthur Trouillet reporter

    I found the problem, it was comming from haraka-submission, the logs was full of message like this one : 

    2024-08-16 20:44:37.727031500  [DEBUG] [-] [outbound] Temp fail for: Error reading queue file 1718374112405_1718669443951_12_750_34UI6J_9876_[REDACTED]: zero bytes
2024-08-16 20:44:37.727103500  [CRIT] [-] [core] TypeError: Cannot read properties of null (reading 'rcpt_to')
2024-08-16 20:44:37.727119500  [CRIT] [-] [core]     at HMailItem.convert_temp_failed_to_bounce (/usr/lib/node_modules/Haraka/outbound/hmail.js:1273:19)
2024-08-16 20:44:37.727135500  [CRIT] [-] [core]     at HMailItem.temp_fail (/usr/lib/node_modules/Haraka/outbound/hmail.js:1288:25)
2024-08-16 20:44:37.727151500  [CRIT] [-] [core]     at /usr/lib/node_modules/Haraka/outbound/hmail.js:83:22
2024-08-16 20:44:37.727167500  [CRIT] [-] [core]     at FSReqCallback.oncomplete (node:fs:199:5)

    I had to delete the entire queue for it to work again

  3. Log in to comment
Assignee
–
Type
bug
Priority
major
Status
resolved
Votes
0
Watchers
1
Jira: the preferred issue tracker for Bitbucket. Join the team!