[ksmtp] [Bug 502671] New: ksmtp stuck in TLS negotiation(?) with some servers

Marc Mezzarobba bugzilla_noreply at kde.org
Fri Apr 11 11:22:53 BST 2025 

https://bugs.kde.org/show_bug.cgi?id=502671

            Bug ID: 502671
           Summary: ksmtp stuck in TLS negotiation(?) with some servers
    Classification: Frameworks and Libraries
           Product: ksmtp
           Version: 6.3.3
          Platform: Debian unstable
                OS: Linux
            Status: REPORTED
          Severity: normal
          Priority: NOR
         Component: general
          Assignee: kdepim-bugs at kde.org
          Reporter: marc+bugs at mezzarobba.net
  Target Milestone: ---

Since I upgraded to akonadi 24.12.3, kmail ofter fails to send email. Messages
remain in outbox; the mail dispatcher agent appears to be stuck "sending" until
one manually aborts its activity using akonadiconsole.

However, this only happens with two out of three SMTP servers, all configured
to use STARTTLS. Looking at the logs, ksmtp appears to be stuck waiting for the
TLS negotiation to complete.

A workaround is to switch the "encryption" setting in kmail from STARTTLS to
SSL/TLS.

This is with libsasl2 version 2.1.28, but I think I previously observed the
same issue with an older version.

This is a case where it works:

[2025-04-11T09:41:59.561Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Item  305004 is accepted into the queue (size 1294
).
[2025-04-11T09:41:59.562Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Attempting to dispatch the next message.
[2025-04-11T09:41:59.567Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Fetched item 305004 ; creating SendJob.
[2025-04-11T09:41:59.568Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Transporting message.
[2025-04-11T09:41:59.568Z] akonadi_mailfilter_agent default 
MailFilterAgent::filterItem 
[2025-04-11T09:41:59.569Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport "1420216228"
[2025-04-11T09:41:59.570Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp Not
using any proxy to connect to the SMTP server.
[2025-04-11T09:41:59.577Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport.smtpplugin Login started
[2025-04-11T09:41:59.579Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
220 ]   "\"----- redacted.hostname ESMTP Postfix -----\""
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "redacted.hostname"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "PIPELINING"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "SIZE 15728640"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "VRFY"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ETRN"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "STARTTLS"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ENHANCEDSTATUSCODES"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "8BITMIME"
[2025-04-11T09:41:59.580Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "DSN"
[2025-04-11T09:41:59.581Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
220 ]   "2.0.0 Ready to start TLS"
[2025-04-11T09:41:59.589Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp TLS
negotiation done, the negotiated protocol is "TLSv1.3"
[2025-04-11T09:41:59.590Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "argos.lix.polytechnique.fr"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "PIPELINING"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "SIZE 15728640"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "VRFY"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ETRN"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "AUTH PLAIN GSSAPI"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "AUTH=PLAIN GSSAPI"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ENHANCEDSTATUSCODES"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "8BITMIME"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "DSN"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
Trying authmod "PLAIN"
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
SASL_INTERACT Id 16385
[2025-04-11T09:41:59.591Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
SASL_INTERACT Id 16386
[2025-04-11T09:41:59.592Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
SASL_CB_[USER|AUTHNAME]: ' "mezzarobba" '
[2025-04-11T09:41:59.592Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
SASL_INTERACT Id 16388
[2025-04-11T09:41:59.592Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
SASL_CB_PASS: [hidden]
[2025-04-11T09:41:59.592Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
Trying authmod "PLAIN"
[2025-04-11T09:41:59.616Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Item 305004 is ignored.
[2025-04-11T09:41:59.905Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
235 ]   "2.7.0 Authentication successful"
[2025-04-11T09:41:59.905Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport.smtpplugin Send started
[2025-04-11T09:41:59.906Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "2.1.0 Ok"
[2025-04-11T09:41:59.910Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "2.1.5 Ok"
[2025-04-11T09:41:59.911Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
354 ]   "End data with <CR><LF>.<CR><LF>"
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "2.0.0 Ok: queued as D93B82C0157"
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher success true message ""
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Success transporting.
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher sentBehaviour= 1 using collection from attribute
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport.smtpplugin clearing SMTP session pool 1
[2025-04-11T09:41:59.915Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport.smtpplugin Removing session
KSmtp::Session(0x56195ac5a230) from the pool
[2025-04-11T09:41:59.916Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
221 ]   "2.0.0 Bye"
[2025-04-11T09:41:59.916Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp
Socket disconnected
[2025-04-11T09:41:59.927Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Success deleting or moving to sent-mail.

And this is one where it gets stuck:

[2025-04-11T09:42:59.034Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Item  305005 is accepted into the queue (size 1188
).
[2025-04-11T09:42:59.034Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Attempting to dispatch the next message.
[2025-04-11T09:42:59.040Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Fetched item 305005 ; creating SendJob.
[2025-04-11T09:42:59.040Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Transporting message.
[2025-04-11T09:42:59.041Z] akonadi_mailfilter_agent default 
MailFilterAgent::filterItem 
[2025-04-11T09:42:59.042Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport "1340730984"
[2025-04-11T09:42:59.042Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp Not
using any proxy to connect to the SMTP server.
[2025-04-11T09:42:59.053Z] akonadi_maildispatcher_agent
org.kde.pim.mailtransport.smtpplugin Login started
[2025-04-11T09:42:59.059Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
220 ]   "other.redacted.hostname ESMTP Postfix (Debian/GNU)"
[2025-04-11T09:42:59.062Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "other.redacted.hostname"
[2025-04-11T09:42:59.062Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "PIPELINING"
[2025-04-11T09:42:59.062Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "SIZE 20971520"
[2025-04-11T09:42:59.062Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "VRFY"
[2025-04-11T09:42:59.062Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ETRN"
[2025-04-11T09:42:59.063Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "STARTTLS"
[2025-04-11T09:42:59.063Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "ENHANCEDSTATUSCODES"
[2025-04-11T09:42:59.063Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ] - "8BITMIME"
[2025-04-11T09:42:59.063Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
250 ]   "CHUNKING"
[2025-04-11T09:42:59.066Z] akonadi_maildispatcher_agent org.kde.pim.ksmtp S:: [
220 ]   "2.0.0 Ready to start TLS"
[2025-04-11T09:42:59.093Z] akonadi_maildispatcher_agent
org.kde.pim.maildispatcher Item 305005 is ignored.

-- 
You are receiving this mail because:
You are the assignee for the bug.

More information about the Kdepim-bugs mailing list