Roundcube does not send STARTTLS command

[SarenT]

I am trying to send an e-mail over SMTP but roundcube does not send the STARTTLS command, even though tls:// prefix is present.
I have openssl, PHP7.3 and Roundcube 1.6.0

Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Connecting to localhost:587...
Sep  2 20:22:05 hostname postfix/submission/smtpd[63751]: initializing the server-side TLS engine
Sep  2 20:22:05 hostname postfix/submission/smtpd[63751]: connect from localhost[::1]
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 220 mail.something.com ESMTP Postfix (Debian/GNU)
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Send: EHLO email.something.com
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-hostname.something.com
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-PIPELINING
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-SIZE 40960000
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-VRFY
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-ETRN
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-STARTTLS
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-ENHANCEDSTATUSCODES
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-8BITMIME
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250-DSN
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 250 SMTPUTF8
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Send: MAIL FROM:<myaddress@something.at>
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 530 5.7.0 Must issue a STARTTLS command first
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> PHP Error: Invalid response code received from server (POST /?_task=mail&_unlock=loading1662150125729&_framed=1&_action=send)
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Send: RSET
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 530 5.7.0 Must issue a STARTTLS command first
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> PHP Error: Invalid response code received from server (POST /?_task=mail&_unlock=loading1662150125729&_framed=1&_action=send)
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> SMTP Error: Failed to set sender 'myaddress@something.at': 5.7.0 Must issue a STARTTLS command first (Code: 530) in /var/local/roundcubemail-1.4.9/program/lib/Roundcube/rcube.php on line 1795 (POST /?_task=mail&_unlock=loading1662150125729&_framed=1&_action=send)
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Send: QUIT
Sep  2 20:22:05 hostname postfix/submission/smtpd[63751]: disconnect from localhost[::1] ehlo=1 mail=0/1 rset=0/1 quit=1 commands=2/4
Sep  2 20:22:05 hostname roundcube: <kafo3q8o> Recv: 221 2.0.0 Bye

[alecpl]

grep smtp_ config.inc.php, please.

[Touchwoody]

I have a similar issue (centos8stream, rc 1.6.0, php 8.1.10).
SMTP server sends 250-STARTTLS, RC-Server does not begin starttls, smtp side hangs up.

$config['smtp_log'] = true;
$config['smtp_host'] = 'tls://mail.example.com';
$config['smtp_port'] = 25;
$config['smtp_timeout'] = 1;
$config['smtp_debug'] = true;
//$config['smtp_auth_type'] = 'PLAIN';

[alecpl]

The config looks fine ($config['smtp_port'] is not used anymore). What about Roundcube logs?

[Touchwoody]

smtp.log is similar to above:

[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Connecting to tls://mail.example.com:587...
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 220 MAIL.EXAMPLE.COM ESMTP Postfix
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Send: EHLO roundcube.example.com
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-MAIL.EXAMPLE.COM
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-PIPELINING
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-SIZE 26214400
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-VRFY
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-ETRN
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-STARTTLS
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-ENHANCEDSTATUSCODES
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250-8BITMIME
[13-Sep-2022 14:31:50 +0200]: <5c4dkj4g> Recv: 250 DSN

Log ends here.
When I rolled back to 1.5.3 and compared it, it should continue at this point with Send: STARTTLS, Recv: 220 2.0.0 Ready to start TLS a.s.o.

SMTP server side looks like this:

Sep 13 14:31:50 mail postfix/smtpd[12848]: connect from roundcube.example.com [x.x.x.x]
Sep 13 14:31:50 mail postfix/smtpd[12848]: match_hostaddr: x.x.x.x ~? x.x.0.0/16
Sep 13 14:31:50 mail postfix/smtpd[12848]: check_namadr_access: name roundcube.example.com addr x.x.x.x
Sep 13 14:31:50 mail postfix/smtpd[12848]: check_addr_access: x.x.x.x
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 220 MAIL.EXAMPLE.COM ESMTP Postfix
Sep 13 14:31:50 mail postfix/smtpd[12848]: < roundcube.example.com[x.x.x.x]: EHLO roundcube.example.com
Sep 13 14:31:50 mail postfix/smtpd[12848]: match_list_match: x.x.x.x: no match
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-MAIL.EXAMPLE.COM
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-PIPELINING
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-SIZE 26214400
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-VRFY
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-ETRN
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-STARTTLS
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-ENHANCEDSTATUSCODES
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250-8BITMIME
Sep 13 14:31:50 mail postfix/smtpd[12848]: > roundcube.example.com[x.x.x.x]: 250 DSN
Sep 13 14:31:50 mail postfix/smtpd[12848]: match_hostaddr: x.x.x.x ~? x.x.0.0/16
Sep 13 14:31:50 mail postfix/smtpd[12848]: lost connection after EHLO from roundcube.example.com[x.x.x.x]
Sep 13 14:31:50 mail postfix/smtpd[12848]: disconnect from roundcube.example.com[x.x.x.x]

error.log was silent.

[alecpl]

It works for me. The only idea I have is #8642 and related tickets. But if it's "old dependencies" issue, then I'd expect an error in log.

[Touchwoody]

Ok, very nice.

Without checking if anything else broke now, I at least fixed this specific SMTP issue with a cp -rf roundcubemail-1.6.0/vendor/* /var/www/html/vendor/, bin/installto.sh was indeed lacking this.

[tallmtt]

@alecpl: You mentioned you would expect an error. This is the error I received for the same issue in my mail.log file:

roundcube: PHP Fatal error: Uncaught Error: Call to undefined method Net_SMTP::starttls() in /opt/www/roundcubemail/program/lib/Roundcube/rcube_smtp.php:164

I think my net_smtp package was too old, and I needed version 1.10.

---

Thanks, @Touchwoody: Your response solved my problem! I have been completely puzzled for several days.

I see @alecpl has submitted a bug report - Thanks, all of you for such a great product and all your work!

[kev300]

Hey, I did update all vendor packages like in @Touchwoody answer, but it did not fix the issue for me.
It still does not send STARTLS.
Roundcube 1.6.0, PHP 8.1

[eehmke]

The bug turned up again when updating from 1.6.0 to 1.6.1. Reverting to 1.6.0 fixed this. I never copied the vendor folder to /var/www/html/vendor/ as suggested by @Touchwoody.