Author Topic: RC not sending mails [solved]  (Read 477 times)

Offline MaMaKow

  • Newbie
  • *
  • Posts: 4
RC not sending mails [solved]
« on: September 16, 2020, 06:42:45 AM »
Roundcube is not sending emails.

Why does it answer with QUIT?

Roundcube log:
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Connecting to localhost:587...
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 220 foo-bar.com ESMTP Postfix
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Send: EHLO foo-bar.com
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-foo-bar.com
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-PIPELINING
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-SIZE 10240000
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-VRFY
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-ETRN
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-STARTTLS
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-ENHANCEDSTATUSCODES
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-8BITMIME
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250-DSN
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 250 SMTPUTF8
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Send: QUIT
[16-Sep-2020 11:46:51 +0200]: <sh3finak> Recv: 221 2.0.0 Bye


Postfix Server log:
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: connect from localhost[127.0.0.1]
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: smtp_stream_setup: maxtime=300 enable_deadline=0
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 82.xxx.xxx.238/32
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 82.xxx.xxx.238/32
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 127.0.0.0/8
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 127.0.0.0/8
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: report connect to all milters
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "j"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: result "foo-bar.com"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{daemon_name}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: result "ORIGINATING"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{daemon_addr}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: result "127.0.0.1"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "v"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: result "Postfix 3.3.1"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: non-protocol events for protocol version 6:
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: transport=inet endpoint=localhost:8891
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: trying... [127.0.0.1]
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_tweak_tcp: TCP_MAXSEG 21845
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: fd=28: stream buffer size old=0 new=43690
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: my_version=0x6
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_fflush_some: fd 28 flush 17
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_buf_get_ready: fd 28 got 17
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: milter inet:localhost:8891 version 6
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: events SMFIP_NOHELO SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_HDR_LEADSPC
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_CHGHDRS SMFIF_SETSYMLIST
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_conn_event: milter inet:localhost:8891: connect localhost/127.0.0.1
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: event: SMFIC_CONNECT; macros: j=foo-bar.com {daemon_name}=ORIGINATING {daemon_addr}=127.0.0.1 v=Postfix 3.3.1
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_fflush_some: fd 28 flush 122
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_buf_get_ready: fd 28 got 5
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: reply: SMFIR_CONTINUE data 0 bytes
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 220 foo-bar.com ESMTP Postfix
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: watchdog_pat: 0x560162f83b80
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_fflush_some: fd 27 flush 39
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_buf_get_ready: fd 27 got 26
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: < localhost[127.0.0.1]: EHLO foo-bar.com
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: report helo to all milters
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{tls_version}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{cipher}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{cipher_bits}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{cert_subject}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter_macro_lookup: "{cert_issuer}"
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_helo_event: milter inet:localhost:8891: helo foo-bar.com
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: event: SMFIC_HELO; macros: (none)
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: skipping event SMFIC_HELO for milter inet:localhost:8891
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_list_match: localhost: no match
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_list_match: 127.0.0.1: no match
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-foo-bar.com
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-PIPELINING
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-SIZE 10240000
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-VRFY
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-ETRN
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-STARTTLS
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-ENHANCEDSTATUSCODES
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-8BITMIME
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250-DSN
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 250 SMTPUTF8
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: watchdog_pat: 0x560162f83b80
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_fflush_some: fd 27 flush 156
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_buf_get_ready: fd 27 got 6
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: < localhost[127.0.0.1]: QUIT
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: > localhost[127.0.0.1]: 221 2.0.0 Bye
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 82.xxx.xxx.238/32
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 82.xxx.xxx.238/32
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostname: smtpd_client_event_limit_exceptions: localhost ~? 127.0.0.0/8
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: match_hostaddr: smtpd_client_event_limit_exceptions: 127.0.0.1 ~? 127.0.0.0/8
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: abort all milters
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_abort: abort milter inet:localhost:8891
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: disconnect event to all milters
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: milter8_disc_event: quit milter inet:localhost:8891
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: vstream_fflush_some: fd 28 flush 16
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: disconnect from localhost[127.0.0.1] ehlo=1 quit=1 commands=2
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: free all milters
Sep 16 11:46:51 localhost postfix/smtpd[1081563]: free milter inet:localhost:8891
Sep 16 11:46:55 localhost postfix/smtpd[1081566]: connect from unknown[212.70.149.4]
Sep 16 11:46:59 localhost postfix/smtpd[1081566]: disconnect from unknown[212.70.149.4] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
« Last Edit: September 29, 2020, 04:00:32 AM by MaMaKow »

Offline alec

  • Hero Member
  • *****
  • Posts: 1,217
Re: RC not sending mails
« Reply #1 on: September 16, 2020, 01:17:52 PM »
You should add tls:// prefix to the smtp_server option value.

Offline MaMaKow

  • Newbie
  • *
  • Posts: 4
Re: RC not sending mails
« Reply #2 on: September 16, 2020, 05:05:56 PM »
OK, I am one step further, but still quitting

[16-Sep-2020 23:02:46 +0200]: <ieck348e> Connecting to tls://localhost:587...
 85 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 220 foo-bar.comfoo-bar.com ESMTP Postfix
 86 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Send: EHLO foo-bar.com
 87 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-foo-bar.com
 88 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-PIPELINING
 89 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-SIZE 10240000
 90 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-VRFY
 91 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-ETRN
 92 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-STARTTLS
 93 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-ENHANCEDSTATUSCODES
 94 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-8BITMIME
 95 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250-DSN
 96 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 250 SMTPUTF8
 97 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Send: STARTTLS
 98 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: 220 2.0.0 Ready to start TLS
 99 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Send: QUIT
100 [16-Sep-2020 23:02:46 +0200]: <ieck348e> Recv: ^W^C^C^@ú^Z^LA¹<9f><94>tê<95>ßjzݺ».@K ÝúºR^B/ª

Offline JohnDoh

  • Global Moderator
  • Hero Member
  • *****
  • Posts: 2,524
Re: RC not sending mails
« Reply #3 on: September 17, 2020, 12:33:09 PM »
make sure you have set `imap_conn_options` in your rc config file to either disable certificate verification or otherwise tell PHP how to do it, Since you are connecting to localhost there is no way it will work automatically.
Roundcube Plugins: Contextmenu, SpamAssassin Prefs, and more…

Offline MaMaKow

  • Newbie
  • *
  • Posts: 4
Re: RC not sending mails
« Reply #4 on: September 21, 2020, 06:00:32 AM »
OK, i added the lines to the config.
Does postfix fail to send the certificates?

Code: [Select]
$config['imap_conn_options'] = array(
   'ssl'         => array(
      'verify_peer'  => true,
      'verify_depth' => 3,
      'cafile'       => '/etc/pki/tls/certs/ca-bundle.crt',
    ),
  );


Quote
#openssl s_client -connect foo-bar.com:587
CONNECTED(00000003)
139671266084680:error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol:s23_clnt.c:769:
---
no peer certificate available
---
No client certificate CA names sent
---
SSL handshake has read 7 bytes and written 247 bytes
---
New, (NONE), Cipher is (NONE)
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
---

Offline JohnDoh

  • Global Moderator
  • Hero Member
  • *****
  • Posts: 2,524
Re: RC not sending mails
« Reply #5 on: September 21, 2020, 03:34:44 PM »
Openssl reporting unknown protocol yea think that is something on the server side may be ask in the postfix community for help with the setup.
Roundcube Plugins: Contextmenu, SpamAssassin Prefs, and more…

Offline MaMaKow

  • Newbie
  • *
  • Posts: 4
Re: RC not sending mails
« Reply #6 on: September 29, 2020, 03:59:54 AM »
OK, i found the error.
TLS checks, if the domain given in the config matches the domain in the certificate.

The value was:
$config['smtp_server'] = 'tls://localhost';
but the value had to be:
$config['smtp_server'] = 'tls://foo-bar.com';

I think roundcube could have been a bit more verbose about this error.